2016-05-20T19:11:45.286Z,1463771505.286 [Supervisor](DEBUG): Initializing supervisor.
2016-05-20T19:11:45.289Z,1463771505.289 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2016-05-20T19:11:45.289Z,1463771505.289 [SyncHandler](INFO): Protected caller Thread ID is 1710
2016-05-20T19:11:45.290Z,1463771505.290 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2016-05-20T19:11:45.291Z,1463771505.291 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2016-05-20T19:11:45.291Z,1463771505.291 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1711
2016-05-20T19:11:45.294Z,1463771505.294 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2016-05-20T19:11:45.306Z,1463771505.306 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2016-05-20T19:11:45.307Z,1463771505.307 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2016-05-20T19:11:45.307Z,1463771505.307 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1712
2016-05-20T19:11:45.308Z,1463771505.308 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2016-05-20T19:11:45.309Z,1463771505.309 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2016-05-20T19:11:45.309Z,1463771505.309 [logger ThreadHandler](INFO): Protected caller Thread ID is 1713
2016-05-20T19:11:45.311Z,1463771505.311 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2016-05-20T19:11:45.312Z,1463771505.312 [Supervisor](INFO): Looking for Config files in directory: Config/
2016-05-20T19:11:45.313Z,1463771505.313 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2016-05-20T19:11:45.660Z,1463771505.660 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2016-05-20T19:11:45.661Z,1463771505.661 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2016-05-20T19:11:45.828Z,1463771505.828 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2016-05-20T19:11:45.829Z,1463771505.829 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2016-05-20T19:11:45.955Z,1463771505.955 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2016-05-20T19:11:45.956Z,1463771505.956 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2016-05-20T19:11:46.087Z,1463771506.087 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2016-05-20T19:11:46.088Z,1463771506.088 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2016-05-20T19:11:46.174Z,1463771506.174 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2016-05-20T19:11:46.364Z,1463771506.364 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2016-05-20T19:11:46.365Z,1463771506.365 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2016-05-20T19:11:46.451Z,1463771506.451 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2016-05-20T19:11:46.452Z,1463771506.452 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2016-05-20T19:11:46.725Z,1463771506.725 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2016-05-20T19:11:46.726Z,1463771506.726 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2016-05-20T19:11:47.066Z,1463771507.066 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2016-05-20T19:11:47.066Z,1463771507.066 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2016-05-20T19:11:47.387Z,1463771507.387 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2016-05-20T19:11:47.388Z,1463771507.388 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2016-05-20T19:11:47.886Z,1463771507.886 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2016-05-20T19:11:47.886Z,1463771507.886 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2016-05-20T19:11:48.088Z,1463771508.088 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2016-05-20T19:11:48.089Z,1463771508.089 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2016-05-20T19:11:48.193Z,1463771508.193 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2016-05-20T19:11:48.193Z,1463771508.193 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2016-05-20T19:11:48.627Z,1463771508.627 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2016-05-20T19:11:48.628Z,1463771508.628 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2016-05-20T19:11:48.739Z,1463771508.739 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2016-05-20T19:11:48.741Z,1463771508.741 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2016-05-20T19:11:48.742Z,1463771508.742 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2016-05-20T19:11:48.981Z,1463771508.981 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2016-05-20T19:11:48.982Z,1463771508.982 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2016-05-20T19:11:49.099Z,1463771509.099 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2016-05-20T19:11:49.197Z,1463771509.197 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2016-05-20T19:11:49.295Z,1463771509.295 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2016-05-20T19:11:49.385Z,1463771509.385 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2016-05-20T19:11:49.531Z,1463771509.531 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2016-05-20T19:11:49.687Z,1463771509.687 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2016-05-20T19:11:49.791Z,1463771509.791 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2016-05-20T19:11:49.875Z,1463771509.875 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2016-05-20T19:11:49.966Z,1463771509.966 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2016-05-20T19:11:50.152Z,1463771510.152 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2016-05-20T19:11:50.153Z,1463771510.153 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2016-05-20T19:11:50.156Z,1463771510.156 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2016-05-20T19:11:50.268Z,1463771510.268 [SBIT](DEBUG): Construct Startup Built In Test.
2016-05-20T19:11:50.299Z,1463771510.299 [SBIT] Loaded
2016-05-20T19:11:50.299Z,1463771510.299 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2016-05-20T19:11:50.300Z,1463771510.300 [IBIT](DEBUG): Construct Initiated Built In Test.
2016-05-20T19:11:50.328Z,1463771510.328 [IBIT] Loaded
2016-05-20T19:11:50.328Z,1463771510.328 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2016-05-20T19:11:50.330Z,1463771510.330 [CBIT](DEBUG): Construct Continuous Built In Test.
2016-05-20T19:11:50.465Z,1463771510.465 [CBIT] Loaded
2016-05-20T19:11:50.465Z,1463771510.465 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2016-05-20T19:11:50.466Z,1463771510.466 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2016-05-20T19:11:50.466Z,1463771510.466 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2016-05-20T19:11:50.511Z,1463771510.511 [VerticalControl](DEBUG): Construct VerticalControl.
2016-05-20T19:11:50.610Z,1463771510.610 [VerticalControl] Loaded
2016-05-20T19:11:50.610Z,1463771510.610 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2016-05-20T19:11:50.611Z,1463771510.611 [HorizontalControl](DEBUG): Construct HorizontalControl.
2016-05-20T19:11:50.671Z,1463771510.671 [HorizontalControl] Loaded
2016-05-20T19:11:50.672Z,1463771510.672 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2016-05-20T19:11:50.672Z,1463771510.672 [SpeedControl](DEBUG): Construct SpeedControl.
2016-05-20T19:11:50.678Z,1463771510.678 [SpeedControl] Loaded
2016-05-20T19:11:50.678Z,1463771510.678 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2016-05-20T19:11:50.679Z,1463771510.679 [LoopControl](DEBUG): Construct LoopControl.
2016-05-20T19:11:50.679Z,1463771510.679 [LoopControl] Loaded
2016-05-20T19:11:50.680Z,1463771510.680 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2016-05-20T19:11:50.680Z,1463771510.680 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2016-05-20T19:11:50.681Z,1463771510.681 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2016-05-20T19:11:50.702Z,1463771510.702 [DepthRateCalculator] Loaded
2016-05-20T19:11:50.702Z,1463771510.702 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2016-05-20T19:11:50.707Z,1463771510.707 [PitchRateCalculator] Loaded
2016-05-20T19:11:50.707Z,1463771510.707 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2016-05-20T19:11:50.718Z,1463771510.718 [SpeedCalculator] Loaded
2016-05-20T19:11:50.718Z,1463771510.718 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2016-05-20T19:11:50.734Z,1463771510.734 [TempGradientCalculator] Loaded
2016-05-20T19:11:50.735Z,1463771510.735 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2016-05-20T19:11:50.751Z,1463771510.751 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2016-05-20T19:11:50.751Z,1463771510.751 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2016-05-20T19:11:50.756Z,1463771510.756 [YawRateCalculator] Loaded
2016-05-20T19:11:50.757Z,1463771510.757 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2016-05-20T19:11:50.757Z,1463771510.757 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2016-05-20T19:11:50.758Z,1463771510.758 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2016-05-20T19:11:50.827Z,1463771510.827 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2016-05-20T19:11:50.827Z,1463771510.827 [StratificationFrontDetector](DEBUG): (re)initializing
2016-05-20T19:11:50.827Z,1463771510.827 [StratificationFrontDetector] Loaded
2016-05-20T19:11:50.828Z,1463771510.828 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2016-05-20T19:11:50.828Z,1463771510.828 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2016-05-20T19:11:50.829Z,1463771510.829 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2016-05-20T19:11:51.038Z,1463771511.038 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2016-05-20T19:11:51.039Z,1463771511.039 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2016-05-20T19:11:51.132Z,1463771511.132 [DeadReckonUsingMultipleVelocitySources] Loaded
2016-05-20T19:11:51.132Z,1463771511.132 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2016-05-20T19:11:51.186Z,1463771511.186 [DeadReckonUsingSpeedCalculator] Loaded
2016-05-20T19:11:51.186Z,1463771511.186 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2016-05-20T19:11:51.202Z,1463771511.202 [NavChart] Loaded
2016-05-20T19:11:51.203Z,1463771511.203 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2016-05-20T19:11:51.207Z,1463771511.207 [UniversalFixResidualReporter] Loaded
2016-05-20T19:11:51.207Z,1463771511.207 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2016-05-20T19:11:51.208Z,1463771511.208 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2016-05-20T19:11:51.208Z,1463771511.208 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2016-05-20T19:11:51.214Z,1463771511.214 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2016-05-20T19:11:51.214Z,1463771511.214 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2016-05-20T19:11:51.390Z,1463771511.390 [Aanderaa_O2] Loaded
2016-05-20T19:11:51.390Z,1463771511.390 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2016-05-20T19:11:51.464Z,1463771511.464 [CTD_NeilBrown] Loaded
2016-05-20T19:11:51.464Z,1463771511.464 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2016-05-20T19:11:51.465Z,1463771511.465 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4059E4E0
2016-05-20T19:11:51.466Z,1463771511.466 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1792
2016-05-20T19:11:51.480Z,1463771511.480 [PAR_Licor] Loaded
2016-05-20T19:11:51.481Z,1463771511.481 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2016-05-20T19:11:51.529Z,1463771511.529 [WetLabsBB2FL] Loaded
2016-05-20T19:11:51.529Z,1463771511.529 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2016-05-20T19:11:51.530Z,1463771511.530 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 405CE4E0
2016-05-20T19:11:51.530Z,1463771511.530 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1793
2016-05-20T19:11:51.531Z,1463771511.531 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2016-05-20T19:11:51.532Z,1463771511.532 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2016-05-20T19:11:51.782Z,1463771511.782 [AcousticModem_Benthos_ATM900] Loaded
2016-05-20T19:11:51.782Z,1463771511.782 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2016-05-20T19:11:51.853Z,1463771511.853 [DataOverHttps] Loaded
2016-05-20T19:11:51.853Z,1463771511.853 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2016-05-20T19:11:51.866Z,1463771511.866 [Depth_Keller] Loaded
2016-05-20T19:11:51.866Z,1463771511.866 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2016-05-20T19:11:51.871Z,1463771511.871 [DropWeight] Loaded
2016-05-20T19:11:51.871Z,1463771511.871 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2016-05-20T19:11:51.961Z,1463771511.961 [NAL9602] Loaded
2016-05-20T19:11:51.961Z,1463771511.961 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2016-05-20T19:11:52.002Z,1463771512.002 [Onboard] Loaded
2016-05-20T19:11:52.002Z,1463771512.002 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2016-05-20T19:11:52.009Z,1463771512.009 [Radio_Surface] Loaded
2016-05-20T19:11:52.009Z,1463771512.009 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2016-05-20T19:11:52.011Z,1463771512.011 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409E84E0
2016-05-20T19:11:52.011Z,1463771512.011 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1794
2016-05-20T19:11:52.057Z,1463771512.057 [PNI_TCM] Loaded
2016-05-20T19:11:52.058Z,1463771512.058 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2016-05-20T19:11:52.115Z,1463771512.115 [Rowe_600LCM] Loaded
2016-05-20T19:11:52.116Z,1463771512.116 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2016-05-20T19:11:52.117Z,1463771512.117 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 40A184E0
2016-05-20T19:11:52.117Z,1463771512.117 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 1795
2016-05-20T19:11:53.897Z,1463771513.897 [BPC1] Loaded
2016-05-20T19:11:53.897Z,1463771513.897 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2016-05-20T19:11:53.898Z,1463771513.898 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2016-05-20T19:11:53.898Z,1463771513.898 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2016-05-20T19:11:54.013Z,1463771514.013 [BuoyancyServo] Loaded
2016-05-20T19:11:54.014Z,1463771514.014 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2016-05-20T19:11:54.026Z,1463771514.026 [ElevatorServo] Loaded
2016-05-20T19:11:54.026Z,1463771514.026 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2016-05-20T19:11:54.037Z,1463771514.037 [MassServo] Loaded
2016-05-20T19:11:54.038Z,1463771514.038 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2016-05-20T19:11:54.049Z,1463771514.049 [RudderServo] Loaded
2016-05-20T19:11:54.050Z,1463771514.050 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2016-05-20T19:11:54.061Z,1463771514.061 [ThrusterServo] Loaded
2016-05-20T19:11:54.061Z,1463771514.061 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2016-05-20T19:11:54.061Z,1463771514.061 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2016-05-20T19:11:54.062Z,1463771514.062 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2016-05-20T19:11:54.157Z,1463771514.157 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2016-05-20T19:11:54.158Z,1463771514.158 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2016-05-20T19:11:54.181Z,1463771514.181 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2016-05-20T19:11:54.185Z,1463771514.185 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2016-05-20T19:11:54.185Z,1463771514.185 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2016-05-20T19:11:54.192Z,1463771514.192 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2016-05-20T19:11:54.193Z,1463771514.193 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AC64E0
2016-05-20T19:11:54.194Z,1463771514.194 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1796
2016-05-20T19:11:54.198Z,1463771514.198 [Supervisor](INFO): Main Thread ID is 1709
2016-05-20T19:11:54.198Z,1463771514.198 [Supervisor](DEBUG): Running supervisor.
2016-05-20T19:11:54.199Z,1463771514.199 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1797
2016-05-20T19:11:54.202Z,1463771514.202 [controlThread ThreadHandler](INFO): Handler Thread ID is 1798
2016-05-20T19:11:54.202Z,1463771514.202 [controlThread](DEBUG): Initializing ControlThread
2016-05-20T19:11:54.203Z,1463771514.203 [SBIT](INFO): Initialize SBIT Component.
2016-05-20T19:11:54.204Z,1463771514.204 [SBIT](IMPORTANT): git: 2015-11-13-11-g036008f
2016-05-20T19:11:54.204Z,1463771514.204 [SBIT](INFO): git hash: 036008fb27dd1443c9c6898c567944386f491f02
2016-05-20T19:11:54.204Z,1463771514.204 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2016-05-20T19:11:54.204Z,1463771514.204 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2016-05-20T19:11:54.205Z,1463771514.205 [SBIT](INFO): Beginning SBIT in 63.000000 seconds.
2016-05-20T19:11:54.206Z,1463771514.206 [IBIT](INFO): Initialize IBIT Component.
2016-05-20T19:11:54.207Z,1463771514.207 [CBIT](DEBUG): Initialize CBIT Component.
2016-05-20T19:11:54.207Z,1463771514.207 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2016-05-20T19:11:54.208Z,1463771514.208 [logger ThreadHandler](INFO): Handler Thread ID is 1799
2016-05-20T19:11:54.228Z,1463771514.228 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1800
2016-05-20T19:11:54.229Z,1463771514.229 [CTD_NeilBrown](INFO): Powering down
2016-05-20T19:11:54.232Z,1463771514.232 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2016-05-20T19:11:54.234Z,1463771514.234 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2016-05-20T19:11:54.235Z,1463771514.235 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2016-05-20T19:11:54.235Z,1463771514.235 [LoopControl](DEBUG): Initialize LoopControlComponent.
2016-05-20T19:11:54.236Z,1463771514.236 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2016-05-20T19:11:54.236Z,1463771514.236 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2016-05-20T19:11:54.236Z,1463771514.236 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2016-05-20T19:11:54.237Z,1463771514.237 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2016-05-20T19:11:54.237Z,1463771514.237 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2016-05-20T19:11:54.238Z,1463771514.238 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2016-05-20T19:11:54.238Z,1463771514.238 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2016-05-20T19:11:54.239Z,1463771514.239 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2016-05-20T19:11:54.243Z,1463771514.243 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2016-05-20T19:11:54.244Z,1463771514.244 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2016-05-20T19:11:54.244Z,1463771514.244 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2016-05-20T19:11:54.245Z,1463771514.245 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2016-05-20T19:11:54.245Z,1463771514.245 [NavChart](DEBUG): Initialize NavChart Navigation.
2016-05-20T19:11:54.246Z,1463771514.246 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2016-05-20T19:11:54.255Z,1463771514.255 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2016-05-20T19:11:54.274Z,1463771514.274 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2016-05-20T19:11:54.284Z,1463771514.284 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1801
2016-05-20T19:11:54.285Z,1463771514.285 [WetLabsBB2FL](INFO): Powering down
2016-05-20T19:11:54.322Z,1463771514.322 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1802
2016-05-20T19:11:54.328Z,1463771514.328 [Radio_Surface](INFO): Powering up
2016-05-20T19:11:54.329Z,1463771514.329 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2016-05-20T19:11:54.330Z,1463771514.330 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2016-05-20T19:11:54.344Z,1463771514.344 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 1803
2016-05-20T19:11:54.345Z,1463771514.345 [Rowe_600LCM](INFO): Initializing
2016-05-20T19:11:54.345Z,1463771514.345 [Rowe_600LCM](INFO): Checking LCM
2016-05-20T19:11:54.345Z,1463771514.345 [Rowe_600LCM](INFO): LCM OK
2016-05-20T19:11:54.346Z,1463771514.346 [Rowe_600LCM](INFO): Powering up
2016-05-20T19:11:54.360Z,1463771514.360 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1804
2016-05-20T19:11:54.363Z,1463771514.363 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources/ElectronicNavigationCharts
2016-05-20T19:11:54.364Z,1463771514.364 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2016-05-20T19:11:54.364Z,1463771514.364 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2016-05-20T19:11:54.364Z,1463771514.364 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2016-05-20T19:11:54.364Z,1463771514.364 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2016-05-20T19:11:54.365Z,1463771514.365 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2016-05-20T19:11:54.365Z,1463771514.365 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2016-05-20T19:11:54.365Z,1463771514.365 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2016-05-20T19:11:54.365Z,1463771514.365 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2016-05-20T19:11:54.419Z,1463771514.419 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2016-05-20T19:11:54.420Z,1463771514.420 [Default:A.Wait](DEBUG): Construct Wait.
2016-05-20T19:11:54.421Z,1463771514.421 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2016-05-20T19:11:54.468Z,1463771514.468 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2016-05-20T19:11:54.470Z,1463771514.470 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2016-05-20T19:11:54.492Z,1463771514.492 [Default:E.Execute](DEBUG): Construct Execute.
2016-05-20T19:11:54.496Z,1463771514.496 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Guidance="Tethys/Guidance"
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Sequence/>
	<Description>Wait a moment to see if the scheduler starts a new mission before starting to actually run Default.
        </Description>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Sequence/>
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Sequence/>
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn 300</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2016-05-20T19:11:54.501Z,1463771514.501 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,PAR_Licor,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2016-05-20T19:11:54.576Z,1463771514.576 [AcousticModem_Benthos_ATM900](INFO): Powering up
2016-05-20T19:11:54.576Z,1463771514.576 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2016-05-20T19:11:55.226Z,1463771515.226 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2016-05-20T19:11:55.249Z,1463771515.249 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-20T19:11:55.361Z,1463771515.361 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2016-05-20T19:11:55.370Z,1463771515.370 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2016-05-20T19:11:55.392Z,1463771515.392 [ElevatorServo](DEBUG): Initializing EZServoServo.
2016-05-20T19:11:55.398Z,1463771515.398 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2016-05-20T19:11:55.412Z,1463771515.412 [MassServo](DEBUG): Initializing EZServoServo.
2016-05-20T19:11:55.418Z,1463771515.418 [MassServo](DEBUG): Initializing MassServo.
2016-05-20T19:11:55.439Z,1463771515.439 [RudderServo](DEBUG): Initializing EZServoServo.
2016-05-20T19:11:55.446Z,1463771515.446 [RudderServo](DEBUG): Initializing RudderServo.
2016-05-20T19:11:55.459Z,1463771515.459 [ThrusterServo](DEBUG): Initializing EZServoServo.
2016-05-20T19:11:55.466Z,1463771515.466 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2016-05-20T19:11:55.510Z,1463771515.510 [CommandLine](FAULT): Scheduling is paused
2016-05-20T19:11:55.794Z,1463771515.794 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2016-05-20T19:11:55.796Z,1463771515.796 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-20T19:11:56.070Z,1463771516.070 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2016-05-20T19:11:56.072Z,1463771516.072 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-20T19:11:56.743Z,1463771516.743 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2016-05-20T19:11:56.745Z,1463771516.745 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-20T19:11:57.067Z,1463771517.067 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2016-05-20T19:11:57.068Z,1463771517.068 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-20T19:11:57.258Z,1463771517.258 [NAL9602](INFO): Powering up NAL9602
2016-05-20T19:11:57.288Z,1463771517.288 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2016-05-20T19:11:57.296Z,1463771517.296 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-20T19:11:57.769Z,1463771517.769 [Aanderaa_O2](INFO): Powering down
2016-05-20T19:11:57.985Z,1463771517.985 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2016-05-20T19:11:57.986Z,1463771517.986 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-20T19:11:58.420Z,1463771518.420 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2016-05-20T19:11:58.421Z,1463771518.421 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-20T19:11:58.624Z,1463771518.624 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2016-05-20T19:11:58.778Z,1463771518.778 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:./bin/roweadcp -dev /dev/ttyA1 -b 38400 >& adcplog.log &
2016-05-20T19:11:58.882Z,1463771518.882 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2016-05-20T19:11:58.893Z,1463771518.893 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2016-05-20T19:12:02.175Z,1463771522.175 [AcousticModem_Benthos_ATM900](DEBUG): 
2016-05-20T19:12:03.368Z,1463771523.368 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2016-05-20T19:12:03.368Z,1463771523.368 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2016-05-20T19:12:03.369Z,1463771523.369 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2016-05-20T19:12:03.768Z,1463771523.768 [AcousticModem_Benthos_ATM900](DEBUG): May 20 2016 19:16:18 
2016-05-20T19:12:04.569Z,1463771524.569 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2016-05-20T19:12:04.969Z,1463771524.969 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2016-05-20T19:12:05.371Z,1463771525.371 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2016-05-20T19:12:05.373Z,1463771525.373 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2016-05-20T19:12:05.373Z,1463771525.373 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2016-05-20T19:12:05.789Z,1463771525.789 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2016-05-20T19:12:06.185Z,1463771526.185 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2016-05-20T19:12:06.195Z,1463771526.195 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2016-05-20T19:12:06.581Z,1463771526.581 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2016-05-20T19:12:07.471Z,1463771527.471 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:08.291Z,1463771528.291 [NAL9602](INFO): NAL9602 initialized
2016-05-20T19:12:09.944Z,1463771529.944 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:13.326Z,1463771533.326 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:15.802Z,1463771535.802 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:18.278Z,1463771538.278 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:19.892Z,1463771539.892 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:21.506Z,1463771541.506 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:23.978Z,1463771543.978 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:25.597Z,1463771545.597 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:27.247Z,1463771547.247 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:32.339Z,1463771552.339 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:33.954Z,1463771553.954 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:35.572Z,1463771555.572 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:39.807Z,1463771559.807 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:41.421Z,1463771561.421 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:43.889Z,1463771563.889 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:45.542Z,1463771565.542 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:48.024Z,1463771568.024 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:49.638Z,1463771569.638 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:51.252Z,1463771571.252 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:53.726Z,1463771573.726 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:55.343Z,1463771575.343 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:57.819Z,1463771577.819 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:12:58.030Z,1463771578.030 [SBIT](IMPORTANT): Beginning Startup BIT
2016-05-20T19:12:58.053Z,1463771578.053 [CBIT](IMPORTANT): Beginning GF scan
2016-05-20T19:13:00.291Z,1463771580.291 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:01.905Z,1463771581.905 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:03.520Z,1463771583.520 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:05.995Z,1463771585.995 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:07.626Z,1463771587.626 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:09.246Z,1463771589.246 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:11.716Z,1463771591.716 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:14.188Z,1463771594.188 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:15.802Z,1463771595.802 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:17.421Z,1463771597.421 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:21.658Z,1463771601.658 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:23.274Z,1463771603.274 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:25.085Z,1463771605.085 [CBIT](IMPORTANT): No ground fault detected
2016-05-20T19:13:25.746Z,1463771605.746 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:28.218Z,1463771608.218 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:29.833Z,1463771609.833 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:33.210Z,1463771613.210 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:35.694Z,1463771615.694 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:37.308Z,1463771617.308 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:39.780Z,1463771619.780 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:42.252Z,1463771622.252 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:43.866Z,1463771623.866 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:45.481Z,1463771625.481 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:47.141Z,1463771627.141 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:49.627Z,1463771629.627 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:51.242Z,1463771631.242 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:52.009Z,1463771632.009 [SBIT](IMPORTANT): SBIT PASSED
2016-05-20T19:13:52.279Z,1463771632.279 [MissionManager](IMPORTANT): Started mission Startup
2016-05-20T19:13:52.279Z,1463771632.279 [Startup] Running Loop=1
2016-05-20T19:13:52.279Z,1463771632.279 [Startup](DEBUG): Aggregate::initialize Startup
2016-05-20T19:13:52.279Z,1463771632.279 [Startup:A.GoToSurface] Running Loop=1
2016-05-20T19:13:52.279Z,1463771632.279 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2016-05-20T19:13:52.280Z,1463771632.280 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2016-05-20T19:13:52.280Z,1463771632.280 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2016-05-20T19:13:52.281Z,1463771632.281 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2016-05-20T19:13:52.281Z,1463771632.281 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2016-05-20T19:13:52.282Z,1463771632.282 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2016-05-20T19:13:52.296Z,1463771632.296 [Startup:StartupSatComms] Running Loop=1
2016-05-20T19:13:52.296Z,1463771632.296 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2016-05-20T19:13:52.296Z,1463771632.296 [Startup:StartupSatComms:A] Running Loop=1
2016-05-20T19:13:52.692Z,1463771632.692 [BPC1](ERROR): Failed to receive battery data
2016-05-20T19:13:52.692Z,1463771632.692 [BPC1] Communications Fault, FailCount= 1
2016-05-20T19:13:52.692Z,1463771632.692 [BPC1](ERROR): Communications Fault
2016-05-20T19:13:52.703Z,1463771632.703 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2016-05-20T19:13:52.714Z,1463771632.714 [CBIT](ERROR): Communications Fault in component: BPC1
2016-05-20T19:13:53.713Z,1463771633.713 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:54.023Z,1463771634.023 [CBIT](INFO): Clearing failed state for component BPC1
2016-05-20T19:13:54.023Z,1463771634.023 [BPC1] No Fault, FailCount= 1
2016-05-20T19:13:56.182Z,1463771636.182 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:57.800Z,1463771637.800 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:13:59.419Z,1463771639.419 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:01.687Z,1463771641.687 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1
2016-05-20T19:14:01.689Z,1463771641.689 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai
2016-05-20T19:14:01.690Z,1463771641.690 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false
2016-05-20T19:14:01.712Z,1463771641.712 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.024738
2016-05-20T19:14:01.926Z,1463771641.926 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:03.540Z,1463771643.540 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:05.194Z,1463771645.194 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:07.684Z,1463771647.684 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:10.159Z,1463771650.159 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:11.773Z,1463771651.773 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:13.392Z,1463771653.392 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:15.865Z,1463771655.865 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:17.491Z,1463771657.491 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:19.962Z,1463771659.962 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:21.576Z,1463771661.576 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:24.045Z,1463771664.045 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:25.668Z,1463771665.668 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:27.293Z,1463771667.293 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:29.765Z,1463771669.765 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:31.380Z,1463771671.380 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:33.856Z,1463771673.856 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:35.470Z,1463771675.470 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:37.943Z,1463771677.943 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:39.583Z,1463771679.583 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:41.211Z,1463771681.211 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:43.688Z,1463771683.688 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:45.301Z,1463771685.301 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:47.776Z,1463771687.776 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:49.391Z,1463771689.391 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:51.865Z,1463771691.865 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:52.328Z,1463771692.328 [Startup:StartupSatComms:A](INFO): Timed out from 2016-05-20T19:13:52.3Z
2016-05-20T19:14:52.329Z,1463771692.329 [Startup:StartupSatComms:A] Stopped
2016-05-20T19:14:52.329Z,1463771692.329 [Startup:StartupSatComms:B] Running Loop=1
2016-05-20T19:14:52.642Z,1463771692.642 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2016-05-20T19:14:54.339Z,1463771694.339 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:55.958Z,1463771695.958 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:57.572Z,1463771697.572 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:58.889Z,1463771698.889 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2016-05-20T19:14:58.889Z,1463771698.889 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2016-05-20T19:14:58.889Z,1463771698.889 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2016-05-20T19:14:58.891Z,1463771698.891 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2016-05-20T19:14:58.891Z,1463771698.891 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2016-05-20T19:14:58.891Z,1463771698.891 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2016-05-20T19:14:58.946Z,1463771698.946 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2016-05-20T19:14:58.946Z,1463771698.946 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2016-05-20T19:14:58.996Z,1463771698.996 [DataOverHttps](INFO): Sending 99 bytes from file Logs/20160520T191145/Courier0000.lzma
2016-05-20T19:14:59.078Z,1463771699.078 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2016-05-20T19:14:59.078Z,1463771699.078 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2016-05-20T19:14:59.078Z,1463771699.078 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2016-05-20T19:14:59.078Z,1463771699.078 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2016-05-20T19:14:59.187Z,1463771699.187 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:14:59.544Z,1463771699.544 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2016-05-20T19:14:59.546Z,1463771699.546 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2016-05-20T19:14:59.546Z,1463771699.546 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2016-05-20T19:14:59.548Z,1463771699.548 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2016-05-20T19:14:59.549Z,1463771699.549 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2016-05-20T19:14:59.550Z,1463771699.550 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2016-05-20T19:14:59.786Z,1463771699.786 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=true&momsn=4115362&filename=Logs%2F20160520T191145%2FCourier0000.lzma, 1
2016-05-20T19:14:59.787Z,1463771699.787 [DataOverHttps](DEBUG): ParseDataRead( data = busy=true&momsn=4115362&filename=Logs%2F20160520T191145%2FCourier0000.lzma, key = 6, value = makai
2016-05-20T19:14:59.788Z,1463771699.788 [DataOverHttps](DEBUG): ParseDataRead( data = momsn=4115362&filename=Logs%2F20160520T191145%2FCourier0000.lzma, key = 0, value = true
2016-05-20T19:14:59.789Z,1463771699.789 [DataOverHttps](DEBUG): ParseDataRead( data = filename=Logs%2F20160520T191145%2FCourier0000.lzma, key = 4, value = 4115362
2016-05-20T19:14:59.791Z,1463771699.791 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 2, value = Logs%2F20160520T191145%2FCourier0000.lzma
2016-05-20T19:14:59.802Z,1463771699.802 [DataOverHttps](INFO): Moved sent file to Logs/20160520T191145/Courier0000.lzma.bak
2016-05-20T19:14:59.802Z,1463771699.802 [DataOverHttps](INFO): SBD MOMSN=4115362
2016-05-20T19:14:59.962Z,1463771699.962 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.1 s old, using for 20.0 s.
2016-05-20T19:15:00.293Z,1463771700.293 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.4 s old, using for 20.0 s.
2016-05-20T19:15:00.654Z,1463771700.654 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.8 s old, using for 20.0 s.
2016-05-20T19:15:01.659Z,1463771701.659 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:03.278Z,1463771703.278 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:05.465Z,1463771705.465 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.6 s old, using for 20.0 s.
2016-05-20T19:15:05.769Z,1463771705.769 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:05.850Z,1463771705.850 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.0 s old, using for 20.0 s.
2016-05-20T19:15:06.272Z,1463771706.272 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.4 s old, using for 20.0 s.
2016-05-20T19:15:06.451Z,1463771706.451 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1
2016-05-20T19:15:06.453Z,1463771706.453 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai
2016-05-20T19:15:06.463Z,1463771706.463 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false
2016-05-20T19:15:06.638Z,1463771706.638 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.7 s old, using for 20.0 s.
2016-05-20T19:15:06.866Z,1463771706.866 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.0 s old, using for 20.0 s.
2016-05-20T19:15:07.289Z,1463771707.289 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.4 s old, using for 20.0 s.
2016-05-20T19:15:08.246Z,1463771708.246 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:09.864Z,1463771709.864 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:11.515Z,1463771711.515 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:13.147Z,1463771713.147 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:14.516Z,1463771714.516 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.6 s old, using for 20.0 s.
2016-05-20T19:15:14.592Z,1463771714.592 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20160520T191145/Courier0004.lzma
2016-05-20T19:15:14.689Z,1463771714.689 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.8 s old, using for 20.0 s.
2016-05-20T19:15:15.043Z,1463771715.043 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.2 s old, using for 20.0 s.
2016-05-20T19:15:15.382Z,1463771715.382 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=true&momsn=4115366&filename=Logs%2F20160520T191145%2FCourier0004.lzma, 1
2016-05-20T19:15:15.400Z,1463771715.400 [DataOverHttps](DEBUG): ParseDataRead( data = busy=true&momsn=4115366&filename=Logs%2F20160520T191145%2FCourier0004.lzma, key = 6, value = makai
2016-05-20T19:15:15.403Z,1463771715.403 [DataOverHttps](DEBUG): ParseDataRead( data = momsn=4115366&filename=Logs%2F20160520T191145%2FCourier0004.lzma, key = 0, value = true
2016-05-20T19:15:15.405Z,1463771715.405 [DataOverHttps](DEBUG): ParseDataRead( data = filename=Logs%2F20160520T191145%2FCourier0004.lzma, key = 4, value = 4115366
2016-05-20T19:15:15.406Z,1463771715.406 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 2, value = Logs%2F20160520T191145%2FCourier0004.lzma
2016-05-20T19:15:15.449Z,1463771715.449 [DataOverHttps](INFO): Moved sent file to Logs/20160520T191145/Courier0004.lzma.bak
2016-05-20T19:15:15.449Z,1463771715.449 [DataOverHttps](INFO): SBD MOMSN=4115366
2016-05-20T19:15:15.625Z,1463771715.625 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:15.886Z,1463771715.886 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.0 s old, using for 20.0 s.
2016-05-20T19:15:16.293Z,1463771716.293 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.4 s old, using for 20.0 s.
2016-05-20T19:15:16.536Z,1463771716.536 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.6 s old, using for 20.0 s.
2016-05-20T19:15:17.239Z,1463771717.239 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:19.715Z,1463771719.715 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:22.187Z,1463771722.187 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:23.806Z,1463771723.806 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:25.419Z,1463771725.419 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:25.494Z,1463771725.494 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1
2016-05-20T19:15:25.495Z,1463771725.495 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai
2016-05-20T19:15:25.496Z,1463771725.496 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false
2016-05-20T19:15:27.888Z,1463771727.888 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:29.502Z,1463771729.502 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:31.180Z,1463771731.180 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20160520T191217/Courier0004.lzma
2016-05-20T19:15:31.952Z,1463771731.952 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=true&momsn=4115368&filename=Logs%2F20160520T191217%2FCourier0004.lzma, 1
2016-05-20T19:15:31.954Z,1463771731.954 [DataOverHttps](DEBUG): ParseDataRead( data = busy=true&momsn=4115368&filename=Logs%2F20160520T191217%2FCourier0004.lzma, key = 6, value = makai
2016-05-20T19:15:31.955Z,1463771731.955 [DataOverHttps](DEBUG): ParseDataRead( data = momsn=4115368&filename=Logs%2F20160520T191217%2FCourier0004.lzma, key = 0, value = true
2016-05-20T19:15:31.956Z,1463771731.956 [DataOverHttps](DEBUG): ParseDataRead( data = filename=Logs%2F20160520T191217%2FCourier0004.lzma, key = 4, value = 4115368
2016-05-20T19:15:31.959Z,1463771731.959 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 2, value = Logs%2F20160520T191217%2FCourier0004.lzma
2016-05-20T19:15:31.960Z,1463771731.960 [DataOverHttps](INFO): Moved sent file to Logs/20160520T191217/Courier0004.lzma.bak
2016-05-20T19:15:31.961Z,1463771731.961 [DataOverHttps](INFO): SBD MOMSN=4115368
2016-05-20T19:15:31.974Z,1463771731.974 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:33.592Z,1463771733.592 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:36.073Z,1463771736.073 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:37.691Z,1463771737.691 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:39.223Z,1463771739.223 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1
2016-05-20T19:15:39.224Z,1463771739.224 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai
2016-05-20T19:15:39.227Z,1463771739.227 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false
2016-05-20T19:15:39.305Z,1463771739.305 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:41.776Z,1463771741.776 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:43.395Z,1463771743.395 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:44.999Z,1463771744.999 [DataOverHttps](INFO): Sending 785 bytes from file Logs/20160520T191145/Express0001.lzma
2016-05-20T19:15:45.769Z,1463771745.769 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=true&momsn=4115370&filename=Logs%2F20160520T191145%2FExpress0001.lzma, 1
2016-05-20T19:15:45.770Z,1463771745.770 [DataOverHttps](DEBUG): ParseDataRead( data = busy=true&momsn=4115370&filename=Logs%2F20160520T191145%2FExpress0001.lzma, key = 6, value = makai
2016-05-20T19:15:45.781Z,1463771745.781 [DataOverHttps](DEBUG): ParseDataRead( data = momsn=4115370&filename=Logs%2F20160520T191145%2FExpress0001.lzma, key = 0, value = true
2016-05-20T19:15:45.791Z,1463771745.791 [DataOverHttps](DEBUG): ParseDataRead( data = filename=Logs%2F20160520T191145%2FExpress0001.lzma, key = 4, value = 4115370
2016-05-20T19:15:45.793Z,1463771745.793 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 2, value = Logs%2F20160520T191145%2FExpress0001.lzma
2016-05-20T19:15:45.803Z,1463771745.803 [DataOverHttps](INFO): Moved sent file to Logs/20160520T191145/Express0001.lzma.bak
2016-05-20T19:15:45.804Z,1463771745.804 [DataOverHttps](INFO): SBD MOMSN=4115370
2016-05-20T19:15:45.872Z,1463771745.872 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:48.344Z,1463771748.344 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:49.964Z,1463771749.964 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:51.580Z,1463771751.580 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:52.249Z,1463771752.249 [CommandLine](IMPORTANT): got command quit
2016-05-20T19:15:52.323Z,1463771752.323 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1
2016-05-20T19:15:52.324Z,1463771752.324 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai
2016-05-20T19:15:52.324Z,1463771752.324 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false
2016-05-20T19:15:52.400Z,1463771752.400 [Startup:StartupSatComms:B](INFO): Timed out from 2016-05-20T19:14:52.3Z
2016-05-20T19:15:52.400Z,1463771752.400 [Startup:StartupSatComms:B] Stopped
2016-05-20T19:15:52.401Z,1463771752.401 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2016-05-20T19:15:52.401Z,1463771752.401 [Startup:StartupSatComms] Stopped
2016-05-20T19:15:52.401Z,1463771752.401 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2016-05-20T19:15:52.402Z,1463771752.402 [Startup](INFO): Completed Startup
2016-05-20T19:15:52.402Z,1463771752.402 [Startup] Stopped
2016-05-20T19:15:52.402Z,1463771752.402 [Startup](DEBUG): Aggregate::uninitialize Startup
2016-05-20T19:15:52.402Z,1463771752.402 [Startup:A.GoToSurface] Stopped
2016-05-20T19:15:52.402Z,1463771752.402 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2016-05-20T19:15:52.794Z,1463771752.794 [MissionManager](IMPORTANT): Started mission Default
2016-05-20T19:15:52.795Z,1463771752.795 [Default] Running Loop=1
2016-05-20T19:15:52.795Z,1463771752.795 [Default](DEBUG): Aggregate::initialize Default
2016-05-20T19:15:52.795Z,1463771752.795 [Default:B.GoToSurface] Running Loop=1
2016-05-20T19:15:52.795Z,1463771752.795 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2016-05-20T19:15:52.795Z,1463771752.795 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2016-05-20T19:15:52.796Z,1463771752.796 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2016-05-20T19:15:52.796Z,1463771752.796 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2016-05-20T19:15:52.796Z,1463771752.796 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2016-05-20T19:15:52.796Z,1463771752.796 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2016-05-20T19:15:52.797Z,1463771752.797 [Default:A.Wait] Running Loop=1
2016-05-20T19:15:52.797Z,1463771752.797 [Default:A.Wait](DEBUG): Initialize Wait Component.
2016-05-20T19:15:53.194Z,1463771753.194 [Rowe_600LCM](IMPORTANT): Valid WT Data.
X:88.888000
Y:88.888000
Z:88.888000
2016-05-20T19:15:53.262Z,1463771753.262 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-20T19:15:53.263Z,1463771753.263 [CommandLine ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:53.403Z,1463771753.403 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2016-05-20T19:15:53.403Z,1463771753.403 [CommandLine ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:53.405Z,1463771753.405 [CommandLine](INFO): Join timeout helper Thread ID is 1829
2016-05-20T19:15:53.411Z,1463771753.411 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2016-05-20T19:15:53.411Z,1463771753.411 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:53.412Z,1463771753.412 [NavChartDb](INFO): Join timeout helper Thread ID is 1830
2016-05-20T19:15:53.784Z,1463771753.784 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-20T19:15:53.785Z,1463771753.785 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:53.787Z,1463771753.787 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2016-05-20T19:15:53.788Z,1463771753.788 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:53.789Z,1463771753.789 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 1831
2016-05-20T19:15:54.001Z,1463771754.001 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-20T19:15:54.001Z,1463771754.001 [Rowe_600LCM](INFO): Powering down
2016-05-20T19:15:54.004Z,1463771754.004 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:54.020Z,1463771754.020 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2016-05-20T19:15:54.020Z,1463771754.020 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:54.021Z,1463771754.021 [Radio_Surface](INFO): Join timeout helper Thread ID is 1832
2016-05-20T19:15:54.408Z,1463771754.408 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-20T19:15:54.408Z,1463771754.408 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:54.428Z,1463771754.428 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2016-05-20T19:15:54.428Z,1463771754.428 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:54.428Z,1463771754.428 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1833
2016-05-20T19:15:54.456Z,1463771754.456 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-20T19:15:54.456Z,1463771754.456 [WetLabsBB2FL](INFO): Powering down
2016-05-20T19:15:54.457Z,1463771754.457 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:54.469Z,1463771754.469 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2016-05-20T19:15:54.469Z,1463771754.469 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:54.469Z,1463771754.469 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1834
2016-05-20T19:15:54.818Z,1463771754.818 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-20T19:15:54.818Z,1463771754.818 [CTD_NeilBrown](INFO): Powering down
2016-05-20T19:15:54.820Z,1463771754.820 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:54.841Z,1463771754.841 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2016-05-20T19:15:54.841Z,1463771754.841 [logger ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:54.842Z,1463771754.842 [logger](INFO): Join timeout helper Thread ID is 1835
2016-05-20T19:15:54.842Z,1463771754.842 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-20T19:15:54.843Z,1463771754.843 [logger ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:54.844Z,1463771754.844 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2016-05-20T19:15:54.844Z,1463771754.844 [CommandLine ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:54.844Z,1463771754.844 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2016-05-20T19:15:54.844Z,1463771754.844 [controlThread ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:54.845Z,1463771754.845 [controlThread](INFO): Join timeout helper Thread ID is 1836
2016-05-20T19:15:56.791Z,1463771756.791 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-20T19:15:56.791Z,1463771756.791 [controlThread](DEBUG): Uninitializing ControlThread
2016-05-20T19:15:56.792Z,1463771756.792 [Aanderaa_O2](INFO): Powering down
2016-05-20T19:15:56.793Z,1463771756.793 [AcousticModem_Benthos_ATM900](INFO): Powering down
2016-05-20T19:15:56.796Z,1463771756.796 [NAL9602](INFO): Powering down
2016-05-20T19:15:56.798Z,1463771756.798 [PNI_TCM](INFO): Powering down
2016-05-20T19:15:56.799Z,1463771756.799 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2016-05-20T19:15:56.803Z,1463771756.803 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2016-05-20T19:15:56.804Z,1463771756.804 [Default] Stopped
2016-05-20T19:15:56.805Z,1463771756.805 [Default](DEBUG): Aggregate::uninitialize Default
2016-05-20T19:15:56.805Z,1463771756.805 [Default:A.Wait] Stopped
2016-05-20T19:15:56.805Z,1463771756.805 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2016-05-20T19:15:56.805Z,1463771756.805 [Default:B.GoToSurface] Stopped
2016-05-20T19:15:56.805Z,1463771756.805 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2016-05-20T19:15:56.811Z,1463771756.811 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2016-05-20T19:15:56.811Z,1463771756.811 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2016-05-20T19:15:56.811Z,1463771756.811 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2016-05-20T19:15:56.812Z,1463771756.812 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2016-05-20T19:15:56.812Z,1463771756.812 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2016-05-20T19:15:56.812Z,1463771756.812 [BuoyancyServo](INFO): Powering down
2016-05-20T19:15:56.824Z,1463771756.824 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2016-05-20T19:15:56.824Z,1463771756.824 [ElevatorServo](INFO): Powering down
2016-05-20T19:15:56.825Z,1463771756.825 [MassServo](DEBUG): Uninitialize Mass Servo.
2016-05-20T19:15:56.825Z,1463771756.825 [MassServo](INFO): Powering down
2016-05-20T19:15:56.826Z,1463771756.826 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2016-05-20T19:15:56.826Z,1463771756.826 [RudderServo](INFO): Powering down
2016-05-20T19:15:56.826Z,1463771756.826 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2016-05-20T19:15:56.827Z,1463771756.827 [ThrusterServo](INFO): Powering down
2016-05-20T19:15:56.827Z,1463771756.827 [SBIT](DEBUG): Uninitialize SBIT Component.
2016-05-20T19:15:56.828Z,1463771756.828 [IBIT](DEBUG): Uninitialize IBIT Component.
2016-05-20T19:15:56.828Z,1463771756.828 [CBIT](DEBUG): Uninitialize CBIT Component.
2016-05-20T19:15:56.860Z,1463771756.860 [controlThread ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:56.920Z,1463771756.920 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:56.924Z,1463771756.924 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:56.985Z,1463771756.985 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:57.012Z,1463771757.012 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:57.061Z,1463771757.061 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2016-05-20T19:15:57.110Z,1463771757.110 [logger ThreadHandler](INFO): Thread cancelled.