2017-10-12T18:58:47.576Z,1507834727.576 [Supervisor](DEBUG): Initializing supervisor. 2017-10-12T18:58:47.579Z,1507834727.579 [SyncHandler](DEBUG): Created PCaller Thread at 4051A4E0 2017-10-12T18:58:47.579Z,1507834727.579 [SyncHandler](INFO): Protected caller Thread ID is 3109 2017-10-12T18:58:47.580Z,1507834727.580 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2017-10-12T18:58:47.581Z,1507834727.581 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4054A4E0 2017-10-12T18:58:47.581Z,1507834727.581 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3110 2017-10-12T18:58:47.584Z,1507834727.584 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2017-10-12T18:58:47.597Z,1507834727.597 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2017-10-12T18:58:47.598Z,1507834727.598 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4057A4E0 2017-10-12T18:58:47.598Z,1507834727.598 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3111 2017-10-12T18:58:47.599Z,1507834727.599 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2017-10-12T18:58:47.600Z,1507834727.600 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405AA4E0 2017-10-12T18:58:47.600Z,1507834727.600 [logger ThreadHandler](INFO): Protected caller Thread ID is 3112 2017-10-12T18:58:47.603Z,1507834727.603 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2017-10-12T18:58:47.603Z,1507834727.603 [Supervisor](INFO): Looking for Config files in directory: Config/ 2017-10-12T18:58:47.605Z,1507834727.605 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2017-10-12T18:58:47.799Z,1507834727.799 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2017-10-12T18:58:47.800Z,1507834727.800 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2017-10-12T18:58:47.917Z,1507834727.917 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2017-10-12T18:58:47.917Z,1507834727.917 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2017-10-12T18:58:48.208Z,1507834728.208 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2017-10-12T18:58:48.209Z,1507834728.209 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2017-10-12T18:58:48.497Z,1507834728.497 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2017-10-12T18:58:48.498Z,1507834728.498 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2017-10-12T18:58:48.858Z,1507834728.858 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2017-10-12T18:58:48.858Z,1507834728.858 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2017-10-12T18:58:49.378Z,1507834729.378 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2017-10-12T18:58:49.378Z,1507834729.378 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2017-10-12T18:58:49.831Z,1507834729.831 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2017-10-12T18:58:49.831Z,1507834729.831 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2017-10-12T18:58:50.321Z,1507834730.321 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2017-10-12T18:58:50.322Z,1507834730.322 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2017-10-12T18:58:50.494Z,1507834730.494 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2017-10-12T18:58:50.959Z,1507834730.959 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2017-10-12T18:58:50.960Z,1507834730.960 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2017-10-12T18:58:51.123Z,1507834731.123 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2017-10-12T18:58:51.123Z,1507834731.123 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2017-10-12T18:58:51.363Z,1507834731.363 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2017-10-12T18:58:51.364Z,1507834731.364 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2017-10-12T18:58:51.665Z,1507834731.665 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2017-10-12T18:58:51.666Z,1507834731.666 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2017-10-12T18:58:51.788Z,1507834731.788 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2017-10-12T18:58:51.788Z,1507834731.788 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2017-10-12T18:58:52.042Z,1507834732.042 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2017-10-12T18:58:52.045Z,1507834732.045 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2017-10-12T18:58:52.045Z,1507834732.045 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2017-10-12T18:58:52.339Z,1507834732.339 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2017-10-12T18:58:52.340Z,1507834732.340 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2017-10-12T18:58:52.434Z,1507834732.434 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2017-10-12T18:58:52.590Z,1507834732.590 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2017-10-12T18:58:52.698Z,1507834732.698 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2017-10-12T18:58:52.804Z,1507834732.804 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2017-10-12T18:58:52.963Z,1507834732.963 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2017-10-12T18:58:53.205Z,1507834733.205 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2017-10-12T18:58:53.317Z,1507834733.317 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2017-10-12T18:58:53.493Z,1507834733.493 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2017-10-12T18:58:53.670Z,1507834733.670 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2017-10-12T18:58:53.770Z,1507834733.770 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/ 2017-10-12T18:58:53.771Z,1507834733.771 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2017-10-12T18:58:53.772Z,1507834733.772 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2017-10-12T18:58:53.907Z,1507834733.907 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2017-10-12T18:58:53.907Z,1507834733.907 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2017-10-12T18:58:53.930Z,1507834733.930 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2017-10-12T18:58:53.930Z,1507834733.930 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2017-10-12T18:58:53.969Z,1507834733.969 [DepthRateCalculator] Loaded 2017-10-12T18:58:53.969Z,1507834733.969 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2017-10-12T18:58:53.975Z,1507834733.975 [PitchRateCalculator] Loaded 2017-10-12T18:58:53.976Z,1507834733.976 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2017-10-12T18:58:53.992Z,1507834733.992 [SpeedCalculator] Loaded 2017-10-12T18:58:53.993Z,1507834733.993 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2017-10-12T18:58:54.015Z,1507834734.015 [TempGradientCalculator] Loaded 2017-10-12T18:58:54.016Z,1507834734.016 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2017-10-12T18:58:54.033Z,1507834734.033 [VerticalTemperatureHomogeneityIndexCalculator] Loaded 2017-10-12T18:58:54.033Z,1507834734.033 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread. 2017-10-12T18:58:54.039Z,1507834734.039 [YawRateCalculator] Loaded 2017-10-12T18:58:54.039Z,1507834734.039 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2017-10-12T18:58:54.039Z,1507834734.039 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2017-10-12T18:58:54.040Z,1507834734.040 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2017-10-12T18:58:54.079Z,1507834734.079 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2017-10-12T18:58:54.079Z,1507834734.079 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2017-10-12T18:58:54.538Z,1507834734.538 [AcousticModem_Benthos_ATM900] Loaded 2017-10-12T18:58:54.539Z,1507834734.539 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread. 2017-10-12T18:58:54.675Z,1507834734.675 [DataOverHttps] Loaded 2017-10-12T18:58:54.676Z,1507834734.676 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2017-10-12T18:58:54.691Z,1507834734.691 [Depth_Keller] Loaded 2017-10-12T18:58:54.691Z,1507834734.691 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2017-10-12T18:58:54.696Z,1507834734.696 [DropWeight] Loaded 2017-10-12T18:58:54.697Z,1507834734.697 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2017-10-12T18:58:54.806Z,1507834734.806 [NAL9602] Loaded 2017-10-12T18:58:54.807Z,1507834734.807 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2017-10-12T18:58:54.824Z,1507834734.824 [Onboard] Loaded 2017-10-12T18:58:54.824Z,1507834734.824 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2017-10-12T18:58:54.835Z,1507834734.835 [Radio_Surface] Loaded 2017-10-12T18:58:54.835Z,1507834734.835 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2017-10-12T18:58:54.837Z,1507834734.837 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408864E0 2017-10-12T18:58:54.837Z,1507834734.837 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3192 2017-10-12T18:58:54.994Z,1507834734.994 [PNI_TCM] Loaded 2017-10-12T18:58:54.994Z,1507834734.994 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2017-10-12T18:58:55.060Z,1507834735.060 [Rowe_600LCM] Loaded 2017-10-12T18:58:55.060Z,1507834735.060 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread. 2017-10-12T18:58:55.061Z,1507834735.061 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 408B64E0 2017-10-12T18:58:55.062Z,1507834735.062 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 3193 2017-10-12T18:58:57.183Z,1507834737.183 [BPC1] Loaded 2017-10-12T18:58:57.183Z,1507834737.183 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2017-10-12T18:58:57.184Z,1507834737.184 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2017-10-12T18:58:57.184Z,1507834737.184 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2017-10-12T18:58:57.331Z,1507834737.331 [SBIT](DEBUG): Construct Startup Built In Test. 2017-10-12T18:58:57.361Z,1507834737.361 [SBIT] Loaded 2017-10-12T18:58:57.361Z,1507834737.361 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2017-10-12T18:58:57.362Z,1507834737.362 [IBIT](DEBUG): Construct Initiated Built In Test. 2017-10-12T18:58:57.375Z,1507834737.375 [IBIT] Loaded 2017-10-12T18:58:57.376Z,1507834737.376 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2017-10-12T18:58:57.379Z,1507834737.379 [CBIT](DEBUG): Construct Continuous Built In Test. 2017-10-12T18:58:57.558Z,1507834737.558 [CBIT] Loaded 2017-10-12T18:58:57.558Z,1507834737.558 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2017-10-12T18:58:57.558Z,1507834737.558 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2017-10-12T18:58:57.559Z,1507834737.559 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2017-10-12T18:58:57.735Z,1507834737.735 [Aanderaa_O2] Loaded 2017-10-12T18:58:57.735Z,1507834737.735 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2017-10-12T18:58:57.827Z,1507834737.827 [CTD_NeilBrown] Loaded 2017-10-12T18:58:57.827Z,1507834737.827 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2017-10-12T18:58:57.829Z,1507834737.829 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409724E0 2017-10-12T18:58:57.829Z,1507834737.829 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 3194 2017-10-12T18:58:57.831Z,1507834737.831 [ESPComponent](CRITICAL): Could not find element ESPComponent.secLoadControl 2017-10-12T18:58:57.832Z,1507834737.832 [ESPComponent](ERROR): Could not open device '/dev/invalid' at ESPComponent.secLoadControl 2017-10-12T18:58:57.848Z,1507834737.848 [ESPComponent] Loaded 2017-10-12T18:58:57.849Z,1507834737.849 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2017-10-12T18:58:57.864Z,1507834737.864 [PAR_Licor] Loaded 2017-10-12T18:58:57.864Z,1507834737.864 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2017-10-12T18:58:57.916Z,1507834737.916 [WetLabsBB2FL] Loaded 2017-10-12T18:58:57.917Z,1507834737.917 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2017-10-12T18:58:57.918Z,1507834737.918 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409A24E0 2017-10-12T18:58:57.918Z,1507834737.918 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 3195 2017-10-12T18:58:57.919Z,1507834737.919 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2017-10-12T18:58:57.919Z,1507834737.919 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2017-10-12T18:58:58.191Z,1507834738.191 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2017-10-12T18:58:58.192Z,1507834738.192 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2017-10-12T18:58:58.276Z,1507834738.276 [VerticalControl](DEBUG): Construct VerticalControl. 2017-10-12T18:58:58.383Z,1507834738.383 [VerticalControl] Loaded 2017-10-12T18:58:58.384Z,1507834738.384 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2017-10-12T18:58:58.385Z,1507834738.385 [HorizontalControl](DEBUG): Construct HorizontalControl. 2017-10-12T18:58:58.455Z,1507834738.455 [HorizontalControl] Loaded 2017-10-12T18:58:58.456Z,1507834738.456 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2017-10-12T18:58:58.456Z,1507834738.456 [SpeedControl](DEBUG): Construct SpeedControl. 2017-10-12T18:58:58.462Z,1507834738.462 [SpeedControl] Loaded 2017-10-12T18:58:58.463Z,1507834738.463 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2017-10-12T18:58:58.463Z,1507834738.463 [LoopControl](DEBUG): Construct LoopControl. 2017-10-12T18:58:58.464Z,1507834738.464 [LoopControl] Loaded 2017-10-12T18:58:58.464Z,1507834738.464 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2017-10-12T18:58:58.465Z,1507834738.465 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2017-10-12T18:58:58.465Z,1507834738.465 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2017-10-12T18:58:58.583Z,1507834738.583 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC 2017-10-12T18:58:58.583Z,1507834738.583 [StratificationFrontDetector](DEBUG): (re)initializing 2017-10-12T18:58:58.584Z,1507834738.584 [StratificationFrontDetector] Loaded 2017-10-12T18:58:58.584Z,1507834738.584 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2017-10-12T18:58:58.585Z,1507834738.585 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2017-10-12T18:58:58.585Z,1507834738.585 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2017-10-12T18:58:58.702Z,1507834738.702 [BuoyancyServo] Loaded 2017-10-12T18:58:58.702Z,1507834738.702 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2017-10-12T18:58:58.715Z,1507834738.715 [ElevatorServo] Loaded 2017-10-12T18:58:58.715Z,1507834738.715 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2017-10-12T18:58:58.727Z,1507834738.727 [MassServo] Loaded 2017-10-12T18:58:58.727Z,1507834738.727 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2017-10-12T18:58:58.740Z,1507834738.740 [RudderServo] Loaded 2017-10-12T18:58:58.740Z,1507834738.740 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2017-10-12T18:58:58.752Z,1507834738.752 [ThrusterServo] Loaded 2017-10-12T18:58:58.753Z,1507834738.753 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2017-10-12T18:58:58.753Z,1507834738.753 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2017-10-12T18:58:58.754Z,1507834738.754 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2017-10-12T18:58:58.879Z,1507834738.879 [DeadReckonUsingMultipleVelocitySources] Loaded 2017-10-12T18:58:58.880Z,1507834738.880 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2017-10-12T18:58:58.942Z,1507834738.942 [DeadReckonUsingSpeedCalculator] Loaded 2017-10-12T18:58:58.942Z,1507834738.942 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2017-10-12T18:58:58.960Z,1507834738.960 [NavChart] Loaded 2017-10-12T18:58:58.961Z,1507834738.961 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2017-10-12T18:58:58.965Z,1507834738.965 [UniversalFixResidualReporter] Loaded 2017-10-12T18:58:58.965Z,1507834738.965 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2017-10-12T18:58:58.966Z,1507834738.966 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2017-10-12T18:58:58.974Z,1507834738.974 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2017-10-12T18:58:58.975Z,1507834738.975 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2017-10-12T18:58:58.984Z,1507834738.984 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2017-10-12T18:58:58.985Z,1507834738.985 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AEA4E0 2017-10-12T18:58:58.985Z,1507834738.985 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3196 2017-10-12T18:58:58.997Z,1507834738.997 [Supervisor](INFO): Main Thread ID is 3108 2017-10-12T18:58:58.997Z,1507834738.997 [Supervisor](DEBUG): Running supervisor. 2017-10-12T18:58:58.998Z,1507834738.998 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3197 2017-10-12T18:58:59.001Z,1507834739.001 [controlThread ThreadHandler](INFO): Handler Thread ID is 3198 2017-10-12T18:58:59.001Z,1507834739.001 [controlThread](DEBUG): Initializing ControlThread 2017-10-12T18:58:59.002Z,1507834739.002 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2017-10-12T18:58:59.002Z,1507834739.002 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2017-10-12T18:58:59.003Z,1507834739.003 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2017-10-12T18:58:59.003Z,1507834739.003 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2017-10-12T18:58:59.004Z,1507834739.004 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing 2017-10-12T18:58:59.005Z,1507834739.005 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2017-10-12T18:58:59.011Z,1507834739.011 [SBIT](INFO): Initialize SBIT Component. 2017-10-12T18:58:59.012Z,1507834739.012 [SBIT](IMPORTANT): git: 2017-08-02-49-g78aae0d 2017-10-12T18:58:59.012Z,1507834739.012 [SBIT](INFO): git hash: 78aae0d749b8a9454d229118b7b3470c376f1b25 2017-10-12T18:58:59.012Z,1507834739.012 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2017-10-12T18:58:59.014Z,1507834739.014 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 Kernel Reported: #2 PREEMPT Tue Oct 3 09:53:58 PDT 2017 2017-10-12T18:58:59.015Z,1507834739.015 [SBIT](INFO): Beginning SBIT in 63.000000 seconds. 2017-10-12T18:58:59.015Z,1507834739.015 [IBIT](INFO): Initialize IBIT Component. 2017-10-12T18:58:59.016Z,1507834739.016 [CBIT](DEBUG): Initialize CBIT Component. 2017-10-12T18:58:59.016Z,1507834739.016 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2017-10-12T18:58:59.017Z,1507834739.017 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2017-10-12T18:58:59.017Z,1507834739.017 [logger ThreadHandler](INFO): Handler Thread ID is 3199 2017-10-12T18:58:59.019Z,1507834739.019 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3200 2017-10-12T18:58:59.039Z,1507834739.039 [Radio_Surface](INFO): Powering up 2017-10-12T18:58:59.041Z,1507834739.041 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 3201 2017-10-12T18:58:59.041Z,1507834739.041 [Rowe_600LCM](INFO): Initializing 2017-10-12T18:58:59.042Z,1507834739.042 [Rowe_600LCM](INFO): Checking LCM 2017-10-12T18:58:59.094Z,1507834739.094 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 3202 2017-10-12T18:58:59.095Z,1507834739.095 [CTD_NeilBrown](INFO): Powering down 2017-10-12T18:58:59.112Z,1507834739.112 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2017-10-12T18:58:59.114Z,1507834739.114 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2017-10-12T18:58:59.115Z,1507834739.115 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2017-10-12T18:58:59.115Z,1507834739.115 [LoopControl](DEBUG): Initialize LoopControlComponent. 2017-10-12T18:58:59.117Z,1507834739.117 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2017-10-12T18:58:59.118Z,1507834739.118 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2017-10-12T18:58:59.119Z,1507834739.119 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2017-10-12T18:58:59.119Z,1507834739.119 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2017-10-12T18:58:59.119Z,1507834739.119 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2017-10-12T18:58:59.124Z,1507834739.124 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2017-10-12T18:58:59.125Z,1507834739.125 [NavChart](DEBUG): Initialize NavChart Navigation. 2017-10-12T18:58:59.126Z,1507834739.126 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2017-10-12T18:58:59.149Z,1507834739.149 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2017-10-12T18:58:59.238Z,1507834739.238 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3204 2017-10-12T18:58:59.240Z,1507834739.240 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 3203 2017-10-12T18:58:59.249Z,1507834739.249 [WetLabsBB2FL](INFO): Powering down 2017-10-12T18:58:59.266Z,1507834739.266 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2017-10-12T18:58:59.267Z,1507834739.267 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2017-10-12T18:58:59.267Z,1507834739.267 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2017-10-12T18:58:59.267Z,1507834739.267 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2017-10-12T18:58:59.267Z,1507834739.267 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2017-10-12T18:58:59.268Z,1507834739.268 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2017-10-12T18:58:59.268Z,1507834739.268 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2017-10-12T18:58:59.269Z,1507834739.269 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2017-10-12T18:58:59.269Z,1507834739.269 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2017-10-12T18:58:59.269Z,1507834739.269 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2017-10-12T18:58:59.269Z,1507834739.269 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2017-10-12T18:58:59.270Z,1507834739.270 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2017-10-12T18:58:59.270Z,1507834739.270 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2017-10-12T18:58:59.270Z,1507834739.270 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2017-10-12T18:58:59.270Z,1507834739.270 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2017-10-12T18:58:59.270Z,1507834739.270 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2017-10-12T18:58:59.273Z,1507834739.273 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2017-10-12T18:58:59.370Z,1507834739.370 [MissionManager](DEBUG): 2017-10-12T18:58:59.371Z,1507834739.371 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2017-10-12T18:58:59.394Z,1507834739.394 [Rowe_600LCM](INFO): LCM OK 2017-10-12T18:58:59.394Z,1507834739.394 [Rowe_600LCM](INFO): Powering up 2017-10-12T18:58:59.448Z,1507834739.448 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2017-10-12T18:58:59.449Z,1507834739.449 [Default:A.Wait](DEBUG): Construct Wait. 2017-10-12T18:58:59.451Z,1507834739.451 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2017-10-12T18:58:59.487Z,1507834739.487 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2017-10-12T18:58:59.490Z,1507834739.490 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2017-10-12T18:58:59.528Z,1507834739.528 [Default:E.Execute](DEBUG): Construct Execute. 2017-10-12T18:58:59.531Z,1507834739.531 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn 300 Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2017-10-12T18:58:59.541Z,1507834739.541 [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,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2017-10-12T18:58:59.567Z,1507834739.567 [AcousticModem_Benthos_ATM900](INFO): Powering up 2017-10-12T18:58:59.568Z,1507834739.568 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2017-10-12T18:58:59.628Z,1507834739.628 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2017-10-12T18:58:59.670Z,1507834739.670 [Depth_Keller](ERROR): Pressure reading out of range: 1895.584351 decibar 2017-10-12T18:58:59.944Z,1507834739.944 [ESPComponent](INFO): powering down ESP 2017-10-12T18:59:00.309Z,1507834740.309 [DepthRateCalculator](ERROR): Depth measurement is not active 2017-10-12T18:59:00.421Z,1507834740.421 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-10-12T18:59:00.563Z,1507834740.563 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-10-12T18:59:00.717Z,1507834740.717 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2017-10-12T18:59:00.724Z,1507834740.724 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2017-10-12T18:59:00.756Z,1507834740.756 [ElevatorServo](DEBUG): Initializing EZServoServo. 2017-10-12T18:59:00.761Z,1507834740.761 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2017-10-12T18:59:00.787Z,1507834740.787 [MassServo](DEBUG): Initializing EZServoServo. 2017-10-12T18:59:00.796Z,1507834740.796 [MassServo](DEBUG): Initializing MassServo. 2017-10-12T18:59:00.810Z,1507834740.810 [RudderServo](DEBUG): Initializing EZServoServo. 2017-10-12T18:59:00.812Z,1507834740.812 [RudderServo](DEBUG): Initializing RudderServo. 2017-10-12T18:59:00.834Z,1507834740.834 [ThrusterServo](DEBUG): Initializing EZServoServo. 2017-10-12T18:59:00.840Z,1507834740.840 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2017-10-12T18:59:00.889Z,1507834740.889 [CommandLine](FAULT): Scheduling is paused 2017-10-12T18:59:00.890Z,1507834740.890 [CBIT](INFO): Critical error at 20171012T185857 2017-10-12T18:59:00.890Z,1507834740.890 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2017-10-12T18:59:01.187Z,1507834741.187 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2017-10-12T18:59:01.187Z,1507834741.187 [DropWeight] Hardware Fault, FailCount= 1 2017-10-12T18:59:01.187Z,1507834741.187 [DropWeight](ERROR): Hardware Fault 2017-10-12T18:59:01.195Z,1507834741.195 [NAL9602](INFO): Powering up NAL9602 2017-10-12T18:59:01.255Z,1507834741.255 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-10-12T18:59:01.256Z,1507834741.256 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-10-12T18:59:01.592Z,1507834741.592 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2017-10-12T18:59:01.592Z,1507834741.592 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2017-10-12T18:59:01.592Z,1507834741.592 [BuoyancyServo] Communications Fault, FailCount= 1 2017-10-12T18:59:01.593Z,1507834741.593 [BuoyancyServo](ERROR): Communications Fault 2017-10-12T18:59:01.858Z,1507834741.858 [CBIT](INFO): Critical error at 20171012T185901 2017-10-12T18:59:01.860Z,1507834741.860 [CBIT](ERROR): Hardware Fault in component: DropWeight 2017-10-12T18:59:01.861Z,1507834741.861 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2017-10-12T18:59:01.861Z,1507834741.861 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2017-10-12T18:59:03.791Z,1507834743.791 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2017-10-12T18:59:03.931Z,1507834743.931 [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 38400 >& /dev/null & 2017-10-12T18:59:04.210Z,1507834744.210 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2017-10-12T18:59:04.211Z,1507834744.211 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2017-10-12T18:59:04.221Z,1507834744.221 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2017-10-12T18:59:11.517Z,1507834751.517 [Aanderaa_O2](DEBUG): Error parsing data: StartupInfo 4831F 14 Mode AADI Smart Sensor Terminal Protocol RS232 Protocol Version 3 Config Version 12 2017-10-12T18:59:11.517Z,1507834751.517 [Aanderaa_O2] Data Fault, FailCount= 1 2017-10-12T18:59:11.517Z,1507834751.517 [Aanderaa_O2](ERROR): Data Fault 2017-10-12T18:59:11.537Z,1507834751.537 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-10-12T18:59:11.538Z,1507834751.538 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-10-12T18:59:11.576Z,1507834751.576 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2017-10-12T18:59:11.578Z,1507834751.578 [BuoyancyServo](INFO): Powering down 2017-10-12T18:59:11.758Z,1507834751.758 [CBIT](INFO): Critical error at 20171012T185901 2017-10-12T18:59:11.760Z,1507834751.760 [CBIT](ERROR): Data Fault in component: Aanderaa_O2 2017-10-12T18:59:11.855Z,1507834751.855 [Aanderaa_O2](INFO): Powering down 2017-10-12T18:59:11.953Z,1507834751.953 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-10-12T18:59:11.954Z,1507834751.954 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-10-12T18:59:12.182Z,1507834752.182 [NAL9602](INFO): NAL9602 initialized 2017-10-12T18:59:12.258Z,1507834752.258 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-10-12T18:59:12.259Z,1507834752.259 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-10-12T18:59:12.581Z,1507834752.581 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003717 2017-10-12T18:59:12.644Z,1507834752.644 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-10-12T18:59:12.660Z,1507834752.660 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-10-12T18:59:12.793Z,1507834752.793 [CBIT](INFO): Clearing failed state for component Aanderaa_O2 2017-10-12T18:59:12.793Z,1507834752.793 [Aanderaa_O2] No Fault, FailCount= 1 2017-10-12T18:59:13.040Z,1507834753.040 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-10-12T18:59:13.042Z,1507834753.042 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-10-12T18:59:13.442Z,1507834753.442 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-10-12T18:59:13.443Z,1507834753.443 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-10-12T18:59:13.488Z,1507834753.488 [MassServo](FAULT): Overload Error 2017-10-12T18:59:13.488Z,1507834753.488 [MassServo] Hardware Fault, FailCount= 1 2017-10-12T18:59:13.488Z,1507834753.488 [MassServo](ERROR): Hardware Fault 2017-10-12T18:59:13.493Z,1507834753.493 [CBIT](ERROR): Hardware Fault in component: MassServo 2017-10-12T18:59:13.957Z,1507834753.957 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-10-12T18:59:13.957Z,1507834753.957 [MassServo](INFO): Powering down 2017-10-12T18:59:14.032Z,1507834754.032 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2017-10-12T18:59:14.032Z,1507834754.032 [BuoyancyServo] No Fault, FailCount= 1 2017-10-12T18:59:14.259Z,1507834754.259 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2017-10-12T18:59:14.259Z,1507834754.259 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2017-10-12T18:59:14.627Z,1507834754.627 [Aanderaa_O2](DEBUG): Error parsing data: StartupInfo 4831F 14 Mode AADI Smart Sensor Terminal Protocol RS232 Protocol Version 3 Config Version 12 2017-10-12T18:59:14.627Z,1507834754.627 [Aanderaa_O2] Data Fault, FailCount= 2 2017-10-12T18:59:14.627Z,1507834754.627 [Aanderaa_O2](ERROR): Data Fault 2017-10-12T18:59:14.679Z,1507834754.679 [MassServo](DEBUG): Initializing EZServoServo. 2017-10-12T18:59:14.679Z,1507834754.679 [MassServo](DEBUG): Initializing MassServo. 2017-10-12T18:59:14.689Z,1507834754.689 [CBIT](ERROR): Data Fault in component: Aanderaa_O2 2017-10-12T18:59:14.689Z,1507834754.689 [CBIT](INFO): Clearing failed state for component MassServo 2017-10-12T18:59:14.689Z,1507834754.689 [MassServo] No Fault, FailCount= 1 2017-10-12T18:59:15.023Z,1507834755.023 [BPC1](FAULT): Failed to initialize 2017-10-12T18:59:15.023Z,1507834755.023 [BPC1] Communications Fault, FailCount= 1 2017-10-12T18:59:15.023Z,1507834755.023 [BPC1](ERROR): Communications Fault 2017-10-12T18:59:15.034Z,1507834755.034 [Aanderaa_O2](INFO): Powering down 2017-10-12T18:59:15.174Z,1507834755.174 [CBIT](ERROR): Communications Fault in component: BPC1 2017-10-12T18:59:15.985Z,1507834755.985 [CBIT](INFO): Clearing failed state for component Aanderaa_O2 2017-10-12T18:59:15.986Z,1507834755.986 [Aanderaa_O2] No Fault, FailCount= 2 2017-10-12T18:59:16.317Z,1507834756.317 [CBIT](INFO): Clearing failed state for component BPC1 2017-10-12T18:59:16.317Z,1507834756.317 [BPC1] No Fault, FailCount= 1 2017-10-12T18:59:17.809Z,1507834757.809 [Aanderaa_O2](DEBUG): Error parsing data: StartupInfo 4831F 14 Mode AADI Smart Sensor Terminal Protocol RS232 Protocol Version 3 Config Version 12 2017-10-12T18:59:17.809Z,1507834757.809 [Aanderaa_O2] Data Fault, FailCount= 3 2017-10-12T18:59:17.809Z,1507834757.809 [Aanderaa_O2](ERROR): Data Fault 2017-10-12T18:59:17.918Z,1507834757.918 [CBIT](ERROR): Data Fault in component: Aanderaa_O2 2017-10-12T18:59:17.918Z,1507834757.918 [CBIT](FAULT): Data Fault in component: Aanderaa_O2 2017-10-12T18:59:18.209Z,1507834758.209 [Aanderaa_O2](INFO): Powering down 2017-10-12T18:59:18.729Z,1507834758.729 [MassServo](FAULT): Overload Error 2017-10-12T18:59:18.729Z,1507834758.729 [MassServo] Hardware Fault, FailCount= 2 2017-10-12T18:59:18.729Z,1507834758.729 [MassServo](ERROR): Hardware Fault 2017-10-12T18:59:18.734Z,1507834758.734 [CBIT](ERROR): Hardware Fault in component: MassServo 2017-10-12T18:59:19.090Z,1507834759.090 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-10-12T18:59:19.090Z,1507834759.090 [MassServo](INFO): Powering down 2017-10-12T18:59:19.776Z,1507834759.776 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface 2017-10-12T18:59:19.776Z,1507834759.776 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 1 2017-10-12T18:59:19.776Z,1507834759.776 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault 2017-10-12T18:59:19.899Z,1507834759.899 [MassServo](DEBUG): Initializing EZServoServo. 2017-10-12T18:59:19.899Z,1507834759.899 [MassServo](DEBUG): Initializing MassServo. 2017-10-12T18:59:19.921Z,1507834759.921 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900 2017-10-12T18:59:19.922Z,1507834759.922 [CBIT](INFO): Clearing failed state for component MassServo 2017-10-12T18:59:19.922Z,1507834759.922 [MassServo] No Fault, FailCount= 2 2017-10-12T18:59:20.176Z,1507834760.176 [AcousticModem_Benthos_ATM900](INFO): Powering down 2017-10-12T18:59:21.131Z,1507834761.131 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900 2017-10-12T18:59:21.131Z,1507834761.131 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 1 2017-10-12T18:59:21.828Z,1507834761.828 [MassServo](FAULT): Mass shifter EEPROM initialization uart error serial timeout 2017-10-12T18:59:21.828Z,1507834761.828 [MassServo] Communications Fault, FailCount= 3 2017-10-12T18:59:21.828Z,1507834761.828 [MassServo](ERROR): Communications Fault 2017-10-12T18:59:21.833Z,1507834761.833 [CBIT](ERROR): Communications Fault in component: MassServo 2017-10-12T18:59:21.941Z,1507834761.941 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-10-12T18:59:21.941Z,1507834761.941 [MassServo](INFO): Powering down 2017-10-12T18:59:22.745Z,1507834762.745 [MassServo](DEBUG): Initializing EZServoServo. 2017-10-12T18:59:22.745Z,1507834762.745 [MassServo](DEBUG): Initializing MassServo. 2017-10-12T18:59:22.759Z,1507834762.759 [CBIT](INFO): Clearing failed state for component MassServo 2017-10-12T18:59:22.759Z,1507834762.759 [MassServo] No Fault, FailCount= 3 2017-10-12T18:59:23.440Z,1507834763.440 [AcousticModem_Benthos_ATM900](INFO): Powering up 2017-10-12T18:59:23.440Z,1507834763.440 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2017-10-12T18:59:23.887Z,1507834763.887 [PNI_TCM](ERROR): CRC does not match. Expected:0x19063 got:0x47049 2017-10-12T18:59:26.784Z,1507834766.784 [MassServo](FAULT): Overload Error 2017-10-12T18:59:26.784Z,1507834766.784 [MassServo] Hardware Fault, FailCount= 4 2017-10-12T18:59:26.785Z,1507834766.784 [MassServo](ERROR): Hardware Fault 2017-10-12T18:59:26.793Z,1507834766.793 [CBIT](ERROR): Hardware Fault in component: MassServo 2017-10-12T18:59:27.131Z,1507834767.131 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-10-12T18:59:27.131Z,1507834767.131 [MassServo](INFO): Powering down 2017-10-12T18:59:27.938Z,1507834767.938 [MassServo](DEBUG): Initializing EZServoServo. 2017-10-12T18:59:27.938Z,1507834767.938 [MassServo](DEBUG): Initializing MassServo. 2017-10-12T18:59:27.960Z,1507834767.960 [CBIT](INFO): Clearing failed state for component MassServo 2017-10-12T18:59:27.960Z,1507834767.960 [MassServo] No Fault, FailCount= 4 2017-10-12T18:59:31.901Z,1507834771.901 [BPC1](FAULT): Failed to initialize 2017-10-12T18:59:31.901Z,1507834771.901 [BPC1] Communications Fault, FailCount= 2 2017-10-12T18:59:31.901Z,1507834771.901 [B