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.