2018-08-23T17:09:12.318Z,1535044152.318 [Supervisor](DEBUG): Initializing supervisor.
2018-08-23T17:09:12.321Z,1535044152.321 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-08-23T17:09:12.322Z,1535044152.322 [SyncHandler](INFO): Protected caller Thread ID is 2145
2018-08-23T17:09:12.322Z,1535044152.322 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-08-23T17:09:12.323Z,1535044152.323 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-08-23T17:09:12.323Z,1535044152.323 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2146
2018-08-23T17:09:12.327Z,1535044152.327 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-08-23T17:09:12.339Z,1535044152.339 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-08-23T17:09:12.340Z,1535044152.340 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-08-23T17:09:12.340Z,1535044152.340 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2147
2018-08-23T17:09:12.341Z,1535044152.341 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-08-23T17:09:12.342Z,1535044152.342 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-08-23T17:09:12.343Z,1535044152.343 [logger ThreadHandler](INFO): Protected caller Thread ID is 2148
2018-08-23T17:09:12.344Z,1535044152.344 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-08-23T17:09:12.345Z,1535044152.345 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-08-23T17:09:12.347Z,1535044152.347 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-08-23T17:09:12.510Z,1535044152.510 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-08-23T17:09:12.511Z,1535044152.511 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-08-23T17:09:12.615Z,1535044152.615 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-08-23T17:09:12.617Z,1535044152.617 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-08-23T17:09:12.828Z,1535044152.828 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-08-23T17:09:12.829Z,1535044152.829 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-08-23T17:09:13.169Z,1535044153.169 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-08-23T17:09:13.170Z,1535044153.170 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-08-23T17:09:13.522Z,1535044153.522 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-08-23T17:09:13.523Z,1535044153.523 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-08-23T17:09:14.001Z,1535044154.001 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-08-23T17:09:14.002Z,1535044154.002 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-08-23T17:09:14.440Z,1535044154.440 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-08-23T17:09:14.441Z,1535044154.441 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-08-23T17:09:14.930Z,1535044154.930 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-08-23T17:09:14.931Z,1535044154.931 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-08-23T17:09:15.014Z,1535044155.014 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-08-23T17:09:15.327Z,1535044155.327 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-08-23T17:09:15.329Z,1535044155.329 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-08-23T17:09:15.479Z,1535044155.479 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-08-23T17:09:15.480Z,1535044155.480 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-08-23T17:09:15.695Z,1535044155.695 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-08-23T17:09:15.696Z,1535044155.696 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-08-23T17:09:15.923Z,1535044155.923 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-08-23T17:09:15.923Z,1535044155.923 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-08-23T17:09:16.024Z,1535044156.024 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-08-23T17:09:16.025Z,1535044156.025 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-08-23T17:09:16.184Z,1535044156.184 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-08-23T17:09:16.186Z,1535044156.186 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2018-08-23T17:09:16.302Z,1535044156.302 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2018-08-23T17:09:16.781Z,1535044156.781 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-08-23T17:09:16.782Z,1535044156.782 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2018-08-23T17:09:16.891Z,1535044156.891 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2018-08-23T17:09:17.039Z,1535044157.039 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2018-08-23T17:09:17.135Z,1535044157.135 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2018-08-23T17:09:17.222Z,1535044157.222 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2018-08-23T17:09:17.370Z,1535044157.370 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2018-08-23T17:09:17.557Z,1535044157.557 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2018-08-23T17:09:17.657Z,1535044157.657 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2018-08-23T17:09:17.755Z,1535044157.755 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2018-08-23T17:09:17.855Z,1535044157.855 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2018-08-23T17:09:17.940Z,1535044157.940 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-08-23T17:09:17.950Z,1535044157.950 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-08-23T17:09:18.077Z,1535044158.077 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-08-23T17:09:18.078Z,1535044158.078 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-08-23T17:09:18.101Z,1535044158.101 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-08-23T17:09:18.102Z,1535044158.102 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-08-23T17:09:18.157Z,1535044158.157 [DepthRateCalculator] Loaded
2018-08-23T17:09:18.157Z,1535044158.157 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-08-23T17:09:18.163Z,1535044158.163 [PitchRateCalculator] Loaded
2018-08-23T17:09:18.163Z,1535044158.163 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-08-23T17:09:18.180Z,1535044158.180 [SpeedCalculator] Loaded
2018-08-23T17:09:18.180Z,1535044158.180 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-08-23T17:09:18.202Z,1535044158.202 [TempGradientCalculator] Loaded
2018-08-23T17:09:18.202Z,1535044158.202 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-08-23T17:09:18.217Z,1535044158.217 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-08-23T17:09:18.218Z,1535044158.218 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-08-23T17:09:18.223Z,1535044158.223 [YawRateCalculator] Loaded
2018-08-23T17:09:18.224Z,1535044158.224 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-08-23T17:09:18.264Z,1535044158.264 [ElevatorOffsetCalculator] Loaded
2018-08-23T17:09:18.264Z,1535044158.264 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-08-23T17:09:18.265Z,1535044158.265 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-08-23T17:09:18.266Z,1535044158.266 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-08-23T17:09:18.303Z,1535044158.303 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-08-23T17:09:18.303Z,1535044158.303 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-08-23T17:09:18.670Z,1535044158.670 [DataOverHttps] Loaded
2018-08-23T17:09:18.670Z,1535044158.670 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-08-23T17:09:18.696Z,1535044158.696 [Depth_Keller] Loaded
2018-08-23T17:09:18.696Z,1535044158.696 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-08-23T17:09:18.701Z,1535044158.701 [DropWeight] Loaded
2018-08-23T17:09:18.701Z,1535044158.701 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-08-23T17:09:18.801Z,1535044158.801 [NAL9602] Loaded
2018-08-23T17:09:18.801Z,1535044158.801 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-08-23T17:09:18.817Z,1535044158.817 [Onboard] Loaded
2018-08-23T17:09:18.817Z,1535044158.817 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-08-23T17:09:18.828Z,1535044158.828 [Radio_Surface] Loaded
2018-08-23T17:09:18.828Z,1535044158.828 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-08-23T17:09:18.829Z,1535044158.829 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407B84E0
2018-08-23T17:09:18.829Z,1535044158.829 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2227
2018-08-23T17:09:18.877Z,1535044158.877 [PNI_TCM] Loaded
2018-08-23T17:09:18.878Z,1535044158.878 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-08-23T17:09:18.939Z,1535044158.939 [Rowe_600LCM] Loaded
2018-08-23T17:09:18.939Z,1535044158.939 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-08-23T17:09:18.940Z,1535044158.940 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 407E84E0
2018-08-23T17:09:18.941Z,1535044158.941 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 2228
2018-08-23T17:09:20.718Z,1535044160.718 [BPC1] Loaded
2018-08-23T17:09:20.718Z,1535044160.718 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-08-23T17:09:20.719Z,1535044160.719 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-08-23T17:09:20.720Z,1535044160.720 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-08-23T17:09:20.873Z,1535044160.873 [SBIT](DEBUG): Construct Startup Built In Test.
2018-08-23T17:09:20.896Z,1535044160.896 [SBIT] Loaded
2018-08-23T17:09:20.896Z,1535044160.896 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-08-23T17:09:20.897Z,1535044160.897 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-08-23T17:09:20.909Z,1535044160.909 [IBIT] Loaded
2018-08-23T17:09:20.910Z,1535044160.910 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-08-23T17:09:20.913Z,1535044160.913 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-08-23T17:09:21.063Z,1535044161.063 [CBIT] Loaded
2018-08-23T17:09:21.064Z,1535044161.064 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-08-23T17:09:21.064Z,1535044161.064 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-08-23T17:09:21.065Z,1535044161.065 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-08-23T17:09:21.251Z,1535044161.251 [Aanderaa_O2] Loaded
2018-08-23T17:09:21.252Z,1535044161.252 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-08-23T17:09:21.305Z,1535044161.305 [CTD_Seabird] Loaded
2018-08-23T17:09:21.306Z,1535044161.306 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-08-23T17:09:21.307Z,1535044161.307 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 408AC4E0
2018-08-23T17:09:21.307Z,1535044161.307 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2229
2018-08-23T17:09:21.324Z,1535044161.324 [ESPComponent] Loaded
2018-08-23T17:09:21.325Z,1535044161.325 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2018-08-23T17:09:21.339Z,1535044161.339 [PAR_Licor] Loaded
2018-08-23T17:09:21.339Z,1535044161.339 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-08-23T17:09:21.389Z,1535044161.389 [WetLabsBB2FL] Loaded
2018-08-23T17:09:21.389Z,1535044161.389 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-08-23T17:09:21.390Z,1535044161.390 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408DC4E0
2018-08-23T17:09:21.391Z,1535044161.391 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2230
2018-08-23T17:09:21.391Z,1535044161.391 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-08-23T17:09:21.392Z,1535044161.392 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-08-23T17:09:22.019Z,1535044162.019 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-08-23T17:09:22.020Z,1535044162.020 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-08-23T17:09:22.106Z,1535044162.106 [VerticalControl](DEBUG): Construct VerticalControl.
2018-08-23T17:09:22.201Z,1535044162.201 [VerticalControl] Loaded
2018-08-23T17:09:22.201Z,1535044162.201 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-08-23T17:09:22.202Z,1535044162.202 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-08-23T17:09:22.263Z,1535044162.263 [HorizontalControl] Loaded
2018-08-23T17:09:22.264Z,1535044162.264 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-08-23T17:09:22.264Z,1535044162.264 [SpeedControl](DEBUG): Construct SpeedControl.
2018-08-23T17:09:22.270Z,1535044162.270 [SpeedControl] Loaded
2018-08-23T17:09:22.270Z,1535044162.270 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-08-23T17:09:22.271Z,1535044162.271 [LoopControl](DEBUG): Construct LoopControl.
2018-08-23T17:09:22.271Z,1535044162.271 [LoopControl] Loaded
2018-08-23T17:09:22.271Z,1535044162.271 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-08-23T17:09:22.272Z,1535044162.272 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-08-23T17:09:22.272Z,1535044162.272 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-08-23T17:09:22.393Z,1535044162.393 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-08-23T17:09:22.393Z,1535044162.393 [StratificationFrontDetector](DEBUG): (re)initializing
2018-08-23T17:09:22.393Z,1535044162.393 [StratificationFrontDetector] Loaded
2018-08-23T17:09:22.393Z,1535044162.393 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-08-23T17:09:22.394Z,1535044162.394 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-08-23T17:09:22.395Z,1535044162.395 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-08-23T17:09:22.512Z,1535044162.512 [BuoyancyServo] Loaded
2018-08-23T17:09:22.512Z,1535044162.512 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-08-23T17:09:22.524Z,1535044162.524 [ElevatorServo] Loaded
2018-08-23T17:09:22.524Z,1535044162.524 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-08-23T17:09:22.536Z,1535044162.536 [MassServo] Loaded
2018-08-23T17:09:22.536Z,1535044162.536 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-08-23T17:09:22.547Z,1535044162.547 [RudderServo] Loaded
2018-08-23T17:09:22.548Z,1535044162.548 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-08-23T17:09:22.559Z,1535044162.559 [ThrusterServo] Loaded
2018-08-23T17:09:22.559Z,1535044162.559 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-08-23T17:09:22.559Z,1535044162.559 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-08-23T17:09:22.560Z,1535044162.560 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-08-23T17:09:22.668Z,1535044162.668 [DeadReckonUsingSpeedCalculator] Loaded
2018-08-23T17:09:22.668Z,1535044162.668 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-08-23T17:09:22.684Z,1535044162.684 [NavChart] Loaded
2018-08-23T17:09:22.684Z,1535044162.684 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-08-23T17:09:22.688Z,1535044162.688 [UniversalFixResidualReporter] Loaded
2018-08-23T17:09:22.689Z,1535044162.689 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-08-23T17:09:22.689Z,1535044162.689 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-08-23T17:09:22.693Z,1535044162.693 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-08-23T17:09:22.694Z,1535044162.694 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-08-23T17:09:22.701Z,1535044162.701 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-08-23T17:09:22.702Z,1535044162.702 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A354E0
2018-08-23T17:09:22.702Z,1535044162.702 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2231
2018-08-23T17:09:22.707Z,1535044162.707 [Supervisor](INFO): Main Thread ID is 796
2018-08-23T17:09:22.707Z,1535044162.707 [Supervisor](DEBUG): Running supervisor.
2018-08-23T17:09:22.708Z,1535044162.708 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2232
2018-08-23T17:09:22.710Z,1535044162.710 [controlThread ThreadHandler](INFO): Handler Thread ID is 2233
2018-08-23T17:09:22.711Z,1535044162.711 [controlThread](DEBUG): Initializing ControlThread
2018-08-23T17:09:22.712Z,1535044162.712 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-08-23T17:09:22.712Z,1535044162.712 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-08-23T17:09:22.712Z,1535044162.712 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-08-23T17:09:22.713Z,1535044162.713 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-08-23T17:09:22.714Z,1535044162.714 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-08-23T17:09:22.714Z,1535044162.714 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-08-23T17:09:22.715Z,1535044162.715 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-08-23T17:09:22.719Z,1535044162.719 [SBIT](INFO): Initialize SBIT Component.
2018-08-23T17:09:22.720Z,1535044162.720 [SBIT](IMPORTANT): git: 2018-08-23
2018-08-23T17:09:22.720Z,1535044162.720 [SBIT](INFO): git hash: d20dfc3a9974152c601b16753a1ba48dabe730d0
2018-08-23T17:09:22.721Z,1535044162.721 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-08-23T17:09:22.722Z,1535044162.722 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-08-23T17:09:22.723Z,1535044162.723 [SBIT](INFO): Beginning SBIT in 59.000000 seconds.
2018-08-23T17:09:22.723Z,1535044162.723 [IBIT](INFO): Initialize IBIT Component.
2018-08-23T17:09:22.724Z,1535044162.724 [CBIT](DEBUG): Initialize CBIT Component.
2018-08-23T17:09:22.725Z,1535044162.725 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-08-23T17:09:22.726Z,1535044162.726 [logger ThreadHandler](INFO): Handler Thread ID is 2234
2018-08-23T17:09:22.745Z,1535044162.745 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2235
2018-08-23T17:09:22.751Z,1535044162.751 [Radio_Surface](INFO): Powering up
2018-08-23T17:09:22.757Z,1535044162.757 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 2236
2018-08-23T17:09:22.758Z,1535044162.758 [Rowe_600LCM](INFO): Initializing
2018-08-23T17:09:22.758Z,1535044162.758 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T17:09:22.770Z,1535044162.770 [Rowe_600LCM](INFO): LCM OK
2018-08-23T17:09:22.770Z,1535044162.770 [Rowe_600LCM](INFO): Powering up
2018-08-23T17:09:22.777Z,1535044162.777 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2237
2018-08-23T17:09:22.778Z,1535044162.778 [CTD_Seabird](INFO): Initializing
2018-08-23T17:09:22.779Z,1535044162.779 [CTD_Seabird](INFO): Checking LCM
2018-08-23T17:09:22.779Z,1535044162.779 [CTD_Seabird](INFO): LCM OK
2018-08-23T17:09:22.779Z,1535044162.779 [CTD_Seabird](INFO): Powering up
2018-08-23T17:09:22.789Z,1535044162.789 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2238
2018-08-23T17:09:22.790Z,1535044162.790 [WetLabsBB2FL](INFO): Powering down
2018-08-23T17:09:22.815Z,1535044162.815 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2239
2018-08-23T17:09:22.824Z,1535044162.824 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI11M.000
2018-08-23T17:09:22.824Z,1535044162.824 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI11M.000
2018-08-23T17:09:22.824Z,1535044162.824 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5MI07M.000
2018-08-23T17:09:22.824Z,1535044162.824 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5MI07M.000
2018-08-23T17:09:22.825Z,1535044162.825 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH07M.000
2018-08-23T17:09:22.825Z,1535044162.825 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH07M.000
2018-08-23T17:09:22.825Z,1535044162.825 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH31M.000
2018-08-23T17:09:22.825Z,1535044162.825 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH31M.000
2018-08-23T17:09:22.849Z,1535044162.849 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-08-23T17:09:22.851Z,1535044162.851 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-08-23T17:09:22.852Z,1535044162.852 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-08-23T17:09:22.852Z,1535044162.852 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-08-23T17:09:22.854Z,1535044162.854 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-23T17:09:22.855Z,1535044162.855 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-23T17:09:22.856Z,1535044162.856 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-23T17:09:22.856Z,1535044162.856 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-08-23T17:09:22.856Z,1535044162.856 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-08-23T17:09:22.858Z,1535044162.858 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-08-23T17:09:22.905Z,1535044162.905 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-08-23T17:09:22.933Z,1535044162.933 [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-08-23T17:09:22.934Z,1535044162.934 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-08-23T17:09:23.018Z,1535044163.018 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-08-23T17:09:23.020Z,1535044163.020 [Default:A.Wait](DEBUG): Construct Wait.
2018-08-23T17:09:23.022Z,1535044163.022 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-08-23T17:09:23.068Z,1535044163.068 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-08-23T17:09:23.071Z,1535044163.071 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-08-23T17:09:23.101Z,1535044163.101 [Default:E.Execute](DEBUG): Construct Execute.
2018-08-23T17:09:23.125Z,1535044163.125 [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-08-23T17:09:23.130Z,1535044163.130 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-08-23T17:09:23.156Z,1535044163.156 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-08-23T17:09:23.492Z,1535044163.492 [ESPComponent](INFO): powering down ESP
2018-08-23T17:09:24.058Z,1535044164.058 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-23T17:09:24.177Z,1535044164.177 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-08-23T17:09:24.185Z,1535044164.185 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-08-23T17:09:24.208Z,1535044164.208 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-08-23T17:09:24.213Z,1535044164.213 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-08-23T17:09:24.223Z,1535044164.223 [MassServo](DEBUG): Initializing EZServoServo.
2018-08-23T17:09:24.229Z,1535044164.229 [MassServo](DEBUG): Initializing MassServo.
2018-08-23T17:09:24.251Z,1535044164.251 [RudderServo](DEBUG): Initializing EZServoServo.
2018-08-23T17:09:24.257Z,1535044164.257 [RudderServo](DEBUG): Initializing RudderServo.
2018-08-23T17:09:24.279Z,1535044164.279 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-08-23T17:09:24.285Z,1535044164.285 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-08-23T17:09:24.528Z,1535044164.528 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-23T17:09:24.881Z,1535044164.881 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-23T17:09:25.284Z,1535044165.284 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-23T17:09:25.742Z,1535044165.742 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-23T17:09:26.102Z,1535044166.102 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-23T17:09:26.593Z,1535044166.593 [Aanderaa_O2](INFO): Powering down
2018-08-23T17:09:26.717Z,1535044166.717 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-23T17:09:26.976Z,1535044166.976 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-23T17:09:27.209Z,1535044167.209 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T17:09:27.390Z,1535044167.390 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T17:09:27.466Z,1535044167.466 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T17:09:27.467Z,1535044167.467 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T17:09:27.467Z,1535044167.467 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T17:09:28.411Z,1535044168.411 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-08-23T17:09:28.552Z,1535044168.552 [CTD_Seabird](INFO): Started Seabird LCM interface with command:nohup ./lrauv-framework/onboard/bin/gpctd -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyC6 -b 9600 >& /dev/null &
2018-08-23T17:09:28.554Z,1535044168.554 [CTD_Seabird](INFO): LCM subscribed to channel:seabird_gpctd_t.seabird-gpctd
2018-08-23T17:09:29.024Z,1535044169.024 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-08-23T17:09:29.025Z,1535044169.025 [CTD_Seabird](INFO): Powering down
2018-08-23T17:09:49.083Z,1535044189.083 [NAL9602](INFO): Powering up NAL9602
2018-08-23T17:10:00.283Z,1535044200.283 [NAL9602](INFO): NAL9602 initialized
2018-08-23T17:10:15.884Z,1535044215.884 [NAL9602](INFO): SBD MO Status=0, MOMSN=23451, MT Status=0, MTMSN=0
2018-08-23T17:10:15.884Z,1535044215.884 [NAL9602](INFO): No messages in MT queue
2018-08-23T17:10:17.092Z,1535044217.092 [NAL9602](INFO): GPS fix at 20180823T171001: (41.827341, -83.413068)
2018-08-23T17:10:22.478Z,1535044222.478 [SBIT](IMPORTANT): Beginning Startup BIT
2018-08-23T17:10:22.505Z,1535044222.505 [CBIT](IMPORTANT): Beginning ground fault scan
2018-08-23T17:10:33.827Z,1535044233.827 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007176
CHAN A1 (24V): -0.013158
CHAN A2 (12V): -0.005305
CHAN A3 (5V): -0.008937
CHAN B0 (3.3V): -0.003747
CHAN B1 (3.15aV): -0.002452
CHAN B2 (3.15bV): -0.001761
CHAN B3 (GND): -0.003856
OPEN: 0.012041
Full Scale Calc: 4.765 mA, -1.589 mA
2018-08-23T17:10:49.846Z,1535044249.846 [NAL9602](INFO): Powering down
2018-08-23T17:11:16.045Z,1535044276.045 [SBIT](IMPORTANT): SBIT PASSED
2018-08-23T17:11:16.102Z,1535044276.102 [CommandLine](IMPORTANT): got command configSet list
2018-08-23T17:11:16.102Z,1535044276.102 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-08-23T17:11:16.103Z,1535044276.103 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.loadAtStartup=0 bool;

2018-08-23T17:11:16.103Z,1535044276.103 [CommandLine](IMPORTANT): CTD_Seabird.minSalinityBound=0.1 practical_salinity_unit;

2018-08-23T17:11:16.103Z,1535044276.103 [CommandLine](IMPORTANT): Depth_Keller.offset=-0.56 decibar;

2018-08-23T17:11:16.104Z,1535044276.104 [CommandLine](IMPORTANT): Express linearApproximation mass_concentration_of_chlorophyll_in_sea_water 1.000000 microgram_per_liter;

2018-08-23T17:11:16.104Z,1535044276.104 [CommandLine](IMPORTANT): IBIT.batteryHibernationTimeout=1 minute;

2018-08-23T17:11:16.104Z,1535044276.104 [CommandLine](IMPORTANT): IBIT.batteryMissingStickThreshold=12 count;

2018-08-23T17:11:16.104Z,1535044276.104 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=200 cubic_centimeter;

2018-08-23T17:11:16.104Z,1535044276.104 [CommandLine](IMPORTANT): VerticalControl.massDefault=-1 centimeter;

2018-08-23T17:11:16.462Z,1535044276.462 [MissionManager](IMPORTANT): Started mission Startup
2018-08-23T17:11:16.462Z,1535044276.462 [Startup] Running Loop=1
2018-08-23T17:11:16.462Z,1535044276.462 [Startup](DEBUG): Aggregate::initialize Startup
2018-08-23T17:11:16.463Z,1535044276.463 [Startup:A.GoToSurface] Running Loop=1
2018-08-23T17:11:16.463Z,1535044276.463 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-23T17:11:16.464Z,1535044276.464 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-23T17:11:16.464Z,1535044276.464 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-23T17:11:16.469Z,1535044276.469 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-23T17:11:16.498Z,1535044276.498 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-23T17:11:16.499Z,1535044276.499 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-23T17:11:16.559Z,1535044276.559 [Startup:StartupSatComms] Running Loop=1
2018-08-23T17:11:16.559Z,1535044276.559 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-08-23T17:11:16.559Z,1535044276.559 [Startup:StartupSatComms:A] Running Loop=1
2018-08-23T17:11:16.837Z,1535044276.837 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-08-23T17:11:17.178Z,1535044277.178 [NAL9602](INFO): Powering up
2018-08-23T17:11:28.382Z,1535044288.382 [NAL9602](INFO): NAL9602 initialized
2018-08-23T17:11:54.812Z,1535044314.812 [NAL9602](INFO): SBD MO Status=2, MOMSN=23452, MT Status=2, MTMSN=0
2018-08-23T17:11:54.812Z,1535044314.812 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-23T17:12:07.586Z,1535044327.586 [NAL9602](INFO): SBD MO Status=0, MOMSN=23452, MT Status=0, MTMSN=0
2018-08-23T17:12:07.586Z,1535044327.586 [NAL9602](INFO): No messages in MT queue
2018-08-23T17:12:08.782Z,1535044328.782 [NAL9602](INFO): GPS fix at 20180823T171152: (41.827326, -83.413071)
2018-08-23T17:12:08.844Z,1535044328.844 [Startup:StartupSatComms:A] Stopped
2018-08-23T17:12:08.844Z,1535044328.844 [Startup:StartupSatComms:B] Running Loop=1
2018-08-23T17:12:09.268Z,1535044329.268 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-08-23T17:12:18.432Z,1535044338.432 [NAL9602](INFO): SBD MO Status=1, MOMSN=23453, MT Status=0, MTMSN=0
2018-08-23T17:12:18.489Z,1535044338.489 [NAL9602](INFO): Sent 25 bytes from file Logs/20180823T162341/Courier0034.lzma
2018-08-23T17:12:18.489Z,1535044338.489 [NAL9602](INFO): Packets left to send: 0
2018-08-23T17:12:18.491Z,1535044338.491 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180823T162341/Courier0034.lzma.parts/0000.sbd
2018-08-23T17:12:18.491Z,1535044338.491 [NAL9602](DEBUG): Completed sending Logs/20180823T162341/Courier0034.lzma
2018-08-23T17:12:27.332Z,1535044347.332 [NAL9602](INFO): SBD MO Status=1, MOMSN=23454, MT Status=0, MTMSN=0
2018-08-23T17:12:27.382Z,1535044347.382 [NAL9602](INFO): Sent 215 bytes from file Logs/20180823T170912/Courier0000.lzma
2018-08-23T17:12:27.382Z,1535044347.382 [NAL9602](INFO): Packets left to send: 0
2018-08-23T17:12:27.383Z,1535044347.383 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180823T170912/Courier0000.lzma.parts/0000.sbd
2018-08-23T17:12:27.384Z,1535044347.384 [NAL9602](DEBUG): Completed sending Logs/20180823T170912/Courier0000.lzma
2018-08-23T17:12:41.840Z,1535044361.840 [NAL9602](INFO): SBD MO Status=1, MOMSN=23455, MT Status=0, MTMSN=0
2018-08-23T17:12:41.902Z,1535044361.902 [NAL9602](INFO): Sent 25 bytes from file Logs/20180823T162341/Express0032.lzma
2018-08-23T17:12:41.902Z,1535044361.902 [NAL9602](INFO): Packets left to send: 0
2018-08-23T17:12:41.904Z,1535044361.904 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180823T162341/Express0032.lzma.parts/0000.sbd
2018-08-23T17:12:41.904Z,1535044361.904 [NAL9602](DEBUG): Completed sending Logs/20180823T162341/Express0032.lzma
2018-08-23T17:12:54.380Z,1535044374.380 [NAL9602](INFO): SBD MO Status=1, MOMSN=23456, MT Status=0, MTMSN=0
2018-08-23T17:12:54.429Z,1535044374.429 [NAL9602](INFO): Sent 100 bytes from file Logs/20180823T162341/Express0035.lzma
2018-08-23T17:12:54.429Z,1535044374.429 [NAL9602](INFO): Packets left to send: 0
2018-08-23T17:12:54.431Z,1535044374.431 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180823T162341/Express0035.lzma.parts/0000.sbd
2018-08-23T17:12:54.431Z,1535044374.431 [NAL9602](DEBUG): Completed sending Logs/20180823T162341/Express0035.lzma
2018-08-23T17:13:09.055Z,1535044389.055 [NAL9602](INFO): SBD MO Status=1, MOMSN=23457, MT Status=0, MTMSN=0
2018-08-23T17:13:09.105Z,1535044389.105 [NAL9602](INFO): Sent 332 bytes from file Logs/20180823T170912/Express0001.lzma
2018-08-23T17:13:09.105Z,1535044389.105 [NAL9602](INFO): Packets left to send: 2
2018-08-23T17:13:09.107Z,1535044389.107 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180823T170912/Express0001.lzma.parts/0002.sbd
2018-08-23T17:13:09.173Z,1535044389.173 [Startup:StartupSatComms:B](INFO): Timed out from 2018-08-23T17:12:08.8Z
2018-08-23T17:13:09.173Z,1535044389.173 [Startup:StartupSatComms:B] Stopped
2018-08-23T17:13:09.173Z,1535044389.173 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-08-23T17:13:09.173Z,1535044389.173 [Startup:StartupSatComms] Stopped
2018-08-23T17:13:09.173Z,1535044389.173 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-08-23T17:13:09.174Z,1535044389.174 [Startup](INFO): Completed Startup
2018-08-23T17:13:09.175Z,1535044389.175 [MissionManager](INFO): Startup is completed.
2018-08-23T17:13:09.175Z,1535044389.175 [MissionManager](INFO): Uninitializing Mission Startup
2018-08-23T17:13:09.175Z,1535044389.175 [Startup] Stopped
2018-08-23T17:13:09.175Z,1535044389.175 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-08-23T17:13:09.175Z,1535044389.175 [Startup:A.GoToSurface] Stopped
2018-08-23T17:13:09.175Z,1535044389.175 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-08-23T17:13:11.167Z,1535044391.167 [MissionManager](IMPORTANT): Started mission Default
2018-08-23T17:13:11.167Z,1535044391.167 [Default] Running Loop=1
2018-08-23T17:13:11.167Z,1535044391.167 [Default](DEBUG): Aggregate::initialize Default
2018-08-23T17:13:11.167Z,1535044391.167 [Default:B.GoToSurface] Running Loop=1
2018-08-23T17:13:11.167Z,1535044391.167 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-23T17:13:11.168Z,1535044391.168 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-23T17:13:11.168Z,1535044391.168 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-23T17:13:11.168Z,1535044391.168 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-23T17:13:11.170Z,1535044391.170 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-23T17:13:11.170Z,1535044391.170 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-23T17:13:11.171Z,1535044391.171 [Default:A.Wait] Running Loop=1
2018-08-23T17:13:11.171Z,1535044391.171 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-08-23T17:13:21.820Z,1535044401.820 [NAL9602](INFO): SBD MO Status=1, MOMSN=23458, MT Status=0, MTMSN=0
2018-08-23T17:13:21.869Z,1535044401.869 [NAL9602](INFO): Sent 332 bytes from file Logs/20180823T170912/Express0001.lzma
2018-08-23T17:13:21.869Z,1535044401.869 [NAL9602](INFO): Packets left to send: 1
2018-08-23T17:13:21.870Z,1535044401.870 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180823T170912/Express0001.lzma.parts/0001.sbd
2018-08-23T17:13:24.272Z,1535044404.272 [Default:A.Wait](INFO): Done Waiting.
2018-08-23T17:13:24.272Z,1535044404.272 [Default:A.Wait] Stopped
2018-08-23T17:13:24.273Z,1535044404.273 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T17:13:28.359Z,1535044408.359 [Default:CheckIn] Running Loop=1
2018-08-23T17:13:28.359Z,1535044408.359 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T17:13:28.359Z,1535044408.359 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T17:13:28.496Z,1535044408.496 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-08-23T17:13:29.596Z,1535044409.596 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004796
2018-08-23T17:13:30.021Z,1535044410.021 [NAL9602](INFO): GPS fix at 20180823T171313: (41.827323, -83.413070)
2018-08-23T17:13:30.139Z,1535044410.139 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T17:13:30.139Z,1535044410.139 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T17:13:30.515Z,1535044410.515 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-08-23T17:13:37.314Z,1535044417.314 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20180823T170912/Courier0004.lzma
2018-08-23T17:13:38.112Z,1535044418.112 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0004.lzma.bak
2018-08-23T17:13:38.112Z,1535044418.112 [DataOverHttps](INFO): SBD MOMSN=8438474
2018-08-23T17:13:50.876Z,1535044430.876 [DataOverHttps](INFO): Sending 955 bytes from file Logs/20180823T170912/Express0001.lzma
2018-08-23T17:13:51.700Z,1535044431.700 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0001.lzma.bak
2018-08-23T17:13:51.708Z,1535044431.708 [DataOverHttps](INFO): SBD MOMSN=8438478
2018-08-23T17:14:04.118Z,1535044444.118 [NAL9602](INFO): Powering down
2018-08-23T17:14:04.662Z,1535044444.662 [DataOverHttps](INFO): Sending 93 bytes from file Logs/20180823T170912/Express0005.lzma
2018-08-23T17:14:05.459Z,1535044445.459 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0005.lzma.bak
2018-08-23T17:14:05.460Z,1535044445.460 [DataOverHttps](INFO): SBD MOMSN=8438498
2018-08-23T17:14:08.429Z,1535044448.429 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T17:14:08.429Z,1535044448.429 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T17:14:08.429Z,1535044448.429 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T17:14:26.679Z,1535044466.679 [CommandLine](IMPORTANT): got command configSet list
2018-08-23T17:14:26.681Z,1535044466.681 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-08-23T17:14:26.684Z,1535044466.684 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.loadAtStartup=0 bool;

2018-08-23T17:14:26.688Z,1535044466.688 [CommandLine](IMPORTANT): CTD_Seabird.minSalinityBound=0.1 practical_salinity_unit;

2018-08-23T17:14:26.705Z,1535044466.705 [CommandLine](IMPORTANT): Depth_Keller.offset=-0.56 decibar;

2018-08-23T17:14:26.706Z,1535044466.706 [CommandLine](IMPORTANT): Express linearApproximation mass_concentration_of_chlorophyll_in_sea_water 1.000000 microgram_per_liter;

2018-08-23T17:14:26.707Z,1535044466.707 [CommandLine](IMPORTANT): IBIT.batteryHibernationTimeout=1 minute;

2018-08-23T17:14:26.708Z,1535044466.708 [CommandLine](IMPORTANT): IBIT.batteryMissingStickThreshold=12 count;

2018-08-23T17:14:26.708Z,1535044466.708 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=200 cubic_centimeter;

2018-08-23T17:14:26.708Z,1535044466.708 [CommandLine](IMPORTANT): VerticalControl.massDefault=-1 centimeter;

2018-08-23T17:14:36.921Z,1535044476.921 [CommandLine](IMPORTANT): got command report touch height_above_sea_floor
2018-08-23T17:14:37.143Z,1535044477.143 [Reporter](INFO): height_above_sea_floor 2.454000 m
2018-08-23T17:14:37.942Z,1535044477.942 [Reporter](INFO): height_above_sea_floor 2.445000 m
2018-08-23T17:14:39.118Z,1535044479.118 [Reporter](INFO): height_above_sea_floor 2.454000 m
2018-08-23T17:14:39.941Z,1535044479.941 [Reporter](INFO): height_above_sea_floor 2.458000 m
2018-08-23T17:14:47.135Z,1535044487.135 [Reporter](INFO): height_above_sea_floor 3.172000 m
2018-08-23T17:14:47.956Z,1535044487.956 [Reporter](INFO): height_above_sea_floor 2.525000 m
2018-08-23T17:14:50.939Z,1535044490.939 [Reporter](INFO): height_above_sea_floor 2.432000 m
2018-08-23T17:14:52.325Z,1535044492.325 [Reporter](INFO): height_above_sea_floor 2.441000 m
2018-08-23T17:15:02.020Z,1535044502.020 [Reporter](INFO): height_above_sea_floor 2.463000 m
2018-08-23T17:15:02.091Z,1535044502.091 [CommandLine](IMPORTANT): got command report clear
2018-08-23T17:15:04.983Z,1535044504.983 [CommandLine](IMPORTANT): got command get depth
2018-08-23T17:15:04.983Z,1535044504.983 [CommandLine](IMPORTANT): depth 0.017645 m
2018-08-23T17:15:11.985Z,1535044511.985 [CommandLine](IMPORTANT): got command get Depth_Keller.offset
2018-08-23T17:15:11.986Z,1535044511.986 [CommandLine](IMPORTANT): Depth_Keller.offset -0.560000 db
2018-08-23T17:18:52.883Z,1535044732.883 [BPC1](ERROR): Bank A: No match for stick 5 serial number:1717 in the onboard configuration file.
2018-08-23T17:18:52.884Z,1535044732.884 [BPC1](ERROR): Failed to parse Bank A battery data
2018-08-23T17:19:08.941Z,1535044748.941 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T17:19:08.942Z,1535044748.942 [Default:CheckIn:C.Wait] Stopped
2018-08-23T17:19:08.942Z,1535044748.942 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T17:19:08.942Z,1535044748.942 [Default:CheckIn:D] Running Loop=1
2018-08-23T17:19:09.362Z,1535044749.362 [Default:CheckIn:D] Stopped
2018-08-23T17:19:09.362Z,1535044749.362 [Default:CheckIn:E] Running Loop=1
2018-08-23T17:19:09.699Z,1535044749.699 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.969812 min 
2018-08-23T17:19:09.702Z,1535044749.702 [Default:CheckIn:E] Stopped
2018-08-23T17:19:09.702Z,1535044749.702 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T17:19:09.702Z,1535044749.702 [Default:CheckIn] Stopped
2018-08-23T17:19:09.702Z,1535044749.702 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T17:19:09.702Z,1535044749.702 [Default:CheckIn](INFO): Running loop #2
2018-08-23T17:19:09.702Z,1535044749.702 [Default:CheckIn] Running Loop=2
2018-08-23T17:19:09.703Z,1535044749.703 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T17:19:09.703Z,1535044749.703 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T17:19:14.011Z,1535044754.011 [NAL9602](INFO): Powering up
2018-08-23T17:19:24.910Z,1535044764.910 [NAL9602](INFO): NAL9602 initialized
2018-08-23T17:19:37.712Z,1535044777.712 [NAL9602](INFO): SBD MO Status=0, MOMSN=23459, MT Status=0, MTMSN=0
2018-08-23T17:19:37.712Z,1535044777.712 [NAL9602](INFO): No messages in MT queue
2018-08-23T17:19:47.337Z,1535044787.337 [NAL9602](INFO): GPS fix at 20180823T171930: (41.827316, -83.413083)
2018-08-23T17:19:47.424Z,1535044787.424 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T17:19:47.424Z,1535044787.424 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T17:19:53.993Z,1535044793.993 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20180823T170912/Courier0007.lzma
2018-08-23T17:19:54.791Z,1535044794.791 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0007.lzma.bak
2018-08-23T17:19:54.792Z,1535044794.792 [DataOverHttps](INFO): SBD MOMSN=8438515
2018-08-23T17:20:08.710Z,1535044808.710 [DataOverHttps](INFO): Sending 637 bytes from file Logs/20180823T170912/Express0008.lzma
2018-08-23T17:20:09.483Z,1535044809.483 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0008.lzma.bak
2018-08-23T17:20:09.484Z,1535044809.484 [DataOverHttps](INFO): SBD MOMSN=8438518
2018-08-23T17:20:11.196Z,1535044811.196 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T17:20:11.196Z,1535044811.196 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T17:20:11.196Z,1535044811.196 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T17:20:19.390Z,1535044819.390 [NAL9602](INFO): Powering down
2018-08-23T17:22:17.399Z,1535044937.399 [DataOverHttps](IMPORTANT): SBD MTMSN=20180823T172201
2018-08-23T17:22:22.308Z,1535044942.308 [DataOverHttps](INFO): Received command:configSet VerticalControl.buoyancyNeutral 380 cc persist
2018-08-23T17:22:22.926Z,1535044942.926 [CommandLine](IMPORTANT): got command configSet VerticalControl.buoyancyNeutral 380.000000 cubic_centimeter persist
2018-08-23T17:22:23.433Z,1535044943.433 [DataOverHttps](IMPORTANT): SBD MTMSN=20180823T172206
2018-08-23T17:22:28.682Z,1535044948.682 [DataOverHttps](INFO): Received command:ibit
2018-08-23T17:22:28.743Z,1535044948.743 [CommandLine](IMPORTANT): got command ibit
2018-08-23T17:22:28.797Z,1535044948.797 [IBIT](IMPORTANT): Beginning Initiated BIT
2018-08-23T17:22:28.797Z,1535044948.797 [IBIT](IMPORTANT): Beginning control surface checks.
2018-08-23T17:22:28.805Z,1535044948.805 [CBIT](IMPORTANT): Beginning ground fault scan
2018-08-23T17:22:29.082Z,1535044949.082 [NAL9602](INFO): Powering up
2018-08-23T17:22:37.539Z,1535044957.539 [CommandLine](IMPORTANT): got command report touch height_above_sea_floor
2018-08-23T17:22:39.661Z,1535044959.661 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002022
CHAN A1 (24V): -0.013679
CHAN A2 (12V): -0.005685
CHAN A3 (5V): -0.007804
CHAN B0 (3.3V): -0.003105
CHAN B1 (3.15aV): -0.002277
CHAN B2 (3.15bV): -0.002194
CHAN B3 (GND): -0.003756
OPEN: 0.011819
Full Scale Calc: 4.765 mA, -1.589 mA
2018-08-23T17:22:40.286Z,1535044960.286 [NAL9602](INFO): NAL9602 initialized
2018-08-23T17:22:40.365Z,1535044960.365 [Reporter](INFO): height_above_sea_floor 0.954372 m
2018-08-23T17:22:40.763Z,1535044960.763 [Reporter](INFO): height_above_sea_floor 0.940018 m
2018-08-23T17:22:41.167Z,1535044961.167 [Reporter](INFO): height_above_sea_floor 0.960652 m
2018-08-23T17:22:41.674Z,1535044961.674 [Reporter](INFO): height_above_sea_floor 0.948989 m
2018-08-23T17:22:42.017Z,1535044962.017 [Reporter](INFO): height_above_sea_floor 0.955269 m
2018-08-23T17:22:42.348Z,1535044962.348 [Reporter](INFO): height_above_sea_floor 0.943158 m
2018-08-23T17:22:42.742Z,1535044962.742 [Reporter](INFO): height_above_sea_floor 0.945401 m
2018-08-23T17:22:43.148Z,1535044963.148 [Reporter](INFO): height_above_sea_floor 0.948989 m
2018-08-23T17:22:43.653Z,1535044963.653 [Reporter](INFO): height_above_sea_floor 0.944503 m
2018-08-23T17:22:43.955Z,1535044963.955 [Reporter](INFO): height_above_sea_floor 0.953026 m
2018-08-23T17:22:44.358Z,1535044964.358 [Reporter](INFO): height_above_sea_floor 0.945849 m
2018-08-23T17:22:44.740Z,1535044964.740 [Reporter](INFO): height_above_sea_floor 2.569000 m
2018-08-23T17:22:46.103Z,1535044966.103 [Reporter](INFO): height_above_sea_floor 2.541000 m
2018-08-23T17:22:47.712Z,1535044967.712 [Reporter](INFO): height_above_sea_floor 2.476000 m
2018-08-23T17:22:49.215Z,1535044969.215 [Reporter](INFO): height_above_sea_floor 2.467000 m
2018-08-23T17:22:59.202Z,1535044979.202 [Reporter](INFO): height_above_sea_floor 0.952129 m
2018-08-23T17:22:59.691Z,1535044979.691 [Reporter](INFO): height_above_sea_floor 0.944055 m
2018-08-23T17:23:00.063Z,1535044980.063 [Reporter](INFO): height_above_sea_floor 0.946746 m
2018-08-23T17:23:00.389Z,1535044980.389 [Reporter](INFO): height_above_sea_floor 0.948540 m
2018-08-23T17:23:00.782Z,1535044980.782 [Reporter](INFO): height_above_sea_floor 0.935084 m
2018-08-23T17:23:01.343Z,1535044981.343 [Reporter](INFO): height_above_sea_floor 0.944503 m
2018-08-23T17:23:01.735Z,1535044981.735 [Reporter](INFO): height_above_sea_floor 0.940466 m
2018-08-23T17:23:01.880Z,1535044981.880 [NAL9602](INFO): SBD MO Status=2, MOMSN=23460, MT Status=2, MTMSN=0
2018-08-23T17:23:01.880Z,1535044981.880 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-23T17:23:02.059Z,1535044982.059 [Reporter](INFO): height_above_sea_floor 0.940915 m
2018-08-23T17:23:02.472Z,1535044982.472 [Reporter](INFO): height_above_sea_floor 0.946746 m
2018-08-23T17:23:02.847Z,1535044982.847 [Reporter](INFO): height_above_sea_floor 0.944952 m
2018-08-23T17:23:03.235Z,1535044983.235 [Reporter](INFO): height_above_sea_floor 0.956614 m
2018-08-23T17:23:03.723Z,1535044983.723 [Reporter](INFO): height_above_sea_floor 0.941363 m
2018-08-23T17:23:04.115Z,1535044984.115 [Reporter](INFO): height_above_sea_floor 0.936878 m
2018-08-23T17:23:04.400Z,1535044984.400 [Reporter](INFO): height_above_sea_floor 0.938672 m
2018-08-23T17:23:04.797Z,1535044984.797 [Reporter](INFO): height_above_sea_floor 0.957960 m
2018-08-23T17:23:05.146Z,1535044985.146 [Reporter](INFO): height_above_sea_floor 0.942709 m
2018-08-23T17:23:05.682Z,1535044985.682 [Reporter](INFO): height_above_sea_floor 0.939569 m
2018-08-23T17:23:05.933Z,1535044985.933 [Reporter](INFO): height_above_sea_floor 0.941812 m
2018-08-23T17:23:06.355Z,1535044986.355 [Reporter](INFO): height_above_sea_floor 0.947643 m
2018-08-23T17:23:06.779Z,1535044986.779 [Reporter](INFO): height_above_sea_floor 0.944503 m
2018-08-23T17:23:07.155Z,1535044987.155 [Reporter](INFO): height_above_sea_floor 0.944503 m
2018-08-23T17:23:07.683Z,1535044987.683 [Reporter](INFO): height_above_sea_floor 0.948092 m
2018-08-23T17:23:07.947Z,1535044987.947 [Reporter](INFO): height_above_sea_floor 0.947643 m
2018-08-23T17:23:08.358Z,1535044988.358 [Reporter](INFO): height_above_sea_floor 0.941363 m
2018-08-23T17:23:08.760Z,1535044988.760 [Reporter](INFO): height_above_sea_floor 0.948540 m
2018-08-23T17:23:09.140Z,1535044989.140 [Reporter](INFO): height_above_sea_floor 0.938224 m
2018-08-23T17:23:09.640Z,1535044989.640 [Reporter](INFO): height_above_sea_floor 0.939121 m
2018-08-23T17:23:10.003Z,1535044990.003 [Reporter](INFO): height_above_sea_floor 3.175000 m
2018-08-23T17:23:11.141Z,1535044991.141 [Reporter](INFO): height_above_sea_floor 2.467000 m
2018-08-23T17:23:19.089Z,1535044999.089 [NAL9602](INFO): SBD MO Status=2, MOMSN=23460, MT Status=2, MTMSN=0
2018-08-23T17:23:19.090Z,1535044999.090 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-23T17:23:21.152Z,1535045001.152 [Reporter](INFO): height_above_sea_floor 0.935981 m
2018-08-23T17:23:21.578Z,1535045001.578 [Reporter](INFO): height_above_sea_floor 0.948092 m
2018-08-23T17:23:21.959Z,1535045001.959 [Reporter](INFO): height_above_sea_floor 0.949886 m
2018-08-23T17:23:22.342Z,1535045002.342 [Reporter](INFO): height_above_sea_floor 0.938672 m
2018-08-23T17:23:22.779Z,1535045002.779 [Reporter](INFO): height_above_sea_floor 0.939121 m
2018-08-23T17:23:23.156Z,1535045003.156 [Reporter](INFO): height_above_sea_floor 0.938672 m
2018-08-23T17:23:23.733Z,1535045003.733 [Reporter](INFO): height_above_sea_floor 0.957063 m
2018-08-23T17:23:23.942Z,1535045003.942 [Reporter](INFO): height_above_sea_floor 0.938224 m
2018-08-23T17:23:24.349Z,1535045004.349 [Reporter](INFO): height_above_sea_floor 0.952578 m
2018-08-23T17:23:28.297Z,1535045008.297 [Reporter](INFO): height_above_sea_floor 0.940915 m
2018-08-23T17:23:28.430Z,1535045008.430 [Reporter](INFO): height_above_sea_floor 0.948989 m
2018-08-23T17:23:28.801Z,1535045008.801 [Reporter](INFO): height_above_sea_floor 0.944055 m
2018-08-23T17:23:29.186Z,1535045009.186 [Reporter](INFO): height_above_sea_floor 0.939569 m
2018-08-23T17:23:29.746Z,1535045009.746 [Reporter](INFO): height_above_sea_floor 0.943158 m
2018-08-23T17:23:30.129Z,1535045010.129 [Reporter](INFO): height_above_sea_floor 0.949438 m
2018-08-23T17:23:30.510Z,1535045010.510 [Reporter](INFO): height_above_sea_floor 0.943158 m
2018-08-23T17:23:30.893Z,1535045010.893 [Reporter](INFO): height_above_sea_floor 0.940466 m
2018-08-23T17:23:31.330Z,1535045011.330 [Reporter](INFO): height_above_sea_floor 2.467000 m
2018-08-23T17:23:36.730Z,1535045016.730 [NAL9602](INFO): SBD MO Status=2, MOMSN=23460, MT Status=2, MTMSN=0
2018-08-23T17:23:36.731Z,1535045016.731 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-23T17:23:41.185Z,1535045021.185 [Reporter](INFO): height_above_sea_floor 0.944503 m
2018-08-23T17:23:41.623Z,1535045021.623 [Reporter](INFO): height_above_sea_floor 0.941812 m
2018-08-23T17:23:42.021Z,1535045022.021 [Reporter](INFO): height_above_sea_floor 0.941363 m
2018-08-23T17:23:42.395Z,1535045022.395 [Reporter](INFO): height_above_sea_floor 0.950335 m
2018-08-23T17:23:42.816Z,1535045022.816 [Reporter](INFO): height_above_sea_floor 0.944055 m
2018-08-23T17:23:43.172Z,1535045023.172 [Reporter](INFO): height_above_sea_floor 0.951680 m
2018-08-23T17:23:43.678Z,1535045023.678 [Reporter](INFO): height_above_sea_floor 0.935084 m
2018-08-23T17:23:43.982Z,1535045023.982 [Reporter](INFO): height_above_sea_floor 0.943158 m
2018-08-23T17:23:44.389Z,1535045024.389 [Reporter](INFO): height_above_sea_floor 0.942261 m
2018-08-23T17:23:44.833Z,1535045024.833 [Reporter](INFO): height_above_sea_floor 0.940018 m
2018-08-23T17:23:45.224Z,1535045025.224 [Reporter](INFO): height_above_sea_floor 0.948092 m
2018-08-23T17:23:45.657Z,1535045025.657 [Reporter](INFO): height_above_sea_floor 0.930149 m
2018-08-23T17:23:45.995Z,1535045025.995 [Reporter](INFO): height_above_sea_floor 0.948989 m
2018-08-23T17:23:46.371Z,1535045026.371 [Reporter](INFO): height_above_sea_floor 0.938224 m
2018-08-23T17:23:46.816Z,1535045026.816 [Reporter](INFO): height_above_sea_floor 0.938224 m
2018-08-23T17:23:47.189Z,1535045027.189 [Reporter](INFO): height_above_sea_floor 3.172000 m
2018-08-23T17:23:58.017Z,1535045038.017 [Reporter](INFO): height_above_sea_floor 0.940466 m
2018-08-23T17:23:58.313Z,1535045038.313 [NAL9602](INFO): SBD MO Status=2, MOMSN=23460, MT Status=2, MTMSN=0
2018-08-23T17:23:58.313Z,1535045038.313 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-23T17:23:58.435Z,1535045038.435 [Reporter](INFO): height_above_sea_floor 0.934635 m
2018-08-23T17:23:58.833Z,1535045038.833 [Reporter](INFO): height_above_sea_floor 0.934635 m
2018-08-23T17:23:59.196Z,1535045039.196 [Reporter](INFO): height_above_sea_floor 0.948092 m
2018-08-23T17:23:59.616Z,1535045039.616 [Reporter](INFO): height_above_sea_floor 0.936429 m
2018-08-23T17:23:59.988Z,1535045039.988 [Reporter](INFO): height_above_sea_floor 0.955717 m
2018-08-23T17:24:00.399Z,1535045040.399 [Reporter](INFO): height_above_sea_floor 0.945849 m
2018-08-23T17:24:00.808Z,1535045040.808 [Reporter](INFO): height_above_sea_floor 0.940018 m
2018-08-23T17:24:01.174Z,1535045041.174 [Reporter](INFO): height_above_sea_floor 0.942261 m
2018-08-23T17:24:01.703Z,1535045041.703 [Reporter](INFO): height_above_sea_floor 0.936878 m
2018-08-23T17:24:01.997Z,1535045041.997 [Reporter](INFO): height_above_sea_floor 0.958857 m
2018-08-23T17:24:02.378Z,1535045042.378 [Reporter](INFO): height_above_sea_floor 0.947643 m
2018-08-23T17:24:02.839Z,1535045042.839 [Reporter](INFO): height_above_sea_floor 0.948092 m
2018-08-23T17:24:03.181Z,1535045043.181 [Reporter](INFO): height_above_sea_floor 0.943606 m
2018-08-23T17:24:03.581Z,1535045043.581 [Reporter](INFO): height_above_sea_floor 0.946746 m
2018-08-23T17:24:03.992Z,1535045043.992 [Reporter](INFO): height_above_sea_floor 0.946746 m
2018-08-23T17:24:04.386Z,1535045044.386 [Reporter](INFO): height_above_sea_floor 0.941812 m
2018-08-23T17:24:04.824Z,1535045044.824 [Reporter](INFO): height_above_sea_floor 0.933738 m
2018-08-23T17:24:05.226Z,1535045045.226 [Reporter](INFO): height_above_sea_floor 0.938672 m
2018-08-23T17:24:05.655Z,1535045045.655 [Reporter](INFO): height_above_sea_floor 0.941812 m
2018-08-23T17:24:06.010Z,1535045046.010 [Reporter](INFO): height_above_sea_floor 0.946746 m
2018-08-23T17:24:06.384Z,1535045046.384 [Reporter](INFO): height_above_sea_floor 0.946746 m
2018-08-23T17:24:06.819Z,1535045046.819 [Reporter](INFO): height_above_sea_floor 0.945401 m
2018-08-23T17:24:07.177Z,1535045047.177 [Reporter](INFO): height_above_sea_floor 0.935532 m
2018-08-23T17:24:07.597Z,1535045047.597 [Reporter](INFO): height_above_sea_floor 0.932841 m
2018-08-23T17:24:07.979Z,1535045047.979 [Reporter](INFO): height_above_sea_floor 0.956166 m
2018-08-23T17:24:08.408Z,1535045048.408 [Reporter](INFO): height_above_sea_floor 0.948989 m
2018-08-23T17:24:08.823Z,1535045048.823 [Reporter](INFO): height_above_sea_floor 0.936878 m
2018-08-23T17:24:09.221Z,1535045049.221 [Reporter](INFO): height_above_sea_floor 0.947195 m
2018-08-23T17:24:09.724Z,1535045049.724 [Reporter](INFO): height_above_sea_floor 0.943158 m
2018-08-23T17:24:10.029Z,1535045050.029 [Reporter](INFO): height_above_sea_floor 0.934635 m
2018-08-23T17:24:10.418Z,1535045050.418 [Reporter](INFO): height_above_sea_floor 0.944503 m
2018-08-23T17:24:10.824Z,1535045050.824 [Reporter](INFO): height_above_sea_floor 0.943606 m
2018-08-23T17:24:11.225Z,1535045051.225 [Reporter](INFO): height_above_sea_floor 0.940018 m
2018-08-23T17:24:11.634Z,1535045051.634 [Reporter](INFO): height_above_sea_floor 0.943158 m
2018-08-23T17:24:11.999Z,1535045051.999 [Reporter](INFO): height_above_sea_floor 0.958857 m
2018-08-23T17:24:12.398Z,1535045052.398 [Reporter](INFO): height_above_sea_floor 0.938224 m
2018-08-23T17:24:12.854Z,1535045052.854 [Reporter](INFO): height_above_sea_floor 0.940915 m
2018-08-23T17:24:13.232Z,1535045053.232 [Reporter](INFO): height_above_sea_floor 0.948540 m
2018-08-23T17:24:13.698Z,1535045053.698 [Reporter](INFO): height_above_sea_floor 0.948092 m
2018-08-23T17:24:14.039Z,1535045054.039 [Reporter](INFO): height_above_sea_floor 0.944503 m
2018-08-23T17:24:14.407Z,1535045054.407 [Reporter](INFO): height_above_sea_floor 0.944055 m
2018-08-23T17:24:14.822Z,1535045054.822 [Reporter](INFO): height_above_sea_floor 0.944055 m
2018-08-23T17:24:15.218Z,1535045055.218 [Reporter](INFO): height_above_sea_floor 0.948540 m
2018-08-23T17:24:15.628Z,1535045055.628 [Reporter](INFO): height_above_sea_floor 0.955269 m
2018-08-23T17:24:16.015Z,1535045056.015 [Reporter](INFO): height_above_sea_floor 2.538000 m
2018-08-23T17:24:17.225Z,1535045057.225 [Reporter](INFO): height_above_sea_floor 2.544000 m
2018-08-23T17:24:18.426Z,1535045058.426 [Reporter](INFO): height_above_sea_floor 2.529000 m
2018-08-23T17:24:19.515Z,1535045059.515 [NAL9602](INFO): SBD MO Status=0, MOMSN=23460, MT Status=0, MTMSN=0
2018-08-23T17:24:19.515Z,1535045059.515 [NAL9602](INFO): No messages in MT queue
2018-08-23T17:24:19.636Z,1535045059.636 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2018-08-23T17:24:20.003Z,1535045060.003 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2018-08-23T17:24:20.425Z,1535045060.425 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2018-08-23T17:24:20.425Z,1535045060.425 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2018-08-23T17:24:20.426Z,1535045060.426 [IBIT](IMPORTANT): Pressure:11.757033 PSI
2018-08-23T17:24:20.426Z,1535045060.426 [IBIT](IMPORTANT): Humidity:19.350506 %
2018-08-23T17:24:20.723Z,1535045060.723 [NAL9602](INFO): GPS fix at 20180823T172403: (41.827315, -83.413086)
2018-08-23T17:24:20.882Z,1535045060.882 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2018-08-23T17:24:20.882Z,1535045060.882 [IBIT](IMPORTANT): buoyancyNeutral: 380.000000 cc
2018-08-23T17:24:20.883Z,1535045060.883 [IBIT](IMPORTANT): massDefault: -1.000000 cm
2018-08-23T17:24:20.883Z,1535045060.883 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2018-08-23T17:24:20.883Z,1535045060.883 [IBIT](IMPORTANT): abortDepth: 255.000000 m
2018-08-23T17:24:20.883Z,1535045060.883 [IBIT](IMPORTANT): IBIT FAILED
2018-08-23T17:24:22.040Z,1535045062.040 [Reporter](INFO): height_above_sea_floor 2.541000 m
2018-08-23T17:24:24.392Z,1535045064.392 [Reporter](INFO): height_above_sea_floor 2.564000 m
2018-08-23T17:24:28.403Z,1535045068.403 [Reporter](INFO): height_above_sea_floor 2.534000 m
2018-08-23T17:24:34.947Z,1535045074.947 [Reporter](INFO): height_above_sea_floor 2.569000 m
2018-08-23T17:24:36.126Z,1535045076.126 [Reporter](INFO): height_above_sea_floor 2.529000 m
2018-08-23T17:24:36.905Z,1535045076.905 [Reporter](INFO): height_above_sea_floor 2.525000 m
2018-08-23T17:24:39.324Z,1535045079.324 [Reporter](INFO): height_above_sea_floor 2.525000 m
2018-08-23T17:24:42.957Z,1535045082.957 [Reporter](INFO): height_above_sea_floor 2.480000 m
2018-08-23T17:24:52.827Z,1535045092.827 [NAL9602](INFO): Powering down
2018-08-23T17:24:53.288Z,1535045093.288 [Reporter](INFO): height_above_sea_floor 2.591000 m
2018-08-23T17:25:03.377Z,1535045103.377 [Reporter](INFO): height_above_sea_floor 0.946597 m
2018-08-23T17:25:03.835Z,1535045103.835 [Reporter](INFO): height_above_sea_floor 0.939420 m
2018-08-23T17:25:04.116Z,1535045104.116 [Reporter](INFO): height_above_sea_floor 0.955119 m
2018-08-23T17:25:04.567Z,1535045104.567 [Reporter](INFO): height_above_sea_floor 0.946597 m
2018-08-23T17:25:04.935Z,1535045104.935 [Reporter](INFO): height_above_sea_floor 0.947494 m
2018-08-23T17:25:05.281Z,1535045105.281 [Reporter](INFO): height_above_sea_floor 0.936728 m
2018-08-23T17:25:05.758Z,1535045105.758 [Reporter](INFO): height_above_sea_floor 0.937625 m
2018-08-23T17:25:06.151Z,1535045106.151 [Reporter](INFO): height_above_sea_floor 0.932243 m
2018-08-23T17:25:06.505Z,1535045106.505 [Reporter](INFO): height_above_sea_floor 0.963642 m
2018-08-23T17:25:06.899Z,1535045106.899 [Reporter](INFO): height_above_sea_floor 0.935383 m
2018-08-23T17:25:07.301Z,1535045107.301 [Reporter](INFO): height_above_sea_floor 0.939868 m
2018-08-23T17:25:07.736Z,1535045107.736 [Reporter](INFO): height_above_sea_floor 0.932243 m
2018-08-23T17:25:08.122Z,1535045108.122 [Reporter](INFO): height_above_sea_floor 0.957362 m
2018-08-23T17:25:08.485Z,1535045108.485 [Reporter](INFO): height_above_sea_floor 0.958708 m
2018-08-23T17:25:08.927Z,1535045108.927 [Reporter](INFO): height_above_sea_floor 0.943457 m
2018-08-23T17:25:09.381Z,1535045109.381 [Reporter](INFO): height_above_sea_floor 0.949737 m
2018-08-23T17:25:09.692Z,1535045109.692 [Reporter](INFO): height_above_sea_floor 0.941214 m
2018-08-23T17:25:10.121Z,1535045110.121 [Reporter](INFO): height_above_sea_floor 0.949737 m
2018-08-23T17:25:10.385Z,1535045110.385 [CommandLine](IMPORTANT): got command report clear
2018-08-23T17:25:11.695Z,1535045111.695 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T17:25:11.696Z,1535045111.696 [Default:CheckIn:C.Wait] Stopped
2018-08-23T17:25:11.696Z,1535045111.696 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T17:25:11.696Z,1535045111.696 [Default:CheckIn:D] Running Loop=1
2018-08-23T17:25:12.064Z,1535045112.064 [Default:CheckIn:D] Stopped
2018-08-23T17:25:12.064Z,1535045112.064 [Default:CheckIn:E] Running Loop=1
2018-08-23T17:25:12.476Z,1535045112.476 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.014939 min 
2018-08-23T17:25:12.476Z,1535045112.476 [Default:CheckIn:E] Stopped
2018-08-23T17:25:12.476Z,1535045112.476 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T17:25:12.476Z,1535045112.476 [Default:CheckIn] Stopped
2018-08-23T17:25:12.501Z,1535045112.501 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T17:25:12.501Z,1535045112.501 [Default:CheckIn](INFO): Running loop #3
2018-08-23T17:25:12.501Z,1535045112.501 [Default:CheckIn] Running Loop=3
2018-08-23T17:25:12.501Z,1535045112.501 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T17:25:12.501Z,1535045112.501 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T17:25:13.214Z,1535045113.214 [NAL9602](INFO): Powering up
2018-08-23T17:25:21.272Z,1535045121.272 [CommandLine](IMPORTANT): got command ibit
2018-08-23T17:25:21.335Z,1535045121.335 [IBIT](IMPORTANT): Beginning Initiated BIT
2018-08-23T17:25:21.335Z,1535045121.335 [IBIT](IMPORTANT): Beginning control surface checks.
2018-08-23T17:25:21.350Z,1535045121.350 [CBIT](IMPORTANT): Beginning ground fault scan
2018-08-23T17:25:24.014Z,1535045124.014 [NAL9602](INFO): NAL9602 initialized
2018-08-23T17:25:35.702Z,1535045135.702 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007855
CHAN A1 (24V): -0.013223
CHAN A2 (12V): -0.005841
CHAN A3 (5V): -0.006944
CHAN B0 (3.3V): -0.006551
CHAN B1 (3.15aV): -0.002305
CHAN B2 (3.15bV): -0.001915
CHAN B3 (GND): -0.003331
OPEN: 0.012101
Full Scale Calc: 4.765 mA, -1.589 mA
2018-08-23T17:25:41.964Z,1535045141.964 [NAL9602](INFO): SBD MO Status=0, MOMSN=23461, MT Status=0, MTMSN=0
2018-08-23T17:25:41.964Z,1535045141.964 [NAL9602](INFO): No messages in MT queue
2018-08-23T17:25:47.970Z,1535045147.970 [NAL9602](INFO): GPS fix at 20180823T172530: (41.827304, -83.413081)
2018-08-23T17:25:50.768Z,1535045150.768 [NAL9602](INFO): GPS fix at 20180823T172533: (41.827308, -83.413081)
2018-08-23T17:25:53.567Z,1535045153.567 [NAL9602](INFO): GPS fix at 20180823T172536: (41.827309, -83.413080)
2018-08-23T17:25:56.782Z,1535045156.782 [NAL9602](INFO): GPS fix at 20180823T172539: (41.827312, -83.413080)
2018-08-23T17:25:59.571Z,1535045159.571 [NAL9602](INFO): GPS fix at 20180823T172542: (41.827314, -83.413078)
2018-08-23T17:26:02.796Z,1535045162.796 [NAL9602](INFO): GPS fix at 20180823T172545: (41.827313, -83.413077)
2018-08-23T17:26:05.578Z,1535045165.578 [NAL9602](INFO): GPS fix at 20180823T172548: (41.827311, -83.413075)
2018-08-23T17:26:07.260Z,1535045167.260 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 3
Latitude: 41.827312 Longitude: -83.413078
2018-08-23T17:26:07.653Z,1535045167.653 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2018-08-23T17:26:08.068Z,1535045168.068 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2018-08-23T17:26:08.068Z,1535045168.068 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2018-08-23T17:26:08.068Z,1535045168.068 [IBIT](IMPORTANT): Pressure:11.757033 PSI
2018-08-23T17:26:08.089Z,1535045168.089 [IBIT](IMPORTANT): Humidity:19.374924 %
2018-08-23T17:26:08.467Z,1535045168.467 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2018-08-23T17:26:08.468Z,1535045168.468 [IBIT](IMPORTANT): buoyancyNeutral: 380.000000 cc
2018-08-23T17:26:08.468Z,1535045168.468 [IBIT](IMPORTANT): massDefault: -1.000000 cm
2018-08-23T17:26:08.468Z,1535045168.468 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2018-08-23T17:26:08.477Z,1535045168.477 [IBIT](IMPORTANT): abortDepth: 255.000000 m
2018-08-23T17:26:08.477Z,1535045168.477 [IBIT](IMPORTANT): IBIT PASSED
2018-08-23T17:26:08.766Z,1535045168.766 [NAL9602](INFO): GPS fix at 20180823T172551: (41.827310, -83.413075)
2018-08-23T17:26:08.972Z,1535045168.972 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T17:26:08.972Z,1535045168.972 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T17:26:16.234Z,1535045176.234 [DataOverHttps](INFO): Sending 65 bytes from file Logs/20180823T170912/Courier0010.lzma
2018-08-23T17:26:17.032Z,1535045177.032 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0010.lzma.bak
2018-08-23T17:26:17.032Z,1535045177.032 [DataOverHttps](INFO): SBD MOMSN=8438543
2018-08-23T17:26:32.134Z,1535045192.134 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180823T170912/Courier0013.lzma
2018-08-23T17:26:32.934Z,1535045192.934 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0013.lzma.bak
2018-08-23T17:26:32.934Z,1535045192.934 [DataOverHttps](INFO): SBD MOMSN=8438546
2018-08-23T17:26:40.899Z,1535045200.899 [NAL9602](INFO): Powering down
2018-08-23T17:26:45.030Z,1535045205.030 [DataOverHttps](INFO): Sending 1001 bytes from file Logs/20180823T170912/Express0011.lzma
2018-08-23T17:26:45.809Z,1535045205.809 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0011.lzma.bak
2018-08-23T17:26:45.809Z,1535045205.809 [DataOverHttps](INFO): SBD MOMSN=8438548
2018-08-23T17:26:58.944Z,1535045218.944 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20180823T170912/Express0014.lzma
2018-08-23T17:26:59.739Z,1535045219.739 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0014.lzma.bak
2018-08-23T17:26:59.739Z,1535045219.739 [DataOverHttps](INFO): SBD MOMSN=8438590
2018-08-23T17:27:02.254Z,1535045222.254 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T17:27:02.254Z,1535045222.254 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T17:27:02.255Z,1535045222.255 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T17:30:07.860Z,1535045407.860 [BPC1](ERROR): Bank A: No match for stick 2 serial number:1717 in the onboard configuration file.
2018-08-23T17:30:07.861Z,1535045407.861 [BPC1](ERROR): Failed to parse Bank A battery data
2018-08-23T17:30:23.814Z,1535045423.814 [BPC1](FAULT): Failed to receive data from all sticks prior to timeout. Missing data from 31 sticks.
2018-08-23T17:30:23.814Z,1535045423.814 [BPC1] Data Fault, FailCount= 1
2018-08-23T17:30:23.814Z,1535045423.814 [BPC1](ERROR): Data Fault
2018-08-23T17:30:23.840Z,1535045423.840 [CBIT](ERROR): Data Fault in component: BPC1
2018-08-23T17:30:25.062Z,1535045425.062 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-23T17:30:25.063Z,1535045425.063 [BPC1] No Fault, FailCount= 1
2018-08-23T17:32:02.533Z,1535045522.533 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T17:32:02.534Z,1535045522.534 [Default:CheckIn:C.Wait] Stopped
2018-08-23T17:32:02.534Z,1535045522.534 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T17:32:02.534Z,1535045522.534 [Default:CheckIn:D] Running Loop=1
2018-08-23T17:32:02.842Z,1535045522.842 [Default:CheckIn:D] Stopped
2018-08-23T17:32:02.842Z,1535045522.842 [Default:CheckIn:E] Running Loop=1
2018-08-23T17:32:03.251Z,1535045523.251 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.861251 min 
2018-08-23T17:32:03.251Z,1535045523.251 [Default:CheckIn:E] Stopped
2018-08-23T17:32:03.251Z,1535045523.251 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T17:32:03.252Z,1535045523.252 [Default:CheckIn] Stopped
2018-08-23T17:32:03.252Z,1535045523.252 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T17:32:03.252Z,1535045523.252 [Default:CheckIn](INFO): Running loop #4
2018-08-23T17:32:03.252Z,1535045523.252 [Default:CheckIn] Running Loop=4
2018-08-23T17:32:03.252Z,1535045523.252 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T17:32:03.252Z,1535045523.252 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T17:32:07.630Z,1535045527.630 [NAL9602](INFO): Powering up
2018-08-23T17:32:18.558Z,1535045538.558 [NAL9602](INFO): NAL9602 initialized
2018-08-23T17:32:45.356Z,1535045565.356 [NAL9602](INFO): SBD MO Status=0, MOMSN=23462, MT Status=0, MTMSN=0
2018-08-23T17:32:45.356Z,1535045565.356 [NAL9602](INFO): No messages in MT queue
2018-08-23T17:32:49.358Z,1535045569.358 [NAL9602](INFO): GPS fix at 20180823T173231: (41.827328, -83.413065)
2018-08-23T17:32:49.522Z,1535045569.522 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T17:32:49.522Z,1535045569.522 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T17:32:55.640Z,1535045575.640 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20180823T170912/Courier0016.lzma
2018-08-23T17:32:56.438Z,1535045576.438 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0016.lzma.bak
2018-08-23T17:32:56.438Z,1535045576.438 [DataOverHttps](INFO): SBD MOMSN=8438593
2018-08-23T17:33:12.340Z,1535045592.340 [DataOverHttps](INFO): Sending 211 bytes from file Logs/20180823T170912/Express0017.lzma
2018-08-23T17:33:13.123Z,1535045593.123 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0017.lzma.bak
2018-08-23T17:33:13.124Z,1535045593.124 [DataOverHttps](INFO): SBD MOMSN=8438597
2018-08-23T17:33:15.008Z,1535045595.008 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T17:33:15.008Z,1535045595.008 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T17:33:15.008Z,1535045595.008 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T17:33:21.483Z,1535045601.483 [NAL9602](INFO): Powering down
2018-08-23T17:38:15.406Z,1535045895.406 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T17:38:15.406Z,1535045895.406 [Default:CheckIn:C.Wait] Stopped
2018-08-23T17:38:15.406Z,1535045895.406 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T17:38:15.406Z,1535045895.406 [Default:CheckIn:D] Running Loop=1
2018-08-23T17:38:15.808Z,1535045895.808 [Default:CheckIn:D] Stopped
2018-08-23T17:38:15.808Z,1535045895.808 [Default:CheckIn:E] Running Loop=1
2018-08-23T17:38:16.209Z,1535045896.209 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.077342 min 
2018-08-23T17:38:16.209Z,1535045896.209 [Default:CheckIn:E] Stopped
2018-08-23T17:38:16.209Z,1535045896.209 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T17:38:16.210Z,1535045896.210 [Default:CheckIn] Stopped
2018-08-23T17:38:16.210Z,1535045896.210 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T17:38:16.210Z,1535045896.210 [Default:CheckIn](INFO): Running loop #5
2018-08-23T17:38:16.210Z,1535045896.210 [Default:CheckIn] Running Loop=5
2018-08-23T17:38:16.210Z,1535045896.210 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T17:38:16.210Z,1535045896.210 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T17:38:20.558Z,1535045900.558 [NAL9602](INFO): Powering up
2018-08-23T17:38:31.445Z,1535045911.445 [NAL9602](INFO): NAL9602 initialized
2018-08-23T17:38:47.444Z,1535045927.444 [NAL9602](INFO): SBD MO Status=0, MOMSN=23463, MT Status=0, MTMSN=0
2018-08-23T17:38:47.444Z,1535045927.444 [NAL9602](INFO): No messages in MT queue
2018-08-23T17:38:48.650Z,1535045928.650 [NAL9602](INFO): GPS fix at 20180823T173830: (41.827322, -83.413090)
2018-08-23T17:38:48.714Z,1535045928.714 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T17:38:48.714Z,1535045928.714 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T17:38:55.377Z,1535045935.377 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20180823T170912/Courier0019.lzma
2018-08-23T17:38:56.176Z,1535045936.176 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0019.lzma.bak
2018-08-23T17:38:56.176Z,1535045936.176 [DataOverHttps](INFO): SBD MOMSN=8438602
2018-08-23T17:39:12.182Z,1535045952.182 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20180823T170912/Express0020.lzma
2018-08-23T17:39:12.983Z,1535045952.983 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0020.lzma.bak
2018-08-23T17:39:12.983Z,1535045952.983 [DataOverHttps](INFO): SBD MOMSN=8438605
2018-08-23T17:39:14.685Z,1535045954.685 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T17:39:14.685Z,1535045954.685 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T17:39:14.685Z,1535045954.685 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T17:39:24.714Z,1535045964.714 [NAL9602](INFO): Powering down
2018-08-23T17:40:20.172Z,1535046020.172 [BPC1](ERROR): Bank A: No match for stick 0 serial number:1717 in the onboard configuration file.
2018-08-23T17:40:20.188Z,1535046020.188 [BPC1](ERROR): Failed to parse Bank A battery data
2018-08-23T17:42:57.902Z,1535046177.902 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T17:42:57.902Z,1535046177.902 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-08-23T17:42:57.902Z,1535046177.902 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T17:42:58.173Z,1535046178.173 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T17:42:58.305Z,1535046178.305 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T17:42:58.638Z,1535046178.638 [Rowe_600LCM](INFO): Powering down
2018-08-23T17:43:00.248Z,1535046180.248 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T17:43:00.248Z,1535046180.248 [Rowe_600LCM] No Fault, FailCount= 1
2018-08-23T17:43:00.253Z,1535046180.253 [Rowe_600LCM](INFO): Initializing
2018-08-23T17:43:00.253Z,1535046180.253 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T17:43:00.254Z,1535046180.254 [Rowe_600LCM](INFO): LCM OK
2018-08-23T17:43:00.254Z,1535046180.254 [Rowe_600LCM](INFO): Powering up
2018-08-23T17:43:04.453Z,1535046184.453 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T17:43:04.680Z,1535046184.680 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T17:43:04.681Z,1535046184.681 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T17:43:04.682Z,1535046184.682 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T17:43:04.682Z,1535046184.682 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T17:44:14.859Z,1535046254.859 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T17:44:14.859Z,1535046254.859 [Default:CheckIn:C.Wait] Stopped
2018-08-23T17:44:14.859Z,1535046254.859 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T17:44:14.859Z,1535046254.859 [Default:CheckIn:D] Running Loop=1
2018-08-23T17:44:15.264Z,1535046255.264 [Default:CheckIn:D] Stopped
2018-08-23T17:44:15.264Z,1535046255.264 [Default:CheckIn:E] Running Loop=1
2018-08-23T17:44:15.666Z,1535046255.666 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.068278 min 
2018-08-23T17:44:15.666Z,1535046255.666 [Default:CheckIn:E] Stopped
2018-08-23T17:44:15.666Z,1535046255.666 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T17:44:15.666Z,1535046255.666 [Default:CheckIn] Stopped
2018-08-23T17:44:15.666Z,1535046255.666 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T17:44:15.667Z,1535046255.667 [Default:CheckIn](INFO): Running loop #6
2018-08-23T17:44:15.667Z,1535046255.667 [Default:CheckIn] Running Loop=6
2018-08-23T17:44:15.667Z,1535046255.667 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T17:44:15.667Z,1535046255.667 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T17:44:19.732Z,1535046259.732 [NAL9602](INFO): Powering up
2018-08-23T17:44:30.929Z,1535046270.929 [NAL9602](INFO): NAL9602 initialized
2018-08-23T17:44:57.728Z,1535046297.728 [NAL9602](INFO): SBD MO Status=2, MOMSN=23464, MT Status=2, MTMSN=0
2018-08-23T17:44:57.728Z,1535046297.728 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-23T17:45:00.697Z,1535046300.697 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T17:45:00.697Z,1535046300.697 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-08-23T17:45:00.697Z,1535046300.697 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T17:45:00.996Z,1535046300.996 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T17:45:01.102Z,1535046301.102 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T17:45:01.291Z,1535046301.291 [Rowe_600LCM](INFO): Powering down
2018-08-23T17:45:02.661Z,1535046302.661 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T17:45:02.661Z,1535046302.661 [Rowe_600LCM] No Fault, FailCount= 2
2018-08-23T17:45:02.913Z,1535046302.913 [Rowe_600LCM](INFO): Initializing
2018-08-23T17:45:02.914Z,1535046302.914 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T17:45:02.914Z,1535046302.914 [Rowe_600LCM](INFO): LCM OK
2018-08-23T17:45:02.914Z,1535046302.914 [Rowe_600LCM](INFO): Powering up
2018-08-23T17:45:07.215Z,1535046307.215 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T17:45:07.304Z,1535046307.304 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T17:45:07.304Z,1535046307.304 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T17:45:07.310Z,1535046307.310 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T17:45:07.311Z,1535046307.311 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T17:45:08.129Z,1535046308.129 [NAL9602](INFO): SBD MO Status=0, MOMSN=23464, MT Status=0, MTMSN=0
2018-08-23T17:45:08.129Z,1535046308.129 [NAL9602](INFO): No messages in MT queue
2018-08-23T17:45:09.331Z,1535046309.331 [NAL9602](INFO): GPS fix at 20180823T174450: (41.827595, -83.412725)
2018-08-23T17:45:09.436Z,1535046309.436 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T17:45:09.436Z,1535046309.436 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T17:45:17.405Z,1535046317.405 [DataOverHttps](INFO): Sending 65 bytes from file Logs/20180823T170912/Courier0022.lzma
2018-08-23T17:45:18.203Z,1535046318.203 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0022.lzma.bak
2018-08-23T17:45:18.204Z,1535046318.204 [DataOverHttps](INFO): SBD MOMSN=8438609
2018-08-23T17:45:30.559Z,1535046330.559 [DataOverHttps](INFO): Sending 241 bytes from file Logs/20180823T170912/Express0023.lzma
2018-08-23T17:45:31.335Z,1535046331.335 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0023.lzma.bak
2018-08-23T17:45:31.336Z,1535046331.336 [DataOverHttps](INFO): SBD MOMSN=8438612
2018-08-23T17:45:33.037Z,1535046333.037 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T17:45:33.037Z,1535046333.037 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T17:45:33.037Z,1535046333.037 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T17:45:42.965Z,1535046342.965 [NAL9602](INFO): Powering down
2018-08-23T17:46:39.408Z,1535046399.408 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-23T17:46:39.408Z,1535046399.408 [BPC1] Communications Fault, FailCount= 2
2018-08-23T17:46:39.409Z,1535046399.409 [BPC1](ERROR): Communications Fault
2018-08-23T17:46:39.462Z,1535046399.462 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-23T17:46:40.636Z,1535046400.636 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-23T17:46:40.636Z,1535046400.636 [BPC1] No Fault, FailCount= 2
2018-08-23T17:47:03.106Z,1535046423.106 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T17:47:03.106Z,1535046423.106 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-08-23T17:47:03.106Z,1535046423.106 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T17:47:03.477Z,1535046423.477 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T17:47:03.509Z,1535046423.509 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T17:47:03.858Z,1535046423.858 [Rowe_600LCM](INFO): Powering down
2018-08-23T17:47:05.098Z,1535046425.098 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T17:47:05.098Z,1535046425.098 [Rowe_600LCM] No Fault, FailCount= 3
2018-08-23T17:47:05.481Z,1535046425.481 [Rowe_600LCM](INFO): Initializing
2018-08-23T17:47:05.482Z,1535046425.482 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T17:47:05.482Z,1535046425.482 [Rowe_600LCM](INFO): LCM OK
2018-08-23T17:47:05.482Z,1535046425.482 [Rowe_600LCM](INFO): Powering up
2018-08-23T17:47:09.604Z,1535046429.604 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T17:47:09.669Z,1535046429.669 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T17:47:09.670Z,1535046429.670 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T17:47:09.671Z,1535046429.671 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T17:47:09.671Z,1535046429.671 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T17:49:05.897Z,1535046545.897 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T17:49:05.897Z,1535046545.897 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-08-23T17:49:05.897Z,1535046545.897 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T17:49:05.991Z,1535046545.991 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T17:49:06.301Z,1535046546.301 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T17:49:06.526Z,1535046546.526 [Rowe_600LCM](INFO): Powering down
2018-08-23T17:49:07.878Z,1535046547.878 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T17:49:07.878Z,1535046547.878 [Rowe_600LCM] No Fault, FailCount= 4
2018-08-23T17:49:08.141Z,1535046548.141 [Rowe_600LCM](INFO): Initializing
2018-08-23T17:49:08.141Z,1535046548.141 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T17:49:08.142Z,1535046548.142 [Rowe_600LCM](INFO): LCM OK
2018-08-23T17:49:08.142Z,1535046548.142 [Rowe_600LCM](INFO): Powering up
2018-08-23T17:49:12.414Z,1535046552.414 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T17:49:12.479Z,1535046552.479 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T17:49:12.480Z,1535046552.480 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T17:49:12.483Z,1535046552.483 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T17:49:12.483Z,1535046552.483 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T17:50:33.438Z,1535046633.438 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T17:50:33.438Z,1535046633.438 [Default:CheckIn:C.Wait] Stopped
2018-08-23T17:50:33.438Z,1535046633.438 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T17:50:33.438Z,1535046633.438 [Default:CheckIn:D] Running Loop=1
2018-08-23T17:50:33.848Z,1535046633.848 [Default:CheckIn:D] Stopped
2018-08-23T17:50:33.849Z,1535046633.849 [Default:CheckIn:E] Running Loop=1
2018-08-23T17:50:34.259Z,1535046634.259 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.378019 min 
2018-08-23T17:50:34.259Z,1535046634.259 [Default:CheckIn:E] Stopped
2018-08-23T17:50:34.259Z,1535046634.259 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T17:50:34.260Z,1535046634.260 [Default:CheckIn] Stopped
2018-08-23T17:50:34.260Z,1535046634.260 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T17:50:34.260Z,1535046634.260 [Default:CheckIn](INFO): Running loop #7
2018-08-23T17:50:34.260Z,1535046634.260 [Default:CheckIn] Running Loop=7
2018-08-23T17:50:34.260Z,1535046634.260 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T17:50:34.260Z,1535046634.260 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T17:50:38.546Z,1535046638.546 [NAL9602](INFO): Powering up
2018-08-23T17:50:49.470Z,1535046649.470 [NAL9602](INFO): NAL9602 initialized
2018-08-23T17:51:02.672Z,1535046662.672 [NAL9602](INFO): SBD MO Status=0, MOMSN=23465, MT Status=0, MTMSN=0
2018-08-23T17:51:02.672Z,1535046662.672 [NAL9602](INFO): No messages in MT queue
2018-08-23T17:51:08.249Z,1535046668.249 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T17:51:08.249Z,1535046668.249 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-08-23T17:51:08.249Z,1535046668.249 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T17:51:08.402Z,1535046668.402 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T17:51:08.403Z,1535046668.403 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-08-23T17:51:08.653Z,1535046668.653 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T17:51:08.900Z,1535046668.900 [Rowe_600LCM](INFO): Powering down
2018-08-23T17:51:21.075Z,1535046681.075 [NAL9602](INFO): GPS fix at 20180823T175101: (41.827200, -83.413297)
2018-08-23T17:51:21.148Z,1535046681.148 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T17:51:21.148Z,1535046681.148 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T17:51:27.362Z,1535046687.362 [DataOverHttps](INFO): Sending 230 bytes from file Logs/20180823T170912/Courier0025.lzma
2018-08-23T17:51:28.159Z,1535046688.159 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0025.lzma.bak
2018-08-23T17:51:28.160Z,1535046688.160 [DataOverHttps](INFO): SBD MOMSN=8438618
2018-08-23T17:51:40.258Z,1535046700.258 [DataOverHttps](INFO): Sending 264 bytes from file Logs/20180823T170912/Express0026.lzma
2018-08-23T17:51:41.055Z,1535046701.055 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0026.lzma.bak
2018-08-23T17:51:41.055Z,1535046701.055 [DataOverHttps](INFO): SBD MOMSN=8438621
2018-08-23T17:51:42.640Z,1535046702.640 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T17:51:42.640Z,1535046702.640 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T17:51:42.640Z,1535046702.640 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T17:51:53.118Z,1535046713.118 [NAL9602](INFO): Powering down
2018-08-23T17:56:43.013Z,1535047003.013 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T17:56:43.013Z,1535047003.013 [Default:CheckIn:C.Wait] Stopped
2018-08-23T17:56:43.013Z,1535047003.013 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T17:56:43.014Z,1535047003.014 [Default:CheckIn:D] Running Loop=1
2018-08-23T17:56:43.419Z,1535047003.419 [Default:CheckIn:D] Stopped
2018-08-23T17:56:43.419Z,1535047003.419 [Default:CheckIn:E] Running Loop=1
2018-08-23T17:56:43.825Z,1535047003.825 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.537533 min 
2018-08-23T17:56:43.825Z,1535047003.825 [Default:CheckIn:E] Stopped
2018-08-23T17:56:43.825Z,1535047003.825 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T17:56:43.826Z,1535047003.826 [Default:CheckIn] Stopped
2018-08-23T17:56:43.826Z,1535047003.826 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T17:56:43.826Z,1535047003.826 [Default:CheckIn](INFO): Running loop #8
2018-08-23T17:56:43.826Z,1535047003.826 [Default:CheckIn] Running Loop=8
2018-08-23T17:56:43.826Z,1535047003.826 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T17:56:43.826Z,1535047003.826 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T17:56:47.402Z,1535047007.402 [NAL9602](INFO): Powering up
2018-08-23T17:56:58.591Z,1535047018.591 [NAL9602](INFO): NAL9602 initialized
2018-08-23T17:57:26.592Z,1535047046.592 [NAL9602](INFO): SBD MO Status=0, MOMSN=23466, MT Status=0, MTMSN=0
2018-08-23T17:57:26.592Z,1535047046.592 [NAL9602](INFO): No messages in MT queue
2018-08-23T17:57:27.792Z,1535047047.792 [NAL9602](INFO): GPS fix at 20180823T175707: (41.827225, -83.413342)
2018-08-23T17:57:27.850Z,1535047047.850 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T17:57:27.850Z,1535047047.850 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T17:57:35.508Z,1535047055.508 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20180823T170912/Courier0028.lzma
2018-08-23T17:57:36.303Z,1535047056.303 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0028.lzma.bak
2018-08-23T17:57:36.304Z,1535047056.304 [DataOverHttps](INFO): SBD MOMSN=8438629
2018-08-23T17:57:47.994Z,1535047067.994 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20180823T170912/Express0029.lzma
2018-08-23T17:57:48.791Z,1535047068.791 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0029.lzma.bak
2018-08-23T17:57:48.792Z,1535047068.792 [DataOverHttps](INFO): SBD MOMSN=8438633
2018-08-23T17:57:50.583Z,1535047070.583 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T17:57:50.583Z,1535047070.583 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T17:57:50.583Z,1535047070.583 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T17:57:59.566Z,1535047079.566 [NAL9602](INFO): Powering down
2018-08-23T18:01:08.451Z,1535047268.451 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T18:01:08.451Z,1535047268.451 [Rowe_600LCM] No Fault, FailCount= 5
2018-08-23T18:01:08.457Z,1535047268.457 [Rowe_600LCM](INFO): Initializing
2018-08-23T18:01:08.458Z,1535047268.458 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T18:01:08.458Z,1535047268.458 [Rowe_600LCM](INFO): LCM OK
2018-08-23T18:01:08.458Z,1535047268.458 [Rowe_600LCM](INFO): Powering up
2018-08-23T18:01:12.615Z,1535047272.615 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T18:01:12.676Z,1535047272.676 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T18:01:12.677Z,1535047272.677 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T18:01:12.678Z,1535047272.678 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T18:01:12.678Z,1535047272.678 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T18:02:50.740Z,1535047370.740 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T18:02:50.740Z,1535047370.740 [Default:CheckIn:C.Wait] Stopped
2018-08-23T18:02:50.740Z,1535047370.740 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T18:02:50.740Z,1535047370.740 [Default:CheckIn:D] Running Loop=1
2018-08-23T18:02:51.116Z,1535047371.116 [Default:CheckIn:D] Stopped
2018-08-23T18:02:51.116Z,1535047371.116 [Default:CheckIn:E] Running Loop=1
2018-08-23T18:02:51.591Z,1535047371.591 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.665812 min 
2018-08-23T18:02:51.591Z,1535047371.591 [Default:CheckIn:E] Stopped
2018-08-23T18:02:51.591Z,1535047371.591 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T18:02:51.592Z,1535047371.592 [Default:CheckIn] Stopped
2018-08-23T18:02:51.592Z,1535047371.592 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T18:02:51.592Z,1535047371.592 [Default:CheckIn](INFO): Running loop #9
2018-08-23T18:02:51.592Z,1535047371.592 [Default:CheckIn] Running Loop=9
2018-08-23T18:02:51.592Z,1535047371.592 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T18:02:51.592Z,1535047371.592 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T18:02:52.288Z,1535047372.288 [NAL9602](INFO): Powering up
2018-08-23T18:03:03.331Z,1535047383.331 [NAL9602](INFO): NAL9602 initialized
2018-08-23T18:03:09.169Z,1535047389.169 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T18:03:09.169Z,1535047389.169 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-08-23T18:03:09.169Z,1535047389.169 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T18:03:09.416Z,1535047389.416 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T18:03:09.573Z,1535047389.573 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T18:03:09.666Z,1535047389.666 [Rowe_600LCM](INFO): Powering down
2018-08-23T18:03:11.065Z,1535047391.065 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T18:03:11.065Z,1535047391.065 [Rowe_600LCM] No Fault, FailCount= 1
2018-08-23T18:03:11.281Z,1535047391.281 [Rowe_600LCM](INFO): Initializing
2018-08-23T18:03:11.281Z,1535047391.281 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T18:03:11.282Z,1535047391.282 [Rowe_600LCM](INFO): LCM OK
2018-08-23T18:03:11.282Z,1535047391.282 [Rowe_600LCM](INFO): Powering up
2018-08-23T18:03:15.518Z,1535047395.518 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T18:03:15.580Z,1535047395.580 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T18:03:15.581Z,1535047395.581 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T18:03:15.581Z,1535047395.581 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T18:03:15.582Z,1535047395.582 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T18:03:25.325Z,1535047405.325 [NAL9602](INFO): SBD MO Status=2, MOMSN=23467, MT Status=2, MTMSN=0
2018-08-23T18:03:25.325Z,1535047405.325 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-23T18:03:33.731Z,1535047413.731 [NAL9602](INFO): SBD MO Status=0, MOMSN=23467, MT Status=0, MTMSN=0
2018-08-23T18:03:33.732Z,1535047413.732 [NAL9602](INFO): No messages in MT queue
2018-08-23T18:03:34.926Z,1535047414.926 [NAL9602](INFO): GPS fix at 20180823T180314: (41.827215, -83.413363)
2018-08-23T18:03:35.037Z,1535047415.037 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T18:03:35.037Z,1535047415.037 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T18:03:42.466Z,1535047422.466 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20180823T170912/Courier0031.lzma
2018-08-23T18:03:43.264Z,1535047423.264 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0031.lzma.bak
2018-08-23T18:03:43.265Z,1535047423.265 [DataOverHttps](INFO): SBD MOMSN=8438637
2018-08-23T18:03:55.871Z,1535047435.871 [DataOverHttps](INFO): Sending 191 bytes from file Logs/20180823T170912/Express0032.lzma
2018-08-23T18:03:56.668Z,1535047436.668 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0032.lzma.bak
2018-08-23T18:03:56.669Z,1535047436.669 [DataOverHttps](INFO): SBD MOMSN=8438640
2018-08-23T18:03:58.458Z,1535047438.458 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T18:03:58.458Z,1535047438.458 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T18:03:58.458Z,1535047438.458 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T18:04:07.742Z,1535047447.742 [NAL9602](INFO): Powering down
2018-08-23T18:05:11.553Z,1535047511.553 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T18:05:11.553Z,1535047511.553 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-08-23T18:05:11.553Z,1535047511.553 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T18:05:11.656Z,1535047511.656 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T18:05:11.957Z,1535047511.957 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T18:05:12.192Z,1535047512.192 [Rowe_600LCM](INFO): Powering down
2018-08-23T18:05:13.683Z,1535047513.683 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T18:05:13.684Z,1535047513.684 [Rowe_600LCM] No Fault, FailCount= 2
2018-08-23T18:05:13.809Z,1535047513.809 [Rowe_600LCM](INFO): Initializing
2018-08-23T18:05:13.809Z,1535047513.809 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T18:05:13.810Z,1535047513.810 [Rowe_600LCM](INFO): LCM OK
2018-08-23T18:05:13.810Z,1535047513.810 [Rowe_600LCM](INFO): Powering up
2018-08-23T18:05:17.930Z,1535047517.930 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T18:05:18.031Z,1535047518.031 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T18:05:18.032Z,1535047518.032 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T18:05:18.033Z,1535047518.033 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T18:05:18.033Z,1535047518.033 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T18:07:14.533Z,1535047634.533 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T18:07:14.533Z,1535047634.533 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-08-23T18:07:14.533Z,1535047634.533 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T18:07:14.785Z,1535047634.785 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T18:07:14.937Z,1535047634.937 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T18:07:15.305Z,1535047635.305 [Rowe_600LCM](INFO): Powering down
2018-08-23T18:07:16.772Z,1535047636.772 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T18:07:16.772Z,1535047636.772 [Rowe_600LCM] No Fault, FailCount= 3
2018-08-23T18:07:16.921Z,1535047636.921 [Rowe_600LCM](INFO): Initializing
2018-08-23T18:07:16.921Z,1535047636.921 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T18:07:16.922Z,1535047636.922 [Rowe_600LCM](INFO): LCM OK
2018-08-23T18:07:16.922Z,1535047636.922 [Rowe_600LCM](INFO): Powering up
2018-08-23T18:07:21.046Z,1535047641.046 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T18:07:21.204Z,1535047641.204 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T18:07:21.205Z,1535047641.205 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T18:07:21.206Z,1535047641.206 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T18:07:21.207Z,1535047641.207 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T18:08:58.843Z,1535047738.843 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T18:08:58.844Z,1535047738.844 [Default:CheckIn:C.Wait] Stopped
2018-08-23T18:08:58.844Z,1535047738.844 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T18:08:58.844Z,1535047738.844 [Default:CheckIn:D] Running Loop=1
2018-08-23T18:08:59.192Z,1535047739.192 [Default:CheckIn:D] Stopped
2018-08-23T18:08:59.192Z,1535047739.192 [Default:CheckIn:E] Running Loop=1
2018-08-23T18:08:59.606Z,1535047739.606 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.800407 min 
2018-08-23T18:08:59.606Z,1535047739.606 [Default:CheckIn:E] Stopped
2018-08-23T18:08:59.606Z,1535047739.606 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T18:08:59.606Z,1535047739.606 [Default:CheckIn] Stopped
2018-08-23T18:08:59.606Z,1535047739.606 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T18:08:59.607Z,1535047739.607 [Default:CheckIn](INFO): Running loop #10
2018-08-23T18:08:59.607Z,1535047739.607 [Default:CheckIn] Running Loop=10
2018-08-23T18:08:59.607Z,1535047739.607 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T18:08:59.607Z,1535047739.607 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T18:09:05.150Z,1535047745.150 [NAL9602](INFO): Powering up
2018-08-23T18:09:16.094Z,1535047756.094 [NAL9602](INFO): NAL9602 initialized
2018-08-23T18:09:16.928Z,1535047756.928 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T18:09:16.928Z,1535047756.928 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-08-23T18:09:16.928Z,1535047756.928 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T18:09:16.996Z,1535047756.996 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T18:09:17.333Z,1535047757.333 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T18:09:17.510Z,1535047757.510 [Rowe_600LCM](INFO): Powering down
2018-08-23T18:09:19.012Z,1535047759.012 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T18:09:19.017Z,1535047759.017 [Rowe_600LCM] No Fault, FailCount= 4
2018-08-23T18:09:19.125Z,1535047759.125 [Rowe_600LCM](INFO): Initializing
2018-08-23T18:09:19.126Z,1535047759.126 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T18:09:19.126Z,1535047759.126 [Rowe_600LCM](INFO): LCM OK
2018-08-23T18:09:19.126Z,1535047759.126 [Rowe_600LCM](INFO): Powering up
2018-08-23T18:09:23.245Z,1535047763.245 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T18:09:23.380Z,1535047763.380 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T18:09:23.381Z,1535047763.381 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T18:09:23.382Z,1535047763.382 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T18:09:23.383Z,1535047763.383 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T18:09:31.296Z,1535047771.296 [NAL9602](INFO): SBD MO Status=0, MOMSN=23468, MT Status=0, MTMSN=0
2018-08-23T18:09:31.297Z,1535047771.297 [NAL9602](INFO): No messages in MT queue
2018-08-23T18:09:47.702Z,1535047787.702 [NAL9602](INFO): GPS fix at 20180823T180926: (41.827219, -83.413339)
2018-08-23T18:09:47.739Z,1535047787.739 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T18:09:47.739Z,1535047787.739 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T18:09:54.774Z,1535047794.774 [DataOverHttps](INFO): Sending 65 bytes from file Logs/20180823T170912/Courier0034.lzma
2018-08-23T18:09:56.393Z,1535047796.393 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0034.lzma.bak
2018-08-23T18:09:56.393Z,1535047796.393 [DataOverHttps](INFO): SBD MOMSN=8438645
2018-08-23T18:10:08.875Z,1535047808.875 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20180823T170912/Express0035.lzma
2018-08-23T18:10:09.675Z,1535047809.675 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0035.lzma.bak
2018-08-23T18:10:09.676Z,1535047809.676 [DataOverHttps](INFO): SBD MOMSN=8438648
2018-08-23T18:10:11.718Z,1535047811.718 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T18:10:11.718Z,1535047811.718 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T18:10:11.718Z,1535047811.718 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T18:10:19.758Z,1535047819.758 [NAL9602](INFO): Powering down
2018-08-23T18:11:19.137Z,1535047879.137 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T18:11:19.137Z,1535047879.137 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-08-23T18:11:19.137Z,1535047879.137 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T18:11:19.144Z,1535047879.144 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T18:11:19.144Z,1535047879.144 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-08-23T18:11:19.541Z,1535047879.541 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T18:11:19.700Z,1535047879.700 [Rowe_600LCM](INFO): Powering down
2018-08-23T18:13:24.717Z,1535048004.717 [BPC1](ERROR): Failed to receive data from both battery packs
2018-08-23T18:13:24.717Z,1535048004.717 [BPC1] Communications Fault, FailCount= 1
2018-08-23T18:13:24.729Z,1535048004.729 [BPC1](ERROR): Communications Fault
2018-08-23T18:13:24.839Z,1535048004.839 [CBIT](ERROR): Communications Fault in component: BPC1
2018-08-23T18:13:25.948Z,1535048005.948 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-23T18:13:25.948Z,1535048005.948 [BPC1] No Fault, FailCount= 1
2018-08-23T18:15:12.176Z,1535048112.176 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T18:15:12.176Z,1535048112.176 [Default:CheckIn:C.Wait] Stopped
2018-08-23T18:15:12.176Z,1535048112.176 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T18:15:12.176Z,1535048112.176 [Default:CheckIn:D] Running Loop=1
2018-08-23T18:15:12.571Z,1535048112.571 [Default:CheckIn:D] Stopped
2018-08-23T18:15:12.571Z,1535048112.571 [Default:CheckIn:E] Running Loop=1
2018-08-23T18:15:16.023Z,1535048116.023 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.023393 min 
2018-08-23T18:15:16.023Z,1535048116.023 [Default:CheckIn:E] Stopped
2018-08-23T18:15:16.023Z,1535048116.023 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T18:15:16.023Z,1535048116.023 [Default:CheckIn] Stopped
2018-08-23T18:15:16.024Z,1535048116.024 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T18:15:16.024Z,1535048116.024 [Default:CheckIn](INFO): Running loop #11
2018-08-23T18:15:16.024Z,1535048116.024 [Default:CheckIn] Running Loop=11
2018-08-23T18:15:16.024Z,1535048116.024 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T18:15:16.024Z,1535048116.024 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T18:15:16.494Z,1535048116.494 [NAL9602](INFO): Powering up
2018-08-23T18:15:27.694Z,1535048127.694 [NAL9602](INFO): NAL9602 initialized
2018-08-23T18:15:44.496Z,1535048144.496 [NAL9602](INFO): SBD MO Status=0, MOMSN=23469, MT Status=0, MTMSN=0
2018-08-23T18:15:44.496Z,1535048144.496 [NAL9602](INFO): No messages in MT queue
2018-08-23T18:15:51.303Z,1535048151.303 [NAL9602](INFO): GPS fix at 20180823T181529: (41.827244, -83.413325)
2018-08-23T18:15:51.358Z,1535048151.358 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T18:15:51.358Z,1535048151.358 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T18:15:58.426Z,1535048158.426 [DataOverHttps](INFO): Sending 80 bytes from file Logs/20180823T170912/Courier0037.lzma
2018-08-23T18:15:59.223Z,1535048159.223 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0037.lzma.bak
2018-08-23T18:15:59.224Z,1535048159.224 [DataOverHttps](INFO): SBD MOMSN=8438655
2018-08-23T18:16:11.443Z,1535048171.443 [DataOverHttps](INFO): Sending 237 bytes from file Logs/20180823T170912/Express0038.lzma
2018-08-23T18:16:12.239Z,1535048172.239 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0038.lzma.bak
2018-08-23T18:16:12.239Z,1535048172.239 [DataOverHttps](INFO): SBD MOMSN=8438658
2018-08-23T18:16:13.809Z,1535048173.809 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T18:16:13.809Z,1535048173.809 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T18:16:13.810Z,1535048173.810 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T18:16:23.478Z,1535048183.478 [NAL9602](INFO): Powering down
2018-08-23T18:21:14.112Z,1535048474.112 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T18:21:14.117Z,1535048474.117 [Default:CheckIn:C.Wait] Stopped
2018-08-23T18:21:14.117Z,1535048474.117 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T18:21:14.117Z,1535048474.117 [Default:CheckIn:D] Running Loop=1
2018-08-23T18:21:14.507Z,1535048474.507 [Default:CheckIn:D] Stopped
2018-08-23T18:21:14.507Z,1535048474.507 [Default:CheckIn:E] Running Loop=1
2018-08-23T18:21:14.912Z,1535048474.912 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.055656 min 
2018-08-23T18:21:14.912Z,1535048474.912 [Default:CheckIn:E] Stopped
2018-08-23T18:21:14.912Z,1535048474.912 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T18:21:14.912Z,1535048474.912 [Default:CheckIn] Stopped
2018-08-23T18:21:14.912Z,1535048474.912 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T18:21:14.912Z,1535048474.912 [Default:CheckIn](INFO): Running loop #12
2018-08-23T18:21:14.913Z,1535048474.913 [Default:CheckIn] Running Loop=12
2018-08-23T18:21:14.913Z,1535048474.913 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T18:21:14.913Z,1535048474.913 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T18:21:18.756Z,1535048478.756 [NAL9602](INFO): Powering up
2018-08-23T18:21:19.307Z,1535048479.307 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T18:21:19.307Z,1535048479.307 [Rowe_600LCM] No Fault, FailCount= 5
2018-08-23T18:21:19.353Z,1535048479.353 [Rowe_600LCM](INFO): Initializing
2018-08-23T18:21:19.353Z,1535048479.353 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T18:21:19.353Z,1535048479.353 [Rowe_600LCM](INFO): LCM OK
2018-08-23T18:21:19.354Z,1535048479.354 [Rowe_600LCM](INFO): Powering up
2018-08-23T18:21:23.476Z,1535048483.476 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T18:21:23.535Z,1535048483.535 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T18:21:23.536Z,1535048483.536 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T18:21:23.537Z,1535048483.537 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T18:21:23.538Z,1535048483.538 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T18:21:29.642Z,1535048489.642 [NAL9602](INFO): NAL9602 initialized
2018-08-23T18:21:53.244Z,1535048513.244 [NAL9602](INFO): SBD MO Status=2, MOMSN=23470, MT Status=2, MTMSN=0
2018-08-23T18:21:53.244Z,1535048513.244 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-23T18:22:13.244Z,1535048533.244 [NAL9602](INFO): SBD MO Status=0, MOMSN=23470, MT Status=0, MTMSN=0
2018-08-23T18:22:13.244Z,1535048533.244 [NAL9602](INFO): No messages in MT queue
2018-08-23T18:22:14.459Z,1535048534.459 [NAL9602](INFO): GPS fix at 20180823T182151: (41.827249, -83.413359)
2018-08-23T18:22:14.613Z,1535048534.613 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T18:22:14.613Z,1535048534.613 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T18:22:20.686Z,1535048540.686 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20180823T170912/Courier0040.lzma
2018-08-23T18:22:21.483Z,1535048541.483 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0040.lzma.bak
2018-08-23T18:22:21.484Z,1535048541.484 [DataOverHttps](INFO): SBD MOMSN=8438664
2018-08-23T18:22:34.024Z,1535048554.024 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20180823T170912/Express0041.lzma
2018-08-23T18:22:34.819Z,1535048554.819 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0041.lzma.bak
2018-08-23T18:22:34.820Z,1535048554.820 [DataOverHttps](INFO): SBD MOMSN=8438667
2018-08-23T18:22:36.728Z,1535048556.728 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T18:22:36.728Z,1535048556.728 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T18:22:36.728Z,1535048556.728 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T18:22:46.502Z,1535048566.502 [NAL9602](INFO): Powering down
2018-08-23T18:23:19.435Z,1535048599.435 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T18:23:19.436Z,1535048599.436 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-08-23T18:23:19.436Z,1535048599.436 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T18:23:19.805Z,1535048599.805 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T18:23:19.853Z,1535048599.853 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T18:23:20.014Z,1535048600.014 [Rowe_600LCM](INFO): Powering down
2018-08-23T18:23:21.379Z,1535048601.379 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T18:23:21.379Z,1535048601.379 [Rowe_600LCM] No Fault, FailCount= 1
2018-08-23T18:23:21.630Z,1535048601.630 [Rowe_600LCM](INFO): Initializing
2018-08-23T18:23:21.630Z,1535048601.630 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T18:23:21.630Z,1535048601.630 [Rowe_600LCM](INFO): LCM OK
2018-08-23T18:23:21.630Z,1535048601.630 [Rowe_600LCM](INFO): Powering up
2018-08-23T18:23:25.877Z,1535048605.877 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T18:23:25.936Z,1535048605.936 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T18:23:25.937Z,1535048605.937 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T18:23:25.938Z,1535048605.938 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T18:23:25.938Z,1535048605.938 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T18:25:21.807Z,1535048721.807 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T18:25:21.807Z,1535048721.807 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-08-23T18:25:21.807Z,1535048721.807 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T18:25:21.860Z,1535048721.860 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T18:25:22.209Z,1535048722.209 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T18:25:22.484Z,1535048722.484 [Rowe_600LCM](INFO): Powering down
2018-08-23T18:25:23.867Z,1535048723.867 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T18:25:23.867Z,1535048723.867 [Rowe_600LCM] No Fault, FailCount= 2
2018-08-23T18:25:24.097Z,1535048724.097 [Rowe_600LCM](INFO): Initializing
2018-08-23T18:25:24.097Z,1535048724.097 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T18:25:24.098Z,1535048724.098 [Rowe_600LCM](INFO): LCM OK
2018-08-23T18:25:24.098Z,1535048724.098 [Rowe_600LCM](INFO): Powering up
2018-08-23T18:25:28.341Z,1535048728.341 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T18:25:28.407Z,1535048728.407 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T18:25:28.408Z,1535048728.408 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T18:25:28.409Z,1535048728.409 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T18:25:28.410Z,1535048728.410 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T18:27:24.599Z,1535048844.599 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T18:27:24.599Z,1535048844.599 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-08-23T18:27:24.599Z,1535048844.599 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T18:27:24.751Z,1535048844.751 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T18:27:25.001Z,1535048845.001 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T18:27:25.269Z,1535048845.269 [Rowe_600LCM](INFO): Powering down
2018-08-23T18:27:26.744Z,1535048846.744 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T18:27:26.744Z,1535048846.744 [Rowe_600LCM] No Fault, FailCount= 3
2018-08-23T18:27:26.885Z,1535048846.885 [Rowe_600LCM](INFO): Initializing
2018-08-23T18:27:26.885Z,1535048846.885 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T18:27:26.886Z,1535048846.886 [Rowe_600LCM](INFO): LCM OK
2018-08-23T18:27:26.886Z,1535048846.886 [Rowe_600LCM](INFO): Powering up
2018-08-23T18:27:31.010Z,1535048851.010 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T18:27:31.152Z,1535048851.152 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T18:27:31.153Z,1535048851.153 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T18:27:31.154Z,1535048851.154 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T18:27:31.154Z,1535048851.154 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T18:27:37.163Z,1535048857.163 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T18:27:37.163Z,1535048857.163 [Default:CheckIn:C.Wait] Stopped
2018-08-23T18:27:37.163Z,1535048857.163 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T18:27:37.163Z,1535048857.163 [Default:CheckIn:D] Running Loop=1
2018-08-23T18:27:37.552Z,1535048857.552 [Default:CheckIn:D] Stopped
2018-08-23T18:27:37.552Z,1535048857.552 [Default:CheckIn:E] Running Loop=1
2018-08-23T18:27:41.451Z,1535048861.451 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.439730 min 
2018-08-23T18:27:41.452Z,1535048861.452 [Default:CheckIn:E] Stopped
2018-08-23T18:27:41.452Z,1535048861.452 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T18:27:41.452Z,1535048861.452 [Default:CheckIn] Stopped
2018-08-23T18:27:41.453Z,1535048861.453 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T18:27:41.454Z,1535048861.454 [Default:CheckIn](INFO): Running loop #13
2018-08-23T18:27:41.454Z,1535048861.454 [Default:CheckIn] Running Loop=13
2018-08-23T18:27:41.454Z,1535048861.454 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T18:27:41.454Z,1535048861.454 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T18:27:41.926Z,1535048861.926 [NAL9602](INFO): Powering up
2018-08-23T18:27:53.122Z,1535048873.122 [NAL9602](INFO): NAL9602 initialized
2018-08-23T18:28:09.128Z,1535048889.128 [NAL9602](INFO): SBD MO Status=0, MOMSN=23471, MT Status=0, MTMSN=0
2018-08-23T18:28:09.128Z,1535048889.128 [NAL9602](INFO): No messages in MT queue
2018-08-23T18:28:25.547Z,1535048905.547 [NAL9602](INFO): GPS fix at 20180823T182802: (41.827214, -83.413334)
2018-08-23T18:28:25.685Z,1535048905.685 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T18:28:25.685Z,1535048905.685 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T18:28:31.780Z,1535048911.780 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20180823T170912/Courier0043.lzma
2018-08-23T18:28:32.576Z,1535048912.576 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0043.lzma.bak
2018-08-23T18:28:32.585Z,1535048912.585 [DataOverHttps](INFO): SBD MOMSN=8438672
2018-08-23T18:28:44.882Z,1535048924.882 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20180823T170912/Express0044.lzma
2018-08-23T18:28:45.680Z,1535048925.680 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0044.lzma.bak
2018-08-23T18:28:45.681Z,1535048925.681 [DataOverHttps](INFO): SBD MOMSN=8438676
2018-08-23T18:28:47.882Z,1535048927.882 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T18:28:47.883Z,1535048927.883 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T18:28:47.883Z,1535048927.883 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T18:28:57.246Z,1535048937.246 [NAL9602](INFO): Powering down
2018-08-23T18:29:26.999Z,1535048966.999 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T18:29:26.999Z,1535048966.999 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-08-23T18:29:26.999Z,1535048966.999 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T18:29:27.338Z,1535048967.338 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T18:29:27.401Z,1535048967.401 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T18:29:27.554Z,1535048967.554 [Rowe_600LCM](INFO): Powering down
2018-08-23T18:29:28.904Z,1535048968.904 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T18:29:28.904Z,1535048968.904 [Rowe_600LCM] No Fault, FailCount= 4
2018-08-23T18:29:29.169Z,1535048969.169 [Rowe_600LCM](INFO): Initializing
2018-08-23T18:29:29.169Z,1535048969.169 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T18:29:29.170Z,1535048969.170 [Rowe_600LCM](INFO): LCM OK
2018-08-23T18:29:29.170Z,1535048969.170 [Rowe_600LCM](INFO): Powering up
2018-08-23T18:29:33.409Z,1535048973.409 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T18:29:33.525Z,1535048973.525 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T18:29:33.526Z,1535048973.526 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T18:29:33.527Z,1535048973.527 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T18:29:33.528Z,1535048973.528 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T18:31:29.367Z,1535049089.367 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T18:31:29.367Z,1535049089.367 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-08-23T18:31:29.367Z,1535049089.367 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T18:31:29.667Z,1535049089.667 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T18:31:29.667Z,1535049089.667 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-08-23T18:31:29.773Z,1535049089.773 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T18:31:29.951Z,1535049089.951 [Rowe_600LCM](INFO): Powering down
2018-08-23T18:33:48.367Z,1535049228.367 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T18:33:48.367Z,1535049228.367 [Default:CheckIn:C.Wait] Stopped
2018-08-23T18:33:48.367Z,1535049228.367 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T18:33:48.367Z,1535049228.367 [Default:CheckIn:D] Running Loop=1
2018-08-23T18:33:48.771Z,1535049228.771 [Default:CheckIn:D] Stopped
2018-08-23T18:33:48.771Z,1535049228.771 [Default:CheckIn:E] Running Loop=1
2018-08-23T18:33:49.176Z,1535049229.176 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 80.626725 min 
2018-08-23T18:33:49.176Z,1535049229.176 [Default:CheckIn:E] Stopped
2018-08-23T18:33:49.176Z,1535049229.176 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T18:33:49.176Z,1535049229.176 [Default:CheckIn] Stopped
2018-08-23T18:33:49.177Z,1535049229.177 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T18:33:49.177Z,1535049229.177 [Default:CheckIn](INFO): Running loop #14
2018-08-23T18:33:49.177Z,1535049229.177 [Default:CheckIn] Running Loop=14
2018-08-23T18:33:49.177Z,1535049229.177 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T18:33:49.178Z,1535049229.178 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T18:33:53.072Z,1535049233.072 [NAL9602](INFO): Powering up
2018-08-23T18:34:03.974Z,1535049243.974 [NAL9602](INFO): NAL9602 initialized
2018-08-23T18:34:16.776Z,1535049256.776 [NAL9602](INFO): SBD MO Status=0, MOMSN=23472, MT Status=0, MTMSN=0
2018-08-23T18:34:16.776Z,1535049256.776 [NAL9602](INFO): No messages in MT queue
2018-08-23T18:34:41.978Z,1535049281.978 [NAL9602](INFO): GPS fix at 20180823T183418: (41.830220, -83.412544)
2018-08-23T18:34:42.045Z,1535049282.045 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T18:34:42.049Z,1535049282.049 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T18:34:47.702Z,1535049287.702 [DataOverHttps](INFO): Sending 80 bytes from file Logs/20180823T170912/Courier0046.lzma
2018-08-23T18:34:48.499Z,1535049288.499 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0046.lzma.bak
2018-08-23T18:34:48.500Z,1535049288.500 [DataOverHttps](INFO): SBD MOMSN=8438683
2018-08-23T18:34:59.981Z,1535049299.981 [DataOverHttps](INFO): Sending 260 bytes from file Logs/20180823T170912/Express0047.lzma
2018-08-23T18:35:00.787Z,1535049300.787 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0047.lzma.bak
2018-08-23T18:35:00.787Z,1535049300.787 [DataOverHttps](INFO): SBD MOMSN=8438686
2018-08-23T18:35:02.727Z,1535049302.727 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T18:35:02.727Z,1535049302.727 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T18:35:02.727Z,1535049302.727 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T18:35:14.042Z,1535049314.042 [NAL9602](INFO): Powering down
2018-08-23T18:40:03.013Z,1535049603.013 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T18:40:03.013Z,1535049603.013 [Default:CheckIn:C.Wait] Stopped
2018-08-23T18:40:03.013Z,1535049603.013 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T18:40:03.013Z,1535049603.013 [Default:CheckIn:D] Running Loop=1
2018-08-23T18:40:03.362Z,1535049603.362 [Default:CheckIn:D] Stopped
2018-08-23T18:40:03.362Z,1535049603.362 [Default:CheckIn:E] Running Loop=1
2018-08-23T18:40:03.789Z,1535049603.789 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 86.869914 min 
2018-08-23T18:40:03.789Z,1535049603.789 [Default:CheckIn:E] Stopped
2018-08-23T18:40:03.789Z,1535049603.789 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T18:40:03.789Z,1535049603.789 [Default:CheckIn] Stopped
2018-08-23T18:40:03.790Z,1535049603.790 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T18:40:03.790Z,1535049603.790 [Default:CheckIn](INFO): Running loop #15
2018-08-23T18:40:03.790Z,1535049603.790 [Default:CheckIn] Running Loop=15
2018-08-23T18:40:03.790Z,1535049603.790 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T18:40:03.790Z,1535049603.790 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T18:40:07.088Z,1535049607.088 [NAL9602](INFO): Powering up
2018-08-23T18:40:17.894Z,1535049617.894 [NAL9602](INFO): NAL9602 initialized
2018-08-23T18:40:32.696Z,1535049632.696 [NAL9602](INFO): SBD MO Status=0, MOMSN=23473, MT Status=0, MTMSN=0
2018-08-23T18:40:32.696Z,1535049632.696 [NAL9602](INFO): No messages in MT queue
2018-08-23T18:40:48.707Z,1535049648.707 [NAL9602](INFO): GPS fix at 20180823T184024: (41.830847, -83.401573)
2018-08-23T18:40:48.772Z,1535049648.772 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T18:40:48.777Z,1535049648.777 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T18:40:55.942Z,1535049655.942 [DataOverHttps](INFO): Sending 80 bytes from file Logs/20180823T170912/Courier0049.lzma
2018-08-23T18:40:56.739Z,1535049656.739 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0049.lzma.bak
2018-08-23T18:40:56.740Z,1535049656.740 [DataOverHttps](INFO): SBD MOMSN=8438693
2018-08-23T18:41:11.398Z,1535049671.398 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20180823T170912/Express0050.lzma
2018-08-23T18:41:12.195Z,1535049672.195 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0050.lzma.bak
2018-08-23T18:41:12.196Z,1535049672.196 [DataOverHttps](INFO): SBD MOMSN=8438697
2018-08-23T18:41:13.896Z,1535049673.896 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T18:41:13.896Z,1535049673.896 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T18:41:13.896Z,1535049673.896 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T18:41:20.760Z,1535049680.760 [NAL9602](INFO): Powering down
2018-08-23T18:41:29.621Z,1535049689.621 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T18:41:29.622Z,1535049689.622 [Rowe_600LCM] No Fault, FailCount= 5
2018-08-23T18:41:29.937Z,1535049689.937 [Rowe_600LCM](INFO): Initializing
2018-08-23T18:41:29.938Z,1535049689.938 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T18:41:29.938Z,1535049689.938 [Rowe_600LCM](INFO): LCM OK
2018-08-23T18:41:29.938Z,1535049689.938 [Rowe_600LCM](INFO): Powering up
2018-08-23T18:41:34.221Z,1535049694.221 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T18:41:34.307Z,1535049694.307 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T18:41:34.308Z,1535049694.308 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T18:41:34.309Z,1535049694.309 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T18:41:34.310Z,1535049694.310 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T18:42:19.729Z,1535049739.729 [PNI_TCM](FAULT): Failed to acquire valid data within timeout.
2018-08-23T18:42:19.729Z,1535049739.729 [PNI_TCM] Data Fault, FailCount= 1
2018-08-23T18:42:19.729Z,1535049739.729 [PNI_TCM](ERROR): Data Fault
2018-08-23T18:42:19.827Z,1535049739.827 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 5.398166 seconds old.
2018-08-23T18:42:19.943Z,1535049739.943 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-08-23T18:42:20.023Z,1535049740.023 [PNI_TCM](INFO): Powering down
2018-08-23T18:42:20.081Z,1535049740.081 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 5.652471 seconds old.
2018-08-23T18:42:20.405Z,1535049740.405 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 5.976895 seconds old.
2018-08-23T18:42:20.835Z,1535049740.835 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 6.406013 seconds old.
2018-08-23T18:42:21.202Z,1535049741.202 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 6.773308 seconds old.
2018-08-23T18:42:21.217Z,1535049741.217 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-08-23T18:42:21.217Z,1535049741.217 [PNI_TCM] No Fault, FailCount= 1
2018-08-23T18:42:21.604Z,1535049741.604 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 7.175294 seconds old.
2018-08-23T18:42:22.002Z,1535049742.002 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 7.574119 seconds old.
2018-08-23T18:42:22.407Z,1535049742.407 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 7.979125 seconds old.
2018-08-23T18:42:22.814Z,1535049742.814 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 8.385303 seconds old.
2018-08-23T18:42:23.212Z,1535049743.212 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 8.783499 seconds old.
2018-08-23T18:42:23.624Z,1535049743.624 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 9.196066 seconds old.
2018-08-23T18:42:24.058Z,1535049744.058 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 9.629630 seconds old.
2018-08-23T18:42:24.406Z,1535049744.406 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 9.977370 seconds old.
2018-08-23T18:43:30.287Z,1535049810.287 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T18:43:30.287Z,1535049810.287 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-08-23T18:43:30.287Z,1535049810.287 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T18:43:30.388Z,1535049810.388 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T18:43:30.689Z,1535049810.689 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T18:43:30.940Z,1535049810.940 [Rowe_600LCM](INFO): Powering down
2018-08-23T18:43:32.364Z,1535049812.364 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T18:43:32.364Z,1535049812.364 [Rowe_600LCM] No Fault, FailCount= 1
2018-08-23T18:43:32.557Z,1535049812.557 [Rowe_600LCM](INFO): Initializing
2018-08-23T18:43:32.557Z,1535049812.557 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T18:43:32.557Z,1535049812.557 [Rowe_600LCM](INFO): LCM OK
2018-08-23T18:43:32.558Z,1535049812.558 [Rowe_600LCM](INFO): Powering up
2018-08-23T18:43:36.675Z,1535049816.675 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T18:43:36.808Z,1535049816.808 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T18:43:36.809Z,1535049816.809 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T18:43:36.810Z,1535049816.810 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T18:43:36.812Z,1535049816.812 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T18:45:33.257Z,1535049933.257 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T18:45:33.257Z,1535049933.257 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-08-23T18:45:33.257Z,1535049933.257 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T18:45:33.518Z,1535049933.518 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T18:45:33.661Z,1535049933.661 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T18:45:33.765Z,1535049933.765 [Rowe_600LCM](INFO): Powering down
2018-08-23T18:45:35.121Z,1535049935.121 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T18:45:35.122Z,1535049935.122 [Rowe_600LCM] No Fault, FailCount= 2
2018-08-23T18:45:35.382Z,1535049935.382 [Rowe_600LCM](INFO): Initializing
2018-08-23T18:45:35.383Z,1535049935.383 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T18:45:35.383Z,1535049935.383 [Rowe_600LCM](INFO): LCM OK
2018-08-23T18:45:35.383Z,1535049935.383 [Rowe_600LCM](INFO): Powering up
2018-08-23T18:45:39.618Z,1535049939.618 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T18:45:39.681Z,1535049939.681 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T18:45:39.683Z,1535049939.683 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T18:45:39.684Z,1535049939.684 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T18:45:39.684Z,1535049939.684 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T18:46:14.341Z,1535049974.341 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T18:46:14.341Z,1535049974.341 [Default:CheckIn:C.Wait] Stopped
2018-08-23T18:46:14.341Z,1535049974.341 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T18:46:14.341Z,1535049974.341 [Default:CheckIn:D] Running Loop=1
2018-08-23T18:46:14.739Z,1535049974.739 [Default:CheckIn:D] Stopped
2018-08-23T18:46:14.739Z,1535049974.739 [Default:CheckIn:E] Running Loop=1
2018-08-23T18:46:15.098Z,1535049975.098 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 93.059530 min 
2018-08-23T18:46:15.098Z,1535049975.098 [Default:CheckIn:E] Stopped
2018-08-23T18:46:15.098Z,1535049975.098 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T18:46:15.098Z,1535049975.098 [Default:CheckIn] Stopped
2018-08-23T18:46:15.098Z,1535049975.098 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T18:46:15.099Z,1535049975.099 [Default:CheckIn](INFO): Running loop #16
2018-08-23T18:46:15.099Z,1535049975.099 [Default:CheckIn] Running Loop=16
2018-08-23T18:46:15.099Z,1535049975.099 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T18:46:15.099Z,1535049975.099 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T18:46:15.854Z,1535049975.854 [NAL9602](INFO): Powering up
2018-08-23T18:46:26.679Z,1535049986.679 [NAL9602](INFO): NAL9602 initialized
2018-08-23T18:46:40.688Z,1535050000.688 [NAL9602](INFO): SBD MO Status=0, MOMSN=23474, MT Status=0, MTMSN=0
2018-08-23T18:46:40.688Z,1535050000.688 [NAL9602](INFO): No messages in MT queue
2018-08-23T18:46:57.106Z,1535050017.106 [NAL9602](INFO): GPS fix at 20180823T184632: (41.848039, -83.365984)
2018-08-23T18:46:57.164Z,1535050017.164 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T18:46:57.164Z,1535050017.164 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T18:47:05.102Z,1535050025.102 [DataOverHttps](INFO): Sending 80 bytes from file Logs/20180823T170912/Courier0052.lzma
2018-08-23T18:47:05.900Z,1535050025.900 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0052.lzma.bak
2018-08-23T18:47:05.900Z,1535050025.900 [DataOverHttps](INFO): SBD MOMSN=8438701
2018-08-23T18:47:21.230Z,1535050041.230 [DataOverHttps](INFO): Sending 272 bytes from file Logs/20180823T170912/Express0053.lzma
2018-08-23T18:47:22.028Z,1535050042.028 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0053.lzma.bak
2018-08-23T18:47:22.028Z,1535050042.028 [DataOverHttps](INFO): SBD MOMSN=8438704
2018-08-23T18:47:23.729Z,1535050043.729 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T18:47:23.729Z,1535050043.729 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T18:47:23.729Z,1535050043.729 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T18:47:31.571Z,1535050051.571 [NAL9602](INFO): Powering down
2018-08-23T18:47:35.659Z,1535050055.659 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T18:47:35.659Z,1535050055.659 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-08-23T18:47:35.659Z,1535050055.659 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T18:47:35.810Z,1535050055.810 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T18:47:36.061Z,1535050056.061 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T18:47:36.427Z,1535050056.427 [Rowe_600LCM](INFO): Powering down
2018-08-23T18:47:37.809Z,1535050057.809 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T18:47:37.809Z,1535050057.809 [Rowe_600LCM] No Fault, FailCount= 3
2018-08-23T18:47:38.041Z,1535050058.041 [Rowe_600LCM](INFO): Initializing
2018-08-23T18:47:38.041Z,1535050058.041 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T18:47:38.042Z,1535050058.042 [Rowe_600LCM](INFO): LCM OK
2018-08-23T18:47:38.042Z,1535050058.042 [Rowe_600LCM](INFO): Powering up
2018-08-23T18:47:42.286Z,1535050062.286 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T18:47:42.358Z,1535050062.358 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T18:47:42.359Z,1535050062.359 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T18:47:42.360Z,1535050062.360 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T18:47:42.361Z,1535050062.361 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T18:49:38.445Z,1535050178.445 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T18:49:38.445Z,1535050178.445 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-08-23T18:49:38.445Z,1535050178.445 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T18:49:38.690Z,1535050178.690 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T18:49:38.849Z,1535050178.849 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T18:49:39.106Z,1535050179.106 [Rowe_600LCM](INFO): Powering down
2018-08-23T18:49:40.678Z,1535050180.678 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T18:49:40.678Z,1535050180.678 [Rowe_600LCM] No Fault, FailCount= 4
2018-08-23T18:49:40.721Z,1535050180.721 [Rowe_600LCM](INFO): Initializing
2018-08-23T18:49:40.721Z,1535050180.721 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T18:49:40.722Z,1535050180.722 [Rowe_600LCM](INFO): LCM OK
2018-08-23T18:49:40.722Z,1535050180.722 [Rowe_600LCM](INFO): Powering up
2018-08-23T18:49:44.850Z,1535050184.850 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T18:49:44.915Z,1535050184.915 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T18:49:44.916Z,1535050184.916 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T18:49:44.917Z,1535050184.917 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T18:49:44.918Z,1535050184.918 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T18:51:40.845Z,1535050300.845 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T18:51:40.845Z,1535050300.845 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-08-23T18:51:40.845Z,1535050300.845 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T18:51:40.863Z,1535050300.863 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T18:51:40.864Z,1535050300.864 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-08-23T18:51:41.249Z,1535050301.249 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T18:51:41.342Z,1535050301.342 [Rowe_600LCM](INFO): Powering down
2018-08-23T18:52:23.971Z,1535050343.971 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T18:52:23.972Z,1535050343.972 [Default:CheckIn:C.Wait] Stopped
2018-08-23T18:52:23.972Z,1535050343.972 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T18:52:23.972Z,1535050343.972 [Default:CheckIn:D] Running Loop=1
2018-08-23T18:52:24.372Z,1535050344.372 [Default:CheckIn:D] Stopped
2018-08-23T18:52:24.372Z,1535050344.372 [Default:CheckIn:E] Running Loop=1
2018-08-23T18:52:24.767Z,1535050344.767 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 99.220085 min 
2018-08-23T18:52:24.768Z,1535050344.768 [Default:CheckIn:E] Stopped
2018-08-23T18:52:24.768Z,1535050344.768 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T18:52:24.768Z,1535050344.768 [Default:CheckIn] Stopped
2018-08-23T18:52:24.768Z,1535050344.768 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T18:52:24.768Z,1535050344.768 [Default:CheckIn](INFO): Running loop #17
2018-08-23T18:52:24.769Z,1535050344.769 [Default:CheckIn] Running Loop=17
2018-08-23T18:52:24.769Z,1535050344.769 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T18:52:24.769Z,1535050344.769 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T18:52:28.637Z,1535050348.637 [NAL9602](INFO): Powering up
2018-08-23T18:52:39.546Z,1535050359.546 [NAL9602](INFO): NAL9602 initialized
2018-08-23T18:52:56.344Z,1535050376.344 [NAL9602](INFO): SBD MO Status=0, MOMSN=23475, MT Status=0, MTMSN=0
2018-08-23T18:52:56.344Z,1535050376.344 [NAL9602](INFO): No messages in MT queue
2018-08-23T18:52:57.546Z,1535050377.546 [NAL9602](INFO): GPS fix at 20180823T185232: (41.861145, -83.330357)
2018-08-23T18:52:57.600Z,1535050377.600 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T18:52:57.600Z,1535050377.600 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T18:53:03.302Z,1535050383.302 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20180823T170912/Courier0055.lzma
2018-08-23T18:53:04.099Z,1535050384.099 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0055.lzma.bak
2018-08-23T18:53:04.100Z,1535050384.100 [DataOverHttps](INFO): SBD MOMSN=8438711
2018-08-23T18:53:16.998Z,1535050396.998 [DataOverHttps](INFO): Sending 264 bytes from file Logs/20180823T170912/Express0056.lzma
2018-08-23T18:53:17.791Z,1535050397.791 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0056.lzma.bak
2018-08-23T18:53:17.792Z,1535050397.792 [DataOverHttps](INFO): SBD MOMSN=8438714
2018-08-23T18:53:19.333Z,1535050399.333 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T18:53:19.334Z,1535050399.334 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T18:53:19.334Z,1535050399.334 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T18:53:32.974Z,1535050412.974 [NAL9602](INFO): Powering down
2018-08-23T18:58:19.484Z,1535050699.484 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T18:58:19.484Z,1535050699.484 [Default:CheckIn:C.Wait] Stopped
2018-08-23T18:58:19.484Z,1535050699.484 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T18:58:19.484Z,1535050699.484 [Default:CheckIn:D] Running Loop=1
2018-08-23T18:58:19.877Z,1535050699.877 [Default:CheckIn:D] Stopped
2018-08-23T18:58:19.877Z,1535050699.877 [Default:CheckIn:E] Running Loop=1
2018-08-23T18:58:20.295Z,1535050700.295 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 105.145166 min 
2018-08-23T18:58:20.295Z,1535050700.295 [Default:CheckIn:E] Stopped
2018-08-23T18:58:20.296Z,1535050700.296 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T18:58:20.296Z,1535050700.296 [Default:CheckIn] Stopped
2018-08-23T18:58:20.296Z,1535050700.296 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T18:58:20.296Z,1535050700.296 [Default:CheckIn](INFO): Running loop #18
2018-08-23T18:58:20.296Z,1535050700.296 [Default:CheckIn] Running Loop=18
2018-08-23T18:58:20.297Z,1535050700.297 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T18:58:20.297Z,1535050700.297 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T18:58:23.726Z,1535050703.726 [NAL9602](INFO): Powering up
2018-08-23T18:58:34.922Z,1535050714.922 [NAL9602](INFO): NAL9602 initialized
2018-08-23T18:58:59.308Z,1535050739.308 [NAL9602](INFO): SBD MO Status=2, MOMSN=23476, MT Status=2, MTMSN=0
2018-08-23T18:58:59.308Z,1535050739.308 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-23T18:59:10.508Z,1535050750.508 [NAL9602](INFO): SBD MO Status=0, MOMSN=23476, MT Status=0, MTMSN=0
2018-08-23T18:59:10.508Z,1535050750.508 [NAL9602](INFO): No messages in MT queue
2018-08-23T18:59:11.718Z,1535050751.718 [NAL9602](INFO): GPS fix at 20180823T185845: (41.880380, -83.296737)
2018-08-23T18:59:11.820Z,1535050751.820 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T18:59:11.857Z,1535050751.857 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T18:59:19.542Z,1535050759.542 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20180823T170912/Courier0058.lzma
2018-08-23T18:59:20.339Z,1535050760.339 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0058.lzma.bak
2018-08-23T18:59:20.340Z,1535050760.340 [DataOverHttps](INFO): SBD MOMSN=8438722
2018-08-23T18:59:34.121Z,1535050774.121 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20180823T170912/Express0059.lzma
2018-08-23T18:59:34.915Z,1535050774.915 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0059.lzma.bak
2018-08-23T18:59:34.916Z,1535050774.916 [DataOverHttps](INFO): SBD MOMSN=8438725
2018-08-23T18:59:36.562Z,1535050776.562 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T18:59:36.562Z,1535050776.562 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T18:59:36.563Z,1535050776.563 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T18:59:43.794Z,1535050783.794 [NAL9602](INFO): Powering down
2018-08-23T19:01:42.222Z,1535050902.222 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T19:01:42.222Z,1535050902.222 [Rowe_600LCM] No Fault, FailCount= 5
2018-08-23T19:01:42.525Z,1535050902.525 [Rowe_600LCM](INFO): Initializing
2018-08-23T19:01:42.525Z,1535050902.525 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T19:01:42.526Z,1535050902.526 [Rowe_600LCM](INFO): LCM OK
2018-08-23T19:01:42.526Z,1535050902.526 [Rowe_600LCM](INFO): Powering up
2018-08-23T19:01:46.727Z,1535050906.727 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T19:01:46.837Z,1535050906.837 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T19:01:46.838Z,1535050906.838 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T19:01:46.839Z,1535050906.839 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T19:01:46.840Z,1535050906.840 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T19:03:42.944Z,1535051022.944 [DataOverHttps](IMPORTANT): SBD MTMSN=20180823T190317
2018-08-23T19:03:42.953Z,1535051022.953 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T19:03:42.953Z,1535051022.953 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-08-23T19:03:42.953Z,1535051022.953 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T19:03:43.043Z,1535051023.043 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T19:03:43.357Z,1535051023.357 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T19:03:43.542Z,1535051023.542 [Rowe_600LCM](INFO): Powering down
2018-08-23T19:03:46.981Z,1535051026.981 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T19:03:46.981Z,1535051026.981 [Rowe_600LCM] No Fault, FailCount= 1
2018-08-23T19:03:47.177Z,1535051027.177 [Rowe_600LCM](INFO): Initializing
2018-08-23T19:03:47.177Z,1535051027.177 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T19:03:47.178Z,1535051027.178 [Rowe_600LCM](INFO): LCM OK
2018-08-23T19:03:47.178Z,1535051027.178 [Rowe_600LCM](INFO): Powering up
2018-08-23T19:03:47.394Z,1535051027.394 [DataOverHttps](INFO): Received command:configSet Express linearApprox height_above_sea_floor 2 meter persist
2018-08-23T19:03:48.310Z,1535051028.310 [CommandLine](IMPORTANT): got command configSet Express linearApproximation height_above_sea_floor 2.000000 meter persist
2018-08-23T19:03:51.488Z,1535051031.488 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T19:03:51.574Z,1535051031.574 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T19:03:51.575Z,1535051031.575 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T19:03:51.576Z,1535051031.576 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T19:03:51.576Z,1535051031.576 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T19:04:36.917Z,1535051076.917 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T19:04:36.917Z,1535051076.917 [Default:CheckIn:C.Wait] Stopped
2018-08-23T19:04:36.917Z,1535051076.917 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T19:04:36.918Z,1535051076.918 [Default:CheckIn:D] Running Loop=1
2018-08-23T19:04:37.281Z,1535051077.281 [Default:CheckIn:D] Stopped
2018-08-23T19:04:37.281Z,1535051077.281 [Default:CheckIn:E] Running Loop=1
2018-08-23T19:04:37.671Z,1535051077.671 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 111.435238 min 
2018-08-23T19:04:37.671Z,1535051077.671 [Default:CheckIn:E] Stopped
2018-08-23T19:04:37.671Z,1535051077.671 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T19:04:37.672Z,1535051077.672 [Default:CheckIn] Stopped
2018-08-23T19:04:37.672Z,1535051077.672 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T19:04:37.672Z,1535051077.672 [Default:CheckIn](INFO): Running loop #19
2018-08-23T19:04:37.672Z,1535051077.672 [Default:CheckIn] Running Loop=19
2018-08-23T19:04:37.672Z,1535051077.672 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T19:04:37.672Z,1535051077.672 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T19:04:38.426Z,1535051078.426 [NAL9602](INFO): Powering up
2018-08-23T19:04:49.591Z,1535051089.591 [NAL9602](INFO): NAL9602 initialized
2018-08-23T19:05:16.792Z,1535051116.792 [NAL9602](INFO): SBD MO Status=2, MOMSN=23477, MT Status=2, MTMSN=0
2018-08-23T19:05:16.792Z,1535051116.792 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-23T19:05:28.796Z,1535051128.796 [NAL9602](INFO): SBD MO Status=2, MOMSN=23477, MT Status=2, MTMSN=0
2018-08-23T19:05:28.796Z,1535051128.796 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-23T19:05:39.992Z,1535051139.992 [NAL9602](INFO): SBD MO Status=0, MOMSN=23477, MT Status=0, MTMSN=0
2018-08-23T19:05:39.992Z,1535051139.992 [NAL9602](INFO): No messages in MT queue
2018-08-23T19:05:47.339Z,1535051147.339 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T19:05:47.339Z,1535051147.339 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-08-23T19:05:47.339Z,1535051147.339 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T19:05:47.741Z,1535051147.741 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T19:05:47.922Z,1535051147.922 [Rowe_600LCM](INFO): Powering down
2018-08-23T19:05:49.182Z,1535051149.182 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T19:05:49.182Z,1535051149.182 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T19:05:49.182Z,1535051149.182 [Rowe_600LCM] No Fault, FailCount= 2
2018-08-23T19:05:49.549Z,1535051149.549 [Rowe_600LCM](INFO): Initializing
2018-08-23T19:05:49.549Z,1535051149.549 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T19:05:49.550Z,1535051149.550 [Rowe_600LCM](INFO): LCM OK
2018-08-23T19:05:49.550Z,1535051149.550 [Rowe_600LCM](INFO): Powering up
2018-08-23T19:05:51.211Z,1535051151.211 [NAL9602](INFO): GPS fix at 20180823T190524: (41.899112, -83.259893)
2018-08-23T19:05:51.264Z,1535051151.264 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T19:05:51.264Z,1535051151.264 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T19:05:53.780Z,1535051153.780 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T19:05:53.858Z,1535051153.858 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T19:05:53.859Z,1535051153.859 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T19:05:53.859Z,1535051153.859 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T19:05:53.860Z,1535051153.860 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T19:06:00.635Z,1535051160.635 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20180823T170912/Courier0061.lzma
2018-08-23T19:06:01.429Z,1535051161.429 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0061.lzma.bak
2018-08-23T19:06:01.429Z,1535051161.429 [DataOverHttps](INFO): SBD MOMSN=8438731
2018-08-23T19:06:13.104Z,1535051173.104 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180823T170912/Courier0064.lzma
2018-08-23T19:06:13.900Z,1535051173.900 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0064.lzma.bak
2018-08-23T19:06:13.900Z,1535051173.900 [DataOverHttps](INFO): SBD MOMSN=8438734
2018-08-23T19:06:28.363Z,1535051188.363 [NAL9602](INFO): Powering down
2018-08-23T19:06:28.887Z,1535051188.887 [DataOverHttps](INFO): Sending 327 bytes from file Logs/20180823T170912/Express0062.lzma
2018-08-23T19:06:29.684Z,1535051189.684 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0062.lzma.bak
2018-08-23T19:06:29.684Z,1535051189.684 [DataOverHttps](INFO): SBD MOMSN=8438736
2018-08-23T19:06:42.738Z,1535051202.738 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180823T170912/Express0065.lzma
2018-08-23T19:06:43.536Z,1535051203.536 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0065.lzma.bak
2018-08-23T19:06:43.536Z,1535051203.536 [DataOverHttps](INFO): SBD MOMSN=8438743
2018-08-23T19:06:45.332Z,1535051205.332 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T19:06:45.332Z,1535051205.332 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T19:06:45.332Z,1535051205.332 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T19:07:31.752Z,1535051251.752 [BPC1](FAULT): Failed to receive data from all sticks prior to timeout. Missing data from 31 sticks.
2018-08-23T19:07:31.752Z,1535051251.752 [BPC1] Data Fault, FailCount= 1
2018-08-23T19:07:31.752Z,1535051251.752 [BPC1](ERROR): Data Fault
2018-08-23T19:07:31.832Z,1535051251.832 [CBIT](ERROR): Data Fault in component: BPC1
2018-08-23T19:07:32.975Z,1535051252.975 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-23T19:07:32.975Z,1535051252.975 [BPC1] No Fault, FailCount= 1
2018-08-23T19:07:49.712Z,1535051269.712 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T19:07:49.712Z,1535051269.712 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-08-23T19:07:49.712Z,1535051269.712 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T19:07:50.107Z,1535051270.107 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T19:07:50.117Z,1535051270.117 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T19:07:50.419Z,1535051270.419 [Rowe_600LCM](INFO): Powering down
2018-08-23T19:07:51.843Z,1535051271.843 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T19:07:51.844Z,1535051271.844 [Rowe_600LCM] No Fault, FailCount= 3
2018-08-23T19:07:52.035Z,1535051272.035 [Rowe_600LCM](INFO): Initializing
2018-08-23T19:07:52.035Z,1535051272.035 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T19:07:52.036Z,1535051272.036 [Rowe_600LCM](INFO): LCM OK
2018-08-23T19:07:52.036Z,1535051272.036 [Rowe_600LCM](INFO): Powering up
2018-08-23T19:07:56.275Z,1535051276.275 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T19:07:56.336Z,1535051276.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-08-23T19:07:56.337Z,1535051276.337 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T19:07:56.338Z,1535051276.338 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T19:07:56.338Z,1535051276.338 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T19:09:52.293Z,1535051392.293 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T19:09:52.293Z,1535051392.293 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-08-23T19:09:52.293Z,1535051392.293 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T19:09:52.351Z,1535051392.351 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T19:09:52.697Z,1535051392.697 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T19:09:52.852Z,1535051392.852 [Rowe_600LCM](INFO): Powering down
2018-08-23T19:09:54.468Z,1535051394.468 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T19:09:54.468Z,1535051394.468 [Rowe_600LCM] No Fault, FailCount= 4
2018-08-23T19:09:54.469Z,1535051394.469 [Rowe_600LCM](INFO): Initializing
2018-08-23T19:09:54.470Z,1535051394.470 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T19:09:54.470Z,1535051394.470 [Rowe_600LCM](INFO): LCM OK
2018-08-23T19:09:54.470Z,1535051394.470 [Rowe_600LCM](INFO): Powering up
2018-08-23T19:09:58.599Z,1535051398.599 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T19:09:58.659Z,1535051398.659 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T19:09:58.660Z,1535051398.660 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T19:09:58.661Z,1535051398.661 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T19:09:58.662Z,1535051398.662 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T19:11:45.671Z,1535051505.671 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T19:11:45.672Z,1535051505.672 [Default:CheckIn:C.Wait] Stopped
2018-08-23T19:11:45.672Z,1535051505.672 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T19:11:45.672Z,1535051505.672 [Default:CheckIn:D] Running Loop=1
2018-08-23T19:11:46.063Z,1535051506.063 [Default:CheckIn:D] Stopped
2018-08-23T19:11:46.063Z,1535051506.063 [Default:CheckIn:E] Running Loop=1
2018-08-23T19:11:50.955Z,1535051510.955 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 118.581592 min 
2018-08-23T19:11:50.956Z,1535051510.956 [Default:CheckIn:E] Stopped
2018-08-23T19:11:50.956Z,1535051510.956 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T19:11:50.957Z,1535051510.957 [Default:CheckIn] Stopped
2018-08-23T19:11:50.957Z,1535051510.957 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T19:11:50.958Z,1535051510.958 [Default:CheckIn](INFO): Running loop #20
2018-08-23T19:11:50.958Z,1535051510.958 [Default:CheckIn] Running Loop=20
2018-08-23T19:11:50.958Z,1535051510.958 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T19:11:50.959Z,1535051510.959 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T19:11:51.433Z,1535051511.433 [NAL9602](INFO): Powering up
2018-08-23T19:11:54.481Z,1535051514.481 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T19:11:54.481Z,1535051514.481 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-08-23T19:11:54.481Z,1535051514.481 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T19:11:54.733Z,1535051514.733 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T19:11:54.734Z,1535051514.734 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-08-23T19:11:54.885Z,1535051514.885 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T19:11:54.975Z,1535051514.975 [Rowe_600LCM](INFO): Powering down
2018-08-23T19:12:02.627Z,1535051522.627 [NAL9602](INFO): NAL9602 initialized
2018-08-23T19:12:18.228Z,1535051538.228 [NAL9602](INFO): SBD MO Status=0, MOMSN=23478, MT Status=0, MTMSN=0
2018-08-23T19:12:18.228Z,1535051538.228 [NAL9602](INFO): No messages in MT queue
2018-08-23T19:13:03.498Z,1535051583.498 [NAL9602](INFO): GPS fix at 20180823T191236: (41.914125, -83.228719)
2018-08-23T19:13:03.566Z,1535051583.566 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T19:13:03.566Z,1535051583.566 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T19:13:09.746Z,1535051589.746 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20180823T170912/Courier0067.lzma
2018-08-23T19:13:10.490Z,1535051590.490 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0067.lzma.bak
2018-08-23T19:13:10.490Z,1535051590.490 [DataOverHttps](INFO): SBD MOMSN=8438746
2018-08-23T19:13:23.646Z,1535051603.646 [DataOverHttps](INFO): Sending 321 bytes from file Logs/20180823T170912/Express0068.lzma
2018-08-23T19:13:24.444Z,1535051604.444 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0068.lzma.bak
2018-08-23T19:13:24.444Z,1535051604.444 [DataOverHttps](INFO): SBD MOMSN=8438749
2018-08-23T19:13:26.338Z,1535051606.338 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T19:13:26.338Z,1535051606.338 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T19:13:26.338Z,1535051606.338 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T19:13:35.538Z,1535051615.538 [NAL9602](INFO): Powering down
2018-08-23T19:18:26.748Z,1535051906.748 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T19:18:26.749Z,1535051906.749 [Default:CheckIn:C.Wait] Stopped
2018-08-23T19:18:26.749Z,1535051906.749 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T19:18:26.749Z,1535051906.749 [Default:CheckIn:D] Running Loop=1
2018-08-23T19:18:27.136Z,1535051907.136 [Default:CheckIn:D] Stopped
2018-08-23T19:18:27.136Z,1535051907.136 [Default:CheckIn:E] Running Loop=1
2018-08-23T19:18:27.542Z,1535051907.542 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.266154 min 
2018-08-23T19:18:27.542Z,1535051907.542 [Default:CheckIn:E] Stopped
2018-08-23T19:18:27.542Z,1535051907.542 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T19:18:27.542Z,1535051907.542 [Default:CheckIn] Stopped
2018-08-23T19:18:27.542Z,1535051907.542 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T19:18:27.543Z,1535051907.543 [Default:CheckIn](INFO): Running loop #21
2018-08-23T19:18:27.543Z,1535051907.543 [Default:CheckIn] Running Loop=21
2018-08-23T19:18:27.543Z,1535051907.543 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T19:18:27.543Z,1535051907.543 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T19:18:31.392Z,1535051911.392 [NAL9602](INFO): Powering up
2018-08-23T19:18:42.302Z,1535051922.302 [NAL9602](INFO): NAL9602 initialized
2018-08-23T19:18:55.903Z,1535051935.903 [NAL9602](INFO): SBD MO Status=0, MOMSN=23479, MT Status=0, MTMSN=0
2018-08-23T19:18:55.903Z,1535051935.903 [NAL9602](INFO): No messages in MT queue
2018-08-23T19:20:32.397Z,1535052032.397 [NAL9602](INFO): GPS fix at 20180823T192004: (41.915161, -83.226790)
2018-08-23T19:20:32.440Z,1535052032.440 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T19:20:32.440Z,1535052032.440 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T19:20:38.645Z,1535052038.645 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20180823T170912/Courier0070.lzma
2018-08-23T19:20:39.443Z,1535052039.443 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0070.lzma.bak
2018-08-23T19:20:39.444Z,1535052039.444 [DataOverHttps](INFO): SBD MOMSN=8438758
2018-08-23T19:20:46.923Z,1535052046.923 [PNI_TCM](FAULT): Failed to acquire valid data within timeout.
2018-08-23T19:20:46.923Z,1535052046.923 [PNI_TCM] Data Fault, FailCount= 1
2018-08-23T19:20:46.923Z,1535052046.923 [PNI_TCM](ERROR): Data Fault
2018-08-23T19:20:46.948Z,1535052046.948 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 4.908551 seconds old.
2018-08-23T19:20:46.964Z,1535052046.964 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-08-23T19:20:47.056Z,1535052047.056 [PNI_TCM](INFO): Powering down
2018-08-23T19:20:47.165Z,1535052047.165 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 5.125438 seconds old.
2018-08-23T19:20:47.418Z,1535052047.418 [PNI_TCM](FAULT): LCB fault:  Software Overcurrent.
2018-08-23T19:20:47.418Z,1535052047.418 [PNI_TCM] Hardware Fault, FailCount= 1
2018-08-23T19:20:47.419Z,1535052047.419 [PNI_TCM](ERROR): Hardware Fault
2018-08-23T19:20:47.452Z,1535052047.452 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 5.412490 seconds old.
2018-08-23T19:20:47.819Z,1535052047.819 [PNI_TCM](FAULT): LCB fault:  Software Overcurrent.
2018-08-23T19:20:47.851Z,1535052047.851 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 5.811015 seconds old.
2018-08-23T19:20:48.258Z,1535052048.258 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 6.218034 seconds old.
2018-08-23T19:20:48.316Z,1535052048.316 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-08-23T19:20:48.316Z,1535052048.316 [PNI_TCM] No Fault, FailCount= 1
2018-08-23T19:20:48.624Z,1535052048.624 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 6.584225 seconds old.
2018-08-23T19:20:49.036Z,1535052049.036 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 6.995858 seconds old.
2018-08-23T19:20:52.507Z,1535052052.507 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 10.466656 seconds old.
2018-08-23T19:20:52.618Z,1535052052.618 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 10.577971 seconds old.
2018-08-23T19:20:52.934Z,1535052052.934 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20180823T170912/Express0071.lzma
2018-08-23T19:20:52.976Z,1535052052.976 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 10.935962 seconds old.
2018-08-23T19:20:53.382Z,1535052053.382 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 11.341952 seconds old.
2018-08-23T19:20:53.732Z,1535052053.732 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0071.lzma.bak
2018-08-23T19:20:53.732Z,1535052053.732 [DataOverHttps](INFO): SBD MOMSN=8438762
2018-08-23T19:20:53.768Z,1535052053.768 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 11.727738 seconds old.
2018-08-23T19:20:55.442Z,1535052055.442 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 13.402194 seconds old.
2018-08-23T19:20:55.458Z,1535052055.458 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T19:20:55.458Z,1535052055.458 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T19:20:55.458Z,1535052055.458 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T19:21:04.284Z,1535052064.284 [NAL9602](INFO): Powering down
2018-08-23T19:21:54.763Z,1535052114.763 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T19:21:54.764Z,1535052114.764 [Rowe_600LCM] No Fault, FailCount= 5
2018-08-23T19:21:54.978Z,1535052114.978 [Rowe_600LCM](INFO): Initializing
2018-08-23T19:21:54.978Z,1535052114.978 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T19:21:54.978Z,1535052114.978 [Rowe_600LCM](INFO): LCM OK
2018-08-23T19:21:54.979Z,1535052114.979 [Rowe_600LCM](INFO): Powering up
2018-08-23T19:21:59.168Z,1535052119.168 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T19:21:59.267Z,1535052119.267 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T19:21:59.268Z,1535052119.268 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T19:21:59.269Z,1535052119.269 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T19:21:59.270Z,1535052119.270 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T19:23:55.187Z,1535052235.187 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T19:23:55.187Z,1535052235.187 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-08-23T19:23:55.188Z,1535052235.188 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T19:23:55.349Z,1535052235.349 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T19:23:55.589Z,1535052235.589 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T19:23:55.881Z,1535052235.881 [Rowe_600LCM](INFO): Powering down
2018-08-23T19:24:00.096Z,1535052240.096 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T19:24:00.096Z,1535052240.096 [Rowe_600LCM] No Fault, FailCount= 1
2018-08-23T19:24:00.325Z,1535052240.325 [Rowe_600LCM](INFO): Initializing
2018-08-23T19:24:00.325Z,1535052240.325 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T19:24:00.326Z,1535052240.326 [Rowe_600LCM](INFO): LCM OK
2018-08-23T19:24:00.326Z,1535052240.326 [Rowe_600LCM](INFO): Powering up
2018-08-23T19:24:04.449Z,1535052244.449 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T19:24:04.559Z,1535052244.559 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T19:24:04.560Z,1535052244.560 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T19:24:04.561Z,1535052244.561 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T19:24:04.562Z,1535052244.562 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T19:25:55.958Z,1535052355.958 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-23T19:25:55.958Z,1535052355.958 [Default:CheckIn:C.Wait] Stopped
2018-08-23T19:25:55.958Z,1535052355.958 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-23T19:25:55.958Z,1535052355.958 [Default:CheckIn:D] Running Loop=1
2018-08-23T19:25:56.320Z,1535052356.320 [Default:CheckIn:D] Stopped
2018-08-23T19:25:56.320Z,1535052356.320 [Default:CheckIn:E] Running Loop=1
2018-08-23T19:25:56.699Z,1535052356.699 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 132.752547 min 
2018-08-23T19:25:56.699Z,1535052356.699 [Default:CheckIn:E] Stopped
2018-08-23T19:25:56.699Z,1535052356.699 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-23T19:25:56.699Z,1535052356.699 [Default:CheckIn] Stopped
2018-08-23T19:25:56.699Z,1535052356.699 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-23T19:25:56.700Z,1535052356.700 [Default:CheckIn](INFO): Running loop #22
2018-08-23T19:25:56.700Z,1535052356.700 [Default:CheckIn] Running Loop=22
2018-08-23T19:25:56.700Z,1535052356.700 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-23T19:25:56.700Z,1535052356.700 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-23T19:25:57.442Z,1535052357.442 [NAL9602](INFO): Powering up
2018-08-23T19:26:00.797Z,1535052360.797 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T19:26:00.797Z,1535052360.797 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-08-23T19:26:00.797Z,1535052360.797 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T19:26:01.201Z,1535052361.201 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T19:26:01.350Z,1535052361.350 [Rowe_600LCM](INFO): Powering down
2018-08-23T19:26:02.268Z,1535052362.268 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T19:26:02.795Z,1535052362.795 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T19:26:02.795Z,1535052362.795 [Rowe_600LCM] No Fault, FailCount= 2
2018-08-23T19:26:02.965Z,1535052362.965 [Rowe_600LCM](INFO): Initializing
2018-08-23T19:26:02.965Z,1535052362.965 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T19:26:02.966Z,1535052362.966 [Rowe_600LCM](INFO): LCM OK
2018-08-23T19:26:02.966Z,1535052362.966 [Rowe_600LCM](INFO): Powering up
2018-08-23T19:26:07.180Z,1535052367.180 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T19:26:07.288Z,1535052367.288 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T19:26:07.290Z,1535052367.290 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T19:26:07.291Z,1535052367.291 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T19:26:07.292Z,1535052367.292 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T19:26:08.283Z,1535052368.283 [NAL9602](INFO): NAL9602 initialized
2018-08-23T19:26:28.284Z,1535052388.284 [NAL9602](INFO): SBD MO Status=0, MOMSN=23480, MT Status=0, MTMSN=0
2018-08-23T19:26:28.284Z,1535052388.284 [NAL9602](INFO): No messages in MT queue
2018-08-23T19:27:02.615Z,1535052422.615 [NAL9602](INFO): GPS fix at 20180823T192634: (41.915751, -83.225770)
2018-08-23T19:27:02.678Z,1535052422.678 [Default:CheckIn:Read_GPS] Stopped
2018-08-23T19:27:02.678Z,1535052422.678 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-23T19:27:09.160Z,1535052429.160 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20180823T170912/Courier0073.lzma
2018-08-23T19:27:09.953Z,1535052429.953 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Courier0073.lzma.bak
2018-08-23T19:27:09.953Z,1535052429.953 [DataOverHttps](INFO): SBD MOMSN=8438765
2018-08-23T19:27:25.082Z,1535052445.082 [DataOverHttps](INFO): Sending 285 bytes from file Logs/20180823T170912/Express0074.lzma
2018-08-23T19:27:25.848Z,1535052445.848 [DataOverHttps](INFO): Moved sent file to Logs/20180823T170912/Express0074.lzma.bak
2018-08-23T19:27:25.848Z,1535052445.848 [DataOverHttps](INFO): SBD MOMSN=8438768
2018-08-23T19:27:27.879Z,1535052447.879 [Default:CheckIn:Read_Iridium] Stopped
2018-08-23T19:27:27.879Z,1535052447.879 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-23T19:27:27.880Z,1535052447.880 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-23T19:27:34.777Z,1535052454.777 [NAL9602](INFO): Powering down
2018-08-23T19:28:03.191Z,1535052483.191 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-23T19:28:03.191Z,1535052483.191 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-08-23T19:28:03.191Z,1535052483.191 [Rowe_600LCM](ERROR): Communications Fault
2018-08-23T19:28:03.276Z,1535052483.276 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-23T19:28:03.593Z,1535052483.593 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-23T19:28:03.767Z,1535052483.767 [Rowe_600LCM](INFO): Powering down
2018-08-23T19:28:05.257Z,1535052485.257 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-23T19:28:05.257Z,1535052485.257 [Rowe_600LCM] No Fault, FailCount= 3
2018-08-23T19:28:05.381Z,1535052485.381 [Rowe_600LCM](INFO): Initializing
2018-08-23T19:28:05.382Z,1535052485.382 [Rowe_600LCM](INFO): Checking LCM
2018-08-23T19:28:05.382Z,1535052485.382 [Rowe_600LCM](INFO): LCM OK
2018-08-23T19:28:05.382Z,1535052485.382 [Rowe_600LCM](INFO): Powering up
2018-08-23T19:28:09.510Z,1535052489.510 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-23T19:28:09.659Z,1535052489.659 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-23T19:28:09.660Z,1535052489.660 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-23T19:28:09.661Z,1535052489.661 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-23T19:28:09.662Z,1535052489.662 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-23T19:28:34.074Z,1535052514.074 [BPC1](FAULT): Failed to receive data from all sticks prior to timeout. Missing data from 15 sticks.
2018-08-23T19:28:34.075Z,1535052514.075 [BPC1] Data Fault, FailCount= 2
2018-08-23T19:28:34.075Z,1535052514.075 [BPC1](ERROR): Data Fault
2018-08-23T19:28:34.192Z,1535052514.192 [CBIT](ERROR): Data Fault in component: BPC1
2018-08-23T19:28:35.312Z,1535052515.312 [CBIT](INFO): Clearing failed state for component BPC1
2018-08-23T19:28:35.312Z,1535052515.312 [BPC1] No Fault, FailCount= 2
2018-08-23T19:29:33.623Z,1535052573.623 [DataOverHttps](IMPORTANT): SBD MTMSN=20180823T192905