2015-01-27T22:45:30.204Z,1422398730.204 [Supervisor](DEBUG): Initializing supervisor. 2015-01-27T22:45:30.206Z,1422398730.206 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0 2015-01-27T22:45:30.207Z,1422398730.207 [SyncHandler](INFO): Protected caller Thread ID is 2089 2015-01-27T22:45:30.208Z,1422398730.208 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2015-01-27T22:45:30.209Z,1422398730.209 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0 2015-01-27T22:45:30.209Z,1422398730.209 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2090 2015-01-27T22:45:30.212Z,1422398730.212 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2015-01-27T22:45:30.223Z,1422398730.223 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2015-01-27T22:45:30.224Z,1422398730.224 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0 2015-01-27T22:45:30.224Z,1422398730.224 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2091 2015-01-27T22:45:30.225Z,1422398730.225 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2015-01-27T22:45:30.226Z,1422398730.226 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0 2015-01-27T22:45:30.226Z,1422398730.226 [logger ThreadHandler](INFO): Protected caller Thread ID is 2092 2015-01-27T22:45:30.229Z,1422398730.229 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2015-01-27T22:45:30.229Z,1422398730.229 [Supervisor](INFO): Looking for Config files in directory: Config/ 2015-01-27T22:45:30.241Z,1422398730.241 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2015-01-27T22:45:30.557Z,1422398730.557 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2015-01-27T22:45:30.557Z,1422398730.557 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2015-01-27T22:45:30.710Z,1422398730.710 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2015-01-27T22:45:30.711Z,1422398730.711 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2015-01-27T22:45:30.816Z,1422398730.816 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2015-01-27T22:45:30.817Z,1422398730.817 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2015-01-27T22:45:30.935Z,1422398730.935 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2015-01-27T22:45:30.936Z,1422398730.936 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2015-01-27T22:45:31.025Z,1422398731.025 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2015-01-27T22:45:31.211Z,1422398731.211 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2015-01-27T22:45:31.212Z,1422398731.212 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2015-01-27T22:45:31.331Z,1422398731.331 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2015-01-27T22:45:31.331Z,1422398731.331 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2015-01-27T22:45:31.633Z,1422398731.633 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2015-01-27T22:45:31.634Z,1422398731.634 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2015-01-27T22:45:32.016Z,1422398732.016 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2015-01-27T22:45:32.017Z,1422398732.017 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2015-01-27T22:45:32.321Z,1422398732.321 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2015-01-27T22:45:32.322Z,1422398732.322 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2015-01-27T22:45:32.910Z,1422398732.910 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2015-01-27T22:45:32.911Z,1422398732.911 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2015-01-27T22:45:33.099Z,1422398733.099 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2015-01-27T22:45:33.100Z,1422398733.100 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2015-01-27T22:45:33.201Z,1422398733.201 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2015-01-27T22:45:33.202Z,1422398733.202 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2015-01-27T22:45:33.609Z,1422398733.609 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2015-01-27T22:45:33.610Z,1422398733.610 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2015-01-27T22:45:33.717Z,1422398733.717 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2015-01-27T22:45:33.719Z,1422398733.719 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2015-01-27T22:45:33.720Z,1422398733.720 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2015-01-27T22:45:33.953Z,1422398733.953 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2015-01-27T22:45:33.954Z,1422398733.954 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2015-01-27T22:45:34.067Z,1422398734.067 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg 2015-01-27T22:45:34.163Z,1422398734.163 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2015-01-27T22:45:34.257Z,1422398734.257 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2015-01-27T22:45:34.369Z,1422398734.369 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2015-01-27T22:45:34.505Z,1422398734.505 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2015-01-27T22:45:34.670Z,1422398734.670 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2015-01-27T22:45:34.768Z,1422398734.768 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2015-01-27T22:45:34.856Z,1422398734.856 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2015-01-27T22:45:34.954Z,1422398734.954 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2015-01-27T22:45:35.049Z,1422398735.049 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2015-01-27T22:45:35.224Z,1422398735.224 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/ 2015-01-27T22:45:35.224Z,1422398735.224 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2015-01-27T22:45:35.237Z,1422398735.237 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2015-01-27T22:45:35.287Z,1422398735.287 [VerticalControl](DEBUG): Construct VerticalControl. 2015-01-27T22:45:35.402Z,1422398735.402 [VerticalControl] Loaded 2015-01-27T22:45:35.402Z,1422398735.402 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2015-01-27T22:45:35.403Z,1422398735.403 [HorizontalControl](DEBUG): Construct HorizontalControl. 2015-01-27T22:45:35.473Z,1422398735.473 [HorizontalControl] Loaded 2015-01-27T22:45:35.473Z,1422398735.473 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2015-01-27T22:45:35.474Z,1422398735.474 [SpeedControl](DEBUG): Construct SpeedControl. 2015-01-27T22:45:35.480Z,1422398735.480 [SpeedControl] Loaded 2015-01-27T22:45:35.480Z,1422398735.480 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2015-01-27T22:45:35.481Z,1422398735.481 [LoopControl](DEBUG): Construct LoopControl. 2015-01-27T22:45:35.481Z,1422398735.481 [LoopControl] Loaded 2015-01-27T22:45:35.481Z,1422398735.481 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2015-01-27T22:45:35.482Z,1422398735.482 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2015-01-27T22:45:35.482Z,1422398735.482 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2015-01-27T22:45:35.576Z,1422398735.576 [SBIT](DEBUG): Construct Startup Built In Test. 2015-01-27T22:45:35.587Z,1422398735.587 [SBIT] Loaded 2015-01-27T22:45:35.588Z,1422398735.588 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2015-01-27T22:45:35.588Z,1422398735.588 [IBIT](DEBUG): Construct Initiated Built In Test. 2015-01-27T22:45:35.616Z,1422398735.616 [IBIT] Loaded 2015-01-27T22:45:35.617Z,1422398735.617 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2015-01-27T22:45:35.619Z,1422398735.619 [CBIT](DEBUG): Construct CBIT Built In Test. 2015-01-27T22:45:35.736Z,1422398735.736 [CBIT] Loaded 2015-01-27T22:45:35.736Z,1422398735.736 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2015-01-27T22:45:35.737Z,1422398735.737 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2015-01-27T22:45:35.737Z,1422398735.737 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2015-01-27T22:45:35.755Z,1422398735.755 [DepthRateCalculator] Loaded 2015-01-27T22:45:35.756Z,1422398735.756 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2015-01-27T22:45:35.761Z,1422398735.761 [PitchRateCalculator] Loaded 2015-01-27T22:45:35.761Z,1422398735.761 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2015-01-27T22:45:35.772Z,1422398735.772 [SpeedCalculator] Loaded 2015-01-27T22:45:35.773Z,1422398735.773 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2015-01-27T22:45:35.789Z,1422398735.789 [TempGradientCalculator] Loaded 2015-01-27T22:45:35.789Z,1422398735.789 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2015-01-27T22:45:35.794Z,1422398735.794 [YawRateCalculator] Loaded 2015-01-27T22:45:35.795Z,1422398735.795 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2015-01-27T22:45:35.795Z,1422398735.795 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2015-01-27T22:45:35.796Z,1422398735.796 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2015-01-27T22:45:35.844Z,1422398735.844 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2015-01-27T22:45:35.845Z,1422398735.845 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2015-01-27T22:45:36.066Z,1422398736.066 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2015-01-27T22:45:36.067Z,1422398736.067 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2015-01-27T22:45:36.109Z,1422398736.109 [NavChart] Loaded 2015-01-27T22:45:36.110Z,1422398736.110 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2015-01-27T22:45:36.116Z,1422398736.116 [UniversalFixResidualReporter] Loaded 2015-01-27T22:45:36.116Z,1422398736.116 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2015-01-27T22:45:36.117Z,1422398736.117 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2015-01-27T22:45:36.117Z,1422398736.117 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2015-01-27T22:45:36.123Z,1422398736.123 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2015-01-27T22:45:36.123Z,1422398736.123 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2015-01-27T22:45:36.207Z,1422398736.207 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2015-01-27T22:45:36.208Z,1422398736.208 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2015-01-27T22:45:36.560Z,1422398736.560 [DataOverHttps] Loaded 2015-01-27T22:45:36.560Z,1422398736.560 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2015-01-27T22:45:36.640Z,1422398736.640 [Depth_Keller] Loaded 2015-01-27T22:45:36.640Z,1422398736.640 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2015-01-27T22:45:36.732Z,1422398736.732 [NAL9602] Loaded 2015-01-27T22:45:36.732Z,1422398736.732 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2015-01-27T22:45:36.773Z,1422398736.773 [Onboard] Loaded 2015-01-27T22:45:36.773Z,1422398736.773 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2015-01-27T22:45:36.780Z,1422398736.780 [Radio_Surface] Loaded 2015-01-27T22:45:36.780Z,1422398736.780 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2015-01-27T22:45:36.781Z,1422398736.781 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4078B4E0 2015-01-27T22:45:36.782Z,1422398736.782 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2175 2015-01-27T22:45:38.593Z,1422398738.593 [BPC1] Loaded 2015-01-27T22:45:38.593Z,1422398738.593 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2015-01-27T22:45:38.593Z,1422398738.593 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2015-01-27T22:45:38.594Z,1422398738.594 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2015-01-27T22:45:38.700Z,1422398738.700 [BuoyancyServo] Loaded 2015-01-27T22:45:38.701Z,1422398738.701 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2015-01-27T22:45:38.712Z,1422398738.712 [ElevatorServo] Loaded 2015-01-27T22:45:38.713Z,1422398738.713 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2015-01-27T22:45:38.724Z,1422398738.724 [RudderServo] Loaded 2015-01-27T22:45:38.724Z,1422398738.724 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2015-01-27T22:45:38.736Z,1422398738.736 [ThrusterServo] Loaded 2015-01-27T22:45:38.736Z,1422398738.736 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2015-01-27T22:45:38.736Z,1422398738.736 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2015-01-27T22:45:38.737Z,1422398738.737 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2015-01-27T22:45:38.835Z,1422398738.835 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2015-01-27T22:45:38.836Z,1422398738.836 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2015-01-27T22:45:38.859Z,1422398738.859 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2015-01-27T22:45:38.861Z,1422398738.861 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2015-01-27T22:45:38.862Z,1422398738.862 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2015-01-27T22:45:38.869Z,1422398738.869 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2015-01-27T22:45:38.870Z,1422398738.870 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4083C4E0 2015-01-27T22:45:38.870Z,1422398738.870 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2176 2015-01-27T22:45:38.875Z,1422398738.875 [Supervisor](INFO): Main Thread ID is 2088 2015-01-27T22:45:38.875Z,1422398738.875 [Supervisor](DEBUG): Running supervisor. 2015-01-27T22:45:38.876Z,1422398738.876 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2177 2015-01-27T22:45:38.880Z,1422398738.880 [controlThread ThreadHandler](INFO): Handler Thread ID is 2178 2015-01-27T22:45:38.880Z,1422398738.880 [controlThread](DEBUG): Initializing ControlThread 2015-01-27T22:45:38.881Z,1422398738.881 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2015-01-27T22:45:38.883Z,1422398738.883 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2015-01-27T22:45:38.883Z,1422398738.883 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2015-01-27T22:45:38.884Z,1422398738.884 [LoopControl](DEBUG): Initialize LoopControlComponent. 2015-01-27T22:45:38.884Z,1422398738.884 [SBIT](INFO): Initialize SBIT Component. 2015-01-27T22:45:38.885Z,1422398738.885 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:11963 2015-01-27T22:45:38.885Z,1422398738.885 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2015-01-27T22:45:38.885Z,1422398738.885 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2015-01-27T22:45:38.886Z,1422398738.886 [IBIT](INFO): Initialize IBIT Component. 2015-01-27T22:45:38.887Z,1422398738.887 [CBIT](DEBUG): Initialize CBIT Component. 2015-01-27T22:45:38.887Z,1422398738.887 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2015-01-27T22:45:38.888Z,1422398738.888 [logger ThreadHandler](INFO): Handler Thread ID is 2179 2015-01-27T22:45:38.909Z,1422398738.909 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2180 2015-01-27T22:45:38.915Z,1422398738.915 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2015-01-27T22:45:38.915Z,1422398738.915 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2015-01-27T22:45:38.915Z,1422398738.915 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2015-01-27T22:45:38.916Z,1422398738.916 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2015-01-27T22:45:38.916Z,1422398738.916 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2015-01-27T22:45:38.917Z,1422398738.917 [NavChart](DEBUG): Initialize NavChart Navigation. 2015-01-27T22:45:38.917Z,1422398738.917 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2015-01-27T22:45:38.923Z,1422398738.923 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2015-01-27T22:45:38.929Z,1422398738.929 [Radio_Surface](INFO): Powering up 2015-01-27T22:45:38.941Z,1422398738.941 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2015-01-27T22:45:38.942Z,1422398738.942 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2181 2015-01-27T22:45:38.945Z,1422398738.945 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2015-01-27T22:45:38.946Z,1422398738.946 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2015-01-27T22:45:38.946Z,1422398738.946 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2015-01-27T22:45:38.946Z,1422398738.946 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2015-01-27T22:45:38.946Z,1422398738.946 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2015-01-27T22:45:38.947Z,1422398738.947 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2015-01-27T22:45:38.947Z,1422398738.947 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2015-01-27T22:45:38.947Z,1422398738.947 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2015-01-27T22:45:38.948Z,1422398738.948 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2015-01-27T22:45:38.979Z,1422398738.979 [MissionManager](DEBUG): 2015-01-27T22:45:38.979Z,1422398738.979 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2015-01-27T22:45:39.071Z,1422398739.071 [MissionManager](INFO): DefineArg Default.TimeMissionWasStarted = 0.000000 h 2015-01-27T22:45:39.075Z,1422398739.075 [MissionManager](INFO): DefineArg Default.ElapsedSinceMissionWasStarted = 0.000000 h 2015-01-27T22:45:39.095Z,1422398739.095 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2015-01-27T22:45:39.118Z,1422398739.118 [Default:CheckIn:A.SetSpeed](DEBUG): Construct. 2015-01-27T22:45:39.156Z,1422398739.156 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2015-01-27T22:45:39.194Z,1422398739.194 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct. 2015-01-27T22:45:39.228Z,1422398739.228 [MissionManager](DEBUG): 0 0 5.0 1.0 400 Burn 300 Dropped drop weight due to communications timeout 5.0 Default mission has been running for 5 2015-01-27T22:45:39.243Z,1422398739.243 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,NAL9602,Onboard,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2015-01-27T22:45:39.380Z,1422398739.380 [NAL9602](INFO): Start 2015-01-27T22:45:39.807Z,1422398739.807 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2015-01-27T22:45:39.814Z,1422398739.814 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2015-01-27T22:45:39.820Z,1422398739.820 [ElevatorServo](DEBUG): Initializing EZServoServo. 2015-01-27T22:45:39.826Z,1422398739.826 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2015-01-27T22:45:39.832Z,1422398739.832 [RudderServo](DEBUG): Initializing EZServoServo. 2015-01-27T22:45:39.838Z,1422398739.838 [RudderServo](DEBUG): Initializing RudderServo. 2015-01-27T22:45:39.844Z,1422398739.844 [ThrusterServo](DEBUG): Initializing EZServoServo. 2015-01-27T22:45:39.850Z,1422398739.850 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2015-01-27T22:45:40.009Z,1422398740.009 [NAL9602](INFO): Start 2015-01-27T22:45:48.563Z,1422398748.563 [NAL9602](INFO): Start 2015-01-27T22:45:48.564Z,1422398748.564 [NAL9602](INFO): Powering up NAL9602 2015-01-27T22:45:49.725Z,1422398749.725 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003506 2015-01-27T22:45:54.589Z,1422398754.589 [SBIT](IMPORTANT): Beginning Startup BIT 2015-01-27T22:45:54.591Z,1422398754.591 [CBIT](IMPORTANT): Beginning GF scan 2015-01-27T22:45:57.851Z,1422398757.851 [CommandLine](IMPORTANT): got command show variable quality 2015-01-27T22:45:57.895Z,1422398757.895 [CommandLine](IMPORTANT): NAL9602.sigQuality (count) 2015-01-27T22:45:59.722Z,1422398759.722 [NAL9602](INFO): ************** CMDMODE ************** 2015-01-27T22:45:59.722Z,1422398759.722 [NAL9602](INFO): NAL9602 initialized 2015-01-27T22:46:02.927Z,1422398762.927 [NAL9602](INFO): Bytes:2 2015-01-27T22:46:02.928Z,1422398762.928 [NAL9602](INFO): MT Sig Qty requested 2015-01-27T22:46:03.324Z,1422398763.324 [NAL9602](INFO): Bytes:12 2015-01-27T22:46:03.324Z,1422398763.324 [NAL9602](INFO): MTQueue SIGNAL QUALITY RESPONSE RECEIVED: +CSQ:0 OK 2015-01-27T22:46:03.725Z,1422398763.725 [NAL9602](INFO): MT Sig Qty requested 2015-01-27T22:46:04.511Z,1422398764.511 [CommandLine](IMPORTANT): got command report mod NAL9602.sigQuality 2015-01-27T22:46:04.680Z,1422398764.680 [Reporter](INFO): NAL9602.sigQuality 0 count 2015-01-27T22:46:07.326Z,1422398767.326 [NAL9602](INFO): Bytes:10 2015-01-27T22:46:07.327Z,1422398767.327 [NAL9602](INFO): MTQueue SIGNAL QUALITY RESPONSE RECEIVED: +CSQ:0 OKOK 2015-01-27T22:46:07.727Z,1422398767.727 [NAL9602](INFO): MT Sig Qty requested 2015-01-27T22:46:07.847Z,1422398767.847 [SBIT](ERROR): Could not read massPosReader_. 2015-01-27T22:46:08.925Z,1422398768.925 [NAL9602](INFO): Bytes:10 2015-01-27T22:46:08.925Z,1422398768.925 [NAL9602](INFO): MTQueue SIGNAL QUALITY RESPONSE RECEIVED: +CSQ:0 OKOK 2015-01-27T22:46:09.325Z,1422398769.325 [NAL9602](INFO): MT Sig Qty requested 2015-01-27T22:46:17.322Z,1422398777.322 [NAL9602](INFO): Bytes:10 2015-01-27T22:46:17.322Z,1422398777.322 [NAL9602](INFO): MTQueue SIGNAL QUALITY RESPONSE RECEIVED: +CSQ:0 OKOK 2015-01-27T22:46:17.726Z,1422398777.726 [NAL9602](INFO): MT Sig Qty requested 2015-01-27T22:46:21.106Z,1422398781.106 [CBIT](IMPORTANT): No ground fault detected 2015-01-27T22:46:21.721Z,1422398781.721 [NAL9602](INFO): Bytes:10 2015-01-27T22:46:21.721Z,1422398781.721 [NAL9602](INFO): MTQueue SIGNAL QUALITY RESPONSE RECEIVED: +CSQ:0 OKOK 2015-01-27T22:46:22.125Z,1422398782.125 [NAL9602](INFO): MT Sig Qty requested 2015-01-27T22:46:26.127Z,1422398786.127 [NAL9602](INFO): Bytes:10 2015-01-27T22:46:26.128Z,1422398786.128 [NAL9602](INFO): MTQueue SIGNAL QUALITY RESPONSE RECEIVED: +CSQ:0 OKOK 2015-01-27T22:46:26.524Z,1422398786.524 [NAL9602](INFO): MT Sig Qty requested 2015-01-27T22:46:26.925Z,1422398786.925 [NAL9602](INFO): Bytes:10 2015-01-27T22:46:26.925Z,1422398786.925 [NAL9602](INFO): MTQueue SIGNAL QUALITY RESPONSE RECEIVED: +CSQ:0 OKOK 2015-01-27T22:46:27.333Z,1422398787.333 [NAL9602](INFO): MT Sig Qty requested 2015-01-27T22:46:31.330Z,1422398791.330 [NAL9602](INFO): Bytes:10 2015-01-27T22:46:31.330Z,1422398791.330 [NAL9602](INFO): MTQueue SIGNAL QUALITY RESPONSE RECEIVED: +CSQ:0 OKOK 2015-01-27T22:46:31.728Z,1422398791.728 [NAL9602](INFO): MT Sig Qty requested 2015-01-27T22:46:34.277Z,1422398794.277 [SBIT](ERROR): Could not read massPosReader_. 2015-01-27T22:46:34.278Z,1422398794.278 [SBIT](FAULT): Control surface position failure. 2015-01-27T22:46:34.531Z,1422398794.531 [NAL9602](INFO): Bytes:10 2015-01-27T22:46:34.531Z,1422398794.531 [NAL9602](INFO): MTQueue SIGNAL QUALITY RESPONSE RECEIVED: +CSQ:0 OKOK 2015-01-27T22:46:34.921Z,1422398794.921 [NAL9602](INFO): MT Sig Qty requested 2015-01-27T22:46:45.676Z,1422398805.676 [NAL9602](INFO): Bytes:10 2015-01-27T22:46:45.676Z,1422398805.676 [NAL9602](INFO): MTQueue SIGNAL QUALITY RESPONSE RECEIVED: +CSQ:0 OKOK 2015-01-27T22:46:45.850Z,1422398805.850 [NAL9602](INFO): MT Sig Qty requested 2015-01-27T22:46:47.419Z,1422398807.419 [NAL9602](INFO): Bytes:10 2015-01-27T22:46:47.420Z,1422398807.420 [NAL9602](INFO): MTQueue SIGNAL QUALITY RESPONSE RECEIVED: +CSQ:0 OKOK 2015-01-27T22:46:47.813Z,1422398807.813 [NAL9602](INFO): MT Sig Qty requested 2015-01-27T22:46:47.862Z,1422398807.862 [SBIT](ERROR): Could not read massPosReader_. 2015-01-27T22:46:47.862Z,1422398807.862 [SBIT](FAULT): Control surface position failure. 2015-01-27T22:46:48.255Z,1422398808.255 [SBIT](CRITICAL): SBIT FAILED 2015-01-27T22:46:48.256Z,1422398808.256 [CommandLine](FAULT): Scheduling is paused 2015-01-27T22:46:48.632Z,1422398808.632 [MissionManager](IMPORTANT): Started mission Startup 2015-01-27T22:46:48.632Z,1422398808.632 [Startup] Running Loop=1 2015-01-27T22:46:48.632Z,1422398808.632 [Startup](INFO): Aggregate::initialize Startup 2015-01-27T22:46:48.632Z,1422398808.632 [Startup:A.GoToSurface] Running Loop=1 2015-01-27T22:46:48.632Z,1422398808.632 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2015-01-27T22:46:48.633Z,1422398808.633 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2015-01-27T22:46:48.633Z,1422398808.633 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2015-01-27T22:46:48.634Z,1422398808.634 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s. 2015-01-27T22:46:48.639Z,1422398808.639 [Startup:StartupSatComms] Running Loop=1 2015-01-27T22:46:48.640Z,1422398808.640 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2015-01-27T22:46:48.640Z,1422398808.640 [Startup:StartupSatComms:A] Running Loop=1 2015-01-27T22:46:49.037Z,1422398809.037 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2015-01-27T22:46:56.211Z,1422398816.211 [NAL9602](INFO): Bytes:10 2015-01-27T22:46:56.211Z,1422398816.211 [NAL9602](INFO): MTQueue SIGNAL QUALITY RESPONSE RECEIVED: +CSQ:2 OKOK 2015-01-27T22:46:56.211Z,1422398816.211 [NAL9602](INFO): questing MT sbdi session. Quality is: 2015-01-27T22:46:56.308Z,1422398816.308 [Reporter](INFO): NAL9602.sigQuality 2 count 2015-01-27T22:46:56.611Z,1422398816.611 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:46:57.016Z,1422398817.016 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:46:57.412Z,1422398817.412 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:46:57.816Z,1422398817.816 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:46:58.213Z,1422398818.213 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:46:58.614Z,1422398818.614 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:46:59.014Z,1422398819.014 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:46:59.415Z,1422398819.415 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:46:59.816Z,1422398819.816 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:47:00.216Z,1422398820.216 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:47:00.613Z,1422398820.613 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:47:01.010Z,1422398821.010 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:47:01.410Z,1422398821.410 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:47:01.811Z,1422398821.811 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:47:02.211Z,1422398822.211 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:47:02.612Z,1422398822.612 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:47:03.009Z,1422398823.009 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:47:03.409Z,1422398823.409 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:47:03.426Z,1422398823.426 [BPC1](FAULT): Failed to receive battery data 2015-01-27T22:47:03.427Z,1422398823.427 [BPC1] Communications Fault, FailCount= 1 2015-01-27T22:47:03.427Z,1422398823.427 [BPC1](ERROR): Communications Fault 2015-01-27T22:47:03.475Z,1422398823.475 [CBIT](ERROR): Communications Fault in component: BPC1 2015-01-27T22:47:03.810Z,1422398823.810 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:47:04.218Z,1422398824.218 [CommandLine](IMPORTANT): got command quit 2015-01-27T22:47:04.224Z,1422398824.224 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:47:04.611Z,1422398824.611 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:47:04.630Z,1422398824.630 [CBIT](INFO): Clearing failed state for component BPC1 2015-01-27T22:47:04.630Z,1422398824.630 [BPC1] No Fault, FailCount= 1 2015-01-27T22:47:05.012Z,1422398825.012 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:47:05.225Z,1422398825.225 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2015-01-27T22:47:05.226Z,1422398825.226 [CommandLine ThreadHandler](INFO): Thread cancelled. 2015-01-27T22:47:05.403Z,1422398825.403 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2015-01-27T22:47:05.403Z,1422398825.403 [CommandLine ThreadHandler](INFO): Thread cancelled. 2015-01-27T22:47:05.404Z,1422398825.404 [CommandLine](INFO): Join timeout helper Thread ID is 2188 2015-01-27T22:47:05.404Z,1422398825.404 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2015-01-27T22:47:05.404Z,1422398825.404 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2015-01-27T22:47:05.405Z,1422398825.405 [NavChartDb](INFO): Join timeout helper Thread ID is 2189 2015-01-27T22:47:05.413Z,1422398825.413 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:47:05.575Z,1422398825.575 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2015-01-27T22:47:05.576Z,1422398825.576 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2015-01-27T22:47:05.583Z,1422398825.583 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2015-01-27T22:47:05.583Z,1422398825.583 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2015-01-27T22:47:05.584Z,1422398825.584 [Radio_Surface](INFO): Join timeout helper Thread ID is 2190 2015-01-27T22:47:05.796Z,1422398825.796 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2015-01-27T22:47:05.796Z,1422398825.796 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2015-01-27T22:47:05.804Z,1422398825.804 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2015-01-27T22:47:05.804Z,1422398825.804 [logger ThreadHandler](INFO): Thread cancelled. 2015-01-27T22:47:05.804Z,1422398825.804 [logger](INFO): Join timeout helper Thread ID is 2191 2015-01-27T22:47:05.813Z,1422398825.813 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY ************** 2015-01-27T22:47:05.844Z,1422398825.844 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2015-01-27T22:47:05.844Z,1422398825.844 [logger ThreadHandler](INFO): Thread cancelled. 2015-01-27T22:47:05.860Z,1422398825.860 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2015-01-27T22:47:05.860Z,1422398825.860 [CommandLine ThreadHandler](INFO): Thread cancelled. 2015-01-27T22:47:05.860Z,1422398825.860 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2015-01-27T22:47:05.860Z,1422398825.860 [controlThread ThreadHandler](INFO): Thread cancelled. 2015-01-27T22:47:05.860Z,1422398825.860 [controlThread](INFO): Join timeout helper Thread ID is 2192 2015-01-27T22:47:06.204Z,1422398826.204 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2015-01-27T22:47:06.205Z,1422398826.205 [controlThread](DEBUG): Uninitializing ControlThread 2015-01-27T22:47:06.205Z,1422398826.205 [NAL9602](INFO): Uninitialize 2015-01-27T22:47:06.205Z,1422398826.205 [NAL9602](INFO): Powering down 2015-01-27T22:47:06.207Z,1422398826.207 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2015-01-27T22:47:06.208Z,1422398826.208 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2015-01-27T22:47:06.211Z,1422398826.211 [Startup] Stopped 2015-01-27T22:47:06.211Z,1422398826.211 [Startup](INFO): Aggregate::uninitialize Startup 2015-01-27T22:47:06.212Z,1422398826.212 [Startup:A.GoToSurface] Stopped 2015-01-27T22:47:06.212Z,1422398826.212 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2015-01-27T22:47:06.212Z,1422398826.212 [Startup:StartupSatComms] Stopped 2015-01-27T22:47:06.212Z,1422398826.212 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2015-01-27T22:47:06.212Z,1422398826.212 [Startup:StartupSatComms:A] Stopped 2015-01-27T22:47:06.213Z,1422398826.213 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2015-01-27T22:47:06.213Z,1422398826.213 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2015-01-27T22:47:06.214Z,1422398826.214 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2015-01-27T22:47:06.214Z,1422398826.214 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2015-01-27T22:47:06.214Z,1422398826.214 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2015-01-27T22:47:06.214Z,1422398826.214 [BuoyancyServo](INFO): Powering down 2015-01-27T22:47:06.228Z,1422398826.228 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2015-01-27T22:47:06.229Z,1422398826.229 [ElevatorServo](INFO): Powering down 2015-01-27T22:47:06.229Z,1422398826.229 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2015-01-27T22:47:06.229Z,1422398826.229 [RudderServo](INFO): Powering down 2015-01-27T22:47:06.230Z,1422398826.230 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2015-01-27T22:47:06.230Z,1422398826.230 [ThrusterServo](INFO): Powering down 2015-01-27T22:47:06.231Z,1422398826.231 [SBIT](DEBUG): Uninitialize SBIT Component. 2015-01-27T22:47:06.231Z,1422398826.231 [IBIT](DEBUG): Uninitialize IBIT Component. 2015-01-27T22:47:06.232Z,1422398826.232 [CBIT](DEBUG): Uninitialize CBIT Component. 2015-01-27T22:47:06.265Z,1422398826.265 [controlThread ThreadHandler](INFO): Thread cancelled. 2015-01-27T22:47:06.372Z,1422398826.372 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2015-01-27T22:47:06.413Z,1422398826.413 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2015-01-27T22:47:06.461Z,1422398826.461 [logger ThreadHandler](INFO): Thread cancelled.