2017-10-30T23:00:18.710Z,1509404418.710 [Supervisor](DEBUG): Initializing supervisor.
2017-10-30T23:00:18.714Z,1509404418.714 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2017-10-30T23:00:18.715Z,1509404418.715 [SyncHandler](INFO): Protected caller Thread ID is 806
2017-10-30T23:00:18.716Z,1509404418.716 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2017-10-30T23:00:18.719Z,1509404418.719 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2017-10-30T23:00:18.720Z,1509404418.720 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 807
2017-10-30T23:00:18.726Z,1509404418.726 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2017-10-30T23:00:18.752Z,1509404418.752 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2017-10-30T23:00:18.754Z,1509404418.754 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2017-10-30T23:00:18.754Z,1509404418.754 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 808
2017-10-30T23:00:18.756Z,1509404418.756 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2017-10-30T23:00:18.758Z,1509404418.758 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2017-10-30T23:00:18.759Z,1509404418.759 [logger ThreadHandler](INFO): Protected caller Thread ID is 809
2017-10-30T23:00:18.764Z,1509404418.764 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2017-10-30T23:00:18.765Z,1509404418.765 [Supervisor](INFO): Looking for Config files in directory: Config/
2017-10-30T23:00:18.771Z,1509404418.771 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2017-10-30T23:00:18.883Z,1509404418.883 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2017-10-30T23:00:18.885Z,1509404418.885 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2017-10-30T23:00:19.010Z,1509404419.010 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2017-10-30T23:00:19.012Z,1509404419.012 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2017-10-30T23:00:19.252Z,1509404419.252 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2017-10-30T23:00:19.252Z,1509404419.252 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2017-10-30T23:00:19.561Z,1509404419.561 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2017-10-30T23:00:19.563Z,1509404419.563 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2017-10-30T23:00:19.966Z,1509404419.966 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2017-10-30T23:00:19.967Z,1509404419.967 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2017-10-30T23:00:20.501Z,1509404420.501 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2017-10-30T23:00:20.502Z,1509404420.502 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2017-10-30T23:00:21.006Z,1509404421.006 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2017-10-30T23:00:21.007Z,1509404421.007 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2017-10-30T23:00:21.519Z,1509404421.519 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2017-10-30T23:00:21.521Z,1509404421.521 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2017-10-30T23:00:21.615Z,1509404421.615 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2017-10-30T23:00:21.974Z,1509404421.974 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2017-10-30T23:00:21.974Z,1509404421.974 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2017-10-30T23:00:22.123Z,1509404422.123 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2017-10-30T23:00:22.124Z,1509404422.124 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2017-10-30T23:00:22.381Z,1509404422.381 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2017-10-30T23:00:22.383Z,1509404422.383 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2017-10-30T23:00:22.619Z,1509404422.619 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2017-10-30T23:00:22.619Z,1509404422.619 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2017-10-30T23:00:22.726Z,1509404422.726 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2017-10-30T23:00:22.727Z,1509404422.727 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2017-10-30T23:00:22.886Z,1509404422.886 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2017-10-30T23:00:22.888Z,1509404422.888 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2017-10-30T23:00:22.891Z,1509404422.891 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2017-10-30T23:00:23.157Z,1509404423.157 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2017-10-30T23:00:23.158Z,1509404423.158 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2017-10-30T23:00:23.259Z,1509404423.259 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2017-10-30T23:00:23.418Z,1509404423.418 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2017-10-30T23:00:23.532Z,1509404423.532 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2017-10-30T23:00:23.632Z,1509404423.632 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2017-10-30T23:00:23.782Z,1509404423.782 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2017-10-30T23:00:23.974Z,1509404423.974 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2017-10-30T23:00:24.090Z,1509404424.090 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2017-10-30T23:00:24.194Z,1509404424.194 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2017-10-30T23:00:24.305Z,1509404424.305 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2017-10-30T23:00:24.404Z,1509404424.404 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2017-10-30T23:00:24.407Z,1509404424.407 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2017-10-30T23:00:24.551Z,1509404424.551 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2017-10-30T23:00:24.552Z,1509404424.552 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2017-10-30T23:00:24.576Z,1509404424.576 [Module Loader](CRITICAL): Could not find element LcmListener.loadAtStartup
2017-10-30T23:00:24.576Z,1509404424.576 [Module Loader](CRITICAL): Could not find element LcmPublisher.loadAtStartup
2017-10-30T23:00:24.577Z,1509404424.577 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2017-10-30T23:00:24.577Z,1509404424.577 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2017-10-30T23:00:24.625Z,1509404424.625 [DepthRateCalculator] Loaded
2017-10-30T23:00:24.625Z,1509404424.625 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2017-10-30T23:00:24.631Z,1509404424.631 [PitchRateCalculator] Loaded
2017-10-30T23:00:24.631Z,1509404424.631 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2017-10-30T23:00:24.655Z,1509404424.655 [SpeedCalculator] Loaded
2017-10-30T23:00:24.655Z,1509404424.655 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2017-10-30T23:00:24.677Z,1509404424.677 [TempGradientCalculator] Loaded
2017-10-30T23:00:24.677Z,1509404424.677 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2017-10-30T23:00:24.694Z,1509404424.694 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2017-10-30T23:00:24.694Z,1509404424.694 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2017-10-30T23:00:24.706Z,1509404424.706 [YawRateCalculator] Loaded
2017-10-30T23:00:24.707Z,1509404424.707 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2017-10-30T23:00:24.707Z,1509404424.707 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2017-10-30T23:00:24.708Z,1509404424.708 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2017-10-30T23:00:24.745Z,1509404424.745 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2017-10-30T23:00:24.746Z,1509404424.746 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2017-10-30T23:00:25.252Z,1509404425.252 [AcousticModem_Benthos_ATM900] Loaded
2017-10-30T23:00:25.253Z,1509404425.253 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2017-10-30T23:00:25.416Z,1509404425.416 [DataOverHttps] Loaded
2017-10-30T23:00:25.416Z,1509404425.416 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2017-10-30T23:00:25.436Z,1509404425.436 [Depth_Keller] Loaded
2017-10-30T23:00:25.436Z,1509404425.436 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2017-10-30T23:00:25.441Z,1509404425.441 [DropWeight] Loaded
2017-10-30T23:00:25.441Z,1509404425.441 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2017-10-30T23:00:25.548Z,1509404425.548 [NAL9602] Loaded
2017-10-30T23:00:25.548Z,1509404425.548 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2017-10-30T23:00:25.567Z,1509404425.567 [Onboard] Loaded
2017-10-30T23:00:25.567Z,1509404425.567 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2017-10-30T23:00:25.578Z,1509404425.578 [Radio_Surface] Loaded
2017-10-30T23:00:25.578Z,1509404425.578 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2017-10-30T23:00:25.579Z,1509404425.579 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407A44E0
2017-10-30T23:00:25.580Z,1509404425.580 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 888
2017-10-30T23:00:25.633Z,1509404425.633 [PNI_TCM] Loaded
2017-10-30T23:00:25.633Z,1509404425.633 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2017-10-30T23:00:25.703Z,1509404425.703 [Rowe_600LCM] Loaded
2017-10-30T23:00:25.703Z,1509404425.703 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2017-10-30T23:00:25.705Z,1509404425.705 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 407D44E0
2017-10-30T23:00:25.706Z,1509404425.706 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 889
2017-10-30T23:00:27.804Z,1509404427.804 [BPC1] Loaded
2017-10-30T23:00:27.804Z,1509404427.804 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2017-10-30T23:00:27.805Z,1509404427.805 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2017-10-30T23:00:27.807Z,1509404427.807 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2017-10-30T23:00:27.964Z,1509404427.964 [SBIT](DEBUG): Construct Startup Built In Test.
2017-10-30T23:00:27.991Z,1509404427.991 [SBIT] Loaded
2017-10-30T23:00:27.991Z,1509404427.991 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2017-10-30T23:00:27.992Z,1509404427.992 [IBIT](DEBUG): Construct Initiated Built In Test.
2017-10-30T23:00:28.003Z,1509404428.003 [IBIT] Loaded
2017-10-30T23:00:28.004Z,1509404428.004 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2017-10-30T23:00:28.007Z,1509404428.007 [CBIT](DEBUG): Construct Continuous Built In Test.
2017-10-30T23:00:28.157Z,1509404428.157 [CBIT] Loaded
2017-10-30T23:00:28.157Z,1509404428.157 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2017-10-30T23:00:28.158Z,1509404428.158 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2017-10-30T23:00:28.158Z,1509404428.158 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2017-10-30T23:00:28.334Z,1509404428.334 [Aanderaa_O2] Loaded
2017-10-30T23:00:28.334Z,1509404428.334 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2017-10-30T23:00:28.412Z,1509404428.412 [CTD_NeilBrown] Loaded
2017-10-30T23:00:28.412Z,1509404428.412 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2017-10-30T23:00:28.413Z,1509404428.413 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408944E0
2017-10-30T23:00:28.414Z,1509404428.414 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 890
2017-10-30T23:00:28.431Z,1509404428.431 [ESPComponent] Loaded
2017-10-30T23:00:28.431Z,1509404428.431 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2017-10-30T23:00:28.445Z,1509404428.445 [PAR_Licor] Loaded
2017-10-30T23:00:28.446Z,1509404428.446 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2017-10-30T23:00:28.496Z,1509404428.496 [WetLabsBB2FL] Loaded
2017-10-30T23:00:28.496Z,1509404428.496 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2017-10-30T23:00:28.497Z,1509404428.497 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408C44E0
2017-10-30T23:00:28.498Z,1509404428.498 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 891
2017-10-30T23:00:28.498Z,1509404428.498 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2017-10-30T23:00:28.499Z,1509404428.499 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2017-10-30T23:00:28.778Z,1509404428.778 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2017-10-30T23:00:28.779Z,1509404428.779 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2017-10-30T23:00:28.868Z,1509404428.868 [VerticalControl](DEBUG): Construct VerticalControl.
2017-10-30T23:00:28.968Z,1509404428.968 [VerticalControl] Loaded
2017-10-30T23:00:28.968Z,1509404428.968 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2017-10-30T23:00:28.969Z,1509404428.969 [HorizontalControl](DEBUG): Construct HorizontalControl.
2017-10-30T23:00:29.031Z,1509404429.031 [HorizontalControl] Loaded
2017-10-30T23:00:29.031Z,1509404429.031 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2017-10-30T23:00:29.032Z,1509404429.032 [SpeedControl](DEBUG): Construct SpeedControl.
2017-10-30T23:00:29.038Z,1509404429.038 [SpeedControl] Loaded
2017-10-30T23:00:29.038Z,1509404429.038 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2017-10-30T23:00:29.039Z,1509404429.039 [LoopControl](DEBUG): Construct LoopControl.
2017-10-30T23:00:29.039Z,1509404429.039 [LoopControl] Loaded
2017-10-30T23:00:29.039Z,1509404429.039 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2017-10-30T23:00:29.040Z,1509404429.040 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2017-10-30T23:00:29.041Z,1509404429.041 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2017-10-30T23:00:29.160Z,1509404429.160 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2017-10-30T23:00:29.160Z,1509404429.160 [StratificationFrontDetector](DEBUG): (re)initializing
2017-10-30T23:00:29.160Z,1509404429.160 [StratificationFrontDetector] Loaded
2017-10-30T23:00:29.161Z,1509404429.161 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2017-10-30T23:00:29.161Z,1509404429.161 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2017-10-30T23:00:29.162Z,1509404429.162 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2017-10-30T23:00:29.281Z,1509404429.281 [BuoyancyServo] Loaded
2017-10-30T23:00:29.281Z,1509404429.281 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2017-10-30T23:00:29.293Z,1509404429.293 [ElevatorServo] Loaded
2017-10-30T23:00:29.293Z,1509404429.293 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2017-10-30T23:00:29.304Z,1509404429.304 [MassServo] Loaded
2017-10-30T23:00:29.305Z,1509404429.305 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2017-10-30T23:00:29.316Z,1509404429.316 [RudderServo] Loaded
2017-10-30T23:00:29.316Z,1509404429.316 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2017-10-30T23:00:29.328Z,1509404429.328 [ThrusterServo] Loaded
2017-10-30T23:00:29.328Z,1509404429.328 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2017-10-30T23:00:29.328Z,1509404429.328 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2017-10-30T23:00:29.330Z,1509404429.330 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2017-10-30T23:00:29.443Z,1509404429.443 [DeadReckonUsingMultipleVelocitySources] Loaded
2017-10-30T23:00:29.443Z,1509404429.443 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2017-10-30T23:00:29.499Z,1509404429.499 [DeadReckonUsingSpeedCalculator] Loaded
2017-10-30T23:00:29.500Z,1509404429.500 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2017-10-30T23:00:29.516Z,1509404429.516 [NavChart] Loaded
2017-10-30T23:00:29.516Z,1509404429.516 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2017-10-30T23:00:29.520Z,1509404429.520 [UniversalFixResidualReporter] Loaded
2017-10-30T23:00:29.521Z,1509404429.521 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2017-10-30T23:00:29.521Z,1509404429.521 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2017-10-30T23:00:29.525Z,1509404429.525 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2017-10-30T23:00:29.526Z,1509404429.526 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2017-10-30T23:00:29.533Z,1509404429.533 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2017-10-30T23:00:29.534Z,1509404429.534 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A154E0
2017-10-30T23:00:29.534Z,1509404429.534 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 892
2017-10-30T23:00:29.539Z,1509404429.539 [Supervisor](INFO): Main Thread ID is 802
2017-10-30T23:00:29.539Z,1509404429.539 [Supervisor](DEBUG): Running supervisor.
2017-10-30T23:00:29.540Z,1509404429.540 [CommandLine ThreadHandler](INFO): Handler Thread ID is 893
2017-10-30T23:00:29.542Z,1509404429.542 [controlThread ThreadHandler](INFO): Handler Thread ID is 894
2017-10-30T23:00:29.543Z,1509404429.543 [controlThread](DEBUG): Initializing ControlThread
2017-10-30T23:00:29.544Z,1509404429.544 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2017-10-30T23:00:29.544Z,1509404429.544 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2017-10-30T23:00:29.544Z,1509404429.544 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2017-10-30T23:00:29.545Z,1509404429.545 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2017-10-30T23:00:29.545Z,1509404429.545 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2017-10-30T23:00:29.546Z,1509404429.546 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2017-10-30T23:00:29.551Z,1509404429.551 [SBIT](INFO): Initialize SBIT Component.
2017-10-30T23:00:29.552Z,1509404429.552 [SBIT](IMPORTANT): git: 2017-10-16-91-g1cda494
2017-10-30T23:00:29.552Z,1509404429.552 [SBIT](INFO): git hash: 1cda4942dadce3e3c6eb9510eb040eaf1a2b49d6
2017-10-30T23:00:29.552Z,1509404429.552 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2017-10-30T23:00:29.554Z,1509404429.554 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #17 PREEMPT Fri Oct 6 17:22:04 PDT 2017
2017-10-30T23:00:29.555Z,1509404429.555 [SBIT](INFO): Beginning SBIT in 63.000000 seconds.
2017-10-30T23:00:29.555Z,1509404429.555 [IBIT](INFO): Initialize IBIT Component.
2017-10-30T23:00:29.556Z,1509404429.556 [CBIT](DEBUG): Initialize CBIT Component.
2017-10-30T23:00:29.556Z,1509404429.556 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2017-10-30T23:00:29.556Z,1509404429.556 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2017-10-30T23:00:29.557Z,1509404429.557 [logger ThreadHandler](INFO): Handler Thread ID is 895
2017-10-30T23:00:29.577Z,1509404429.577 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 896
2017-10-30T23:00:29.583Z,1509404429.583 [Radio_Surface](INFO): Powering up
2017-10-30T23:00:29.589Z,1509404429.589 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 897
2017-10-30T23:00:29.590Z,1509404429.590 [Rowe_600LCM](INFO): Initializing
2017-10-30T23:00:29.591Z,1509404429.591 [Rowe_600LCM](INFO): Checking LCM
2017-10-30T23:00:29.645Z,1509404429.645 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2017-10-30T23:00:29.647Z,1509404429.647 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2017-10-30T23:00:29.648Z,1509404429.648 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2017-10-30T23:00:29.648Z,1509404429.648 [LoopControl](DEBUG): Initialize LoopControlComponent.
2017-10-30T23:00:29.694Z,1509404429.694 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-10-30T23:00:29.695Z,1509404429.695 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-10-30T23:00:29.695Z,1509404429.695 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-10-30T23:00:29.695Z,1509404429.695 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-10-30T23:00:29.696Z,1509404429.696 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-10-30T23:00:29.696Z,1509404429.696 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-10-30T23:00:29.696Z,1509404429.696 [NavChart](DEBUG): Initialize NavChart Navigation.
2017-10-30T23:00:29.697Z,1509404429.697 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2017-10-30T23:00:29.698Z,1509404429.698 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 898
2017-10-30T23:00:29.698Z,1509404429.698 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2017-10-30T23:00:29.700Z,1509404429.700 [CTD_NeilBrown](INFO): Powering down
2017-10-30T23:00:29.725Z,1509404429.725 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 899
2017-10-30T23:00:29.726Z,1509404429.726 [WetLabsBB2FL](INFO): Powering down
2017-10-30T23:00:29.862Z,1509404429.862 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 900
2017-10-30T23:00:29.875Z,1509404429.875 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2017-10-30T23:00:29.875Z,1509404429.875 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2017-10-30T23:00:29.875Z,1509404429.875 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2017-10-30T23:00:29.875Z,1509404429.875 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2017-10-30T23:00:29.875Z,1509404429.875 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2017-10-30T23:00:29.875Z,1509404429.875 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2017-10-30T23:00:29.876Z,1509404429.876 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2017-10-30T23:00:29.876Z,1509404429.876 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2017-10-30T23:00:29.876Z,1509404429.876 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2017-10-30T23:00:29.876Z,1509404429.876 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2017-10-30T23:00:29.876Z,1509404429.876 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2017-10-30T23:00:29.877Z,1509404429.877 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2017-10-30T23:00:29.877Z,1509404429.877 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2017-10-30T23:00:29.877Z,1509404429.877 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2017-10-30T23:00:29.877Z,1509404429.877 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2017-10-30T23:00:29.877Z,1509404429.877 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2017-10-30T23:00:29.896Z,1509404429.896 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2017-10-30T23:00:29.969Z,1509404429.969 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2017-10-30T23:00:29.970Z,1509404429.970 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2017-10-30T23:00:30.066Z,1509404430.066 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2017-10-30T23:00:30.068Z,1509404430.068 [Default:A.Wait](DEBUG): Construct Wait.
2017-10-30T23:00:30.072Z,1509404430.072 [Rowe_600LCM](INFO): LCM OK
2017-10-30T23:00:30.073Z,1509404430.073 [Rowe_600LCM](INFO): Powering up
2017-10-30T23:00:30.097Z,1509404430.097 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2017-10-30T23:00:30.123Z,1509404430.123 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2017-10-30T23:00:30.125Z,1509404430.125 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2017-10-30T23:00:30.151Z,1509404430.151 [Default:E.Execute](DEBUG): Construct Execute.
2017-10-30T23:00:30.160Z,1509404430.160 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Guidance="Tethys/Guidance"
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Sequence/>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Sequence/>
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Sequence/>
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn 300</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2017-10-30T23:00:30.166Z,1509404430.166 [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-30T23:00:30.197Z,1509404430.197 [AcousticModem_Benthos_ATM900](INFO): Powering up
2017-10-30T23:00:30.197Z,1509404430.197 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2017-10-30T23:00:30.219Z,1509404430.219 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2017-10-30T23:00:30.581Z,1509404430.581 [ESPComponent](INFO): powering down ESP
2017-10-30T23:00:31.097Z,1509404431.097 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-10-30T23:00:31.197Z,1509404431.197 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-10-30T23:00:31.301Z,1509404431.301 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2017-10-30T23:00:31.309Z,1509404431.309 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2017-10-30T23:00:31.324Z,1509404431.324 [ElevatorServo](DEBUG): Initializing EZServoServo.
2017-10-30T23:00:31.329Z,1509404431.329 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2017-10-30T23:00:31.339Z,1509404431.339 [MassServo](DEBUG): Initializing EZServoServo.
2017-10-30T23:00:31.345Z,1509404431.345 [MassServo](DEBUG): Initializing MassServo.
2017-10-30T23:00:31.367Z,1509404431.367 [RudderServo](DEBUG): Initializing EZServoServo.
2017-10-30T23:00:31.373Z,1509404431.373 [RudderServo](DEBUG): Initializing RudderServo.
2017-10-30T23:00:31.386Z,1509404431.386 [ThrusterServo](DEBUG): Initializing EZServoServo.
2017-10-30T23:00:31.393Z,1509404431.393 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2017-10-30T23:00:31.427Z,1509404431.427 [CommandLine](FAULT): Scheduling is paused
2017-10-30T23:00:31.427Z,1509404431.427 [CBIT](INFO): Critical error at 20171030T230029
2017-10-30T23:00:31.427Z,1509404431.427 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2017-10-30T23:00:31.658Z,1509404431.658 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-10-30T23:00:31.659Z,1509404431.659 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-10-30T23:00:34.011Z,1509404434.011 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2017-10-30T23:00:34.140Z,1509404434.140 [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-30T23:00:34.318Z,1509404434.318 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2017-10-30T23:00:34.319Z,1509404434.319 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2017-10-30T23:00:34.319Z,1509404434.319 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2017-10-30T23:00:41.321Z,1509404441.321 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-10-30T23:00:41.323Z,1509404441.323 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-10-30T23:00:41.691Z,1509404441.691 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-10-30T23:00:41.692Z,1509404441.692 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-10-30T23:00:42.075Z,1509404442.075 [Aanderaa_O2](INFO): Powering down
2017-10-30T23:00:42.147Z,1509404442.147 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-10-30T23:00:42.148Z,1509404442.148 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-10-30T23:00:42.441Z,1509404442.441 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003741
2017-10-30T23:00:42.524Z,1509404442.524 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-10-30T23:00:42.526Z,1509404442.526 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-10-30T23:00:42.920Z,1509404442.920 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-10-30T23:00:42.922Z,1509404442.922 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-10-30T23:00:43.315Z,1509404443.315 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-10-30T23:00:43.316Z,1509404443.316 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-10-30T23:00:46.869Z,1509404446.869 [BPC1](ERROR): Failed to parse bank A battery data
2017-10-30T23:00:46.869Z,1509404446.869 [BPC1] Data Fault, FailCount= 1
2017-10-30T23:00:46.869Z,1509404446.869 [BPC1](ERROR): Data Fault
2017-10-30T23:00:47.014Z,1509404447.014 [CBIT](ERROR): Data Fault in component: BPC1
2017-10-30T23:00:48.219Z,1509404448.219 [CBIT](INFO): Clearing failed state for component BPC1
2017-10-30T23:00:48.219Z,1509404448.219 [BPC1] No Fault, FailCount= 1
2017-10-30T23:00:50.436Z,1509404450.436 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2017-10-30T23:00:50.436Z,1509404450.436 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 1
2017-10-30T23:00:50.436Z,1509404450.436 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2017-10-30T23:00:50.537Z,1509404450.537 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2017-10-30T23:00:50.836Z,1509404450.836 [AcousticModem_Benthos_ATM900](INFO): Powering down
2017-10-30T23:00:51.745Z,1509404451.745 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2017-10-30T23:00:51.746Z,1509404451.746 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 1
2017-10-30T23:00:54.036Z,1509404454.036 [AcousticModem_Benthos_ATM900](INFO): Powering up
2017-10-30T23:00:54.036Z,1509404454.036 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2017-10-30T23:00:55.643Z,1509404455.643 [NAL9602](INFO): Powering up NAL9602
2017-10-30T23:01:08.493Z,1509404468.493 [BPC1](ERROR): Failed to parse bank B battery data
2017-10-30T23:01:08.493Z,1509404468.493 [BPC1] Data Fault, FailCount= 2
2017-10-30T23:01:08.493Z,1509404468.493 [BPC1](ERROR): Data Fault
2017-10-30T23:01:08.591Z,1509404468.591 [CBIT](ERROR): Data Fault in component: BPC1
2017-10-30T23:01:09.770Z,1509404469.770 [CBIT](INFO): Clearing failed state for component BPC1
2017-10-30T23:01:09.770Z,1509404469.770 [BPC1] No Fault, FailCount= 2
2017-10-30T23:01:14.436Z,1509404474.436 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2017-10-30T23:01:14.436Z,1509404474.436 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 2
2017-10-30T23:01:14.436Z,1509404474.436 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2017-10-30T23:01:14.555Z,1509404474.555 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2017-10-30T23:01:14.836Z,1509404474.836 [AcousticModem_Benthos_ATM900](INFO): Powering down
2017-10-30T23:01:15.761Z,1509404475.761 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2017-10-30T23:01:15.761Z,1509404475.761 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 2
2017-10-30T23:01:16.843Z,1509404476.843 [NAL9602](ERROR): NAL9602 initialization error.
2017-10-30T23:01:16.843Z,1509404476.843 [NAL9602] Communications Fault, FailCount= 1
2017-10-30T23:01:16.843Z,1509404476.843 [NAL9602](ERROR): Communications Fault
2017-10-30T23:01:16.939Z,1509404476.939 [CBIT](ERROR): Communications Fault in component: NAL9602
2017-10-30T23:01:17.242Z,1509404477.242 [NAL9602](INFO): Powering down
2017-10-30T23:01:18.036Z,1509404478.036 [AcousticModem_Benthos_ATM900](INFO): Powering up
2017-10-30T23:01:18.036Z,1509404478.036 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2017-10-30T23:01:18.139Z,1509404478.139 [CBIT](INFO): Clearing failed state for component NAL9602
2017-10-30T23:01:18.139Z,1509404478.139 [NAL9602] No Fault, FailCount= 1
2017-10-30T23:01:23.673Z,1509404483.673 [BPC1](ERROR): Failed to parse bank A battery data
2017-10-30T23:01:23.673Z,1509404483.673 [BPC1] Data Fault, FailCount= 3
2017-10-30T23:01:23.673Z,1509404483.673 [BPC1](ERROR): Data Fault
2017-10-30T23:01:23.707Z,1509404483.707 [CBIT](ERROR): Data Fault in component: BPC1
2017-10-30T23:01:25.017Z,1509404485.017 [CBIT](INFO): Clearing failed state for component BPC1
2017-10-30T23:01:25.017Z,1509404485.017 [BPC1] No Fault, FailCount= 3
2017-10-30T23:01:34.264Z,1509404494.264 [SBIT](IMPORTANT): Beginning Startup BIT
2017-10-30T23:01:34.268Z,1509404494.268 [CBIT](IMPORTANT): Beginning ground fault scan
2017-10-30T23:01:38.428Z,1509404498.428 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2017-10-30T23:01:38.428Z,1509404498.428 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 3
2017-10-30T23:01:38.428Z,1509404498.428 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2017-10-30T23:01:38.587Z,1509404498.587 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2017-10-30T23:01:38.842Z,1509404498.842 [AcousticModem_Benthos_ATM900](INFO): Powering down
2017-10-30T23:01:38.935Z,1509404498.935 [BPC1](ERROR): Failed to parse bank A battery data
2017-10-30T23:01:38.935Z,1509404498.935 [BPC1] Data Fault, FailCount= 4
2017-10-30T23:01:38.935Z,1509404498.935 [BPC1](ERROR): Data Fault
2017-10-30T23:01:39.138Z,1509404499.138 [CBIT](ERROR): Data Fault in component: BPC1
2017-10-30T23:01:39.751Z,1509404499.751 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2017-10-30T23:01:39.751Z,1509404499.751 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 3
2017-10-30T23:01:40.130Z,1509404500.130 [CBIT](INFO): Clearing failed state for component BPC1
2017-10-30T23:01:40.130Z,1509404500.130 [BPC1] No Fault, FailCount= 4
2017-10-30T23:01:42.036Z,1509404502.036 [AcousticModem_Benthos_ATM900](INFO): Powering up
2017-10-30T23:01:42.036Z,1509404502.036 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2017-10-30T23:01:46.099Z,1509404506.099 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.011842
CHAN A1 (24V): 0.006841
CHAN A2 (12V): -0.005285
CHAN A3 (5V): -0.002089
CHAN B0 (3.3V): -0.000992
CHAN B1 (3.15aV): -0.001031
CHAN B2 (3.15bV): -0.001078
CHAN B3 (GND): -0.000495
OPEN: 0.004411
Full Scale Calc: 4.765 mA, -1.589 mA
2017-10-30T23:01:47.642Z,1509404507.642 [NAL9602](INFO): Powering up NAL9602
2017-10-30T23:02:01.133Z,1509404521.133 [BPC1](ERROR): Failed to parse bank A battery data
2017-10-30T23:02:01.133Z,1509404521.133 [BPC1] Data Fault, FailCount= 5
2017-10-30T23:02:01.133Z,1509404521.133 [BPC1](ERROR): Data Fault
2017-10-30T23:02:01.183Z,1509404521.183 [CBIT](ERROR): Data Fault in component: BPC1
2017-10-30T23:02:02.288Z,1509404522.288 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2017-10-30T23:02:02.288Z,1509404522.288 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 4
2017-10-30T23:02:02.288Z,1509404522.288 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2017-10-30T23:02:02.374Z,1509404522.374 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2017-10-30T23:02:02.374Z,1509404522.374 [CBIT](INFO): Clearing failed state for component BPC1
2017-10-30T23:02:02.374Z,1509404522.374 [BPC1] No Fault, FailCount= 5
2017-10-30T23:02:02.688Z,1509404522.688 [AcousticModem_Benthos_ATM900](INFO): Powering down
2017-10-30T23:02:03.539Z,1509404523.539 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2017-10-30T23:02:03.539Z,1509404523.539 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 4
2017-10-30T23:02:05.888Z,1509404525.888 [AcousticModem_Benthos_ATM900](INFO): Powering up
2017-10-30T23:02:05.888Z,1509404525.888 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2017-10-30T23:02:08.698Z,1509404528.698 [NAL9602](ERROR): NAL9602 initialization error.
2017-10-30T23:02:08.698Z,1509404528.698 [NAL9602] Communications Fault, FailCount= 2
2017-10-30T23:02:08.698Z,1509404528.698 [NAL9602](ERROR): Communications Fault
2017-10-30T23:02:08.760Z,1509404528.760 [CBIT](ERROR): Communications Fault in component: NAL9602
2017-10-30T23:02:09.105Z,1509404529.105 [NAL9602](INFO): Powering down
2017-10-30T23:02:09.958Z,1509404529.958 [CBIT](INFO): Clearing failed state for component NAL9602
2017-10-30T23:02:09.958Z,1509404529.958 [NAL9602] No Fault, FailCount= 2
2017-10-30T23:02:16.323Z,1509404536.323 [BPC1](ERROR): Failed to parse bank A battery data
2017-10-30T23:02:16.323Z,1509404536.323 [BPC1] Data Fault, FailCount= 6
2017-10-30T23:02:16.323Z,1509404536.323 [BPC1](ERROR): Data Fault
2017-10-30T23:02:16.814Z,1509404536.814 [CBIT](ERROR): Data Fault in component: BPC1
2017-10-30T23:02:17.804Z,1509404537.804 [CBIT](INFO): Clearing failed state for component BPC1
2017-10-30T23:02:17.804Z,1509404537.804 [BPC1] No Fault, FailCount= 6
2017-10-30T23:02:26.020Z,1509404546.020 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2017-10-30T23:02:26.020Z,1509404546.020 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 5
2017-10-30T23:02:26.020Z,1509404546.020 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2017-10-30T23:02:26.099Z,1509404546.099 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2017-10-30T23:02:26.420Z,1509404546.420 [AcousticModem_Benthos_ATM900](INFO): Powering down
2017-10-30T23:02:27.283Z,1509404547.283 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2017-10-30T23:02:27.283Z,1509404547.283 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 5
2017-10-30T23:02:28.077Z,1509404548.077 [SBIT](IMPORTANT): SBIT PASSED
2017-10-30T23:02:28.478Z,1509404548.478 [MissionManager](IMPORTANT): Started mission Startup
2017-10-30T23:02:28.478Z,1509404548.478 [Startup] Running Loop=1
2017-10-30T23:02:28.478Z,1509404548.478 [Startup](DEBUG): Aggregate::initialize Startup
2017-10-30T23:02:28.478Z,1509404548.478 [Startup:A.GoToSurface] Running Loop=1
2017-10-30T23:02:28.478Z,1509404548.478 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2017-10-30T23:02:28.479Z,1509404548.479 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2017-10-30T23:02:28.479Z,1509404548.479 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2017-10-30T23:02:28.480Z,1509404548.480 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2017-10-30T23:02:28.480Z,1509404548.480 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2017-10-30T23:02:28.480Z,1509404548.480 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2017-10-30T23:02:28.486Z,1509404548.486 [Startup:StartupSatComms] Running Loop=1
2017-10-30T23:02:28.486Z,1509404548.486 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2017-10-30T23:02:28.487Z,1509404548.487 [Startup:StartupSatComms:A] Running Loop=1
2017-10-30T23:02:28.872Z,1509404548.872 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2017-10-30T23:02:29.620Z,1509404549.620 [AcousticModem_Benthos_ATM900](INFO): Powering up
2017-10-30T23:02:29.620Z,1509404549.620 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2017-10-30T23:02:30.201Z,1509404550.201 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2017-10-30T23:02:30.201Z,1509404550.201 [Rowe_600LCM] Communications Fault, FailCount= 1
2017-10-30T23:02:30.201Z,1509404550.201 [Rowe_600LCM](ERROR): Communications Fault
2017-10-30T23:02:30.470Z,1509404550.470 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.4 s old, using for 20.0 s.
2017-10-30T23:02:30.484Z,1509404550.484 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2017-10-30T23:02:30.605Z,1509404550.605 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-10-30T23:02:30.704Z,1509404550.704 [Rowe_600LCM](INFO): Powering down
2017-10-30T23:02:30.871Z,1509404550.871 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.8 s old, using for 20.0 s.
2017-10-30T23:02:31.268Z,1509404551.268 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s.
2017-10-30T23:02:34.401Z,1509404554.401 [BPC1](ERROR): Failed to parse bank A battery data
2017-10-30T23:02:34.401Z,1509404554.401 [BPC1] Data Fault, FailCount= 7
2017-10-30T23:02:34.401Z,1509404554.401 [BPC1](ERROR): Data Fault
2017-10-30T23:02:34.414Z,1509404554.414 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.3 s old, using for 20.0 s.
2017-10-30T23:02:34.427Z,1509404554.427 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2017-10-30T23:02:34.427Z,1509404554.427 [Rowe_600LCM] No Fault, FailCount= 1
2017-10-30T23:02:34.428Z,1509404554.428 [CBIT](ERROR): Data Fault in component: BPC1
2017-10-30T23:02:34.538Z,1509404554.538 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.5 s old, using for 20.0 s.
2017-10-30T23:02:34.741Z,1509404554.741 [Rowe_600LCM](INFO): Initializing
2017-10-30T23:02:34.741Z,1509404554.741 [Rowe_600LCM](INFO): Checking LCM
2017-10-30T23:02:34.741Z,1509404554.741 [Rowe_600LCM](INFO): LCM OK
2017-10-30T23:02:34.742Z,1509404554.742 [Rowe_600LCM](INFO): Powering up
2017-10-30T23:02:34.895Z,1509404554.895 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s.
2017-10-30T23:02:35.280Z,1509404555.280 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s.
2017-10-30T23:02:35.294Z,1509404555.294 [CBIT](INFO): Clearing failed state for component BPC1
2017-10-30T23:02:35.294Z,1509404555.294 [BPC1] No Fault, FailCount= 7
2017-10-30T23:02:35.736Z,1509404555.736 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.7 s old, using for 20.0 s.
2017-10-30T23:02:36.080Z,1509404556.080 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s.
2017-10-30T23:02:36.484Z,1509404556.484 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s.
2017-10-30T23:02:36.880Z,1509404556.880 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.8 s old, using for 20.0 s.
2017-10-30T23:02:37.283Z,1509404557.283 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.2 s old, using for 20.0 s.
2017-10-30T23:02:37.679Z,1509404557.679 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.6 s old, using for 20.0 s.
2017-10-30T23:02:38.083Z,1509404558.083 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.0 s old, using for 20.0 s.
2017-10-30T23:02:38.487Z,1509404558.487 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.4 s old, using for 20.0 s.
2017-10-30T23:02:38.911Z,1509404558.911 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2017-10-30T23:02:38.955Z,1509404558.955 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.9 s old, using for 20.0 s.
2017-10-30T23:02:39.036Z,1509404559.036 [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-30T23:02:39.037Z,1509404559.037 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2017-10-30T23:02:39.037Z,1509404559.037 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2017-10-30T23:02:39.038Z,1509404559.038 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2017-10-30T23:02:39.249Z,1509404559.249 [NAL9602](INFO): Powering up NAL9602
2017-10-30T23:02:39.312Z,1509404559.312 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.2 s old, using for 20.0 s.
2017-10-30T23:02:49.636Z,1509404569.636 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2017-10-30T23:02:49.636Z,1509404569.636 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 6
2017-10-30T23:02:49.636Z,1509404569.636 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2017-10-30T23:02:49.726Z,1509404569.726 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2017-10-30T23:02:50.036Z,1509404570.036 [AcousticModem_Benthos_ATM900](INFO): Powering down
2017-10-30T23:02:50.968Z,1509404570.968 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2017-10-30T23:02:50.968Z,1509404570.968 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 6
2017-10-30T23:02:53.236Z,1509404573.236 [AcousticModem_Benthos_ATM900](INFO): Powering up
2017-10-30T23:02:53.236Z,1509404573.236 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2017-10-30T23:02:56.074Z,1509404576.074 [BPC1](ERROR): Failed to parse bank A battery data
2017-10-30T23:02:56.075Z,1509404576.075 [BPC1] Data Fault, FailCount= 8
2017-10-30T23:02:56.075Z,1509404576.075 [BPC1](ERROR): Data Fault
2017-10-30T23:02:56.103Z,1509404576.103 [CBIT](ERROR): Data Fault in component: BPC1
2017-10-30T23:02:57.297Z,1509404577.297 [CBIT](INFO): Clearing failed state for component BPC1
2017-10-30T23:02:57.297Z,1509404577.297 [BPC1] No Fault, FailCount= 8
2017-10-30T23:03:00.443Z,1509404580.443 [NAL9602](ERROR): NAL9602 initialization error.
2017-10-30T23:03:00.443Z,1509404580.443 [NAL9602] Communications Fault, FailCount= 3
2017-10-30T23:03:00.443Z,1509404580.443 [NAL9602](ERROR): Communications Fault
2017-10-30T23:03:00.534Z,1509404580.534 [CBIT](ERROR): Communications Fault in component: NAL9602
2017-10-30T23:03:00.874Z,1509404580.874 [NAL9602](INFO): Powering down
2017-10-30T23:03:01.690Z,1509404581.690 [CBIT](INFO): Clearing failed state for component NAL9602
2017-10-30T23:03:01.690Z,1509404581.690 [NAL9602] No Fault, FailCount= 3
2017-10-30T23:03:13.636Z,1509404593.636 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2017-10-30T23:03:13.636Z,1509404593.636 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 7
2017-10-30T23:03:13.636Z,1509404593.636 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2017-10-30T23:03:13.725Z,1509404593.725 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2017-10-30T23:03:14.036Z,1509404594.036 [AcousticModem_Benthos_ATM900](INFO): Powering down
2017-10-30T23:03:14.983Z,1509404594.983 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2017-10-30T23:03:14.983Z,1509404594.983 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 7
2017-10-30T23:03:16.474Z,1509404596.474 [BPC1](ERROR): Failed to parse bank A battery data
2017-10-30T23:03:16.474Z,1509404596.474 [BPC1] Data Fault, FailCount= 9
2017-10-30T23:03:16.474Z,1509404596.474 [BPC1](ERROR): Data Fault
2017-10-30T23:03:16.527Z,1509404596.527 [CBIT](ERROR): Data Fault in component: BPC1
2017-10-30T23:03:17.236Z,1509404597.236 [AcousticModem_Benthos_ATM900](INFO): Powering up
2017-10-30T23:03:17.236Z,1509404597.236 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2017-10-30T23:03:17.693Z,1509404597.693 [CBIT](INFO): Clearing failed state for component BPC1
2017-10-30T23:03:17.701Z,1509404597.701 [BPC1] No Fault, FailCount= 9
2017-10-30T23:03:28.965Z,1509404608.965 [Startup:StartupSatComms:A](INFO): Timed out from 2017-10-30T23:02:28.5Z
2017-10-30T23:03:28.965Z,1509404608.965 [Startup:StartupSatComms:A] Stopped
2017-10-30T23:03:28.966Z,1509404608.966 [Startup:StartupSatComms:B] Running Loop=1
2017-10-30T23:03:29.283Z,1509404609.283 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2017-10-30T23:03:30.174Z,1509404610.174 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-10-30T23:03:30.174Z,1509404610.174 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2017-10-30T23:03:30.174Z,1509404610.174 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-10-30T23:03:30.176Z,1509404610.176 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-10-30T23:03:30.176Z,1509404610.176 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2017-10-30T23:03:30.176Z,1509404610.176 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2017-10-30T23:03:30.189Z,1509404610.189 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-10-30T23:03:30.189Z,1509404610.189 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2017-10-30T23:03:30.338Z,1509404610.338 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-10-30T23:03:30.338Z,1509404610.338 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2017-10-30T23:03:30.338Z,1509404610.338 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2017-10-30T23:03:30.338Z,1509404610.338 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2017-10-30T23:03:33.668Z,1509404613.668 [NAL9602](INFO): Powering up NAL9602
2017-10-30T23:03:33.696Z,1509404613.696 [BPC1](ERROR): Failed to parse bank A battery data
2017-10-30T23:03:33.696Z,1509404613.696 [BPC1] Data Fault, FailCount= 10
2017-10-30T23:03:33.696Z,1509404613.696 [BPC1](ERROR): Data Fault
2017-10-30T23:03:33.705Z,1509404613.705 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-10-30T23:03:33.705Z,1509404613.705 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-10-30T23:03:33.705Z,1509404613.705 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-10-30T23:03:33.706Z,1509404613.706 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-10-30T23:03:33.706Z,1509404613.706 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-10-30T23:03:33.707Z,1509404613.707 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-10-30T23:03:33.755Z,1509404613.755 [CBIT](ERROR): Data Fault in component: BPC1
2017-10-30T23:03:33.756Z,1509404613.756 [CBIT](CRITICAL): Data Fault in component: BPC1
2017-10-30T23:03:33.774Z,1509404613.774 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20171030T225014/Courier0008.lzma
2017-10-30T23:03:33.861Z,1509404613.861 [CBIT](INFO): Critical error at 20171030T230333
2017-10-30T23:03:34.570Z,1509404614.570 [DataOverHttps](INFO): Moved sent file to Logs/20171030T225014/Courier0008.lzma.bak
2017-10-30T23:03:34.570Z,1509404614.570 [DataOverHttps](INFO): SBD MOMSN=5177409
2017-10-30T23:03:38.658Z,1509404618.658 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2017-10-30T23:03:38.658Z,1509404618.658 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 8
2017-10-30T23:03:38.658Z,1509404618.658 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2017-10-30T23:03:38.756Z,1509404618.756 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2017-10-30T23:03:38.757Z,1509404618.757 [CBIT](FAULT): Communications Fault in component: AcousticModem_Benthos_ATM900
2017-10-30T23:03:39.056Z,1509404619.056 [AcousticModem_Benthos_ATM900](INFO): Powering down
2017-10-30T23:03:43.609Z,1509404623.609 [DataOverHttps](INFO): Sending 185 bytes from file Logs/20171030T230018/Courier0000.lzma
2017-10-30T23:03:44.410Z,1509404624.410 [DataOverHttps](INFO): Moved sent file to Logs/20171030T230018/Courier0000.lzma.bak
2017-10-30T23:03:44.411Z,1509404624.411 [DataOverHttps](INFO): SBD MOMSN=5177411
2017-10-30T23:03:53.621Z,1509404633.621 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20171030T225014/Express0005.lzma
2017-10-30T23:03:54.413Z,1509404634.413 [DataOverHttps](INFO): Moved sent file to Logs/20171030T225014/Express0005.lzma.bak
2017-10-30T23:03:54.414Z,1509404634.414 [DataOverHttps](INFO): SBD MOMSN=5177417
2017-10-30T23:03:55.260Z,1509404635.260 [NAL9602](ERROR): NAL9602 initialization error.
2017-10-30T23:03:55.260Z,1509404635.260 [NAL9602] Communications Fault, FailCount= 4
2017-10-30T23:03:55.260Z,1509404635.260 [NAL9602](ERROR): Communications Fault
2017-10-30T23:03:55.327Z,1509404635.327 [CBIT](ERROR): Communications Fault in component: NAL9602
2017-10-30T23:03:55.387Z,1509404635.387 [NAL9602](INFO): Powering down
2017-10-30T23:03:58.753Z,1509404638.753 [CBIT](INFO): Clearing failed state for component NAL9602
2017-10-30T23:03:58.753Z,1509404638.753 [NAL9602] No Fault, FailCount= 4
2017-10-30T23:04:03.618Z,1509404643.618 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20171030T225014/Express0009.lzma
2017-10-30T23:04:04.418Z,1509404644.418 [DataOverHttps](INFO): Moved sent file to Logs/20171030T225014/Express0009.lzma.bak
2017-10-30T23:04:04.418Z,1509404644.418 [DataOverHttps](INFO): SBD MOMSN=5177420
2017-10-30T23:04:13.476Z,1509404653.476 [DataOverHttps](INFO): Sending 799 bytes from file Logs/20171030T230018/Express0001.lzma
2017-10-30T23:04:14.274Z,1509404654.274 [DataOverHttps](INFO): Moved sent file to Logs/20171030T230018/Express0001.lzma.bak
2017-10-30T23:04:14.274Z,1509404654.274 [DataOverHttps](INFO): SBD MOMSN=5177422
2017-10-30T23:04:15.172Z,1509404655.172 [Startup:StartupSatComms:B] Stopped
2017-10-30T23:04:15.173Z,1509404655.173 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2017-10-30T23:04:15.173Z,1509404655.173 [Startup:StartupSatComms] Stopped
2017-10-30T23:04:15.173Z,1509404655.173 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2017-10-30T23:04:15.174Z,1509404655.174 [Startup](INFO): Completed Startup
2017-10-30T23:04:15.174Z,1509404655.174 [MissionManager](INFO): Startup is completed.
2017-10-30T23:04:15.174Z,1509404655.174 [MissionManager](INFO): Uninitializing Mission Startup
2017-10-30T23:04:15.174Z,1509404655.174 [Startup] Stopped
2017-10-30T23:04:15.174Z,1509404655.174 [Startup](DEBUG): Aggregate::uninitialize Startup
2017-10-30T23:04:15.174Z,1509404655.174 [Startup:A.GoToSurface] Stopped
2017-10-30T23:04:15.175Z,1509404655.175 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2017-10-30T23:04:15.303Z,1509404655.303 [MissionManager](IMPORTANT): Started mission Default
2017-10-30T23:04:15.303Z,1509404655.303 [Default] Running Loop=1
2017-10-30T23:04:15.303Z,1509404655.303 [Default](DEBUG): Aggregate::initialize Default
2017-10-30T23:04:15.303Z,1509404655.303 [Default:B.GoToSurface] Running Loop=1
2017-10-30T23:04:15.303Z,1509404655.303 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2017-10-30T23:04:15.304Z,1509404655.304 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2017-10-30T23:04:15.304Z,1509404655.304 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2017-10-30T23:04:15.304Z,1509404655.304 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2017-10-30T23:04:15.305Z,1509404655.305 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2017-10-30T23:04:15.305Z,1509404655.305 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2017-10-30T23:04:15.305Z,1509404655.305 [Default:A.Wait] Running Loop=1
2017-10-30T23:04:15.305Z,1509404655.305 [Default:A.Wait](DEBUG): Initialize Wait Component.
2017-10-30T23:04:23.720Z,1509404663.720 [PNI_TCM](ERROR): CRC does not match. Expected:0x48996 got:0x40136
2017-10-30T23:04:25.687Z,1509404665.687 [NAL9602](INFO): Powering up NAL9602
2017-10-30T23:04:25.724Z,1509404665.724 [PNI_TCM](ERROR): CRC does not match. Expected:0x53071 got:0x22627
2017-10-30T23:04:28.532Z,1509404668.532 [Default:A.Wait](INFO): Done Waiting.
2017-10-30T23:04:28.532Z,1509404668.532 [Default:A.Wait] Stopped
2017-10-30T23:04:28.532Z,1509404668.532 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2017-10-30T23:04:29.186Z,1509404669.186 [Default:CheckIn] Running Loop=1
2017-10-30T23:04:29.186Z,1509404669.186 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-10-30T23:04:29.186Z,1509404669.186 [Default:CheckIn:Read_GPS] Running Loop=1
2017-10-30T23:04:29.350Z,1509404669.350 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2017-10-30T23:04:46.483Z,1509404686.483 [NAL9602](ERROR): NAL9602 initialization error.
2017-10-30T23:04:46.483Z,1509404686.483 [NAL9602] Communications Fault, FailCount= 5
2017-10-30T23:04:46.483Z,1509404686.483 [NAL9602](ERROR): Communications Fault
2017-10-30T23:04:46.558Z,1509404686.558 [CBIT](ERROR): Communications Fault in component: NAL9602
2017-10-30T23:04:46.559Z,1509404686.559 [CBIT](CRITICAL): Communications Fault in component: NAL9602
2017-10-30T23:04:46.883Z,1509404686.883 [NAL9602](INFO): Powering down
2017-10-30T23:04:46.953Z,1509404686.953 [CBIT](INFO): Critical error at 20171030T230446
2017-10-30T23:05:17.037Z,1509404717.037 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2017-10-30T23:05:17.037Z,1509404717.037 [Rowe_600LCM] Communications Fault, FailCount= 2
2017-10-30T23:05:17.037Z,1509404717.037 [Rowe_600LCM](ERROR): Communications Fault
2017-10-30T23:05:17.441Z,1509404717.441 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-10-30T23:05:17.590Z,1509404717.590 [Rowe_600LCM](INFO): Powering down
2017-10-30T23:05:19.008Z,1509404719.008 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.3 s old, using for 20.0 s.
2017-10-30T23:05:19.040Z,1509404719.040 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2017-10-30T23:05:19.045Z,1509404719.045 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2017-10-30T23:05:19.045Z,1509404719.045 [Rowe_600LCM] No Fault, FailCount= 2
2017-10-30T23:05:19.147Z,1509404719.147 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.4 s old, using for 20.0 s.
2017-10-30T23:05:19.205Z,1509404719.205 [Rowe_600LCM](INFO): Initializing
2017-10-30T23:05:19.206Z,1509404719.206 [Rowe_600LCM](INFO): Checking LCM
2017-10-30T23:05:19.206Z,1509404719.206 [Rowe_600LCM](INFO): LCM OK
2017-10-30T23:05:19.206Z,1509404719.206 [Rowe_600LCM](INFO): Powering up
2017-10-30T23:05:19.503Z,1509404719.503 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.8 s old, using for 20.0 s.
2017-10-30T23:05:19.899Z,1509404719.899 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.2 s old, using for 20.0 s.
2017-10-30T23:05:20.304Z,1509404720.304 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.6 s old, using for 20.0 s.
2017-10-30T23:05:20.696Z,1509404720.696 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.0 s old, using for 20.0 s.
2017-10-30T23:05:21.096Z,1509404721.096 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.4 s old, using for 20.0 s.
2017-10-30T23:05:21.497Z,1509404721.497 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.8 s old, using for 20.0 s.
2017-10-30T23:05:21.896Z,1509404721.896 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.2 s old, using for 20.0 s.
2017-10-30T23:05:22.300Z,1509404722.300 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.6 s old, using for 20.0 s.
2017-10-30T23:05:22.704Z,1509404722.704 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.0 s old, using for 20.0 s.
2017-10-30T23:05:23.096Z,1509404723.096 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.4 s old, using for 20.0 s.
2017-10-30T23:05:23.327Z,1509404723.327 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2017-10-30T23:05:23.381Z,1509404723.381 [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-30T23:05:23.382Z,1509404723.382 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2017-10-30T23:05:23.383Z,1509404723.383 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2017-10-30T23:05:23.384Z,1509404723.384 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2017-10-30T23:05:23.528Z,1509404723.528 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.8 s old, using for 20.0 s.
2017-10-30T23:06:33.951Z,1509404793.951 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-10-30T23:06:33.951Z,1509404793.951 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2017-10-30T23:06:33.951Z,1509404793.951 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-10-30T23:06:33.952Z,1509404793.952 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-10-30T23:06:33.953Z,1509404793.953 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2017-10-30T23:06:33.953Z,1509404793.953 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2017-10-30T23:06:33.965Z,1509404793.965 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-10-30T23:06:33.965Z,1509404793.965 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2017-10-30T23:06:34.377Z,1509404794.377 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-10-30T23:06:34.378Z,1509404794.378 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2017-10-30T23:06:34.378Z,1509404794.378 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2017-10-30T23:06:34.378Z,1509404794.378 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2017-10-30T23:06:34.739Z,1509404794.739 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-10-30T23:06:34.739Z,1509404794.739 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-10-30T23:06:34.740Z,1509404794.740 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-10-30T23:06:34.740Z,1509404794.740 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-10-30T23:06:34.740Z,1509404794.740 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-10-30T23:06:34.741Z,1509404794.741 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-10-30T23:06:46.753Z,1509404806.753 [CBIT](INFO): Clearing failed state for component NAL9602
2017-10-30T23:06:46.753Z,1509404806.753 [NAL9602] No Fault, FailCount= 5
2017-10-30T23:06:47.099Z,1509404807.099 [NAL9602](INFO): Powering up NAL9602
2017-10-30T23:07:08.303Z,1509404828.303 [NAL9602](ERROR): NAL9602 initialization error.
2017-10-30T23:07:08.303Z,1509404828.303 [NAL9602] Communications Fault, FailCount= 1
2017-10-30T23:07:08.303Z,1509404828.303 [NAL9602](ERROR): Communications Fault
2017-10-30T23:07:08.381Z,1509404828.381 [CBIT](ERROR): Communications Fault in component: NAL9602
2017-10-30T23:07:08.702Z,1509404828.702 [NAL9602](INFO): Powering down
2017-10-30T23:07:09.563Z,1509404829.563 [CBIT](INFO): Clearing failed state for component NAL9602
2017-10-30T23:07:09.563Z,1509404829.563 [NAL9602] No Fault, FailCount= 1
2017-10-30T23:07:19.225Z,1509404839.225 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2017-10-30T23:07:19.225Z,1509404839.225 [Rowe_600LCM] Communications Fault, FailCount= 3
2017-10-30T23:07:19.225Z,1509404839.225 [Rowe_600LCM](ERROR): Communications Fault
2017-10-30T23:07:19.323Z,1509404839.323 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.1 s old, using for 20.0 s.
2017-10-30T23:07:19.357Z,1509404839.357 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2017-10-30T23:07:19.630Z,1509404839.630 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-10-30T23:07:19.719Z,1509404839.719 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.5 s old, using for 20.0 s.
2017-10-30T23:07:19.810Z,1509404839.810 [Rowe_600LCM](INFO): Powering down
2017-10-30T23:07:20.069Z,1509404840.069 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.9 s old, using for 20.0 s.
2017-10-30T23:07:20.460Z,1509404840.460 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.3 s old, using for 20.0 s.
2017-10-30T23:07:20.864Z,1509404840.864 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.7 s old, using for 20.0 s.
2017-10-30T23:07:21.260Z,1509404841.260 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.1 s old, using for 20.0 s.
2017-10-30T23:07:21.274Z,1509404841.274 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2017-10-30T23:07:21.274Z,1509404841.274 [Rowe_600LCM] No Fault, FailCount= 3
2017-10-30T23:07:21.425Z,1509404841.425 [Rowe_600LCM](INFO): Initializing
2017-10-30T23:07:21.426Z,1509404841.426 [Rowe_600LCM](INFO): Checking LCM
2017-10-30T23:07:21.426Z,1509404841.426 [Rowe_600LCM](INFO): LCM OK
2017-10-30T23:07:21.426Z,1509404841.426 [Rowe_600LCM](INFO): Powering up
2017-10-30T23:07:21.665Z,1509404841.665 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.5 s old, using for 20.0 s.
2017-10-30T23:07:22.071Z,1509404842.071 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.9 s old, using for 20.0 s.
2017-10-30T23:07:22.461Z,1509404842.461 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.3 s old, using for 20.0 s.
2017-10-30T23:07:22.872Z,1509404842.872 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.7 s old, using for 20.0 s.
2017-10-30T23:07:23.264Z,1509404843.264 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.1 s old, using for 20.0 s.
2017-10-30T23:07:23.661Z,1509404843.661 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.5 s old, using for 20.0 s.
2017-10-30T23:07:24.072Z,1509404844.072 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.9 s old, using for 20.0 s.
2017-10-30T23:07:24.464Z,1509404844.464 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.3 s old, using for 20.0 s.
2017-10-30T23:07:24.865Z,1509404844.865 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.7 s old, using for 20.0 s.
2017-10-30T23:07:25.265Z,1509404845.265 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.1 s old, using for 20.0 s.
2017-10-30T23:07:25.543Z,1509404845.543 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2017-10-30T23:07:25.601Z,1509404845.601 [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-30T23:07:25.602Z,1509404845.602 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2017-10-30T23:07:25.603Z,1509404845.603 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2017-10-30T23:07:25.603Z,1509404845.603 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2017-10-30T23:07:25.720Z,1509404845.720 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.5 s old, using for 20.0 s.
2017-10-30T23:07:38.823Z,1509404858.823 [NAL9602](INFO): Powering up NAL9602
2017-10-30T23:07:59.628Z,1509404879.628 [NAL9602](ERROR): NAL9602 initialization error.
2017-10-30T23:07:59.628Z,1509404879.628 [NAL9602] Communications Fault, FailCount= 2
2017-10-30T23:07:59.628Z,1509404879.628 [NAL9602](ERROR): Communications Fault
2017-10-30T23:07:59.705Z,1509404879.705 [CBIT](ERROR): Communications Fault in component: NAL9602
2017-10-30T23:08:00.022Z,1509404880.022 [NAL9602](INFO): Powering down
2017-10-30T23:08:00.881Z,1509404880.881 [CBIT](INFO): Clearing failed state for component NAL9602
2017-10-30T23:08:00.881Z,1509404880.881 [NAL9602] No Fault, FailCount= 2
2017-10-30T23:08:13.555Z,1509404893.555 [CommandLine](IMPORTANT): got command quit
2017-10-30T23:08:14.580Z,1509404894.580 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2017-10-30T23:08:14.580Z,1509404894.580 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:14.637Z,1509404894.637 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2017-10-30T23:08:14.637Z,1509404894.637 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:14.638Z,1509404894.638 [CommandLine](INFO): Join timeout helper Thread ID is 940
2017-10-30T23:08:14.638Z,1509404894.638 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2017-10-30T23:08:14.638Z,1509404894.638 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:14.639Z,1509404894.639 [NavChartDb](INFO): Join timeout helper Thread ID is 941
2017-10-30T23:08:14.657Z,1509404894.657 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2017-10-30T23:08:14.657Z,1509404894.657 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:14.677Z,1509404894.677 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2017-10-30T23:08:14.677Z,1509404894.677 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:14.677Z,1509404894.677 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 942
2017-10-30T23:08:14.701Z,1509404894.701 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2017-10-30T23:08:14.701Z,1509404894.701 [WetLabsBB2FL](INFO): Powering down
2017-10-30T23:08:14.702Z,1509404894.702 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:14.721Z,1509404894.721 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2017-10-30T23:08:14.721Z,1509404894.721 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:14.721Z,1509404894.721 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 943
2017-10-30T23:08:15.053Z,1509404895.053 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2017-10-30T23:08:15.053Z,1509404895.053 [CTD_NeilBrown](INFO): Powering down
2017-10-30T23:08:15.054Z,1509404895.054 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:15.065Z,1509404895.065 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2017-10-30T23:08:15.065Z,1509404895.065 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:15.065Z,1509404895.065 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 944
2017-10-30T23:08:15.081Z,1509404895.081 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2017-10-30T23:08:15.081Z,1509404895.081 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-10-30T23:08:15.177Z,1509404895.177 [Rowe_600LCM](INFO): Powering down
2017-10-30T23:08:15.179Z,1509404895.179 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:15.194Z,1509404895.194 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2017-10-30T23:08:15.194Z,1509404895.194 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:15.195Z,1509404895.195 [Radio_Surface](INFO): Join timeout helper Thread ID is 946
2017-10-30T23:08:15.589Z,1509404895.589 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2017-10-30T23:08:15.589Z,1509404895.589 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:15.597Z,1509404895.597 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2017-10-30T23:08:15.598Z,1509404895.598 [logger ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:15.598Z,1509404895.598 [logger](INFO): Join timeout helper Thread ID is 947
2017-10-30T23:08:15.598Z,1509404895.598 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2017-10-30T23:08:15.599Z,1509404895.599 [logger ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:15.600Z,1509404895.600 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2017-10-30T23:08:15.600Z,1509404895.600 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:15.600Z,1509404895.600 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2017-10-30T23:08:15.600Z,1509404895.600 [controlThread ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:15.601Z,1509404895.601 [controlThread](INFO): Join timeout helper Thread ID is 948
2017-10-30T23:08:15.617Z,1509404895.617 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2017-10-30T23:08:15.617Z,1509404895.617 [controlThread](DEBUG): Uninitializing ControlThread
2017-10-30T23:08:15.618Z,1509404895.618 [AcousticModem_Benthos_ATM900](INFO): Powering down
2017-10-30T23:08:15.619Z,1509404895.619 [NAL9602](INFO): Powering down
2017-10-30T23:08:15.620Z,1509404895.620 [PNI_TCM](INFO): Powering down
2017-10-30T23:08:15.709Z,1509404895.709 [Aanderaa_O2](INFO): Powering down
2017-10-30T23:08:15.712Z,1509404895.712 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2017-10-30T23:08:15.714Z,1509404895.714 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2017-10-30T23:08:15.715Z,1509404895.715 [MissionManager](INFO): Uninitializing Mission Default
2017-10-30T23:08:15.715Z,1509404895.715 [Default] Stopped
2017-10-30T23:08:15.715Z,1509404895.715 [Default](DEBUG): Aggregate::uninitialize Default
2017-10-30T23:08:15.715Z,1509404895.715 [Default:B.GoToSurface] Stopped
2017-10-30T23:08:15.715Z,1509404895.715 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2017-10-30T23:08:15.715Z,1509404895.715 [Default:CheckIn] Stopped
2017-10-30T23:08:15.715Z,1509404895.715 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-10-30T23:08:15.715Z,1509404895.715 [Default:CheckIn:Read_GPS] Stopped
2017-10-30T23:08:15.718Z,1509404895.718 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2017-10-30T23:08:15.719Z,1509404895.719 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2017-10-30T23:08:15.719Z,1509404895.719 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2017-10-30T23:08:15.719Z,1509404895.719 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2017-10-30T23:08:15.719Z,1509404895.719 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2017-10-30T23:08:15.720Z,1509404895.720 [BuoyancyServo](INFO): Powering down
2017-10-30T23:08:15.733Z,1509404895.733 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2017-10-30T23:08:15.733Z,1509404895.733 [ElevatorServo](INFO): Powering down
2017-10-30T23:08:15.734Z,1509404895.734 [MassServo](DEBUG): Uninitialize Mass Servo.
2017-10-30T23:08:15.734Z,1509404895.734 [MassServo](INFO): Powering down
2017-10-30T23:08:15.735Z,1509404895.735 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2017-10-30T23:08:15.735Z,1509404895.735 [RudderServo](INFO): Powering down
2017-10-30T23:08:15.736Z,1509404895.736 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2017-10-30T23:08:15.736Z,1509404895.736 [ThrusterServo](INFO): Powering down
2017-10-30T23:08:15.737Z,1509404895.737 [SBIT](DEBUG): Uninitialize SBIT Component.
2017-10-30T23:08:15.738Z,1509404895.738 [IBIT](DEBUG): Uninitialize IBIT Component.
2017-10-30T23:08:15.738Z,1509404895.738 [CBIT](DEBUG): Uninitialize CBIT Component.
2017-10-30T23:08:15.739Z,1509404895.739 [controlThread ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:15.819Z,1509404895.819 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:15.825Z,1509404895.825 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:15.861Z,1509404895.861 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:15.865Z,1509404895.865 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:15.910Z,1509404895.910 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-10-30T23:08:15.958Z,1509404895.958 [logger ThreadHandler](INFO): Thread cancelled.