2018-05-31T20:16:11.792Z,1527797771.792 [Supervisor](DEBUG): Initializing supervisor.
2018-05-31T20:16:11.795Z,1527797771.795 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-05-31T20:16:11.795Z,1527797771.795 [SyncHandler](INFO): Protected caller Thread ID is 4610
2018-05-31T20:16:11.796Z,1527797771.796 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-05-31T20:16:11.797Z,1527797771.797 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-05-31T20:16:11.797Z,1527797771.797 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4611
2018-05-31T20:16:11.800Z,1527797771.800 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-05-31T20:16:11.812Z,1527797771.812 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-05-31T20:16:11.813Z,1527797771.813 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-05-31T20:16:11.813Z,1527797771.813 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4612
2018-05-31T20:16:11.814Z,1527797771.814 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-05-31T20:16:11.815Z,1527797771.815 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-05-31T20:16:11.815Z,1527797771.815 [logger ThreadHandler](INFO): Protected caller Thread ID is 4613
2018-05-31T20:16:11.817Z,1527797771.817 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-05-31T20:16:11.818Z,1527797771.818 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-05-31T20:16:11.819Z,1527797771.819 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-05-31T20:16:11.919Z,1527797771.919 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-05-31T20:16:11.919Z,1527797771.919 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-05-31T20:16:12.021Z,1527797772.021 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-05-31T20:16:12.022Z,1527797772.022 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-05-31T20:16:12.228Z,1527797772.228 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-05-31T20:16:12.228Z,1527797772.228 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-05-31T20:16:12.556Z,1527797772.556 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-05-31T20:16:12.557Z,1527797772.557 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-05-31T20:16:12.907Z,1527797772.907 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-05-31T20:16:12.908Z,1527797772.908 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-05-31T20:16:13.387Z,1527797773.387 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-05-31T20:16:13.387Z,1527797773.387 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-05-31T20:16:13.807Z,1527797773.807 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-05-31T20:16:13.807Z,1527797773.807 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-05-31T20:16:14.537Z,1527797774.537 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-05-31T20:16:14.538Z,1527797774.538 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-05-31T20:16:14.619Z,1527797774.619 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-05-31T20:16:14.927Z,1527797774.927 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-05-31T20:16:14.928Z,1527797774.928 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-05-31T20:16:15.074Z,1527797775.074 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-05-31T20:16:15.074Z,1527797775.074 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-05-31T20:16:15.288Z,1527797775.288 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-05-31T20:16:15.288Z,1527797775.288 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-05-31T20:16:15.510Z,1527797775.510 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-05-31T20:16:15.510Z,1527797775.510 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-05-31T20:16:15.608Z,1527797775.608 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-05-31T20:16:15.609Z,1527797775.609 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-05-31T20:16:15.751Z,1527797775.751 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-05-31T20:16:15.753Z,1527797775.753 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2018-05-31T20:16:15.754Z,1527797775.754 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2018-05-31T20:16:15.986Z,1527797775.986 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-05-31T20:16:15.987Z,1527797775.987 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2018-05-31T20:16:16.093Z,1527797776.093 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2018-05-31T20:16:16.240Z,1527797776.240 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2018-05-31T20:16:16.334Z,1527797776.334 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2018-05-31T20:16:16.419Z,1527797776.419 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2018-05-31T20:16:16.558Z,1527797776.558 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2018-05-31T20:16:16.742Z,1527797776.742 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2018-05-31T20:16:16.840Z,1527797776.840 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2018-05-31T20:16:16.934Z,1527797776.934 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2018-05-31T20:16:17.032Z,1527797777.032 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2018-05-31T20:16:17.116Z,1527797777.116 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2018-05-31T20:16:17.116Z,1527797777.116 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-05-31T20:16:17.120Z,1527797777.120 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-05-31T20:16:17.220Z,1527797777.220 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-05-31T20:16:17.220Z,1527797777.220 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-05-31T20:16:17.233Z,1527797777.233 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-05-31T20:16:17.234Z,1527797777.234 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-05-31T20:16:17.275Z,1527797777.275 [DepthRateCalculator] Loaded
2018-05-31T20:16:17.276Z,1527797777.276 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-05-31T20:16:17.282Z,1527797777.282 [PitchRateCalculator] Loaded
2018-05-31T20:16:17.282Z,1527797777.282 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-05-31T20:16:17.298Z,1527797777.298 [SpeedCalculator] Loaded
2018-05-31T20:16:17.298Z,1527797777.298 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-05-31T20:16:17.319Z,1527797777.319 [TempGradientCalculator] Loaded
2018-05-31T20:16:17.320Z,1527797777.320 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-05-31T20:16:17.335Z,1527797777.335 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-05-31T20:16:17.336Z,1527797777.336 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-05-31T20:16:17.341Z,1527797777.341 [YawRateCalculator] Loaded
2018-05-31T20:16:17.342Z,1527797777.342 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-05-31T20:16:17.382Z,1527797777.382 [ElevatorOffsetCalculator] Loaded
2018-05-31T20:16:17.382Z,1527797777.382 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-05-31T20:16:17.382Z,1527797777.382 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-05-31T20:16:17.383Z,1527797777.383 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-05-31T20:16:17.407Z,1527797777.407 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-05-31T20:16:17.408Z,1527797777.408 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-05-31T20:16:17.676Z,1527797777.676 [AcousticModem_Benthos_ATM900] Loaded
2018-05-31T20:16:17.676Z,1527797777.676 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2018-05-31T20:16:17.750Z,1527797777.750 [DataOverHttps] Loaded
2018-05-31T20:16:17.750Z,1527797777.750 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-05-31T20:16:17.764Z,1527797777.764 [Depth_Keller] Loaded
2018-05-31T20:16:17.764Z,1527797777.764 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-05-31T20:16:17.864Z,1527797777.864 [NAL9602] Loaded
2018-05-31T20:16:17.864Z,1527797777.864 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-05-31T20:16:17.880Z,1527797777.880 [Onboard] Loaded
2018-05-31T20:16:17.880Z,1527797777.880 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-05-31T20:16:17.891Z,1527797777.891 [Radio_Surface] Loaded
2018-05-31T20:16:17.891Z,1527797777.891 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-05-31T20:16:17.892Z,1527797777.892 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407B74E0
2018-05-31T20:16:17.893Z,1527797777.893 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4692
2018-05-31T20:16:17.940Z,1527797777.940 [PNI_TCM] Loaded
2018-05-31T20:16:17.940Z,1527797777.940 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-05-31T20:16:18.002Z,1527797778.002 [Rowe_600LCM] Loaded
2018-05-31T20:16:18.003Z,1527797778.003 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-05-31T20:16:18.003Z,1527797778.003 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 407E74E0
2018-05-31T20:16:18.004Z,1527797778.004 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 4693
2018-05-31T20:16:20.292Z,1527797780.292 [BPC1] Loaded
2018-05-31T20:16:20.292Z,1527797780.292 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-05-31T20:16:20.293Z,1527797780.293 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-05-31T20:16:20.293Z,1527797780.293 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-05-31T20:16:20.422Z,1527797780.422 [SBIT](DEBUG): Construct Startup Built In Test.
2018-05-31T20:16:20.445Z,1527797780.445 [SBIT] Loaded
2018-05-31T20:16:20.446Z,1527797780.446 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-05-31T20:16:20.446Z,1527797780.446 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-05-31T20:16:20.458Z,1527797780.458 [IBIT] Loaded
2018-05-31T20:16:20.458Z,1527797780.458 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-05-31T20:16:20.462Z,1527797780.462 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-05-31T20:16:20.614Z,1527797780.614 [CBIT] Loaded
2018-05-31T20:16:20.614Z,1527797780.614 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-05-31T20:16:20.614Z,1527797780.614 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-05-31T20:16:20.615Z,1527797780.615 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-05-31T20:16:20.754Z,1527797780.754 [Aanderaa_O2] Loaded
2018-05-31T20:16:20.755Z,1527797780.755 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-05-31T20:16:20.803Z,1527797780.803 [CTD_Seabird] Loaded
2018-05-31T20:16:20.804Z,1527797780.804 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-05-31T20:16:20.805Z,1527797780.805 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 408A74E0
2018-05-31T20:16:20.805Z,1527797780.805 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 4694
2018-05-31T20:16:20.822Z,1527797780.822 [ESPComponent] Loaded
2018-05-31T20:16:20.822Z,1527797780.822 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2018-05-31T20:16:20.836Z,1527797780.836 [PAR_Licor] Loaded
2018-05-31T20:16:20.837Z,1527797780.837 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-05-31T20:16:20.886Z,1527797780.886 [WetLabsBB2FL] Loaded
2018-05-31T20:16:20.886Z,1527797780.886 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-05-31T20:16:20.887Z,1527797780.887 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408D74E0
2018-05-31T20:16:20.888Z,1527797780.888 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4695
2018-05-31T20:16:20.888Z,1527797780.888 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-05-31T20:16:20.889Z,1527797780.889 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-05-31T20:16:21.126Z,1527797781.126 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-05-31T20:16:21.127Z,1527797781.127 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-05-31T20:16:21.194Z,1527797781.194 [VerticalControl](DEBUG): Construct VerticalControl.
2018-05-31T20:16:21.290Z,1527797781.290 [VerticalControl] Loaded
2018-05-31T20:16:21.290Z,1527797781.290 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-05-31T20:16:21.291Z,1527797781.291 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-05-31T20:16:21.353Z,1527797781.353 [HorizontalControl] Loaded
2018-05-31T20:16:21.353Z,1527797781.353 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-05-31T20:16:21.354Z,1527797781.354 [SpeedControl](DEBUG): Construct SpeedControl.
2018-05-31T20:16:21.359Z,1527797781.359 [SpeedControl] Loaded
2018-05-31T20:16:21.360Z,1527797781.360 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-05-31T20:16:21.360Z,1527797781.360 [LoopControl](DEBUG): Construct LoopControl.
2018-05-31T20:16:21.361Z,1527797781.361 [LoopControl] Loaded
2018-05-31T20:16:21.361Z,1527797781.361 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-05-31T20:16:21.362Z,1527797781.362 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-05-31T20:16:21.362Z,1527797781.362 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-05-31T20:16:21.444Z,1527797781.444 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-05-31T20:16:21.444Z,1527797781.444 [StratificationFrontDetector](DEBUG): (re)initializing
2018-05-31T20:16:21.445Z,1527797781.445 [StratificationFrontDetector] Loaded
2018-05-31T20:16:21.445Z,1527797781.445 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-05-31T20:16:21.446Z,1527797781.446 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-05-31T20:16:21.446Z,1527797781.446 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-05-31T20:16:21.543Z,1527797781.543 [BuoyancyServo] Loaded
2018-05-31T20:16:21.544Z,1527797781.544 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-05-31T20:16:21.555Z,1527797781.555 [ElevatorServo] Loaded
2018-05-31T20:16:21.555Z,1527797781.555 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-05-31T20:16:21.566Z,1527797781.566 [MassServo] Loaded
2018-05-31T20:16:21.567Z,1527797781.567 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-05-31T20:16:21.578Z,1527797781.578 [RudderServo] Loaded
2018-05-31T20:16:21.578Z,1527797781.578 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-05-31T20:16:21.589Z,1527797781.589 [ThrusterServo] Loaded
2018-05-31T20:16:21.590Z,1527797781.590 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-05-31T20:16:21.590Z,1527797781.590 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-05-31T20:16:21.591Z,1527797781.591 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-05-31T20:16:21.682Z,1527797781.682 [DeadReckonUsingSpeedCalculator] Loaded
2018-05-31T20:16:21.682Z,1527797781.682 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-05-31T20:16:21.699Z,1527797781.699 [NavChart] Loaded
2018-05-31T20:16:21.699Z,1527797781.699 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-05-31T20:16:21.703Z,1527797781.703 [UniversalFixResidualReporter] Loaded
2018-05-31T20:16:21.703Z,1527797781.703 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-05-31T20:16:21.704Z,1527797781.704 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-05-31T20:16:21.707Z,1527797781.707 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-05-31T20:16:21.708Z,1527797781.708 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-05-31T20:16:21.715Z,1527797781.715 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-05-31T20:16:21.716Z,1527797781.716 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A304E0
2018-05-31T20:16:21.716Z,1527797781.716 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4696
2018-05-31T20:16:21.721Z,1527797781.721 [Supervisor](INFO): Main Thread ID is 4448
2018-05-31T20:16:21.721Z,1527797781.721 [Supervisor](DEBUG): Running supervisor.
2018-05-31T20:16:21.722Z,1527797781.722 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4697
2018-05-31T20:16:21.724Z,1527797781.724 [controlThread ThreadHandler](INFO): Handler Thread ID is 4698
2018-05-31T20:16:21.725Z,1527797781.725 [controlThread](DEBUG): Initializing ControlThread
2018-05-31T20:16:21.726Z,1527797781.726 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-05-31T20:16:21.726Z,1527797781.726 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-05-31T20:16:21.727Z,1527797781.727 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-05-31T20:16:21.727Z,1527797781.727 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-05-31T20:16:21.728Z,1527797781.728 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-05-31T20:16:21.728Z,1527797781.728 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-05-31T20:16:21.729Z,1527797781.729 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-05-31T20:16:21.734Z,1527797781.734 [SBIT](INFO): Initialize SBIT Component.
2018-05-31T20:16:21.734Z,1527797781.734 [SBIT](IMPORTANT): git: 2018-05-22-8-g8382578
2018-05-31T20:16:21.735Z,1527797781.735 [SBIT](INFO): git hash: 83825789aaa96a7be17ace6d33dcc0adbd55c958
2018-05-31T20:16:21.735Z,1527797781.735 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-05-31T20:16:21.736Z,1527797781.736 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-05-31T20:16:21.738Z,1527797781.738 [SBIT](INFO): Beginning SBIT in 63.000000 seconds.
2018-05-31T20:16:21.738Z,1527797781.738 [IBIT](INFO): Initialize IBIT Component.
2018-05-31T20:16:21.739Z,1527797781.739 [CBIT](DEBUG): Initialize CBIT Component.
2018-05-31T20:16:21.739Z,1527797781.739 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-05-31T20:16:21.740Z,1527797781.740 [logger ThreadHandler](INFO): Handler Thread ID is 4699
2018-05-31T20:16:21.757Z,1527797781.757 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4700
2018-05-31T20:16:21.763Z,1527797781.763 [Radio_Surface](INFO): Powering up
2018-05-31T20:16:21.769Z,1527797781.769 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 4701
2018-05-31T20:16:21.770Z,1527797781.770 [Rowe_600LCM](INFO): Initializing
2018-05-31T20:16:21.770Z,1527797781.770 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T20:16:21.779Z,1527797781.779 [Rowe_600LCM](INFO): LCM OK
2018-05-31T20:16:21.780Z,1527797781.780 [Rowe_600LCM](INFO): Powering up
2018-05-31T20:16:21.785Z,1527797781.785 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 4702
2018-05-31T20:16:21.786Z,1527797781.786 [CTD_Seabird](INFO): Initializing
2018-05-31T20:16:21.787Z,1527797781.787 [CTD_Seabird](INFO): Checking LCM
2018-05-31T20:16:21.787Z,1527797781.787 [CTD_Seabird](INFO): LCM OK
2018-05-31T20:16:21.787Z,1527797781.787 [CTD_Seabird](INFO): Powering up
2018-05-31T20:16:21.793Z,1527797781.793 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4703
2018-05-31T20:16:21.794Z,1527797781.794 [WetLabsBB2FL](INFO): Powering down
2018-05-31T20:16:21.817Z,1527797781.817 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4704
2018-05-31T20:16:21.820Z,1527797781.820 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-05-31T20:16:21.821Z,1527797781.821 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-05-31T20:16:21.821Z,1527797781.821 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-05-31T20:16:21.821Z,1527797781.821 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-05-31T20:16:21.822Z,1527797781.822 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-05-31T20:16:21.822Z,1527797781.822 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-05-31T20:16:21.822Z,1527797781.822 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-05-31T20:16:21.822Z,1527797781.822 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-05-31T20:16:21.823Z,1527797781.823 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-05-31T20:16:21.823Z,1527797781.823 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-05-31T20:16:21.823Z,1527797781.823 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-05-31T20:16:21.823Z,1527797781.823 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-05-31T20:16:21.823Z,1527797781.823 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-05-31T20:16:21.824Z,1527797781.824 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-05-31T20:16:21.824Z,1527797781.824 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-05-31T20:16:21.824Z,1527797781.824 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-05-31T20:16:21.849Z,1527797781.849 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-05-31T20:16:21.851Z,1527797781.851 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-05-31T20:16:21.852Z,1527797781.852 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-05-31T20:16:21.852Z,1527797781.852 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-05-31T20:16:21.854Z,1527797781.854 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T20:16:21.855Z,1527797781.855 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T20:16:21.856Z,1527797781.856 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T20:16:21.856Z,1527797781.856 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-05-31T20:16:21.856Z,1527797781.856 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-05-31T20:16:21.858Z,1527797781.858 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-05-31T20:16:21.878Z,1527797781.878 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-05-31T20:16:21.906Z,1527797781.906 [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>


2018-05-31T20:16:21.906Z,1527797781.906 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-05-31T20:16:22.003Z,1527797782.003 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-05-31T20:16:22.004Z,1527797782.004 [Default:A.Wait](DEBUG): Construct Wait.
2018-05-31T20:16:22.006Z,1527797782.006 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-05-31T20:16:22.053Z,1527797782.053 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-05-31T20:16:22.055Z,1527797782.055 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-05-31T20:16:22.077Z,1527797782.077 [Default:E.Execute](DEBUG): Construct Execute.
2018-05-31T20:16:22.089Z,1527797782.089 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <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">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <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>


2018-05-31T20:16:22.094Z,1527797782.094 [controlThread](DEBUG): Component order: CycleStarter,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-05-31T20:16:22.120Z,1527797782.120 [AcousticModem_Benthos_ATM900](INFO): Powering up
2018-05-31T20:16:22.120Z,1527797782.120 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2018-05-31T20:16:22.153Z,1527797782.153 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-05-31T20:16:22.162Z,1527797782.162 [Depth_Keller](ERROR): Pressure reading out of range: 1895.584351 decibar
2018-05-31T20:16:22.435Z,1527797782.435 [ESPComponent](INFO): powering down ESP
2018-05-31T20:16:22.909Z,1527797782.909 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-05-31T20:16:23.002Z,1527797783.002 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-31T20:16:23.141Z,1527797783.141 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-05-31T20:16:23.149Z,1527797783.149 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-05-31T20:16:23.164Z,1527797783.164 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-05-31T20:16:23.169Z,1527797783.169 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-05-31T20:16:23.181Z,1527797783.181 [MassServo](DEBUG): Initializing EZServoServo.
2018-05-31T20:16:23.189Z,1527797783.189 [MassServo](DEBUG): Initializing MassServo.
2018-05-31T20:16:23.211Z,1527797783.211 [RudderServo](DEBUG): Initializing EZServoServo.
2018-05-31T20:16:23.217Z,1527797783.217 [RudderServo](DEBUG): Initializing RudderServo.
2018-05-31T20:16:23.227Z,1527797783.227 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-05-31T20:16:23.233Z,1527797783.233 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-05-31T20:16:23.560Z,1527797783.560 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-31T20:16:23.811Z,1527797783.811 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-31T20:16:24.313Z,1527797784.313 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-31T20:16:24.671Z,1527797784.671 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-31T20:16:25.039Z,1527797785.039 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-31T20:16:25.549Z,1527797785.549 [Aanderaa_O2](INFO): Powering down
2018-05-31T20:16:25.602Z,1527797785.602 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-31T20:16:25.899Z,1527797785.899 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-31T20:16:26.066Z,1527797786.066 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T20:16:26.139Z,1527797786.139 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T20:16:26.170Z,1527797786.170 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T20:16:26.171Z,1527797786.171 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T20:16:26.172Z,1527797786.172 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T20:16:27.363Z,1527797787.363 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-05-31T20:16:27.516Z,1527797787.516 [CTD_Seabird](INFO): Started Seabird LCM interface with command:nohup ./lrauv-framework/onboard/bin/gpctd -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyC6 -b 9600 >& /dev/null &
2018-05-31T20:16:27.521Z,1527797787.521 [CTD_Seabird](INFO): LCM subscribed to channel:ctd_t.seabird-gpctd
2018-05-31T20:16:27.951Z,1527797787.951 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-05-31T20:16:27.952Z,1527797787.952 [CTD_Seabird](INFO): Powering down
2018-05-31T20:16:29.809Z,1527797789.809 [AcousticModem_Benthos_ATM900](DEBUG): 
2018-05-31T20:16:31.008Z,1527797791.008 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2018-05-31T20:16:31.009Z,1527797791.009 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2018-05-31T20:16:31.009Z,1527797791.009 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2018-05-31T20:16:31.010Z,1527797791.010 [AcousticModem_Benthos_ATM900](DEBUG): Apr  7 2000 20:12:08 
2018-05-31T20:16:31.407Z,1527797791.407 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: battery low
2018-05-31T20:16:32.207Z,1527797792.207 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2018-05-31T20:16:32.607Z,1527797792.607 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2018-05-31T20:16:32.607Z,1527797792.607 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2018-05-31T20:16:32.608Z,1527797792.608 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2018-05-31T20:16:33.008Z,1527797793.008 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2018-05-31T20:16:33.407Z,1527797793.407 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2018-05-31T20:16:33.408Z,1527797793.408 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2018-05-31T20:16:33.809Z,1527797793.809 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2018-05-31T20:16:48.215Z,1527797808.215 [NAL9602](INFO): Powering up NAL9602
2018-05-31T20:16:59.108Z,1527797819.108 [CommandLine](IMPORTANT): got command get ESPComponent.loadAtStartup
2018-05-31T20:16:59.108Z,1527797819.108 [CommandLine](IMPORTANT): ESPComponent.loadAtStartup 1 bool
2018-05-31T20:16:59.431Z,1527797819.431 [NAL9602](INFO): NAL9602 initialized
2018-05-31T20:17:18.827Z,1527797838.827 [CommandLine](IMPORTANT): got command get ESPComponent.simulateHardware
2018-05-31T20:17:18.828Z,1527797838.828 [CommandLine](IMPORTANT): ESPComponent.simulateHardware 0 bool
2018-05-31T20:17:25.140Z,1527797845.140 [SBIT](IMPORTANT): Beginning Startup BIT
2018-05-31T20:17:25.162Z,1527797845.162 [CBIT](IMPORTANT): Beginning ground fault scan
2018-05-31T20:17:36.207Z,1527797856.207 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.010959
CHAN A1 (24V): -0.013965
CHAN A2 (12V): -0.005787
CHAN A3 (5V): -0.002564
CHAN B0 (3.3V): -0.001005
CHAN B1 (3.15aV): -0.001156
CHAN B2 (3.15bV): -0.001550
CHAN B3 (GND): 0.000218
OPEN: 0.004550
Full Scale Calc: 4.765 mA, -1.589 mA
2018-05-31T20:18:04.722Z,1527797884.722 [CommandLine](IMPORTANT): got command failComponent
2018-05-31T20:18:04.722Z,1527797884.722 [CommandLine](IMPORTANT): Failed components:
2018-05-31T20:18:04.723Z,1527797884.723 [CommandLine](IMPORTANT): No failed Components.
2018-05-31T20:18:18.938Z,1527797898.938 [SBIT](IMPORTANT): SBIT PASSED
2018-05-31T20:18:19.035Z,1527797899.035 [CommandLine](IMPORTANT): got command configSet list
2018-05-31T20:18:19.036Z,1527797899.036 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-05-31T20:18:19.037Z,1527797899.037 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2018-05-31T20:18:19.323Z,1527797899.323 [MissionManager](IMPORTANT): Started mission Startup
2018-05-31T20:18:19.324Z,1527797899.324 [Startup] Running Loop=1
2018-05-31T20:18:19.324Z,1527797899.324 [Startup](DEBUG): Aggregate::initialize Startup
2018-05-31T20:18:19.324Z,1527797899.324 [Startup:A.GoToSurface] Running Loop=1
2018-05-31T20:18:19.324Z,1527797899.324 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-05-31T20:18:19.326Z,1527797899.326 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-05-31T20:18:19.327Z,1527797899.327 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-05-31T20:18:19.328Z,1527797899.328 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-05-31T20:18:19.328Z,1527797899.328 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-05-31T20:18:19.329Z,1527797899.329 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-05-31T20:18:19.338Z,1527797899.338 [Startup:StartupSatComms] Running Loop=1
2018-05-31T20:18:19.338Z,1527797899.338 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-05-31T20:18:19.338Z,1527797899.338 [Startup:StartupSatComms:A] Running Loop=1
2018-05-31T20:18:19.720Z,1527797899.720 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-05-31T20:18:22.457Z,1527797902.457 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T20:18:22.457Z,1527797902.457 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-05-31T20:18:22.457Z,1527797902.457 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T20:18:22.552Z,1527797902.552 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T20:18:22.861Z,1527797902.861 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T20:18:23.131Z,1527797903.131 [Rowe_600LCM](INFO): Powering down
2018-05-31T20:18:24.478Z,1527797904.478 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-05-31T20:18:24.478Z,1527797904.478 [Rowe_600LCM] No Fault, FailCount= 1
2018-05-31T20:18:24.748Z,1527797904.748 [Rowe_600LCM](INFO): Initializing
2018-05-31T20:18:24.749Z,1527797904.749 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T20:18:24.749Z,1527797904.749 [Rowe_600LCM](INFO): LCM OK
2018-05-31T20:18:24.749Z,1527797904.749 [Rowe_600LCM](INFO): Powering up
2018-05-31T20:18:28.999Z,1527797908.999 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T20:18:29.064Z,1527797909.064 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T20:18:29.065Z,1527797909.065 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T20:18:29.066Z,1527797909.066 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T20:18:29.067Z,1527797909.067 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T20:19:19.686Z,1527797959.686 [Startup:StartupSatComms:A](INFO): Timed out from 2018-05-31T20:18:19.3Z
2018-05-31T20:19:19.686Z,1527797959.686 [Startup:StartupSatComms:A] Stopped
2018-05-31T20:19:19.687Z,1527797959.687 [Startup:StartupSatComms:B] Running Loop=1
2018-05-31T20:19:20.079Z,1527797960.079 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-05-31T20:19:22.081Z,1527797962.081 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T20:19:22.081Z,1527797962.081 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-05-31T20:19:22.081Z,1527797962.081 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T20:19:22.110Z,1527797962.110 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T20:19:22.527Z,1527797962.527 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T20:19:22.527Z,1527797962.527 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-05-31T20:19:22.902Z,1527797962.902 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T20:19:22.902Z,1527797962.902 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T20:19:22.903Z,1527797962.903 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T20:19:28.890Z,1527797968.890 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.008782
2018-05-31T20:19:33.480Z,1527797973.480 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180531T200647/Courier0004.lzma
2018-05-31T20:19:34.282Z,1527797974.282 [DataOverHttps](INFO): Moved sent file to Logs/20180531T200647/Courier0004.lzma.bak
2018-05-31T20:19:34.282Z,1527797974.282 [DataOverHttps](INFO): SBD MOMSN=8300470
2018-05-31T20:19:45.315Z,1527797985.315 [DataOverHttps](INFO): Sending 612 bytes from file Logs/20180531T200647/Express0005.lzma
2018-05-31T20:19:46.094Z,1527797986.094 [DataOverHttps](INFO): Moved sent file to Logs/20180531T200647/Express0005.lzma.bak
2018-05-31T20:19:46.094Z,1527797986.094 [DataOverHttps](INFO): SBD MOMSN=8300472
2018-05-31T20:19:57.375Z,1527797997.375 [DataOverHttps](INFO): Sending 794 bytes from file Logs/20180531T201611/Express0001.lzma
2018-05-31T20:19:58.146Z,1527797998.146 [DataOverHttps](INFO): Moved sent file to Logs/20180531T201611/Express0001.lzma.bak
2018-05-31T20:19:58.146Z,1527797998.146 [DataOverHttps](INFO): SBD MOMSN=8300489
2018-05-31T20:19:59.531Z,1527797999.531 [Startup:StartupSatComms:B] Stopped
2018-05-31T20:19:59.531Z,1527797999.531 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-05-31T20:19:59.531Z,1527797999.531 [Startup:StartupSatComms] Stopped
2018-05-31T20:19:59.531Z,1527797999.531 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-05-31T20:19:59.533Z,1527797999.533 [Startup](INFO): Completed Startup
2018-05-31T20:19:59.533Z,1527797999.533 [MissionManager](INFO): Startup is completed.
2018-05-31T20:19:59.533Z,1527797999.533 [MissionManager](INFO): Uninitializing Mission Startup
2018-05-31T20:19:59.533Z,1527797999.533 [Startup] Stopped
2018-05-31T20:19:59.534Z,1527797999.534 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-05-31T20:19:59.534Z,1527797999.534 [Startup:A.GoToSurface] Stopped
2018-05-31T20:19:59.534Z,1527797999.534 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-05-31T20:19:59.692Z,1527797999.692 [MissionManager](IMPORTANT): Started mission Default
2018-05-31T20:19:59.692Z,1527797999.692 [Default] Running Loop=1
2018-05-31T20:19:59.692Z,1527797999.692 [Default](DEBUG): Aggregate::initialize Default
2018-05-31T20:19:59.693Z,1527797999.693 [Default:B.GoToSurface] Running Loop=1
2018-05-31T20:19:59.693Z,1527797999.693 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-05-31T20:19:59.694Z,1527797999.694 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-05-31T20:19:59.694Z,1527797999.694 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-05-31T20:19:59.694Z,1527797999.694 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-05-31T20:19:59.695Z,1527797999.695 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-05-31T20:19:59.695Z,1527797999.695 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-05-31T20:19:59.696Z,1527797999.696 [Default:A.Wait] Running Loop=1
2018-05-31T20:19:59.696Z,1527797999.696 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-05-31T20:20:12.880Z,1527798012.880 [Default:A.Wait](INFO): Done Waiting.
2018-05-31T20:20:12.880Z,1527798012.880 [Default:A.Wait] Stopped
2018-05-31T20:20:12.880Z,1527798012.880 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-05-31T20:20:13.292Z,1527798013.292 [Default:CheckIn] Running Loop=1
2018-05-31T20:20:13.292Z,1527798013.292 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-05-31T20:20:13.293Z,1527798013.293 [Default:CheckIn:Read_GPS] Running Loop=1
2018-05-31T20:20:13.694Z,1527798013.694 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-05-31T20:20:25.349Z,1527798025.349 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T20:20:25.349Z,1527798025.349 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-05-31T20:20:25.349Z,1527798025.349 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T20:20:25.382Z,1527798025.382 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T20:20:25.753Z,1527798025.753 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T20:20:26.071Z,1527798026.071 [Rowe_600LCM](INFO): Powering down
2018-05-31T20:20:27.317Z,1527798027.317 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-05-31T20:20:27.317Z,1527798027.317 [Rowe_600LCM] No Fault, FailCount= 2
2018-05-31T20:20:27.689Z,1527798027.689 [Rowe_600LCM](INFO): Initializing
2018-05-31T20:20:27.690Z,1527798027.690 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T20:20:27.690Z,1527798027.690 [Rowe_600LCM](INFO): LCM OK
2018-05-31T20:20:27.690Z,1527798027.690 [Rowe_600LCM](INFO): Powering up
2018-05-31T20:20:31.903Z,1527798031.903 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T20:20:32.002Z,1527798032.002 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T20:20:32.004Z,1527798032.004 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T20:20:32.005Z,1527798032.005 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T20:20:32.006Z,1527798032.006 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T20:21:03.483Z,1527798063.483 [CommandLine](IMPORTANT): got command show stack
2018-05-31T20:21:03.483Z,1527798063.483 [CommandLine](IMPORTANT): Behavior Stack:

2018-05-31T20:21:03.484Z,1527798063.484 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface
2018-05-31T20:21:03.484Z,1527798063.484 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:Read_GPS
2018-05-31T20:21:06.778Z,1527798066.778 [CommandLine](IMPORTANT): got command failComponent
2018-05-31T20:21:06.778Z,1527798066.778 [CommandLine](IMPORTANT): Failed components:
2018-05-31T20:21:06.778Z,1527798066.778 [CommandLine](IMPORTANT): No failed Components.
2018-05-31T20:21:33.836Z,1527798093.836 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-05-31T20:21:34.638Z,1527798094.638 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-05-31T20:21:35.014Z,1527798095.014 [CommandLine](IMPORTANT): got command failComponent
2018-05-31T20:21:35.014Z,1527798095.014 [CommandLine](IMPORTANT): Failed components:
2018-05-31T20:21:35.014Z,1527798095.014 [CommandLine](IMPORTANT): No failed Components.
2018-05-31T20:22:05.668Z,1527798125.668 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-05-31T20:22:06.643Z,1527798126.643 [DataOverHttps](IMPORTANT): SBD MTMSN=20180531T202151
2018-05-31T20:22:12.096Z,1527798132.096 [DataOverHttps](INFO): Received command:load Maintenance/sample.xml;set sample.MissionTimeout 120 minute;set sample.Depth 2 meter;set sample.WaitBeforeSample 10 second;set sample:SampleAtDepth.TargetDepth 2 meter;set sample:SampleAtDepth.SettleTime 10 second;run 
2018-05-31T20:22:12.138Z,1527798132.138 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/sample.xml
2018-05-31T20:22:12.150Z,1527798132.150 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/sample.xml
2018-05-31T20:22:12.191Z,1527798132.191 [MissionManager](INFO): DefineArg sample.MissionTimeout = 90.000000 min
2018-05-31T20:22:12.217Z,1527798132.217 [MissionManager](INFO): DefineArg sample.Depth = 7.000000 m
2018-05-31T20:22:12.223Z,1527798132.223 [MissionManager](INFO): DefineArg sample.NumberOfSamples = 1.000000 count
2018-05-31T20:22:12.228Z,1527798132.228 [MissionManager](INFO): DefineArg sample.WaitBeforeSample = 3.000000 min
2018-05-31T20:22:12.230Z,1527798132.230 [sample:A.Pitch](DEBUG): Construct.
2018-05-31T20:22:12.238Z,1527798132.238 [sample:B.SetSpeed](DEBUG): Construct.
2018-05-31T20:22:12.265Z,1527798132.265 [MissionManager](INFO): Inserting Stack: Missions/Insert/SampleAtDepth.xml
2018-05-31T20:22:12.410Z,1527798132.410 [MissionManager](INFO): DefineArg sample:SampleAtDepth.TargetDepth = 5.000000 m
2018-05-31T20:22:12.414Z,1527798132.414 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SettleTime = 30.000000 s
2018-05-31T20:22:12.418Z,1527798132.418 [MissionManager](INFO): DefineArg sample:SampleAtDepth.MaxWaitNotReachingDepth = 3.000000 h
2018-05-31T20:22:12.422Z,1527798132.422 [MissionManager](INFO): DefineArg sample:SampleAtDepth.RotateOnly = 0.000000 bool
2018-05-31T20:22:12.426Z,1527798132.426 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseCANONSampler = 0.000000 bool
2018-05-31T20:22:12.430Z,1527798132.430 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseESP = 1.000000 bool
2018-05-31T20:22:12.434Z,1527798132.434 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTriggerTimeout = 1.000000 min
2018-05-31T20:22:12.438Z,1527798132.438 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTimeout = 6.000000 min
2018-05-31T20:22:12.442Z,1527798132.442 [sample:SampleAtDepth:B.Pitch](DEBUG): Construct.
2018-05-31T20:22:12.477Z,1527798132.477 [sample:SampleAtDepth:B.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2018-05-31T20:22:12.482Z,1527798132.482 [sample:SampleAtDepth:D.Wait](DEBUG): Construct Wait.
2018-05-31T20:22:12.542Z,1527798132.542 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler:A_Timeout:B.Execute](DEBUG): Construct Execute.
2018-05-31T20:22:12.545Z,1527798132.545 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature
2018-05-31T20:22:12.545Z,1527798132.545 [MissionManager](ERROR): Slate does not contain celsius
2018-05-31T20:22:12.554Z,1527798132.554 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E:A_Timeout:B.Execute](DEBUG): Construct Execute.
2018-05-31T20:22:12.560Z,1527798132.560 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature
2018-05-31T20:22:12.560Z,1527798132.560 [MissionManager](ERROR): Slate does not contain celsius
2018-05-31T20:22:12.614Z,1527798132.614 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd"
       Id="sample">

    <Description>
        This mission is designed to be run in the test tank only and samples
        whichever sampler is installed once the vehicle reaches the target depth.
    </Description>
    <DefineArg Name="MissionTimeout"><Description>
        How long to let the mission run.
    </Description><Units:minute/><Value>90</Value></DefineArg>

    <DefineArg Name="Depth"><Description>
        Depth to sample at.
    </Description><Units:meter/><Value>7</Value></DefineArg>

    <DefineArg Name="NumberOfSamples"><Description>
        Number of samples to take.
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="WaitBeforeSample"><Description>
        How long to wait between samples. This starts *before* the first sample
        to exercise the SettleTime setting in the insert aggregate.
    </Description><Units:minute/><Value>3</Value></DefineArg>
    <Timeout Duration="MissionTimeout"/>
    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Units:meter_per_second/><Value>0</Value></Setting>
    </Guidance:SetSpeed>

    <Insert Filename="Insert/SampleAtDepth.xml"/>

    <Assign><Sequence/><Arg Name="SampleAtDepth:TargetDepth"/><Arg Name="Depth"/></Assign>

    <Assign><Sequence/><Arg Name="SampleAtDepth:SettleTime"/><Arg Name="WaitBeforeSample"/></Assign>

    <Aggregate Id="SampleRepeater">
        <Sequence Repeat="NumberOfSamples"/>

        <Call Id="Sample" RefId="SampleAtDepth"/>
    </Aggregate>
</Mission>

2018-05-31T20:22:12.614Z,1527798132.614 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/sample.xml
2018-05-31T20:22:21.778Z,1527798141.778 [CommandLine](IMPORTANT): got command set sample.MissionTimeout 120.000000 minute
2018-05-31T20:22:21.779Z,1527798141.779 [CommandLine](IMPORTANT): got command set sample.Depth 2.000000 meter
2018-05-31T20:22:21.780Z,1527798141.780 [CommandLine](IMPORTANT): got command set sample.WaitBeforeSample 10.000000 second
2018-05-31T20:22:21.781Z,1527798141.781 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.TargetDepth 2.000000 meter
2018-05-31T20:22:21.782Z,1527798141.782 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.SettleTime 10.000000 second
2018-05-31T20:22:21.783Z,1527798141.783 [CommandLine](IMPORTANT): got command run 
2018-05-31T20:22:21.786Z,1527798141.786 [CommandLine](IMPORTANT): Running 
2018-05-31T20:22:21.874Z,1527798141.875 [Default] Stopped
2018-05-31T20:22:21.875Z,1527798141.875 [Default](DEBUG): Aggregate::uninitialize Default
2018-05-31T20:22:21.875Z,1527798141.875 [Default:B.GoToSurface] Stopped
2018-05-31T20:22:21.875Z,1527798141.875 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-05-31T20:22:21.875Z,1527798141.875 [Default:CheckIn] Stopped
2018-05-31T20:22:21.875Z,1527798141.875 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-05-31T20:22:21.875Z,1527798141.875 [Default:CheckIn:Read_GPS] Stopped
2018-05-31T20:22:21.876Z,1527798141.876 [MissionManager](IMPORTANT): Started mission sample
2018-05-31T20:22:21.876Z,1527798141.876 [sample] Running Loop=1
2018-05-31T20:22:21.876Z,1527798141.876 [sample](DEBUG): Aggregate::initialize sample
2018-05-31T20:22:21.876Z,1527798141.876 [sample:A.Pitch] Running Loop=1
2018-05-31T20:22:21.876Z,1527798141.876 [sample:A.Pitch](DEBUG): Initialize.
2018-05-31T20:22:21.881Z,1527798141.881 [sample:B.SetSpeed] Running Loop=1
2018-05-31T20:22:21.881Z,1527798141.881 [sample:B.SetSpeed](DEBUG): Initialize.
2018-05-31T20:22:21.881Z,1527798141.881 [sample:D] Running Loop=1
2018-05-31T20:22:21.884Z,1527798141.884 [sample:D] Stopped
2018-05-31T20:22:21.884Z,1527798141.884 [sample:E] Running Loop=1
2018-05-31T20:22:21.884Z,1527798141.884 [sample:B.SetSpeed] Running Loop=1
2018-05-31T20:22:21.898Z,1527798141.898 [sample:A.Pitch] Running Loop=1
2018-05-31T20:22:22.083Z,1527798142.083 [sample:E] Stopped
2018-05-31T20:22:22.083Z,1527798142.083 [sample:SampleRepeater] Running Loop=1
2018-05-31T20:22:22.083Z,1527798142.083 [sample:SampleRepeater](DEBUG): Aggregate::initialize sample:SampleRepeater
2018-05-31T20:22:22.083Z,1527798142.083 [sample:SampleRepeater:Sample] Running Loop=1
2018-05-31T20:22:22.084Z,1527798142.084 [sample:SampleRepeater:Sample](DEBUG): Aggregate::initialize sample:SampleRepeater:Sample
2018-05-31T20:22:22.424Z,1527798142.424 [sample:SampleAtDepth] Running Loop=1
2018-05-31T20:22:22.424Z,1527798142.424 [sample:SampleAtDepth](DEBUG): Aggregate::initialize sample:SampleAtDepth
2018-05-31T20:22:22.425Z,1527798142.425 [sample:SampleAtDepth:B.Pitch] Running Loop=1
2018-05-31T20:22:22.425Z,1527798142.425 [sample:SampleAtDepth:B.Pitch](DEBUG): Initialize.
2018-05-31T20:22:22.425Z,1527798142.425 [sample:SampleAtDepth:A] Running Loop=1
2018-05-31T20:22:22.432Z,1527798142.432 [sample:SampleAtDepth:A](INFO): Moving to 2.000000 m 
2018-05-31T20:22:22.435Z,1527798142.435 [sample:SampleAtDepth:A] Stopped
2018-05-31T20:22:23.212Z,1527798143.212 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T20:22:23.214Z,1527798143.214 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2018-05-31T20:22:23.214Z,1527798143.214 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T20:22:23.243Z,1527798143.243 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T20:22:23.672Z,1527798143.672 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T20:22:23.672Z,1527798143.672 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2018-05-31T20:22:24.008Z,1527798144.008 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T20:22:24.008Z,1527798144.008 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T20:22:24.013Z,1527798144.013 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T20:22:27.737Z,1527798147.737 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T20:22:27.737Z,1527798147.737 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-05-31T20:22:27.737Z,1527798147.737 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T20:22:28.095Z,1527798148.095 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T20:22:28.141Z,1527798148.141 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T20:22:28.271Z,1527798148.271 [Rowe_600LCM](INFO): Powering down
2018-05-31T20:22:29.671Z,1527798149.671 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-05-31T20:22:29.672Z,1527798149.672 [Rowe_600LCM] No Fault, FailCount= 3
2018-05-31T20:22:29.885Z,1527798149.885 [Rowe_600LCM](INFO): Initializing
2018-05-31T20:22:29.885Z,1527798149.885 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T20:22:29.886Z,1527798149.886 [Rowe_600LCM](INFO): LCM OK
2018-05-31T20:22:29.886Z,1527798149.886 [Rowe_600LCM](INFO): Powering up
2018-05-31T20:22:34.139Z,1527798154.139 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T20:22:34.216Z,1527798154.216 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T20:22:34.217Z,1527798154.217 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T20:22:34.218Z,1527798154.218 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T20:22:34.218Z,1527798154.218 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T20:22:40.797Z,1527798160.797 [BPC1](ERROR): Failed to receive data from both battery packs
2018-05-31T20:22:40.797Z,1527798160.797 [BPC1] Communications Fault, FailCount= 1
2018-05-31T20:22:40.797Z,1527798160.797 [BPC1](ERROR): Communications Fault
2018-05-31T20:22:40.887Z,1527798160.887 [CBIT](ERROR): Communications Fault in component: BPC1
2018-05-31T20:22:42.112Z,1527798162.112 [CBIT](INFO): Clearing failed state for component BPC1
2018-05-31T20:22:42.112Z,1527798162.112 [BPC1] No Fault, FailCount= 1
2018-05-31T20:22:43.827Z,1527798163.827 [CommandLine](IMPORTANT): got command maintain sensor Depth_Keller.depth 2.000000 meter
2018-05-31T20:22:43.829Z,1527798163.829 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread.
2018-05-31T20:22:44.086Z,1527798164.086 [controlThread](DEBUG): Component order: CycleStarter,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_Depth_Keller.depth,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-05-31T20:22:44.437Z,1527798164.437 [sample:SampleAtDepth:C] Running Loop=1
2018-05-31T20:22:44.666Z,1527798164.666 [Radio_Surface](INFO): Powering down
2018-05-31T20:22:44.804Z,1527798164.804 [sample:SampleAtDepth:C](INFO): At 2.000000 m , settling for 0.166667 min 
2018-05-31T20:22:44.822Z,1527798164.822 [sample:SampleAtDepth:C] Stopped
2018-05-31T20:22:44.822Z,1527798164.822 [sample:SampleAtDepth:D.Wait] Running Loop=1
2018-05-31T20:22:44.822Z,1527798164.822 [sample:SampleAtDepth:D.Wait](DEBUG): Initialize Wait Component.
2018-05-31T20:22:46.327Z,1527798166.327 [CommandLine](IMPORTANT): got command get depth
2018-05-31T20:22:46.328Z,1527798166.328 [CommandLine](IMPORTANT): depth 2.000000 m
2018-05-31T20:22:54.362Z,1527798174.362 [Radio_Surface](INFO): Powering up
2018-05-31T20:22:55.619Z,1527798175.619 [sample:SampleAtDepth:D.Wait](INFO): Done Waiting.
2018-05-31T20:22:55.619Z,1527798175.619 [sample:SampleAtDepth:D.Wait] Stopped
2018-05-31T20:22:55.619Z,1527798175.619 [sample:SampleAtDepth:D.Wait](DEBUG): Uninitialize Wait Component.
2018-05-31T20:22:55.620Z,1527798175.620 [sample:SampleAtDepth:SampleWrapper] Running Loop=1
2018-05-31T20:22:55.620Z,1527798175.620 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper
2018-05-31T20:22:55.620Z,1527798175.620 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Running Loop=1
2018-05-31T20:22:55.620Z,1527798175.620 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2018-05-31T20:22:55.620Z,1527798175.620 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Running Loop=1
2018-05-31T20:22:55.620Z,1527798175.620 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Running Loop=1
2018-05-31T20:22:55.621Z,1527798175.621 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Running Loop=1
2018-05-31T20:22:56.002Z,1527798176.002 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Stopped
2018-05-31T20:22:56.002Z,1527798176.002 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2018-05-31T20:22:56.002Z,1527798176.002 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Stopped
2018-05-31T20:22:56.002Z,1527798176.002 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Stopped
2018-05-31T20:22:56.002Z,1527798176.002 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Stopped
2018-05-31T20:22:56.002Z,1527798176.002 [sample:SampleAtDepth:SampleWrapper:SampleESP] Running Loop=1
2018-05-31T20:22:56.003Z,1527798176.003 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleESP
2018-05-31T20:22:56.003Z,1527798176.003 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Running Loop=1
2018-05-31T20:22:56.430Z,1527798176.430 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sampling
2018-05-31T20:22:57.598Z,1527798177.598 [ESPComponent](INFO): powering up ESP
2018-05-31T20:22:57.599Z,1527798177.599 [ESPComponent](INFO): manually powering up ESP
2018-05-31T20:22:57.601Z,1527798177.601 [ESPComponent](IMPORTANT): Powered ESP with command: ! echo 1 > /dev/loadA6
2018-05-31T20:22:57.602Z,1527798177.602 [ESPComponent](IMPORTANT): Starting PPPD with command:/sbin/pppd xonxoff asyncmap A0000 /dev/ttyTX1 linkname esp noauth local lock 115200 134.89.95.2:134.89.95.12 persist maxfail 0 holdoff 10 lcp-echo-interval 60 lcp-echo-failure 3 proxyarp ktune deflate 12 ms-dns 134.89.10.32 ms-dns 134.89.10.10
2018-05-31T20:22:57.632Z,1527798177.632 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadA6
2018-05-31T20:22:58.046Z,1527798178.046 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=150.0000)
2018-05-31T20:23:00.018Z,1527798180.018 [Radio_Surface](INFO): Powering down
2018-05-31T20:23:21.034Z,1527798201.034 [Radio_Surface](INFO): Powering up
2018-05-31T20:23:26.690Z,1527798206.690 [Radio_Surface](INFO): Powering down
2018-05-31T20:23:33.091Z,1527798213.091 [ESPComponent](IMPORTANT): ESP has connected as client
2018-05-31T20:23:33.876Z,1527798213.876 [ESPComponent](IMPORTANT): ESP sampling sequence starting (sample #1)  sampling state: S_WAITING_INITIAL_PROMPT
2018-05-31T20:23:33.877Z,1527798213.877 [ESPComponent](DEBUG): Writing samplingActive=1, sampleNumber=1
2018-05-31T20:23:33.920Z,1527798213.920 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Stopped
2018-05-31T20:23:33.921Z,1527798213.921 [sample:SampleAtDepth:SampleWrapper:SampleESP:B] Running Loop=1
2018-05-31T20:23:34.369Z,1527798214.369 [sample:SampleAtDepth:SampleWrapper:SampleESP:B](IMPORTANT): ESP sampling at 2.000000 m inwater with nan ug/l chlorophyll fluorescence.
2018-05-31T20:23:34.371Z,1527798214.371 [sample:SampleAtDepth:SampleWrapper:SampleESP:B] Stopped
2018-05-31T20:23:34.372Z,1527798214.372 [sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP] Running Loop=1
2018-05-31T20:23:34.703Z,1527798214.703 [sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sample_number
2018-05-31T20:23:35.087Z,1527798215.087 [ESPComponent](IMPORTANT): ESP sampling state: S_PREPARING_SHOW_LOG
2018-05-31T20:23:35.477Z,1527798215.477 [ESPComponent](IMPORTANT): ESP sampling state: S_PREPARING_SHOW_STATUS
2018-05-31T20:23:37.079Z,1527798217.079 [ESPComponent](IMPORTANT): ESP sampling state: S_LOADING_CARTRIDGE
2018-05-31T20:23:37.425Z,1527798217.425 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:23:59.038Z,1527798239.038 [Radio_Surface](INFO): Powering up
2018-05-31T20:24:04.694Z,1527798244.694 [Radio_Surface](INFO): Powering down
2018-05-31T20:24:30.625Z,1527798270.625 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T20:24:30.625Z,1527798270.625 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-05-31T20:24:30.625Z,1527798270.625 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T20:24:30.765Z,1527798270.765 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T20:24:31.029Z,1527798271.029 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T20:24:31.300Z,1527798271.300 [Rowe_600LCM](INFO): Powering down
2018-05-31T20:24:32.723Z,1527798272.723 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-05-31T20:24:32.723Z,1527798272.723 [Rowe_600LCM] No Fault, FailCount= 4
2018-05-31T20:24:32.913Z,1527798272.913 [Rowe_600LCM](INFO): Initializing
2018-05-31T20:24:32.913Z,1527798272.913 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T20:24:32.914Z,1527798272.914 [Rowe_600LCM](INFO): LCM OK
2018-05-31T20:24:32.914Z,1527798272.914 [Rowe_600LCM](INFO): Powering up
2018-05-31T20:24:37.099Z,1527798277.099 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T20:24:37.242Z,1527798277.242 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T20:24:37.243Z,1527798277.243 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T20:24:37.244Z,1527798277.244 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T20:24:37.244Z,1527798277.244 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T20:24:37.838Z,1527798277.838 [Radio_Surface](INFO): Powering up
2018-05-31T20:24:38.223Z,1527798278.223 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:24:43.502Z,1527798283.502 [Radio_Surface](INFO): Powering down
2018-05-31T20:25:05.881Z,1527798305.881 [BPC1](ERROR): Bank B: No match for stick 5 serial number:0000 in the onboard configuration file.
2018-05-31T20:25:05.881Z,1527798305.881 [BPC1](ERROR): Failed to parse Bank B battery data
2018-05-31T20:25:16.238Z,1527798316.238 [Radio_Surface](INFO): Powering up
2018-05-31T20:25:21.894Z,1527798321.894 [Radio_Surface](INFO): Powering down
2018-05-31T20:25:22.624Z,1527798322.624 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.275650
2018-05-31T20:25:24.306Z,1527798324.306 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T20:25:24.306Z,1527798324.306 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2018-05-31T20:25:24.306Z,1527798324.306 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T20:25:24.355Z,1527798324.355 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T20:25:24.733Z,1527798324.733 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T20:25:24.733Z,1527798324.733 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2018-05-31T20:25:25.076Z,1527798325.076 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T20:25:25.077Z,1527798325.077 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T20:25:25.078Z,1527798325.078 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T20:25:55.438Z,1527798355.438 [Radio_Surface](INFO): Powering up
2018-05-31T20:26:01.098Z,1527798361.098 [Radio_Surface](INFO): Powering down
2018-05-31T20:26:33.017Z,1527798393.017 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T20:26:33.017Z,1527798393.017 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-05-31T20:26:33.017Z,1527798393.017 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T20:26:33.157Z,1527798393.157 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T20:26:33.158Z,1527798393.158 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-05-31T20:26:33.421Z,1527798393.421 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T20:26:33.702Z,1527798393.702 [Rowe_600LCM](INFO): Powering down
2018-05-31T20:26:33.869Z,1527798393.869 [Radio_Surface](INFO): Powering up
2018-05-31T20:26:38.623Z,1527798398.623 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:26:39.538Z,1527798399.538 [Radio_Surface](INFO): Powering down
2018-05-31T20:27:01.827Z,1527798421.827 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-05-31T20:27:01.827Z,1527798421.827 [NAL9602] Data Fault, FailCount= 1
2018-05-31T20:27:01.827Z,1527798421.827 [NAL9602](ERROR): Data Fault
2018-05-31T20:27:01.928Z,1527798421.928 [CBIT](ERROR): Data Fault in component: NAL9602
2018-05-31T20:27:02.226Z,1527798422.226 [NAL9602](INFO): Powering down
2018-05-31T20:27:03.100Z,1527798423.100 [CBIT](INFO): Clearing failed state for component NAL9602
2018-05-31T20:27:03.100Z,1527798423.100 [NAL9602] No Fault, FailCount= 1
2018-05-31T20:27:07.826Z,1527798427.826 [Radio_Surface](INFO): Powering up
2018-05-31T20:27:13.482Z,1527798433.482 [Radio_Surface](INFO): Powering down
2018-05-31T20:27:22.947Z,1527798442.947 [CommandLine](IMPORTANT): got command show stack
2018-05-31T20:27:22.947Z,1527798442.947 [CommandLine](IMPORTANT): Behavior Stack:

2018-05-31T20:27:22.947Z,1527798442.947 [sample](IMPORTANT): Priority 0: sample:A.Pitch
2018-05-31T20:27:22.948Z,1527798442.948 [sample](IMPORTANT): Priority 1: sample:B.SetSpeed
2018-05-31T20:27:22.948Z,1527798442.948 [sample:SampleAtDepth](IMPORTANT): Priority 2: sample:SampleAtDepth:B.Pitch
2018-05-31T20:27:22.948Z,1527798442.948 [sample:SampleAtDepth:SampleWrapper:SampleESP](IMPORTANT): Priority 3: sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP
2018-05-31T20:27:32.630Z,1527798452.630 [NAL9602](INFO): Powering up NAL9602
2018-05-31T20:27:38.623Z,1527798458.623 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:27:43.826Z,1527798463.826 [NAL9602](INFO): NAL9602 initialized
2018-05-31T20:27:46.632Z,1527798466.632 [Radio_Surface](INFO): Powering up
2018-05-31T20:27:52.290Z,1527798472.290 [Radio_Surface](INFO): Powering down
2018-05-31T20:27:57.462Z,1527798477.462 [ESPComponent](IMPORTANT): ESP sampling state: S_FILTERING
2018-05-31T20:27:59.852Z,1527798479.852 [ESPComponent](IMPORTANT): ESP sampling state: S_WAITING_FOR_PAUSED
2018-05-31T20:28:25.080Z,1527798505.080 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T20:28:25.080Z,1527798505.080 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4
2018-05-31T20:28:25.080Z,1527798505.080 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T20:28:25.095Z,1527798505.095 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T20:28:25.498Z,1527798505.498 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T20:28:25.498Z,1527798505.498 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4
2018-05-31T20:28:25.890Z,1527798505.890 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T20:28:25.891Z,1527798505.891 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T20:28:25.891Z,1527798505.891 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T20:28:26.234Z,1527798506.234 [Radio_Surface](INFO): Powering up
2018-05-31T20:28:31.890Z,1527798511.890 [Radio_Surface](INFO): Powering down
2018-05-31T20:28:38.624Z,1527798518.624 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:29:05.435Z,1527798545.435 [Radio_Surface](INFO): Powering up
2018-05-31T20:29:11.090Z,1527798551.090 [Radio_Surface](INFO): Powering down
2018-05-31T20:29:39.023Z,1527798579.023 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:29:43.027Z,1527798583.027 [Radio_Surface](INFO): Powering up
2018-05-31T20:29:48.682Z,1527798588.682 [Radio_Surface](INFO): Powering down
2018-05-31T20:29:53.471Z,1527798593.471 [BPC1](ERROR): Failed to receive data from both battery packs
2018-05-31T20:29:53.471Z,1527798593.471 [BPC1] Communications Fault, FailCount= 2
2018-05-31T20:29:53.471Z,1527798593.471 [BPC1](ERROR): Communications Fault
2018-05-31T20:29:53.498Z,1527798593.498 [CBIT](ERROR): Communications Fault in component: BPC1
2018-05-31T20:29:54.697Z,1527798594.697 [CBIT](INFO): Clearing failed state for component BPC1
2018-05-31T20:29:54.697Z,1527798594.697 [BPC1] No Fault, FailCount= 2
2018-05-31T20:30:21.429Z,1527798621.429 [Radio_Surface](INFO): Powering up
2018-05-31T20:30:27.086Z,1527798627.086 [Radio_Surface](INFO): Powering down
2018-05-31T20:30:39.423Z,1527798639.423 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:30:59.430Z,1527798659.430 [Radio_Surface](INFO): Powering up
2018-05-31T20:31:05.086Z,1527798665.086 [Radio_Surface](INFO): Powering down
2018-05-31T20:31:26.280Z,1527798686.280 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T20:31:26.281Z,1527798686.281 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5
2018-05-31T20:31:26.281Z,1527798686.281 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T20:31:26.296Z,1527798686.296 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T20:31:26.693Z,1527798686.693 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T20:31:26.693Z,1527798686.693 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5
2018-05-31T20:31:27.077Z,1527798687.077 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T20:31:27.077Z,1527798687.077 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T20:31:27.078Z,1527798687.078 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T20:31:38.230Z,1527798698.230 [Radio_Surface](INFO): Powering up
2018-05-31T20:31:39.423Z,1527798699.423 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:31:43.886Z,1527798703.886 [Radio_Surface](INFO): Powering down
2018-05-31T20:32:16.229Z,1527798736.229 [Radio_Surface](INFO): Powering up
2018-05-31T20:32:21.886Z,1527798741.886 [Radio_Surface](INFO): Powering down
2018-05-31T20:32:39.823Z,1527798759.823 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:32:55.838Z,1527798775.838 [Radio_Surface](INFO): Powering up
2018-05-31T20:33:01.494Z,1527798781.494 [Radio_Surface](INFO): Powering down
2018-05-31T20:33:33.830Z,1527798813.830 [Radio_Surface](INFO): Powering up
2018-05-31T20:33:39.486Z,1527798819.486 [Radio_Surface](INFO): Powering down
2018-05-31T20:33:39.823Z,1527798819.823 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:34:13.834Z,1527798853.834 [Radio_Surface](INFO): Powering up
2018-05-31T20:34:19.490Z,1527798859.490 [Radio_Surface](INFO): Powering down
2018-05-31T20:34:27.469Z,1527798867.469 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T20:34:27.469Z,1527798867.469 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 6
2018-05-31T20:34:27.469Z,1527798867.469 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T20:34:27.484Z,1527798867.484 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T20:34:27.912Z,1527798867.912 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T20:34:27.912Z,1527798867.912 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 6
2018-05-31T20:34:28.282Z,1527798868.282 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T20:34:28.282Z,1527798868.282 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T20:34:28.283Z,1527798868.283 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T20:34:40.623Z,1527798880.623 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:34:53.033Z,1527798893.033 [Radio_Surface](INFO): Powering up
2018-05-31T20:34:58.690Z,1527798898.690 [Radio_Surface](INFO): Powering down
2018-05-31T20:35:31.430Z,1527798931.430 [Radio_Surface](INFO): Powering up
2018-05-31T20:35:37.086Z,1527798937.086 [Radio_Surface](INFO): Powering down
2018-05-31T20:35:41.023Z,1527798941.023 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:36:10.630Z,1527798970.630 [Radio_Surface](INFO): Powering up
2018-05-31T20:36:16.286Z,1527798976.286 [Radio_Surface](INFO): Powering down
2018-05-31T20:36:33.125Z,1527798993.125 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-05-31T20:36:33.125Z,1527798993.125 [Rowe_600LCM] No Fault, FailCount= 5
2018-05-31T20:36:33.461Z,1527798993.461 [Rowe_600LCM](INFO): Initializing
2018-05-31T20:36:33.461Z,1527798993.461 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T20:36:33.461Z,1527798993.461 [Rowe_600LCM](INFO): LCM OK
2018-05-31T20:36:33.462Z,1527798993.462 [Rowe_600LCM](INFO): Powering up
2018-05-31T20:36:37.615Z,1527798997.615 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T20:36:37.683Z,1527798997.683 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T20:36:37.684Z,1527798997.684 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T20:36:37.685Z,1527798997.685 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T20:36:37.686Z,1527798997.686 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T20:36:41.026Z,1527799001.026 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:36:51.038Z,1527799011.038 [Radio_Surface](INFO): Powering up
2018-05-31T20:36:56.694Z,1527799016.694 [Radio_Surface](INFO): Powering down
2018-05-31T20:37:25.092Z,1527799045.092 [BPC1](ERROR): Failed to receive data from both battery packs
2018-05-31T20:37:25.092Z,1527799045.092 [BPC1] Communications Fault, FailCount= 3
2018-05-31T20:37:25.092Z,1527799045.092 [BPC1](ERROR): Communications Fault
2018-05-31T20:37:25.124Z,1527799045.124 [CBIT](ERROR): Communications Fault in component: BPC1
2018-05-31T20:37:26.322Z,1527799046.322 [CBIT](INFO): Clearing failed state for component BPC1
2018-05-31T20:37:26.322Z,1527799046.322 [BPC1] No Fault, FailCount= 3
2018-05-31T20:37:28.291Z,1527799048.291 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T20:37:28.291Z,1527799048.291 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 7
2018-05-31T20:37:28.291Z,1527799048.291 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T20:37:28.333Z,1527799048.333 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T20:37:28.734Z,1527799048.734 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T20:37:28.735Z,1527799048.735 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 7
2018-05-31T20:37:29.181Z,1527799049.181 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T20:37:29.182Z,1527799049.182 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T20:37:29.183Z,1527799049.183 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T20:37:30.638Z,1527799050.638 [Radio_Surface](INFO): Powering up
2018-05-31T20:37:36.295Z,1527799056.295 [Radio_Surface](INFO): Powering down
2018-05-31T20:37:41.424Z,1527799061.424 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:37:45.031Z,1527799065.031 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-05-31T20:37:45.031Z,1527799065.031 [NAL9602] Data Fault, FailCount= 2
2018-05-31T20:37:45.031Z,1527799065.031 [NAL9602](ERROR): Data Fault
2018-05-31T20:37:45.153Z,1527799065.153 [CBIT](ERROR): Data Fault in component: NAL9602
2018-05-31T20:37:45.431Z,1527799065.431 [NAL9602](INFO): Powering down
2018-05-31T20:37:46.341Z,1527799066.341 [CBIT](INFO): Clearing failed state for component NAL9602
2018-05-31T20:37:46.341Z,1527799066.341 [NAL9602] No Fault, FailCount= 2
2018-05-31T20:38:10.638Z,1527799090.638 [Radio_Surface](INFO): Powering up
2018-05-31T20:38:15.835Z,1527799095.835 [NAL9602](INFO): Powering up NAL9602
2018-05-31T20:38:16.302Z,1527799096.302 [Radio_Surface](INFO): Powering down
2018-05-31T20:38:26.632Z,1527799106.632 [NAL9602](INFO): NAL9602 initialized
2018-05-31T20:38:34.213Z,1527799114.213 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T20:38:34.213Z,1527799114.213 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-05-31T20:38:34.213Z,1527799114.213 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T20:38:34.358Z,1527799114.358 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T20:38:34.629Z,1527799114.629 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T20:38:34.898Z,1527799114.898 [Rowe_600LCM](INFO): Powering down
2018-05-31T20:38:36.307Z,1527799116.307 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-05-31T20:38:36.307Z,1527799116.307 [Rowe_600LCM] No Fault, FailCount= 1
2018-05-31T20:38:36.513Z,1527799116.513 [Rowe_600LCM](INFO): Initializing
2018-05-31T20:38:36.514Z,1527799116.514 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T20:38:36.514Z,1527799116.514 [Rowe_600LCM](INFO): LCM OK
2018-05-31T20:38:36.514Z,1527799116.514 [Rowe_600LCM](INFO): Powering up
2018-05-31T20:38:40.710Z,1527799120.710 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T20:38:40.828Z,1527799120.828 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T20:38:40.829Z,1527799120.829 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T20:38:40.830Z,1527799120.830 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T20:38:40.831Z,1527799120.831 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T20:38:41.423Z,1527799121.423 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:38:48.634Z,1527799128.634 [Radio_Surface](INFO): Powering up
2018-05-31T20:38:54.694Z,1527799134.694 [Radio_Surface](INFO): Powering down
2018-05-31T20:39:28.639Z,1527799168.639 [Radio_Surface](INFO): Powering up
2018-05-31T20:39:28.998Z,1527799168.998 [CommandLine](IMPORTANT): got command show stack
2018-05-31T20:39:28.998Z,1527799168.998 [CommandLine](IMPORTANT): Behavior Stack:

2018-05-31T20:39:28.998Z,1527799168.998 [sample](IMPORTANT): Priority 0: sample:A.Pitch
2018-05-31T20:39:28.999Z,1527799168.999 [sample](IMPORTANT): Priority 1: sample:B.SetSpeed
2018-05-31T20:39:28.999Z,1527799168.999 [sample:SampleAtDepth](IMPORTANT): Priority 2: sample:SampleAtDepth:B.Pitch
2018-05-31T20:39:28.000Z,1527799169.000 [sample:SampleAtDepth:SampleWrapper:SampleESP](IMPORTANT): Priority 3: sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP
2018-05-31T20:39:34.294Z,1527799174.294 [Radio_Surface](INFO): Powering down
2018-05-31T20:39:41.424Z,1527799181.424 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:40:07.434Z,1527799207.434 [Radio_Surface](INFO): Powering up
2018-05-31T20:40:13.090Z,1527799213.090 [Radio_Surface](INFO): Powering down
2018-05-31T20:40:29.495Z,1527799229.495 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T20:40:29.495Z,1527799229.495 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 8
2018-05-31T20:40:29.495Z,1527799229.495 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T20:40:29.533Z,1527799229.533 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T20:40:29.907Z,1527799229.907 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T20:40:29.908Z,1527799229.908 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 8
2018-05-31T20:40:30.294Z,1527799230.294 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T20:40:30.294Z,1527799230.294 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T20:40:30.295Z,1527799230.295 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T20:40:36.613Z,1527799236.613 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T20:40:36.613Z,1527799236.613 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-05-31T20:40:36.613Z,1527799236.613 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T20:40:36.745Z,1527799236.745 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T20:40:37.025Z,1527799237.025 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T20:40:37.289Z,1527799237.289 [Rowe_600LCM](INFO): Powering down
2018-05-31T20:40:38.705Z,1527799238.705 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-05-31T20:40:38.705Z,1527799238.705 [Rowe_600LCM] No Fault, FailCount= 2
2018-05-31T20:40:38.905Z,1527799238.905 [Rowe_600LCM](INFO): Initializing
2018-05-31T20:40:38.905Z,1527799238.905 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T20:40:38.906Z,1527799238.906 [Rowe_600LCM](INFO): LCM OK
2018-05-31T20:40:38.906Z,1527799238.906 [Rowe_600LCM](INFO): Powering up
2018-05-31T20:40:41.823Z,1527799241.823 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:40:43.098Z,1527799243.098 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T20:40:43.226Z,1527799243.226 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T20:40:43.227Z,1527799243.227 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T20:40:43.228Z,1527799243.228 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T20:40:43.229Z,1527799243.229 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T20:40:45.845Z,1527799245.845 [Radio_Surface](INFO): Powering up
2018-05-31T20:40:51.510Z,1527799251.510 [Radio_Surface](INFO): Powering down
2018-05-31T20:41:23.438Z,1527799283.438 [Radio_Surface](INFO): Powering up
2018-05-31T20:41:29.098Z,1527799289.098 [Radio_Surface](INFO): Powering down
2018-05-31T20:41:41.425Z,1527799301.425 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:41:56.710Z,1527799316.710 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.392224 seconds old.
2018-05-31T20:41:57.094Z,1527799317.094 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.776310 seconds old.
2018-05-31T20:41:57.489Z,1527799317.489 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.170977 seconds old.
2018-05-31T20:41:57.919Z,1527799317.919 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.601624 seconds old.
2018-05-31T20:42:02.246Z,1527799322.246 [Radio_Surface](INFO): Powering up
2018-05-31T20:42:07.902Z,1527799327.902 [Radio_Surface](INFO): Powering down
2018-05-31T20:42:32.859Z,1527799352.859 [CommandLine](IMPORTANT): got command show stack
2018-05-31T20:42:32.859Z,1527799352.859 [CommandLine](IMPORTANT): Behavior Stack:

2018-05-31T20:42:32.860Z,1527799352.860 [sample](IMPORTANT): Priority 0: sample:A.Pitch
2018-05-31T20:42:32.860Z,1527799352.860 [sample](IMPORTANT): Priority 1: sample:B.SetSpeed
2018-05-31T20:42:32.861Z,1527799352.861 [sample:SampleAtDepth](IMPORTANT): Priority 2: sample:SampleAtDepth:B.Pitch
2018-05-31T20:42:32.862Z,1527799352.862 [sample:SampleAtDepth:SampleWrapper:SampleESP](IMPORTANT): Priority 3: sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP
2018-05-31T20:42:39.017Z,1527799359.017 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T20:42:39.017Z,1527799359.017 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-05-31T20:42:39.017Z,1527799359.017 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T20:42:39.159Z,1527799359.159 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T20:42:39.421Z,1527799359.421 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T20:42:39.674Z,1527799359.674 [Rowe_600LCM](INFO): Powering down
2018-05-31T20:42:39.877Z,1527799359.877 [Radio_Surface](INFO): Powering up
2018-05-31T20:42:41.085Z,1527799361.085 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-05-31T20:42:41.086Z,1527799361.086 [Rowe_600LCM] No Fault, FailCount= 3
2018-05-31T20:42:41.289Z,1527799361.289 [Rowe_600LCM](INFO): Initializing
2018-05-31T20:42:41.289Z,1527799361.289 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T20:42:41.289Z,1527799361.289 [Rowe_600LCM](INFO): LCM OK
2018-05-31T20:42:41.290Z,1527799361.290 [Rowe_600LCM](INFO): Powering up
2018-05-31T20:42:41.823Z,1527799361.823 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:42:45.411Z,1527799365.411 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T20:42:45.534Z,1527799365.534 [Radio_Surface](INFO): Powering down
2018-05-31T20:42:45.562Z,1527799365.562 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T20:42:45.563Z,1527799365.563 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T20:42:45.564Z,1527799365.564 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T20:42:45.565Z,1527799365.565 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T20:43:12.291Z,1527799392.291 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-05-31T20:43:13.086Z,1527799393.086 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-05-31T20:43:14.237Z,1527799394.237 [Radio_Surface](INFO): Powering up
2018-05-31T20:43:19.898Z,1527799399.898 [Radio_Surface](INFO): Powering down
2018-05-31T20:43:30.300Z,1527799410.300 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T20:43:30.300Z,1527799410.300 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 9
2018-05-31T20:43:30.300Z,1527799410.300 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T20:43:30.351Z,1527799410.351 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T20:43:30.712Z,1527799410.712 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T20:43:30.712Z,1527799410.712 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 9
2018-05-31T20:43:31.085Z,1527799411.085 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T20:43:31.086Z,1527799411.086 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T20:43:31.086Z,1527799411.086 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T20:43:39.887Z,1527799419.887 [BPC1](ERROR): Failed to receive data from both battery packs
2018-05-31T20:43:39.887Z,1527799419.887 [BPC1] Communications Fault, FailCount= 4
2018-05-31T20:43:39.887Z,1527799419.887 [BPC1](ERROR): Communications Fault
2018-05-31T20:43:39.951Z,1527799419.951 [CBIT](ERROR): Communications Fault in component: BPC1
2018-05-31T20:43:41.109Z,1527799421.109 [CBIT](INFO): Clearing failed state for component BPC1
2018-05-31T20:43:41.109Z,1527799421.109 [BPC1] No Fault, FailCount= 4
2018-05-31T20:43:41.825Z,1527799421.825 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:43:51.838Z,1527799431.838 [Radio_Surface](INFO): Powering up
2018-05-31T20:43:57.494Z,1527799437.494 [Radio_Surface](INFO): Powering down
2018-05-31T20:44:29.843Z,1527799469.843 [Radio_Surface](INFO): Powering up
2018-05-31T20:44:35.498Z,1527799475.498 [Radio_Surface](INFO): Powering down
2018-05-31T20:44:41.425Z,1527799481.425 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T20:44:41.425Z,1527799481.425 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-05-31T20:44:41.425Z,1527799481.425 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T20:44:41.538Z,1527799481.538 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T20:44:41.829Z,1527799481.829 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T20:44:42.096Z,1527799482.096 [Rowe_600LCM](INFO): Powering down
2018-05-31T20:44:42.224Z,1527799482.224 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:44:43.499Z,1527799483.499 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-05-31T20:44:43.499Z,1527799483.499 [Rowe_600LCM] No Fault, FailCount= 4
2018-05-31T20:44:43.713Z,1527799483.713 [Rowe_600LCM](INFO): Initializing
2018-05-31T20:44:43.713Z,1527799483.713 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T20:44:43.714Z,1527799483.714 [Rowe_600LCM](INFO): LCM OK
2018-05-31T20:44:43.714Z,1527799483.714 [Rowe_600LCM](INFO): Powering up
2018-05-31T20:44:47.883Z,1527799487.883 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T20:44:48.023Z,1527799488.023 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T20:44:48.024Z,1527799488.024 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T20:44:48.027Z,1527799488.027 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T20:44:48.027Z,1527799488.027 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T20:45:08.230Z,1527799508.230 [Radio_Surface](INFO): Powering up
2018-05-31T20:45:14.694Z,1527799514.694 [Radio_Surface](INFO): Powering down
2018-05-31T20:45:39.085Z,1527799539.085 [BPC1](ERROR): Failed to parse Bank B battery data
2018-05-31T20:45:42.628Z,1527799542.628 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:45:48.639Z,1527799548.639 [Radio_Surface](INFO): Powering up
2018-05-31T20:45:54.702Z,1527799554.702 [Radio_Surface](INFO): Powering down
2018-05-31T20:46:27.841Z,1527799587.841 [Radio_Surface](INFO): Powering up
2018-05-31T20:46:31.088Z,1527799591.088 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T20:46:31.089Z,1527799591.089 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 10
2018-05-31T20:46:31.089Z,1527799591.089 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T20:46:31.120Z,1527799591.120 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T20:46:31.507Z,1527799591.507 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T20:46:31.507Z,1527799591.507 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 10
2018-05-31T20:46:31.897Z,1527799591.897 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T20:46:31.897Z,1527799591.897 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T20:46:31.898Z,1527799591.898 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T20:46:33.498Z,1527799593.498 [Radio_Surface](INFO): Powering down
2018-05-31T20:46:42.229Z,1527799602.229 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:46:43.821Z,1527799603.821 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T20:46:43.821Z,1527799603.821 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-05-31T20:46:43.821Z,1527799603.821 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T20:46:43.961Z,1527799603.961 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T20:46:43.962Z,1527799603.962 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-05-31T20:46:44.225Z,1527799604.225 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T20:46:44.495Z,1527799604.495 [Rowe_600LCM](INFO): Powering down
2018-05-31T20:47:06.230Z,1527799626.230 [Radio_Surface](INFO): Powering up
2018-05-31T20:47:11.886Z,1527799631.886 [Radio_Surface](INFO): Powering down
2018-05-31T20:47:42.623Z,1527799662.623 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:47:45.830Z,1527799665.830 [Radio_Surface](INFO): Powering up
2018-05-31T20:47:51.486Z,1527799671.486 [Radio_Surface](INFO): Powering down
2018-05-31T20:48:24.630Z,1527799704.630 [Radio_Surface](INFO): Powering up
2018-05-31T20:48:27.826Z,1527799707.826 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-05-31T20:48:27.826Z,1527799707.826 [NAL9602] Data Fault, FailCount= 3
2018-05-31T20:48:27.827Z,1527799707.827 [NAL9602](ERROR): Data Fault
2018-05-31T20:48:27.928Z,1527799707.928 [CBIT](ERROR): Data Fault in component: NAL9602
2018-05-31T20:48:28.226Z,1527799708.226 [NAL9602](INFO): Powering down
2018-05-31T20:48:29.090Z,1527799709.090 [CBIT](INFO): Clearing failed state for component NAL9602
2018-05-31T20:48:29.090Z,1527799709.090 [NAL9602] No Fault, FailCount= 3
2018-05-31T20:48:30.286Z,1527799710.286 [Radio_Surface](INFO): Powering down
2018-05-31T20:48:42.623Z,1527799722.623 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:48:58.626Z,1527799738.626 [NAL9602](INFO): Powering up NAL9602
2018-05-31T20:49:03.431Z,1527799743.431 [Radio_Surface](INFO): Powering up
2018-05-31T20:49:09.102Z,1527799749.102 [Radio_Surface](INFO): Powering down
2018-05-31T20:49:09.426Z,1527799749.426 [NAL9602](INFO): NAL9602 initialized
2018-05-31T20:49:32.276Z,1527799772.276 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T20:49:32.277Z,1527799772.277 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 11
2018-05-31T20:49:32.277Z,1527799772.277 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T20:49:32.312Z,1527799772.312 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T20:49:32.710Z,1527799772.710 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T20:49:32.710Z,1527799772.710 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 11
2018-05-31T20:49:33.083Z,1527799773.083 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T20:49:33.084Z,1527799773.084 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T20:49:33.084Z,1527799773.084 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T20:49:41.434Z,1527799781.434 [Radio_Surface](INFO): Powering up
2018-05-31T20:49:43.023Z,1527799783.023 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:49:47.090Z,1527799787.090 [Radio_Surface](INFO): Powering down
2018-05-31T20:50:19.830Z,1527799819.830 [Radio_Surface](INFO): Powering up
2018-05-31T20:50:25.486Z,1527799825.486 [Radio_Surface](INFO): Powering down
2018-05-31T20:50:43.423Z,1527799843.423 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:50:52.260Z,1527799852.260 [BPC1](ERROR): Failed to receive data from both battery packs
2018-05-31T20:50:52.260Z,1527799852.260 [BPC1] Communications Fault, FailCount= 5
2018-05-31T20:50:52.260Z,1527799852.260 [BPC1](ERROR): Communications Fault
2018-05-31T20:50:52.287Z,1527799852.287 [CBIT](ERROR): Communications Fault in component: BPC1
2018-05-31T20:50:53.530Z,1527799853.530 [CBIT](INFO): Clearing failed state for component BPC1
2018-05-31T20:50:53.530Z,1527799853.530 [BPC1] No Fault, FailCount= 5
2018-05-31T20:50:58.231Z,1527799858.231 [Radio_Surface](INFO): Powering up
2018-05-31T20:51:03.886Z,1527799863.886 [Radio_Surface](INFO): Powering down
2018-05-31T20:51:36.629Z,1527799896.629 [Radio_Surface](INFO): Powering up
2018-05-31T20:51:42.286Z,1527799902.286 [Radio_Surface](INFO): Powering down
2018-05-31T20:51:43.424Z,1527799903.424 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:52:16.230Z,1527799936.230 [Radio_Surface](INFO): Powering up
2018-05-31T20:52:21.890Z,1527799941.890 [Radio_Surface](INFO): Powering down
2018-05-31T20:52:33.103Z,1527799953.103 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T20:52:33.103Z,1527799953.103 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 12
2018-05-31T20:52:33.103Z,1527799953.103 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T20:52:33.118Z,1527799953.118 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T20:52:33.501Z,1527799953.501 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T20:52:33.501Z,1527799953.501 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 12
2018-05-31T20:52:33.872Z,1527799953.872 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T20:52:33.873Z,1527799953.873 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T20:52:33.873Z,1527799953.873 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T20:52:41.418Z,1527799961.418 [CommandLine](IMPORTANT): got command show stack
2018-05-31T20:52:41.418Z,1527799961.418 [CommandLine](IMPORTANT): Behavior Stack:

2018-05-31T20:52:41.418Z,1527799961.418 [sample](IMPORTANT): Priority 0: sample:A.Pitch
2018-05-31T20:52:41.419Z,1527799961.419 [sample](IMPORTANT): Priority 1: sample:B.SetSpeed
2018-05-31T20:52:41.419Z,1527799961.419 [sample:SampleAtDepth](IMPORTANT): Priority 2: sample:SampleAtDepth:B.Pitch
2018-05-31T20:52:41.419Z,1527799961.419 [sample:SampleAtDepth:SampleWrapper:SampleESP](IMPORTANT): Priority 3: sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP
2018-05-31T20:52:43.424Z,1527799963.424 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:52:55.029Z,1527799975.029 [Radio_Surface](INFO): Powering up
2018-05-31T20:53:00.695Z,1527799980.695 [Radio_Surface](INFO): Powering down
2018-05-31T20:53:16.689Z,1527799996.689 [BPC1](ERROR): Failed to parse Bank B battery data
2018-05-31T20:53:32.630Z,1527800012.630 [Radio_Surface](INFO): Powering up
2018-05-31T20:53:38.294Z,1527800018.294 [Radio_Surface](INFO): Powering down
2018-05-31T20:53:44.223Z,1527800024.223 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:54:11.433Z,1527800051.433 [Radio_Surface](INFO): Powering up
2018-05-31T20:54:17.090Z,1527800057.090 [Radio_Surface](INFO): Powering down
2018-05-31T20:54:44.223Z,1527800084.223 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:54:50.630Z,1527800090.630 [Radio_Surface](INFO): Powering up
2018-05-31T20:54:56.286Z,1527800096.286 [Radio_Surface](INFO): Powering down
2018-05-31T20:55:29.827Z,1527800129.827 [Radio_Surface](INFO): Powering up
2018-05-31T20:55:33.874Z,1527800133.874 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T20:55:33.874Z,1527800133.874 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 13
2018-05-31T20:55:33.874Z,1527800133.874 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T20:55:33.889Z,1527800133.889 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T20:55:34.300Z,1527800134.300 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T20:55:34.300Z,1527800134.300 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 13
2018-05-31T20:55:34.687Z,1527800134.687 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T20:55:34.687Z,1527800134.687 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T20:55:34.688Z,1527800134.688 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T20:55:35.886Z,1527800135.886 [Radio_Surface](INFO): Powering down
2018-05-31T20:55:44.623Z,1527800144.623 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:56:09.429Z,1527800169.429 [Radio_Surface](INFO): Powering up
2018-05-31T20:56:15.086Z,1527800175.086 [Radio_Surface](INFO): Powering down
2018-05-31T20:56:43.923Z,1527800203.923 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-05-31T20:56:43.923Z,1527800203.923 [Rowe_600LCM] No Fault, FailCount= 5
2018-05-31T20:56:44.281Z,1527800204.281 [Rowe_600LCM](INFO): Initializing
2018-05-31T20:56:44.281Z,1527800204.281 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T20:56:44.282Z,1527800204.282 [Rowe_600LCM](INFO): LCM OK
2018-05-31T20:56:44.282Z,1527800204.282 [Rowe_600LCM](INFO): Powering up
2018-05-31T20:56:45.023Z,1527800205.023 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:56:48.408Z,1527800208.408 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T20:56:48.486Z,1527800208.486 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T20:56:48.487Z,1527800208.487 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T20:56:48.488Z,1527800208.488 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T20:56:48.489Z,1527800208.489 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T20:56:48.646Z,1527800208.646 [Radio_Surface](INFO): Powering up
2018-05-31T20:56:54.302Z,1527800214.302 [Radio_Surface](INFO): Powering down
2018-05-31T20:57:26.238Z,1527800246.238 [Radio_Surface](INFO): Powering up
2018-05-31T20:57:31.902Z,1527800251.902 [Radio_Surface](INFO): Powering down
2018-05-31T20:57:44.624Z,1527800264.624 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:58:05.038Z,1527800285.038 [Radio_Surface](INFO): Powering up
2018-05-31T20:58:10.698Z,1527800290.698 [Radio_Surface](INFO): Powering down
2018-05-31T20:58:11.102Z,1527800291.102 [Radio_Surface](FAULT): LCB fault:  Invalid Command. Hardware Overcurrent Shutdown. Current Limiter Activated.
2018-05-31T20:58:11.102Z,1527800291.102 [Radio_Surface] Hardware Fault, FailCount= 1
2018-05-31T20:58:11.102Z,1527800291.102 [Radio_Surface](ERROR): Hardware Fault
2018-05-31T20:58:11.133Z,1527800291.133 [CBIT](ERROR): Hardware Fault in component: Radio_Surface
2018-05-31T20:58:11.914Z,1527800291.914 [CBIT](INFO): Clearing failed state for component Radio_Surface
2018-05-31T20:58:11.914Z,1527800291.914 [Radio_Surface] No Fault, FailCount= 1
2018-05-31T20:58:12.313Z,1527800292.313 [Radio_Surface](INFO): Powering up
2018-05-31T20:58:17.970Z,1527800297.970 [Radio_Surface](INFO): Powering down
2018-05-31T20:58:34.692Z,1527800314.692 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T20:58:34.692Z,1527800314.692 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 14
2018-05-31T20:58:34.693Z,1527800314.693 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T20:58:34.748Z,1527800314.748 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T20:58:35.146Z,1527800315.146 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T20:58:35.146Z,1527800315.146 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 14
2018-05-31T20:58:35.488Z,1527800315.488 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T20:58:35.493Z,1527800315.493 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T20:58:35.494Z,1527800315.494 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T20:58:44.631Z,1527800324.631 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:58:45.017Z,1527800325.017 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T20:58:45.017Z,1527800325.017 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-05-31T20:58:45.018Z,1527800325.018 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T20:58:45.158Z,1527800325.158 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T20:58:45.421Z,1527800325.421 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T20:58:45.683Z,1527800325.683 [Rowe_600LCM](INFO): Powering down
2018-05-31T20:58:45.846Z,1527800325.846 [Radio_Surface](INFO): Powering up
2018-05-31T20:58:47.105Z,1527800327.105 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-05-31T20:58:47.105Z,1527800327.105 [Rowe_600LCM] No Fault, FailCount= 1
2018-05-31T20:58:47.298Z,1527800327.298 [Rowe_600LCM](INFO): Initializing
2018-05-31T20:58:47.299Z,1527800327.299 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T20:58:47.299Z,1527800327.299 [Rowe_600LCM](INFO): LCM OK
2018-05-31T20:58:47.299Z,1527800327.299 [Rowe_600LCM](INFO): Powering up
2018-05-31T20:58:51.446Z,1527800331.446 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T20:58:51.598Z,1527800331.598 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T20:58:51.599Z,1527800331.599 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T20:58:51.600Z,1527800331.600 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T20:58:51.601Z,1527800331.601 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T20:58:51.918Z,1527800331.918 [Radio_Surface](INFO): Powering down
2018-05-31T20:59:03.888Z,1527800343.888 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.390308 seconds old.
2018-05-31T20:59:04.308Z,1527800344.308 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.810355 seconds old.
2018-05-31T20:59:04.692Z,1527800344.692 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.193575 seconds old.
2018-05-31T20:59:05.100Z,1527800345.100 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.602286 seconds old.
2018-05-31T20:59:05.502Z,1527800345.502 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.003723 seconds old.
2018-05-31T20:59:05.886Z,1527800345.886 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.388212 seconds old.
2018-05-31T20:59:06.285Z,1527800346.285 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.786570 seconds old.
2018-05-31T20:59:06.686Z,1527800346.686 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.187609 seconds old.
2018-05-31T20:59:10.231Z,1527800350.231 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-05-31T20:59:10.231Z,1527800350.231 [NAL9602] Data Fault, FailCount= 4
2018-05-31T20:59:10.231Z,1527800350.231 [NAL9602](ERROR): Data Fault
2018-05-31T20:59:10.366Z,1527800350.366 [CBIT](ERROR): Data Fault in component: NAL9602
2018-05-31T20:59:10.630Z,1527800350.630 [NAL9602](INFO): Powering down
2018-05-31T20:59:11.506Z,1527800351.506 [CBIT](INFO): Clearing failed state for component NAL9602
2018-05-31T20:59:11.506Z,1527800351.506 [NAL9602] No Fault, FailCount= 4
2018-05-31T20:59:22.635Z,1527800362.635 [Radio_Surface](INFO): Powering up
2018-05-31T20:59:28.291Z,1527800368.291 [Radio_Surface](INFO): Powering down
2018-05-31T20:59:34.270Z,1527800374.270 [BPC1](ERROR): Failed to receive data from both battery packs
2018-05-31T20:59:34.270Z,1527800374.270 [BPC1] Communications Fault, FailCount= 6
2018-05-31T20:59:34.270Z,1527800374.270 [BPC1](ERROR): Communications Fault
2018-05-31T20:59:34.328Z,1527800374.328 [CBIT](ERROR): Communications Fault in component: BPC1
2018-05-31T20:59:35.524Z,1527800375.524 [CBIT](INFO): Clearing failed state for component BPC1
2018-05-31T20:59:35.529Z,1527800375.529 [BPC1] No Fault, FailCount= 6
2018-05-31T20:59:41.035Z,1527800381.035 [NAL9602](INFO): Powering up NAL9602
2018-05-31T20:59:45.026Z,1527800385.026 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T20:59:52.231Z,1527800392.231 [NAL9602](INFO): NAL9602 initialized
2018-05-31T21:00:02.230Z,1527800402.230 [Radio_Surface](INFO): Powering up
2018-05-31T21:00:08.694Z,1527800408.694 [Radio_Surface](INFO): Powering down
2018-05-31T21:00:41.834Z,1527800441.834 [Radio_Surface](INFO): Powering up
2018-05-31T21:00:45.427Z,1527800445.427 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T21:00:47.417Z,1527800447.417 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T21:00:47.417Z,1527800447.417 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-05-31T21:00:47.417Z,1527800447.417 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T21:00:47.558Z,1527800447.558 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T21:00:47.821Z,1527800447.821 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T21:00:48.101Z,1527800448.101 [Rowe_600LCM](INFO): Powering down
2018-05-31T21:00:48.314Z,1527800448.314 [Radio_Surface](INFO): Powering down
2018-05-31T21:00:49.512Z,1527800449.512 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-05-31T21:00:49.512Z,1527800449.512 [Rowe_600LCM] No Fault, FailCount= 2
2018-05-31T21:00:49.717Z,1527800449.717 [Rowe_600LCM](INFO): Initializing
2018-05-31T21:00:49.717Z,1527800449.717 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T21:00:49.717Z,1527800449.717 [Rowe_600LCM](INFO): LCM OK
2018-05-31T21:00:49.718Z,1527800449.718 [Rowe_600LCM](INFO): Powering up
2018-05-31T21:00:53.925Z,1527800453.925 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T21:00:54.027Z,1527800454.027 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T21:00:54.028Z,1527800454.028 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T21:00:54.029Z,1527800454.029 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T21:00:54.030Z,1527800454.030 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T21:01:19.038Z,1527800479.038 [Radio_Surface](INFO): Powering up
2018-05-31T21:01:24.698Z,1527800484.698 [Radio_Surface](INFO): Powering down
2018-05-31T21:01:35.495Z,1527800495.495 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T21:01:35.495Z,1527800495.495 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 15
2018-05-31T21:01:35.495Z,1527800495.495 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T21:01:35.542Z,1527800495.542 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T21:01:35.919Z,1527800495.919 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T21:01:35.919Z,1527800495.919 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 15
2018-05-31T21:01:36.290Z,1527800496.290 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T21:01:36.291Z,1527800496.291 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T21:01:36.291Z,1527800496.291 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T21:01:45.825Z,1527800505.825 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T21:01:56.634Z,1527800516.634 [Radio_Surface](INFO): Powering up
2018-05-31T21:01:59.191Z,1527800519.191 [CommandLine](IMPORTANT): got command show stack
2018-05-31T21:01:59.191Z,1527800519.191 [CommandLine](IMPORTANT): Behavior Stack:

2018-05-31T21:01:59.192Z,1527800519.192 [sample](IMPORTANT): Priority 0: sample:A.Pitch
2018-05-31T21:01:59.193Z,1527800519.193 [sample](IMPORTANT): Priority 1: sample:B.SetSpeed
2018-05-31T21:01:59.193Z,1527800519.193 [sample:SampleAtDepth](IMPORTANT): Priority 2: sample:SampleAtDepth:B.Pitch
2018-05-31T21:01:59.194Z,1527800519.194 [sample:SampleAtDepth:SampleWrapper:SampleESP](IMPORTANT): Priority 3: sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP
2018-05-31T21:02:02.290Z,1527800522.290 [Radio_Surface](INFO): Powering down
2018-05-31T21:02:22.222Z,1527800542.222 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-05-31T21:02:23.026Z,1527800543.026 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2018-05-31T21:02:35.038Z,1527800555.038 [Radio_Surface](INFO): Powering up
2018-05-31T21:02:40.702Z,1527800560.702 [Radio_Surface](INFO): Powering down
2018-05-31T21:02:46.224Z,1527800566.224 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T21:02:49.817Z,1527800569.817 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T21:02:49.817Z,1527800569.817 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-05-31T21:02:49.817Z,1527800569.817 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T21:02:49.955Z,1527800569.955 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T21:02:50.221Z,1527800570.221 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T21:02:50.491Z,1527800570.491 [Rowe_600LCM](INFO): Powering down
2018-05-31T21:02:51.904Z,1527800571.904 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-05-31T21:02:51.904Z,1527800571.904 [Rowe_600LCM] No Fault, FailCount= 3
2018-05-31T21:02:52.105Z,1527800572.105 [Rowe_600LCM](INFO): Initializing
2018-05-31T21:02:52.105Z,1527800572.105 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T21:02:52.106Z,1527800572.106 [Rowe_600LCM](INFO): LCM OK
2018-05-31T21:02:52.106Z,1527800572.106 [Rowe_600LCM](INFO): Powering up
2018-05-31T21:02:56.369Z,1527800576.369 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T21:02:56.434Z,1527800576.434 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T21:02:56.435Z,1527800576.435 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T21:02:56.436Z,1527800576.436 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T21:02:56.436Z,1527800576.436 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T21:03:13.438Z,1527800593.438 [Radio_Surface](INFO): Powering up
2018-05-31T21:03:19.102Z,1527800599.102 [Radio_Surface](INFO): Powering down
2018-05-31T21:03:46.225Z,1527800626.225 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T21:03:51.438Z,1527800631.438 [Radio_Surface](INFO): Powering up
2018-05-31T21:03:57.303Z,1527800637.303 [CommandLine](IMPORTANT): got command show stack
2018-05-31T21:03:57.303Z,1527800637.303 [CommandLine](IMPORTANT): Behavior Stack:

2018-05-31T21:03:57.304Z,1527800637.304 [sample](IMPORTANT): Priority 0: sample:A.Pitch
2018-05-31T21:03:57.304Z,1527800637.304 [sample](IMPORTANT): Priority 1: sample:B.SetSpeed
2018-05-31T21:03:57.305Z,1527800637.305 [sample:SampleAtDepth](IMPORTANT): Priority 2: sample:SampleAtDepth:B.Pitch
2018-05-31T21:03:57.305Z,1527800637.305 [sample:SampleAtDepth:SampleWrapper:SampleESP](IMPORTANT): Priority 3: sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP
2018-05-31T21:03:57.499Z,1527800637.499 [Radio_Surface](INFO): Powering down
2018-05-31T21:04:29.842Z,1527800669.842 [Radio_Surface](INFO): Powering up
2018-05-31T21:04:35.502Z,1527800675.502 [Radio_Surface](INFO): Powering down
2018-05-31T21:04:36.299Z,1527800676.299 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T21:04:36.300Z,1527800676.300 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 16
2018-05-31T21:04:36.300Z,1527800676.300 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T21:04:36.340Z,1527800676.340 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T21:04:36.716Z,1527800676.716 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T21:04:36.716Z,1527800676.716 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 16
2018-05-31T21:04:37.082Z,1527800677.082 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T21:04:37.083Z,1527800677.083 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T21:04:37.083Z,1527800677.083 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T21:04:46.225Z,1527800686.225 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T21:04:52.221Z,1527800692.221 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T21:04:52.221Z,1527800692.221 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-05-31T21:04:52.221Z,1527800692.221 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T21:04:52.346Z,1527800692.346 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T21:04:52.625Z,1527800692.625 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T21:04:52.891Z,1527800692.891 [Rowe_600LCM](INFO): Powering down
2018-05-31T21:04:54.300Z,1527800694.300 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-05-31T21:04:54.300Z,1527800694.300 [Rowe_600LCM] No Fault, FailCount= 4
2018-05-31T21:04:54.505Z,1527800694.505 [Rowe_600LCM](INFO): Initializing
2018-05-31T21:04:54.505Z,1527800694.505 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T21:04:54.505Z,1527800694.505 [Rowe_600LCM](INFO): LCM OK
2018-05-31T21:04:54.506Z,1527800694.506 [Rowe_600LCM](INFO): Powering up
2018-05-31T21:04:58.671Z,1527800698.671 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T21:04:58.813Z,1527800698.813 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T21:04:58.814Z,1527800698.814 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T21:04:58.815Z,1527800698.815 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T21:04:58.816Z,1527800698.816 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T21:05:07.835Z,1527800707.835 [Radio_Surface](INFO): Powering up
2018-05-31T21:05:13.490Z,1527800713.490 [Radio_Surface](INFO): Powering down
2018-05-31T21:05:46.238Z,1527800746.238 [Radio_Surface](INFO): Powering up
2018-05-31T21:05:46.624Z,1527800746.624 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T21:05:51.895Z,1527800751.895 [Radio_Surface](INFO): Powering down
2018-05-31T21:06:25.038Z,1527800785.038 [Radio_Surface](INFO): Powering up
2018-05-31T21:06:30.698Z,1527800790.698 [Radio_Surface](INFO): Powering down
2018-05-31T21:06:39.885Z,1527800799.885 [BPC1](ERROR): Failed to receive data from both battery packs
2018-05-31T21:06:39.885Z,1527800799.885 [BPC1] Communications Fault, FailCount= 7
2018-05-31T21:06:39.886Z,1527800799.886 [BPC1](ERROR): Communications Fault
2018-05-31T21:06:39.958Z,1527800799.958 [CBIT](ERROR): Communications Fault in component: BPC1
2018-05-31T21:06:41.099Z,1527800801.099 [CBIT](INFO): Clearing failed state for component BPC1
2018-05-31T21:06:41.099Z,1527800801.099 [BPC1] No Fault, FailCount= 7
2018-05-31T21:06:46.624Z,1527800806.624 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T21:06:54.613Z,1527800814.613 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T21:06:54.613Z,1527800814.613 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-05-31T21:06:54.613Z,1527800814.613 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T21:06:54.724Z,1527800814.724 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T21:06:54.725Z,1527800814.725 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-05-31T21:06:55.031Z,1527800815.031 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T21:06:55.300Z,1527800815.300 [Rowe_600LCM](INFO): Powering down
2018-05-31T21:07:03.029Z,1527800823.029 [Radio_Surface](INFO): Powering up
2018-05-31T21:07:08.686Z,1527800828.686 [Radio_Surface](INFO): Powering down
2018-05-31T21:07:37.092Z,1527800857.092 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T21:07:37.092Z,1527800857.092 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 17
2018-05-31T21:07:37.092Z,1527800857.092 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T21:07:37.107Z,1527800857.107 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T21:07:37.500Z,1527800857.500 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T21:07:37.500Z,1527800857.500 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 17
2018-05-31T21:07:37.886Z,1527800857.886 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T21:07:37.886Z,1527800857.886 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T21:07:37.887Z,1527800857.887 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T21:07:43.030Z,1527800863.030 [Radio_Surface](INFO): Powering up
2018-05-31T21:07:46.623Z,1527800866.623 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T21:07:48.690Z,1527800868.690 [Radio_Surface](INFO): Powering down
2018-05-31T21:08:15.775Z,1527800895.775 [CommandLine](IMPORTANT): got command show stack
2018-05-31T21:08:15.775Z,1527800895.775 [CommandLine](IMPORTANT): Behavior Stack:

2018-05-31T21:08:15.775Z,1527800895.775 [sample](IMPORTANT): Priority 0: sample:A.Pitch
2018-05-31T21:08:15.776Z,1527800895.776 [sample](IMPORTANT): Priority 1: sample:B.SetSpeed
2018-05-31T21:08:15.776Z,1527800895.776 [sample:SampleAtDepth](IMPORTANT): Priority 2: sample:SampleAtDepth:B.Pitch
2018-05-31T21:08:15.776Z,1527800895.776 [sample:SampleAtDepth:SampleWrapper:SampleESP](IMPORTANT): Priority 3: sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP
2018-05-31T21:08:21.030Z,1527800901.030 [Radio_Surface](INFO): Powering up
2018-05-31T21:08:26.690Z,1527800906.690 [Radio_Surface](INFO): Powering down
2018-05-31T21:08:47.023Z,1527800927.023 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T21:08:59.829Z,1527800939.829 [Radio_Surface](INFO): Powering up
2018-05-31T21:09:05.494Z,1527800945.494 [Radio_Surface](INFO): Powering down
2018-05-31T21:09:38.633Z,1527800978.633 [Radio_Surface](INFO): Powering up
2018-05-31T21:09:44.298Z,1527800984.298 [Radio_Surface](INFO): Powering down
2018-05-31T21:09:47.023Z,1527800987.023 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T21:09:55.426Z,1527800995.426 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-05-31T21:09:55.426Z,1527800995.426 [NAL9602] Data Fault, FailCount= 5
2018-05-31T21:09:55.426Z,1527800995.426 [NAL9602](ERROR): Data Fault
2018-05-31T21:09:55.529Z,1527800995.529 [CBIT](ERROR): Data Fault in component: NAL9602
2018-05-31T21:09:55.533Z,1527800995.533 [CBIT](CRITICAL): Data Fault in component: NAL9602
2018-05-31T21:09:55.826Z,1527800995.826 [NAL9602](INFO): Powering down
2018-05-31T21:09:55.913Z,1527800995.913 [CommandLine](FAULT): Scheduling is paused
2018-05-31T21:09:55.914Z,1527800995.914 [CBIT](INFO): Critical error at 20180531T210955
2018-05-31T21:09:55.914Z,1527800995.914 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-05-31T21:09:56.278Z,1527800996.278 [MissionManager](INFO): MissionManager is completed.
2018-05-31T21:09:56.278Z,1527800996.278 [MissionManager](INFO): Uninitializing Mission sample
2018-05-31T21:09:56.278Z,1527800996.278 [sample] Stopped
2018-05-31T21:09:56.278Z,1527800996.278 [sample](DEBUG): Aggregate::uninitialize sample
2018-05-31T21:09:56.278Z,1527800996.278 [sample:A.Pitch] Stopped
2018-05-31T21:09:56.278Z,1527800996.278 [sample:B.SetSpeed] Stopped
2018-05-31T21:09:56.278Z,1527800996.278 [sample:B.SetSpeed](DEBUG): Uninitialize.
2018-05-31T21:09:56.278Z,1527800996.278 [sample:SampleAtDepth] Stopped
2018-05-31T21:09:56.278Z,1527800996.278 [sample:SampleAtDepth](DEBUG): Aggregate::uninitialize sample:SampleAtDepth
2018-05-31T21:09:56.278Z,1527800996.278 [sample:SampleAtDepth:B.Pitch] Stopped
2018-05-31T21:09:56.279Z,1527800996.279 [sample:SampleAtDepth:SampleWrapper] Stopped
2018-05-31T21:09:56.279Z,1527800996.279 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper
2018-05-31T21:09:56.279Z,1527800996.279 [sample:SampleAtDepth:SampleWrapper:SampleESP] Stopped
2018-05-31T21:09:56.279Z,1527800996.279 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleESP
2018-05-31T21:09:56.279Z,1527800996.279 [sample:SampleAtDepth:SampleWrapper:SampleESP:WaitForESP] Stopped
2018-05-31T21:09:56.279Z,1527800996.279 [sample:SampleRepeater] Stopped
2018-05-31T21:09:56.279Z,1527800996.279 [sample:SampleRepeater](DEBUG): Aggregate::uninitialize sample:SampleRepeater
2018-05-31T21:09:56.279Z,1527800996.279 [sample:SampleRepeater:Sample] Stopped
2018-05-31T21:09:56.280Z,1527800996.280 [sample:SampleRepeater:Sample](DEBUG): Aggregate::uninitialize sample:SampleRepeater:Sample
2018-05-31T21:09:56.669Z,1527800996.669 [MissionManager](IMPORTANT): Started mission Default
2018-05-31T21:09:56.669Z,1527800996.669 [Default] Running Loop=1
2018-05-31T21:09:56.670Z,1527800996.670 [Default](DEBUG): Aggregate::initialize Default
2018-05-31T21:09:56.670Z,1527800996.670 [Default:B.GoToSurface] Running Loop=1
2018-05-31T21:09:56.670Z,1527800996.670 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-05-31T21:09:56.670Z,1527800996.670 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-05-31T21:09:56.670Z,1527800996.670 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-05-31T21:09:56.671Z,1527800996.671 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-05-31T21:09:56.671Z,1527800996.671 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-05-31T21:09:56.671Z,1527800996.671 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-05-31T21:09:56.672Z,1527800996.672 [Default:A.Wait] Running Loop=1
2018-05-31T21:09:56.672Z,1527800996.672 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-05-31T21:09:57.070Z,1527800997.070 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -13.00 mm (1 active estimators).
2018-05-31T21:10:09.988Z,1527801009.988 [Default:A.Wait](INFO): Done Waiting.
2018-05-31T21:10:09.988Z,1527801009.988 [Default:A.Wait] Stopped
2018-05-31T21:10:09.988Z,1527801009.988 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-05-31T21:10:29.950Z,1527801029.950 [Radio_Surface](INFO): Powering up
2018-05-31T21:10:35.614Z,1527801035.614 [Radio_Surface](INFO): Powering down
2018-05-31T21:10:37.992Z,1527801037.992 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T21:10:37.992Z,1527801037.992 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 18
2018-05-31T21:10:37.992Z,1527801037.992 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T21:10:38.093Z,1527801038.093 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T21:10:38.453Z,1527801038.453 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T21:10:38.453Z,1527801038.453 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 18
2018-05-31T21:10:38.788Z,1527801038.788 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T21:10:38.789Z,1527801038.789 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T21:10:38.789Z,1527801038.789 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T21:10:47.139Z,1527801047.139 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T21:11:07.950Z,1527801067.950 [Radio_Surface](INFO): Powering up
2018-05-31T21:11:13.606Z,1527801073.606 [Radio_Surface](INFO): Powering down
2018-05-31T21:11:25.587Z,1527801085.587 [Default:B.GoToSurface](ERROR): Pitch down timeout. Pitch: -0.16
2018-05-31T21:11:25.730Z,1527801085.730 [Radio_Surface](INFO): Powering up
2018-05-31T21:11:47.139Z,1527801107.139 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T21:11:55.655Z,1527801115.655 [CBIT](INFO): Clearing failed state for component NAL9602
2018-05-31T21:11:55.655Z,1527801115.655 [NAL9602] No Fault, FailCount= 5
2018-05-31T21:11:55.946Z,1527801115.946 [NAL9602](INFO): Powering up NAL9602
2018-05-31T21:12:07.142Z,1527801127.142 [NAL9602](INFO): NAL9602 initialized
2018-05-31T21:12:47.142Z,1527801167.142 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T21:13:24.375Z,1527801204.375 [BPC1](ERROR): Failed to receive data from both battery packs
2018-05-31T21:13:24.375Z,1527801204.375 [BPC1] Communications Fault, FailCount= 8
2018-05-31T21:13:24.375Z,1527801204.375 [BPC1](ERROR): Communications Fault
2018-05-31T21:13:24.406Z,1527801204.406 [CBIT](ERROR): Communications Fault in component: BPC1
2018-05-31T21:13:25.642Z,1527801205.642 [CBIT](INFO): Clearing failed state for component BPC1
2018-05-31T21:13:25.642Z,1527801205.642 [BPC1] No Fault, FailCount= 8
2018-05-31T21:13:39.191Z,1527801219.191 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T21:13:39.191Z,1527801219.191 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 19
2018-05-31T21:13:39.191Z,1527801219.191 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T21:13:39.211Z,1527801219.211 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T21:13:39.614Z,1527801219.614 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T21:13:39.614Z,1527801219.614 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 19
2018-05-31T21:13:39.995Z,1527801219.995 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T21:13:39.996Z,1527801219.996 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T21:13:39.996Z,1527801219.996 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T21:13:47.139Z,1527801227.139 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T21:14:03.981Z,1527801243.981 [ESPComponent](IMPORTANT): ESP sampling state: S_PROCESSING
2018-05-31T21:14:06.379Z,1527801246.379 [ESPComponent](IMPORTANT): ESP sampling state: S_WAITING_FOR_PROCESSED
2018-05-31T21:14:21.975Z,1527801261.975 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003405
2018-05-31T21:15:54.910Z,1527801354.910 [Radio_Surface](INFO): Powering down
2018-05-31T21:16:00.974Z,1527801360.974 [Radio_Surface](INFO): Powering up
2018-05-31T21:16:40.081Z,1527801400.081 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T21:16:40.081Z,1527801400.081 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 20
2018-05-31T21:16:40.081Z,1527801400.081 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T21:16:40.108Z,1527801400.108 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T21:16:40.491Z,1527801400.491 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T21:16:40.491Z,1527801400.491 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 20
2018-05-31T21:16:40.878Z,1527801400.878 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T21:16:40.879Z,1527801400.879 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T21:16:40.879Z,1527801400.879 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T21:16:48.015Z,1527801408.015 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T21:16:54.890Z,1527801414.890 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-05-31T21:16:54.890Z,1527801414.890 [Rowe_600LCM] No Fault, FailCount= 5
2018-05-31T21:16:55.069Z,1527801415.069 [Rowe_600LCM](INFO): Initializing
2018-05-31T21:16:55.069Z,1527801415.069 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T21:16:55.069Z,1527801415.069 [Rowe_600LCM](INFO): LCM OK
2018-05-31T21:16:55.070Z,1527801415.070 [Rowe_600LCM](INFO): Powering up
2018-05-31T21:16:59.207Z,1527801419.207 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T21:16:59.336Z,1527801419.336 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T21:16:59.349Z,1527801419.349 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T21:16:59.350Z,1527801419.350 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T21:16:59.351Z,1527801419.351 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T21:17:47.286Z,1527801467.286 [Radio_Surface](INFO): Powering down
2018-05-31T21:17:47.616Z,1527801467.616 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T21:17:53.354Z,1527801473.354 [Radio_Surface](INFO): Powering up
2018-05-31T21:18:22.018Z,1527801502.018 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.000732
2018-05-31T21:18:55.209Z,1527801535.209 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T21:18:55.209Z,1527801535.209 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-05-31T21:18:55.209Z,1527801535.209 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T21:18:55.340Z,1527801535.340 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T21:18:55.613Z,1527801535.613 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T21:18:55.890Z,1527801535.890 [Rowe_600LCM](INFO): Powering down
2018-05-31T21:18:57.314Z,1527801537.314 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-05-31T21:18:57.314Z,1527801537.314 [Rowe_600LCM] No Fault, FailCount= 1
2018-05-31T21:18:57.505Z,1527801537.505 [Rowe_600LCM](INFO): Initializing
2018-05-31T21:18:57.506Z,1527801537.506 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T21:18:57.506Z,1527801537.506 [Rowe_600LCM](INFO): LCM OK
2018-05-31T21:18:57.506Z,1527801537.506 [Rowe_600LCM](INFO): Powering up
2018-05-31T21:19:01.719Z,1527801541.719 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T21:19:01.848Z,1527801541.848 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T21:19:01.852Z,1527801541.852 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T21:19:01.852Z,1527801541.852 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T21:19:01.857Z,1527801541.857 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T21:19:05.706Z,1527801545.706 [Radio_Surface](INFO): Powering down
2018-05-31T21:19:11.782Z,1527801551.782 [Radio_Surface](INFO): Powering up
2018-05-31T21:19:41.276Z,1527801581.276 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T21:19:41.276Z,1527801581.276 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 21
2018-05-31T21:19:41.277Z,1527801581.277 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T21:19:41.295Z,1527801581.295 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T21:19:41.695Z,1527801581.695 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T21:19:41.695Z,1527801581.695 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 21
2018-05-31T21:19:42.080Z,1527801582.080 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T21:19:42.080Z,1527801582.080 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T21:19:42.085Z,1527801582.085 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T21:19:48.816Z,1527801588.816 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T21:20:24.622Z,1527801624.622 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004948
2018-05-31T21:20:33.068Z,1527801633.068 [BPC1](ERROR): Failed to receive data from both battery packs
2018-05-31T21:20:33.069Z,1527801633.069 [BPC1] Communications Fault, FailCount= 9
2018-05-31T21:20:33.069Z,1527801633.069 [BPC1](ERROR): Communications Fault
2018-05-31T21:20:33.144Z,1527801633.144 [CBIT](ERROR): Communications Fault in component: BPC1
2018-05-31T21:20:34.324Z,1527801634.324 [CBIT](INFO): Clearing failed state for component BPC1
2018-05-31T21:20:34.324Z,1527801634.324 [BPC1] No Fault, FailCount= 9
2018-05-31T21:20:39.903Z,1527801639.903 [Radio_Surface](INFO): Powering down
2018-05-31T21:20:45.966Z,1527801645.966 [Radio_Surface](INFO): Powering up
2018-05-31T21:20:58.242Z,1527801658.242 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T21:20:58.242Z,1527801658.242 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-05-31T21:20:58.242Z,1527801658.242 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T21:20:58.351Z,1527801658.351 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T21:20:58.645Z,1527801658.645 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T21:20:58.889Z,1527801658.889 [Rowe_600LCM](INFO): Powering down
2018-05-31T21:21:00.314Z,1527801660.314 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-05-31T21:21:00.314Z,1527801660.314 [Rowe_600LCM] No Fault, FailCount= 2
2018-05-31T21:21:00.505Z,1527801660.505 [Rowe_600LCM](INFO): Initializing
2018-05-31T21:21:00.505Z,1527801660.505 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T21:21:00.506Z,1527801660.506 [Rowe_600LCM](INFO): LCM OK
2018-05-31T21:21:00.506Z,1527801660.506 [Rowe_600LCM](INFO): Powering up
2018-05-31T21:21:04.718Z,1527801664.718 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T21:21:04.832Z,1527801664.832 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T21:21:04.835Z,1527801664.835 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T21:21:04.836Z,1527801664.836 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T21:21:04.837Z,1527801664.837 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T21:21:35.271Z,1527801695.271 [CommandLine](IMPORTANT): got command show stack
2018-05-31T21:21:35.271Z,1527801695.271 [CommandLine](IMPORTANT): Behavior Stack:

2018-05-31T21:21:35.272Z,1527801695.272 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface
2018-05-31T21:21:41.579Z,1527801701.579 [CommandLine](IMPORTANT): got command maintain clear
2018-05-31T21:21:41.598Z,1527801701.598 [controlThread](DEBUG): Component order: CycleStarter,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-05-31T21:21:41.917Z,1527801701.917 [Default:CheckIn] Running Loop=1
2018-05-31T21:21:41.918Z,1527801701.918 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-05-31T21:21:41.918Z,1527801701.918 [Default:CheckIn:Read_GPS] Running Loop=1
2018-05-31T21:21:44.983Z,1527801704.983 [CommandLine](IMPORTANT): got command get depth
2018-05-31T21:21:44.984Z,1527801704.984 [CommandLine](IMPORTANT): depth -0.059171 m
2018-05-31T21:21:49.124Z,1527801709.124 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T21:22:08.335Z,1527801728.335 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-05-31T21:22:08.335Z,1527801728.335 [NAL9602] Data Fault, FailCount= 1
2018-05-31T21:22:08.335Z,1527801728.335 [NAL9602](ERROR): Data Fault
2018-05-31T21:22:08.496Z,1527801728.496 [CBIT](ERROR): Data Fault in component: NAL9602
2018-05-31T21:22:08.735Z,1527801728.735 [NAL9602](INFO): Powering down
2018-05-31T21:22:09.668Z,1527801729.668 [CBIT](INFO): Clearing failed state for component NAL9602
2018-05-31T21:22:09.668Z,1527801729.668 [NAL9602] No Fault, FailCount= 1
2018-05-31T21:22:22.315Z,1527801742.315 [CommandLine](IMPORTANT): got command failComponent
2018-05-31T21:22:22.315Z,1527801742.315 [CommandLine](IMPORTANT): Failed components:
2018-05-31T21:22:22.315Z,1527801742.315 [CommandLine](IMPORTANT): No failed Components.
2018-05-31T21:22:38.739Z,1527801758.739 [NAL9602](INFO): Powering up NAL9602
2018-05-31T21:22:42.388Z,1527801762.388 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T21:22:42.388Z,1527801762.388 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 22
2018-05-31T21:22:42.389Z,1527801762.389 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T21:22:42.429Z,1527801762.429 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T21:22:42.803Z,1527801762.803 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T21:22:42.803Z,1527801762.803 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 22
2018-05-31T21:22:43.187Z,1527801763.187 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T21:22:43.188Z,1527801763.188 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T21:22:43.188Z,1527801763.188 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T21:22:49.524Z,1527801769.524 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-05-31T21:22:49.935Z,1527801769.935 [NAL9602](INFO): NAL9602 initialized
2018-05-31T21:23:01.121Z,1527801781.121 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T21:23:01.121Z,1527801781.121 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-05-31T21:23:01.121Z,1527801781.121 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T21:23:01.248Z,1527801781.248 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T21:23:01.525Z,1527801781.525 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T21:23:01.798Z,1527801781.798 [Rowe_600LCM](INFO): Powering down
2018-05-31T21:23:03.198Z,1527801783.198 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-05-31T21:23:03.198Z,1527801783.198 [Rowe_600LCM] No Fault, FailCount= 3
2018-05-31T21:23:03.413Z,1527801783.413 [Rowe_600LCM](INFO): Initializing
2018-05-31T21:23:03.413Z,1527801783.413 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T21:23:03.414Z,1527801783.414 [Rowe_600LCM](INFO): LCM OK
2018-05-31T21:23:03.414Z,1527801783.414 [Rowe_600LCM](INFO): Powering up
2018-05-31T21:23:07.760Z,1527801787.760 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T21:23:07.876Z,1527801787.876 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T21:23:07.880Z,1527801787.880 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T21:23:07.881Z,1527801787.881 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T21:23:07.882Z,1527801787.882 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T21:23:25.931Z,1527801805.931 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=181.314133
2018-05-31T21:24:24.834Z,1527801864.834 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003969
2018-05-31T21:25:03.625Z,1527801903.625 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T21:25:03.625Z,1527801903.625 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-05-31T21:25:03.625Z,1527801903.625 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T21:25:03.739Z,1527801903.739 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T21:25:04.029Z,1527801904.029 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T21:25:04.288Z,1527801904.288 [Rowe_600LCM](INFO): Powering down
2018-05-31T21:25:05.710Z,1527801905.710 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-05-31T21:25:05.710Z,1527801905.710 [Rowe_600LCM] No Fault, FailCount= 4
2018-05-31T21:25:05.905Z,1527801905.905 [Rowe_600LCM](INFO): Initializing
2018-05-31T21:25:05.905Z,1527801905.905 [Rowe_600LCM](INFO): Checking LCM
2018-05-31T21:25:05.906Z,1527801905.906 [Rowe_600LCM](INFO): LCM OK
2018-05-31T21:25:05.906Z,1527801905.906 [Rowe_600LCM](INFO): Powering up
2018-05-31T21:25:10.096Z,1527801910.096 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-05-31T21:25:10.216Z,1527801910.216 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-05-31T21:25:10.217Z,1527801910.217 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-05-31T21:25:10.218Z,1527801910.218 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-05-31T21:25:10.219Z,1527801910.219 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-05-31T21:25:30.792Z,1527801930.792 [ESPComponent](IMPORTANT): ESP sampling state: S_STOPPING
2018-05-31T21:25:43.266Z,1527801943.266 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T21:25:43.266Z,1527801943.266 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 23
2018-05-31T21:25:43.266Z,1527801943.266 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T21:25:43.317Z,1527801943.317 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T21:25:43.702Z,1527801943.702 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T21:25:43.702Z,1527801943.702 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 23
2018-05-31T21:25:44.027Z,1527801944.027 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T21:25:44.028Z,1527801944.028 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T21:25:44.028Z,1527801944.028 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T21:25:54.826Z,1527801954.826 [ESPComponent](IMPORTANT): ESP sampling sequence completed normally (sample #1)
2018-05-31T21:25:54.827Z,1527801954.827 [ESPComponent](DEBUG): Writing samplingActive=0, sampleNumber=1
2018-05-31T21:25:55.218Z,1527801955.218 [ESPComponent](INFO): powering down ESP
2018-05-31T21:26:42.240Z,1527802002.240 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-05-31T21:21:41.9Z
2018-05-31T21:26:42.241Z,1527802002.241 [Default:CheckIn:Read_GPS] Stopped
2018-05-31T21:26:42.241Z,1527802002.241 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-05-31T21:26:42.666Z,1527802002.666 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-05-31T21:26:47.519Z,1527802007.519 [DataOverHttps](INFO): Sending 93 bytes from file Logs/20180531T201611/Courier0004.lzma
2018-05-31T21:26:48.305Z,1527802008.305 [DataOverHttps](INFO): Moved sent file to Logs/20180531T201611/Courier0004.lzma.bak
2018-05-31T21:26:48.305Z,1527802008.305 [DataOverHttps](INFO): SBD MOMSN=8300582
2018-05-31T21:26:58.752Z,1527802018.752 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180531T201611/Courier0007.lzma
2018-05-31T21:26:59.538Z,1527802019.538 [DataOverHttps](INFO): Moved sent file to Logs/20180531T201611/Courier0007.lzma.bak
2018-05-31T21:26:59.538Z,1527802019.538 [DataOverHttps](INFO): SBD MOMSN=8300585
2018-05-31T21:27:06.485Z,1527802026.485 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-05-31T21:27:06.485Z,1527802026.485 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-05-31T21:27:06.485Z,1527802026.485 [Rowe_600LCM](ERROR): Communications Fault
2018-05-31T21:27:06.880Z,1527802026.880 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-05-31T21:27:06.880Z,1527802026.880 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-05-31T21:27:06.889Z,1527802026.889 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-05-31T21:27:07.062Z,1527802027.062 [Rowe_600LCM](INFO): Powering down
2018-05-31T21:27:09.988Z,1527802029.988 [DataOverHttps](INFO): Sending 1984 bytes from file Logs/20180531T201611/Express0005.lzma
2018-05-31T21:27:10.764Z,1527802030.764 [DataOverHttps](INFO): Moved sent file to Logs/20180531T201611/Express0005.lzma.bak
2018-05-31T21:27:10.765Z,1527802030.765 [DataOverHttps](INFO): SBD MOMSN=8300587
2018-05-31T21:27:19.984Z,1527802039.984 [BPC1](ERROR): Failed to receive data from both battery packs
2018-05-31T21:27:19.984Z,1527802039.984 [BPC1] Communications Fault, FailCount= 10
2018-05-31T21:27:19.984Z,1527802039.984 [BPC1](ERROR): Communications Fault
2018-05-31T21:27:20.066Z,1527802040.066 [CBIT](ERROR): Communications Fault in component: BPC1
2018-05-31T21:27:20.066Z,1527802040.066 [CBIT](CRITICAL): Communications Fault in component: BPC1
2018-05-31T21:27:20.078Z,1527802040.078 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180531T201611/Express0008.lzma
2018-05-31T21:27:20.184Z,1527802040.184 [CBIT](INFO): Critical error at 20180531T212720
2018-05-31T21:27:20.879Z,1527802040.879 [DataOverHttps](INFO): Moved sent file to Logs/20180531T201611/Express0008.lzma.bak
2018-05-31T21:27:20.879Z,1527802040.879 [DataOverHttps](INFO): SBD MOMSN=8300712
2018-05-31T21:27:22.020Z,1527802042.020 [Default:CheckIn:Read_Iridium] Stopped
2018-05-31T21:27:22.021Z,1527802042.021 [Default:CheckIn:C.Wait] Running Loop=1
2018-05-31T21:27:22.021Z,1527802042.021 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-05-31T21:28:44.149Z,1527802124.149 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T21:28:44.149Z,1527802124.149 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 24
2018-05-31T21:28:44.149Z,1527802124.149 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T21:28:44.184Z,1527802124.184 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T21:28:44.555Z,1527802124.555 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T21:28:44.555Z,1527802124.555 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 24
2018-05-31T21:28:44.932Z,1527802124.932 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T21:28:44.932Z,1527802124.932 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T21:28:44.933Z,1527802124.933 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T21:29:26.500Z,1527802166.500 [DataOverHttps](IMPORTANT): SBD MTMSN=20180531T212904
2018-05-31T21:29:30.506Z,1527802170.506 [DataOverHttps](INFO): Received command:! nohup summarizeESP
2018-05-31T21:29:30.558Z,1527802170.558 [CommandLine](IMPORTANT): got command ! nohup summarizeESP
2018-05-31T21:30:33.140Z,1527802233.140 [DataOverHttps](IMPORTANT): SBD MTMSN=20180531T213011
2018-05-31T21:30:40.546Z,1527802240.546 [DataOverHttps](INFO): Received command:! nohup /mnt/mmc/LRAUV/Tools/summarizeESP
2018-05-31T21:30:40.554Z,1527802240.554 [CommandLine](IMPORTANT): got command ! nohup /mnt/mmc/LRAUV/Tools/summarizeESP
2018-05-31T21:31:45.022Z,1527802305.022 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T21:31:45.022Z,1527802305.022 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 25
2018-05-31T21:31:45.022Z,1527802305.022 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T21:31:45.052Z,1527802305.052 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T21:31:45.454Z,1527802305.454 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T21:31:45.454Z,1527802305.454 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 25
2018-05-31T21:31:45.822Z,1527802305.822 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T21:31:45.823Z,1527802305.823 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T21:31:45.823Z,1527802305.823 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T21:32:20.235Z,1527802340.235 [CBIT](INFO): Clearing failed state for component BPC1
2018-05-31T21:32:20.235Z,1527802340.235 [BPC1] No Fault, FailCount= 10
2018-05-31T21:32:22.224Z,1527802342.224 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-05-31T21:32:22.224Z,1527802342.224 [Default:CheckIn:C.Wait] Stopped
2018-05-31T21:32:22.224Z,1527802342.224 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-05-31T21:32:22.225Z,1527802342.225 [Default:CheckIn:D] Running Loop=1
2018-05-31T21:32:22.628Z,1527802342.628 [Default:CheckIn:D] Stopped
2018-05-31T21:32:22.628Z,1527802342.628 [Default:CheckIn:E] Running Loop=1
2018-05-31T21:32:23.020Z,1527802343.020 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.432603 min 
2018-05-31T21:32:23.027Z,1527802343.027 [Default:CheckIn:E] Stopped
2018-05-31T21:32:23.027Z,1527802343.027 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-05-31T21:32:23.027Z,1527802343.027 [Default:CheckIn] Stopped
2018-05-31T21:32:23.027Z,1527802343.027 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-05-31T21:32:23.027Z,1527802343.027 [Default:CheckIn](INFO): Running loop #2
2018-05-31T21:32:23.027Z,1527802343.027 [Default:CheckIn] Running Loop=2
2018-05-31T21:32:23.027Z,1527802343.027 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-05-31T21:32:23.028Z,1527802343.028 [Default:CheckIn:Read_GPS] Running Loop=1
2018-05-31T21:32:39.092Z,1527802359.092 [DataOverHttps](IMPORTANT): SBD MTMSN=20180531T213217
2018-05-31T21:32:43.090Z,1527802363.090 [DataOverHttps](INFO): Received command:! ESPsummary
2018-05-31T21:32:43.118Z,1527802363.118 [CommandLine](IMPORTANT): got command ! ESPsummary
2018-05-31T21:32:51.090Z,1527802371.090 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-05-31T21:32:51.091Z,1527802371.091 [NAL9602] Data Fault, FailCount= 2
2018-05-31T21:32:51.091Z,1527802371.091 [NAL9602](ERROR): Data Fault
2018-05-31T21:32:51.177Z,1527802371.177 [CBIT](ERROR): Data Fault in component: NAL9602
2018-05-31T21:32:51.490Z,1527802371.490 [NAL9602](INFO): Powering down
2018-05-31T21:32:52.345Z,1527802372.345 [CBIT](INFO): Clearing failed state for component NAL9602
2018-05-31T21:32:52.345Z,1527802372.345 [NAL9602] No Fault, FailCount= 2
2018-05-31T21:33:03.586Z,1527802383.586 [CommandLine](IMPORTANT): got command ! summarizeESP
2018-05-31T21:33:21.498Z,1527802401.498 [NAL9602](INFO): Powering up NAL9602
2018-05-31T21:33:21.759Z,1527802401.759 [CommandLine](IMPORTANT): got command ! /LRAUV/Tools/summarizeESP
2018-05-31T21:33:29.379Z,1527802409.379 [CommandLine](IMPORTANT): got command ! ls /LRUAV/
2018-05-31T21:33:32.690Z,1527802412.690 [NAL9602](INFO): NAL9602 initialized
2018-05-31T21:33:34.951Z,1527802414.951 [CommandLine](IMPORTANT): got command ! ls /LRAUV
2018-05-31T21:33:35.032Z,1527802415.032 [CommandLine](IMPORTANT): Config
Data
LRAUV
Logs
Missions
Modules
Resources
RoweADCP-2018-05-31T20.ENS
Tools
bin
lrauv-framework

2018-05-31T21:33:44.146Z,1527802424.146 [CommandLine](IMPORTANT): got command ! /LRAUV/Tools/summarizeESP
2018-05-31T21:34:12.055Z,1527802452.055 [CommandLine](IMPORTANT): got command failComponent
2018-05-31T21:34:12.055Z,1527802452.055 [CommandLine](IMPORTANT): Failed components:
2018-05-31T21:34:12.055Z,1527802452.055 [CommandLine](IMPORTANT): Rowe_600LCM: Communications Fault
2018-05-31T21:34:44.379Z,1527802484.379 [DataOverHttps](IMPORTANT): SBD MTMSN=20180531T213422
2018-05-31T21:34:48.330Z,1527802488.330 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-31T21:34:48.331Z,1527802488.331 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 26
2018-05-31T21:34:48.331Z,1527802488.331 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-31T21:34:48.388Z,1527802488.388 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-31T21:34:48.417Z,1527802488.417 [DataOverHttps](INFO): Received command:! nohup summarizeESP.sh
2018-05-31T21:34:48.486Z,1527802488.486 [CommandLine](IMPORTANT): got command ! nohup summarizeESP.sh
2018-05-31T21:34:48.607Z,1527802488.607 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-31T21:34:48.607Z,1527802488.607 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 26
2018-05-31T21:34:48.868Z,1527802488.868 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-31T21:34:48.868Z,1527802488.868 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-31T21:34:48.869Z,1527802488.869 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-31T21:35:04.835Z,1527802504.835 [CommandLine](IMPORTANT): got command ! /LRAUV/Tools/summarizeESP.sh
2018-05-31T21:36:02.039Z,1527802562.039 [AcousticModem_Benthos_ATM900](DEBUG): LCB error: Software Overcurrent.
2018-05-31T21:36:02.439Z,1527802562.439 [AcousticModem_Benthos_ATM900](DEBUG): LCB error: Software Overcurrent.
2018-05-31T21:36:02.839Z,1527802562.839 [AcousticModem_Benthos_ATM900](DEBUG): LCB error: Software Overcurrent.
2018-05-31T21:36:03.238Z,1527802563.238 [AcousticModem_Benthos_ATM900](DEBUG): LCB error: Software Overcurrent.
2018-05-31T21:36:03.639Z,1527802563.639 [AcousticModem_Benthos_ATM900](DEBUG): LCB error: Software Overcurrent.
2018-05-31T21:36:04.039Z,1527802564.039 [AcousticModem_Benthos_ATM900](DEBUG): LCB error: Software Overcurrent.
2018-05-31T21:36:04.439Z,1527802564.439 [AcousticModem_Benthos_ATM900](DEBUG): LCB error: Software Overcurrent.
2018-05-31T21:36:04.839Z,1527802564.839 [AcousticModem_Benthos_ATM900](DEBUG): LCB error: Software Overcurrent.
2018-05-31T21:36:05.238Z,1527802565.238 [AcousticModem_Benthos_ATM900](DEBUG): LCB error: Software Overcurrent.
2018-05-31T21:36:49.260Z,1527802609.260 [DataOverHttps](IMPORTANT): SBD MTMSN=20180531T213626
2018-05-31T21:36:54.082Z,1527802614.082 [DataOverHttps](INFO): Received command:! /LRAUV/Tools/ESPsummary.sh
2018-05-31T21:36:54.102Z,1527802614.102 [CommandLine](IMPORTANT): got command ! /LRAUV/Tools/ESPsummary.sh
2018-05-31T21:36:54.448Z,1527802614.448 [CommandLine](IMPORTANT): @13:27:35.09 Selecting Cartridge 60
@14:13:37.14 Cartridge::Sampler::Clogged in FILTERING -- Cartridge clogged
@14:13:37.23 <FILTERING> Sampled  691.2ml

2018-05-31T21:36:54.880Z,1527802614.880 [DataOverHttps](IMPORTANT): SBD MTMSN=20180531T213632
2018-05-31T21:36:58.901Z,1527802618.901 [DataOverHttps](INFO): Received command:restart logs