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.