2016-05-11T17:58:55.700Z,1462989535.700 [Supervisor](DEBUG): Initializing supervisor.
2016-05-11T17:58:55.702Z,1462989535.702 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2016-05-11T17:58:55.703Z,1462989535.703 [SyncHandler](INFO): Protected caller Thread ID is 2715
2016-05-11T17:58:55.703Z,1462989535.703 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2016-05-11T17:58:55.704Z,1462989535.704 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2016-05-11T17:58:55.704Z,1462989535.704 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2716
2016-05-11T17:58:55.707Z,1462989535.707 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2016-05-11T17:58:55.719Z,1462989535.719 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2016-05-11T17:58:55.720Z,1462989535.720 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2016-05-11T17:58:55.720Z,1462989535.720 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2717
2016-05-11T17:58:55.721Z,1462989535.721 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2016-05-11T17:58:55.722Z,1462989535.722 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2016-05-11T17:58:55.723Z,1462989535.723 [logger ThreadHandler](INFO): Protected caller Thread ID is 2718
2016-05-11T17:58:55.725Z,1462989535.725 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2016-05-11T17:58:55.725Z,1462989535.725 [Supervisor](INFO): Looking for Config files in directory: Config/
2016-05-11T17:58:55.726Z,1462989535.726 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2016-05-11T17:58:56.067Z,1462989536.067 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2016-05-11T17:58:56.067Z,1462989536.067 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2016-05-11T17:58:56.232Z,1462989536.232 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2016-05-11T17:58:56.233Z,1462989536.233 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2016-05-11T17:58:56.358Z,1462989536.358 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2016-05-11T17:58:56.358Z,1462989536.358 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2016-05-11T17:58:56.489Z,1462989536.489 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2016-05-11T17:58:56.490Z,1462989536.490 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2016-05-11T17:58:56.575Z,1462989536.575 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2016-05-11T17:58:56.763Z,1462989536.763 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2016-05-11T17:58:56.763Z,1462989536.763 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2016-05-11T17:58:56.849Z,1462989536.849 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2016-05-11T17:58:56.849Z,1462989536.849 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2016-05-11T17:58:57.121Z,1462989537.121 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2016-05-11T17:58:57.121Z,1462989537.121 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2016-05-11T17:58:57.458Z,1462989537.458 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2016-05-11T17:58:57.459Z,1462989537.459 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2016-05-11T17:58:57.757Z,1462989537.757 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2016-05-11T17:58:57.758Z,1462989537.758 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2016-05-11T17:58:58.254Z,1462989538.254 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2016-05-11T17:58:58.255Z,1462989538.255 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2016-05-11T17:58:58.453Z,1462989538.453 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2016-05-11T17:58:58.454Z,1462989538.454 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2016-05-11T17:58:58.556Z,1462989538.556 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2016-05-11T17:58:58.557Z,1462989538.557 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2016-05-11T17:58:58.987Z,1462989538.987 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2016-05-11T17:58:58.988Z,1462989538.988 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2016-05-11T17:58:59.097Z,1462989539.097 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2016-05-11T17:58:59.099Z,1462989539.099 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2016-05-11T17:58:59.100Z,1462989539.100 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2016-05-11T17:58:59.339Z,1462989539.339 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2016-05-11T17:58:59.340Z,1462989539.340 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2016-05-11T17:58:59.455Z,1462989539.455 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2016-05-11T17:58:59.551Z,1462989539.551 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2016-05-11T17:58:59.647Z,1462989539.647 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2016-05-11T17:58:59.737Z,1462989539.737 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2016-05-11T17:58:59.893Z,1462989539.893 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2016-05-11T17:59:00.074Z,1462989540.074 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2016-05-11T17:59:00.175Z,1462989540.175 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2016-05-11T17:59:00.257Z,1462989540.257 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2016-05-11T17:59:00.346Z,1462989540.346 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2016-05-11T17:59:00.521Z,1462989540.521 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2016-05-11T17:59:00.522Z,1462989540.522 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2016-05-11T17:59:00.529Z,1462989540.529 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2016-05-11T17:59:00.649Z,1462989540.649 [SBIT](DEBUG): Construct Startup Built In Test.
2016-05-11T17:59:00.680Z,1462989540.680 [SBIT] Loaded
2016-05-11T17:59:00.680Z,1462989540.680 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2016-05-11T17:59:00.681Z,1462989540.681 [IBIT](DEBUG): Construct Initiated Built In Test.
2016-05-11T17:59:00.709Z,1462989540.709 [IBIT] Loaded
2016-05-11T17:59:00.709Z,1462989540.709 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2016-05-11T17:59:00.711Z,1462989540.711 [CBIT](DEBUG): Construct Continuous Built In Test.
2016-05-11T17:59:00.852Z,1462989540.852 [CBIT] Loaded
2016-05-11T17:59:00.852Z,1462989540.852 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2016-05-11T17:59:00.852Z,1462989540.852 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2016-05-11T17:59:00.853Z,1462989540.853 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2016-05-11T17:59:00.901Z,1462989540.901 [VerticalControl](DEBUG): Construct VerticalControl.
2016-05-11T17:59:01.002Z,1462989541.002 [VerticalControl] Loaded
2016-05-11T17:59:01.002Z,1462989541.002 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2016-05-11T17:59:01.003Z,1462989541.003 [HorizontalControl](DEBUG): Construct HorizontalControl.
2016-05-11T17:59:01.066Z,1462989541.066 [HorizontalControl] Loaded
2016-05-11T17:59:01.066Z,1462989541.066 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2016-05-11T17:59:01.067Z,1462989541.067 [SpeedControl](DEBUG): Construct SpeedControl.
2016-05-11T17:59:01.072Z,1462989541.072 [SpeedControl] Loaded
2016-05-11T17:59:01.073Z,1462989541.073 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2016-05-11T17:59:01.073Z,1462989541.073 [LoopControl](DEBUG): Construct LoopControl.
2016-05-11T17:59:01.074Z,1462989541.074 [LoopControl] Loaded
2016-05-11T17:59:01.074Z,1462989541.074 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2016-05-11T17:59:01.075Z,1462989541.075 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2016-05-11T17:59:01.075Z,1462989541.075 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2016-05-11T17:59:01.097Z,1462989541.097 [DepthRateCalculator] Loaded
2016-05-11T17:59:01.098Z,1462989541.098 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2016-05-11T17:59:01.103Z,1462989541.103 [PitchRateCalculator] Loaded
2016-05-11T17:59:01.103Z,1462989541.103 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2016-05-11T17:59:01.114Z,1462989541.114 [SpeedCalculator] Loaded
2016-05-11T17:59:01.115Z,1462989541.115 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2016-05-11T17:59:01.131Z,1462989541.131 [TempGradientCalculator] Loaded
2016-05-11T17:59:01.131Z,1462989541.131 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2016-05-11T17:59:01.148Z,1462989541.148 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2016-05-11T17:59:01.148Z,1462989541.148 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2016-05-11T17:59:01.153Z,1462989541.153 [YawRateCalculator] Loaded
2016-05-11T17:59:01.153Z,1462989541.153 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2016-05-11T17:59:01.154Z,1462989541.154 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2016-05-11T17:59:01.154Z,1462989541.154 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2016-05-11T17:59:01.227Z,1462989541.227 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2016-05-11T17:59:01.227Z,1462989541.227 [StratificationFrontDetector](DEBUG): (re)initializing
2016-05-11T17:59:01.228Z,1462989541.228 [StratificationFrontDetector] Loaded
2016-05-11T17:59:01.228Z,1462989541.228 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2016-05-11T17:59:01.228Z,1462989541.228 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2016-05-11T17:59:01.229Z,1462989541.229 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2016-05-11T17:59:01.453Z,1462989541.453 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2016-05-11T17:59:01.453Z,1462989541.453 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2016-05-11T17:59:01.544Z,1462989541.544 [DeadReckonUsingSpeedCalculator] Loaded
2016-05-11T17:59:01.544Z,1462989541.544 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2016-05-11T17:59:01.562Z,1462989541.562 [NavChart] Loaded
2016-05-11T17:59:01.562Z,1462989541.562 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2016-05-11T17:59:01.566Z,1462989541.566 [UniversalFixResidualReporter] Loaded
2016-05-11T17:59:01.566Z,1462989541.566 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2016-05-11T17:59:01.567Z,1462989541.567 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2016-05-11T17:59:01.567Z,1462989541.567 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2016-05-11T17:59:01.573Z,1462989541.573 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2016-05-11T17:59:01.574Z,1462989541.574 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2016-05-11T17:59:01.755Z,1462989541.755 [Aanderaa_O2] Loaded
2016-05-11T17:59:01.755Z,1462989541.755 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2016-05-11T17:59:01.831Z,1462989541.831 [CTD_NeilBrown] Loaded
2016-05-11T17:59:01.831Z,1462989541.831 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2016-05-11T17:59:01.832Z,1462989541.832 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4059E4E0
2016-05-11T17:59:01.833Z,1462989541.833 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 2797
2016-05-11T17:59:01.835Z,1462989541.835 [ESPComponent](CRITICAL): No configuration setting for: ESPComponent.espSimulator
2016-05-11T17:59:01.841Z,1462989541.841 [ESPComponent](CRITICAL): No configuration setting for: ESPComponent.stopCompleteTimeout
2016-05-11T17:59:01.853Z,1462989541.853 [ESPComponent] Loaded
2016-05-11T17:59:01.853Z,1462989541.853 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2016-05-11T17:59:01.868Z,1462989541.868 [PAR_Licor] Loaded
2016-05-11T17:59:01.868Z,1462989541.868 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2016-05-11T17:59:01.919Z,1462989541.919 [WetLabsBB2FL] Loaded
2016-05-11T17:59:01.920Z,1462989541.920 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2016-05-11T17:59:01.921Z,1462989541.921 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 405CE4E0
2016-05-11T17:59:01.921Z,1462989541.921 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2798
2016-05-11T17:59:01.922Z,1462989541.922 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2016-05-11T17:59:01.922Z,1462989541.922 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2016-05-11T17:59:02.183Z,1462989542.183 [AcousticModem_Benthos_ATM900] Loaded
2016-05-11T17:59:02.183Z,1462989542.183 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2016-05-11T17:59:02.257Z,1462989542.257 [DataOverHttps] Loaded
2016-05-11T17:59:02.257Z,1462989542.257 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2016-05-11T17:59:02.270Z,1462989542.270 [Depth_Keller] Loaded
2016-05-11T17:59:02.271Z,1462989542.271 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2016-05-11T17:59:02.276Z,1462989542.276 [DropWeight] Loaded
2016-05-11T17:59:02.276Z,1462989542.276 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2016-05-11T17:59:02.369Z,1462989542.369 [NAL9602] Loaded
2016-05-11T17:59:02.369Z,1462989542.369 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2016-05-11T17:59:02.411Z,1462989542.411 [Onboard] Loaded
2016-05-11T17:59:02.411Z,1462989542.411 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2016-05-11T17:59:02.418Z,1462989542.418 [Radio_Surface] Loaded
2016-05-11T17:59:02.418Z,1462989542.418 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2016-05-11T17:59:02.419Z,1462989542.419 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409DE4E0
2016-05-11T17:59:02.420Z,1462989542.420 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2799
2016-05-11T17:59:02.469Z,1462989542.469 [PNI_TCM] Loaded
2016-05-11T17:59:02.469Z,1462989542.469 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2016-05-11T17:59:02.653Z,1462989542.653 [Rowe_600] Loaded
2016-05-11T17:59:02.653Z,1462989542.653 [ComponentRegistry](DEBUG): Component "Rowe_600" handled in its own thread.
2016-05-11T17:59:02.655Z,1462989542.655 [Rowe_600 ThreadHandler](DEBUG): Created PCaller Thread at 40A0E4E0
2016-05-11T17:59:02.655Z,1462989542.655 [Rowe_600 ThreadHandler](INFO): Protected caller Thread ID is 2800
2016-05-11T17:59:02.671Z,1462989542.671 [Rowe_600LCM] Loaded
2016-05-11T17:59:02.671Z,1462989542.671 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2016-05-11T17:59:02.673Z,1462989542.673 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 40A3E4E0
2016-05-11T17:59:02.673Z,1462989542.673 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 2801
2016-05-11T17:59:04.538Z,1462989544.538 [BPC1] Loaded
2016-05-11T17:59:04.538Z,1462989544.538 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2016-05-11T17:59:04.538Z,1462989544.538 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2016-05-11T17:59:04.539Z,1462989544.539 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2016-05-11T17:59:04.636Z,1462989544.636 [BuoyancyServo] Loaded
2016-05-11T17:59:04.636Z,1462989544.636 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2016-05-11T17:59:04.648Z,1462989544.648 [ElevatorServo] Loaded
2016-05-11T17:59:04.648Z,1462989544.648 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2016-05-11T17:59:04.660Z,1462989544.660 [MassServo] Loaded
2016-05-11T17:59:04.660Z,1462989544.660 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2016-05-11T17:59:04.672Z,1462989544.672 [RudderServo] Loaded
2016-05-11T17:59:04.672Z,1462989544.672 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2016-05-11T17:59:04.683Z,1462989544.683 [ThrusterServo] Loaded
2016-05-11T17:59:04.683Z,1462989544.683 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2016-05-11T17:59:04.684Z,1462989544.684 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2016-05-11T17:59:04.684Z,1462989544.684 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2016-05-11T17:59:04.785Z,1462989544.785 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2016-05-11T17:59:04.786Z,1462989544.786 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2016-05-11T17:59:04.810Z,1462989544.810 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2016-05-11T17:59:04.813Z,1462989544.813 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2016-05-11T17:59:04.814Z,1462989544.814 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2016-05-11T17:59:04.821Z,1462989544.821 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2016-05-11T17:59:04.822Z,1462989544.822 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AEC4E0
2016-05-11T17:59:04.822Z,1462989544.822 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2802
2016-05-11T17:59:04.827Z,1462989544.827 [Supervisor](INFO): Main Thread ID is 2714
2016-05-11T17:59:04.827Z,1462989544.827 [Supervisor](DEBUG): Running supervisor.
2016-05-11T17:59:04.828Z,1462989544.828 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2803
2016-05-11T17:59:04.831Z,1462989544.831 [controlThread ThreadHandler](INFO): Handler Thread ID is 2804
2016-05-11T17:59:04.831Z,1462989544.831 [controlThread](DEBUG): Initializing ControlThread
2016-05-11T17:59:04.832Z,1462989544.832 [SBIT](INFO): Initialize SBIT Component.
2016-05-11T17:59:04.833Z,1462989544.833 [SBIT](IMPORTANT): git: 2015-11-13-11-g036008f
2016-05-11T17:59:04.833Z,1462989544.833 [SBIT](INFO): git hash: 036008fb27dd1443c9c6898c567944386f491f02
2016-05-11T17:59:04.833Z,1462989544.833 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2016-05-11T17:59:04.833Z,1462989544.833 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2016-05-11T17:59:04.834Z,1462989544.834 [SBIT](INFO): Beginning SBIT in 35.000000 seconds.
2016-05-11T17:59:04.835Z,1462989544.835 [IBIT](INFO): Initialize IBIT Component.
2016-05-11T17:59:04.836Z,1462989544.836 [CBIT](DEBUG): Initialize CBIT Component.
2016-05-11T17:59:04.836Z,1462989544.836 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2016-05-11T17:59:04.837Z,1462989544.837 [logger ThreadHandler](INFO): Handler Thread ID is 2805
2016-05-11T17:59:04.857Z,1462989544.857 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 2806
2016-05-11T17:59:04.858Z,1462989544.858 [CTD_NeilBrown](INFO): Powering down
2016-05-11T17:59:04.861Z,1462989544.861 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2016-05-11T17:59:04.863Z,1462989544.863 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2016-05-11T17:59:04.863Z,1462989544.863 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2016-05-11T17:59:04.864Z,1462989544.864 [LoopControl](DEBUG): Initialize LoopControlComponent.
2016-05-11T17:59:04.864Z,1462989544.864 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2016-05-11T17:59:04.865Z,1462989544.865 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2016-05-11T17:59:04.865Z,1462989544.865 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2016-05-11T17:59:04.866Z,1462989544.866 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2016-05-11T17:59:04.866Z,1462989544.866 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2016-05-11T17:59:04.867Z,1462989544.867 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2016-05-11T17:59:04.867Z,1462989544.867 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2016-05-11T17:59:04.868Z,1462989544.868 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2016-05-11T17:59:04.872Z,1462989544.872 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2016-05-11T17:59:04.873Z,1462989544.873 [NavChart](DEBUG): Initialize NavChart Navigation.
2016-05-11T17:59:04.873Z,1462989544.873 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2016-05-11T17:59:04.881Z,1462989544.881 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2016-05-11T17:59:04.907Z,1462989544.907 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2016-05-11T17:59:04.913Z,1462989544.913 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2807
2016-05-11T17:59:04.914Z,1462989544.914 [WetLabsBB2FL](INFO): Powering down
2016-05-11T17:59:04.949Z,1462989544.949 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2808
2016-05-11T17:59:04.955Z,1462989544.955 [Radio_Surface](INFO): Powering up
2016-05-11T17:59:04.959Z,1462989544.959 [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-11T17:59:04.965Z,1462989544.965 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2016-05-11T17:59:04.971Z,1462989544.971 [Rowe_600 ThreadHandler](INFO): Handler Thread ID is 2809
2016-05-11T17:59:04.993Z,1462989544.993 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 2810
2016-05-11T17:59:04.994Z,1462989544.994 [Rowe_600LCM](INFO): Powering down
2016-05-11T17:59:05.049Z,1462989545.049 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2812
2016-05-11T17:59:05.052Z,1462989545.052 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources/ElectronicNavigationCharts
2016-05-11T17:59:05.053Z,1462989545.053 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2016-05-11T17:59:05.053Z,1462989545.053 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2016-05-11T17:59:05.053Z,1462989545.053 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2016-05-11T17:59:05.054Z,1462989545.054 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2016-05-11T17:59:05.054Z,1462989545.054 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2016-05-11T17:59:05.054Z,1462989545.054 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2016-05-11T17:59:05.054Z,1462989545.054 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2016-05-11T17:59:05.054Z,1462989545.054 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2016-05-11T17:59:05.093Z,1462989545.093 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2016-05-11T17:59:05.094Z,1462989545.094 [Default:A.Wait](DEBUG): Construct Wait.
2016-05-11T17:59:05.096Z,1462989545.096 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2016-05-11T17:59:05.163Z,1462989545.163 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2016-05-11T17:59:05.165Z,1462989545.165 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2016-05-11T17:59:05.195Z,1462989545.195 [Default:E.Execute](DEBUG): Construct Execute.
2016-05-11T17:59:05.211Z,1462989545.211 [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-11T17:59:05.216Z,1462989545.216 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,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,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2016-05-11T17:59:05.257Z,1462989545.257 [Rowe_600](INFO): Powering down
2016-05-11T17:59:05.284Z,1462989545.284 [ESPComponent](INFO): powering down ESP
2016-05-11T17:59:05.319Z,1462989545.319 [Rowe_600LCM](INFO): Initializing
2016-05-11T17:59:05.321Z,1462989545.321 [Rowe_600LCM](INFO): Checking LCM
2016-05-11T17:59:05.321Z,1462989545.321 [Rowe_600LCM](INFO): LCM OK
2016-05-11T17:59:05.322Z,1462989545.322 [Rowe_600LCM](INFO): Powering up
2016-05-11T17:59:05.672Z,1462989545.672 [AcousticModem_Benthos_ATM900](INFO): Powering up
2016-05-11T17:59:05.672Z,1462989545.672 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2016-05-11T17:59:06.111Z,1462989546.111 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-11T17:59:06.231Z,1462989546.231 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2016-05-11T17:59:06.239Z,1462989546.239 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2016-05-11T17:59:06.271Z,1462989546.271 [ElevatorServo](DEBUG): Initializing EZServoServo.
2016-05-11T17:59:06.275Z,1462989546.275 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2016-05-11T17:59:06.305Z,1462989546.305 [MassServo](DEBUG): Initializing EZServoServo.
2016-05-11T17:59:06.311Z,1462989546.311 [MassServo](DEBUG): Initializing MassServo.
2016-05-11T17:59:06.317Z,1462989546.317 [RudderServo](DEBUG): Initializing EZServoServo.
2016-05-11T17:59:06.323Z,1462989546.323 [RudderServo](DEBUG): Initializing RudderServo.
2016-05-11T17:59:06.341Z,1462989546.341 [ThrusterServo](DEBUG): Initializing EZServoServo.
2016-05-11T17:59:06.347Z,1462989546.347 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2016-05-11T17:59:06.388Z,1462989546.388 [CommandLine](FAULT): Scheduling is paused
2016-05-11T17:59:06.597Z,1462989546.597 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-11T17:59:06.927Z,1462989546.927 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-11T17:59:07.362Z,1462989547.362 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-11T17:59:07.837Z,1462989547.837 [Aanderaa_O2](INFO): Powering down
2016-05-11T17:59:07.898Z,1462989547.898 [NAL9602](INFO): Powering up NAL9602
2016-05-11T17:59:07.966Z,1462989547.966 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-11T17:59:08.178Z,1462989548.178 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-11T17:59:08.558Z,1462989548.558 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-11T17:59:09.175Z,1462989549.175 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-11T17:59:09.684Z,1462989549.684 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2016-05-11T17:59:09.827Z,1462989549.827 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:./bin/roweadcp -dev /dev/ttyA1 -b 38400.000000 bps >& adcpLog.log &
2016-05-11T17:59:09.893Z,1462989549.893 [Rowe_600LCM](INFO): LCM subscribed to channel:rti.adcp_dvl.bottom_track
2016-05-11T17:59:13.323Z,1462989553.323 [AcousticModem_Benthos_ATM900](DEBUG): 
2016-05-11T17:59:14.526Z,1462989554.526 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2016-05-11T17:59:14.526Z,1462989554.526 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2016-05-11T17:59:14.527Z,1462989554.527 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2016-05-11T17:59:14.926Z,1462989554.926 [AcousticModem_Benthos_ATM900](DEBUG): May 11 2016 17:51:46 
2016-05-11T17:59:15.722Z,1462989555.722 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2016-05-11T17:59:16.123Z,1462989556.123 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2016-05-11T17:59:16.540Z,1462989556.540 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2016-05-11T17:59:16.540Z,1462989556.540 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2016-05-11T17:59:16.540Z,1462989556.540 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2016-05-11T17:59:16.924Z,1462989556.924 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2016-05-11T17:59:17.325Z,1462989557.325 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2016-05-11T17:59:17.326Z,1462989557.326 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2016-05-11T17:59:17.722Z,1462989557.722 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2016-05-11T17:59:18.928Z,1462989558.928 [NAL9602](INFO): NAL9602 initialized
2016-05-11T17:59:40.621Z,1462989580.621 [SBIT](IMPORTANT): Beginning Startup BIT
2016-05-11T17:59:40.623Z,1462989580.623 [CBIT](IMPORTANT): Beginning GF scan
2016-05-11T17:59:47.528Z,1462989587.528 [BPC1](ERROR): Failed to parse bank B battery data
2016-05-11T17:59:47.528Z,1462989587.528 [BPC1] Data Fault, FailCount= 1
2016-05-11T17:59:47.528Z,1462989587.528 [BPC1](ERROR): Data Fault
2016-05-11T17:59:47.623Z,1462989587.623 [CBIT](ERROR): Data Fault in component: BPC1
2016-05-11T17:59:48.833Z,1462989588.833 [CBIT](INFO): Clearing failed state for component BPC1
2016-05-11T17:59:48.833Z,1462989588.833 [BPC1] No Fault, FailCount= 1
2016-05-11T18:00:07.434Z,1462989607.434 [CBIT](IMPORTANT): No ground fault detected
2016-05-11T18:00:34.711Z,1462989634.711 [SBIT](IMPORTANT): SBIT PASSED
2016-05-11T18:00:35.097Z,1462989635.097 [MissionManager](IMPORTANT): Started mission Startup
2016-05-11T18:00:35.097Z,1462989635.097 [Startup] Running Loop=1
2016-05-11T18:00:35.097Z,1462989635.097 [Startup](DEBUG): Aggregate::initialize Startup
2016-05-11T18:00:35.097Z,1462989635.097 [Startup:A.GoToSurface] Running Loop=1
2016-05-11T18:00:35.097Z,1462989635.097 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2016-05-11T18:00:35.098Z,1462989635.098 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2016-05-11T18:00:35.098Z,1462989635.098 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2016-05-11T18:00:35.099Z,1462989635.099 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2016-05-11T18:00:35.099Z,1462989635.099 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2016-05-11T18:00:35.099Z,1462989635.099 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2016-05-11T18:00:35.106Z,1462989635.106 [Startup:StartupSatComms] Running Loop=1
2016-05-11T18:00:35.106Z,1462989635.106 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2016-05-11T18:00:35.106Z,1462989635.106 [Startup:StartupSatComms:A] Running Loop=1
2016-05-11T18:00:35.498Z,1462989635.498 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2016-05-11T18:01:05.724Z,1462989665.724 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2016-05-11T18:01:05.724Z,1462989665.724 [Rowe_600LCM] Communications Fault, FailCount= 1
2016-05-11T18:01:05.724Z,1462989665.724 [Rowe_600LCM](ERROR): Communications Fault
2016-05-11T18:01:05.897Z,1462989665.897 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2016-05-11T18:01:06.129Z,1462989666.129 [Rowe_600LCM](INFO): Powering down
2016-05-11T18:01:09.627Z,1462989669.627 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2016-05-11T18:01:09.627Z,1462989669.627 [Rowe_600LCM] No Fault, FailCount= 1
2016-05-11T18:01:09.830Z,1462989669.830 [Rowe_600LCM](INFO): Initializing
2016-05-11T18:01:09.832Z,1462989669.832 [Rowe_600LCM](INFO): Checking LCM
2016-05-11T18:01:09.832Z,1462989669.832 [Rowe_600LCM](INFO): LCM OK
2016-05-11T18:01:09.832Z,1462989669.832 [Rowe_600LCM](INFO): Powering up
2016-05-11T18:01:10.442Z,1462989670.442 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1
2016-05-11T18:01:10.442Z,1462989670.442 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai
2016-05-11T18:01:10.443Z,1462989670.443 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false
2016-05-11T18:01:10.447Z,1462989670.447 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005006
2016-05-11T18:01:12.079Z,1462989672.079 [CommandLine](IMPORTANT): got command restart application
2016-05-11T18:01:13.087Z,1462989673.087 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-11T18:01:13.088Z,1462989673.088 [CommandLine ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:13.171Z,1462989673.171 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2016-05-11T18:01:13.171Z,1462989673.171 [CommandLine ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:13.172Z,1462989673.172 [CommandLine](INFO): Join timeout helper Thread ID is 2842
2016-05-11T18:01:13.173Z,1462989673.173 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2016-05-11T18:01:13.173Z,1462989673.173 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:13.173Z,1462989673.173 [NavChartDb](INFO): Join timeout helper Thread ID is 2843
2016-05-11T18:01:13.488Z,1462989673.488 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-11T18:01:13.488Z,1462989673.488 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:13.492Z,1462989673.492 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2016-05-11T18:01:13.492Z,1462989673.492 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:13.492Z,1462989673.492 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 2844
2016-05-11T18:01:13.857Z,1462989673.857 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-11T18:01:13.857Z,1462989673.857 [Rowe_600LCM](INFO): Powering down
2016-05-11T18:01:13.955Z,1462989673.955 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:13.965Z,1462989673.965 [ComponentRegistry](INFO): Shutting down Rowe_600 ThreadHandler
2016-05-11T18:01:13.965Z,1462989673.965 [Rowe_600 ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:13.966Z,1462989673.966 [Rowe_600](INFO): Join timeout helper Thread ID is 2846
2016-05-11T18:01:14.033Z,1462989674.033 [Rowe_600 ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-11T18:01:14.033Z,1462989674.033 [Rowe_600](INFO): Powering down
2016-05-11T18:01:14.034Z,1462989674.034 [Rowe_600 ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:14.045Z,1462989674.045 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2016-05-11T18:01:14.045Z,1462989674.045 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:14.046Z,1462989674.046 [Radio_Surface](INFO): Join timeout helper Thread ID is 2847
2016-05-11T18:01:14.341Z,1462989674.341 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-11T18:01:14.342Z,1462989674.342 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:14.358Z,1462989674.358 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2016-05-11T18:01:14.358Z,1462989674.358 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:14.359Z,1462989674.359 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2848
2016-05-11T18:01:14.566Z,1462989674.566 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-11T18:01:14.566Z,1462989674.566 [WetLabsBB2FL](INFO): Powering down
2016-05-11T18:01:14.567Z,1462989674.567 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:14.583Z,1462989674.583 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2016-05-11T18:01:14.583Z,1462989674.583 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:14.583Z,1462989674.583 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 2849
2016-05-11T18:01:14.642Z,1462989674.642 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-11T18:01:14.642Z,1462989674.642 [CTD_NeilBrown](INFO): Powering down
2016-05-11T18:01:14.643Z,1462989674.643 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:14.667Z,1462989674.667 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2016-05-11T18:01:14.667Z,1462989674.667 [logger ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:14.667Z,1462989674.667 [logger](INFO): Join timeout helper Thread ID is 2850
2016-05-11T18:01:14.674Z,1462989674.674 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-11T18:01:14.675Z,1462989674.675 [logger ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:14.687Z,1462989674.687 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2016-05-11T18:01:14.687Z,1462989674.687 [CommandLine ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:14.687Z,1462989674.687 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2016-05-11T18:01:14.687Z,1462989674.687 [controlThread ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:14.687Z,1462989674.687 [controlThread](INFO): Join timeout helper Thread ID is 2851
2016-05-11T18:01:14.830Z,1462989674.830 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-11T18:01:14.830Z,1462989674.830 [controlThread](DEBUG): Uninitializing ControlThread
2016-05-11T18:01:14.831Z,1462989674.831 [Aanderaa_O2](INFO): Powering down
2016-05-11T18:01:14.833Z,1462989674.833 [AcousticModem_Benthos_ATM900](INFO): Powering down
2016-05-11T18:01:14.951Z,1462989674.951 [NAL9602](INFO): Powering down
2016-05-11T18:01:14.953Z,1462989674.953 [PNI_TCM](INFO): Powering down
2016-05-11T18:01:15.039Z,1462989675.039 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2016-05-11T18:01:15.041Z,1462989675.041 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2016-05-11T18:01:15.044Z,1462989675.044 [Startup] Stopped
2016-05-11T18:01:15.044Z,1462989675.044 [Startup](DEBUG): Aggregate::uninitialize Startup
2016-05-11T18:01:15.044Z,1462989675.044 [Startup:A.GoToSurface] Stopped
2016-05-11T18:01:15.044Z,1462989675.044 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2016-05-11T18:01:15.044Z,1462989675.044 [Startup:StartupSatComms] Stopped
2016-05-11T18:01:15.044Z,1462989675.044 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2016-05-11T18:01:15.044Z,1462989675.044 [Startup:StartupSatComms:A] Stopped
2016-05-11T18:01:15.046Z,1462989675.046 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2016-05-11T18:01:15.046Z,1462989675.046 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2016-05-11T18:01:15.046Z,1462989675.046 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2016-05-11T18:01:15.047Z,1462989675.047 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2016-05-11T18:01:15.047Z,1462989675.047 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2016-05-11T18:01:15.047Z,1462989675.047 [BuoyancyServo](INFO): Powering down
2016-05-11T18:01:15.063Z,1462989675.063 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2016-05-11T18:01:15.063Z,1462989675.063 [ElevatorServo](INFO): Powering down
2016-05-11T18:01:15.064Z,1462989675.064 [MassServo](DEBUG): Uninitialize Mass Servo.
2016-05-11T18:01:15.064Z,1462989675.064 [MassServo](INFO): Powering down
2016-05-11T18:01:15.065Z,1462989675.065 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2016-05-11T18:01:15.065Z,1462989675.065 [RudderServo](INFO): Powering down
2016-05-11T18:01:15.065Z,1462989675.065 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2016-05-11T18:01:15.066Z,1462989675.066 [ThrusterServo](INFO): Powering down
2016-05-11T18:01:15.067Z,1462989675.067 [SBIT](DEBUG): Uninitialize SBIT Component.
2016-05-11T18:01:15.067Z,1462989675.067 [IBIT](DEBUG): Uninitialize IBIT Component.
2016-05-11T18:01:15.067Z,1462989675.067 [CBIT](DEBUG): Uninitialize CBIT Component.
2016-05-11T18:01:15.099Z,1462989675.099 [controlThread ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:15.152Z,1462989675.152 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:15.157Z,1462989675.157 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:15.225Z,1462989675.225 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:15.235Z,1462989675.235 [Rowe_600 ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:15.244Z,1462989675.244 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:15.294Z,1462989675.294 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2016-05-11T18:01:15.346Z,1462989675.346 [logger ThreadHandler](INFO): Thread cancelled.