2013-02-13T22:39:22.202Z,1360795162.202 [Supervisor](DEBUG): Initializing supervisor. 2013-02-13T22:39:22.204Z,1360795162.204 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2013-02-13T22:39:22.205Z,1360795162.205 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2013-02-13T22:39:22.206Z,1360795162.206 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2013-02-13T22:39:22.210Z,1360795162.210 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2013-02-13T22:39:22.221Z,1360795162.220 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2013-02-13T22:39:22.222Z,1360795162.222 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2013-02-13T22:39:22.222Z,1360795162.223 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2013-02-13T22:39:22.223Z,1360795162.223 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0 2013-02-13T22:39:22.224Z,1360795162.224 [Supervisor](INFO): Looking for Config files in directory: Config/ 2013-02-13T22:39:22.225Z,1360795162.225 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2013-02-13T22:39:22.507Z,1360795162.507 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2013-02-13T22:39:22.507Z,1360795162.507 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2013-02-13T22:39:22.696Z,1360795162.696 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2013-02-13T22:39:22.696Z,1360795162.696 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2013-02-13T22:39:22.780Z,1360795162.780 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2013-02-13T22:39:22.781Z,1360795162.781 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2013-02-13T22:39:22.978Z,1360795162.977 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2013-02-13T22:39:22.978Z,1360795162.978 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2013-02-13T22:39:23.111Z,1360795163.111 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2013-02-13T22:39:23.112Z,1360795163.112 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2013-02-13T22:39:23.351Z,1360795163.351 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2013-02-13T22:39:23.351Z,1360795163.351 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2013-02-13T22:39:23.522Z,1360795163.522 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2013-02-13T22:39:23.523Z,1360795163.523 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2013-02-13T22:39:23.784Z,1360795163.784 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2013-02-13T22:39:23.784Z,1360795163.784 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2013-02-13T22:39:23.883Z,1360795163.883 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2013-02-13T22:39:23.884Z,1360795163.884 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2013-02-13T22:39:24.287Z,1360795164.287 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2013-02-13T22:39:24.288Z,1360795164.288 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2013-02-13T22:39:24.403Z,1360795164.403 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2013-02-13T22:39:24.404Z,1360795164.404 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2013-02-13T22:39:24.489Z,1360795164.489 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2013-02-13T22:39:24.490Z,1360795164.490 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2013-02-13T22:39:24.592Z,1360795164.592 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2013-02-13T22:39:24.724Z,1360795164.724 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2013-02-13T22:39:24.808Z,1360795164.808 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2013-02-13T22:39:24.909Z,1360795164.909 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2013-02-13T22:39:25.008Z,1360795165.008 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2013-02-13T22:39:25.126Z,1360795165.126 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2013-02-13T22:39:25.218Z,1360795165.218 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2013-02-13T22:39:25.304Z,1360795165.304 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2013-02-13T22:39:25.333Z,1360795165.333 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2013-02-13T22:39:25.492Z,1360795165.492 [InternalSim] Loaded 2013-02-13T22:39:25.492Z,1360795165.492 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2013-02-13T22:39:25.493Z,1360795165.493 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2013-02-13T22:39:25.494Z,1360795165.494 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2013-02-13T22:39:25.553Z,1360795165.553 [SBIT](DEBUG): Construct Startup Built In Test. 2013-02-13T22:39:25.583Z,1360795165.583 [SBIT] Loaded 2013-02-13T22:39:25.583Z,1360795165.583 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2013-02-13T22:39:25.584Z,1360795165.584 [IBIT](DEBUG): Construct Initiated Built In Test. 2013-02-13T22:39:25.614Z,1360795165.614 [IBIT] Loaded 2013-02-13T22:39:25.614Z,1360795165.614 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2013-02-13T22:39:25.618Z,1360795165.618 [CBIT](DEBUG): Construct CBIT Built In Test. 2013-02-13T22:39:25.744Z,1360795165.744 [CBIT] Loaded 2013-02-13T22:39:25.744Z,1360795165.744 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2013-02-13T22:39:25.744Z,1360795165.744 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2013-02-13T22:39:25.745Z,1360795165.745 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2013-02-13T22:39:25.900Z,1360795165.900 [BuoyancyServo] Loaded 2013-02-13T22:39:25.901Z,1360795165.901 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2013-02-13T22:39:25.914Z,1360795165.914 [ElevatorServo] Loaded 2013-02-13T22:39:25.914Z,1360795165.914 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2013-02-13T22:39:25.926Z,1360795165.926 [MassServo] Loaded 2013-02-13T22:39:25.926Z,1360795165.926 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2013-02-13T22:39:25.939Z,1360795165.939 [RudderServo] Loaded 2013-02-13T22:39:25.940Z,1360795165.940 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2013-02-13T22:39:25.952Z,1360795165.952 [ThrusterServo] Loaded 2013-02-13T22:39:25.952Z,1360795165.952 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2013-02-13T22:39:25.953Z,1360795165.953 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2013-02-13T22:39:25.953Z,1360795165.953 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2013-02-13T22:39:25.971Z,1360795165.971 [DepthRateCalculator] Loaded 2013-02-13T22:39:25.971Z,1360795165.971 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2013-02-13T22:39:29.376Z,1360795169.376 [HFRadarModelCalc] Loaded 2013-02-13T22:39:29.376Z,1360795169.376 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread. 2013-02-13T22:39:29.393Z,1360795169.393 [NavChart] Loaded 2013-02-13T22:39:29.394Z,1360795169.394 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2013-02-13T22:39:29.400Z,1360795169.400 [PitchRateCalculator] Loaded 2013-02-13T22:39:29.400Z,1360795169.400 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2013-02-13T22:39:29.407Z,1360795169.407 [SpeedCalculator] Loaded 2013-02-13T22:39:29.407Z,1360795169.407 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2013-02-13T22:39:29.423Z,1360795169.423 [TempGradientCalculator] Loaded 2013-02-13T22:39:29.423Z,1360795169.423 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2013-02-13T22:39:29.429Z,1360795169.429 [YawRateCalculator] Loaded 2013-02-13T22:39:29.429Z,1360795169.429 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2013-02-13T22:39:29.472Z,1360795169.472 [Navigation] Loaded 2013-02-13T22:39:29.473Z,1360795169.473 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread. 2013-02-13T22:39:29.473Z,1360795169.473 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2013-02-13T22:39:29.474Z,1360795169.474 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2013-02-13T22:39:29.705Z,1360795169.705 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2013-02-13T22:39:29.706Z,1360795169.706 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2013-02-13T22:39:29.728Z,1360795169.728 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2013-02-13T22:39:29.729Z,1360795169.729 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2013-02-13T22:39:29.770Z,1360795169.770 [VerticalControl](DEBUG): Construct VerticalControl. 2013-02-13T22:39:29.870Z,1360795169.870 [VerticalControl] Loaded 2013-02-13T22:39:29.871Z,1360795169.871 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2013-02-13T22:39:29.872Z,1360795169.872 [HorizontalControl](DEBUG): Construct HorizontalControl. 2013-02-13T22:39:29.932Z,1360795169.931 [HorizontalControl] Loaded 2013-02-13T22:39:29.932Z,1360795169.932 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2013-02-13T22:39:29.933Z,1360795169.933 [SpeedControl](DEBUG): Construct SpeedControl. 2013-02-13T22:39:29.934Z,1360795169.934 [SpeedControl] Loaded 2013-02-13T22:39:29.935Z,1360795169.935 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2013-02-13T22:39:29.936Z,1360795169.936 [LoopControl](DEBUG): Construct LoopControl. 2013-02-13T22:39:29.936Z,1360795169.936 [LoopControl] Loaded 2013-02-13T22:39:29.937Z,1360795169.937 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2013-02-13T22:39:29.937Z,1360795169.937 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2013-02-13T22:39:29.938Z,1360795169.938 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2013-02-13T22:39:29.943Z,1360795169.943 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2013-02-13T22:39:29.948Z,1360795169.948 [AsyncPiEstimator] Loaded 2013-02-13T22:39:29.948Z,1360795169.948 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2013-02-13T22:39:29.950Z,1360795169.950 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A34E0 2013-02-13T22:39:29.950Z,1360795169.950 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2013-02-13T22:39:29.951Z,1360795169.951 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2013-02-13T22:39:30.083Z,1360795170.083 [AHRS_sp3003D] Loaded 2013-02-13T22:39:30.083Z,1360795170.083 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2013-02-13T22:39:30.357Z,1360795170.357 [Batt_Ocean_Server] Loaded 2013-02-13T22:39:30.357Z,1360795170.357 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2013-02-13T22:39:30.371Z,1360795170.371 [Depth_Keller] Loaded 2013-02-13T22:39:30.371Z,1360795170.372 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2013-02-13T22:39:30.543Z,1360795170.543 [DVL_micro] Loaded 2013-02-13T22:39:30.543Z,1360795170.543 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread. 2013-02-13T22:39:30.544Z,1360795170.545 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 407274E0 2013-02-13T22:39:30.598Z,1360795170.598 [Onboard] Loaded 2013-02-13T22:39:30.598Z,1360795170.598 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2013-02-13T22:39:30.605Z,1360795170.605 [Radio_Freewave] Loaded 2013-02-13T22:39:30.606Z,1360795170.606 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2013-02-13T22:39:30.692Z,1360795170.692 [DAT] Loaded 2013-02-13T22:39:30.692Z,1360795170.692 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2013-02-13T22:39:30.692Z,1360795170.692 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2013-02-13T22:39:30.693Z,1360795170.693 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2013-02-13T22:39:30.751Z,1360795170.751 [PAR_Licor] Loaded 2013-02-13T22:39:30.751Z,1360795170.751 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2013-02-13T22:39:30.752Z,1360795170.752 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2013-02-13T22:39:30.755Z,1360795170.755 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2013-02-13T22:39:30.756Z,1360795170.756 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2013-02-13T22:39:30.762Z,1360795170.762 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2013-02-13T22:39:30.764Z,1360795170.764 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407794E0 2013-02-13T22:39:30.768Z,1360795170.768 [Supervisor](DEBUG): Running supervisor. 2013-02-13T22:39:30.769Z,1360795170.769 [CommandLine](INFO): Thread ID is 6183 2013-02-13T22:39:30.772Z,1360795170.772 [controlThread](INFO): Thread ID is 6182 2013-02-13T22:39:30.772Z,1360795170.772 [controlThread](DEBUG): Initializing ControlThread 2013-02-13T22:39:30.772Z,1360795170.772 [CycleStarter](INFO): Thread ID is 6181 2013-02-13T22:39:30.773Z,1360795170.773 [InternalSim](DEBUG): InternalSim initializing... 2013-02-13T22:39:30.807Z,1360795170.807 [logger](INFO): Thread ID is 6184 2013-02-13T22:39:30.834Z,1360795170.834 [SBIT](INFO): Initialize SBIT Component. 2013-02-13T22:39:30.834Z,1360795170.834 [SBIT](IMPORTANT): Tethys CM Info: $Rev: 10106 2013-02-13T22:39:30.835Z,1360795170.835 [IBIT](INFO): Initialize IBIT Component. 2013-02-13T22:39:30.836Z,1360795170.836 [CBIT](DEBUG): Initialize CBIT Component. 2013-02-13T22:39:30.836Z,1360795170.836 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2013-02-13T22:39:30.836Z,1360795170.836 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2013-02-13T22:39:30.847Z,1360795170.847 [AsyncPiEstimator](INFO): Thread ID is 6245 2013-02-13T22:39:30.847Z,1360795170.847 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2013-02-13T22:39:30.862Z,1360795170.862 [DVL_micro](INFO): Thread ID is 6246 2013-02-13T22:39:30.868Z,1360795170.868 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2013-02-13T22:39:30.868Z,1360795170.868 [NavChart](DEBUG): Initialize NavChart Derivation. 2013-02-13T22:39:30.869Z,1360795170.869 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2013-02-13T22:39:30.869Z,1360795170.869 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2013-02-13T22:39:30.869Z,1360795170.869 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2013-02-13T22:39:30.871Z,1360795170.871 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2013-02-13T22:39:30.872Z,1360795170.872 [Navigation](DEBUG): Initializing Navigation. 2013-02-13T22:39:30.872Z,1360795170.872 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2013-02-13T22:39:30.874Z,1360795170.874 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2013-02-13T22:39:30.875Z,1360795170.875 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2013-02-13T22:39:30.875Z,1360795170.875 [LoopControl](DEBUG): Initialize LoopControlComponent. 2013-02-13T22:39:30.883Z,1360795170.883 [DVL_micro](INFO): Initializing 2013-02-13T22:39:30.883Z,1360795170.883 [DVL_micro](INFO): start:Powering up 2013-02-13T22:39:30.884Z,1360795170.884 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-02-13T22:39:30.884Z,1360795170.884 [DVL_micro](INFO): Cycling power to configure device. 2013-02-13T22:39:30.892Z,1360795170.892 [NavChartDb](INFO): Thread ID is 6247 2013-02-13T22:39:30.893Z,1360795170.894 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2013-02-13T22:39:30.894Z,1360795170.894 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2013-02-13T22:39:30.895Z,1360795170.895 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2013-02-13T22:39:30.895Z,1360795170.895 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2013-02-13T22:39:30.895Z,1360795170.895 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2013-02-13T22:39:32.554Z,1360795172.554 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2013-02-13T22:39:32.595Z,1360795172.595 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2013-02-13T22:39:32.625Z,1360795172.625 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2013-02-13T22:39:32.661Z,1360795172.661 [MissionManager](DEBUG): 2013-02-13T22:39:32.662Z,1360795172.662 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2013-02-13T22:39:32.745Z,1360795172.745 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2013-02-13T22:39:32.747Z,1360795172.747 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2013-02-13T22:39:32.766Z,1360795172.766 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-02-13T22:39:32.774Z,1360795172.774 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2013-02-13T22:39:32.777Z,1360795172.777 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-02-13T22:39:32.800Z,1360795172.800 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2013-02-13T22:39:32.837Z,1360795172.837 [Default:D.SetSpeed](DEBUG): Construct. 2013-02-13T22:39:32.840Z,1360795172.840 [Default:E.GoToSurface](DEBUG): Construct GoToSurface. 2013-02-13T22:39:32.861Z,1360795172.861 [Default:F.Wait](DEBUG): Construct Wait. 2013-02-13T22:39:32.864Z,1360795172.865 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2013-02-13T22:39:32.871Z,1360795172.871 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,Onboard,Radio_Freewave,DAT,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-02-13T22:39:32.929Z,1360795172.930 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2013-02-13T22:39:32.959Z,1360795172.959 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-02-13T22:39:32.959Z,1360795172.959 [DVL_micro](INFO): Querying output modes 2013-02-13T22:39:32.960Z,1360795172.960 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-02-13T22:39:32.971Z,1360795172.971 [DVL_micro](DEBUG): cmdResponse: 01 2013-02-13T22:39:32.971Z,1360795172.971 [DVL_micro](INFO): NQ1 output enabled 2013-02-13T22:39:32.971Z,1360795172.971 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-02-13T22:39:32.983Z,1360795172.983 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-02-13T22:39:32.988Z,1360795172.988 [DVL_micro](INFO): pause:Powering down 2013-02-13T22:39:33.103Z,1360795173.103 [Radio_Freewave](INFO): Powering up 2013-02-13T22:39:33.108Z,1360795173.108 [DAT](INFO): Powering up 2013-02-13T22:39:33.108Z,1360795173.108 [DAT](DEBUG): Initializing DAT. 2013-02-13T22:39:33.431Z,1360795173.431 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2013-02-13T22:39:33.439Z,1360795173.439 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2013-02-13T22:39:33.459Z,1360795173.459 [ElevatorServo](DEBUG): Initializing EZServoServo. 2013-02-13T22:39:33.463Z,1360795173.463 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2013-02-13T22:39:33.469Z,1360795173.469 [MassServo](DEBUG): Initializing EZServoServo. 2013-02-13T22:39:33.475Z,1360795173.475 [MassServo](DEBUG): Initializing MassServo. 2013-02-13T22:39:33.481Z,1360795173.480 [RudderServo](DEBUG): Initializing EZServoServo. 2013-02-13T22:39:33.487Z,1360795173.487 [RudderServo](DEBUG): Initializing RudderServo. 2013-02-13T22:39:33.493Z,1360795173.493 [ThrusterServo](DEBUG): Initializing EZServoServo. 2013-02-13T22:39:33.499Z,1360795173.499 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2013-02-13T22:39:33.979Z,1360795173.978 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout 2013-02-13T22:39:33.979Z,1360795173.979 [AHRS_sp3003D](ERROR): SP3003D failed to initialize 2013-02-13T22:39:33.979Z,1360795173.979 [AHRS_sp3003D] Hardware Fault, FailCount= 1 2013-02-13T22:39:33.979Z,1360795173.979 [AHRS_sp3003D](ERROR): Hardware Fault 2013-02-13T22:39:34.205Z,1360795174.204 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-02-13T22:39:34.206Z,1360795174.206 [DVL_micro](INFO): resume:Powering up 2013-02-13T22:39:34.207Z,1360795174.207 [DVL_micro](INFO): Cycling power to configure device. 2013-02-13T22:39:34.473Z,1360795174.473 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D 2013-02-13T22:39:34.499Z,1360795174.499 [AHRS_sp3003D](INFO): Powering down 2013-02-13T22:39:35.937Z,1360795175.937 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D 2013-02-13T22:39:35.937Z,1360795175.937 [AHRS_sp3003D] No Fault, FailCount= 1 2013-02-13T22:39:36.085Z,1360795176.085 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2013-02-13T22:39:36.223Z,1360795176.223 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-02-13T22:39:36.223Z,1360795176.223 [DVL_micro](INFO): Querying output modes 2013-02-13T22:39:36.223Z,1360795176.223 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-02-13T22:39:36.235Z,1360795176.235 [DVL_micro](DEBUG): cmdResponse: 01 2013-02-13T22:39:36.235Z,1360795176.235 [DVL_micro](INFO): NQ1 output enabled 2013-02-13T22:39:36.235Z,1360795176.235 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-02-13T22:39:36.247Z,1360795176.247 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-02-13T22:39:36.249Z,1360795176.249 [DVL_micro](INFO): pause:Powering down 2013-02-13T22:39:37.235Z,1360795177.234 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout 2013-02-13T22:39:37.235Z,1360795177.235 [AHRS_sp3003D](ERROR): SP3003D failed to initialize 2013-02-13T22:39:37.235Z,1360795177.235 [AHRS_sp3003D] Hardware Fault, FailCount= 2 2013-02-13T22:39:37.235Z,1360795177.235 [AHRS_sp3003D](ERROR): Hardware Fault 2013-02-13T22:39:37.467Z,1360795177.467 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-02-13T22:39:37.468Z,1360795177.467 [DVL_micro](INFO): resume:Powering up 2013-02-13T22:39:37.468Z,1360795177.468 [DVL_micro](INFO): Cycling power to configure device. 2013-02-13T22:39:37.785Z,1360795177.785 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D 2013-02-13T22:39:37.820Z,1360795177.820 [AHRS_sp3003D](INFO): Powering down 2013-02-13T22:39:39.326Z,1360795179.326 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D 2013-02-13T22:39:39.326Z,1360795179.326 [AHRS_sp3003D] No Fault, FailCount= 2 2013-02-13T22:39:39.475Z,1360795179.475 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-02-13T22:39:39.475Z,1360795179.475 [DVL_micro](INFO): Querying output modes 2013-02-13T22:39:39.475Z,1360795179.475 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-02-13T22:39:39.487Z,1360795179.487 [DVL_micro](DEBUG): cmdResponse: 01 2013-02-13T22:39:39.487Z,1360795179.487 [DVL_micro](INFO): NQ1 output enabled 2013-02-13T22:39:39.487Z,1360795179.487 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-02-13T22:39:39.499Z,1360795179.499 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-02-13T22:39:39.501Z,1360795179.501 [DVL_micro](INFO): pause:Powering down 2013-02-13T22:39:39.609Z,1360795179.609 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2013-02-13T22:39:40.758Z,1360795180.758 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout 2013-02-13T22:39:40.759Z,1360795180.759 [AHRS_sp3003D](ERROR): SP3003D failed to initialize 2013-02-13T22:39:40.759Z,1360795180.759 [AHRS_sp3003D] Hardware Fault, FailCount= 3 2013-02-13T22:39:40.759Z,1360795180.759 [AHRS_sp3003D](ERROR): Hardware Fault 2013-02-13T22:39:40.854Z,1360795180.854 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D 2013-02-13T22:39:40.869Z,1360795180.869 [AHRS_sp3003D](INFO): Powering down 2013-02-13T22:39:41.119Z,1360795181.119 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-02-13T22:39:41.120Z,1360795181.120 [DVL_micro](INFO): resume:Powering up 2013-02-13T22:39:41.120Z,1360795181.120 [DVL_micro](INFO): Cycling power to configure device. 2013-02-13T22:39:42.250Z,1360795182.250 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D 2013-02-13T22:39:42.250Z,1360795182.250 [AHRS_sp3003D] No Fault, FailCount= 3 2013-02-13T22:39:42.403Z,1360795182.403 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 200.000000 cubic_centimeter 2013-02-13T22:39:42.405Z,1360795182.405 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.buoyancyAction" handled in the control thread. 2013-02-13T22:39:42.469Z,1360795182.469 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2013-02-13T22:39:42.630Z,1360795182.630 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,Onboard,Radio_Freewave,DAT,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter, 2013-02-13T22:39:43.127Z,1360795183.127 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-02-13T22:39:43.127Z,1360795183.127 [DVL_micro](INFO): Querying output modes 2013-02-13T22:39:43.127Z,1360795183.127 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-02-13T22:39:43.139Z,1360795183.139 [DVL_micro](DEBUG): cmdResponse: 01 2013-02-13T22:39:43.139Z,1360795183.139 [DVL_micro](INFO): NQ1 output enabled 2013-02-13T22:39:43.139Z,1360795183.139 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-02-13T22:39:43.151Z,1360795183.151 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-02-13T22:39:43.153Z,1360795183.153 [DVL_micro](INFO): pause:Powering down 2013-02-13T22:39:43.614Z,1360795183.614 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout 2013-02-13T22:39:43.615Z,1360795183.615 [AHRS_sp3003D](ERROR): SP3003D failed to initialize 2013-02-13T22:39:43.615Z,1360795183.615 [AHRS_sp3003D] Hardware Fault, FailCount= 4 2013-02-13T22:39:43.615Z,1360795183.615 [AHRS_sp3003D](ERROR): Hardware Fault 2013-02-13T22:39:43.734Z,1360795183.734 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D 2013-02-13T22:39:43.745Z,1360795183.745 [AHRS_sp3003D](INFO): Powering down 2013-02-13T22:39:43.963Z,1360795183.963 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-02-13T22:39:43.964Z,1360795183.964 [DVL_micro](INFO): resume:Powering up 2013-02-13T22:39:43.964Z,1360795183.964 [DVL_micro](INFO): Cycling power to configure device. 2013-02-13T22:39:45.062Z,1360795185.062 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D 2013-02-13T22:39:45.062Z,1360795185.062 [AHRS_sp3003D] No Fault, FailCount= 4 2013-02-13T22:39:45.349Z,1360795185.349 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2013-02-13T22:39:45.971Z,1360795185.971 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-02-13T22:39:45.971Z,1360795185.971 [DVL_micro](INFO): Querying output modes 2013-02-13T22:39:45.971Z,1360795185.971 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-02-13T22:39:45.983Z,1360795185.983 [DVL_micro](DEBUG): cmdResponse: 01 2013-02-13T22:39:45.983Z,1360795185.983 [DVL_micro](INFO): NQ1 output enabled 2013-02-13T22:39:45.983Z,1360795185.983 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-02-13T22:39:45.995Z,1360795185.995 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-02-13T22:39:45.997Z,1360795185.997 [DVL_micro](INFO): pause:Powering down 2013-02-13T22:39:46.478Z,1360795186.478 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout 2013-02-13T22:39:46.479Z,1360795186.479 [AHRS_sp3003D](ERROR): SP3003D failed to initialize 2013-02-13T22:39:46.479Z,1360795186.479 [AHRS_sp3003D] Hardware Fault, FailCount= 5 2013-02-13T22:39:46.479Z,1360795186.479 [AHRS_sp3003D](ERROR): Hardware Fault 2013-02-13T22:39:46.633Z,1360795186.633 [SBIT](IMPORTANT): Beginning Startup BIT 2013-02-13T22:39:46.635Z,1360795186.635 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D 2013-02-13T22:39:46.636Z,1360795186.636 [CBIT](CRITICAL): Hardware Fault in component: AHRS_sp3003D 2013-02-13T22:39:46.636Z,1360795186.636 [CBIT](IMPORTANT): Beginning GF scan 2013-02-13T22:39:46.688Z,1360795186.688 [AHRS_sp3003D](INFO): Powering down 2013-02-13T22:39:46.807Z,1360795186.807 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-02-13T22:39:46.808Z,1360795186.808 [DVL_micro](INFO): resume:Powering up 2013-02-13T22:39:46.808Z,1360795186.808 [DVL_micro](INFO): Cycling power to configure device. 2013-02-13T22:39:47.955Z,1360795187.955 [CommandLine](IMPORTANT): got command report mod platform_buoyancy_position 2013-02-13T22:39:48.343Z,1360795188.343 [Reporter](INFO): platform_buoyancy_position 934.986572 cc 2013-02-13T22:39:48.580Z,1360795188.579 [Reporter](INFO): platform_buoyancy_position 934.852287 cc 2013-02-13T22:39:48.815Z,1360795188.815 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-02-13T22:39:48.815Z,1360795188.815 [DVL_micro](INFO): Querying output modes 2013-02-13T22:39:48.815Z,1360795188.815 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-02-13T22:39:48.827Z,1360795188.827 [DVL_micro](DEBUG): cmdResponse: 01 2013-02-13T22:39:48.827Z,1360795188.827 [DVL_micro](INFO): NQ1 output enabled 2013-02-13T22:39:48.827Z,1360795188.827 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-02-13T22:39:48.839Z,1360795188.839 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-02-13T22:39:48.900Z,1360795188.900 [Reporter](INFO): platform_buoyancy_position 932.972063 cc 2013-02-13T22:39:49.071Z,1360795189.071 [DVL_micro](DEBUG): NQ1 2013-02-13T22:39:49.328Z,1360795189.328 [Reporter](INFO): platform_buoyancy_position 930.823269 cc 2013-02-13T22:39:49.776Z,1360795189.776 [Reporter](INFO): platform_buoyancy_position 930.688984 cc 2013-02-13T22:39:50.055Z,1360795190.055 [DVL_micro](DEBUG): NQ1 2013-02-13T22:39:50.128Z,1360795190.128 [Reporter](INFO): platform_buoyancy_position 928.540190 cc 2013-02-13T22:39:50.536Z,1360795190.536 [Reporter](INFO): platform_buoyancy_position 928.405905 cc 2013-02-13T22:39:50.900Z,1360795190.900 [Reporter](INFO): platform_buoyancy_position 926.525623 cc 2013-02-13T22:39:51.043Z,1360795191.043 [DVL_micro](DEBUG): NQ1 2013-02-13T22:39:51.360Z,1360795191.360 [Reporter](INFO): platform_buoyancy_position 924.511172 cc 2013-02-13T22:39:51.800Z,1360795191.800 [Reporter](INFO): platform_buoyancy_position 924.242544 cc 2013-02-13T22:39:52.043Z,1360795192.043 [DVL_micro](DEBUG): NQ1 2013-02-13T22:39:52.172Z,1360795192.172 [Reporter](INFO): platform_buoyancy_position 922.228035 cc 2013-02-13T22:39:52.674Z,1360795192.674 [DAT](INFO): Init failed - response: 23:37:56.0379 , LVL= 14736, 17041, 15122, 17091, AGC= 25, IDX= 62-0.02,-0.040, PHS= 1.354, 1.007, 1.882, |v|= 0.972, RAW= 186.8,-62.9, CAL= 179.4,-59.9, ROT= 258.4,-59.9, CMP= 88.8, 24.8, 0.2, 23:37:56.0735 23:37:57.0379 , LVL= 14688, 19121, 12994, 17395, AGC= 25, IDX= 62 0.11, 1.803, PHS= 1.363, 1.003, 1.888, |v|= 0.976, RAW= 186.2,-62.8, CAL= 179.0,-59.8, ROT= 258.0,-59.8, CMP= 89.1 2013-02-13T22:39:52.674Z,1360795192.674 [DAT](FAULT): DAT failed to initialize 2013-02-13T22:39:52.674Z,1360795192.674 [DAT] Communications Fault, FailCount= 1 2013-02-13T22:39:52.674Z,1360795192.674 [DAT](ERROR): Communications Fault 2013-02-13T22:39:52.695Z,1360795192.695 [CommandLine](IMPORTANT): got command report clear 2013-02-13T22:39:52.891Z,1360795192.891 [CBIT](ERROR): Communications Fault in component: DAT 2013-02-13T22:39:52.943Z,1360795192.943 [DAT](INFO): Powering down 2013-02-13T22:39:53.027Z,1360795193.027 [DVL_micro](DEBUG): NQ1 2013-02-13T22:39:53.767Z,1360795193.767 [CBIT](INFO): Clearing failed state for component DAT 2013-02-13T22:39:53.767Z,1360795193.767 [DAT] No Fault, FailCount= 1 2013-02-13T22:39:54.014Z,1360795194.014 [DVL_micro](DEBUG): NQ1 2013-02-13T22:39:54.998Z,1360795194.999 [DVL_micro](DEBUG): NQ1 2013-02-13T22:39:55.987Z,1360795195.987 [DVL_micro](DEBUG): NQ1 2013-02-13T22:39:56.121Z,1360795196.121 [DAT](INFO): Powering up 2013-02-13T22:39:56.122Z,1360795196.122 [DAT](DEBUG): Initializing DAT. 2013-02-13T22:39:56.971Z,1360795196.971 [DVL_micro](DEBUG): NQ1 2013-02-13T22:39:57.966Z,1360795197.967 [DVL_micro](DEBUG): NQ1 2013-02-13T22:39:58.951Z,1360795198.951 [DVL_micro](DEBUG): NQ1 2013-02-13T22:39:59.947Z,1360795199.947 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:00.931Z,1360795200.931 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:01.923Z,1360795201.922 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:02.899Z,1360795202.899 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:03.891Z,1360795203.891 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:04.887Z,1360795204.887 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:05.874Z,1360795205.875 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:06.863Z,1360795206.862 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:07.855Z,1360795207.855 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:08.840Z,1360795208.840 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:09.831Z,1360795209.830 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:10.811Z,1360795210.811 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:11.803Z,1360795211.803 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:12.790Z,1360795212.790 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:13.005Z,1360795213.005 [CBIT](FAULT): Low side GF detected mA: CHAN 5 (24V): 0.391695 CHAN 4 (Batt): 0.391695 CHAN 2 (12V): 0.391695 CHAN 1 (5V): 0.391695 CHAN 0 (3.3V): 0.336791 OPEN: 0.391695 Full Scale Calc: 0.392 2013-02-13T22:40:13.775Z,1360795213.775 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:14.762Z,1360795214.763 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:15.362Z,1360795215.362 [DAT](INFO): Init failed - response: 00:00:06.0014 , LVL= 7120, 6897, 7522, 6019, AGC= 18, IDX= 82-0.00, 2.103, PHS= 0.917, 1.459, 0.626, |v|= 0.744, RAW= 350.1,-55.3, CAL= 18.5,-58.1, ROT= 97.5,-58.1, CMP= 293.0, 1.3, 0.5, 00:00:00.0000 00:00:08.0011 , LVL= 26944, 28289, 29746, 30643, AGC= 36, IDX= 62 0.30, 0.863, PHS= 0.979, 1.515, 0.657, |v|= 0.776, RAW= 351.8,-55.9, CAL= 20.2,-58.6, ROT= 99.2,-58.6, CMP= 11.5 2013-02-13T22:40:15.362Z,1360795215.362 [DAT](FAULT): DAT failed to initialize 2013-02-13T22:40:15.362Z,1360795215.362 [DAT] Communications Fault, FailCount= 2 2013-02-13T22:40:15.362Z,1360795215.362 [DAT](ERROR): Communications Fault 2013-02-13T22:40:15.455Z,1360795215.455 [CBIT](ERROR): Communications Fault in component: DAT 2013-02-13T22:40:15.697Z,1360795215.697 [DAT](INFO): Powering down 2013-02-13T22:40:15.758Z,1360795215.759 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:16.678Z,1360795216.678 [CBIT](INFO): Clearing failed state for component DAT 2013-02-13T22:40:16.679Z,1360795216.679 [DAT] No Fault, FailCount= 2 2013-02-13T22:40:16.743Z,1360795216.743 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:17.731Z,1360795217.731 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:18.715Z,1360795218.715 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:18.902Z,1360795218.902 [DAT](INFO): Powering up 2013-02-13T22:40:18.902Z,1360795218.902 [DAT](DEBUG): Initializing DAT. 2013-02-13T22:40:19.703Z,1360795219.703 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:20.691Z,1360795220.691 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:21.687Z,1360795221.687 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:22.674Z,1360795222.674 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:23.663Z,1360795223.662 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:24.655Z,1360795224.655 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:25.635Z,1360795225.635 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:26.618Z,1360795226.618 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:27.614Z,1360795227.615 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:28.595Z,1360795228.595 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:29.591Z,1360795229.591 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:30.552Z,1360795230.552 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 2.000000 centimeter 2013-02-13T22:40:30.553Z,1360795230.553 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread. 2013-02-13T22:40:30.571Z,1360795230.571 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:30.628Z,1360795230.628 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,Onboard,Radio_Freewave,DAT,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,Maintain_VerticalControl.massPositionAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter, 2013-02-13T22:40:31.567Z,1360795231.566 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:32.531Z,1360795232.531 [CommandLine](IMPORTANT): got command failComponent 2013-02-13T22:40:32.532Z,1360795232.532 [CommandLine](IMPORTANT): Failed components: 2013-02-13T22:40:32.532Z,1360795232.532 [CommandLine](IMPORTANT): AHRS_sp3003D: Hardware Fault 2013-02-13T22:40:32.547Z,1360795232.547 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:33.543Z,1360795233.543 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:34.527Z,1360795234.527 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:35.517Z,1360795235.517 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:36.503Z,1360795236.503 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:37.486Z,1360795237.487 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:38.157Z,1360795238.158 [DAT](INFO): Init failed - response: 00:00:06.1809 , LVL= 20976, 18289, 25458, 19811, AGC= 30, IDX= 82 0.17, 2.741, PHS= 1.195, 1.741, 0.554, |v|= 0.928, RAW= 2.6,-50.1, CAL= 26.3,-55.3, ROT= 105.3,-55.3, CMP= 293.0, 1.3, 0.5, 00:00:00.0000 00:00:08.1808 , LVL= 30336, 28369, 28242, 27635, AGC= 34, IDX= 62-0.21,-0.984, PHS= 1.125, 1.670, 0.547, |v|= 0.884, RAW= 1.0,-50.4, CAL= 25.0,-55.4, ROT= 104.0,-55.4, CMP= 1.2 2013-02-13T22:40:38.158Z,1360795238.158 [DAT](FAULT): DAT failed to initialize 2013-02-13T22:40:38.158Z,1360795238.158 [DAT] Communications Fault, FailCount= 3 2013-02-13T22:40:38.158Z,1360795238.158 [DAT](ERROR): Communications Fault 2013-02-13T22:40:38.239Z,1360795238.239 [CBIT](ERROR): Communications Fault in component: DAT 2013-02-13T22:40:38.239Z,1360795238.239 [CBIT](CRITICAL): Communications Fault in component: DAT 2013-02-13T22:40:38.438Z,1360795238.438 [DAT](INFO): Powering down 2013-02-13T22:40:38.475Z,1360795238.474 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:39.235Z,1360795239.235 [CommandLine](IMPORTANT): got command get platform_buoyancy_position 2013-02-13T22:40:39.236Z,1360795239.236 [CommandLine](IMPORTANT): platform_buoyancy_position 767.514459 cubic_centimeter 2013-02-13T22:40:39.470Z,1360795239.470 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:39.729Z,1360795239.729 [SBIT](FAULT): Mass: EXPECTED:0.000000 ACTUAL:0.001701 2013-02-13T22:40:39.729Z,1360795239.729 [SBIT](FAULT): Control surface position failure. 2013-02-13T22:40:40.127Z,1360795240.127 [SBIT](CRITICAL): SBIT FAILED 2013-02-13T22:40:40.454Z,1360795240.454 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:40.489Z,1360795240.489 [MissionManager](IMPORTANT): Started mission Startup 2013-02-13T22:40:40.489Z,1360795240.489 [Startup] Running Loop=1 2013-02-13T22:40:40.489Z,1360795240.489 [Startup](INFO): Aggregate::initialize Startup 2013-02-13T22:40:40.489Z,1360795240.489 [Startup:A.GoToSurface] Running Loop=1 2013-02-13T22:40:40.489Z,1360795240.489 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-02-13T22:40:41.443Z,1360795241.443 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:42.431Z,1360795242.431 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:43.419Z,1360795243.419 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:44.416Z,1360795244.416 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:44.707Z,1360795244.707 [CommandLine](IMPORTANT): got command get platform_mass_position centimeter 2013-02-13T22:40:44.707Z,1360795244.707 [CommandLine](IMPORTANT): platform_mass_position 0.527032 centimeter 2013-02-13T22:40:45.395Z,1360795245.395 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:46.382Z,1360795246.382 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:47.375Z,1360795247.375 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:47.683Z,1360795247.683 [CommandLine](IMPORTANT): got command get platform_mass_position centimeter 2013-02-13T22:40:47.683Z,1360795247.684 [CommandLine](IMPORTANT): platform_mass_position 0.734584 centimeter 2013-02-13T22:40:48.359Z,1360795248.359 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:49.339Z,1360795249.339 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:50.335Z,1360795250.335 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:51.335Z,1360795251.335 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:52.311Z,1360795252.311 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:53.295Z,1360795253.295 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:54.287Z,1360795254.286 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:55.275Z,1360795255.275 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:56.262Z,1360795256.263 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:57.247Z,1360795257.247 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:58.238Z,1360795258.239 [DVL_micro](DEBUG): NQ1 2013-02-13T22:40:59.223Z,1360795259.223 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:00.214Z,1360795260.214 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:01.199Z,1360795261.198 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:02.199Z,1360795262.199 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:03.185Z,1360795263.185 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:04.171Z,1360795264.171 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:05.154Z,1360795265.155 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:06.139Z,1360795266.138 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:07.094Z,1360795267.095 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:08.084Z,1360795268.084 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:09.106Z,1360795269.106 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:10.094Z,1360795270.095 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:11.083Z,1360795271.083 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:12.067Z,1360795272.067 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:13.031Z,1360795273.031 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:14.043Z,1360795274.043 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:15.008Z,1360795275.008 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:16.002Z,1360795276.003 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:17.015Z,1360795277.015 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:18.002Z,1360795278.003 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:18.970Z,1360795278.970 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:19.983Z,1360795279.983 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:20.935Z,1360795280.935 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:21.963Z,1360795281.963 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:22.943Z,1360795282.943 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:23.942Z,1360795283.943 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:24.936Z,1360795284.936 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:25.912Z,1360795285.912 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:26.871Z,1360795286.871 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:27.851Z,1360795287.851 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:28.839Z,1360795288.839 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:29.874Z,1360795289.875 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:30.860Z,1360795290.860 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:31.846Z,1360795291.846 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:32.827Z,1360795292.827 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:33.779Z,1360795293.779 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:34.783Z,1360795294.783 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:35.811Z,1360795295.811 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:36.786Z,1360795296.786 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:37.783Z,1360795297.783 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:38.762Z,1360795298.763 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:39.724Z,1360795299.724 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:40.706Z,1360795300.707 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:41.735Z,1360795301.735 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:42.726Z,1360795302.727 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:43.727Z,1360795303.727 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:44.695Z,1360795304.694 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:45.653Z,1360795305.653 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:46.642Z,1360795306.642 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:47.666Z,1360795307.667 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:48.650Z,1360795308.651 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:49.643Z,1360795309.643 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:50.628Z,1360795310.628 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:51.582Z,1360795311.582 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:52.607Z,1360795312.606 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:53.595Z,1360795313.595 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:54.586Z,1360795314.586 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:55.578Z,1360795315.579 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:56.523Z,1360795316.523 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:57.543Z,1360795317.543 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:58.539Z,1360795318.539 [DVL_micro](DEBUG): NQ1 2013-02-13T22:41:59.523Z,1360795319.523 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:00.523Z,1360795320.523 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:01.498Z,1360795321.499 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:02.491Z,1360795322.490 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:03.479Z,1360795323.479 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:04.467Z,1360795324.467 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:05.454Z,1360795325.454 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:06.447Z,1360795326.447 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:07.439Z,1360795327.439 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:08.431Z,1360795328.431 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:08.707Z,1360795328.707 [CommandLine](IMPORTANT): got command failComponent 2013-02-13T22:42:08.707Z,1360795328.707 [CommandLine](IMPORTANT): Failed components: 2013-02-13T22:42:08.707Z,1360795328.707 [CommandLine](IMPORTANT): AHRS_sp3003D: Hardware Fault 2013-02-13T22:42:08.707Z,1360795328.707 [CommandLine](IMPORTANT): DAT: Communications Fault 2013-02-13T22:42:09.411Z,1360795329.411 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:10.394Z,1360795330.395 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:11.383Z,1360795331.383 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:12.370Z,1360795332.371 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:13.363Z,1360795333.362 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:14.347Z,1360795334.346 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:15.338Z,1360795335.339 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:16.331Z,1360795336.330 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:17.323Z,1360795337.323 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:18.299Z,1360795338.299 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:19.287Z,1360795339.286 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:20.282Z,1360795340.283 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:21.271Z,1360795341.270 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:22.262Z,1360795342.263 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:23.203Z,1360795343.203 [CommandLine](IMPORTANT): got command show best platform_pitch_angle 2013-02-13T22:42:23.203Z,1360795343.203 [CommandLine](IMPORTANT): platform_pitch_angle best is DVL_micro.platform_pitch_angle 2013-02-13T22:42:23.243Z,1360795343.243 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:24.227Z,1360795344.227 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:25.227Z,1360795345.227 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:26.212Z,1360795346.212 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:27.203Z,1360795347.203 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:27.807Z,1360795347.807 [CommandLine](IMPORTANT): got command get platform_pitch_angle 2013-02-13T22:42:27.808Z,1360795347.807 [CommandLine](IMPORTANT): platform_pitch_angle -1.580000 degree 2013-02-13T22:42:28.185Z,1360795348.185 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:29.170Z,1360795349.171 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:30.162Z,1360795350.162 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:30.303Z,1360795350.303 [CommandLine](IMPORTANT): got command get platform_pitch_angle 2013-02-13T22:42:30.303Z,1360795350.303 [CommandLine](IMPORTANT): platform_pitch_angle -1.670000 degree 2013-02-13T22:42:31.150Z,1360795351.151 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:32.135Z,1360795352.135 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:32.643Z,1360795352.643 [CommandLine](IMPORTANT): got command get platform_pitch_angle 2013-02-13T22:42:32.643Z,1360795352.643 [CommandLine](IMPORTANT): platform_pitch_angle -1.610000 degree 2013-02-13T22:42:33.126Z,1360795353.126 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:34.119Z,1360795354.119 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:35.098Z,1360795355.099 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:35.579Z,1360795355.579 [CommandLine](IMPORTANT): got command get platform_pitch_angle 2013-02-13T22:42:35.580Z,1360795355.579 [CommandLine](IMPORTANT): platform_pitch_angle -1.550000 degree 2013-02-13T22:42:36.099Z,1360795356.099 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:37.075Z,1360795357.075 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:38.062Z,1360795358.062 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:39.062Z,1360795359.062 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:40.043Z,1360795360.043 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:40.139Z,1360795360.139 [CommandLine](IMPORTANT): got command get platform_pitch_angle 2013-02-13T22:42:40.140Z,1360795360.139 [CommandLine](IMPORTANT): platform_pitch_angle -1.550000 degree 2013-02-13T22:42:41.039Z,1360795361.039 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:42.019Z,1360795362.019 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:43.015Z,1360795363.015 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:43.311Z,1360795363.311 [CommandLine](IMPORTANT): got command get platform_pitch_angle 2013-02-13T22:42:43.311Z,1360795363.311 [CommandLine](IMPORTANT): platform_pitch_angle -1.620000 degree 2013-02-13T22:42:43.998Z,1360795363.999 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:44.990Z,1360795364.990 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:45.395Z,1360795365.395 [CommandLine](IMPORTANT): got command get platform_pitch_angle 2013-02-13T22:42:45.395Z,1360795365.395 [CommandLine](IMPORTANT): platform_pitch_angle -1.550000 degree 2013-02-13T22:42:45.979Z,1360795365.978 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:46.963Z,1360795366.963 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:47.947Z,1360795367.947 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:48.935Z,1360795368.935 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:49.927Z,1360795369.927 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:50.919Z,1360795370.919 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:51.899Z,1360795371.899 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:52.895Z,1360795372.895 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:53.883Z,1360795373.883 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:54.874Z,1360795374.875 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:55.863Z,1360795375.862 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:56.846Z,1360795376.846 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:57.835Z,1360795377.835 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:58.827Z,1360795378.827 [DVL_micro](DEBUG): NQ1 2013-02-13T22:42:59.811Z,1360795379.811 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:00.799Z,1360795380.799 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:01.786Z,1360795381.786 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:02.771Z,1360795382.770 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:03.758Z,1360795383.759 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:04.751Z,1360795384.750 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:05.738Z,1360795385.739 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:06.726Z,1360795386.727 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:07.723Z,1360795387.723 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:08.699Z,1360795388.699 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:09.695Z,1360795389.695 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:10.679Z,1360795390.679 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:11.667Z,1360795391.667 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:12.655Z,1360795392.655 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:13.648Z,1360795393.648 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:14.627Z,1360795394.626 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:15.619Z,1360795395.619 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:16.607Z,1360795396.606 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:17.607Z,1360795397.607 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:18.595Z,1360795398.595 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:19.578Z,1360795399.579 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:20.558Z,1360795400.559 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:21.554Z,1360795401.555 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:22.535Z,1360795402.535 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:23.530Z,1360795403.530 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:24.523Z,1360795404.523 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:25.502Z,1360795405.503 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:26.486Z,1360795406.487 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:27.486Z,1360795407.487 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:28.467Z,1360795408.467 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:29.454Z,1360795409.454 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:30.447Z,1360795410.447 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:31.438Z,1360795411.438 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:32.423Z,1360795412.423 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:33.411Z,1360795413.411 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:34.403Z,1360795414.402 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:35.387Z,1360795415.386 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:36.379Z,1360795416.378 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:37.370Z,1360795417.371 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:38.354Z,1360795418.355 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:39.338Z,1360795419.339 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:40.331Z,1360795420.330 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:41.323Z,1360795421.323 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:42.306Z,1360795422.306 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:43.294Z,1360795423.295 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:44.282Z,1360795424.283 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:45.266Z,1360795425.266 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:46.259Z,1360795426.259 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:47.247Z,1360795427.247 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:48.235Z,1360795428.234 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:49.231Z,1360795429.231 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:50.212Z,1360795430.212 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:51.199Z,1360795431.198 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:52.186Z,1360795432.187 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:53.170Z,1360795433.171 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:54.162Z,1360795434.162 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:55.147Z,1360795435.147 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:56.139Z,1360795436.138 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:57.127Z,1360795437.127 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:57.755Z,1360795437.755 [CommandLine](IMPORTANT): got command get platform_pitch_angle 2013-02-13T22:43:57.755Z,1360795437.755 [CommandLine](IMPORTANT): platform_pitch_angle -1.410000 degree 2013-02-13T22:43:58.123Z,1360795438.123 [DVL_micro](DEBUG): NQ1 2013-02-13T22:43:59.111Z,1360795439.111 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:00.091Z,1360795440.091 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:01.083Z,1360795441.083 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:02.071Z,1360795442.071 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:03.059Z,1360795443.059 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:04.051Z,1360795444.051 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:05.031Z,1360795445.031 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:06.023Z,1360795446.023 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:07.014Z,1360795447.014 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:08.002Z,1360795448.003 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:08.990Z,1360795448.990 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:09.970Z,1360795449.970 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:10.967Z,1360795450.967 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:11.951Z,1360795451.951 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:12.942Z,1360795452.943 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:13.927Z,1360795453.927 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:14.919Z,1360795454.919 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:15.906Z,1360795455.907 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:16.895Z,1360795456.895 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:17.879Z,1360795457.879 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:18.867Z,1360795458.867 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:19.859Z,1360795459.859 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:20.847Z,1360795460.847 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:21.835Z,1360795461.835 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:22.820Z,1360795462.820 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:23.811Z,1360795463.811 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:24.807Z,1360795464.806 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:25.799Z,1360795465.799 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:26.779Z,1360795466.779 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:27.771Z,1360795467.771 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:28.758Z,1360795468.759 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:29.743Z,1360795469.743 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:30.735Z,1360795470.735 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:31.723Z,1360795471.723 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:32.711Z,1360795472.711 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:33.350Z,1360795473.351 [CommandLine](INFO): End of History 2013-02-13T22:44:33.699Z,1360795473.699 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:34.403Z,1360795474.403 [CommandLine](INFO): End of History 2013-02-13T22:44:34.687Z,1360795474.687 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:35.671Z,1360795475.671 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:36.655Z,1360795476.655 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:37.647Z,1360795477.647 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:38.642Z,1360795478.642 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:39.631Z,1360795479.631 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:40.614Z,1360795480.615 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:41.607Z,1360795481.607 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:41.919Z,1360795481.919 [CommandLine](IMPORTANT): got command get platform_pitch_angle 2013-02-13T22:44:41.919Z,1360795481.920 [CommandLine](IMPORTANT): platform_pitch_angle -1.450000 degree 2013-02-13T22:44:42.590Z,1360795482.591 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:43.584Z,1360795483.584 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:44.571Z,1360795484.570 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:45.554Z,1360795485.555 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:46.481Z,1360795486.481 [CBIT](INFO): Clearing failed count for component AHRS_sp3003D 2013-02-13T22:44:46.481Z,1360795486.481 [AHRS_sp3003D] No Fault, FailCount= 5 2013-02-13T22:44:46.543Z,1360795486.543 [DVL_micro](DEBUG): NQ1 2013-02-13T22:44:46.575Z,1360795486.575 [DVL_micro](INFO): pause:Powering down 2013-02-13T22:44:46.821Z,1360795486.821 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2013-02-13T22:44:47.966Z,1360795487.966 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout 2013-02-13T22:44:47.966Z,1360795487.967 [AHRS_sp3003D](ERROR): SP3003D failed to initialize 2013-02-13T22:44:47.967Z,1360795487.967 [AHRS_sp3003D] Hardware Fault, FailCount= 1 2013-02-13T22:44:47.967Z,1360795487.967 [AHRS_sp3003D](ERROR): Hardware Fault 2013-02-13T22:44:48.077Z,1360795488.077 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D 2013-02-13T22:44:48.112Z,1360795488.112 [AHRS_sp3003D](INFO): Powering down 2013-02-13T22:44:48.191Z,1360795488.191 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-02-13T22:44:48.191Z,1360795488.191 [DVL_micro](INFO): resume:Powering up 2013-02-13T22:44:48.192Z,1360795488.192 [DVL_micro](INFO): Cycling power to configure device. 2013-02-13T22:44:49.349Z,1360795489.349 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D 2013-02-13T22:44:49.349Z,1360795489.349 [AHRS_sp3003D] No Fault, FailCount= 1 2013-02-13T22:44:49.694Z,1360795489.694 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2013-02-13T22:44:50.199Z,1360795490.199 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-02-13T22:44:50.199Z,1360795490.199 [DVL_micro](INFO): Querying output modes 2013-02-13T22:44:50.199Z,1360795490.199 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-02-13T22:44:50.211Z,1360795490.211 [DVL_micro](DEBUG): cmdResponse: 01 2013-02-13T22:44:50.211Z,1360795490.211 [DVL_micro](INFO): NQ1 output enabled 2013-02-13T22:44:50.211Z,1360795490.211 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-02-13T22:44:50.223Z,1360795490.223 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-02-13T22:44:50.225Z,1360795490.225 [DVL_micro](INFO): pause:Powering down 2013-02-13T22:44:50.684Z,1360795490.684 [CommandLine](IMPORTANT): got command quit 2013-02-13T22:44:50.834Z,1360795490.834 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout 2013-02-13T22:44:50.835Z,1360795490.835 [AHRS_sp3003D](ERROR): SP3003D failed to initialize 2013-02-13T22:44:50.835Z,1360795490.835 [AHRS_sp3003D] Hardware Fault, FailCount= 2 2013-02-13T22:44:50.835Z,1360795490.835 [AHRS_sp3003D](ERROR): Hardware Fault 2013-02-13T22:44:50.953Z,1360795490.953 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D 2013-02-13T22:44:50.965Z,1360795490.965 [AHRS_sp3003D](INFO): Powering down 2013-02-13T22:44:51.035Z,1360795491.035 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-02-13T22:44:51.036Z,1360795491.036 [DVL_micro](INFO): resume:Powering up 2013-02-13T22:44:51.036Z,1360795491.036 [DVL_micro](INFO): Cycling power to configure device. 2013-02-13T22:44:51.826Z,1360795491.826 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2013-02-13T22:44:51.826Z,1360795491.826 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2013-02-13T22:44:51.899Z,1360795491.898 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler 2013-02-13T22:44:52.237Z,1360795492.237 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D 2013-02-13T22:44:52.237Z,1360795492.237 [AHRS_sp3003D] No Fault, FailCount= 2 2013-02-13T22:44:52.569Z,1360795492.569 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2013-02-13T22:44:53.043Z,1360795493.043 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-02-13T22:44:53.043Z,1360795493.043 [DVL_micro](INFO): Querying output modes 2013-02-13T22:44:53.043Z,1360795493.043 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-02-13T22:44:53.054Z,1360795493.055 [DVL_micro](DEBUG): cmdResponse: 01 2013-02-13T22:44:53.055Z,1360795493.055 [DVL_micro](INFO): NQ1 output enabled 2013-02-13T22:44:53.055Z,1360795493.055 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-02-13T22:44:53.067Z,1360795493.067 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-02-13T22:44:53.067Z,1360795493.067 [DVL_micro](INFO): uninitialize:Powering down 2013-02-13T22:44:53.078Z,1360795493.078 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler 2013-02-13T22:44:53.183Z,1360795493.183 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator. 2013-02-13T22:44:53.185Z,1360795493.185 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2013-02-13T22:44:53.186Z,1360795493.186 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2013-02-13T22:44:53.188Z,1360795493.188 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2013-02-13T22:44:53.359Z,1360795493.359 [controlThread](DEBUG): Uninitializing ControlThread 2013-02-13T22:44:53.359Z,1360795493.359 [AHRS_sp3003D](INFO): Powering down 2013-02-13T22:44:53.448Z,1360795493.448 [DAT](INFO): Powering down 2013-02-13T22:44:53.449Z,1360795493.449 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2013-02-13T22:44:53.450Z,1360795493.450 [NavChart](DEBUG): Uninitialize NavChart Derivation. 2013-02-13T22:44:53.454Z,1360795493.454 [Startup] Stopped 2013-02-13T22:44:53.454Z,1360795493.454 [Startup](INFO): Aggregate::uninitialize Startup 2013-02-13T22:44:53.454Z,1360795493.454 [Startup:A.GoToSurface] Stopped 2013-02-13T22:44:53.454Z,1360795493.454 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-02-13T22:44:53.456Z,1360795493.456 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2013-02-13T22:44:53.456Z,1360795493.456 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2013-02-13T22:44:53.456Z,1360795493.456 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2013-02-13T22:44:53.456Z,1360795493.457 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2013-02-13T22:44:53.457Z,1360795493.457 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2013-02-13T22:44:53.457Z,1360795493.457 [BuoyancyServo](INFO): Powering down 2013-02-13T22:44:53.471Z,1360795493.471 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2013-02-13T22:44:53.471Z,1360795493.471 [ElevatorServo](INFO): Powering down 2013-02-13T22:44:53.472Z,1360795493.471 [MassServo](DEBUG): Uninitialize Mass Servo. 2013-02-13T22:44:53.472Z,1360795493.472 [MassServo](INFO): Powering down 2013-02-13T22:44:53.472Z,1360795493.473 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2013-02-13T22:44:53.473Z,1360795493.473 [RudderServo](INFO): Powering down 2013-02-13T22:44:53.473Z,1360795493.473 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2013-02-13T22:44:53.474Z,1360795493.474 [ThrusterServo](INFO): Powering down 2013-02-13T22:44:53.474Z,1360795493.474 [SBIT](DEBUG): Uninitialize SBIT Component. 2013-02-13T22:44:53.475Z,1360795493.475 [IBIT](DEBUG): Uninitialize IBIT Component. 2013-02-13T22:44:53.475Z,1360795493.475 [CBIT](DEBUG): Uninitialize CBIT Component.