2016-05-10T17:24:26.411Z,1462901066.411 [Supervisor](DEBUG): Initializing supervisor.
2016-05-10T17:24:26.414Z,1462901066.414 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2016-05-10T17:24:26.414Z,1462901066.414 [SyncHandler](INFO): Protected caller Thread ID is 8782
2016-05-10T17:24:26.415Z,1462901066.415 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2016-05-10T17:24:26.416Z,1462901066.416 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2016-05-10T17:24:26.416Z,1462901066.416 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 8783
2016-05-10T17:24:26.419Z,1462901066.419 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2016-05-10T17:24:26.430Z,1462901066.430 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2016-05-10T17:24:26.431Z,1462901066.431 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2016-05-10T17:24:26.432Z,1462901066.432 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 8784
2016-05-10T17:24:26.433Z,1462901066.433 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2016-05-10T17:24:26.433Z,1462901066.433 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2016-05-10T17:24:26.434Z,1462901066.434 [logger ThreadHandler](INFO): Protected caller Thread ID is 8785
2016-05-10T17:24:26.436Z,1462901066.436 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2016-05-10T17:24:26.436Z,1462901066.436 [Supervisor](INFO): Looking for Config files in directory: Config/
2016-05-10T17:24:26.438Z,1462901066.438 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2016-05-10T17:24:26.777Z,1462901066.777 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2016-05-10T17:24:26.777Z,1462901066.777 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2016-05-10T17:24:26.942Z,1462901066.942 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2016-05-10T17:24:26.943Z,1462901066.943 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2016-05-10T17:24:27.068Z,1462901067.068 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2016-05-10T17:24:27.068Z,1462901067.068 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2016-05-10T17:24:27.199Z,1462901067.199 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2016-05-10T17:24:27.199Z,1462901067.199 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2016-05-10T17:24:27.285Z,1462901067.285 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2016-05-10T17:24:27.472Z,1462901067.472 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2016-05-10T17:24:27.473Z,1462901067.473 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2016-05-10T17:24:27.559Z,1462901067.559 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2016-05-10T17:24:27.560Z,1462901067.560 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2016-05-10T17:24:27.828Z,1462901067.828 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2016-05-10T17:24:27.829Z,1462901067.829 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2016-05-10T17:24:28.163Z,1462901068.163 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2016-05-10T17:24:28.164Z,1462901068.164 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2016-05-10T17:24:28.460Z,1462901068.460 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2016-05-10T17:24:28.460Z,1462901068.460 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2016-05-10T17:24:28.949Z,1462901068.949 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2016-05-10T17:24:28.950Z,1462901068.950 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2016-05-10T17:24:29.147Z,1462901069.147 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2016-05-10T17:24:29.148Z,1462901069.148 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2016-05-10T17:24:29.251Z,1462901069.251 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2016-05-10T17:24:29.251Z,1462901069.251 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2016-05-10T17:24:29.676Z,1462901069.676 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2016-05-10T17:24:29.676Z,1462901069.676 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2016-05-10T17:24:29.787Z,1462901069.787 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2016-05-10T17:24:29.789Z,1462901069.789 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2016-05-10T17:24:29.790Z,1462901069.790 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2016-05-10T17:24:30.026Z,1462901070.026 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2016-05-10T17:24:30.027Z,1462901070.027 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2016-05-10T17:24:30.142Z,1462901070.142 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2016-05-10T17:24:30.240Z,1462901070.240 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2016-05-10T17:24:30.338Z,1462901070.338 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2016-05-10T17:24:30.428Z,1462901070.428 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2016-05-10T17:24:30.581Z,1462901070.581 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2016-05-10T17:24:30.826Z,1462901070.826 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2016-05-10T17:24:30.928Z,1462901070.928 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2016-05-10T17:24:31.011Z,1462901071.011 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2016-05-10T17:24:31.102Z,1462901071.102 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2016-05-10T17:24:31.276Z,1462901071.276 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2016-05-10T17:24:31.277Z,1462901071.277 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2016-05-10T17:24:31.284Z,1462901071.284 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2016-05-10T17:24:31.395Z,1462901071.395 [SBIT](DEBUG): Construct Startup Built In Test.
2016-05-10T17:24:31.424Z,1462901071.424 [SBIT] Loaded
2016-05-10T17:24:31.425Z,1462901071.425 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2016-05-10T17:24:31.425Z,1462901071.425 [IBIT](DEBUG): Construct Initiated Built In Test.
2016-05-10T17:24:31.452Z,1462901071.452 [IBIT] Loaded
2016-05-10T17:24:31.453Z,1462901071.453 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2016-05-10T17:24:31.455Z,1462901071.455 [CBIT](DEBUG): Construct Continuous Built In Test.
2016-05-10T17:24:31.590Z,1462901071.590 [CBIT] Loaded
2016-05-10T17:24:31.590Z,1462901071.590 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2016-05-10T17:24:31.591Z,1462901071.591 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2016-05-10T17:24:31.591Z,1462901071.591 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2016-05-10T17:24:31.636Z,1462901071.636 [VerticalControl](DEBUG): Construct VerticalControl.
2016-05-10T17:24:31.734Z,1462901071.734 [VerticalControl] Loaded
2016-05-10T17:24:31.734Z,1462901071.734 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2016-05-10T17:24:31.735Z,1462901071.735 [HorizontalControl](DEBUG): Construct HorizontalControl.
2016-05-10T17:24:31.795Z,1462901071.795 [HorizontalControl] Loaded
2016-05-10T17:24:31.795Z,1462901071.795 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2016-05-10T17:24:31.796Z,1462901071.796 [SpeedControl](DEBUG): Construct SpeedControl.
2016-05-10T17:24:31.801Z,1462901071.801 [SpeedControl] Loaded
2016-05-10T17:24:31.801Z,1462901071.801 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2016-05-10T17:24:31.802Z,1462901071.802 [LoopControl](DEBUG): Construct LoopControl.
2016-05-10T17:24:31.803Z,1462901071.803 [LoopControl] Loaded
2016-05-10T17:24:31.803Z,1462901071.803 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2016-05-10T17:24:31.803Z,1462901071.803 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2016-05-10T17:24:31.804Z,1462901071.804 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2016-05-10T17:24:31.825Z,1462901071.825 [DepthRateCalculator] Loaded
2016-05-10T17:24:31.826Z,1462901071.826 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2016-05-10T17:24:31.831Z,1462901071.831 [PitchRateCalculator] Loaded
2016-05-10T17:24:31.831Z,1462901071.831 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2016-05-10T17:24:31.842Z,1462901071.842 [SpeedCalculator] Loaded
2016-05-10T17:24:31.842Z,1462901071.842 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2016-05-10T17:24:31.857Z,1462901071.857 [TempGradientCalculator] Loaded
2016-05-10T17:24:31.858Z,1462901071.858 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2016-05-10T17:24:31.874Z,1462901071.874 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2016-05-10T17:24:31.874Z,1462901071.874 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2016-05-10T17:24:31.879Z,1462901071.879 [YawRateCalculator] Loaded
2016-05-10T17:24:31.879Z,1462901071.879 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2016-05-10T17:24:31.880Z,1462901071.880 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2016-05-10T17:24:31.880Z,1462901071.880 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2016-05-10T17:24:31.950Z,1462901071.950 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2016-05-10T17:24:31.950Z,1462901071.950 [StratificationFrontDetector](DEBUG): (re)initializing
2016-05-10T17:24:31.951Z,1462901071.951 [StratificationFrontDetector] Loaded
2016-05-10T17:24:31.951Z,1462901071.951 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2016-05-10T17:24:31.952Z,1462901071.952 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2016-05-10T17:24:31.952Z,1462901071.952 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2016-05-10T17:24:32.158Z,1462901072.158 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2016-05-10T17:24:32.159Z,1462901072.159 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2016-05-10T17:24:32.245Z,1462901072.245 [DeadReckonUsingSpeedCalculator] Loaded
2016-05-10T17:24:32.246Z,1462901072.246 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2016-05-10T17:24:32.262Z,1462901072.262 [NavChart] Loaded
2016-05-10T17:24:32.262Z,1462901072.262 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2016-05-10T17:24:32.266Z,1462901072.266 [UniversalFixResidualReporter] Loaded
2016-05-10T17:24:32.267Z,1462901072.267 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2016-05-10T17:24:32.267Z,1462901072.267 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2016-05-10T17:24:32.268Z,1462901072.268 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2016-05-10T17:24:32.274Z,1462901072.274 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2016-05-10T17:24:32.274Z,1462901072.274 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2016-05-10T17:24:32.447Z,1462901072.447 [Aanderaa_O2] Loaded
2016-05-10T17:24:32.448Z,1462901072.448 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2016-05-10T17:24:32.521Z,1462901072.521 [CTD_NeilBrown] Loaded
2016-05-10T17:24:32.521Z,1462901072.521 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2016-05-10T17:24:32.522Z,1462901072.522 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4059E4E0
2016-05-10T17:24:32.523Z,1462901072.523 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 8866
2016-05-10T17:24:32.525Z,1462901072.525 [ESPComponent](CRITICAL): No configuration setting for: ESPComponent.espSimulator
2016-05-10T17:24:32.531Z,1462901072.531 [ESPComponent](CRITICAL): No configuration setting for: ESPComponent.stopCompleteTimeout
2016-05-10T17:24:32.543Z,1462901072.543 [ESPComponent] Loaded
2016-05-10T17:24:32.543Z,1462901072.543 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2016-05-10T17:24:32.557Z,1462901072.557 [PAR_Licor] Loaded
2016-05-10T17:24:32.557Z,1462901072.557 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2016-05-10T17:24:32.606Z,1462901072.606 [WetLabsBB2FL] Loaded
2016-05-10T17:24:32.606Z,1462901072.606 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2016-05-10T17:24:32.607Z,1462901072.607 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 405CE4E0
2016-05-10T17:24:32.608Z,1462901072.608 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 8867
2016-05-10T17:24:32.608Z,1462901072.608 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2016-05-10T17:24:32.609Z,1462901072.609 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2016-05-10T17:24:32.856Z,1462901072.856 [AcousticModem_Benthos_ATM900] Loaded
2016-05-10T17:24:32.856Z,1462901072.856 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2016-05-10T17:24:32.929Z,1462901072.929 [DataOverHttps] Loaded
2016-05-10T17:24:32.929Z,1462901072.929 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2016-05-10T17:24:32.942Z,1462901072.942 [Depth_Keller] Loaded
2016-05-10T17:24:32.943Z,1462901072.943 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2016-05-10T17:24:32.947Z,1462901072.947 [DropWeight] Loaded
2016-05-10T17:24:32.947Z,1462901072.947 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2016-05-10T17:24:33.036Z,1462901073.036 [NAL9602] Loaded
2016-05-10T17:24:33.036Z,1462901073.036 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2016-05-10T17:24:33.076Z,1462901073.076 [Onboard] Loaded
2016-05-10T17:24:33.076Z,1462901073.076 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2016-05-10T17:24:33.083Z,1462901073.083 [Radio_Surface] Loaded
2016-05-10T17:24:33.083Z,1462901073.083 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2016-05-10T17:24:33.084Z,1462901073.084 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409E54E0
2016-05-10T17:24:33.085Z,1462901073.085 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 8868
2016-05-10T17:24:33.132Z,1462901073.132 [PNI_TCM] Loaded
2016-05-10T17:24:33.132Z,1462901073.132 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2016-05-10T17:24:33.306Z,1462901073.306 [Rowe_600] Loaded
2016-05-10T17:24:33.306Z,1462901073.306 [ComponentRegistry](DEBUG): Component "Rowe_600" handled in its own thread.
2016-05-10T17:24:33.307Z,1462901073.307 [Rowe_600 ThreadHandler](DEBUG): Created PCaller Thread at 40A154E0
2016-05-10T17:24:33.307Z,1462901073.307 [Rowe_600 ThreadHandler](INFO): Protected caller Thread ID is 8869
2016-05-10T17:24:33.321Z,1462901073.321 [Rowe_600LCM] Loaded
2016-05-10T17:24:33.321Z,1462901073.321 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2016-05-10T17:24:33.323Z,1462901073.323 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 40A454E0
2016-05-10T17:24:33.323Z,1462901073.323 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 8870
2016-05-10T17:24:35.093Z,1462901075.093 [BPC1] Loaded
2016-05-10T17:24:35.093Z,1462901075.093 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2016-05-10T17:24:35.094Z,1462901075.094 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2016-05-10T17:24:35.094Z,1462901075.094 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2016-05-10T17:24:35.186Z,1462901075.186 [BuoyancyServo] Loaded
2016-05-10T17:24:35.186Z,1462901075.186 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2016-05-10T17:24:35.198Z,1462901075.198 [ElevatorServo] Loaded
2016-05-10T17:24:35.198Z,1462901075.198 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2016-05-10T17:24:35.209Z,1462901075.209 [MassServo] Loaded
2016-05-10T17:24:35.210Z,1462901075.210 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2016-05-10T17:24:35.221Z,1462901075.221 [RudderServo] Loaded
2016-05-10T17:24:35.221Z,1462901075.221 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2016-05-10T17:24:35.232Z,1462901075.232 [ThrusterServo] Loaded
2016-05-10T17:24:35.232Z,1462901075.232 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2016-05-10T17:24:35.233Z,1462901075.233 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2016-05-10T17:24:35.233Z,1462901075.233 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2016-05-10T17:24:35.326Z,1462901075.326 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2016-05-10T17:24:35.326Z,1462901075.326 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2016-05-10T17:24:35.350Z,1462901075.350 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2016-05-10T17:24:35.353Z,1462901075.353 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2016-05-10T17:24:35.354Z,1462901075.354 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2016-05-10T17:24:35.361Z,1462901075.361 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2016-05-10T17:24:35.362Z,1462901075.362 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AF34E0
2016-05-10T17:24:35.362Z,1462901075.362 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 8871
2016-05-10T17:24:35.367Z,1462901075.367 [Supervisor](INFO): Main Thread ID is 8781
2016-05-10T17:24:35.367Z,1462901075.367 [Supervisor](DEBUG): Running supervisor.
2016-05-10T17:24:35.368Z,1462901075.368 [CommandLine ThreadHandler](INFO): Handler Thread ID is 8872
2016-05-10T17:24:35.371Z,1462901075.371 [controlThread ThreadHandler](INFO): Handler Thread ID is 8873
2016-05-10T17:24:35.371Z,1462901075.371 [controlThread](DEBUG): Initializing ControlThread
2016-05-10T17:24:35.372Z,1462901075.372 [SBIT](INFO): Initialize SBIT Component.
2016-05-10T17:24:35.372Z,1462901075.372 [SBIT](IMPORTANT): git: 2015-11-13-11-g036008f
2016-05-10T17:24:35.373Z,1462901075.373 [SBIT](INFO): git hash: 036008fb27dd1443c9c6898c567944386f491f02
2016-05-10T17:24:35.373Z,1462901075.373 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2016-05-10T17:24:35.373Z,1462901075.373 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2016-05-10T17:24:35.374Z,1462901075.374 [SBIT](INFO): Beginning SBIT in 35.000000 seconds.
2016-05-10T17:24:35.375Z,1462901075.375 [IBIT](INFO): Initialize IBIT Component.
2016-05-10T17:24:35.376Z,1462901075.376 [CBIT](DEBUG): Initialize CBIT Component.
2016-05-10T17:24:35.376Z,1462901075.376 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2016-05-10T17:24:35.377Z,1462901075.377 [logger ThreadHandler](INFO): Handler Thread ID is 8874
2016-05-10T17:24:35.402Z,1462901075.402 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2016-05-10T17:24:35.404Z,1462901075.404 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2016-05-10T17:24:35.404Z,1462901075.404 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2016-05-10T17:24:35.405Z,1462901075.405 [LoopControl](DEBUG): Initialize LoopControlComponent.
2016-05-10T17:24:35.405Z,1462901075.405 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2016-05-10T17:24:35.406Z,1462901075.406 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2016-05-10T17:24:35.406Z,1462901075.406 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2016-05-10T17:24:35.406Z,1462901075.406 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2016-05-10T17:24:35.407Z,1462901075.407 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2016-05-10T17:24:35.408Z,1462901075.408 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2016-05-10T17:24:35.408Z,1462901075.408 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2016-05-10T17:24:35.409Z,1462901075.409 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2016-05-10T17:24:35.409Z,1462901075.409 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2016-05-10T17:24:35.410Z,1462901075.410 [NavChart](DEBUG): Initialize NavChart Navigation.
2016-05-10T17:24:35.410Z,1462901075.410 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2016-05-10T17:24:35.418Z,1462901075.418 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 8875
2016-05-10T17:24:35.419Z,1462901075.419 [CTD_NeilBrown](INFO): Powering down
2016-05-10T17:24:35.453Z,1462901075.453 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2016-05-10T17:24:35.459Z,1462901075.459 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 8876
2016-05-10T17:24:35.460Z,1462901075.460 [WetLabsBB2FL](INFO): Powering down
2016-05-10T17:24:35.495Z,1462901075.495 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 8877
2016-05-10T17:24:35.501Z,1462901075.501 [Radio_Surface](INFO): Powering up
2016-05-10T17:24:35.508Z,1462901075.508 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2016-05-10T17:24:35.511Z,1462901075.511 [Rowe_600 ThreadHandler](INFO): Handler Thread ID is 8878
2016-05-10T17:24:35.530Z,1462901075.530 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 8879
2016-05-10T17:24:35.531Z,1462901075.531 [Rowe_600LCM](INFO): Powering down
2016-05-10T17:24:35.549Z,1462901075.549 [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-10T17:24:35.554Z,1462901075.554 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2016-05-10T17:24:35.566Z,1462901075.566 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 8880
2016-05-10T17:24:35.569Z,1462901075.569 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources/ElectronicNavigationCharts
2016-05-10T17:24:35.570Z,1462901075.570 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2016-05-10T17:24:35.570Z,1462901075.570 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2016-05-10T17:24:35.571Z,1462901075.571 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2016-05-10T17:24:35.571Z,1462901075.571 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2016-05-10T17:24:35.571Z,1462901075.571 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2016-05-10T17:24:35.571Z,1462901075.571 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2016-05-10T17:24:35.571Z,1462901075.571 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2016-05-10T17:24:35.572Z,1462901075.572 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2016-05-10T17:24:35.644Z,1462901075.644 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2016-05-10T17:24:35.645Z,1462901075.645 [Default:A.Wait](DEBUG): Construct Wait.
2016-05-10T17:24:35.647Z,1462901075.647 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2016-05-10T17:24:35.685Z,1462901075.685 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2016-05-10T17:24:35.712Z,1462901075.712 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2016-05-10T17:24:35.763Z,1462901075.763 [Default:E.Execute](DEBUG): Construct Execute.
2016-05-10T17:24:35.787Z,1462901075.787 [Rowe_600](INFO): Powering down
2016-05-10T17:24:35.815Z,1462901075.815 [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-10T17:24:35.820Z,1462901075.820 [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-10T17:24:35.901Z,1462901075.901 [ESPComponent](INFO): powering down ESP
2016-05-10T17:24:36.261Z,1462901076.261 [AcousticModem_Benthos_ATM900](INFO): Powering up
2016-05-10T17:24:36.262Z,1462901076.262 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2016-05-10T17:24:36.364Z,1462901076.364 [Rowe_600LCM](INFO): Initializing
2016-05-10T17:24:36.364Z,1462901076.364 [Rowe_600LCM](IMPORTANT): Checking LCM
2016-05-10T17:24:36.364Z,1462901076.364 [Rowe_600LCM](IMPORTANT): LCM OK
2016-05-10T17:24:36.365Z,1462901076.365 [Rowe_600LCM](INFO): Powering up
2016-05-10T17:24:36.668Z,1462901076.668 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-10T17:24:36.805Z,1462901076.805 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2016-05-10T17:24:36.812Z,1462901076.812 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2016-05-10T17:24:36.834Z,1462901076.834 [ElevatorServo](DEBUG): Initializing EZServoServo.
2016-05-10T17:24:36.840Z,1462901076.840 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2016-05-10T17:24:36.858Z,1462901076.858 [MassServo](DEBUG): Initializing EZServoServo.
2016-05-10T17:24:36.864Z,1462901076.864 [MassServo](DEBUG): Initializing MassServo.
2016-05-10T17:24:36.872Z,1462901076.872 [RudderServo](DEBUG): Initializing EZServoServo.
2016-05-10T17:24:36.881Z,1462901076.881 [RudderServo](DEBUG): Initializing RudderServo.
2016-05-10T17:24:36.902Z,1462901076.902 [ThrusterServo](DEBUG): Initializing EZServoServo.
2016-05-10T17:24:36.909Z,1462901076.909 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2016-05-10T17:24:36.957Z,1462901076.957 [CommandLine](FAULT): Scheduling is paused
2016-05-10T17:24:37.194Z,1462901077.194 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-10T17:24:37.673Z,1462901077.673 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-10T17:24:38.075Z,1462901078.075 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-10T17:24:38.487Z,1462901078.487 [Aanderaa_O2](INFO): Powering down
2016-05-10T17:24:38.564Z,1462901078.564 [NAL9602](INFO): Powering up NAL9602
2016-05-10T17:24:38.631Z,1462901078.631 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-10T17:24:38.926Z,1462901078.926 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-10T17:24:39.322Z,1462901079.322 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-10T17:24:39.632Z,1462901079.632 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2016-05-10T17:24:40.807Z,1462901080.807 [Rowe_600LCM](INFO): Stopping previous instance(s) of Rowe LCM interface
2016-05-10T17:24:41.058Z,1462901081.058 [Rowe_600LCM](INFO): Starting Rowe LCM interface
2016-05-10T17:24:41.153Z,1462901081.153 [Rowe_600LCM](IMPORTANT): LCM subscribed
2016-05-10T17:24:49.674Z,1462901089.674 [NAL9602](INFO): NAL9602 initialized
2016-05-10T17:24:51.655Z,1462901091.655 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2016-05-10T17:24:51.655Z,1462901091.655 [Rowe_600LCM] Communications Fault, FailCount= 1
2016-05-10T17:24:51.655Z,1462901091.655 [Rowe_600LCM](ERROR): Communications Fault
2016-05-10T17:24:51.787Z,1462901091.787 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2016-05-10T17:24:52.084Z,1462901092.084 [Rowe_600LCM](INFO): Powering down
2016-05-10T17:24:53.850Z,1462901093.850 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2016-05-10T17:24:53.850Z,1462901093.850 [Rowe_600LCM] No Fault, FailCount= 1
2016-05-10T17:24:54.091Z,1462901094.091 [Rowe_600LCM](INFO): Initializing
2016-05-10T17:24:54.091Z,1462901094.091 [Rowe_600LCM](IMPORTANT): Checking LCM
2016-05-10T17:24:54.091Z,1462901094.091 [Rowe_600LCM](IMPORTANT): LCM OK
2016-05-10T17:24:54.091Z,1462901094.091 [Rowe_600LCM](INFO): Powering up
2016-05-10T17:24:56.467Z,1462901096.467 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2016-05-10T17:24:56.467Z,1462901096.467 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 1
2016-05-10T17:24:56.467Z,1462901096.467 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2016-05-10T17:24:56.595Z,1462901096.595 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2016-05-10T17:24:56.872Z,1462901096.872 [AcousticModem_Benthos_ATM900](INFO): Powering down
2016-05-10T17:24:57.841Z,1462901097.841 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2016-05-10T17:24:57.841Z,1462901097.841 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 1
2016-05-10T17:24:58.404Z,1462901098.404 [Rowe_600LCM](INFO): Stopping previous instance(s) of Rowe LCM interface
2016-05-10T17:24:58.525Z,1462901098.525 [Rowe_600LCM](INFO): Starting Rowe LCM interface
2016-05-10T17:24:58.527Z,1462901098.527 [Rowe_600LCM](IMPORTANT): LCM subscribed
2016-05-10T17:25:00.069Z,1462901100.069 [AcousticModem_Benthos_ATM900](INFO): Powering up
2016-05-10T17:25:00.069Z,1462901100.069 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2016-05-10T17:25:07.669Z,1462901107.669 [AcousticModem_Benthos_ATM900](DEBUG): 
2016-05-10T17:25:08.872Z,1462901108.872 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2016-05-10T17:25:08.872Z,1462901108.872 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2016-05-10T17:25:08.873Z,1462901108.873 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2016-05-10T17:25:09.303Z,1462901109.303 [AcousticModem_Benthos_ATM900](DEBUG): May 10 2016 17:17:48 
2016-05-10T17:25:09.431Z,1462901109.431 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2016-05-10T17:25:09.431Z,1462901109.431 [Rowe_600LCM] Communications Fault, FailCount= 2
2016-05-10T17:25:09.431Z,1462901109.431 [Rowe_600LCM](ERROR): Communications Fault
2016-05-10T17:25:09.785Z,1462901109.785 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2016-05-10T17:25:09.835Z,1462901109.835 [Rowe_600LCM](INFO): Powering down
2016-05-10T17:25:10.069Z,1462901110.069 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2016-05-10T17:25:10.469Z,1462901110.469 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2016-05-10T17:25:10.870Z,1462901110.870 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2016-05-10T17:25:10.870Z,1462901110.870 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2016-05-10T17:25:10.870Z,1462901110.870 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2016-05-10T17:25:10.948Z,1462901110.948 [SBIT](IMPORTANT): Beginning Startup BIT
2016-05-10T17:25:10.954Z,1462901110.954 [CBIT](IMPORTANT): Beginning GF scan
2016-05-10T17:25:11.270Z,1462901111.270 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2016-05-10T17:25:11.495Z,1462901111.495 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2016-05-10T17:25:11.495Z,1462901111.495 [Rowe_600LCM] No Fault, FailCount= 2
2016-05-10T17:25:11.667Z,1462901111.667 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2016-05-10T17:25:11.668Z,1462901111.668 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2016-05-10T17:25:11.846Z,1462901111.846 [Rowe_600LCM](INFO): Initializing
2016-05-10T17:25:11.846Z,1462901111.846 [Rowe_600LCM](IMPORTANT): Checking LCM
2016-05-10T17:25:11.847Z,1462901111.847 [Rowe_600LCM](IMPORTANT): LCM OK
2016-05-10T17:25:11.847Z,1462901111.847 [Rowe_600LCM](INFO): Powering up
2016-05-10T17:25:12.068Z,1462901112.068 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2016-05-10T17:25:16.156Z,1462901116.156 [Rowe_600LCM](INFO): Stopping previous instance(s) of Rowe LCM interface
2016-05-10T17:25:16.316Z,1462901116.316 [Rowe_600LCM](INFO): Starting Rowe LCM interface
2016-05-10T17:25:16.318Z,1462901116.318 [Rowe_600LCM](IMPORTANT): LCM subscribed
2016-05-10T17:25:16.663Z,1462901116.663 [BPC1](ERROR): Failed to parse bank A battery data
2016-05-10T17:25:16.663Z,1462901116.663 [BPC1] Data Fault, FailCount= 1
2016-05-10T17:25:16.663Z,1462901116.663 [BPC1](ERROR): Data Fault
2016-05-10T17:25:16.771Z,1462901116.771 [CBIT](ERROR): Data Fault in component: BPC1
2016-05-10T17:25:18.002Z,1462901118.002 [CBIT](INFO): Clearing failed state for component BPC1
2016-05-10T17:25:18.002Z,1462901118.002 [BPC1] No Fault, FailCount= 1
2016-05-10T17:25:27.228Z,1462901127.228 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2016-05-10T17:25:27.229Z,1462901127.229 [Rowe_600LCM] Communications Fault, FailCount= 3
2016-05-10T17:25:27.229Z,1462901127.229 [Rowe_600LCM](ERROR): Communications Fault
2016-05-10T17:25:27.499Z,1462901127.499 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2016-05-10T17:25:27.667Z,1462901127.667 [Rowe_600LCM](INFO): Powering down
2016-05-10T17:25:29.425Z,1462901129.425 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2016-05-10T17:25:29.425Z,1462901129.425 [Rowe_600LCM] No Fault, FailCount= 3
2016-05-10T17:25:29.678Z,1462901129.678 [Rowe_600LCM](INFO): Initializing
2016-05-10T17:25:29.678Z,1462901129.678 [Rowe_600LCM](IMPORTANT): Checking LCM
2016-05-10T17:25:29.678Z,1462901129.678 [Rowe_600LCM](IMPORTANT): LCM OK
2016-05-10T17:25:29.678Z,1462901129.678 [Rowe_600LCM](INFO): Powering up
2016-05-10T17:25:33.975Z,1462901133.975 [Rowe_600LCM](INFO): Stopping previous instance(s) of Rowe LCM interface
2016-05-10T17:25:34.108Z,1462901134.108 [Rowe_600LCM](INFO): Starting Rowe LCM interface
2016-05-10T17:25:34.110Z,1462901134.110 [Rowe_600LCM](IMPORTANT): LCM subscribed
2016-05-10T17:25:37.785Z,1462901137.785 [CBIT](IMPORTANT): No ground fault detected
2016-05-10T17:25:45.010Z,1462901145.010 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2016-05-10T17:25:45.010Z,1462901145.010 [Rowe_600LCM] Communications Fault, FailCount= 4
2016-05-10T17:25:45.010Z,1462901145.010 [Rowe_600LCM](ERROR): Communications Fault
2016-05-10T17:25:45.316Z,1462901145.316 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2016-05-10T17:25:45.415Z,1462901145.415 [Rowe_600LCM](INFO): Powering down
2016-05-10T17:25:47.326Z,1462901147.326 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2016-05-10T17:25:47.326Z,1462901147.326 [Rowe_600LCM] No Fault, FailCount= 4
2016-05-10T17:25:47.422Z,1462901147.422 [Rowe_600LCM](INFO): Initializing
2016-05-10T17:25:47.422Z,1462901147.422 [Rowe_600LCM](IMPORTANT): Checking LCM
2016-05-10T17:25:47.422Z,1462901147.422 [Rowe_600LCM](IMPORTANT): LCM OK
2016-05-10T17:25:47.422Z,1462901147.422 [Rowe_600LCM](INFO): Powering up
2016-05-10T17:25:51.527Z,1462901151.527 [Rowe_600LCM](INFO): Stopping previous instance(s) of Rowe LCM interface
2016-05-10T17:25:51.602Z,1462901151.602 [Rowe_600LCM](INFO): Starting Rowe LCM interface
2016-05-10T17:25:51.604Z,1462901151.604 [Rowe_600LCM](IMPORTANT): LCM subscribed
2016-05-10T17:26:02.501Z,1462901162.501 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2016-05-10T17:26:02.501Z,1462901162.501 [Rowe_600LCM] Communications Fault, FailCount= 5
2016-05-10T17:26:02.501Z,1462901162.501 [Rowe_600LCM](ERROR): Communications Fault
2016-05-10T17:26:02.759Z,1462901162.759 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2016-05-10T17:26:02.760Z,1462901162.760 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2016-05-10T17:26:02.906Z,1462901162.906 [Rowe_600LCM](INFO): Powering down
2016-05-10T17:26:04.761Z,1462901164.761 [SBIT](IMPORTANT): SBIT PASSED
2016-05-10T17:26:05.160Z,1462901165.160 [MissionManager](IMPORTANT): Started mission Startup
2016-05-10T17:26:05.160Z,1462901165.160 [Startup] Running Loop=1
2016-05-10T17:26:05.160Z,1462901165.160 [Startup](DEBUG): Aggregate::initialize Startup
2016-05-10T17:26:05.160Z,1462901165.160 [Startup:A.GoToSurface] Running Loop=1
2016-05-10T17:26:05.160Z,1462901165.160 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2016-05-10T17:26:05.161Z,1462901165.161 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2016-05-10T17:26:05.162Z,1462901165.162 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2016-05-10T17:26:05.162Z,1462901165.162 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2016-05-10T17:26:05.162Z,1462901165.162 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2016-05-10T17:26:05.163Z,1462901165.163 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2016-05-10T17:26:05.170Z,1462901165.170 [Startup:StartupSatComms] Running Loop=1
2016-05-10T17:26:05.170Z,1462901165.170 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2016-05-10T17:26:05.170Z,1462901165.170 [Startup:StartupSatComms:A] Running Loop=1
2016-05-10T17:26:05.562Z,1462901165.562 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2016-05-10T17:26:41.335Z,1462901201.335 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=false, 1
2016-05-10T17:26:41.336Z,1462901201.336 [DataOverHttps](DEBUG): ParseDataRead( data = busy=false, key = 6, value = makai
2016-05-10T17:26:41.337Z,1462901201.337 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 0, value = false
2016-05-10T17:26:41.340Z,1462901201.340 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004706
2016-05-10T17:27:05.489Z,1462901225.489 [Startup:StartupSatComms:A](INFO): Timed out from 2016-05-10T17:26:05.2Z
2016-05-10T17:27:05.489Z,1462901225.489 [Startup:StartupSatComms:A] Stopped
2016-05-10T17:27:05.490Z,1462901225.490 [Startup:StartupSatComms:B] Running Loop=1
2016-05-10T17:27:05.813Z,1462901225.813 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2016-05-10T17:27:11.623Z,1462901231.623 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20160317T221648/Courier0084.lzma
2016-05-10T17:27:12.131Z,1462901232.131 [CommandLine](IMPORTANT): got command restart application
2016-05-10T17:27:12.399Z,1462901232.399 [DataOverHttps](DEBUG): dataRead() @791 received: vehicle=makai&busy=true&momsn=4059266&filename=Logs%2F20160317T221648%2FCourier0084.lzma, 1
2016-05-10T17:27:12.399Z,1462901232.399 [DataOverHttps](DEBUG): ParseDataRead( data = busy=true&momsn=4059266&filename=Logs%2F20160317T221648%2FCourier0084.lzma, key = 6, value = makai
2016-05-10T17:27:12.400Z,1462901232.400 [DataOverHttps](DEBUG): ParseDataRead( data = momsn=4059266&filename=Logs%2F20160317T221648%2FCourier0084.lzma, key = 0, value = true
2016-05-10T17:27:12.400Z,1462901232.400 [DataOverHttps](DEBUG): ParseDataRead( data = filename=Logs%2F20160317T221648%2FCourier0084.lzma, key = 4, value = 4059266
2016-05-10T17:27:12.401Z,1462901232.401 [DataOverHttps](DEBUG): ParseDataRead( data = , key = 2, value = Logs%2F20160317T221648%2FCourier0084.lzma
2016-05-10T17:27:12.405Z,1462901232.405 [DataOverHttps](INFO): Moved sent file to Logs/20160317T221648/Courier0084.lzma.bak
2016-05-10T17:27:12.405Z,1462901232.405 [DataOverHttps](INFO): SBD MOMSN=4059266
2016-05-10T17:27:13.142Z,1462901233.142 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-10T17:27:13.142Z,1462901233.142 [CommandLine ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:13.198Z,1462901233.198 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2016-05-10T17:27:13.199Z,1462901233.199 [CommandLine ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:13.200Z,1462901233.200 [CommandLine](INFO): Join timeout helper Thread ID is 8988
2016-05-10T17:27:13.200Z,1462901233.200 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2016-05-10T17:27:13.200Z,1462901233.200 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:13.201Z,1462901233.201 [NavChartDb](INFO): Join timeout helper Thread ID is 8989
2016-05-10T17:27:13.567Z,1462901233.567 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-10T17:27:13.567Z,1462901233.567 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:13.595Z,1462901233.595 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2016-05-10T17:27:13.595Z,1462901233.595 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:13.596Z,1462901233.596 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 8990
2016-05-10T17:27:13.851Z,1462901233.851 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-10T17:27:13.852Z,1462901233.852 [Rowe_600LCM](INFO): Powering down
2016-05-10T17:27:13.852Z,1462901233.852 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:13.859Z,1462901233.859 [ComponentRegistry](INFO): Shutting down Rowe_600 ThreadHandler
2016-05-10T17:27:13.860Z,1462901233.860 [Rowe_600 ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:13.860Z,1462901233.860 [Rowe_600](INFO): Join timeout helper Thread ID is 8991
2016-05-10T17:27:13.908Z,1462901233.908 [Rowe_600 ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-10T17:27:13.908Z,1462901233.908 [Rowe_600](INFO): Powering down
2016-05-10T17:27:13.909Z,1462901233.909 [Rowe_600 ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:13.920Z,1462901233.920 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2016-05-10T17:27:13.920Z,1462901233.920 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:13.920Z,1462901233.920 [Radio_Surface](INFO): Join timeout helper Thread ID is 8992
2016-05-10T17:27:14.172Z,1462901234.172 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-10T17:27:14.172Z,1462901234.172 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:14.193Z,1462901234.193 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2016-05-10T17:27:14.193Z,1462901234.193 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:14.193Z,1462901234.193 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 8993
2016-05-10T17:27:14.284Z,1462901234.284 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-10T17:27:14.284Z,1462901234.284 [WetLabsBB2FL](INFO): Powering down
2016-05-10T17:27:14.285Z,1462901234.285 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:14.301Z,1462901234.301 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2016-05-10T17:27:14.301Z,1462901234.301 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:14.301Z,1462901234.301 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 8994
2016-05-10T17:27:14.302Z,1462901234.302 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-10T17:27:14.302Z,1462901234.302 [CTD_NeilBrown](INFO): Powering down
2016-05-10T17:27:14.303Z,1462901234.303 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:14.305Z,1462901234.305 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2016-05-10T17:27:14.305Z,1462901234.305 [logger ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:14.305Z,1462901234.305 [logger](INFO): Join timeout helper Thread ID is 8995
2016-05-10T17:27:14.344Z,1462901234.344 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-10T17:27:14.345Z,1462901234.345 [logger ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:14.346Z,1462901234.346 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2016-05-10T17:27:14.346Z,1462901234.346 [CommandLine ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:14.346Z,1462901234.346 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2016-05-10T17:27:14.346Z,1462901234.346 [controlThread ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:14.347Z,1462901234.347 [controlThread](INFO): Join timeout helper Thread ID is 8996
2016-05-10T17:27:16.550Z,1462901236.550 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2016-05-10T17:27:16.550Z,1462901236.550 [controlThread](DEBUG): Uninitializing ControlThread
2016-05-10T17:27:16.550Z,1462901236.550 [Aanderaa_O2](INFO): Powering down
2016-05-10T17:27:16.553Z,1462901236.553 [AcousticModem_Benthos_ATM900](INFO): Powering down
2016-05-10T17:27:16.556Z,1462901236.556 [NAL9602](INFO): Powering down
2016-05-10T17:27:16.557Z,1462901236.557 [PNI_TCM](INFO): Powering down
2016-05-10T17:27:16.559Z,1462901236.559 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2016-05-10T17:27:16.560Z,1462901236.560 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2016-05-10T17:27:16.563Z,1462901236.563 [Startup] Stopped
2016-05-10T17:27:16.563Z,1462901236.563 [Startup](DEBUG): Aggregate::uninitialize Startup
2016-05-10T17:27:16.563Z,1462901236.563 [Startup:A.GoToSurface] Stopped
2016-05-10T17:27:16.563Z,1462901236.563 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2016-05-10T17:27:16.563Z,1462901236.563 [Startup:StartupSatComms] Stopped
2016-05-10T17:27:16.563Z,1462901236.563 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2016-05-10T17:27:16.563Z,1462901236.563 [Startup:StartupSatComms:B] Stopped
2016-05-10T17:27:16.565Z,1462901236.565 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2016-05-10T17:27:16.565Z,1462901236.565 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2016-05-10T17:27:16.565Z,1462901236.565 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2016-05-10T17:27:16.566Z,1462901236.566 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2016-05-10T17:27:16.566Z,1462901236.566 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2016-05-10T17:27:16.566Z,1462901236.566 [BuoyancyServo](INFO): Powering down
2016-05-10T17:27:16.580Z,1462901236.580 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2016-05-10T17:27:16.580Z,1462901236.580 [ElevatorServo](INFO): Powering down
2016-05-10T17:27:16.581Z,1462901236.581 [MassServo](DEBUG): Uninitialize Mass Servo.
2016-05-10T17:27:16.581Z,1462901236.581 [MassServo](INFO): Powering down
2016-05-10T17:27:16.582Z,1462901236.582 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2016-05-10T17:27:16.582Z,1462901236.582 [RudderServo](INFO): Powering down
2016-05-10T17:27:16.583Z,1462901236.583 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2016-05-10T17:27:16.583Z,1462901236.583 [ThrusterServo](INFO): Powering down
2016-05-10T17:27:16.584Z,1462901236.584 [SBIT](DEBUG): Uninitialize SBIT Component.
2016-05-10T17:27:16.584Z,1462901236.584 [IBIT](DEBUG): Uninitialize IBIT Component.
2016-05-10T17:27:16.584Z,1462901236.584 [CBIT](DEBUG): Uninitialize CBIT Component.
2016-05-10T17:27:16.616Z,1462901236.616 [controlThread ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:16.664Z,1462901236.664 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:16.669Z,1462901236.669 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:16.729Z,1462901236.729 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:16.755Z,1462901236.755 [Rowe_600 ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:16.762Z,1462901236.762 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:16.839Z,1462901236.839 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2016-05-10T17:27:16.893Z,1462901236.893 [logger ThreadHandler](INFO): Thread cancelled.