2018-08-28T17:24:14.950Z,1535477054.950 [Supervisor](DEBUG): Initializing supervisor.
2018-08-28T17:24:14.953Z,1535477054.953 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-08-28T17:24:14.953Z,1535477054.953 [SyncHandler](INFO): Protected caller Thread ID is 797
2018-08-28T17:24:14.954Z,1535477054.954 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-08-28T17:24:14.955Z,1535477054.955 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-08-28T17:24:14.955Z,1535477054.955 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 798
2018-08-28T17:24:14.958Z,1535477054.958 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-08-28T17:24:14.970Z,1535477054.970 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-08-28T17:24:14.971Z,1535477054.971 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-08-28T17:24:14.971Z,1535477054.971 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 799
2018-08-28T17:24:14.972Z,1535477054.972 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-08-28T17:24:14.973Z,1535477054.973 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-08-28T17:24:14.973Z,1535477054.973 [logger ThreadHandler](INFO): Protected caller Thread ID is 800
2018-08-28T17:24:14.975Z,1535477054.975 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-08-28T17:24:14.975Z,1535477054.975 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-08-28T17:24:14.979Z,1535477054.979 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-08-28T17:24:15.078Z,1535477055.078 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-08-28T17:24:15.080Z,1535477055.080 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-08-28T17:24:15.184Z,1535477055.184 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-08-28T17:24:15.186Z,1535477055.186 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-08-28T17:24:15.398Z,1535477055.398 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-08-28T17:24:15.400Z,1535477055.400 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-08-28T17:24:15.740Z,1535477055.740 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-08-28T17:24:15.741Z,1535477055.741 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-08-28T17:24:16.096Z,1535477056.096 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-08-28T17:24:16.097Z,1535477056.097 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-08-28T17:24:16.577Z,1535477056.577 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-08-28T17:24:16.578Z,1535477056.578 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-08-28T17:24:17.019Z,1535477057.019 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-08-28T17:24:17.019Z,1535477057.019 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-08-28T17:24:17.512Z,1535477057.512 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-08-28T17:24:17.514Z,1535477057.514 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-08-28T17:24:17.597Z,1535477057.597 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-08-28T17:24:17.921Z,1535477057.921 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-08-28T17:24:17.923Z,1535477057.923 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-08-28T17:24:18.075Z,1535477058.075 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-08-28T17:24:18.076Z,1535477058.076 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-08-28T17:24:18.292Z,1535477058.292 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-08-28T17:24:18.294Z,1535477058.294 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-08-28T17:24:18.515Z,1535477058.514 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-08-28T17:24:18.515Z,1535477058.515 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-08-28T17:24:18.619Z,1535477058.619 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-08-28T17:24:18.620Z,1535477058.620 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-08-28T17:24:19.253Z,1535477059.253 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-08-28T17:24:19.255Z,1535477059.255 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2018-08-28T17:24:19.257Z,1535477059.257 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2018-08-28T17:24:19.495Z,1535477059.495 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-08-28T17:24:19.495Z,1535477059.495 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2018-08-28T17:24:19.603Z,1535477059.603 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2018-08-28T17:24:19.751Z,1535477059.751 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2018-08-28T17:24:19.847Z,1535477059.847 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2018-08-28T17:24:19.934Z,1535477059.934 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2018-08-28T17:24:20.081Z,1535477060.081 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2018-08-28T17:24:20.268Z,1535477060.268 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2018-08-28T17:24:20.368Z,1535477060.368 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2018-08-28T17:24:20.465Z,1535477060.465 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2018-08-28T17:24:20.565Z,1535477060.565 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2018-08-28T17:24:20.649Z,1535477060.649 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2018-08-28T17:24:20.652Z,1535477060.652 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-08-28T17:24:20.782Z,1535477060.782 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-08-28T17:24:20.783Z,1535477060.783 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-08-28T17:24:20.806Z,1535477060.806 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-08-28T17:24:20.807Z,1535477060.807 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-08-28T17:24:20.863Z,1535477060.863 [DepthRateCalculator] Loaded
2018-08-28T17:24:20.863Z,1535477060.863 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-08-28T17:24:20.869Z,1535477060.869 [PitchRateCalculator] Loaded
2018-08-28T17:24:20.869Z,1535477060.869 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-08-28T17:24:20.886Z,1535477060.886 [SpeedCalculator] Loaded
2018-08-28T17:24:20.886Z,1535477060.886 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-08-28T17:24:20.907Z,1535477060.907 [TempGradientCalculator] Loaded
2018-08-28T17:24:20.907Z,1535477060.907 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-08-28T17:24:20.923Z,1535477060.923 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-08-28T17:24:20.923Z,1535477060.923 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-08-28T17:24:20.929Z,1535477060.929 [YawRateCalculator] Loaded
2018-08-28T17:24:20.930Z,1535477060.930 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-08-28T17:24:20.970Z,1535477060.970 [ElevatorOffsetCalculator] Loaded
2018-08-28T17:24:20.970Z,1535477060.970 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-08-28T17:24:20.970Z,1535477060.970 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-08-28T17:24:20.971Z,1535477060.971 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-08-28T17:24:21.008Z,1535477061.008 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-08-28T17:24:21.009Z,1535477061.009 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-08-28T17:24:21.488Z,1535477061.488 [AcousticModem_Benthos_ATM900] Loaded
2018-08-28T17:24:21.488Z,1535477061.488 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2018-08-28T17:24:21.622Z,1535477061.622 [DataOverHttps] Loaded
2018-08-28T17:24:21.623Z,1535477061.623 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-08-28T17:24:21.636Z,1535477061.636 [Depth_Keller] Loaded
2018-08-28T17:24:21.637Z,1535477061.637 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-08-28T17:24:21.641Z,1535477061.641 [DropWeight] Loaded
2018-08-28T17:24:21.642Z,1535477061.642 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-08-28T17:24:21.740Z,1535477061.740 [NAL9602] Loaded
2018-08-28T17:24:21.741Z,1535477061.741 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-08-28T17:24:21.756Z,1535477061.756 [Onboard] Loaded
2018-08-28T17:24:21.757Z,1535477061.757 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-08-28T17:24:21.767Z,1535477061.767 [Radio_Surface] Loaded
2018-08-28T17:24:21.767Z,1535477061.767 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-08-28T17:24:21.768Z,1535477061.768 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407B84E0
2018-08-28T17:24:21.769Z,1535477061.769 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 879
2018-08-28T17:24:21.922Z,1535477061.922 [PNI_TCM] Loaded
2018-08-28T17:24:21.922Z,1535477061.922 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-08-28T17:24:21.984Z,1535477061.984 [Rowe_600LCM] Loaded
2018-08-28T17:24:21.984Z,1535477061.984 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-08-28T17:24:21.985Z,1535477061.985 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 407E84E0
2018-08-28T17:24:21.986Z,1535477061.986 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 880
2018-08-28T17:24:23.779Z,1535477063.779 [BPC1] Loaded
2018-08-28T17:24:23.779Z,1535477063.779 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-08-28T17:24:23.780Z,1535477063.780 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-08-28T17:24:23.782Z,1535477063.782 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-08-28T17:24:23.936Z,1535477063.936 [SBIT](DEBUG): Construct Startup Built In Test.
2018-08-28T17:24:23.960Z,1535477063.960 [SBIT] Loaded
2018-08-28T17:24:23.960Z,1535477063.960 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-08-28T17:24:23.965Z,1535477063.965 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-08-28T17:24:24.005Z,1535477064.005 [IBIT] Loaded
2018-08-28T17:24:24.005Z,1535477064.005 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-08-28T17:24:24.008Z,1535477064.008 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-08-28T17:24:24.287Z,1535477064.287 [CBIT] Loaded
2018-08-28T17:24:24.288Z,1535477064.288 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-08-28T17:24:24.288Z,1535477064.288 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-08-28T17:24:24.289Z,1535477064.289 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-08-28T17:24:24.592Z,1535477064.592 [Aanderaa_O2] Loaded
2018-08-28T17:24:24.592Z,1535477064.592 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-08-28T17:24:24.646Z,1535477064.646 [CTD_Seabird] Loaded
2018-08-28T17:24:24.646Z,1535477064.646 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-08-28T17:24:24.648Z,1535477064.648 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 408AC4E0
2018-08-28T17:24:24.648Z,1535477064.648 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 882
2018-08-28T17:24:24.666Z,1535477064.666 [ESPComponent] Loaded
2018-08-28T17:24:24.666Z,1535477064.666 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2018-08-28T17:24:24.681Z,1535477064.681 [PAR_Licor] Loaded
2018-08-28T17:24:24.681Z,1535477064.681 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-08-28T17:24:24.731Z,1535477064.731 [WetLabsBB2FL] Loaded
2018-08-28T17:24:24.732Z,1535477064.732 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-08-28T17:24:24.733Z,1535477064.733 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408DC4E0
2018-08-28T17:24:24.733Z,1535477064.733 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 883
2018-08-28T17:24:24.734Z,1535477064.734 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-08-28T17:24:24.734Z,1535477064.734 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-08-28T17:24:25.019Z,1535477065.019 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-08-28T17:24:25.019Z,1535477065.019 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-08-28T17:24:25.107Z,1535477065.107 [VerticalControl](DEBUG): Construct VerticalControl.
2018-08-28T17:24:25.204Z,1535477065.204 [VerticalControl] Loaded
2018-08-28T17:24:25.204Z,1535477065.204 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-08-28T17:24:25.205Z,1535477065.205 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-08-28T17:24:25.266Z,1535477065.266 [HorizontalControl] Loaded
2018-08-28T17:24:25.267Z,1535477065.267 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-08-28T17:24:25.267Z,1535477065.267 [SpeedControl](DEBUG): Construct SpeedControl.
2018-08-28T17:24:25.273Z,1535477065.273 [SpeedControl] Loaded
2018-08-28T17:24:25.273Z,1535477065.273 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-08-28T17:24:25.274Z,1535477065.274 [LoopControl](DEBUG): Construct LoopControl.
2018-08-28T17:24:25.274Z,1535477065.274 [LoopControl] Loaded
2018-08-28T17:24:25.275Z,1535477065.275 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-08-28T17:24:25.275Z,1535477065.275 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-08-28T17:24:25.276Z,1535477065.276 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-08-28T17:24:25.397Z,1535477065.397 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-08-28T17:24:25.398Z,1535477065.398 [StratificationFrontDetector](DEBUG): (re)initializing
2018-08-28T17:24:25.398Z,1535477065.398 [StratificationFrontDetector] Loaded
2018-08-28T17:24:25.398Z,1535477065.398 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-08-28T17:24:25.399Z,1535477065.399 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-08-28T17:24:25.399Z,1535477065.399 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-08-28T17:24:25.520Z,1535477065.520 [BuoyancyServo] Loaded
2018-08-28T17:24:25.520Z,1535477065.520 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-08-28T17:24:25.532Z,1535477065.532 [ElevatorServo] Loaded
2018-08-28T17:24:25.532Z,1535477065.532 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-08-28T17:24:25.543Z,1535477065.543 [MassServo] Loaded
2018-08-28T17:24:25.543Z,1535477065.543 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-08-28T17:24:25.555Z,1535477065.555 [RudderServo] Loaded
2018-08-28T17:24:25.555Z,1535477065.555 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-08-28T17:24:25.566Z,1535477065.566 [ThrusterServo] Loaded
2018-08-28T17:24:25.567Z,1535477065.567 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-08-28T17:24:25.567Z,1535477065.567 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-08-28T17:24:25.568Z,1535477065.568 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-08-28T17:24:25.676Z,1535477065.676 [DeadReckonUsingSpeedCalculator] Loaded
2018-08-28T17:24:25.677Z,1535477065.677 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-08-28T17:24:25.696Z,1535477065.696 [NavChart] Loaded
2018-08-28T17:24:25.696Z,1535477065.696 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-08-28T17:24:25.700Z,1535477065.700 [UniversalFixResidualReporter] Loaded
2018-08-28T17:24:25.700Z,1535477065.700 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-08-28T17:24:25.701Z,1535477065.701 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-08-28T17:24:25.705Z,1535477065.705 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-08-28T17:24:25.705Z,1535477065.705 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-08-28T17:24:25.712Z,1535477065.712 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-08-28T17:24:25.713Z,1535477065.713 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A354E0
2018-08-28T17:24:25.714Z,1535477065.714 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 884
2018-08-28T17:24:25.718Z,1535477065.718 [Supervisor](INFO): Main Thread ID is 796
2018-08-28T17:24:25.718Z,1535477065.718 [Supervisor](DEBUG): Running supervisor.
2018-08-28T17:24:25.719Z,1535477065.719 [CommandLine ThreadHandler](INFO): Handler Thread ID is 885
2018-08-28T17:24:25.721Z,1535477065.721 [controlThread ThreadHandler](INFO): Handler Thread ID is 886
2018-08-28T17:24:25.722Z,1535477065.722 [controlThread](DEBUG): Initializing ControlThread
2018-08-28T17:24:25.723Z,1535477065.723 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-08-28T17:24:25.723Z,1535477065.723 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-08-28T17:24:25.723Z,1535477065.723 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-08-28T17:24:25.724Z,1535477065.724 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-08-28T17:24:25.724Z,1535477065.724 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-08-28T17:24:25.725Z,1535477065.725 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-08-28T17:24:25.726Z,1535477065.726 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-08-28T17:24:25.731Z,1535477065.731 [SBIT](INFO): Initialize SBIT Component.
2018-08-28T17:24:25.732Z,1535477065.732 [SBIT](IMPORTANT): git: 2018-08-28
2018-08-28T17:24:25.732Z,1535477065.732 [SBIT](INFO): git hash: d6107db9677002c22763a174f01a68f0b5afcf19
2018-08-28T17:24:25.733Z,1535477065.733 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-08-28T17:24:25.734Z,1535477065.734 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-08-28T17:24:25.735Z,1535477065.735 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2018-08-28T17:24:25.735Z,1535477065.735 [IBIT](INFO): Initialize IBIT Component.
2018-08-28T17:24:25.736Z,1535477065.736 [CBIT](DEBUG): Initialize CBIT Component.
2018-08-28T17:24:25.737Z,1535477065.737 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2018-08-28T17:24:25.737Z,1535477065.737 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-08-28T17:24:25.738Z,1535477065.738 [logger ThreadHandler](INFO): Handler Thread ID is 887
2018-08-28T17:24:25.757Z,1535477065.757 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 888
2018-08-28T17:24:25.763Z,1535477065.763 [Radio_Surface](INFO): Powering up
2018-08-28T17:24:25.769Z,1535477065.769 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 889
2018-08-28T17:24:25.770Z,1535477065.770 [Rowe_600LCM](INFO): Initializing
2018-08-28T17:24:25.770Z,1535477065.770 [Rowe_600LCM](INFO): Checking LCM
2018-08-28T17:24:25.849Z,1535477065.849 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-08-28T17:24:25.851Z,1535477065.851 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-08-28T17:24:25.852Z,1535477065.852 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-08-28T17:24:25.852Z,1535477065.852 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-08-28T17:24:25.884Z,1535477065.884 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-28T17:24:25.885Z,1535477065.885 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-28T17:24:25.885Z,1535477065.885 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-28T17:24:25.886Z,1535477065.886 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-08-28T17:24:25.886Z,1535477065.886 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-08-28T17:24:25.887Z,1535477065.887 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-08-28T17:24:25.897Z,1535477065.897 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 890
2018-08-28T17:24:25.899Z,1535477065.899 [CTD_Seabird](INFO): Initializing
2018-08-28T17:24:25.899Z,1535477065.899 [CTD_Seabird](INFO): Checking LCM
2018-08-28T17:24:26.018Z,1535477066.018 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 891
2018-08-28T17:24:26.026Z,1535477066.026 [WetLabsBB2FL](INFO): Powering down
2018-08-28T17:24:26.048Z,1535477066.048 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-08-28T17:24:26.105Z,1535477066.105 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 892
2018-08-28T17:24:26.121Z,1535477066.121 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI11M.000
2018-08-28T17:24:26.121Z,1535477066.121 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI11M.000
2018-08-28T17:24:26.121Z,1535477066.121 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5MI07M.000
2018-08-28T17:24:26.121Z,1535477066.121 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5MI07M.000
2018-08-28T17:24:26.122Z,1535477066.122 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH07M.000
2018-08-28T17:24:26.122Z,1535477066.122 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH07M.000
2018-08-28T17:24:26.122Z,1535477066.122 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH31M.000
2018-08-28T17:24:26.122Z,1535477066.122 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH31M.000
2018-08-28T17:24:26.186Z,1535477066.186 [MissionManager](DEBUG):
2018-08-28T17:24:26.187Z,1535477066.187 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-08-28T17:24:26.204Z,1535477066.204 [CTD_Seabird](INFO): LCM OK
2018-08-28T17:24:26.205Z,1535477066.205 [CTD_Seabird](INFO): Powering up
2018-08-28T17:24:26.205Z,1535477066.205 [Rowe_600LCM](INFO): LCM OK
2018-08-28T17:24:26.205Z,1535477066.205 [Rowe_600LCM](INFO): Powering up
2018-08-28T17:24:26.272Z,1535477066.272 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-08-28T17:24:26.273Z,1535477066.273 [Default:A.Wait](DEBUG): Construct Wait.
2018-08-28T17:24:26.275Z,1535477066.275 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-08-28T17:24:26.322Z,1535477066.322 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-08-28T17:24:26.325Z,1535477066.325 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-08-28T17:24:26.351Z,1535477066.351 [Default:E.Execute](DEBUG): Construct Execute.
2018-08-28T17:24:26.355Z,1535477066.355 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2018-08-28T17:24:26.366Z,1535477066.366 [controlThread](DEBUG): Component order: CycleStarter,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-08-28T17:24:26.390Z,1535477066.390 [AcousticModem_Benthos_ATM900](INFO): Powering up
2018-08-28T17:24:26.391Z,1535477066.391 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2018-08-28T17:24:26.416Z,1535477066.416 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-08-28T17:24:26.798Z,1535477066.798 [ESPComponent](INFO): powering down ESP
2018-08-28T17:24:27.323Z,1535477067.323 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-28T17:24:27.499Z,1535477067.499 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-08-28T17:24:27.505Z,1535477067.505 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-08-28T17:24:27.524Z,1535477067.524 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-08-28T17:24:27.533Z,1535477067.533 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-08-28T17:24:27.555Z,1535477067.555 [MassServo](DEBUG): Initializing EZServoServo.
2018-08-28T17:24:27.561Z,1535477067.561 [MassServo](DEBUG): Initializing MassServo.
2018-08-28T17:24:27.575Z,1535477067.575 [RudderServo](DEBUG): Initializing EZServoServo.
2018-08-28T17:24:27.581Z,1535477067.581 [RudderServo](DEBUG): Initializing RudderServo.
2018-08-28T17:24:27.595Z,1535477067.595 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-08-28T17:24:27.601Z,1535477067.601 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-08-28T17:24:27.856Z,1535477067.856 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-28T17:24:28.177Z,1535477068.177 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-28T17:24:28.513Z,1535477068.513 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-08-28T17:24:28.513Z,1535477068.513 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-08-28T17:24:28.513Z,1535477068.513 [BuoyancyServo] Communications Fault, FailCount= 1
2018-08-28T17:24:28.513Z,1535477068.513 [BuoyancyServo](ERROR): Communications Fault
2018-08-28T17:24:28.725Z,1535477068.725 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-08-28T17:24:28.815Z,1535477068.815 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-28T17:24:28.822Z,1535477068.822 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-08-28T17:24:28.823Z,1535477068.823 [BuoyancyServo](INFO): Powering down
2018-08-28T17:24:29.217Z,1535477069.217 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-28T17:24:29.596Z,1535477069.596 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-28T17:24:29.960Z,1535477069.960 [Aanderaa_O2](INFO): Powering down
2018-08-28T17:24:30.111Z,1535477070.111 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-28T17:24:30.310Z,1535477070.310 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-28T17:24:30.412Z,1535477070.412 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-28T17:24:30.455Z,1535477070.455 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-28T17:24:30.584Z,1535477070.584 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-28T17:24:30.584Z,1535477070.584 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-28T17:24:30.585Z,1535477070.585 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-28T17:24:30.906Z,1535477070.906 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-08-28T17:24:30.906Z,1535477070.906 [BuoyancyServo] No Fault, FailCount= 1
2018-08-28T17:24:31.050Z,1535477071.050 [CommandLine](IMPORTANT): got command
2018-08-28T17:24:31.051Z,1535477071.051 [CommandLine](FAULT): Incomplete syntax. Try: help
2018-08-28T17:24:31.403Z,1535477071.403 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-08-28T17:24:31.404Z,1535477071.404 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-08-28T17:24:31.436Z,1535477071.436 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-08-28T17:24:31.736Z,1535477071.736 [CTD_Seabird](INFO): Started Seabird LCM interface with command:nohup ./lrauv-framework/onboard/bin/gpctd -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyC6 -b 9600 >& /dev/null &
2018-08-28T17:24:31.737Z,1535477071.737 [CTD_Seabird](INFO): LCM subscribed to channel:seabird_gpctd_t.seabird-gpctd
2018-08-28T17:24:32.825Z,1535477072.825 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-08-28T17:24:32.825Z,1535477072.825 [CTD_Seabird](INFO): Powering down
2018-08-28T17:24:33.717Z,1535477073.717 [CommandLine](IMPORTANT): got command failComponent
2018-08-28T17:24:33.718Z,1535477073.718 [CommandLine](IMPORTANT): Failed components:
2018-08-28T17:24:33.718Z,1535477073.718 [CommandLine](IMPORTANT): No failed Components.
2018-08-28T17:24:34.055Z,1535477074.055 [AcousticModem_Benthos_ATM900](DEBUG):
2018-08-28T17:24:35.258Z,1535477075.258 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2018-08-28T17:24:35.655Z,1535477075.655 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2018-08-28T17:24:35.655Z,1535477075.655 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2018-08-28T17:24:35.656Z,1535477075.656 [AcousticModem_Benthos_ATM900](DEBUG): Jan 16 2000 19:29:09
2018-08-28T17:24:36.055Z,1535477076.055 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: battery low
2018-08-28T17:24:36.856Z,1535477076.856 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2018-08-28T17:24:37.255Z,1535477077.255 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2018-08-28T17:24:37.255Z,1535477077.255 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2018-08-28T17:24:37.256Z,1535477077.256 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2018-08-28T17:24:37.654Z,1535477077.654 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2018-08-28T17:24:38.054Z,1535477078.054 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2018-08-28T17:24:38.055Z,1535477078.055 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2018-08-28T17:24:38.455Z,1535477078.455 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2018-08-28T17:24:50.188Z,1535477090.188 [SBIT](IMPORTANT): Beginning Startup BIT
2018-08-28T17:24:50.193Z,1535477090.193 [CBIT](IMPORTANT): Beginning ground fault scan
2018-08-28T17:24:52.076Z,1535477092.076 [NAL9602](INFO): Powering up NAL9602
2018-08-28T17:25:01.462Z,1535477101.462 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.008777
CHAN A1 (24V): -0.014011
CHAN A2 (12V): -0.005393
CHAN A3 (5V): -0.004355
CHAN B0 (3.3V): -0.001682
CHAN B1 (3.15aV): -0.001509
CHAN B2 (3.15bV): -0.001614
CHAN B3 (GND): 0.000629
OPEN: 0.004758
Full Scale Calc: 4.765 mA, -1.589 mA
2018-08-28T17:25:02.899Z,1535477102.899 [NAL9602](INFO): NAL9602 initialized
2018-08-28T17:25:44.138Z,1535477144.138 [SBIT](IMPORTANT): SBIT PASSED
2018-08-28T17:25:44.238Z,1535477144.238 [CommandLine](IMPORTANT): got command configSet list
2018-08-28T17:25:44.238Z,1535477144.238 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-08-28T17:25:44.240Z,1535477144.240 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.loadAtStartup=0 bool;
2018-08-28T17:25:44.241Z,1535477144.241 [CommandLine](IMPORTANT): BPC1.loadAtStartup=0 bool;
2018-08-28T17:25:44.241Z,1535477144.241 [CommandLine](IMPORTANT): CTD_Seabird.minSalinityBound=0.01 practical_salinity_unit;
2018-08-28T17:25:44.241Z,1535477144.241 [CommandLine](IMPORTANT): Depth_Keller.offset=-0.56 decibar;
2018-08-28T17:25:44.241Z,1535477144.241 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;
2018-08-28T17:25:44.241Z,1535477144.241 [CommandLine](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_salinity 0.000500 practical_salinity_unit;
2018-08-28T17:25:44.241Z,1535477144.241 [CommandLine](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_temperature 0.005000 kelvin;
2018-08-28T17:25:44.241Z,1535477144.241 [CommandLine](IMPORTANT): Express linearApproximation WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 0.100000 microgram_per_liter;
2018-08-28T17:25:44.242Z,1535477144.242 [CommandLine](IMPORTANT): Express linearApproximation height_above_sea_floor 2.000000 meter;
2018-08-28T17:25:44.242Z,1535477144.242 [CommandLine](IMPORTANT): Express linearApproximation mass_concentration_of_chlorophyll_in_sea_water 1.000000 microgram_per_liter;
2018-08-28T17:25:44.242Z,1535477144.242 [CommandLine](IMPORTANT): IBIT.batteryHibernationTimeout=1 minute;
2018-08-28T17:25:44.242Z,1535477144.242 [CommandLine](IMPORTANT): IBIT.batteryMissingStickThreshold=18 count;
2018-08-28T17:25:44.242Z,1535477144.242 [CommandLine](IMPORTANT): NavChart.loadAtStartup=0 bool;
2018-08-28T17:25:44.242Z,1535477144.242 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool;
2018-08-28T17:25:44.242Z,1535477144.242 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=539 cubic_centimeter;
2018-08-28T17:25:44.242Z,1535477144.242 [CommandLine](IMPORTANT): VerticalControl.massDefault=-12 millimeter;
2018-08-28T17:25:44.479Z,1535477144.479 [MissionManager](IMPORTANT): Started mission Startup
2018-08-28T17:25:44.480Z,1535477144.480 [Startup] Running Loop=1
2018-08-28T17:25:44.480Z,1535477144.480 [Startup](DEBUG): Aggregate::initialize Startup
2018-08-28T17:25:44.480Z,1535477144.480 [Startup:A.GoToSurface] Running Loop=1
2018-08-28T17:25:44.480Z,1535477144.480 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-28T17:25:44.485Z,1535477144.485 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-28T17:25:44.486Z,1535477144.486 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-28T17:25:44.486Z,1535477144.486 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-28T17:25:44.486Z,1535477144.486 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-28T17:25:44.487Z,1535477144.487 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-28T17:25:44.498Z,1535477144.498 [Startup:StartupSatComms] Running Loop=1
2018-08-28T17:25:44.498Z,1535477144.498 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-08-28T17:25:44.498Z,1535477144.498 [Startup:StartupSatComms:A] Running Loop=1
2018-08-28T17:25:44.886Z,1535477144.886 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-08-28T17:26:26.973Z,1535477186.973 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-28T17:26:26.973Z,1535477186.973 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-08-28T17:26:26.973Z,1535477186.973 [Rowe_600LCM](ERROR): Communications Fault
2018-08-28T17:26:27.280Z,1535477187.280 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-28T17:26:27.377Z,1535477187.377 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-28T17:26:27.478Z,1535477187.478 [Rowe_600LCM](INFO): Powering down
2018-08-28T17:26:28.918Z,1535477188.918 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-28T17:26:28.918Z,1535477188.918 [Rowe_600LCM] No Fault, FailCount= 1
2018-08-28T17:26:29.093Z,1535477189.093 [Rowe_600LCM](INFO): Initializing
2018-08-28T17:26:29.094Z,1535477189.094 [Rowe_600LCM](INFO): Checking LCM
2018-08-28T17:26:29.094Z,1535477189.094 [Rowe_600LCM](INFO): LCM OK
2018-08-28T17:26:29.094Z,1535477189.094 [Rowe_600LCM](INFO): Powering up
2018-08-28T17:26:33.253Z,1535477193.253 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-28T17:26:33.376Z,1535477193.376 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-28T17:26:33.377Z,1535477193.377 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-28T17:26:33.378Z,1535477193.378 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-28T17:26:33.378Z,1535477193.378 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-28T17:26:44.872Z,1535477204.872 [Startup:StartupSatComms:A](INFO): Timed out from 2018-08-28T17:25:44.5Z
2018-08-28T17:26:44.872Z,1535477204.872 [Startup:StartupSatComms:A] Stopped
2018-08-28T17:26:44.872Z,1535477204.872 [Startup:StartupSatComms:B] Running Loop=1
2018-08-28T17:26:45.272Z,1535477205.272 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-08-28T17:27:26.062Z,1535477246.062 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-28T17:27:26.062Z,1535477246.062 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-08-28T17:27:26.062Z,1535477246.062 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-28T17:27:26.124Z,1535477246.124 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-28T17:27:26.512Z,1535477246.512 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-28T17:27:26.512Z,1535477246.512 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-08-28T17:27:26.868Z,1535477246.868 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-28T17:27:26.869Z,1535477246.869 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-28T17:27:26.869Z,1535477246.869 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-28T17:27:44.881Z,1535477264.881 [Startup:StartupSatComms:B](INFO): Timed out from 2018-08-28T17:26:44.9Z
2018-08-28T17:27:44.881Z,1535477264.881 [Startup:StartupSatComms:B] Stopped
2018-08-28T17:27:44.882Z,1535477264.882 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-08-28T17:27:44.882Z,1535477264.882 [Startup:StartupSatComms] Stopped
2018-08-28T17:27:44.882Z,1535477264.882 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-08-28T17:27:44.883Z,1535477264.883 [Startup](INFO): Completed Startup
2018-08-28T17:27:44.883Z,1535477264.883 [MissionManager](INFO): Startup is completed.
2018-08-28T17:27:44.883Z,1535477264.883 [MissionManager](INFO): Uninitializing Mission Startup
2018-08-28T17:27:44.883Z,1535477264.883 [Startup] Stopped
2018-08-28T17:27:44.883Z,1535477264.883 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-08-28T17:27:44.884Z,1535477264.884 [Startup:A.GoToSurface] Stopped
2018-08-28T17:27:44.884Z,1535477264.884 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-08-28T17:27:45.289Z,1535477265.289 [MissionManager](IMPORTANT): Started mission Default
2018-08-28T17:27:45.289Z,1535477265.289 [Default] Running Loop=1
2018-08-28T17:27:45.289Z,1535477265.289 [Default](DEBUG): Aggregate::initialize Default
2018-08-28T17:27:45.289Z,1535477265.289 [Default:B.GoToSurface] Running Loop=1
2018-08-28T17:27:45.290Z,1535477265.290 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-28T17:27:45.290Z,1535477265.290 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-28T17:27:45.290Z,1535477265.290 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-28T17:27:45.290Z,1535477265.290 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-28T17:27:45.291Z,1535477265.291 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-28T17:27:45.291Z,1535477265.291 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-28T17:27:45.291Z,1535477265.291 [Default:A.Wait] Running Loop=1
2018-08-28T17:27:45.292Z,1535477265.292 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-08-28T17:27:58.469Z,1535477278.469 [Default:A.Wait](INFO): Done Waiting.
2018-08-28T17:27:58.469Z,1535477278.469 [Default:A.Wait] Stopped
2018-08-28T17:27:58.469Z,1535477278.469 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-08-28T17:27:58.871Z,1535477278.871 [Default:CheckIn] Running Loop=1
2018-08-28T17:27:58.871Z,1535477278.871 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-28T17:27:58.871Z,1535477278.871 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-28T17:27:59.317Z,1535477279.317 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-08-28T17:28:09.266Z,1535477289.266 [CommandLine](IMPORTANT): got command failComponent
2018-08-28T17:28:09.266Z,1535477289.266 [CommandLine](IMPORTANT): Failed components:
2018-08-28T17:28:09.267Z,1535477289.267 [CommandLine](IMPORTANT): No failed Components.
2018-08-28T17:28:10.044Z,1535477290.044 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004099
2018-08-28T17:28:29.157Z,1535477309.157 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-28T17:28:29.157Z,1535477309.157 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-08-28T17:28:29.157Z,1535477309.157 [Rowe_600LCM](ERROR): Communications Fault
2018-08-28T17:28:29.382Z,1535477309.382 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-28T17:28:29.561Z,1535477309.561 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-28T17:28:29.766Z,1535477309.766 [Rowe_600LCM](INFO): Powering down
2018-08-28T17:28:31.322Z,1535477311.322 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-28T17:28:31.322Z,1535477311.322 [Rowe_600LCM] No Fault, FailCount= 2
2018-08-28T17:28:31.381Z,1535477311.381 [Rowe_600LCM](INFO): Initializing
2018-08-28T17:28:31.382Z,1535477311.382 [Rowe_600LCM](INFO): Checking LCM
2018-08-28T17:28:31.382Z,1535477311.382 [Rowe_600LCM](INFO): LCM OK
2018-08-28T17:28:31.382Z,1535477311.382 [Rowe_600LCM](INFO): Powering up
2018-08-28T17:28:35.503Z,1535477315.503 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-28T17:28:35.562Z,1535477315.562 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-28T17:28:35.563Z,1535477315.563 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-28T17:28:35.563Z,1535477315.563 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-28T17:28:35.564Z,1535477315.564 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-28T17:28:42.123Z,1535477322.123 [CommandLine](IMPORTANT): got command configSet Rowe_600LCM.loadAtStartup 0.000000 bool
2018-08-28T17:28:42.123Z,1535477322.123 [CommandLine](FAULT): configSet Rowe_600LCM.loadAtStartup without persist will have no effect.
2018-08-28T17:28:42.757Z,1535477322.757 [Rowe_600LCM](IMPORTANT): Stopping now due to load at startup. No immediate restart required.
2018-08-28T17:28:42.758Z,1535477322.758 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-28T17:28:42.959Z,1535477322.959 [Rowe_600LCM](INFO): Powering down
2018-08-28T17:30:06.054Z,1535477406.054 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-08-28T17:30:26.898Z,1535477426.898 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-28T17:30:26.898Z,1535477426.898 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2018-08-28T17:30:26.898Z,1535477426.898 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-28T17:30:26.912Z,1535477426.912 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-08-28T17:30:27.295Z,1535477427.295 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-28T17:30:27.295Z,1535477427.295 [BPC1] Communications Fault, FailCount= 1
2018-08-28T17:30:27.295Z,1535477427.295 [BPC1](ERROR): Communications Fault
2018-08-28T17:30:27.318Z,1535477427.318 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-28T17:30:27.319Z,1535477427.319 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-08-28T17:30:27.319Z,1535477427.319 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2018-08-28T17:30:27.706Z,1535477427.706 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-28T17:30:27.706Z,1535477427.706 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-28T17:30:27.707Z,1535477427.707 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-28T17:30:28.526Z,1535477428.526 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-28T17:30:28.526Z,1535477428.526 [BPC1] No Fault, FailCount= 1
2018-08-28T17:31:07.603Z,1535477467.603 [CommandLine](IMPORTANT): got command restart application
2018-08-28T17:31:08.609Z,1535477468.609 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2018-08-28T17:31:08.612Z,1535477468.612 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-28T17:31:08.613Z,1535477468.613 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:08.749Z,1535477468.749 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2018-08-28T17:31:08.749Z,1535477468.749 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:08.750Z,1535477468.750 [CommandLine](INFO): Join timeout helper Thread ID is 943
2018-08-28T17:31:08.750Z,1535477468.750 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-08-28T17:31:08.750Z,1535477468.750 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:08.751Z,1535477468.751 [NavChartDb](INFO): Join timeout helper Thread ID is 944
2018-08-28T17:31:08.909Z,1535477468.909 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-28T17:31:08.909Z,1535477468.909 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:08.913Z,1535477468.913 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-08-28T17:31:08.913Z,1535477468.913 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:08.913Z,1535477468.913 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 945
2018-08-28T17:31:08.937Z,1535477468.937 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-28T17:31:08.937Z,1535477468.937 [WetLabsBB2FL](INFO): Powering down
2018-08-28T17:31:08.938Z,1535477468.938 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:08.941Z,1535477468.941 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2018-08-28T17:31:08.941Z,1535477468.941 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:08.941Z,1535477468.941 [CTD_Seabird](INFO): Join timeout helper Thread ID is 946
2018-08-28T17:31:08.977Z,1535477468.977 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-28T17:31:09.075Z,1535477469.075 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-08-28T17:31:09.075Z,1535477469.075 [CTD_Seabird](INFO): Powering down
2018-08-28T17:31:09.076Z,1535477469.076 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:09.089Z,1535477469.089 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2018-08-28T17:31:09.089Z,1535477469.089 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:09.090Z,1535477469.090 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 948
2018-08-28T17:31:09.265Z,1535477469.265 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-28T17:31:09.266Z,1535477469.266 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-28T17:31:09.471Z,1535477469.471 [Rowe_600LCM](INFO): Powering down
2018-08-28T17:31:09.472Z,1535477469.472 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:09.490Z,1535477469.490 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-08-28T17:31:09.490Z,1535477469.490 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:09.491Z,1535477469.491 [Radio_Surface](INFO): Join timeout helper Thread ID is 950
2018-08-28T17:31:09.633Z,1535477469.633 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-28T17:31:09.633Z,1535477469.633 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:09.654Z,1535477469.654 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-08-28T17:31:09.654Z,1535477469.654 [logger ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:09.654Z,1535477469.654 [logger](INFO): Join timeout helper Thread ID is 951
2018-08-28T17:31:09.668Z,1535477469.668 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-28T17:31:09.669Z,1535477469.669 [logger ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:09.670Z,1535477469.670 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-08-28T17:31:09.670Z,1535477469.670 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:09.670Z,1535477469.670 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-08-28T17:31:09.670Z,1535477469.670 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:09.671Z,1535477469.671 [controlThread](INFO): Join timeout helper Thread ID is 952
2018-08-28T17:31:09.731Z,1535477469.731 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-08-28T17:31:09.731Z,1535477469.731 [controlThread](DEBUG): Uninitializing ControlThread
2018-08-28T17:31:09.731Z,1535477469.731 [AcousticModem_Benthos_ATM900](INFO): Powering down
2018-08-28T17:31:09.850Z,1535477469.850 [NAL9602](INFO): Powering down
2018-08-28T17:31:09.852Z,1535477469.852 [PNI_TCM](INFO): Powering down
2018-08-28T17:31:09.942Z,1535477469.942 [Aanderaa_O2](INFO): Powering down
2018-08-28T17:31:09.945Z,1535477469.945 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-08-28T17:31:09.946Z,1535477469.946 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-08-28T17:31:09.947Z,1535477469.947 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-08-28T17:31:09.947Z,1535477469.947 [MissionManager](INFO): Uninitializing Mission Default
2018-08-28T17:31:09.947Z,1535477469.947 [Default] Stopped
2018-08-28T17:31:09.948Z,1535477469.948 [Default](DEBUG): Aggregate::uninitialize Default
2018-08-28T17:31:09.948Z,1535477469.948 [Default:B.GoToSurface] Stopped
2018-08-28T17:31:09.948Z,1535477469.948 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-08-28T17:31:09.948Z,1535477469.948 [Default:CheckIn] Stopped
2018-08-28T17:31:09.948Z,1535477469.948 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-28T17:31:09.948Z,1535477469.948 [Default:CheckIn:Read_GPS] Stopped
2018-08-28T17:31:09.952Z,1535477469.952 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-08-28T17:31:09.952Z,1535477469.952 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-08-28T17:31:09.952Z,1535477469.952 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-08-28T17:31:09.953Z,1535477469.953 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-08-28T17:31:09.953Z,1535477469.953 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-08-28T17:31:09.953Z,1535477469.953 [BuoyancyServo](INFO): Powering down
2018-08-28T17:31:09.965Z,1535477469.965 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-08-28T17:31:09.965Z,1535477469.965 [ElevatorServo](INFO): Powering down
2018-08-28T17:31:09.966Z,1535477469.966 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-08-28T17:31:09.966Z,1535477469.966 [MassServo](INFO): Powering down
2018-08-28T17:31:09.967Z,1535477469.967 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-08-28T17:31:09.967Z,1535477469.967 [RudderServo](INFO): Powering down
2018-08-28T17:31:09.968Z,1535477469.968 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-08-28T17:31:09.968Z,1535477469.968 [ThrusterServo](INFO): Powering down
2018-08-28T17:31:09.969Z,1535477469.969 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-08-28T17:31:09.970Z,1535477469.970 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-08-28T17:31:09.970Z,1535477469.970 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-08-28T17:31:09.971Z,1535477469.971 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:10.075Z,1535477470.075 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:10.082Z,1535477470.082 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:10.121Z,1535477470.121 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:10.126Z,1535477470.126 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:10.172Z,1535477470.172 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-08-28T17:31:10.229Z,1535477470.229 [logger ThreadHandler](INFO): Thread cancelled.