2013-03-05T07:22:47.472Z,1362468167.473 [Supervisor](DEBUG): Initializing supervisor. 2013-03-05T07:22:47.477Z,1362468167.477 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2013-03-05T07:22:47.478Z,1362468167.478 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2013-03-05T07:22:47.481Z,1362468167.481 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2013-03-05T07:22:47.485Z,1362468167.485 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2013-03-05T07:22:47.496Z,1362468167.496 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2013-03-05T07:22:47.498Z,1362468167.497 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2013-03-05T07:22:47.498Z,1362468167.498 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2013-03-05T07:22:47.502Z,1362468167.501 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0 2013-03-05T07:22:47.502Z,1362468167.502 [Supervisor](INFO): Looking for Config files in directory: Config/ 2013-03-05T07:22:47.506Z,1362468167.506 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2013-03-05T07:22:47.822Z,1362468167.822 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2013-03-05T07:22:47.823Z,1362468167.823 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2013-03-05T07:22:48.033Z,1362468168.033 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2013-03-05T07:22:48.034Z,1362468168.034 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2013-03-05T07:22:48.129Z,1362468168.129 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2013-03-05T07:22:48.131Z,1362468168.131 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2013-03-05T07:22:48.346Z,1362468168.346 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2013-03-05T07:22:48.347Z,1362468168.347 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2013-03-05T07:22:48.494Z,1362468168.494 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2013-03-05T07:22:48.496Z,1362468168.496 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2013-03-05T07:22:48.758Z,1362468168.758 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2013-03-05T07:22:48.759Z,1362468168.759 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2013-03-05T07:22:48.950Z,1362468168.950 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2013-03-05T07:22:48.952Z,1362468168.952 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2013-03-05T07:22:49.233Z,1362468169.233 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2013-03-05T07:22:49.235Z,1362468169.235 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2013-03-05T07:22:49.346Z,1362468169.346 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2013-03-05T07:22:49.347Z,1362468169.347 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2013-03-05T07:22:49.793Z,1362468169.793 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2013-03-05T07:22:49.794Z,1362468169.794 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2013-03-05T07:22:49.922Z,1362468169.922 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2013-03-05T07:22:49.923Z,1362468169.923 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2013-03-05T07:22:50.019Z,1362468170.019 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2013-03-05T07:22:50.115Z,1362468170.115 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2013-03-05T07:22:50.232Z,1362468170.232 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2013-03-05T07:22:50.377Z,1362468170.378 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2013-03-05T07:22:50.473Z,1362468170.473 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2013-03-05T07:22:50.587Z,1362468170.587 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2013-03-05T07:22:50.699Z,1362468170.699 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2013-03-05T07:22:50.831Z,1362468170.831 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2013-03-05T07:22:50.935Z,1362468170.935 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2013-03-05T07:22:51.033Z,1362468171.033 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2013-03-05T07:22:51.064Z,1362468171.064 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2013-03-05T07:22:51.275Z,1362468171.275 [InternalSim] Loaded 2013-03-05T07:22:51.276Z,1362468171.276 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2013-03-05T07:22:51.277Z,1362468171.277 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2013-03-05T07:22:51.277Z,1362468171.277 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2013-03-05T07:22:51.361Z,1362468171.361 [SBIT](DEBUG): Construct Startup Built In Test. 2013-03-05T07:22:51.394Z,1362468171.394 [SBIT] Loaded 2013-03-05T07:22:51.394Z,1362468171.394 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2013-03-05T07:22:51.395Z,1362468171.395 [IBIT](DEBUG): Construct Initiated Built In Test. 2013-03-05T07:22:51.428Z,1362468171.428 [IBIT] Loaded 2013-03-05T07:22:51.429Z,1362468171.429 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2013-03-05T07:22:51.432Z,1362468171.432 [CBIT](DEBUG): Construct CBIT Built In Test. 2013-03-05T07:22:51.574Z,1362468171.574 [CBIT] Loaded 2013-03-05T07:22:51.575Z,1362468171.575 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2013-03-05T07:22:51.575Z,1362468171.575 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2013-03-05T07:22:51.576Z,1362468171.576 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2013-03-05T07:22:51.760Z,1362468171.760 [BuoyancyServo] Loaded 2013-03-05T07:22:51.760Z,1362468171.760 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2013-03-05T07:22:51.772Z,1362468171.773 [ElevatorServo] Loaded 2013-03-05T07:22:51.773Z,1362468171.773 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2013-03-05T07:22:51.789Z,1362468171.789 [MassServo] Loaded 2013-03-05T07:22:51.789Z,1362468171.789 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2013-03-05T07:22:51.802Z,1362468171.802 [RudderServo] Loaded 2013-03-05T07:22:51.802Z,1362468171.802 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2013-03-05T07:22:51.814Z,1362468171.814 [ThrusterServo] Loaded 2013-03-05T07:22:51.814Z,1362468171.814 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2013-03-05T07:22:51.815Z,1362468171.815 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2013-03-05T07:22:51.815Z,1362468171.815 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2013-03-05T07:22:51.852Z,1362468171.852 [DepthRateCalculator] Loaded 2013-03-05T07:22:51.852Z,1362468171.852 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2013-03-05T07:22:55.550Z,1362468175.550 [HFRadarModelCalc] Loaded 2013-03-05T07:22:55.550Z,1362468175.550 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread. 2013-03-05T07:22:55.567Z,1362468175.567 [NavChart] Loaded 2013-03-05T07:22:55.567Z,1362468175.567 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2013-03-05T07:22:55.573Z,1362468175.573 [PitchRateCalculator] Loaded 2013-03-05T07:22:55.573Z,1362468175.573 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2013-03-05T07:22:55.580Z,1362468175.580 [SpeedCalculator] Loaded 2013-03-05T07:22:55.580Z,1362468175.580 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2013-03-05T07:22:55.600Z,1362468175.600 [TempGradientCalculator] Loaded 2013-03-05T07:22:55.600Z,1362468175.600 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2013-03-05T07:22:55.610Z,1362468175.610 [YawRateCalculator] Loaded 2013-03-05T07:22:55.610Z,1362468175.610 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2013-03-05T07:22:55.656Z,1362468175.656 [Navigation] Loaded 2013-03-05T07:22:55.657Z,1362468175.657 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread. 2013-03-05T07:22:55.657Z,1362468175.657 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2013-03-05T07:22:55.658Z,1362468175.658 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2013-03-05T07:22:55.949Z,1362468175.949 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2013-03-05T07:22:55.949Z,1362468175.949 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2013-03-05T07:22:55.994Z,1362468175.994 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2013-03-05T07:22:55.995Z,1362468175.995 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2013-03-05T07:22:56.060Z,1362468176.060 [VerticalControl](DEBUG): Construct VerticalControl. 2013-03-05T07:22:56.165Z,1362468176.165 [VerticalControl] Loaded 2013-03-05T07:22:56.165Z,1362468176.165 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2013-03-05T07:22:56.166Z,1362468176.166 [HorizontalControl](DEBUG): Construct HorizontalControl. 2013-03-05T07:22:56.233Z,1362468176.233 [HorizontalControl] Loaded 2013-03-05T07:22:56.233Z,1362468176.233 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2013-03-05T07:22:56.234Z,1362468176.234 [SpeedControl](DEBUG): Construct SpeedControl. 2013-03-05T07:22:56.236Z,1362468176.236 [SpeedControl] Loaded 2013-03-05T07:22:56.236Z,1362468176.236 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2013-03-05T07:22:56.237Z,1362468176.237 [LoopControl](DEBUG): Construct LoopControl. 2013-03-05T07:22:56.238Z,1362468176.238 [LoopControl] Loaded 2013-03-05T07:22:56.238Z,1362468176.238 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2013-03-05T07:22:56.238Z,1362468176.239 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2013-03-05T07:22:56.239Z,1362468176.239 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2013-03-05T07:22:56.247Z,1362468176.247 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2013-03-05T07:22:56.252Z,1362468176.252 [AsyncPiEstimator] Loaded 2013-03-05T07:22:56.253Z,1362468176.253 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2013-03-05T07:22:56.258Z,1362468176.258 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A44E0 2013-03-05T07:22:56.258Z,1362468176.258 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2013-03-05T07:22:56.259Z,1362468176.259 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2013-03-05T07:22:56.448Z,1362468176.448 [AHRS_sp3003D] Loaded 2013-03-05T07:22:56.448Z,1362468176.448 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2013-03-05T07:22:56.752Z,1362468176.752 [Batt_Ocean_Server] Loaded 2013-03-05T07:22:56.752Z,1362468176.752 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2013-03-05T07:22:56.771Z,1362468176.770 [Depth_Keller] Loaded 2013-03-05T07:22:56.771Z,1362468176.771 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2013-03-05T07:22:56.777Z,1362468176.777 [DropWeight] Loaded 2013-03-05T07:22:56.777Z,1362468176.777 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2013-03-05T07:22:56.983Z,1362468176.983 [DVL_micro] Loaded 2013-03-05T07:22:56.983Z,1362468176.983 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread. 2013-03-05T07:22:56.985Z,1362468176.986 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 407284E0 2013-03-05T07:22:57.082Z,1362468177.082 [NAL9602] Loaded 2013-03-05T07:22:57.082Z,1362468177.082 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2013-03-05T07:22:57.144Z,1362468177.144 [Onboard] Loaded 2013-03-05T07:22:57.144Z,1362468177.144 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2013-03-05T07:22:57.145Z,1362468177.145 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2013-03-05T07:22:57.146Z,1362468177.146 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2013-03-05T07:22:57.238Z,1362468177.238 [Aanderaa_O2] Loaded 2013-03-05T07:22:57.238Z,1362468177.238 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2013-03-05T07:22:57.276Z,1362468177.276 [CTD_NeilBrown] Loaded 2013-03-05T07:22:57.276Z,1362468177.276 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2013-03-05T07:22:57.278Z,1362468177.277 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4077A4E0 2013-03-05T07:22:57.292Z,1362468177.292 [ISUS] Loaded 2013-03-05T07:22:57.292Z,1362468177.292 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread. 2013-03-05T07:22:57.312Z,1362468177.312 [PAR_Licor] Loaded 2013-03-05T07:22:57.312Z,1362468177.312 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2013-03-05T07:22:57.348Z,1362468177.348 [WetLabsBB2FL] Loaded 2013-03-05T07:22:57.348Z,1362468177.348 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2013-03-05T07:22:57.350Z,1362468177.349 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407AA4E0 2013-03-05T07:22:57.350Z,1362468177.350 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2013-03-05T07:22:57.353Z,1362468177.353 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2013-03-05T07:22:57.354Z,1362468177.354 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2013-03-05T07:22:57.364Z,1362468177.364 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2013-03-05T07:22:57.366Z,1362468177.366 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407DA4E0 2013-03-05T07:22:57.370Z,1362468177.370 [Supervisor](DEBUG): Running supervisor. 2013-03-05T07:22:57.371Z,1362468177.372 [CommandLine](INFO): Thread ID is 750 2013-03-05T07:22:57.374Z,1362468177.374 [controlThread](INFO): Thread ID is 749 2013-03-05T07:22:57.374Z,1362468177.374 [controlThread](DEBUG): Initializing ControlThread 2013-03-05T07:22:57.375Z,1362468177.375 [CycleStarter](INFO): Thread ID is 748 2013-03-05T07:22:57.375Z,1362468177.375 [InternalSim](DEBUG): InternalSim initializing... 2013-03-05T07:22:57.486Z,1362468177.486 [logger](INFO): Thread ID is 751 2013-03-05T07:22:57.614Z,1362468177.614 [AsyncPiEstimator](INFO): Thread ID is 812 2013-03-05T07:22:57.614Z,1362468177.614 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2013-03-05T07:22:57.679Z,1362468177.679 [DVL_micro](INFO): Thread ID is 813 2013-03-05T07:22:57.698Z,1362468177.698 [DVL_micro](INFO): Initializing 2013-03-05T07:22:57.698Z,1362468177.698 [DVL_micro](INFO): start:Powering up 2013-03-05T07:22:57.699Z,1362468177.699 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-03-05T07:22:57.700Z,1362468177.700 [DVL_micro](INFO): Cycling power to configure device. 2013-03-05T07:22:57.718Z,1362468177.718 [CTD_NeilBrown](INFO): Thread ID is 814 2013-03-05T07:22:57.719Z,1362468177.719 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2013-03-05T07:22:57.730Z,1362468177.730 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2013-03-05T07:22:57.777Z,1362468177.777 [WetLabsBB2FL](INFO): Thread ID is 815 2013-03-05T07:22:57.777Z,1362468177.777 [WetLabsBB2FL](INFO): Powering down 2013-03-05T07:22:57.801Z,1362468177.801 [SBIT](INFO): Initialize SBIT Component. 2013-03-05T07:22:57.801Z,1362468177.801 [SBIT](IMPORTANT): Tethys CM Info: $Rev: 10215 2013-03-05T07:22:57.803Z,1362468177.803 [NavChartDb](INFO): Thread ID is 816 2013-03-05T07:22:57.804Z,1362468177.804 [IBIT](INFO): Initialize IBIT Component. 2013-03-05T07:22:57.820Z,1362468177.820 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2013-03-05T07:22:57.820Z,1362468177.820 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2013-03-05T07:22:57.821Z,1362468177.821 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2013-03-05T07:22:57.821Z,1362468177.821 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2013-03-05T07:22:57.821Z,1362468177.821 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2013-03-05T07:22:57.822Z,1362468177.822 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2013-03-05T07:22:57.822Z,1362468177.822 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2013-03-05T07:22:57.822Z,1362468177.822 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2013-03-05T07:22:57.822Z,1362468177.822 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2013-03-05T07:22:57.831Z,1362468177.831 [CBIT](DEBUG): Initialize CBIT Component. 2013-03-05T07:22:57.831Z,1362468177.831 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2013-03-05T07:22:57.845Z,1362468177.845 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2013-03-05T07:22:57.883Z,1362468177.883 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2013-03-05T07:22:57.883Z,1362468177.883 [NavChart](DEBUG): Initialize NavChart Derivation. 2013-03-05T07:22:57.884Z,1362468177.884 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2013-03-05T07:22:57.884Z,1362468177.884 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2013-03-05T07:22:57.885Z,1362468177.885 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2013-03-05T07:22:57.890Z,1362468177.890 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2013-03-05T07:22:57.891Z,1362468177.891 [Navigation](DEBUG): Initializing Navigation. 2013-03-05T07:22:57.891Z,1362468177.891 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2013-03-05T07:22:57.893Z,1362468177.893 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2013-03-05T07:22:57.893Z,1362468177.893 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2013-03-05T07:22:57.894Z,1362468177.894 [LoopControl](DEBUG): Initialize LoopControlComponent. 2013-03-05T07:22:59.611Z,1362468179.611 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2013-03-05T07:22:59.642Z,1362468179.642 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2013-03-05T07:22:59.687Z,1362468179.687 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2013-03-05T07:22:59.705Z,1362468179.705 [MissionManager](DEBUG): 2013-03-05T07:22:59.722Z,1362468179.722 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2013-03-05T07:22:59.793Z,1362468179.793 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2013-03-05T07:22:59.807Z,1362468179.807 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2013-03-05T07:22:59.818Z,1362468179.818 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-03-05T07:22:59.818Z,1362468179.818 [DVL_micro](INFO): Querying output modes 2013-03-05T07:22:59.819Z,1362468179.819 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-03-05T07:22:59.830Z,1362468179.830 [DVL_micro](DEBUG): cmdResponse: 01 2013-03-05T07:22:59.830Z,1362468179.830 [DVL_micro](INFO): NQ1 output enabled 2013-03-05T07:22:59.830Z,1362468179.830 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-03-05T07:22:59.832Z,1362468179.832 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-03-05T07:22:59.842Z,1362468179.842 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-03-05T07:22:59.847Z,1362468179.847 [DVL_micro](INFO): pause:Powering down 2013-03-05T07:22:59.869Z,1362468179.869 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2013-03-05T07:22:59.872Z,1362468179.872 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-03-05T07:22:59.887Z,1362468179.887 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2013-03-05T07:22:59.895Z,1362468179.895 [Default:D.SetSpeed](DEBUG): Construct. 2013-03-05T07:22:59.934Z,1362468179.934 [Default:E.GoToSurface](DEBUG): Construct GoToSurface. 2013-03-05T07:22:59.939Z,1362468179.939 [Default:F.Wait](DEBUG): Construct Wait. 2013-03-05T07:22:59.959Z,1362468179.959 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2013-03-05T07:22:59.963Z,1362468179.963 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Aanderaa_O2,ISUS,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter, 2013-03-05T07:23:00.007Z,1362468180.007 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2013-03-05T07:23:00.770Z,1362468180.770 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2013-03-05T07:23:00.778Z,1362468180.778 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2013-03-05T07:23:00.784Z,1362468180.784 [ElevatorServo](DEBUG): Initializing EZServoServo. 2013-03-05T07:23:00.790Z,1362468180.790 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2013-03-05T07:23:00.796Z,1362468180.796 [MassServo](DEBUG): Initializing EZServoServo. 2013-03-05T07:23:00.802Z,1362468180.802 [MassServo](DEBUG): Initializing MassServo. 2013-03-05T07:23:00.807Z,1362468180.807 [RudderServo](DEBUG): Initializing EZServoServo. 2013-03-05T07:23:00.838Z,1362468180.838 [RudderServo](DEBUG): Initializing RudderServo. 2013-03-05T07:23:00.851Z,1362468180.851 [ThrusterServo](DEBUG): Initializing EZServoServo. 2013-03-05T07:23:00.862Z,1362468180.862 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2013-03-05T07:23:02.160Z,1362468182.160 [NAL9602](INFO): Powering up NAL9602 2013-03-05T07:23:03.158Z,1362468183.158 [Aanderaa_O2](INFO): Powering down 2013-03-05T07:23:12.870Z,1362468192.870 [NAL9602](INFO): NAL9602 initialized 2013-03-05T07:23:13.292Z,1362468193.292 [SBIT](IMPORTANT): Beginning Startup BIT 2013-03-05T07:23:13.294Z,1362468193.294 [CBIT](IMPORTANT): Beginning GF scan 2013-03-05T07:23:36.932Z,1362468216.932 [NAL9602](IMPORTANT): GPS fix at: 1362511406.00 2013-03-05T07:23:39.794Z,1362468219.794 [CBIT](IMPORTANT): No ground fault detected 2013-03-05T07:23:44.130Z,1362468224.130 [NAL9602](INFO): Powering down 2013-03-05T07:24:07.080Z,1362468247.080 [SBIT](IMPORTANT): SBIT PASSED 2013-03-05T07:24:07.535Z,1362468247.535 [MissionManager](IMPORTANT): Started mission Startup 2013-03-05T07:24:07.535Z,1362468247.535 [Startup] Running Loop=1 2013-03-05T07:24:07.535Z,1362468247.535 [Startup](INFO): Aggregate::initialize Startup 2013-03-05T07:24:07.535Z,1362468247.535 [Startup:A.GoToSurface] Running Loop=1 2013-03-05T07:24:07.535Z,1362468247.535 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-03-05T07:24:07.541Z,1362468247.541 [Startup:StartupSatComms] Running Loop=1 2013-03-05T07:24:07.541Z,1362468247.541 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2013-03-05T07:24:07.541Z,1362468247.541 [Startup:StartupSatComms:A] Running Loop=1 2013-03-05T07:24:07.868Z,1362468247.868 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2013-03-05T07:24:08.259Z,1362468248.259 [NAL9602](INFO): Powering up 2013-03-05T07:24:19.298Z,1362468259.298 [NAL9602](INFO): NAL9602 initialized 2013-03-05T07:24:44.762Z,1362468284.762 [NAL9602](IMPORTANT): GPS fix at: 1362511474.00 2013-03-05T07:24:44.777Z,1362468284.777 [Startup:StartupSatComms:A] Stopped 2013-03-05T07:24:44.777Z,1362468284.777 [Startup:StartupSatComms:B] Running Loop=1 2013-03-05T07:24:45.184Z,1362468285.184 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-03-05T07:25:02.821Z,1362468302.821 [NAL9602](INFO): SBD MO Status=1, MOMSN=6505, MT Status=0, MTMSN=0 2013-03-05T07:25:02.870Z,1362468302.870 [NAL9602](INFO): Sent 171 bytes from file Logs/20130305T055746/shore0010.lzma 2013-03-05T07:25:02.870Z,1362468302.870 [NAL9602](INFO): Packets left to send: 0 2013-03-05T07:25:02.872Z,1362468302.872 [NAL9602](INFO): Stored copy of sent data in Logs/20130305T055746/shore0010.lzma.parts/0000.sbd 2013-03-05T07:25:27.837Z,1362468327.837 [NAL9602](INFO): SBD MO Status=2, MOMSN=6506, MT Status=2, MTMSN=0 2013-03-05T07:25:27.837Z,1362468327.837 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-03-05T07:25:45.153Z,1362468345.153 [Startup:StartupSatComms:B](INFO): Timed out from 2013-03-05T07:24:44.8Z 2013-03-05T07:25:45.153Z,1362468345.153 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1 2013-03-05T07:25:45.153Z,1362468345.153 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout 2013-03-05T07:25:45.154Z,1362468345.154 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout 2013-03-05T07:25:45.154Z,1362468345.154 [Startup:StartupSatComms:B] Stopped 2013-03-05T07:25:45.154Z,1362468345.154 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2013-03-05T07:25:45.154Z,1362468345.154 [Startup:StartupSatComms] Stopped 2013-03-05T07:25:45.154Z,1362468345.154 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2013-03-05T07:25:45.155Z,1362468345.155 [Startup](INFO): Completed Startup 2013-03-05T07:25:45.155Z,1362468345.155 [Startup] Stopped 2013-03-05T07:25:45.155Z,1362468345.155 [Startup](INFO): Aggregate::uninitialize Startup 2013-03-05T07:25:45.155Z,1362468345.155 [Startup:A.GoToSurface] Stopped 2013-03-05T07:25:45.155Z,1362468345.155 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-03-05T07:25:45.538Z,1362468345.538 [MissionManager](IMPORTANT): Started mission Default 2013-03-05T07:25:45.538Z,1362468345.538 [Default] Running Loop=1 2013-03-05T07:25:45.538Z,1362468345.538 [Default](INFO): Aggregate::initialize Default 2013-03-05T07:25:45.539Z,1362468345.539 [Default:D.SetSpeed] Running Loop=1 2013-03-05T07:25:45.539Z,1362468345.539 [Default:D.SetSpeed](DEBUG): Initialize. 2013-03-05T07:25:45.539Z,1362468345.539 [Default:E.GoToSurface] Running Loop=1 2013-03-05T07:25:45.539Z,1362468345.539 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-03-05T07:25:45.539Z,1362468345.539 [Default:Iridium] Running Loop=1 2013-03-05T07:25:45.539Z,1362468345.539 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-03-05T07:25:45.539Z,1362468345.539 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-03-05T07:25:45.539Z,1362468345.539 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-03-05T07:25:45.540Z,1362468345.540 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-03-05T07:25:45.540Z,1362468345.540 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-03-05T07:25:45.540Z,1362468345.540 [Default:E.GoToSurface] Running Loop=1 2013-03-05T07:25:45.546Z,1362468345.546 [Default:D.SetSpeed] Running Loop=1 2013-03-05T07:25:45.551Z,1362468345.551 [Default:CallIridium] Running Loop=1 2013-03-05T07:25:45.551Z,1362468345.551 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-03-05T07:25:45.551Z,1362468345.551 [Default:CallIridium:A] Running Loop=1 2013-03-05T07:25:45.553Z,1362468345.553 [Default:CallIridium:A] Stopped 2013-03-05T07:25:45.553Z,1362468345.553 [Default:CallIridium:B] Running Loop=1 2013-03-05T07:25:45.553Z,1362468345.553 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-03-05T07:25:45.559Z,1362468345.559 [Default:Iridium:B.GoToSurface] Stopped 2013-03-05T07:25:45.559Z,1362468345.559 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-03-05T07:25:45.559Z,1362468345.559 [Default:Iridium:Read_Iridium] Running Loop=1 2013-03-05T07:25:45.559Z,1362468345.559 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-03-05T07:25:45.564Z,1362468345.564 [Default:GPS] Running Loop=1 2013-03-05T07:25:45.564Z,1362468345.565 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-03-05T07:25:45.565Z,1362468345.565 [Default:GPS:A.SetSpeed] Running Loop=1 2013-03-05T07:25:45.565Z,1362468345.565 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-03-05T07:25:45.565Z,1362468345.565 [Default:GPS:B.GoToSurface] Running Loop=1 2013-03-05T07:25:45.565Z,1362468345.565 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-03-05T07:25:45.571Z,1362468345.571 [Default:GPS:B.GoToSurface] Stopped 2013-03-05T07:25:45.571Z,1362468345.571 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-03-05T07:25:45.571Z,1362468345.571 [Default:GPS:Read_GPS] Running Loop=1 2013-03-05T07:25:45.571Z,1362468345.571 [Default:GPS:A.SetSpeed] Running Loop=1 2013-03-05T07:25:45.992Z,1362468345.992 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-03-05T07:25:45.995Z,1362468345.995 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2013-03-05T07:25:52.671Z,1362468352.671 [NAL9602](IMPORTANT): GPS fix at: 1362511542.00 2013-03-05T07:25:52.687Z,1362468352.687 [Default:GPS:Read_GPS] Stopped 2013-03-05T07:25:52.687Z,1362468352.687 [Default:GPS:D] Running Loop=1 2013-03-05T07:25:53.077Z,1362468353.077 [Default:GPS:D] Stopped 2013-03-05T07:25:53.078Z,1362468353.078 [Default:GPS](INFO): Completed Default:GPS 2013-03-05T07:25:53.078Z,1362468353.078 [Default:GPS] Stopped 2013-03-05T07:25:53.078Z,1362468353.078 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-03-05T07:25:53.078Z,1362468353.078 [Default:GPS:A.SetSpeed] Stopped 2013-03-05T07:25:53.078Z,1362468353.078 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-03-05T07:28:55.257Z,1362468535.257 [NAL9602](INFO): SBD MO Status=2, MOMSN=6506, MT Status=2, MTMSN=0 2013-03-05T07:28:55.257Z,1362468535.257 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-03-05T07:29:25.760Z,1362468565.760 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#2 STATUS: 65535 2013-03-05T07:29:30.084Z,1362468570.084 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#2 STATUS: 65535 2013-03-05T07:29:34.408Z,1362468574.408 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#2 STATUS: 65535 2013-03-05T07:29:39.142Z,1362468579.142 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#2 STATUS: 65535 2013-03-05T07:29:42.996Z,1362468582.996 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#2 STATUS: 65535 2013-03-05T07:29:47.387Z,1362468587.387 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#2 STATUS: 65535 2013-03-05T07:29:51.786Z,1362468591.786 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#2 STATUS: 65535 2013-03-05T07:29:56.224Z,1362468596.224 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#2 STATUS: 65535 2013-03-05T07:29:56.564Z,1362468596.564 [NAL9602](INFO): SBD MO Status=2, MOMSN=6506, MT Status=2, MTMSN=0 2013-03-05T07:29:56.565Z,1362468596.565 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-03-05T07:30:00.593Z,1362468600.593 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#2 STATUS: 65535 2013-03-05T07:30:04.847Z,1362468604.847 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#2 STATUS: 65535 2013-03-05T07:30:09.168Z,1362468609.168 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#2 STATUS: 65535 2013-03-05T07:30:25.724Z,1362468625.724 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=6506, MT Status=1, MTMSN=530 2013-03-05T07:30:25.774Z,1362468625.774 [NAL9602](INFO): Sent 160 bytes from file Logs/20130305T055746/shore0011.lzma 2013-03-05T07:30:25.774Z,1362468625.774 [NAL9602](INFO): Packets left to send: 0 2013-03-05T07:30:25.776Z,1362468625.776 [NAL9602](INFO): Stored copy of sent data in Logs/20130305T055746/shore0011.lzma.parts/0000.sbd 2013-03-05T07:30:26.362Z,1362468626.362 [NAL9602](INFO): Received command:! echo 1 > /dev/loadA2 2013-03-05T07:30:26.410Z,1362468626.410 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadA2 2013-03-05T07:30:46.851Z,1362468646.851 [NAL9602](INFO): SBD MO Status=1, MOMSN=6507, MT Status=0, MTMSN=0 2013-03-05T07:30:46.898Z,1362468646.898 [NAL9602](INFO): Sent 332 bytes from file Logs/20130305T072247/shore0000.lzma 2013-03-05T07:30:46.898Z,1362468646.898 [NAL9602](INFO): Packets left to send: 2 2013-03-05T07:30:46.900Z,1362468646.900 [NAL9602](INFO): Stored copy of sent data in Logs/20130305T072247/shore0000.lzma.parts/0002.sbd 2013-03-05T07:30:59.915Z,1362468659.915 [NAL9602](INFO): SBD MO Status=1, MOMSN=6508, MT Status=0, MTMSN=0 2013-03-05T07:30:59.962Z,1362468659.962 [NAL9602](INFO): Sent 332 bytes from file Logs/20130305T072247/shore0000.lzma 2013-03-05T07:30:59.962Z,1362468659.962 [NAL9602](INFO): Packets left to send: 1 2013-03-05T07:30:59.963Z,1362468659.963 [NAL9602](INFO): Stored copy of sent data in Logs/20130305T072247/shore0000.lzma.parts/0001.sbd 2013-03-05T07:31:10.644Z,1362468670.644 [NAL9602](INFO): SBD MO Status=1, MOMSN=6509, MT Status=0, MTMSN=0 2013-03-05T07:31:10.694Z,1362468670.694 [NAL9602](INFO): Sent 73 bytes from file Logs/20130305T072247/shore0000.lzma 2013-03-05T07:31:10.694Z,1362468670.694 [NAL9602](INFO): Packets left to send: 0 2013-03-05T07:31:10.695Z,1362468670.695 [NAL9602](INFO): Stored copy of sent data in Logs/20130305T072247/shore0000.lzma.parts/0000.sbd 2013-03-05T07:31:18.643Z,1362468678.643 [NAL9602](INFO): SBD MO Status=0, MOMSN=6510, MT Status=0, MTMSN=0 2013-03-05T07:31:31.257Z,1362468691.257 [NAL9602](INFO): SBD MO Status=1, MOMSN=6511, MT Status=0, MTMSN=0 2013-03-05T07:31:31.310Z,1362468691.310 [NAL9602](INFO): Sent 332 bytes from file Logs/20130305T072247/shore0001.lzma 2013-03-05T07:31:31.310Z,1362468691.310 [NAL9602](INFO): Packets left to send: 1 2013-03-05T07:31:31.312Z,1362468691.312 [NAL9602](INFO): Stored copy of sent data in Logs/20130305T072247/shore0001.lzma.parts/0001.sbd 2013-03-05T07:31:41.856Z,1362468701.856 [NAL9602](INFO): SBD MO Status=1, MOMSN=6512, MT Status=0, MTMSN=0 2013-03-05T07:31:41.906Z,1362468701.906 [NAL9602](INFO): Sent 41 bytes from file Logs/20130305T072247/shore0001.lzma 2013-03-05T07:31:41.906Z,1362468701.906 [NAL9602](INFO): Packets left to send: 0 2013-03-05T07:31:41.907Z,1362468701.907 [NAL9602](INFO): Stored copy of sent data in Logs/20130305T072247/shore0001.lzma.parts/0000.sbd 2013-03-05T07:31:52.257Z,1362468712.257 [NAL9602](INFO): SBD MO Status=0, MOMSN=6513, MT Status=0, MTMSN=0 2013-03-05T07:31:52.349Z,1362468712.349 [Default:Iridium:Read_Iridium] Stopped 2013-03-05T07:31:52.349Z,1362468712.349 [Default:Iridium](INFO): Completed Default:Iridium 2013-03-05T07:31:52.349Z,1362468712.349 [Default:Iridium] Stopped 2013-03-05T07:31:52.349Z,1362468712.349 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-03-05T07:31:52.349Z,1362468712.349 [Default:Iridium:A.SetSpeed] Stopped 2013-03-05T07:31:52.350Z,1362468712.349 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-03-05T07:31:52.350Z,1362468712.350 [Default:F.Wait] Running Loop=1 2013-03-05T07:31:52.350Z,1362468712.350 [Default:F.Wait](DEBUG): Initialize Wait Component. 2013-03-05T07:31:52.688Z,1362468712.688 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2013-03-05T07:31:52.688Z,1362468712.688 [Default:CallIridium:B] Stopped 2013-03-05T07:31:52.688Z,1362468712.688 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2013-03-05T07:31:52.689Z,1362468712.689 [Default:CallIridium](INFO): Completed Default:CallIridium 2013-03-05T07:31:52.689Z,1362468712.689 [Default:CallIridium] Stopped 2013-03-05T07:31:52.689Z,1362468712.689 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2013-03-05T07:32:02.824Z,1362468722.824 [NAL9602](INFO): Powering down 2013-03-05T07:36:52.841Z,1362469012.841 [Default:CallIridium] Running Loop=1 2013-03-05T07:36:52.841Z,1362469012.841 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-03-05T07:36:52.841Z,1362469012.842 [Default:CallIridium:A] Running Loop=1 2013-03-05T07:36:52.842Z,1362469012.842 [Default:CallIridium:A] Stopped 2013-03-05T07:36:52.842Z,1362469012.842 [Default:CallIridium:B] Running Loop=1 2013-03-05T07:36:52.842Z,1362469012.842 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-03-05T07:36:57.908Z,1362469017.908 [Default:Iridium] Running Loop=1 2013-03-05T07:36:57.908Z,1362469017.908 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-03-05T07:36:57.908Z,1362469017.908 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-03-05T07:36:57.908Z,1362469017.908 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-03-05T07:36:57.908Z,1362469017.908 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-03-05T07:36:57.908Z,1362469017.908 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-03-05T07:36:57.909Z,1362469017.909 [Default:Iridium:B.GoToSurface] Stopped 2013-03-05T07:36:57.909Z,1362469017.909 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-03-05T07:36:57.936Z,1362469017.936 [Default:Iridium:Read_Iridium] Running Loop=1 2013-03-05T07:36:57.938Z,1362469017.938 [Default:GPS] Running Loop=1 2013-03-05T07:36:57.938Z,1362469017.938 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-03-05T07:36:57.939Z,1362469017.939 [Default:GPS:A.SetSpeed] Running Loop=1 2013-03-05T07:36:57.939Z,1362469017.939 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-03-05T07:36:57.939Z,1362469017.939 [Default:GPS:B.GoToSurface] Running Loop=1 2013-03-05T07:36:57.939Z,1362469017.939 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-03-05T07:36:57.942Z,1362469017.942 [Default:GPS:B.GoToSurface] Stopped 2013-03-05T07:36:57.942Z,1362469017.942 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-03-05T07:36:57.942Z,1362469017.943 [Default:GPS:Read_GPS] Running Loop=1 2013-03-05T07:36:58.543Z,1362469018.543 [NAL9602](INFO): Powering up 2013-03-05T07:37:09.406Z,1362469029.406 [NAL9602](INFO): NAL9602 initialized 2013-03-05T07:37:45.828Z,1362469065.828 [NAL9602](INFO): SBD MO Status=2, MOMSN=6514, MT Status=2, MTMSN=0 2013-03-05T07:37:45.828Z,1362469065.828 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-03-05T07:37:47.054Z,1362469067.055 [NAL9602](IMPORTANT): GPS fix at: 1362512257.00 2013-03-05T07:37:47.071Z,1362469067.071 [Default:GPS:Read_GPS] Stopped 2013-03-05T07:37:47.071Z,1362469067.071 [Default:GPS:D] Running Loop=1 2013-03-05T07:37:47.458Z,1362469067.458 [Default:GPS:D] Stopped 2013-03-05T07:37:47.458Z,1362469067.458 [Default:GPS](INFO): Completed Default:GPS 2013-03-05T07:37:47.459Z,1362469067.459 [Default:GPS] Stopped 2013-03-05T07:37:47.459Z,1362469067.459 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-03-05T07:37:47.459Z,1362469067.459 [Default:GPS:A.SetSpeed] Stopped 2013-03-05T07:37:47.459Z,1362469067.459 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-03-05T07:39:14.553Z,1362469154.553 [NAL9602](INFO): SBD MO Status=1, MOMSN=6514, MT Status=0, MTMSN=0 2013-03-05T07:39:14.602Z,1362469154.602 [NAL9602](INFO): Sent 112 bytes from file Logs/20130305T072247/shore0002.lzma 2013-03-05T07:39:14.602Z,1362469154.602 [NAL9602](INFO): Packets left to send: 0 2013-03-05T07:39:14.604Z,1362469154.604 [NAL9602](INFO): Stored copy of sent data in Logs/20130305T072247/shore0002.lzma.parts/0000.sbd 2013-03-05T07:39:21.756Z,1362469161.756 [NAL9602](INFO): SBD MO Status=0, MOMSN=6515, MT Status=0, MTMSN=0 2013-03-05T07:39:21.841Z,1362469161.841 [Default:Iridium:Read_Iridium] Stopped 2013-03-05T07:39:21.841Z,1362469161.841 [Default:Iridium](INFO): Completed Default:Iridium 2013-03-05T07:39:21.841Z,1362469161.841 [Default:Iridium] Stopped 2013-03-05T07:39:21.841Z,1362469161.842 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-03-05T07:39:21.842Z,1362469161.842 [Default:Iridium:A.SetSpeed] Stopped 2013-03-05T07:39:21.842Z,1362469161.842 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-03-05T07:39:22.170Z,1362469162.171 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2013-03-05T07:39:22.170Z,1362469162.171 [Default:CallIridium:B] Stopped 2013-03-05T07:39:22.171Z,1362469162.171 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2013-03-05T07:39:22.171Z,1362469162.171 [Default:CallIridium](INFO): Completed Default:CallIridium 2013-03-05T07:39:22.171Z,1362469162.171 [Default:CallIridium] Stopped 2013-03-05T07:39:22.171Z,1362469162.171 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2013-03-05T07:39:32.324Z,1362469172.324 [NAL9602](INFO): Powering down 2013-03-05T07:41:32.522Z,1362469292.522 [CommandLine](IMPORTANT): got command ! chmod 755 /mnt/mmc/LRAUV/Tools/*.* 2013-03-05T07:41:46.306Z,1362469306.306 [CommandLine](IMPORTANT): got command ! ls -l -h /mnt/mmc/LRAUV/Tools/ 2013-03-05T07:41:46.513Z,1362469306.513 [CommandLine](IMPORTANT): total 36K -rwxr-xr-x 1 root root 592 Mar 1 19:17 disable-tools-on-vehicle.sh -rwxr-xr-x 1 root root 443 Sep 25 21:41 disableEmergency.sh -rwxr-xr-x 1 root root 203 Sep 25 21:41 disableWDT.sh -rwxr-xr-x 1 root root 756 Aug 23 2012 gfScan.sh -rwxr-xr-x 1 root root 225 Sep 25 21:41 keepAlive.sh -rwxr-xr-x 1 root root 631 Sep 25 21:41 loadControlOff.sh -rwxr-xr-x 1 root root 1.3K Sep 25 21:41 loadControlOn.sh -rwxr-xr-x 1 root root 246 Feb 27 19:02 thresh4A.sh -rwxr-xr-x 1 root root 123 Sep 25 21:41 toggleHeartbeat.sh