2018-08-20T20:09:08.105Z,1534795748.105 [Supervisor](DEBUG): Initializing supervisor.
2018-08-20T20:09:08.108Z,1534795748.108 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-08-20T20:09:08.108Z,1534795748.108 [SyncHandler](INFO): Protected caller Thread ID is 797
2018-08-20T20:09:08.109Z,1534795748.109 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-08-20T20:09:08.110Z,1534795748.110 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-08-20T20:09:08.110Z,1534795748.110 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 798
2018-08-20T20:09:08.113Z,1534795748.113 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-08-20T20:09:08.125Z,1534795748.125 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-08-20T20:09:08.126Z,1534795748.126 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-08-20T20:09:08.127Z,1534795748.127 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 799
2018-08-20T20:09:08.127Z,1534795748.127 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-08-20T20:09:08.128Z,1534795748.128 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-08-20T20:09:08.129Z,1534795748.129 [logger ThreadHandler](INFO): Protected caller Thread ID is 800
2018-08-20T20:09:08.131Z,1534795748.131 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-08-20T20:09:08.131Z,1534795748.131 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-08-20T20:09:08.135Z,1534795748.135 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-08-20T20:09:08.510Z,1534795748.510 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-08-20T20:09:08.511Z,1534795748.511 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-08-20T20:09:08.739Z,1534795748.739 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-08-20T20:09:08.740Z,1534795748.740 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-08-20T20:09:09.056Z,1534795749.056 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-08-20T20:09:09.058Z,1534795749.058 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-08-20T20:09:09.207Z,1534795749.207 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-08-20T20:09:09.209Z,1534795749.209 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-08-20T20:09:09.311Z,1534795749.311 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-08-20T20:09:09.313Z,1534795749.313 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-08-20T20:09:09.826Z,1534795749.826 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-08-20T20:09:09.828Z,1534795749.828 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-08-20T20:09:10.301Z,1534795750.301 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-08-20T20:09:10.303Z,1534795750.303 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-08-20T20:09:10.823Z,1534795750.823 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-08-20T20:09:10.824Z,1534795750.824 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-08-20T20:09:10.934Z,1534795750.934 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-08-20T20:09:10.935Z,1534795750.935 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-08-20T20:09:11.036Z,1534795751.036 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-08-20T20:09:11.037Z,1534795751.037 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-08-20T20:09:11.260Z,1534795751.260 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-08-20T20:09:11.262Z,1534795751.262 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-08-20T20:09:11.490Z,1534795751.490 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-08-20T20:09:11.491Z,1534795751.491 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-08-20T20:09:11.935Z,1534795751.935 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-08-20T20:09:11.936Z,1534795751.936 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-08-20T20:09:12.800Z,1534795752.800 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-08-20T20:09:12.800Z,1534795752.800 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-08-20T20:09:12.886Z,1534795752.886 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-08-20T20:09:12.888Z,1534795752.888 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-08-20T20:09:12.999Z,1534795752.999 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-08-20T20:09:13.127Z,1534795753.127 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-08-20T20:09:13.226Z,1534795753.226 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-08-20T20:09:13.315Z,1534795753.315 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-08-20T20:09:13.487Z,1534795753.487 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-08-20T20:09:13.682Z,1534795753.682 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-08-20T20:09:13.759Z,1534795753.759 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-08-20T20:09:14.003Z,1534795754.003 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-08-20T20:09:14.004Z,1534795754.004 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-08-20T20:09:14.090Z,1534795754.090 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-08-20T20:09:14.183Z,1534795754.183 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-08-20T20:09:14.290Z,1534795754.290 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-08-20T20:09:14.425Z,1534795754.425 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-08-20T20:09:14.434Z,1534795754.434 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-08-20T20:09:14.721Z,1534795754.721 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-08-20T20:09:14.722Z,1534795754.722 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-08-20T20:09:14.778Z,1534795754.778 [DepthRateCalculator] Loaded
2018-08-20T20:09:14.778Z,1534795754.778 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-08-20T20:09:14.785Z,1534795754.785 [PitchRateCalculator] Loaded
2018-08-20T20:09:14.785Z,1534795754.785 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-08-20T20:09:14.801Z,1534795754.801 [SpeedCalculator] Loaded
2018-08-20T20:09:14.802Z,1534795754.802 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-08-20T20:09:14.824Z,1534795754.824 [TempGradientCalculator] Loaded
2018-08-20T20:09:14.825Z,1534795754.825 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-08-20T20:09:14.841Z,1534795754.841 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-08-20T20:09:14.841Z,1534795754.841 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-08-20T20:09:14.847Z,1534795754.847 [YawRateCalculator] Loaded
2018-08-20T20:09:14.847Z,1534795754.847 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-08-20T20:09:14.888Z,1534795754.888 [ElevatorOffsetCalculator] Loaded
2018-08-20T20:09:14.888Z,1534795754.888 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-08-20T20:09:14.888Z,1534795754.888 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-08-20T20:09:14.890Z,1534795754.890 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-08-20T20:09:15.012Z,1534795755.012 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-08-20T20:09:15.013Z,1534795755.013 [StratificationFrontDetector](DEBUG): (re)initializing
2018-08-20T20:09:15.013Z,1534795755.013 [StratificationFrontDetector] Loaded
2018-08-20T20:09:15.013Z,1534795755.013 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-08-20T20:09:15.014Z,1534795755.014 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-08-20T20:09:15.016Z,1534795755.016 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-08-20T20:09:15.151Z,1534795755.151 [BuoyancyServo] Loaded
2018-08-20T20:09:15.151Z,1534795755.151 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-08-20T20:09:15.166Z,1534795755.166 [ElevatorServo] Loaded
2018-08-20T20:09:15.167Z,1534795755.167 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-08-20T20:09:15.182Z,1534795755.182 [MassServo] Loaded
2018-08-20T20:09:15.182Z,1534795755.182 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-08-20T20:09:15.198Z,1534795755.198 [RudderServo] Loaded
2018-08-20T20:09:15.198Z,1534795755.198 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-08-20T20:09:15.213Z,1534795755.213 [ThrusterServo] Loaded
2018-08-20T20:09:15.213Z,1534795755.213 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-08-20T20:09:15.213Z,1534795755.213 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-08-20T20:09:15.215Z,1534795755.215 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-08-20T20:09:15.239Z,1534795755.239 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-08-20T20:09:15.240Z,1534795755.240 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-08-20T20:09:15.367Z,1534795755.367 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-08-20T20:09:15.369Z,1534795755.369 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-08-20T20:09:15.939Z,1534795755.939 [DataOverHttps] Loaded
2018-08-20T20:09:15.939Z,1534795755.939 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-08-20T20:09:15.953Z,1534795755.953 [Depth_Keller] Loaded
2018-08-20T20:09:15.953Z,1534795755.953 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-08-20T20:09:15.959Z,1534795755.959 [DropWeight] Loaded
2018-08-20T20:09:15.959Z,1534795755.959 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-08-20T20:09:16.061Z,1534795756.061 [NAL9602] Loaded
2018-08-20T20:09:16.061Z,1534795756.061 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-08-20T20:09:16.078Z,1534795756.078 [Onboard] Loaded
2018-08-20T20:09:16.078Z,1534795756.078 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-08-20T20:09:16.089Z,1534795756.089 [Radio_Surface] Loaded
2018-08-20T20:09:16.089Z,1534795756.089 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-08-20T20:09:16.090Z,1534795756.090 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408854E0
2018-08-20T20:09:16.091Z,1534795756.091 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 882
2018-08-20T20:09:16.244Z,1534795756.244 [PNI_TCM] Loaded
2018-08-20T20:09:16.245Z,1534795756.245 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-08-20T20:09:16.307Z,1534795756.307 [Rowe_600LCM] Loaded
2018-08-20T20:09:16.307Z,1534795756.307 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-08-20T20:09:16.308Z,1534795756.308 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 408B54E0
2018-08-20T20:09:16.308Z,1534795756.308 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 883
2018-08-20T20:09:18.108Z,1534795758.108 [BPC1] Loaded
2018-08-20T20:09:18.108Z,1534795758.108 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-08-20T20:09:18.109Z,1534795758.109 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-08-20T20:09:18.110Z,1534795758.110 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-08-20T20:09:18.699Z,1534795758.699 [SBIT](DEBUG): Construct Startup Built In Test.
2018-08-20T20:09:18.724Z,1534795758.724 [SBIT] Loaded
2018-08-20T20:09:18.724Z,1534795758.724 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-08-20T20:09:18.725Z,1534795758.725 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-08-20T20:09:18.737Z,1534795758.737 [IBIT] Loaded
2018-08-20T20:09:18.737Z,1534795758.737 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-08-20T20:09:18.740Z,1534795758.740 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-08-20T20:09:18.984Z,1534795758.984 [CBIT] Loaded
2018-08-20T20:09:18.984Z,1534795758.984 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-08-20T20:09:18.985Z,1534795758.985 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-08-20T20:09:18.987Z,1534795758.987 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-08-20T20:09:19.178Z,1534795759.178 [Aanderaa_O2] Loaded
2018-08-20T20:09:19.178Z,1534795759.178 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-08-20T20:09:19.257Z,1534795759.257 [CTD_NeilBrown] Loaded
2018-08-20T20:09:19.258Z,1534795759.258 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2018-08-20T20:09:19.259Z,1534795759.259 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409794E0
2018-08-20T20:09:19.259Z,1534795759.259 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 884
2018-08-20T20:09:19.311Z,1534795759.311 [CTD_Seabird] Loaded
2018-08-20T20:09:19.312Z,1534795759.312 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-08-20T20:09:19.313Z,1534795759.313 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409A94E0
2018-08-20T20:09:19.313Z,1534795759.313 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 885
2018-08-20T20:09:19.328Z,1534795759.328 [PAR_Licor] Loaded
2018-08-20T20:09:19.329Z,1534795759.329 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-08-20T20:09:19.379Z,1534795759.379 [WetLabsBB2FL] Loaded
2018-08-20T20:09:19.380Z,1534795759.380 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-08-20T20:09:19.381Z,1534795759.381 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409D94E0
2018-08-20T20:09:19.381Z,1534795759.381 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 886
2018-08-20T20:09:19.382Z,1534795759.382 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-08-20T20:09:19.382Z,1534795759.382 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-08-20T20:09:19.472Z,1534795759.472 [VerticalControl](DEBUG): Construct VerticalControl.
2018-08-20T20:09:19.557Z,1534795759.557 [VerticalControl] Loaded
2018-08-20T20:09:19.558Z,1534795759.558 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-08-20T20:09:19.558Z,1534795759.558 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-08-20T20:09:19.618Z,1534795759.618 [HorizontalControl] Loaded
2018-08-20T20:09:19.618Z,1534795759.618 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-08-20T20:09:19.619Z,1534795759.619 [SpeedControl](DEBUG): Construct SpeedControl.
2018-08-20T20:09:19.621Z,1534795759.621 [SpeedControl] Loaded
2018-08-20T20:09:19.621Z,1534795759.621 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-08-20T20:09:19.622Z,1534795759.622 [LoopControl](DEBUG): Construct LoopControl.
2018-08-20T20:09:19.622Z,1534795759.622 [LoopControl] Loaded
2018-08-20T20:09:19.623Z,1534795759.623 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-08-20T20:09:19.623Z,1534795759.623 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-08-20T20:09:19.625Z,1534795759.625 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-08-20T20:09:19.664Z,1534795759.664 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-08-20T20:09:19.664Z,1534795759.664 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-08-20T20:09:19.772Z,1534795759.772 [DeadReckonUsingSpeedCalculator] Loaded
2018-08-20T20:09:19.773Z,1534795759.773 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-08-20T20:09:19.790Z,1534795759.790 [NavChart] Loaded
2018-08-20T20:09:19.790Z,1534795759.790 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-08-20T20:09:19.794Z,1534795759.794 [UniversalFixResidualReporter] Loaded
2018-08-20T20:09:19.794Z,1534795759.794 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-08-20T20:09:19.795Z,1534795759.795 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-08-20T20:09:19.799Z,1534795759.799 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-08-20T20:09:19.800Z,1534795759.800 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-08-20T20:09:19.806Z,1534795759.806 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-08-20T20:09:19.807Z,1534795759.807 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A654E0
2018-08-20T20:09:19.808Z,1534795759.808 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 887
2018-08-20T20:09:19.812Z,1534795759.812 [Supervisor](INFO): Main Thread ID is 796
2018-08-20T20:09:19.813Z,1534795759.813 [Supervisor](DEBUG): Running supervisor.
2018-08-20T20:09:19.813Z,1534795759.813 [CommandLine ThreadHandler](INFO): Handler Thread ID is 888
2018-08-20T20:09:19.816Z,1534795759.816 [controlThread ThreadHandler](INFO): Handler Thread ID is 889
2018-08-20T20:09:19.816Z,1534795759.816 [controlThread](DEBUG): Initializing ControlThread
2018-08-20T20:09:19.817Z,1534795759.817 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-08-20T20:09:19.817Z,1534795759.817 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-08-20T20:09:19.818Z,1534795759.818 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-08-20T20:09:19.818Z,1534795759.818 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-08-20T20:09:19.819Z,1534795759.819 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-08-20T20:09:19.819Z,1534795759.819 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-08-20T20:09:19.820Z,1534795759.820 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-08-20T20:09:19.827Z,1534795759.827 [SBIT](INFO): Initialize SBIT Component.
2018-08-20T20:09:19.828Z,1534795759.828 [SBIT](IMPORTANT): git: 2018-08-20
2018-08-20T20:09:19.828Z,1534795759.828 [SBIT](INFO): git hash: 695b514009632b0c9b638e65628c1e5f155de51b
2018-08-20T20:09:19.828Z,1534795759.828 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-08-20T20:09:19.830Z,1534795759.830 [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-20T20:09:19.831Z,1534795759.831 [SBIT](INFO): Beginning SBIT in 23.000000 seconds.
2018-08-20T20:09:19.831Z,1534795759.831 [IBIT](INFO): Initialize IBIT Component.
2018-08-20T20:09:19.832Z,1534795759.832 [CBIT](DEBUG): Initialize CBIT Component.
2018-08-20T20:09:19.833Z,1534795759.833 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-08-20T20:09:19.834Z,1534795759.834 [logger ThreadHandler](INFO): Handler Thread ID is 890
2018-08-20T20:09:19.853Z,1534795759.853 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 891
2018-08-20T20:09:19.859Z,1534795759.859 [Radio_Surface](INFO): Powering up
2018-08-20T20:09:19.865Z,1534795759.865 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 892
2018-08-20T20:09:19.866Z,1534795759.866 [Rowe_600LCM](INFO): Initializing
2018-08-20T20:09:19.866Z,1534795759.866 [Rowe_600LCM](INFO): Checking LCM
2018-08-20T20:09:19.945Z,1534795759.945 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-08-20T20:09:19.947Z,1534795759.947 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-08-20T20:09:19.948Z,1534795759.948 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-08-20T20:09:19.948Z,1534795759.948 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-08-20T20:09:19.949Z,1534795759.949 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-20T20:09:19.950Z,1534795759.950 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-20T20:09:19.950Z,1534795759.950 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-20T20:09:19.951Z,1534795759.951 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-08-20T20:09:19.951Z,1534795759.951 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-08-20T20:09:19.969Z,1534795759.969 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-08-20T20:09:19.980Z,1534795759.980 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 893
2018-08-20T20:09:19.981Z,1534795759.981 [CTD_NeilBrown](INFO): Powering down
2018-08-20T20:09:20.121Z,1534795760.121 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 894
2018-08-20T20:09:20.122Z,1534795760.122 [CTD_Seabird](INFO): Initializing
2018-08-20T20:09:20.122Z,1534795760.122 [CTD_Seabird](INFO): Checking LCM
2018-08-20T20:09:20.125Z,1534795760.125 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 895
2018-08-20T20:09:20.130Z,1534795760.130 [WetLabsBB2FL](INFO): Powering down
2018-08-20T20:09:20.219Z,1534795760.219 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 896
2018-08-20T20:09:20.227Z,1534795760.227 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-08-20T20:09:20.227Z,1534795760.227 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-08-20T20:09:20.227Z,1534795760.227 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-08-20T20:09:20.227Z,1534795760.227 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-08-20T20:09:20.227Z,1534795760.227 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-08-20T20:09:20.228Z,1534795760.228 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-08-20T20:09:20.228Z,1534795760.228 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-08-20T20:09:20.228Z,1534795760.228 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-08-20T20:09:20.228Z,1534795760.228 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-08-20T20:09:20.228Z,1534795760.228 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-08-20T20:09:20.229Z,1534795760.229 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-08-20T20:09:20.229Z,1534795760.229 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-08-20T20:09:20.229Z,1534795760.229 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-08-20T20:09:20.229Z,1534795760.229 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-08-20T20:09:20.229Z,1534795760.229 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-08-20T20:09:20.230Z,1534795760.230 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-08-20T20:09:20.231Z,1534795760.231 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-08-20T20:09:20.300Z,1534795760.300 [CTD_Seabird](INFO): LCM OK
2018-08-20T20:09:20.301Z,1534795760.301 [CTD_Seabird](INFO): Powering up
2018-08-20T20:09:20.301Z,1534795760.301 [Rowe_600LCM](INFO): LCM OK
2018-08-20T20:09:20.301Z,1534795760.301 [Rowe_600LCM](INFO): Powering up
2018-08-20T20:09:20.302Z,1534795760.302 [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-20T20:09:20.303Z,1534795760.303 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-08-20T20:09:20.374Z,1534795760.374 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-08-20T20:09:20.375Z,1534795760.375 [Default:A.Wait](DEBUG): Construct Wait.
2018-08-20T20:09:20.393Z,1534795760.393 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-08-20T20:09:20.424Z,1534795760.424 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-08-20T20:09:20.427Z,1534795760.427 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-08-20T20:09:20.452Z,1534795760.452 [Default:E.Execute](DEBUG): Construct Execute.
2018-08-20T20:09:20.464Z,1534795760.464 [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-20T20:09:20.485Z,1534795760.485 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,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-20T20:09:20.514Z,1534795760.514 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-08-20T20:09:20.543Z,1534795760.543 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2018-08-20T20:09:20.814Z,1534795760.814 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-08-20T20:09:20.929Z,1534795760.929 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-20T20:09:21.149Z,1534795761.149 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-08-20T20:09:21.158Z,1534795761.158 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-08-20T20:09:21.177Z,1534795761.177 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-08-20T20:09:21.185Z,1534795761.185 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-08-20T20:09:21.207Z,1534795761.207 [MassServo](DEBUG): Initializing EZServoServo.
2018-08-20T20:09:21.213Z,1534795761.213 [MassServo](DEBUG): Initializing MassServo.
2018-08-20T20:09:21.235Z,1534795761.235 [RudderServo](DEBUG): Initializing EZServoServo.
2018-08-20T20:09:21.241Z,1534795761.241 [RudderServo](DEBUG): Initializing RudderServo.
2018-08-20T20:09:21.248Z,1534795761.248 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-08-20T20:09:21.253Z,1534795761.253 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-08-20T20:09:21.633Z,1534795761.633 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-20T20:09:21.810Z,1534795761.810 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-20T20:09:22.369Z,1534795762.369 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-20T20:09:22.729Z,1534795762.729 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-20T20:09:23.118Z,1534795763.118 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-20T20:09:23.561Z,1534795763.561 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-20T20:09:24.037Z,1534795764.037 [Aanderaa_O2](INFO): Powering down
2018-08-20T20:09:24.108Z,1534795764.108 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-20T20:09:24.238Z,1534795764.238 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-20T20:09:24.379Z,1534795764.379 [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-20T20:09:24.528Z,1534795764.528 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-20T20:09:24.530Z,1534795764.530 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-20T20:09:24.530Z,1534795764.530 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-20T20:09:25.604Z,1534795765.604 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-08-20T20:09:25.794Z,1534795765.794 [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-20T20:09:25.796Z,1534795765.796 [CTD_Seabird](INFO): LCM subscribed to channel:seabird_gpctd_t.seabird-gpctd
2018-08-20T20:09:26.753Z,1534795766.753 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-08-20T20:09:26.753Z,1534795766.753 [CTD_Seabird](INFO): Powering down
2018-08-20T20:09:43.440Z,1534795783.440 [SBIT](IMPORTANT): Beginning Startup BIT
2018-08-20T20:09:43.453Z,1534795783.453 [CBIT](IMPORTANT): Beginning ground fault scan
2018-08-20T20:09:46.412Z,1534795786.412 [NAL9602](INFO): Powering up NAL9602
2018-08-20T20:09:54.543Z,1534795794.543 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.006292
CHAN A1 (24V): 4.657929
CHAN A2 (12V): -0.001865
CHAN A3 (5V): 4.753929
CHAN B0 (3.3V): 0.001680
CHAN B1 (3.15aV): -0.000470
CHAN B2 (3.15bV): -0.000395
CHAN B3 (GND): 0.000290
OPEN: -0.000420
Full Scale Calc: 4.765 mA, -1.589 mA
2018-08-20T20:09:57.603Z,1534795797.603 [NAL9602](INFO): NAL9602 initialized
2018-08-20T20:10:15.846Z,1534795815.846 [NAL9602](INFO): SBD MO Status=0, MOMSN=8048, MT Status=0, MTMSN=0
2018-08-20T20:10:15.846Z,1534795815.846 [NAL9602](INFO): No messages in MT queue
2018-08-20T20:10:26.443Z,1534795826.443 [NAL9602](INFO): GPS fix at 20180820T201024: (36.802726, -121.786885)
2018-08-20T20:10:37.328Z,1534795837.328 [SBIT](IMPORTANT): SBIT PASSED
2018-08-20T20:10:37.407Z,1534795837.407 [CommandLine](IMPORTANT): got command configSet list
2018-08-20T20:10:37.407Z,1534795837.407 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-08-20T20:10:37.408Z,1534795837.408 [CommandLine](IMPORTANT): CBIT.stopDepth=215 meter;

2018-08-20T20:10:37.710Z,1534795837.710 [MissionManager](IMPORTANT): Started mission Startup
2018-08-20T20:10:37.710Z,1534795837.710 [Startup] Running Loop=1
2018-08-20T20:10:37.711Z,1534795837.711 [Startup](DEBUG): Aggregate::initialize Startup
2018-08-20T20:10:37.711Z,1534795837.711 [Startup:A.GoToSurface] Running Loop=1
2018-08-20T20:10:37.711Z,1534795837.711 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-20T20:10:37.712Z,1534795837.712 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-20T20:10:37.712Z,1534795837.712 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-20T20:10:37.713Z,1534795837.713 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-20T20:10:37.714Z,1534795837.714 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-20T20:10:37.714Z,1534795837.714 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-20T20:10:37.739Z,1534795837.739 [Startup:StartupSatComms] Running Loop=1
2018-08-20T20:10:37.739Z,1534795837.739 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-08-20T20:10:37.739Z,1534795837.739 [Startup:StartupSatComms:A] Running Loop=1
2018-08-20T20:10:38.135Z,1534795838.135 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-08-20T20:10:39.621Z,1534795839.621 [NAL9602](INFO): GPS fix at 20180820T201037: (36.802752, -121.786951)
2018-08-20T20:10:39.771Z,1534795839.771 [Startup:StartupSatComms:A] Stopped
2018-08-20T20:10:39.771Z,1534795839.771 [Startup:StartupSatComms:B] Running Loop=1
2018-08-20T20:10:40.147Z,1534795840.147 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-08-20T20:10:55.470Z,1534795855.470 [NAL9602](INFO): SBD MO Status=1, MOMSN=8049, MT Status=0, MTMSN=0
2018-08-20T20:10:55.525Z,1534795855.525 [NAL9602](INFO): Sent 232 bytes from file Logs/20180820T190131/Courier0022.lzma
2018-08-20T20:10:55.526Z,1534795855.526 [NAL9602](INFO): Packets left to send: 0
2018-08-20T20:10:55.528Z,1534795855.528 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180820T190131/Courier0022.lzma.parts/0000.sbd
2018-08-20T20:10:55.528Z,1534795855.528 [NAL9602](DEBUG): Completed sending Logs/20180820T190131/Courier0022.lzma
2018-08-20T20:11:05.569Z,1534795865.569 [NAL9602](INFO): SBD MO Status=1, MOMSN=8050, MT Status=0, MTMSN=0
2018-08-20T20:11:05.623Z,1534795865.623 [NAL9602](INFO): Sent 214 bytes from file Logs/20180820T200908/Courier0000.lzma
2018-08-20T20:11:05.623Z,1534795865.623 [NAL9602](INFO): Packets left to send: 0
2018-08-20T20:11:05.625Z,1534795865.625 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180820T200908/Courier0000.lzma.parts/0000.sbd
2018-08-20T20:11:05.626Z,1534795865.626 [NAL9602](DEBUG): Completed sending Logs/20180820T200908/Courier0000.lzma
2018-08-20T20:11:13.281Z,1534795873.281 [NAL9602](INFO): SBD MO Status=1, MOMSN=8051, MT Status=0, MTMSN=0
2018-08-20T20:11:13.334Z,1534795873.334 [NAL9602](INFO): Sent 332 bytes from file Logs/20180820T190131/Express0023.lzma
2018-08-20T20:11:13.334Z,1534795873.334 [NAL9602](INFO): Packets left to send: 3
2018-08-20T20:11:13.336Z,1534795873.336 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180820T190131/Express0023.lzma.parts/0003.sbd
2018-08-20T20:11:20.857Z,1534795880.857 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-20T20:11:20.857Z,1534795880.857 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-08-20T20:11:20.857Z,1534795880.857 [Rowe_600LCM](ERROR): Communications Fault
2018-08-20T20:11:21.130Z,1534795881.130 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-20T20:11:21.263Z,1534795881.263 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-20T20:11:21.395Z,1534795881.395 [Rowe_600LCM](INFO): Powering down
2018-08-20T20:11:22.711Z,1534795882.711 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-20T20:11:22.711Z,1534795882.711 [Rowe_600LCM] No Fault, FailCount= 1
2018-08-20T20:11:23.009Z,1534795883.009 [Rowe_600LCM](INFO): Initializing
2018-08-20T20:11:23.009Z,1534795883.009 [Rowe_600LCM](INFO): Checking LCM
2018-08-20T20:11:23.010Z,1534795883.010 [Rowe_600LCM](INFO): LCM OK
2018-08-20T20:11:23.010Z,1534795883.010 [Rowe_600LCM](INFO): Powering up
2018-08-20T20:11:25.428Z,1534795885.428 [NAL9602](INFO): SBD MO Status=1, MOMSN=8052, MT Status=0, MTMSN=0
2018-08-20T20:11:25.478Z,1534795885.478 [NAL9602](INFO): Sent 332 bytes from file Logs/20180820T190131/Express0023.lzma
2018-08-20T20:11:25.479Z,1534795885.479 [NAL9602](INFO): Packets left to send: 2
2018-08-20T20:11:25.480Z,1534795885.480 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180820T190131/Express0023.lzma.parts/0002.sbd
2018-08-20T20:11:27.142Z,1534795887.142 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-20T20:11:27.215Z,1534795887.215 [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-20T20:11:27.217Z,1534795887.217 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-20T20:11:27.217Z,1534795887.217 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-20T20:11:27.218Z,1534795887.218 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-20T20:11:37.225Z,1534795897.225 [NAL9602](INFO): SBD MO Status=1, MOMSN=8053, MT Status=0, MTMSN=0
2018-08-20T20:11:37.273Z,1534795897.273 [NAL9602](INFO): Sent 332 bytes from file Logs/20180820T190131/Express0023.lzma
2018-08-20T20:11:37.273Z,1534795897.273 [NAL9602](INFO): Packets left to send: 1
2018-08-20T20:11:37.275Z,1534795897.275 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180820T190131/Express0023.lzma.parts/0001.sbd
2018-08-20T20:11:40.685Z,1534795900.685 [Startup:StartupSatComms:B](INFO): Timed out from 2018-08-20T20:10:39.8Z
2018-08-20T20:11:40.685Z,1534795900.685 [Startup:StartupSatComms:B] Stopped
2018-08-20T20:11:40.686Z,1534795900.686 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-08-20T20:11:40.686Z,1534795900.686 [Startup:StartupSatComms] Stopped
2018-08-20T20:11:40.686Z,1534795900.686 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-08-20T20:11:40.687Z,1534795900.687 [Startup](INFO): Completed Startup
2018-08-20T20:11:40.687Z,1534795900.687 [MissionManager](INFO): Startup is completed.
2018-08-20T20:11:40.687Z,1534795900.687 [MissionManager](INFO): Uninitializing Mission Startup
2018-08-20T20:11:40.688Z,1534795900.688 [Startup] Stopped
2018-08-20T20:11:40.688Z,1534795900.688 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-08-20T20:11:40.688Z,1534795900.688 [Startup:A.GoToSurface] Stopped
2018-08-20T20:11:40.688Z,1534795900.688 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-08-20T20:11:40.844Z,1534795900.844 [MissionManager](IMPORTANT): Started mission Default
2018-08-20T20:11:40.844Z,1534795900.844 [Default] Running Loop=1
2018-08-20T20:11:40.844Z,1534795900.844 [Default](DEBUG): Aggregate::initialize Default
2018-08-20T20:11:40.849Z,1534795900.849 [Default:B.GoToSurface] Running Loop=1
2018-08-20T20:11:40.849Z,1534795900.849 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-20T20:11:40.849Z,1534795900.849 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-20T20:11:40.850Z,1534795900.850 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-20T20:11:40.850Z,1534795900.850 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-20T20:11:40.851Z,1534795900.851 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-20T20:11:40.851Z,1534795900.851 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-20T20:11:40.851Z,1534795900.851 [Default:A.Wait] Running Loop=1
2018-08-20T20:11:40.851Z,1534795900.851 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-08-20T20:11:45.546Z,1534795905.546 [NAL9602](INFO): SBD MO Status=1, MOMSN=8054, MT Status=0, MTMSN=0
2018-08-20T20:11:45.593Z,1534795905.593 [NAL9602](INFO): Sent 151 bytes from file Logs/20180820T190131/Express0023.lzma
2018-08-20T20:11:45.594Z,1534795905.594 [NAL9602](INFO): Packets left to send: 0
2018-08-20T20:11:45.595Z,1534795905.595 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180820T190131/Express0023.lzma.parts/0000.sbd
2018-08-20T20:11:45.595Z,1534795905.595 [NAL9602](DEBUG): Completed sending Logs/20180820T190131/Express0023.lzma
2018-08-20T20:11:54.011Z,1534795914.011 [Default:A.Wait](INFO): Done Waiting.
2018-08-20T20:11:54.011Z,1534795914.011 [Default:A.Wait] Stopped
2018-08-20T20:11:54.012Z,1534795914.012 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-08-20T20:11:54.402Z,1534795914.402 [Default:CheckIn] Running Loop=1
2018-08-20T20:11:54.402Z,1534795914.402 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-20T20:11:54.402Z,1534795914.402 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-20T20:11:54.807Z,1534795914.807 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-08-20T20:11:56.356Z,1534795916.356 [NAL9602](INFO): GPS fix at 20180820T201154: (36.802755, -121.786942)
2018-08-20T20:11:56.429Z,1534795916.429 [Default:CheckIn:Read_GPS] Stopped
2018-08-20T20:11:56.429Z,1534795916.429 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-20T20:11:56.816Z,1534795916.816 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-08-20T20:12:12.512Z,1534795932.512 [NAL9602](INFO): SBD MO Status=1, MOMSN=8055, MT Status=0, MTMSN=0
2018-08-20T20:12:12.569Z,1534795932.569 [NAL9602](INFO): Sent 230 bytes from file Logs/20180820T200908/Courier0004.lzma
2018-08-20T20:12:12.570Z,1534795932.570 [NAL9602](INFO): Packets left to send: 0
2018-08-20T20:12:12.571Z,1534795932.571 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180820T200908/Courier0004.lzma.parts/0000.sbd
2018-08-20T20:12:12.572Z,1534795932.572 [NAL9602](DEBUG): Completed sending Logs/20180820T200908/Courier0004.lzma
2018-08-20T20:12:23.064Z,1534795943.064 [NAL9602](INFO): SBD MO Status=1, MOMSN=8056, MT Status=0, MTMSN=0
2018-08-20T20:12:23.117Z,1534795943.117 [NAL9602](INFO): Sent 332 bytes from file Logs/20180820T200908/Express0001.lzma
2018-08-20T20:12:23.117Z,1534795943.117 [NAL9602](INFO): Packets left to send: 2
2018-08-20T20:12:23.119Z,1534795943.119 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180820T200908/Express0001.lzma.parts/0002.sbd
2018-08-20T20:12:31.577Z,1534795951.577 [NAL9602](INFO): SBD MO Status=1, MOMSN=8057, MT Status=0, MTMSN=0
2018-08-20T20:12:31.631Z,1534795951.631 [NAL9602](INFO): Sent 332 bytes from file Logs/20180820T200908/Express0001.lzma
2018-08-20T20:12:31.632Z,1534795951.632 [NAL9602](INFO): Packets left to send: 1
2018-08-20T20:12:31.633Z,1534795951.633 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180820T200908/Express0001.lzma.parts/0001.sbd
2018-08-20T20:12:39.608Z,1534795959.608 [NAL9602](INFO): SBD MO Status=1, MOMSN=8058, MT Status=0, MTMSN=0
2018-08-20T20:12:39.657Z,1534795959.657 [NAL9602](INFO): Sent 17 bytes from file Logs/20180820T200908/Express0001.lzma
2018-08-20T20:12:39.657Z,1534795959.657 [NAL9602](INFO): Packets left to send: 0
2018-08-20T20:12:39.659Z,1534795959.659 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180820T200908/Express0001.lzma.parts/0000.sbd
2018-08-20T20:12:39.659Z,1534795959.659 [NAL9602](DEBUG): Completed sending Logs/20180820T200908/Express0001.lzma
2018-08-20T20:12:54.780Z,1534795974.780 [NAL9602](INFO): SBD MO Status=1, MOMSN=8059, MT Status=0, MTMSN=0
2018-08-20T20:12:54.829Z,1534795974.829 [NAL9602](INFO): Sent 199 bytes from file Logs/20180820T200908/Express0005.lzma
2018-08-20T20:12:54.830Z,1534795974.830 [NAL9602](INFO): Packets left to send: 0
2018-08-20T20:12:54.831Z,1534795974.831 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180820T200908/Express0005.lzma.parts/0000.sbd
2018-08-20T20:12:54.832Z,1534795974.832 [NAL9602](DEBUG): Completed sending Logs/20180820T200908/Express0005.lzma
2018-08-20T20:13:09.528Z,1534795989.528 [NAL9602](INFO): SBD MO Status=2, MOMSN=8060, MT Status=2, MTMSN=0
2018-08-20T20:13:09.528Z,1534795989.528 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-20T20:13:21.018Z,1534796001.018 [NAL9602](INFO): SBD MO Status=0, MOMSN=8060, MT Status=0, MTMSN=0
2018-08-20T20:13:21.163Z,1534796001.163 [Default:CheckIn:Read_Iridium] Stopped
2018-08-20T20:13:21.163Z,1534796001.163 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-20T20:13:21.163Z,1534796001.163 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-20T20:13:23.593Z,1534796003.593 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-20T20:13:23.593Z,1534796003.593 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-08-20T20:13:23.593Z,1534796003.593 [Rowe_600LCM](ERROR): Communications Fault
2018-08-20T20:13:23.847Z,1534796003.847 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-20T20:13:23.997Z,1534796003.997 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-20T20:13:24.365Z,1534796004.365 [Rowe_600LCM](INFO): Powering down
2018-08-20T20:13:25.173Z,1534796005.173 [Rowe_600LCM](FAULT): LCB fault:  Software Overcurrent.
2018-08-20T20:13:25.173Z,1534796005.173 [Rowe_600LCM] Hardware Fault, FailCount= 2
2018-08-20T20:13:25.174Z,1534796005.174 [Rowe_600LCM](ERROR): Hardware Fault
2018-08-20T20:13:25.791Z,1534796005.791 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-20T20:13:25.791Z,1534796005.791 [Rowe_600LCM] No Fault, FailCount= 2
2018-08-20T20:13:25.981Z,1534796005.981 [Rowe_600LCM](INFO): Initializing
2018-08-20T20:13:25.981Z,1534796005.981 [Rowe_600LCM](INFO): Checking LCM
2018-08-20T20:13:25.982Z,1534796005.982 [Rowe_600LCM](INFO): LCM OK
2018-08-20T20:13:25.982Z,1534796005.982 [Rowe_600LCM](INFO): Powering up
2018-08-20T20:13:30.159Z,1534796010.159 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-20T20:13:30.292Z,1534796010.292 [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-20T20:13:30.293Z,1534796010.293 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-20T20:13:30.293Z,1534796010.293 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-20T20:13:30.294Z,1534796010.294 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-20T20:13:39.883Z,1534796019.883 [CommandLine](IMPORTANT): got command failComponent
2018-08-20T20:13:39.883Z,1534796019.883 [CommandLine](IMPORTANT): Failed components:
2018-08-20T20:13:39.884Z,1534796019.884 [CommandLine](IMPORTANT): No failed Components.
2018-08-20T20:13:46.068Z,1534796026.068 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004921
2018-08-20T20:13:47.465Z,1534796027.465 [CommandLine](IMPORTANT): got command ibit
2018-08-20T20:13:47.734Z,1534796027.734 [IBIT](IMPORTANT): Beginning Initiated BIT
2018-08-20T20:13:47.734Z,1534796027.734 [IBIT](IMPORTANT): Beginning control surface checks.
2018-08-20T20:13:47.737Z,1534796027.737 [CBIT](IMPORTANT): Beginning ground fault scan
2018-08-20T20:13:49.276Z,1534796029.276 [NAL9602](INFO): GPS fix at 20180820T201347: (36.802765, -121.786935)
2018-08-20T20:13:52.080Z,1534796032.080 [NAL9602](INFO): GPS fix at 20180820T201350: (36.802766, -121.786936)
2018-08-20T20:13:55.291Z,1534796035.291 [NAL9602](INFO): GPS fix at 20180820T201353: (36.802767, -121.786939)
2018-08-20T20:13:58.091Z,1534796038.091 [NAL9602](INFO): GPS fix at 20180820T201356: (36.802767, -121.786940)
2018-08-20T20:13:58.609Z,1534796038.609 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.128803
CHAN A1 (24V): 4.657929
CHAN A2 (12V): -0.002824
CHAN A3 (5V): -0.001969
CHAN B0 (3.3V): 0.000261
CHAN B1 (3.15aV): -0.000569
CHAN B2 (3.15bV): -0.000419
CHAN B3 (GND): 0.000300
OPEN: -0.000350
Full Scale Calc: 4.765 mA, -1.589 mA
2018-08-20T20:14:01.291Z,1534796041.291 [NAL9602](INFO): GPS fix at 20180820T201359: (36.802766, -121.786941)
2018-08-20T20:14:04.091Z,1534796044.091 [NAL9602](INFO): GPS fix at 20180820T201402: (36.802765, -121.786941)
2018-08-20T20:14:07.300Z,1534796047.300 [NAL9602](INFO): GPS fix at 20180820T201405: (36.802764, -121.786942)
2018-08-20T20:14:10.108Z,1534796050.108 [NAL9602](INFO): GPS fix at 20180820T201408: (36.802765, -121.786943)
2018-08-20T20:14:13.295Z,1534796053.295 [NAL9602](INFO): GPS fix at 20180820T201411: (36.802765, -121.786945)
2018-08-20T20:14:16.095Z,1534796056.095 [NAL9602](INFO): GPS fix at 20180820T201414: (36.802766, -121.786947)
2018-08-20T20:14:19.207Z,1534796059.207 [CommandLine](IMPORTANT): got command show variable NAL
2018-08-20T20:14:19.217Z,1534796059.217 [CommandLine](IMPORTANT): LoopControl.nominalDt (second)
2018-08-20T20:14:19.227Z,1534796059.227 [CommandLine](IMPORTANT): ExternalSim.loadAtStartup (bool)
2018-08-20T20:14:19.228Z,1534796059.228 [CommandLine](IMPORTANT): ExternalSim.SimDaemonServer (none)
2018-08-20T20:14:19.228Z,1534796059.228 [CommandLine](IMPORTANT): InternalSim.loadAtStartup (bool)
2018-08-20T20:14:19.295Z,1534796059.295 [NAL9602](INFO): GPS fix at 20180820T201417: (36.802767, -121.786947)
2018-08-20T20:14:19.356Z,1534796059.356 [CommandLine](IMPORTANT): NAL9602.gpsFailTimeout (minute)
2018-08-20T20:14:19.381Z,1534796059.381 [CommandLine](IMPORTANT): NAL9602.iridiumMTQueueTimeout (minute)
2018-08-20T20:14:19.381Z,1534796059.381 [CommandLine](IMPORTANT): NAL9602.requestGGA (bool)
2018-08-20T20:14:19.382Z,1534796059.382 [CommandLine](IMPORTANT): NAL9602.loadAtStartup (bool)
2018-08-20T20:14:19.382Z,1534796059.382 [CommandLine](IMPORTANT): NAL9602.simulateHardware (bool)
2018-08-20T20:14:19.383Z,1534796059.383 [CommandLine](IMPORTANT): NAL9602.power (watt)
2018-08-20T20:14:19.383Z,1534796059.383 [CommandLine](IMPORTANT): NAL9602.power_platform_communications (watt)
2018-08-20T20:14:19.418Z,1534796059.418 [CommandLine](IMPORTANT): NAL9602.loadControl (none)
2018-08-20T20:14:19.418Z,1534796059.418 [CommandLine](IMPORTANT): NAL9602.uart (none)
2018-08-20T20:14:19.418Z,1534796059.418 [CommandLine](IMPORTANT): NAL9602.baud (bit_per_second)
2018-08-20T20:14:19.530Z,1534796059.530 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_0 (count)
2018-08-20T20:14:19.531Z,1534796059.531 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_1 (count)
2018-08-20T20:14:19.531Z,1534796059.531 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_2 (count)
2018-08-20T20:14:19.532Z,1534796059.532 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_3 (count)
2018-08-20T20:14:19.532Z,1534796059.532 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_4 (count)
2018-08-20T20:14:19.551Z,1534796059.551 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_5 (count)
2018-08-20T20:14:19.551Z,1534796059.551 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_6 (count)
2018-08-20T20:14:19.552Z,1534796059.552 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_7 (count)
2018-08-20T20:14:19.552Z,1534796059.552 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_8 (count)
2018-08-20T20:14:19.553Z,1534796059.553 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_9 (count)
2018-08-20T20:14:19.553Z,1534796059.553 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_10 (count)
2018-08-20T20:14:19.554Z,1534796059.554 [CommandLine](IMPORTANT): NAL9602.SNRSatellite_11 (count)
2018-08-20T20:14:19.554Z,1534796059.554 [CommandLine](IMPORTANT): NAL9602.goodFix (bool)
2018-08-20T20:14:19.555Z,1534796059.555 [CommandLine](IMPORTANT): NAL9602.numSatellites (count)
2018-08-20T20:14:19.555Z,1534796059.555 [CommandLine](IMPORTANT): NAL9602.sigQuality (count)
2018-08-20T20:14:19.555Z,1534796059.555 [CommandLine](IMPORTANT): NAL9602.SOG (knot)
2018-08-20T20:14:19.556Z,1534796059.556 [CommandLine](IMPORTANT): NAL9602.COG (degree)
2018-08-20T20:14:19.600Z,1534796059.600 [CommandLine](IMPORTANT): NAL9602.time_fix (second)
2018-08-20T20:14:19.600Z,1534796059.600 [CommandLine](IMPORTANT): NAL9602.latitude_fix (degree)
2018-08-20T20:14:19.601Z,1534796059.601 [CommandLine](IMPORTANT): NAL9602.longitude_fix (degree)
2018-08-20T20:14:19.601Z,1534796059.601 [CommandLine](IMPORTANT): NAL9602.location_fix (degree)
2018-08-20T20:14:19.602Z,1534796059.602 [CommandLine](IMPORTANT): NAL9602.platform_communications (bool)
2018-08-20T20:14:19.742Z,1534796059.742 [CommandLine](IMPORTANT): VerticalControl.depth2buoyIntInternal (cubic_centimeter)
2018-08-20T20:14:19.743Z,1534796059.743 [CommandLine](IMPORTANT): VerticalControl.depthErrorInternal (meter)
2018-08-20T20:14:19.743Z,1534796059.743 [CommandLine](IMPORTANT): VerticalControl.depthIntegralInternal (radian)
2018-08-20T20:14:19.744Z,1534796059.744 [CommandLine](IMPORTANT): VerticalControl.dtInternal (second)
2018-08-20T20:14:19.744Z,1534796059.744 [CommandLine](IMPORTANT): VerticalControl.elevatorIntegralInternal (radian)
2018-08-20T20:14:19.754Z,1534796059.754 [CommandLine](IMPORTANT): VerticalControl.massIntegralInternal (meter)
2018-08-20T20:14:19.754Z,1534796059.754 [CommandLine](IMPORTANT): VerticalControl.massPitchErrorInternal (radian)
2018-08-20T20:14:19.755Z,1534796059.755 [CommandLine](IMPORTANT): VerticalControl.pitchInternal (radian)
2018-08-20T20:14:19.755Z,1534796059.755 [CommandLine](IMPORTANT): VerticalControl.smoothDepthInternal (meter)
2018-08-20T20:14:19.756Z,1534796059.756 [CommandLine](IMPORTANT): HorizontalControl.headingInternal (radian)
2018-08-20T20:14:19.769Z,1534796059.769 [CommandLine](IMPORTANT): HorizontalControl.smoothHeadingInternal (radian)
2018-08-20T20:14:19.773Z,1534796059.773 [CommandLine](IMPORTANT): HorizontalControl.headingIntegralInternal (radian)
2018-08-20T20:14:19.774Z,1534796059.774 [CommandLine](IMPORTANT): HorizontalControl.xteIntegralInternal (radian)
2018-08-20T20:14:19.775Z,1534796059.775 [CommandLine](IMPORTANT): HorizontalControl.xteInternal (meter)
2018-08-20T20:14:19.775Z,1534796059.775 [CommandLine](IMPORTANT): HorizontalControl.kxteInternal (radian)
2018-08-20T20:14:19.776Z,1534796059.776 [CommandLine](IMPORTANT): HorizontalControl.bearingInternal (radian)
2018-08-20T20:14:19.788Z,1534796059.788 [CommandLine](IMPORTANT): NAL9602.durationOfLastRun (second)
2018-08-20T20:14:19.854Z,1534796059.854 [CommandLine](IMPORTANT): NAL9602.component_voltage (volt)
2018-08-20T20:14:19.855Z,1534796059.855 [CommandLine](IMPORTANT): NAL9602.component_avgVoltage (volt)
2018-08-20T20:14:19.855Z,1534796059.855 [CommandLine](IMPORTANT): NAL9602.component_current (milliampere)
2018-08-20T20:14:19.856Z,1534796059.856 [CommandLine](IMPORTANT): NAL9602.component_avgCurrent (milliampere)
2018-08-20T20:14:22.096Z,1534796062.096 [NAL9602](INFO): GPS fix at 20180820T201420: (36.802767, -121.786948)
2018-08-20T20:14:22.990Z,1534796062.990 [CommandLine](INFO): End of History
2018-08-20T20:14:23.107Z,1534796063.107 [CommandLine](INFO): End of History
2018-08-20T20:14:23.261Z,1534796063.261 [CommandLine](INFO): End of History
2018-08-20T20:14:23.444Z,1534796063.444 [CommandLine](INFO): End of History
2018-08-20T20:14:23.586Z,1534796063.586 [CommandLine](INFO): End of History
2018-08-20T20:14:23.795Z,1534796063.795 [CommandLine](INFO): End of History
2018-08-20T20:14:23.992Z,1534796063.992 [CommandLine](INFO): End of History
2018-08-20T20:14:24.138Z,1534796064.138 [CommandLine](INFO): End of History
2018-08-20T20:14:25.291Z,1534796065.291 [NAL9602](INFO): GPS fix at 20180820T201423: (36.802768, -121.786948)
2018-08-20T20:14:28.119Z,1534796068.119 [NAL9602](INFO): GPS fix at 20180820T201426: (36.802769, -121.786949)
2018-08-20T20:14:31.302Z,1534796071.302 [NAL9602](INFO): GPS fix at 20180820T201429: (36.802770, -121.786949)
2018-08-20T20:14:33.797Z,1534796073.797 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 4
Latitude: 36.802769 Longitude: -121.786949
2018-08-20T20:14:34.091Z,1534796074.091 [NAL9602](INFO): GPS fix at 20180820T201432: (36.802773, -121.786949)
2018-08-20T20:14:34.187Z,1534796074.187 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 0.000000
2018-08-20T20:14:34.188Z,1534796074.188 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah
2018-08-20T20:14:34.188Z,1534796074.188 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V
2018-08-20T20:14:34.567Z,1534796074.567 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2018-08-20T20:14:34.568Z,1534796074.568 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2018-08-20T20:14:34.568Z,1534796074.568 [IBIT](IMPORTANT): Pressure:12.033130 PSI
2018-08-20T20:14:34.568Z,1534796074.568 [IBIT](IMPORTANT): Humidity:15.394945 %
2018-08-20T20:14:34.978Z,1534796074.978 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2018-08-20T20:14:34.978Z,1534796074.978 [IBIT](IMPORTANT): buoyancyNeutral: 315.000000 cc
2018-08-20T20:14:34.979Z,1534796074.979 [IBIT](IMPORTANT): massDefault: -0.075000 cm
2018-08-20T20:14:34.979Z,1534796074.979 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2018-08-20T20:14:34.979Z,1534796074.979 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2018-08-20T20:14:34.980Z,1534796074.980 [IBIT](IMPORTANT): IBIT PASSED
2018-08-20T20:15:06.850Z,1534796106.850 [NAL9602](INFO): Powering down
2018-08-20T20:15:26.597Z,1534796126.597 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-20T20:15:26.597Z,1534796126.597 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-08-20T20:15:26.597Z,1534796126.597 [Rowe_600LCM](ERROR): Communications Fault
2018-08-20T20:15:26.930Z,1534796126.930 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-20T20:15:27.001Z,1534796127.001 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-20T20:15:27.173Z,1534796127.173 [Rowe_600LCM](INFO): Powering down
2018-08-20T20:15:28.528Z,1534796128.528 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-20T20:15:28.528Z,1534796128.528 [Rowe_600LCM] No Fault, FailCount= 3
2018-08-20T20:15:28.789Z,1534796128.789 [Rowe_600LCM](INFO): Initializing
2018-08-20T20:15:28.789Z,1534796128.789 [Rowe_600LCM](INFO): Checking LCM
2018-08-20T20:15:28.790Z,1534796128.790 [Rowe_600LCM](INFO): LCM OK
2018-08-20T20:15:28.790Z,1534796128.790 [Rowe_600LCM](INFO): Powering up
2018-08-20T20:15:33.051Z,1534796133.051 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-20T20:15:33.124Z,1534796133.124 [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-20T20:15:33.125Z,1534796133.125 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-20T20:15:33.126Z,1534796133.126 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-20T20:15:33.126Z,1534796133.126 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-20T20:15:55.128Z,1534796155.128 [CommandLine](IMPORTANT): got command get BPC1.platform_battery_voltage
2018-08-20T20:15:55.128Z,1534796155.128 [CommandLine](IMPORTANT): BPC1.platform_battery_voltage 16.076693 _
2018-08-20T20:16:11.967Z,1534796171.967 [CommandLine](IMPORTANT): got command get BPC1.platform_battery_charge
2018-08-20T20:16:11.968Z,1534796171.968 [CommandLine](IMPORTANT): BPC1.platform_battery_charge 341.241007 Ah
2018-08-20T20:16:23.799Z,1534796183.799 [CommandLine](IMPORTANT): got command failComponent
2018-08-20T20:16:23.799Z,1534796183.799 [CommandLine](IMPORTANT): Failed components:
2018-08-20T20:16:23.800Z,1534796183.800 [CommandLine](IMPORTANT): No failed Components.
2018-08-20T20:17:29.561Z,1534796249.561 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-20T20:17:29.561Z,1534796249.561 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-08-20T20:17:29.561Z,1534796249.561 [Rowe_600LCM](ERROR): Communications Fault
2018-08-20T20:17:29.581Z,1534796249.581 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-20T20:17:29.965Z,1534796249.965 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-20T20:17:30.139Z,1534796250.139 [Rowe_600LCM](INFO): Powering down
2018-08-20T20:17:31.570Z,1534796251.570 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-20T20:17:31.571Z,1534796251.571 [Rowe_600LCM] No Fault, FailCount= 4
2018-08-20T20:17:31.753Z,1534796251.753 [Rowe_600LCM](INFO): Initializing
2018-08-20T20:17:31.753Z,1534796251.753 [Rowe_600LCM](INFO): Checking LCM
2018-08-20T20:17:31.754Z,1534796251.754 [Rowe_600LCM](INFO): LCM OK
2018-08-20T20:17:31.754Z,1534796251.754 [Rowe_600LCM](INFO): Powering up
2018-08-20T20:17:35.947Z,1534796255.947 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-20T20:17:36.077Z,1534796256.077 [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-20T20:17:36.078Z,1534796256.078 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-20T20:17:36.079Z,1534796256.079 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-20T20:17:36.080Z,1534796256.080 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-20T20:18:21.482Z,1534796301.482 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-20T20:18:21.482Z,1534796301.482 [Default:CheckIn:C.Wait] Stopped
2018-08-20T20:18:21.482Z,1534796301.482 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-20T20:18:21.483Z,1534796301.483 [Default:CheckIn:D] Running Loop=1
2018-08-20T20:18:21.888Z,1534796301.888 [Default:CheckIn:D] Stopped
2018-08-20T20:18:21.888Z,1534796301.888 [Default:CheckIn:E] Running Loop=1
2018-08-20T20:18:22.297Z,1534796302.297 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.684025 min 
2018-08-20T20:18:22.300Z,1534796302.300 [Default:CheckIn:E] Stopped
2018-08-20T20:18:22.300Z,1534796302.300 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-20T20:18:22.300Z,1534796302.300 [Default:CheckIn] Stopped
2018-08-20T20:18:22.300Z,1534796302.300 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-20T20:18:22.300Z,1534796302.300 [Default:CheckIn](INFO): Running loop #2
2018-08-20T20:18:22.300Z,1534796302.300 [Default:CheckIn] Running Loop=2
2018-08-20T20:18:22.309Z,1534796302.309 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-20T20:18:22.309Z,1534796302.309 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-20T20:18:23.026Z,1534796303.026 [NAL9602](INFO): Powering up
2018-08-20T20:18:34.235Z,1534796314.235 [NAL9602](INFO): NAL9602 initialized
2018-08-20T20:19:05.482Z,1534796345.482 [NAL9602](INFO): SBD MO Status=0, MOMSN=8061, MT Status=0, MTMSN=0
2018-08-20T20:19:05.483Z,1534796345.483 [NAL9602](INFO): No messages in MT queue
2018-08-20T20:19:06.679Z,1534796346.679 [NAL9602](INFO): GPS fix at 20180820T201904: (36.802754, -121.786998)
2018-08-20T20:19:06.780Z,1534796346.780 [Default:CheckIn:Read_GPS] Stopped
2018-08-20T20:19:06.780Z,1534796346.780 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-20T20:19:11.613Z,1534796351.613 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20180820T200908/Courier0007.lzma
2018-08-20T20:19:12.404Z,1534796352.404 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Courier0007.lzma.bak
2018-08-20T20:19:12.404Z,1534796352.404 [DataOverHttps](INFO): SBD MOMSN=8430505
2018-08-20T20:19:22.058Z,1534796362.058 [DataOverHttps](INFO): Sending 1614 bytes from file Logs/20180820T200908/Express0008.lzma
2018-08-20T20:19:22.836Z,1534796362.836 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Express0008.lzma.bak
2018-08-20T20:19:22.836Z,1534796362.836 [DataOverHttps](INFO): SBD MOMSN=8430508
2018-08-20T20:19:23.664Z,1534796363.664 [Default:CheckIn:Read_Iridium] Stopped
2018-08-20T20:19:23.664Z,1534796363.664 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-20T20:19:23.664Z,1534796363.664 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-20T20:19:32.441Z,1534796372.441 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-20T20:19:32.441Z,1534796372.441 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-08-20T20:19:32.441Z,1534796372.441 [Rowe_600LCM](ERROR): Communications Fault
2018-08-20T20:19:32.718Z,1534796372.718 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-20T20:19:32.719Z,1534796372.719 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-08-20T20:19:32.845Z,1534796372.845 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-20T20:19:32.959Z,1534796372.959 [Rowe_600LCM](INFO): Powering down
2018-08-20T20:19:41.838Z,1534796381.838 [NAL9602](INFO): Powering down
2018-08-20T20:23:29.091Z,1534796609.091 [DataOverHttps](IMPORTANT): SBD MTMSN=20180820T202328
2018-08-20T20:23:33.273Z,1534796613.273 [DataOverHttps](INFO): Received command:gfscan
2018-08-20T20:23:33.346Z,1534796613.346 [CommandLine](IMPORTANT): got command gfscan
2018-08-20T20:23:33.395Z,1534796613.395 [CBIT](IMPORTANT): Beginning ground fault scan
2018-08-20T20:23:44.135Z,1534796624.135 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.128553
CHAN A1 (24V): -0.009404
CHAN A2 (12V): -0.001885
CHAN A3 (5V): -0.001719
CHAN B0 (3.3V): -0.000248
CHAN B1 (3.15aV): -0.001008
CHAN B2 (3.15bV): -0.000311
CHAN B3 (GND): -0.000145
OPEN: -0.000415
Full Scale Calc: 4.765 mA, -1.589 mA
2018-08-20T20:24:24.238Z,1534796664.238 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-20T20:24:24.238Z,1534796664.238 [Default:CheckIn:C.Wait] Stopped
2018-08-20T20:24:24.238Z,1534796664.238 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-20T20:24:24.238Z,1534796664.238 [Default:CheckIn:D] Running Loop=1
2018-08-20T20:24:24.555Z,1534796664.555 [Default:CheckIn:D] Stopped
2018-08-20T20:24:24.555Z,1534796664.555 [Default:CheckIn:E] Running Loop=1
2018-08-20T20:24:24.984Z,1534796664.984 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.728510 min 
2018-08-20T20:24:24.984Z,1534796664.984 [Default:CheckIn:E] Stopped
2018-08-20T20:24:25.017Z,1534796665.017 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-20T20:24:25.017Z,1534796665.017 [Default:CheckIn] Stopped
2018-08-20T20:24:25.017Z,1534796665.017 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-20T20:24:25.017Z,1534796665.017 [Default:CheckIn](INFO): Running loop #3
2018-08-20T20:24:25.018Z,1534796665.018 [Default:CheckIn] Running Loop=3
2018-08-20T20:24:25.018Z,1534796665.018 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-20T20:24:25.018Z,1534796665.018 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-20T20:24:25.662Z,1534796665.662 [NAL9602](INFO): Powering up
2018-08-20T20:24:36.486Z,1534796676.486 [NAL9602](INFO): NAL9602 initialized
2018-08-20T20:24:50.488Z,1534796690.488 [NAL9602](INFO): SBD MO Status=0, MOMSN=8062, MT Status=0, MTMSN=0
2018-08-20T20:24:50.488Z,1534796690.488 [NAL9602](INFO): No messages in MT queue
2018-08-20T20:25:02.490Z,1534796702.490 [NAL9602](INFO): GPS fix at 20180820T202500: (36.802741, -121.786910)
2018-08-20T20:25:02.560Z,1534796702.560 [Default:CheckIn:Read_GPS] Stopped
2018-08-20T20:25:02.560Z,1534796702.560 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-20T20:25:07.466Z,1534796707.466 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20180820T200908/Courier0010.lzma
2018-08-20T20:25:08.274Z,1534796708.274 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Courier0010.lzma.bak
2018-08-20T20:25:08.274Z,1534796708.274 [DataOverHttps](INFO): SBD MOMSN=8430605
2018-08-20T20:25:17.069Z,1534796717.069 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180820T200908/Courier0013.lzma
2018-08-20T20:25:17.859Z,1534796717.859 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Courier0013.lzma.bak
2018-08-20T20:25:17.859Z,1534796717.859 [DataOverHttps](INFO): SBD MOMSN=8430608
2018-08-20T20:25:26.947Z,1534796726.947 [DataOverHttps](INFO): Sending 494 bytes from file Logs/20180820T200908/Express0011.lzma
2018-08-20T20:25:27.723Z,1534796727.723 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Express0011.lzma.bak
2018-08-20T20:25:27.723Z,1534796727.723 [DataOverHttps](INFO): SBD MOMSN=8430610
2018-08-20T20:25:37.288Z,1534796737.288 [NAL9602](INFO): Powering down
2018-08-20T20:25:37.415Z,1534796737.415 [DataOverHttps](INFO): Sending 51 bytes from file Logs/20180820T200908/Express0014.lzma
2018-08-20T20:25:38.215Z,1534796738.215 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Express0014.lzma.bak
2018-08-20T20:25:38.215Z,1534796738.215 [DataOverHttps](INFO): SBD MOMSN=8430619
2018-08-20T20:25:38.981Z,1534796738.981 [Default:CheckIn:Read_Iridium] Stopped
2018-08-20T20:25:38.981Z,1534796738.981 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-20T20:25:38.981Z,1534796738.981 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-20T20:26:43.728Z,1534796803.728 [DataOverHttps](IMPORTANT): SBD MTMSN=20180820T202642
2018-08-20T20:26:47.811Z,1534796807.811 [DataOverHttps](INFO): Received command:load Science/sci2.xml;set sci2.NeedCommsTime 45 minute;set sci2.Lat1 36.797 degree;set sci2.Lon1 -121.847 degree;set sci2.Lat2 36.750 degree;set sci2.Lon2 -122.022 degree;set sci2.YoYoMaxDepth 40 meter;run 
2018-08-20T20:26:47.837Z,1534796807.837 [CommandLine](IMPORTANT): got command load ./Missions/Science/sci2.xml
2018-08-20T20:26:47.837Z,1534796807.837 [MissionManager](INFO): Loading Mission: ./Missions/Science/sci2.xml
2018-08-20T20:26:48.001Z,1534796808.001 [MissionManager](INFO): DefineArg sci2.MissionTimeout = 2.000000 h
2018-08-20T20:26:48.004Z,1534796808.004 [MissionManager](INFO): DefineArg sci2.NeedCommsTime = 60.000000 min
2018-08-20T20:26:48.008Z,1534796808.008 [MissionManager](INFO): DefineArg sci2.Repeat = 1.000000 count
2018-08-20T20:26:48.011Z,1534796808.011 [MissionManager](INFO): DefineArg sci2.Lat1 = nan arcdeg
2018-08-20T20:26:48.014Z,1534796808.014 [MissionManager](INFO): DefineArg sci2.Lon1 = nan arcdeg
2018-08-20T20:26:48.016Z,1534796808.016 [MissionManager](INFO): DefineArg sci2.Lat2 = nan arcdeg
2018-08-20T20:26:48.019Z,1534796808.019 [MissionManager](INFO): DefineArg sci2.Lon2 = nan arcdeg
2018-08-20T20:26:48.022Z,1534796808.022 [MissionManager](INFO): DefineArg sci2.Lat3 = nan arcdeg
2018-08-20T20:26:48.025Z,1534796808.025 [MissionManager](INFO): DefineArg sci2.Lon3 = nan arcdeg
2018-08-20T20:26:48.028Z,1534796808.028 [MissionManager](INFO): DefineArg sci2.Lat4 = nan arcdeg
2018-08-20T20:26:48.031Z,1534796808.031 [MissionManager](INFO): DefineArg sci2.Lon4 = nan arcdeg
2018-08-20T20:26:48.034Z,1534796808.034 [MissionManager](INFO): DefineArg sci2.Lat5 = nan arcdeg
2018-08-20T20:26:48.081Z,1534796808.081 [MissionManager](INFO): DefineArg sci2.Lon5 = nan arcdeg
2018-08-20T20:26:48.084Z,1534796808.084 [MissionManager](INFO): DefineArg sci2.Lat6 = nan arcdeg
2018-08-20T20:26:48.087Z,1534796808.087 [MissionManager](INFO): DefineArg sci2.Lon6 = nan arcdeg
2018-08-20T20:26:48.089Z,1534796808.089 [MissionManager](INFO): DefineArg sci2.Lat7 = nan arcdeg
2018-08-20T20:26:48.092Z,1534796808.092 [MissionManager](INFO): DefineArg sci2.Lon7 = nan arcdeg
2018-08-20T20:26:48.105Z,1534796808.105 [MissionManager](INFO): DefineArg sci2.Speed = 1.000000 m/s
2018-08-20T20:26:48.108Z,1534796808.108 [MissionManager](INFO): DefineArg sci2.YoYoMinDepth = 2.000000 m
2018-08-20T20:26:48.112Z,1534796808.112 [MissionManager](INFO): DefineArg sci2.YoYoMaxDepth = 200.000000 m
2018-08-20T20:26:48.145Z,1534796808.145 [MissionManager](INFO): DefineArg sci2.YoYoMinAltitude = 9.000000 m
2018-08-20T20:26:48.148Z,1534796808.148 [MissionManager](INFO): DefineArg sci2.YoYoUpPitch = 20.000000 arcdeg
2018-08-20T20:26:48.151Z,1534796808.151 [MissionManager](INFO): DefineArg sci2.YoYoDownPitch = -20.000000 arcdeg
2018-08-20T20:26:48.166Z,1534796808.166 [MissionManager](INFO): DefineArg sci2.BuoyancyNeutral = 315.000012 cc
2018-08-20T20:26:48.170Z,1534796808.170 [MissionManager](INFO): DefineArg sci2.MassDefault = -0.075000 cm
2018-08-20T20:26:48.172Z,1534796808.172 [MissionManager](INFO): DefineArg sci2.MinAltitude = 5.000000 m
2018-08-20T20:26:48.192Z,1534796808.192 [MissionManager](INFO): DefineArg sci2.MaxDepth = 205.000000 m
2018-08-20T20:26:48.195Z,1534796808.195 [MissionManager](INFO): DefineArg sci2.MinOffshore = 2.000000 km
2018-08-20T20:26:48.196Z,1534796808.196 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2018-08-20T20:26:48.587Z,1534796808.587 [MissionManager](INFO): DefineArg sci2:Science.SampleISUS = 0 bool
2018-08-20T20:26:48.591Z,1534796808.591 [MissionManager](INFO): DefineArg sci2:Science.SampleISUSmaxPitch = 60.000000 arcdeg
2018-08-20T20:26:48.610Z,1534796808.610 [MissionManager](INFO): DefineArg sci2:Science.SampleISUSminPitch = -60.000000 arcdeg
2018-08-20T20:26:48.617Z,1534796808.617 [MissionManager](INFO): DefineArg sci2:Science.PeakDetectChlActive = 0 bool
2018-08-20T20:26:48.620Z,1534796808.620 [MissionManager](INFO): DefineArg sci2:Science.HighestChlPeakReportActive = 0 bool
2018-08-20T20:26:48.623Z,1534796808.623 [MissionManager](INFO): DefineArg sci2:Science.PatchTracking = 0 bool
2018-08-20T20:26:48.638Z,1534796808.638 [MissionManager](INFO): DefineArg sci2:Science.FilterWidthHorizontal = 3.000000 count
2018-08-20T20:26:48.642Z,1534796808.642 [MissionManager](INFO): DefineArg sci2:Science.NumProfilesSlidingwindow = 100.000000 count
2018-08-20T20:26:48.644Z,1534796808.644 [MissionManager](INFO): DefineArg sci2:Science.PeakDetectNO3Active = 0 bool
2018-08-20T20:26:48.647Z,1534796808.647 [MissionManager](INFO): DefineArg sci2:Science.PeakDetectOilActive = 0 bool
2018-08-20T20:26:48.669Z,1534796808.669 [MissionManager](INFO): DefineArg sci2:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2018-08-20T20:26:48.673Z,1534796808.673 [MissionManager](INFO): DefineArg sci2:Science.EnabledAanderaaO2 = 1.000000 bool
2018-08-20T20:26:48.676Z,1534796808.676 [MissionManager](INFO): DefineArg sci2:Science.EnabledNeilBrown = 1.000000 bool
2018-08-20T20:26:48.692Z,1534796808.692 [MissionManager](INFO): DefineArg sci2:Science.EnabledSeabird = 1.000000 bool
2018-08-20T20:26:48.695Z,1534796808.695 [MissionManager](INFO): DefineArg sci2:Science.EnabledTurbulence_NPS = 0.000000 bool
2018-08-20T20:26:48.699Z,1534796808.699 [MissionManager](INFO): DefineArg sci2:Science.EnabledWetLabsBB2FL = 1.000000 bool
2018-08-20T20:26:48.728Z,1534796808.728 [MissionManager](INFO): DefineArg sci2:Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool
2018-08-20T20:26:48.732Z,1534796808.732 [MissionManager](INFO): DefineArg sci2:Science.EnabledISUS = 0.000000 bool
2018-08-20T20:26:48.735Z,1534796808.735 [MissionManager](INFO): DefineArg sci2:Science.LowPassWindowLength = 20.000000 count
2018-08-20T20:26:48.751Z,1534796808.751 [MissionManager](INFO): DefineArg sci2:Science.PeakChlShallowBound = nan m
2018-08-20T20:26:48.755Z,1534796808.755 [MissionManager](INFO): DefineArg sci2:Science.PeakChlDeepBound = nan m
2018-08-20T20:26:48.759Z,1534796808.759 [MissionManager](INFO): DefineOutput sci2:Science.PeakChl = 0.000000 ug/l
2018-08-20T20:26:48.796Z,1534796808.796 [MissionManager](INFO): DefineOutput sci2:Science.PeakChlDepth = 0.000000 m
2018-08-20T20:26:48.799Z,1534796808.799 [MissionManager](INFO): DefineOutput sci2:Science.PeakChlTemperature = 0.000000 degC
2018-08-20T20:26:48.815Z,1534796808.815 [MissionManager](INFO): DefineOutput sci2:Science.PeakChlLatitude = nan arcdeg
2018-08-20T20:26:48.818Z,1534796808.818 [MissionManager](INFO): DefineOutput sci2:Science.PeakChlLongitude = nan arcdeg
2018-08-20T20:26:48.822Z,1534796808.822 [MissionManager](INFO): DefineOutput sci2:Science.PeakNO3 = 0.000000 umol/l
2018-08-20T20:26:48.837Z,1534796808.837 [MissionManager](INFO): DefineOutput sci2:Science.PeakNO3Depth = 0.000000 m
2018-08-20T20:26:48.840Z,1534796808.840 [MissionManager](INFO): DefineOutput sci2:Science.PeakNO3Latitude = nan arcdeg
2018-08-20T20:26:48.843Z,1534796808.843 [MissionManager](INFO): DefineOutput sci2:Science.PeakNO3Longitude = nan arcdeg
2018-08-20T20:26:48.846Z,1534796808.846 [MissionManager](INFO): DefineOutput sci2:Science.PatchChl = 0.000000 m
2018-08-20T20:26:48.879Z,1534796808.879 [MissionManager](INFO): DefineOutput sci2:Science.PatchChlDepth = 0.000000 m
2018-08-20T20:26:48.883Z,1534796808.883 [MissionManager](INFO): DefineOutput sci2:Science.PatchChlLatitude = nan arcdeg
2018-08-20T20:26:48.886Z,1534796808.886 [MissionManager](INFO): DefineOutput sci2:Science.PatchChlLongitude = nan arcdeg
2018-08-20T20:26:48.910Z,1534796808.910 [MissionManager](INFO): DefineOutput sci2:Science.PatchChlDistance = nan m
2018-08-20T20:26:48.914Z,1534796808.914 [MissionManager](INFO): DefineOutput sci2:Science.PeakOil = 0.000000 kg/m3
2018-08-20T20:26:48.917Z,1534796808.917 [MissionManager](INFO): DefineOutput sci2:Science.PeakOilDepth = 0.000000 m
2018-08-20T20:26:48.920Z,1534796808.920 [MissionManager](INFO): DefineOutput sci2:Science.PeakOilLatitude = nan arcdeg
2018-08-20T20:26:48.947Z,1534796808.947 [MissionManager](INFO): DefineOutput sci2:Science.PeakOilLongitude = nan arcdeg
2018-08-20T20:26:48.994Z,1534796808.994 [sci2:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2018-08-20T20:26:49.045Z,1534796809.045 [sci2:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2018-08-20T20:26:49.079Z,1534796809.079 [sci2:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2018-08-20T20:26:49.101Z,1534796809.101 [sci2:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2018-08-20T20:26:49.135Z,1534796809.135 [MissionManager](INFO): RedefineArg sci2:Science.SampleISUS = value:1 bool
2018-08-20T20:26:49.138Z,1534796809.138 [MissionManager](INFO): RedefineArg sci2:Science.PeakDetectChlActive = value:1 bool
2018-08-20T20:26:49.138Z,1534796809.138 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2018-08-20T20:26:49.255Z,1534796809.255 [MissionManager](INFO): DefineArg sci2:NeedComms.DiveInterval = 3.000000 h
2018-08-20T20:26:49.268Z,1534796809.268 [MissionManager](INFO): DefineArg sci2:NeedComms.WaitForPitchUp = 10.000000 min
2018-08-20T20:26:49.271Z,1534796809.271 [MissionManager](INFO): DefineArg sci2:NeedComms.SurfacePitch = 20.000000 arcdeg
2018-08-20T20:26:49.274Z,1534796809.274 [MissionManager](INFO): DefineArg sci2:NeedComms.SurfaceDepthRate = nan m/s
2018-08-20T20:26:49.312Z,1534796809.312 [MissionManager](INFO): DefineArg sci2:NeedComms.SurfaceSpeed = 1.000000 m/s
2018-08-20T20:26:49.315Z,1534796809.315 [MissionManager](INFO): DefineArg sci2:NeedComms.GPSTimeout = 7.000000 min
2018-08-20T20:26:49.318Z,1534796809.318 [MissionManager](INFO): DefineArg sci2:NeedComms.CommsTimeout = 30.000000 min
2018-08-20T20:26:49.336Z,1534796809.336 [sci2:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-08-20T20:26:49.376Z,1534796809.376 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2018-08-20T20:26:49.463Z,1534796809.463 [MissionManager](INFO): DefineArg sci2:StandardEnvelopes.MinAltitude = 5.000000 m
2018-08-20T20:26:49.487Z,1534796809.487 [MissionManager](INFO): DefineArg sci2:StandardEnvelopes.MaxDepth = 200.000000 m
2018-08-20T20:26:49.491Z,1534796809.491 [MissionManager](INFO): DefineArg sci2:StandardEnvelopes.MinOffshore = 2000.000000 m
2018-08-20T20:26:49.492Z,1534796809.492 [sci2:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2018-08-20T20:26:49.512Z,1534796809.512 [sci2:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2018-08-20T20:26:49.535Z,1534796809.535 [sci2:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2018-08-20T20:26:49.581Z,1534796809.581 [sci2:I.Pitch](DEBUG): Construct.
2018-08-20T20:26:49.598Z,1534796809.598 [sci2:J.Buoyancy](DEBUG): Construct Buoyancy.
2018-08-20T20:26:49.601Z,1534796809.601 [sci2:K.SetSpeed](DEBUG): Construct.
2018-08-20T20:26:49.604Z,1534796809.604 [sci2:L.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2018-08-20T20:26:49.639Z,1534796809.639 [sci2:M.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2018-08-20T20:26:49.659Z,1534796809.659 [sci2:N.YoYo](DEBUG): Construct YoYo.
2018-08-20T20:26:49.693Z,1534796809.693 [sci2:Lap:Wpt1:A.Waypoint](DEBUG): Construct Waypoint.
2018-08-20T20:26:49.708Z,1534796809.708 [sci2:Lap:Wpt2:A.Waypoint](DEBUG): Construct Waypoint.
2018-08-20T20:26:49.723Z,1534796809.723 [sci2:Lap:Wpt3:A.Waypoint](DEBUG): Construct Waypoint.
2018-08-20T20:26:49.751Z,1534796809.751 [sci2:Lap:Wpt4:A.Waypoint](DEBUG): Construct Waypoint.
2018-08-20T20:26:49.770Z,1534796809.770 [sci2:Lap:Wpt5:A.Waypoint](DEBUG): Construct Waypoint.
2018-08-20T20:26:49.785Z,1534796809.785 [sci2:Lap:Wpt6:A.Waypoint](DEBUG): Construct Waypoint.
2018-08-20T20:26:49.809Z,1534796809.809 [sci2:Lap:Wpt7:A.Waypoint](DEBUG): Construct Waypoint.
2018-08-20T20:26:49.894Z,1534796809.894 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Control="Tethys/Control"
         xmlns:Guidance="Tethys/Guidance"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd"
       Id="sci2">

    <Description>
        Vehicle yo-yo's to the specified waypoints, with science turned on.
    </Description>
    <DefineArg Name="MissionTimeout"><Description>
        Maximum duration of mission
    </Description><Units:hour/><Value>2</Value></DefineArg>

    <DefineArg Name="NeedCommsTime"><Description>
        How often to surface for commumications
    </Description><Units:minute/><Value>60</Value></DefineArg>

    <DefineArg Name="Repeat"><Description>
        Number of times the vehicle should try to cycle through waypoints..
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="Lat1"><Description>
        Latitude of waypoint 1. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon1"><Description>
        Longitude of waypoint 1. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat2"><Description>
        Latitude of waypoint 2. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon2"><Description>
        Longitude of waypoint 2. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat3"><Description>
        Latitude of waypoint 3. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon3"><Description>
        Longitude of waypoint 3. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat4"><Description>
        Latitude of waypoint 4. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon4"><Description>
        Longitude of waypoint 4. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat5"><Description>
        Latitude of waypoint 5. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon5"><Description>
        Longitude of waypoint 5. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat6"><Description>
        Latitude of waypoint 6. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon6"><Description>
        Longitude of waypoint 6. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat7"><Description>
        Latitude of waypoint 7. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon7"><Description>
        Longitude of waypoint 7. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Speed"><Description>
        Speed while performing the YoYo behavior.
    </Description><Units:meter_per_second/><Value>1</Value></DefineArg>

    <DefineArg Name="YoYoMinDepth"><Description>
        Minimum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>2</Value></DefineArg>

    <DefineArg Name="YoYoMaxDepth"><Description>
        Maximum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>200</Value></DefineArg>

    <DefineArg Name="YoYoMinAltitude"><Description>
        Minimum altitude while performing the YoYo behavior (for
        bottom-terminated YoYos).
    </Description><Units:meter/><Value>9</Value></DefineArg>

    <DefineArg Name="YoYoUpPitch"><Description>
        Vehicle up pitch while performing the YoYo behavior.
    </Description><Units:degree/><Value>20</Value></DefineArg>

    <DefineArg Name="YoYoDownPitch"><Description>
        Vehicle down pitch while performing the YoYo behavior.
    </Description><Units:degree/><Value>-20</Value></DefineArg>

    <DefineArg Name="BuoyancyNeutral"><Description>
        Buoyancy bladder position while performing the YoYo behavior. Defaults
        to buoyancyNeutral setting in the Config/Control.cfg file. Set to NaN cc
        for active buoyancy
    </Description><Control:VerticalControl.buoyancyNeutral/></DefineArg>

    <DefineArg Name="MassDefault"><Description>
        Static setting for mass during the mission. Set to NaN mm for active
        mass position
    </Description><Control:VerticalControl.massDefault/></DefineArg>

    <DefineArg Name="MinAltitude"><Description>
        Minimum height above the sea floor for the entire mission.
    </Description><Units:meter/><Value>5</Value></DefineArg>

    <DefineArg Name="MaxDepth"><Description>
        Maximum depth for the entire mission.
    </Description><Units:meter/><Value>205</Value></DefineArg>

    <DefineArg Name="MinOffshore"><Description>
        Minimum offshore distance for the entire mission.
    </Description><Units:kilometer/><Value>2</Value></DefineArg>
    <Timeout Duration="MissionTimeout"/>

    <Insert Filename="Insert/Science.xml">
        <Description>
            Most missions will run the science sensors. If you don't place this
            aggregate above NeedComms, science instruments get turned off on the
            last upcast and while floating on the surface.
        </Description>
        <RedefineArg Name="SampleISUS"><True/></RedefineArg>
        <RedefineArg Name="PeakDetectChlActive"><True/></RedefineArg>
    </Insert>

    <Insert Filename="Insert/NeedComms.xml" Id="NeedComms"/>

    <Assign><Sequence/><Arg Name="NeedComms:DiveInterval"/><Arg Name="NeedCommsTime"/></Assign>

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

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinAltitude"/><Arg Name="MinAltitude"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MaxDepth"/><Arg Name="MaxDepth"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinOffshore"/><Arg Name="MinOffshore"/></Assign>

    <Call Id="StartingMission" RefId="NeedComms"/>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Arg Name="MassDefault"/></Setting>
    </Guidance:Pitch>

    <Guidance:Buoyancy>
        <Parallel/>
        <Setting><Guidance:Buoyancy.position/><Arg Name="BuoyancyNeutral"/></Setting>
    </Guidance:Buoyancy>

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Arg Name="Speed"/></Setting>
    </Guidance:SetSpeed>

    <Guidance:DepthEnvelope>
        <Description>
            Another depth envelope for the YoYo behavior. This envelope should
            fall within the limits of the standard safety envelopes in
            Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
            angles for depth-terminated YoYos.
        </Description>
        <Parallel/>
        <Setting><Guidance:DepthEnvelope.minDepth/><Arg Name="YoYoMinDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.maxDepth/><Arg Name="YoYoMaxDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.downPitch/><Arg Name="YoYoDownPitch"/></Setting>
        <Setting><Guidance:DepthEnvelope.upPitch/><Arg Name="YoYoUpPitch"/></Setting>
    </Guidance:DepthEnvelope>

    <Guidance:AltitudeEnvelope>
        <Description>
            Another altitude envelope for the YoYo behavior. This envelope
            should fall within the limits of the standard safety envelopes in
            Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
            angles for bottom-terminated YoYos.
        </Description>
        <Parallel/>
        <Setting><Guidance:AltitudeEnvelope.minAltitude/><Arg Name="YoYoMinAltitude"/></Setting>
        <Setting><Guidance:AltitudeEnvelope.upPitch/><Arg Name="YoYoUpPitch"/></Setting>
    </Guidance:AltitudeEnvelope>

    <Guidance:YoYo>
        <Parallel/>
        <Setting><Guidance:YoYo.downPitch/><Arg Name="YoYoDownPitch"/></Setting>
        <Setting><Guidance:YoYo.upPitch/><Arg Name="YoYoUpPitch"/></Setting>
    </Guidance:YoYo>

    <Aggregate Id="Lap">
        <Sequence Repeat="Repeat"/>

        <Aggregate Id="Wpt1">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat1"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon1"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt2">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat2"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon2"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt3">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat3"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon3"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt4">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat4"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon4"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt5">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat5"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon5"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt6">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat6"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon6"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt7">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat7"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon7"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>
    </Aggregate>
</Mission>

2018-08-20T20:26:49.895Z,1534796809.895 [CommandLine](IMPORTANT): Loaded ./Missions/Science/sci2.xml
2018-08-20T20:26:55.884Z,1534796815.884 [CommandLine](IMPORTANT): got command set sci2.NeedCommsTime 45.000000 minute
2018-08-20T20:26:55.885Z,1534796815.885 [CommandLine](IMPORTANT): got command set sci2.Lat1 36.797001 degree
2018-08-20T20:26:55.886Z,1534796815.886 [CommandLine](IMPORTANT): got command set sci2.Lon1 -121.847000 degree
2018-08-20T20:26:55.887Z,1534796815.887 [CommandLine](IMPORTANT): got command set sci2.Lat2 36.750000 degree
2018-08-20T20:26:55.888Z,1534796815.888 [CommandLine](IMPORTANT): got command set sci2.Lon2 -122.022003 degree
2018-08-20T20:26:55.889Z,1534796815.889 [CommandLine](IMPORTANT): got command set sci2.YoYoMaxDepth 40.000000 meter
2018-08-20T20:26:55.889Z,1534796815.889 [CommandLine](IMPORTANT): got command run 
2018-08-20T20:26:55.892Z,1534796815.892 [CommandLine](IMPORTANT): Running 
2018-08-20T20:26:56.003Z,1534796816.003 [Default] Stopped
2018-08-20T20:26:56.003Z,1534796816.003 [Default](DEBUG): Aggregate::uninitialize Default
2018-08-20T20:26:56.003Z,1534796816.003 [Default:B.GoToSurface] Stopped
2018-08-20T20:26:56.003Z,1534796816.003 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-08-20T20:26:56.003Z,1534796816.003 [Default:CheckIn] Stopped
2018-08-20T20:26:56.003Z,1534796816.003 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-20T20:26:56.003Z,1534796816.003 [Default:CheckIn:C.Wait] Stopped
2018-08-20T20:26:56.003Z,1534796816.003 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-20T20:26:56.004Z,1534796816.004 [MissionManager](IMPORTANT): Started mission sci2
2018-08-20T20:26:56.004Z,1534796816.004 [sci2] Running Loop=1
2018-08-20T20:26:56.004Z,1534796816.004 [sci2](DEBUG): Aggregate::initialize sci2
2018-08-20T20:26:56.004Z,1534796816.004 [sci2:Science] Running Loop=1
2018-08-20T20:26:56.004Z,1534796816.004 [sci2:Science](DEBUG): Aggregate::initialize sci2:Science
2018-08-20T20:26:56.004Z,1534796816.004 [sci2:Science:A] Running Loop=1
2018-08-20T20:26:56.014Z,1534796816.014 [sci2:Science:B] Running Loop=1
2018-08-20T20:26:56.014Z,1534796816.014 [sci2:Science:C] Running Loop=1
2018-08-20T20:26:56.014Z,1534796816.014 [sci2:Science:D] Running Loop=1
2018-08-20T20:26:56.015Z,1534796816.015 [sci2:Science:E] Running Loop=1
2018-08-20T20:26:56.015Z,1534796816.015 [sci2:Science:F] Running Loop=1
2018-08-20T20:26:56.015Z,1534796816.015 [sci2:Science:G] Running Loop=1
2018-08-20T20:26:56.015Z,1534796816.015 [sci2:Science:Read_Oil] Running Loop=1
2018-08-20T20:26:56.015Z,1534796816.015 [sci2:Science:PeakDetectChl] Running Loop=1
2018-08-20T20:26:56.015Z,1534796816.015 [sci2:Science:PeakDetectChl](DEBUG): Aggregate::initialize sci2:Science:PeakDetectChl
2018-08-20T20:26:56.015Z,1534796816.015 [sci2:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2018-08-20T20:26:56.015Z,1534796816.015 [sci2:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2018-08-20T20:26:56.026Z,1534796816.026 [sci2:Science:HighestChlPeakReport] Running Loop=1
2018-08-20T20:26:56.026Z,1534796816.026 [sci2:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize sci2:Science:HighestChlPeakReport
2018-08-20T20:26:56.027Z,1534796816.027 [sci2:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2018-08-20T20:26:56.027Z,1534796816.027 [sci2:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2018-08-20T20:26:56.027Z,1534796816.027 [sci2:Science:PeakDetectNO3] Running Loop=1
2018-08-20T20:26:56.027Z,1534796816.027 [sci2:Science:PeakDetectNO3](DEBUG): Aggregate::initialize sci2:Science:PeakDetectNO3
2018-08-20T20:26:56.027Z,1534796816.027 [sci2:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2018-08-20T20:26:56.027Z,1534796816.027 [sci2:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2018-08-20T20:26:56.030Z,1534796816.030 [sci2:Science:PeakDetectOil] Running Loop=1
2018-08-20T20:26:56.030Z,1534796816.030 [sci2:Science:PeakDetectOil](DEBUG): Aggregate::initialize sci2:Science:PeakDetectOil
2018-08-20T20:26:56.030Z,1534796816.030 [sci2:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2018-08-20T20:26:56.030Z,1534796816.030 [sci2:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2018-08-20T20:26:56.032Z,1534796816.032 [sci2:StandardEnvelopes] Running Loop=1
2018-08-20T20:26:56.032Z,1534796816.032 [sci2:StandardEnvelopes](DEBUG): Aggregate::initialize sci2:StandardEnvelopes
2018-08-20T20:26:56.032Z,1534796816.032 [sci2:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2018-08-20T20:26:56.041Z,1534796816.041 [sci2:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2018-08-20T20:26:56.041Z,1534796816.041 [sci2:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2018-08-20T20:26:56.041Z,1534796816.041 [sci2:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2018-08-20T20:26:56.041Z,1534796816.041 [sci2:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2018-08-20T20:26:56.042Z,1534796816.042 [sci2:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2018-08-20T20:26:56.042Z,1534796816.042 [sci2:I.Pitch] Running Loop=1
2018-08-20T20:26:56.042Z,1534796816.042 [sci2:I.Pitch](DEBUG): Initialize.
2018-08-20T20:26:56.042Z,1534796816.042 [sci2:J.Buoyancy] Running Loop=1
2018-08-20T20:26:56.042Z,1534796816.042 [sci2:J.Buoyancy](DEBUG): Initialize Buoyancy Component.
2018-08-20T20:26:56.042Z,1534796816.042 [sci2:K.SetSpeed] Running Loop=1
2018-08-20T20:26:56.042Z,1534796816.042 [sci2:K.SetSpeed](DEBUG): Initialize.
2018-08-20T20:26:56.042Z,1534796816.042 [sci2:L.DepthEnvelope] Running Loop=1
2018-08-20T20:26:56.043Z,1534796816.043 [sci2:L.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2018-08-20T20:26:56.043Z,1534796816.043 [sci2:M.AltitudeEnvelope] Running Loop=1
2018-08-20T20:26:56.043Z,1534796816.043 [sci2:M.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2018-08-20T20:26:56.043Z,1534796816.043 [sci2:N.YoYo] Running Loop=1
2018-08-20T20:26:56.043Z,1534796816.043 [sci2:N.YoYo](DEBUG): Initialize YoYoComponent.
2018-08-20T20:26:56.044Z,1534796816.044 [sci2:C] Running Loop=1
2018-08-20T20:26:56.044Z,1534796816.044 [sci2:N.YoYo] Running Loop=1
2018-08-20T20:26:56.054Z,1534796816.054 [sci2:M.AltitudeEnvelope] Running Loop=1
2018-08-20T20:26:56.069Z,1534796816.069 [sci2:L.DepthEnvelope] Running Loop=1
2018-08-20T20:26:56.082Z,1534796816.082 [sci2:K.SetSpeed] Running Loop=1
2018-08-20T20:26:56.087Z,1534796816.087 [sci2:J.Buoyancy] Running Loop=1
2018-08-20T20:26:56.101Z,1534796816.101 [sci2:I.Pitch] Running Loop=1
2018-08-20T20:26:56.110Z,1534796816.110 [sci2:StandardEnvelopes] Running Loop=1
2018-08-20T20:26:56.110Z,1534796816.110 [sci2:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2018-08-20T20:26:56.136Z,1534796816.136 [sci2:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2018-08-20T20:26:56.145Z,1534796816.145 [sci2:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2018-08-20T20:26:56.165Z,1534796816.165 [sci2:C] Stopped
2018-08-20T20:26:56.165Z,1534796816.165 [sci2:E] Running Loop=1
2018-08-20T20:26:56.165Z,1534796816.165 [sci2:Science] Running Loop=1
2018-08-20T20:26:56.169Z,1534796816.169 [sci2:Science:PeakDetectOil] Stopped
2018-08-20T20:26:56.169Z,1534796816.169 [sci2:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize sci2:Science:PeakDetectOil
2018-08-20T20:26:56.169Z,1534796816.169 [sci2:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2018-08-20T20:26:56.169Z,1534796816.169 [sci2:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2018-08-20T20:26:56.169Z,1534796816.169 [sci2:Science:PeakDetectNO3] Stopped
2018-08-20T20:26:56.170Z,1534796816.170 [sci2:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize sci2:Science:PeakDetectNO3
2018-08-20T20:26:56.170Z,1534796816.170 [sci2:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2018-08-20T20:26:56.170Z,1534796816.170 [sci2:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2018-08-20T20:26:56.170Z,1534796816.170 [sci2:Science:HighestChlPeakReport] Stopped
2018-08-20T20:26:56.170Z,1534796816.170 [sci2:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize sci2:Science:HighestChlPeakReport
2018-08-20T20:26:56.170Z,1534796816.170 [sci2:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2018-08-20T20:26:56.170Z,1534796816.170 [sci2:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2018-08-20T20:26:56.170Z,1534796816.170 [sci2:Science:PeakDetectChl] Running Loop=1
2018-08-20T20:26:56.175Z,1534796816.175 [sci2:Science:Read_Oil] Stopped
2018-08-20T20:26:56.175Z,1534796816.175 [sci2:Science:G] Running Loop=1
2018-08-20T20:26:56.176Z,1534796816.176 [sci2:Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2018-08-20T20:26:56.198Z,1534796816.198 [sci2:Science:F] Stopped
2018-08-20T20:26:56.198Z,1534796816.198 [sci2:Science:E] Stopped
2018-08-20T20:26:56.198Z,1534796816.198 [sci2:Science:D] Running Loop=1
2018-08-20T20:26:56.199Z,1534796816.199 [sci2:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2018-08-20T20:26:56.199Z,1534796816.199 [sci2:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2018-08-20T20:26:56.201Z,1534796816.201 [sci2:Science:C] Running Loop=1
2018-08-20T20:26:56.202Z,1534796816.202 [sci2:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2018-08-20T20:26:56.202Z,1534796816.202 [sci2:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2018-08-20T20:26:56.204Z,1534796816.204 [sci2:Science:B] Stopped
2018-08-20T20:26:56.204Z,1534796816.204 [sci2:Science:A] Running Loop=1
2018-08-20T20:26:56.205Z,1534796816.205 [sci2:Science:A](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_oxygen_in_sea_water
2018-08-20T20:26:56.333Z,1534796816.333 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2018-08-20T20:26:56.353Z,1534796816.353 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2018-08-20T20:26:56.426Z,1534796816.426 [sci2:E] Stopped
2018-08-20T20:26:56.426Z,1534796816.426 [sci2:F] Running Loop=1
2018-08-20T20:26:56.490Z,1534796816.490 [CTD_Seabird](INFO): Initializing
2018-08-20T20:26:56.490Z,1534796816.490 [CTD_Seabird](INFO): Checking LCM
2018-08-20T20:26:56.490Z,1534796816.490 [CTD_Seabird](INFO): LCM OK
2018-08-20T20:26:56.490Z,1534796816.490 [CTD_Seabird](INFO): Powering up
2018-08-20T20:26:56.501Z,1534796816.501 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2018-08-20T20:26:56.502Z,1534796816.502 [WetLabsBB2FL](INFO): Powering up
2018-08-20T20:26:56.651Z,1534796816.651 [DataOverHttps](IMPORTANT): SBD MTMSN=20180820T202647
2018-08-20T20:26:56.757Z,1534796816.757 [CTD_NeilBrown](DEBUG): serial timeout
2018-08-20T20:26:56.765Z,1534796816.765 [sci2:F] Stopped
2018-08-20T20:26:56.765Z,1534796816.765 [sci2:G] Running Loop=1
2018-08-20T20:26:56.877Z,1534796816.877 [CTD_NeilBrown](DEBUG): serial timeout
2018-08-20T20:26:57.105Z,1534796817.105 [ThrusterServo](FAULT): getVelocity uart error serial timeout
2018-08-20T20:26:57.105Z,1534796817.105 [ThrusterServo](FAULT): Thruster uart error: serial timeout
2018-08-20T20:26:57.105Z,1534796817.105 [ThrusterServo] Communications Fault, FailCount= 1
2018-08-20T20:26:57.106Z,1534796817.106 [ThrusterServo](ERROR): Communications Fault
2018-08-20T20:26:57.110Z,1534796817.110 [CBIT](ERROR): Communications Fault in component: ThrusterServo
2018-08-20T20:26:57.207Z,1534796817.207 [sci2:G] Stopped
2018-08-20T20:26:57.208Z,1534796817.208 [sci2:StartingMission] Running Loop=1
2018-08-20T20:26:57.208Z,1534796817.208 [sci2:StartingMission](DEBUG): Aggregate::initialize sci2:StartingMission
2018-08-20T20:26:57.290Z,1534796817.290 [CTD_NeilBrown](DEBUG): serial timeout
2018-08-20T20:26:57.434Z,1534796817.434 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-08-20T20:26:57.434Z,1534796817.434 [ThrusterServo](INFO): Powering down
2018-08-20T20:26:57.604Z,1534796817.604 [sci2:NeedComms] Running Loop=1
2018-08-20T20:26:57.604Z,1534796817.604 [sci2:NeedComms](DEBUG): Aggregate::initialize sci2:NeedComms
2018-08-20T20:26:57.604Z,1534796817.604 [sci2:NeedComms:B.GoToSurface] Running Loop=1
2018-08-20T20:26:57.625Z,1534796817.625 [sci2:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-20T20:26:57.625Z,1534796817.625 [sci2:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2018-08-20T20:26:57.626Z,1534796817.626 [sci2:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2018-08-20T20:26:57.626Z,1534796817.626 [sci2:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2018-08-20T20:26:57.627Z,1534796817.627 [sci2:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-20T20:26:57.627Z,1534796817.627 [sci2:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-20T20:26:57.627Z,1534796817.627 [sci2:NeedComms:A] Running Loop=1
2018-08-20T20:26:57.633Z,1534796817.633 [sci2:NeedComms:A](INFO): last time_fix was: 1534796700.000000 second since 1970/01/01T00:00:00Z 
2018-08-20T20:26:57.635Z,1534796817.635 [sci2:NeedComms:A] Stopped
2018-08-20T20:26:57.698Z,1534796817.698 [CTD_NeilBrown](DEBUG): serial timeout
2018-08-20T20:26:58.101Z,1534796818.101 [CTD_NeilBrown](DEBUG): serial timeout
2018-08-20T20:26:58.509Z,1534796818.509 [CTD_NeilBrown](DEBUG): serial timeout
2018-08-20T20:26:58.913Z,1534796818.913 [CTD_NeilBrown](DEBUG): serial timeout
2018-08-20T20:26:59.325Z,1534796819.325 [CTD_NeilBrown](DEBUG): serial timeout
2018-08-20T20:26:59.733Z,1534796819.733 [CTD_NeilBrown](DEBUG): serial timeout
2018-08-20T20:27:00.137Z,1534796820.137 [CTD_NeilBrown](DEBUG): serial timeout
2018-08-20T20:27:00.549Z,1534796820.549 [CTD_NeilBrown](DEBUG): serial timeout
2018-08-20T20:27:00.957Z,1534796820.957 [CTD_NeilBrown](DEBUG): serial timeout
2018-08-20T20:27:01.370Z,1534796821.370 [CTD_NeilBrown](DEBUG): serial timeout
2018-08-20T20:27:01.730Z,1534796821.730 [sci2:NeedComms:C] Running Loop=1
2018-08-20T20:27:01.800Z,1534796821.800 [CTD_NeilBrown](DEBUG): serial timeout
2018-08-20T20:27:01.954Z,1534796821.954 [CBIT](INFO): Clearing failed state for component ThrusterServo
2018-08-20T20:27:01.954Z,1534796821.954 [ThrusterServo] No Fault, FailCount= 1
2018-08-20T20:27:01.972Z,1534796821.972 [DataOverHttps](INFO): Received command:stop
2018-08-20T20:27:02.001Z,1534796822.001 [CommandLine](IMPORTANT): got command stop
2018-08-20T20:27:02.002Z,1534796822.002 [CommandLine](IMPORTANT): Scheduling is paused
2018-08-20T20:27:02.002Z,1534796822.002 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2018-08-20T20:27:02.187Z,1534796822.187 [sci2:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-08-20T20:27:02.209Z,1534796822.209 [CTD_NeilBrown](DEBUG): serial timeout
2018-08-20T20:27:02.213Z,1534796822.213 [MissionManager](INFO): MissionManager is completed.
2018-08-20T20:27:02.213Z,1534796822.213 [MissionManager](INFO): Uninitializing Mission sci2
2018-08-20T20:27:02.213Z,1534796822.213 [sci2] Stopped
2018-08-20T20:27:02.213Z,1534796822.213 [sci2](DEBUG): Aggregate::uninitialize sci2
2018-08-20T20:27:02.213Z,1534796822.213 [sci2:Science] Stopped
2018-08-20T20:27:02.214Z,1534796822.214 [sci2:Science](DEBUG): Aggregate::uninitialize sci2:Science
2018-08-20T20:27:02.214Z,1534796822.214 [sci2:Science:A] Stopped
2018-08-20T20:27:02.214Z,1534796822.214 [sci2:Science:C] Stopped
2018-08-20T20:27:02.214Z,1534796822.214 [sci2:Science:D] Stopped
2018-08-20T20:27:02.214Z,1534796822.214 [sci2:Science:G] Stopped
2018-08-20T20:27:02.214Z,1534796822.214 [sci2:Science:PeakDetectChl] Stopped
2018-08-20T20:27:02.214Z,1534796822.214 [sci2:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize sci2:Science:PeakDetectChl
2018-08-20T20:27:02.214Z,1534796822.214 [sci2:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2018-08-20T20:27:02.214Z,1534796822.214 [sci2:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2018-08-20T20:27:02.215Z,1534796822.215 [sci2:NeedComms] Stopped
2018-08-20T20:27:02.215Z,1534796822.215 [sci2:NeedComms](DEBUG): Aggregate::uninitialize sci2:NeedComms
2018-08-20T20:27:02.215Z,1534796822.215 [sci2:NeedComms:B.GoToSurface] Stopped
2018-08-20T20:27:02.215Z,1534796822.215 [sci2:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-08-20T20:27:02.215Z,1534796822.215 [sci2:NeedComms:C] Stopped
2018-08-20T20:27:02.215Z,1534796822.215 [sci2:StandardEnvelopes] Stopped
2018-08-20T20:27:02.215Z,1534796822.215 [sci2:StandardEnvelopes](DEBUG): Aggregate::uninitialize sci2:StandardEnvelopes
2018-08-20T20:27:02.215Z,1534796822.215 [sci2:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2018-08-20T20:27:02.215Z,1534796822.215 [sci2:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2018-08-20T20:27:02.216Z,1534796822.216 [sci2:StandardEnvelopes:B.DepthEnvelope] Stopped
2018-08-20T20:27:02.216Z,1534796822.216 [sci2:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2018-08-20T20:27:02.216Z,1534796822.216 [sci2:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2018-08-20T20:27:02.216Z,1534796822.216 [sci2:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2018-08-20T20:27:02.216Z,1534796822.216 [sci2:StartingMission] Stopped
2018-08-20T20:27:02.216Z,1534796822.216 [sci2:StartingMission](DEBUG): Aggregate::uninitialize sci2:StartingMission
2018-08-20T20:27:02.216Z,1534796822.216 [sci2:I.Pitch] Stopped
2018-08-20T20:27:02.216Z,1534796822.216 [sci2:J.Buoyancy] Stopped
2018-08-20T20:27:02.216Z,1534796822.216 [sci2:J.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2018-08-20T20:27:02.221Z,1534796822.221 [sci2:K.SetSpeed] Stopped
2018-08-20T20:27:02.221Z,1534796822.221 [sci2:K.SetSpeed](DEBUG): Uninitialize.
2018-08-20T20:27:02.221Z,1534796822.221 [sci2:L.DepthEnvelope] Stopped
2018-08-20T20:27:02.221Z,1534796822.221 [sci2:L.DepthEnvelope](DEBUG): Uninitialize.
2018-08-20T20:27:02.221Z,1534796822.221 [sci2:M.AltitudeEnvelope] Stopped
2018-08-20T20:27:02.221Z,1534796822.221 [sci2:M.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2018-08-20T20:27:02.222Z,1534796822.222 [sci2:N.YoYo] Stopped
2018-08-20T20:27:02.222Z,1534796822.222 [sci2:N.YoYo](DEBUG): Uninitialize YoYoComponent.
2018-08-20T20:27:02.356Z,1534796822.356 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-08-20T20:27:02.369Z,1534796822.369 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-08-20T20:27:02.450Z,1534796822.450 [MissionManager](IMPORTANT): Started mission Default
2018-08-20T20:27:02.451Z,1534796822.451 [Default] Running Loop=1
2018-08-20T20:27:02.451Z,1534796822.451 [Default](DEBUG): Aggregate::initialize Default
2018-08-20T20:27:02.451Z,1534796822.451 [Default:B.GoToSurface] Running Loop=1
2018-08-20T20:27:02.451Z,1534796822.451 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-20T20:27:02.451Z,1534796822.451 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-20T20:27:02.452Z,1534796822.452 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-20T20:27:02.452Z,1534796822.452 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-20T20:27:02.457Z,1534796822.457 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-20T20:27:02.457Z,1534796822.457 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-20T20:27:02.458Z,1534796822.458 [Default:A.Wait] Running Loop=1
2018-08-20T20:27:02.458Z,1534796822.458 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-08-20T20:27:02.569Z,1534796822.569 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-08-20T20:27:02.598Z,1534796822.598 [WetLabsBB2FL](INFO): Powering down
2018-08-20T20:27:02.613Z,1534796822.613 [CTD_NeilBrown](DEBUG): serial timeout
2018-08-20T20:27:02.644Z,1534796822.644 [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-20T20:27:02.646Z,1534796822.646 [CTD_Seabird](INFO): LCM subscribed to channel:seabird_gpctd_t.seabird-gpctd
2018-08-20T20:27:02.851Z,1534796822.851 [Aanderaa_O2](INFO): Powering down
2018-08-20T20:27:03.003Z,1534796823.003 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-08-20T20:27:03.004Z,1534796823.004 [CTD_Seabird](INFO): Powering down
2018-08-20T20:27:15.636Z,1534796835.636 [Default:A.Wait](INFO): Done Waiting.
2018-08-20T20:27:15.637Z,1534796835.637 [Default:A.Wait] Stopped
2018-08-20T20:27:15.637Z,1534796835.637 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-08-20T20:27:16.031Z,1534796836.031 [Default:CheckIn] Running Loop=1
2018-08-20T20:27:16.031Z,1534796836.031 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-20T20:27:16.032Z,1534796836.032 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-20T20:27:16.786Z,1534796836.786 [NAL9602](INFO): Powering up
2018-08-20T20:27:27.594Z,1534796847.594 [NAL9602](INFO): NAL9602 initialized
2018-08-20T20:27:42.788Z,1534796862.788 [NAL9602](INFO): SBD MO Status=0, MOMSN=8063, MT Status=0, MTMSN=0
2018-08-20T20:27:42.788Z,1534796862.788 [NAL9602](INFO): No messages in MT queue
2018-08-20T20:28:04.974Z,1534796884.974 [NAL9602](INFO): GPS fix at 20180820T202802: (36.802766, -121.786945)
2018-08-20T20:28:05.044Z,1534796885.044 [Default:CheckIn:Read_GPS] Stopped
2018-08-20T20:28:05.049Z,1534796885.049 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-20T20:28:09.747Z,1534796889.747 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20180820T200908/Courier0016.lzma
2018-08-20T20:28:10.541Z,1534796890.541 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Courier0016.lzma.bak
2018-08-20T20:28:10.541Z,1534796890.541 [DataOverHttps](INFO): SBD MOMSN=8430626
2018-08-20T20:28:19.381Z,1534796899.381 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180820T200908/Courier0019.lzma
2018-08-20T20:28:20.472Z,1534796900.472 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Courier0019.lzma.bak
2018-08-20T20:28:20.472Z,1534796900.472 [DataOverHttps](INFO): SBD MOMSN=8430629
2018-08-20T20:28:31.196Z,1534796911.196 [DataOverHttps](INFO): Sending 450 bytes from file Logs/20180820T200908/Express0017.lzma
2018-08-20T20:28:31.995Z,1534796911.995 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Express0017.lzma.bak
2018-08-20T20:28:31.995Z,1534796911.995 [DataOverHttps](INFO): SBD MOMSN=8430631
2018-08-20T20:28:40.938Z,1534796920.938 [NAL9602](INFO): Powering down
2018-08-20T20:28:41.042Z,1534796921.042 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20180820T200908/Express0020.lzma
2018-08-20T20:28:41.843Z,1534796921.843 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Express0020.lzma.bak
2018-08-20T20:28:41.843Z,1534796921.843 [DataOverHttps](INFO): SBD MOMSN=8430651
2018-08-20T20:28:42.651Z,1534796922.651 [Default:CheckIn:Read_Iridium] Stopped
2018-08-20T20:28:42.651Z,1534796922.651 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-20T20:28:42.651Z,1534796922.651 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-20T20:29:32.452Z,1534796972.452 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-20T20:29:32.452Z,1534796972.452 [Rowe_600LCM] No Fault, FailCount= 5
2018-08-20T20:29:32.749Z,1534796972.749 [Rowe_600LCM](INFO): Initializing
2018-08-20T20:29:32.749Z,1534796972.749 [Rowe_600LCM](INFO): Checking LCM
2018-08-20T20:29:32.750Z,1534796972.750 [Rowe_600LCM](INFO): LCM OK
2018-08-20T20:29:32.750Z,1534796972.750 [Rowe_600LCM](INFO): Powering up
2018-08-20T20:29:37.012Z,1534796977.012 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-20T20:29:37.095Z,1534796977.095 [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-20T20:29:37.096Z,1534796977.096 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-20T20:29:37.096Z,1534796977.096 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-20T20:29:37.097Z,1534796977.097 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-20T20:31:32.841Z,1534797092.841 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-20T20:31:32.841Z,1534797092.841 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-08-20T20:31:32.841Z,1534797092.841 [Rowe_600LCM](ERROR): Communications Fault
2018-08-20T20:31:32.961Z,1534797092.961 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-20T20:31:33.245Z,1534797093.245 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-20T20:31:33.508Z,1534797093.508 [Rowe_600LCM](INFO): Powering down
2018-08-20T20:31:34.912Z,1534797094.912 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-20T20:31:34.912Z,1534797094.912 [Rowe_600LCM] No Fault, FailCount= 1
2018-08-20T20:31:35.125Z,1534797095.125 [Rowe_600LCM](INFO): Initializing
2018-08-20T20:31:35.125Z,1534797095.125 [Rowe_600LCM](INFO): Checking LCM
2018-08-20T20:31:35.126Z,1534797095.126 [Rowe_600LCM](INFO): LCM OK
2018-08-20T20:31:35.126Z,1534797095.126 [Rowe_600LCM](INFO): Powering up
2018-08-20T20:31:39.306Z,1534797099.306 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-20T20:31:39.406Z,1534797099.406 [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-20T20:31:39.407Z,1534797099.407 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-20T20:31:39.408Z,1534797099.408 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-20T20:31:39.408Z,1534797099.408 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-20T20:33:35.661Z,1534797215.661 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-20T20:33:35.661Z,1534797215.661 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-08-20T20:33:35.661Z,1534797215.661 [Rowe_600LCM](ERROR): Communications Fault
2018-08-20T20:33:36.053Z,1534797216.053 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-20T20:33:36.065Z,1534797216.065 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-20T20:33:36.227Z,1534797216.227 [Rowe_600LCM](INFO): Powering down
2018-08-20T20:33:37.637Z,1534797217.637 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-20T20:33:37.637Z,1534797217.637 [Rowe_600LCM] No Fault, FailCount= 2
2018-08-20T20:33:37.841Z,1534797217.841 [Rowe_600LCM](INFO): Initializing
2018-08-20T20:33:37.841Z,1534797217.841 [Rowe_600LCM](INFO): Checking LCM
2018-08-20T20:33:37.842Z,1534797217.842 [Rowe_600LCM](INFO): LCM OK
2018-08-20T20:33:37.842Z,1534797217.842 [Rowe_600LCM](INFO): Powering up
2018-08-20T20:33:42.075Z,1534797222.075 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-20T20:33:42.184Z,1534797222.184 [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-20T20:33:42.185Z,1534797222.185 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-20T20:33:42.186Z,1534797222.186 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-20T20:33:42.186Z,1534797222.186 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-20T20:33:42.849Z,1534797222.849 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-20T20:33:42.849Z,1534797222.849 [Default:CheckIn:C.Wait] Stopped
2018-08-20T20:33:42.849Z,1534797222.849 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-20T20:33:42.850Z,1534797222.850 [Default:CheckIn:D] Running Loop=1
2018-08-20T20:33:43.215Z,1534797223.215 [Default:CheckIn:D] Stopped
2018-08-20T20:33:43.216Z,1534797223.216 [Default:CheckIn:E] Running Loop=1
2018-08-20T20:33:43.615Z,1534797223.615 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.679409 min 
2018-08-20T20:33:43.615Z,1534797223.615 [Default:CheckIn:E] Stopped
2018-08-20T20:33:43.616Z,1534797223.616 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-20T20:33:43.616Z,1534797223.616 [Default:CheckIn] Stopped
2018-08-20T20:33:43.616Z,1534797223.616 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-20T20:33:43.616Z,1534797223.616 [Default:CheckIn](INFO): Running loop #2
2018-08-20T20:33:43.616Z,1534797223.616 [Default:CheckIn] Running Loop=2
2018-08-20T20:33:43.616Z,1534797223.616 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-20T20:33:43.617Z,1534797223.617 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-20T20:33:48.729Z,1534797228.729 [NAL9602](INFO): Powering up
2018-08-20T20:33:59.611Z,1534797239.611 [NAL9602](INFO): NAL9602 initialized
2018-08-20T20:34:22.012Z,1534797262.012 [NAL9602](INFO): SBD MO Status=2, MOMSN=8064, MT Status=2, MTMSN=0
2018-08-20T20:34:22.013Z,1534797262.013 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-20T20:34:39.212Z,1534797279.212 [NAL9602](INFO): SBD MO Status=2, MOMSN=8064, MT Status=2, MTMSN=0
2018-08-20T20:34:39.212Z,1534797279.212 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-20T20:34:57.580Z,1534797297.580 [NAL9602](INFO): SBD MO Status=0, MOMSN=8064, MT Status=0, MTMSN=0
2018-08-20T20:34:57.580Z,1534797297.580 [NAL9602](INFO): No messages in MT queue
2018-08-20T20:34:58.783Z,1534797298.783 [NAL9602](INFO): GPS fix at 20180820T203456: (36.802734, -121.786973)
2018-08-20T20:34:58.863Z,1534797298.863 [Default:CheckIn:Read_GPS] Stopped
2018-08-20T20:34:58.863Z,1534797298.863 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-20T20:35:03.623Z,1534797303.623 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20180820T200908/Courier0022.lzma
2018-08-20T20:35:04.392Z,1534797304.392 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Courier0022.lzma.bak
2018-08-20T20:35:04.392Z,1534797304.392 [DataOverHttps](INFO): SBD MOMSN=8430654
2018-08-20T20:35:13.982Z,1534797313.982 [DataOverHttps](INFO): Sending 199 bytes from file Logs/20180820T200908/Express0023.lzma
2018-08-20T20:35:14.780Z,1534797314.780 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Express0023.lzma.bak
2018-08-20T20:35:14.780Z,1534797314.780 [DataOverHttps](INFO): SBD MOMSN=8430657
2018-08-20T20:35:15.611Z,1534797315.611 [Default:CheckIn:Read_Iridium] Stopped
2018-08-20T20:35:15.611Z,1534797315.611 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-20T20:35:15.611Z,1534797315.611 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-20T20:35:30.042Z,1534797330.042 [NAL9602](INFO): Powering down
2018-08-20T20:35:38.545Z,1534797338.545 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-20T20:35:38.545Z,1534797338.545 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-08-20T20:35:38.545Z,1534797338.545 [Rowe_600LCM](ERROR): Communications Fault
2018-08-20T20:35:38.920Z,1534797338.920 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-20T20:35:38.949Z,1534797338.949 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-20T20:35:39.092Z,1534797339.092 [Rowe_600LCM](INFO): Powering down
2018-08-20T20:35:39.903Z,1534797339.903 [Rowe_600LCM](FAULT): LCB fault:  Software Overcurrent.
2018-08-20T20:35:39.903Z,1534797339.903 [Rowe_600LCM] Hardware Fault, FailCount= 3
2018-08-20T20:35:39.903Z,1534797339.903 [Rowe_600LCM](ERROR): Hardware Fault
2018-08-20T20:35:40.586Z,1534797340.586 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-20T20:35:40.586Z,1534797340.586 [Rowe_600LCM] No Fault, FailCount= 3
2018-08-20T20:35:40.709Z,1534797340.709 [Rowe_600LCM](INFO): Initializing
2018-08-20T20:35:40.709Z,1534797340.709 [Rowe_600LCM](INFO): Checking LCM
2018-08-20T20:35:40.710Z,1534797340.710 [Rowe_600LCM](INFO): LCM OK
2018-08-20T20:35:40.710Z,1534797340.710 [Rowe_600LCM](INFO): Powering up
2018-08-20T20:35:44.900Z,1534797344.900 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-20T20:35:45.020Z,1534797345.020 [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-20T20:35:45.021Z,1534797345.021 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-20T20:35:45.022Z,1534797345.022 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-20T20:35:45.022Z,1534797345.022 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-20T20:37:40.797Z,1534797460.797 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-20T20:37:40.797Z,1534797460.797 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-08-20T20:37:40.797Z,1534797460.797 [Rowe_600LCM](ERROR): Communications Fault
2018-08-20T20:37:40.949Z,1534797460.949 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-20T20:37:41.201Z,1534797461.201 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-20T20:37:41.460Z,1534797461.460 [Rowe_600LCM](INFO): Powering down
2018-08-20T20:37:42.875Z,1534797462.875 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-20T20:37:42.875Z,1534797462.875 [Rowe_600LCM] No Fault, FailCount= 4
2018-08-20T20:37:43.077Z,1534797463.077 [Rowe_600LCM](INFO): Initializing
2018-08-20T20:37:43.078Z,1534797463.078 [Rowe_600LCM](INFO): Checking LCM
2018-08-20T20:37:43.078Z,1534797463.078 [Rowe_600LCM](INFO): LCM OK
2018-08-20T20:37:43.078Z,1534797463.078 [Rowe_600LCM](INFO): Powering up
2018-08-20T20:37:47.260Z,1534797467.260 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-20T20:37:47.360Z,1534797467.360 [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-20T20:37:47.361Z,1534797467.361 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-20T20:37:47.362Z,1534797467.362 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-20T20:37:47.363Z,1534797467.363 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-20T20:39:43.721Z,1534797583.721 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-20T20:39:43.721Z,1534797583.721 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-08-20T20:39:43.721Z,1534797583.721 [Rowe_600LCM](ERROR): Communications Fault
2018-08-20T20:39:43.843Z,1534797583.843 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-20T20:39:43.844Z,1534797583.844 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-08-20T20:39:44.125Z,1534797584.125 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-20T20:39:44.390Z,1534797584.390 [Rowe_600LCM](INFO): Powering down
2018-08-20T20:40:15.787Z,1534797615.787 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-20T20:40:15.787Z,1534797615.787 [Default:CheckIn:C.Wait] Stopped
2018-08-20T20:40:15.787Z,1534797615.787 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-20T20:40:15.788Z,1534797615.788 [Default:CheckIn:D] Running Loop=1
2018-08-20T20:40:16.196Z,1534797616.196 [Default:CheckIn:D] Stopped
2018-08-20T20:40:16.201Z,1534797616.201 [Default:CheckIn:E] Running Loop=1
2018-08-20T20:40:16.598Z,1534797616.598 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.229094 min 
2018-08-20T20:40:16.598Z,1534797616.598 [Default:CheckIn:E] Stopped
2018-08-20T20:40:16.599Z,1534797616.599 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-20T20:40:16.599Z,1534797616.599 [Default:CheckIn] Stopped
2018-08-20T20:40:16.599Z,1534797616.599 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-20T20:40:16.599Z,1534797616.599 [Default:CheckIn](INFO): Running loop #3
2018-08-20T20:40:16.599Z,1534797616.599 [Default:CheckIn] Running Loop=3
2018-08-20T20:40:16.599Z,1534797616.599 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-20T20:40:16.599Z,1534797616.599 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-20T20:40:20.057Z,1534797620.057 [NAL9602](INFO): Powering up
2018-08-20T20:40:30.982Z,1534797630.982 [NAL9602](INFO): NAL9602 initialized
2018-08-20T20:40:50.584Z,1534797650.584 [NAL9602](INFO): SBD MO Status=2, MOMSN=8065, MT Status=2, MTMSN=0
2018-08-20T20:40:50.584Z,1534797650.584 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-20T20:41:58.192Z,1534797718.192 [NAL9602](INFO): SBD MO Status=2, MOMSN=8065, MT Status=2, MTMSN=0
2018-08-20T20:41:58.192Z,1534797718.192 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-20T20:42:06.996Z,1534797726.996 [NAL9602](INFO): SBD MO Status=0, MOMSN=8065, MT Status=0, MTMSN=0
2018-08-20T20:42:06.996Z,1534797726.996 [NAL9602](INFO): No messages in MT queue
2018-08-20T20:42:08.194Z,1534797728.194 [NAL9602](INFO): GPS fix at 20180820T204206: (36.802743, -121.786935)
2018-08-20T20:42:08.273Z,1534797728.273 [Default:CheckIn:Read_GPS] Stopped
2018-08-20T20:42:08.273Z,1534797728.273 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-20T20:42:12.978Z,1534797732.978 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20180820T200908/Courier0025.lzma
2018-08-20T20:42:13.779Z,1534797733.779 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Courier0025.lzma.bak
2018-08-20T20:42:13.780Z,1534797733.780 [DataOverHttps](INFO): SBD MOMSN=8430663
2018-08-20T20:42:23.548Z,1534797743.548 [DataOverHttps](INFO): Sending 285 bytes from file Logs/20180820T200908/Express0026.lzma
2018-08-20T20:42:24.324Z,1534797744.324 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Express0026.lzma.bak
2018-08-20T20:42:24.324Z,1534797744.324 [DataOverHttps](INFO): SBD MOMSN=8430666
2018-08-20T20:42:25.302Z,1534797745.302 [Default:CheckIn:Read_Iridium] Stopped
2018-08-20T20:42:25.302Z,1534797745.302 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-20T20:42:25.302Z,1534797745.302 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-20T20:42:43.034Z,1534797763.034 [NAL9602](INFO): Powering down
2018-08-20T20:44:31.199Z,1534797871.199 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.429029 seconds old.
2018-08-20T20:44:31.568Z,1534797871.568 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.797568 seconds old.
2018-08-20T20:44:31.979Z,1534797871.979 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.208649 seconds old.
2018-08-20T20:44:32.378Z,1534797872.378 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.608035 seconds old.
2018-08-20T20:47:25.854Z,1534798045.854 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-20T20:47:25.854Z,1534798045.854 [Default:CheckIn:C.Wait] Stopped
2018-08-20T20:47:25.854Z,1534798045.854 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-20T20:47:25.855Z,1534798045.855 [Default:CheckIn:D] Running Loop=1
2018-08-20T20:47:26.249Z,1534798046.249 [Default:CheckIn:D] Stopped
2018-08-20T20:47:26.249Z,1534798046.249 [Default:CheckIn:E] Running Loop=1
2018-08-20T20:47:29.365Z,1534798049.365 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.396639 min 
2018-08-20T20:47:29.365Z,1534798049.365 [Default:CheckIn:E] Stopped
2018-08-20T20:47:29.365Z,1534798049.365 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-20T20:47:29.365Z,1534798049.365 [Default:CheckIn] Stopped
2018-08-20T20:47:29.365Z,1534798049.365 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-20T20:47:29.366Z,1534798049.366 [Default:CheckIn](INFO): Running loop #4
2018-08-20T20:47:29.366Z,1534798049.366 [Default:CheckIn] Running Loop=4
2018-08-20T20:47:29.366Z,1534798049.366 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-20T20:47:29.366Z,1534798049.366 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-20T20:47:29.822Z,1534798049.822 [NAL9602](INFO): Powering up
2018-08-20T20:47:41.022Z,1534798061.022 [NAL9602](INFO): NAL9602 initialized
2018-08-20T20:47:57.028Z,1534798077.028 [NAL9602](INFO): SBD MO Status=0, MOMSN=8066, MT Status=0, MTMSN=0
2018-08-20T20:47:57.028Z,1534798077.028 [NAL9602](INFO): No messages in MT queue
2018-08-20T20:48:04.226Z,1534798084.226 [NAL9602](INFO): GPS fix at 20180820T204802: (36.802803, -121.786950)
2018-08-20T20:48:04.300Z,1534798084.300 [Default:CheckIn:Read_GPS] Stopped
2018-08-20T20:48:04.300Z,1534798084.300 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-20T20:48:08.678Z,1534798088.678 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20180820T200908/Courier0028.lzma
2018-08-20T20:48:09.447Z,1534798089.447 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Courier0028.lzma.bak
2018-08-20T20:48:09.447Z,1534798089.447 [DataOverHttps](INFO): SBD MOMSN=8430675
2018-08-20T20:48:18.695Z,1534798098.695 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20180820T200908/Express0029.lzma
2018-08-20T20:48:19.483Z,1534798099.483 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Express0029.lzma.bak
2018-08-20T20:48:19.484Z,1534798099.484 [DataOverHttps](INFO): SBD MOMSN=8430678
2018-08-20T20:48:20.256Z,1534798100.256 [Default:CheckIn:Read_Iridium] Stopped
2018-08-20T20:48:20.256Z,1534798100.256 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-20T20:48:20.256Z,1534798100.256 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-20T20:48:38.878Z,1534798118.878 [NAL9602](INFO): Powering down
2018-08-20T20:49:43.748Z,1534798183.748 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-20T20:49:43.748Z,1534798183.748 [Rowe_600LCM] No Fault, FailCount= 5
2018-08-20T20:49:43.813Z,1534798183.813 [Rowe_600LCM](INFO): Initializing
2018-08-20T20:49:43.813Z,1534798183.813 [Rowe_600LCM](INFO): Checking LCM
2018-08-20T20:49:43.813Z,1534798183.813 [Rowe_600LCM](INFO): LCM OK
2018-08-20T20:49:43.814Z,1534798183.814 [Rowe_600LCM](INFO): Powering up
2018-08-20T20:49:47.944Z,1534798187.944 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-20T20:49:48.023Z,1534798188.023 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-08-20T20:49:48.033Z,1534798188.033 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-20T20:49:48.034Z,1534798188.034 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-20T20:49:48.034Z,1534798188.034 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-20T20:51:44.401Z,1534798304.401 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-20T20:51:44.401Z,1534798304.401 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-08-20T20:51:44.401Z,1534798304.401 [Rowe_600LCM](ERROR): Communications Fault
2018-08-20T20:51:44.613Z,1534798304.613 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-20T20:51:44.805Z,1534798304.805 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-20T20:51:44.928Z,1534798304.928 [Rowe_600LCM](INFO): Powering down
2018-08-20T20:51:46.220Z,1534798306.220 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-20T20:51:46.220Z,1534798306.220 [Rowe_600LCM] No Fault, FailCount= 1
2018-08-20T20:51:46.545Z,1534798306.545 [Rowe_600LCM](INFO): Initializing
2018-08-20T20:51:46.546Z,1534798306.546 [Rowe_600LCM](INFO): Checking LCM
2018-08-20T20:51:46.546Z,1534798306.546 [Rowe_600LCM](INFO): LCM OK
2018-08-20T20:51:46.546Z,1534798306.546 [Rowe_600LCM](INFO): Powering up
2018-08-20T20:51:50.740Z,1534798310.740 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-20T20:51:50.819Z,1534798310.819 [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-20T20:51:50.820Z,1534798310.820 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-20T20:51:50.821Z,1534798310.821 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-20T20:51:50.822Z,1534798310.822 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-20T20:53:20.524Z,1534798400.524 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-20T20:53:20.529Z,1534798400.529 [Default:CheckIn:C.Wait] Stopped
2018-08-20T20:53:20.529Z,1534798400.529 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-20T20:53:20.530Z,1534798400.530 [Default:CheckIn:D] Running Loop=1
2018-08-20T20:53:20.928Z,1534798400.928 [Default:CheckIn:D] Stopped
2018-08-20T20:53:20.928Z,1534798400.928 [Default:CheckIn:E] Running Loop=1
2018-08-20T20:53:21.324Z,1534798401.324 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.307955 min 
2018-08-20T20:53:21.324Z,1534798401.324 [Default:CheckIn:E] Stopped
2018-08-20T20:53:21.329Z,1534798401.329 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-20T20:53:21.329Z,1534798401.329 [Default:CheckIn] Stopped
2018-08-20T20:53:21.329Z,1534798401.329 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-20T20:53:21.329Z,1534798401.329 [Default:CheckIn](INFO): Running loop #5
2018-08-20T20:53:21.329Z,1534798401.329 [Default:CheckIn] Running Loop=5
2018-08-20T20:53:21.330Z,1534798401.330 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-20T20:53:21.330Z,1534798401.330 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-20T20:53:25.117Z,1534798405.117 [NAL9602](INFO): Powering up
2018-08-20T20:53:36.031Z,1534798416.031 [NAL9602](INFO): NAL9602 initialized
2018-08-20T20:53:47.221Z,1534798427.221 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-20T20:53:47.221Z,1534798427.221 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-08-20T20:53:47.221Z,1534798427.221 [Rowe_600LCM](ERROR): Communications Fault
2018-08-20T20:53:47.348Z,1534798427.348 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-20T20:53:47.625Z,1534798427.625 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-20T20:53:47.886Z,1534798427.886 [Rowe_600LCM](INFO): Powering down
2018-08-20T20:53:49.298Z,1534798429.298 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-20T20:53:49.298Z,1534798429.298 [Rowe_600LCM] No Fault, FailCount= 2
2018-08-20T20:53:49.501Z,1534798429.501 [Rowe_600LCM](INFO): Initializing
2018-08-20T20:53:49.502Z,1534798429.502 [Rowe_600LCM](INFO): Checking LCM
2018-08-20T20:53:49.502Z,1534798429.502 [Rowe_600LCM](INFO): LCM OK
2018-08-20T20:53:49.502Z,1534798429.502 [Rowe_600LCM](INFO): Powering up
2018-08-20T20:53:53.682Z,1534798433.682 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-20T20:53:53.780Z,1534798433.780 [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-20T20:53:53.781Z,1534798433.781 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-20T20:53:53.781Z,1534798433.781 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-20T20:53:53.782Z,1534798433.782 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-20T20:54:01.641Z,1534798441.641 [NAL9602](INFO): SBD MO Status=2, MOMSN=8067, MT Status=2, MTMSN=0
2018-08-20T20:54:01.641Z,1534798441.641 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-08-20T20:54:12.032Z,1534798452.032 [NAL9602](INFO): SBD MO Status=0, MOMSN=8067, MT Status=0, MTMSN=0
2018-08-20T20:54:12.032Z,1534798452.032 [NAL9602](INFO): No messages in MT queue
2018-08-20T20:54:13.244Z,1534798453.244 [NAL9602](INFO): GPS fix at 20180820T205411: (36.802701, -121.786865)
2018-08-20T20:54:13.330Z,1534798453.330 [Default:CheckIn:Read_GPS] Stopped
2018-08-20T20:54:13.330Z,1534798453.330 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-20T20:54:18.122Z,1534798458.122 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20180820T200908/Courier0031.lzma
2018-08-20T20:54:18.852Z,1534798458.852 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Courier0031.lzma.bak
2018-08-20T20:54:18.852Z,1534798458.852 [DataOverHttps](INFO): SBD MOMSN=8430682
2018-08-20T20:54:30.074Z,1534798470.074 [DataOverHttps](INFO): Sending 201 bytes from file Logs/20180820T200908/Express0032.lzma
2018-08-20T20:54:30.832Z,1534798470.832 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Express0032.lzma.bak
2018-08-20T20:54:30.832Z,1534798470.832 [DataOverHttps](INFO): SBD MOMSN=8430685
2018-08-20T20:54:31.680Z,1534798471.680 [Default:CheckIn:Read_Iridium] Stopped
2018-08-20T20:54:31.680Z,1534798471.680 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-20T20:54:31.680Z,1534798471.680 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-20T20:54:48.418Z,1534798488.418 [NAL9602](INFO): Powering down
2018-08-20T20:55:49.601Z,1534798549.601 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-20T20:55:49.601Z,1534798549.601 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-08-20T20:55:49.601Z,1534798549.601 [Rowe_600LCM](ERROR): Communications Fault
2018-08-20T20:55:49.715Z,1534798549.715 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-20T20:55:50.006Z,1534798550.006 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-20T20:55:50.257Z,1534798550.257 [Rowe_600LCM](INFO): Powering down
2018-08-20T20:55:51.677Z,1534798551.677 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-20T20:55:51.677Z,1534798551.677 [Rowe_600LCM] No Fault, FailCount= 3
2018-08-20T20:55:51.875Z,1534798551.875 [Rowe_600LCM](INFO): Initializing
2018-08-20T20:55:51.875Z,1534798551.875 [Rowe_600LCM](INFO): Checking LCM
2018-08-20T20:55:51.875Z,1534798551.875 [Rowe_600LCM](INFO): LCM OK
2018-08-20T20:55:51.875Z,1534798551.875 [Rowe_600LCM](INFO): Powering up
2018-08-20T20:55:56.089Z,1534798556.089 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-20T20:55:56.223Z,1534798556.223 [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-20T20:55:56.224Z,1534798556.224 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-20T20:55:56.225Z,1534798556.225 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-20T20:55:56.226Z,1534798556.226 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-20T20:57:52.613Z,1534798672.613 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-20T20:57:52.613Z,1534798672.613 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-08-20T20:57:52.613Z,1534798672.613 [Rowe_600LCM](ERROR): Communications Fault
2018-08-20T20:57:52.900Z,1534798672.900 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-20T20:57:53.017Z,1534798673.017 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-20T20:57:53.138Z,1534798673.138 [Rowe_600LCM](INFO): Powering down
2018-08-20T20:57:54.475Z,1534798674.475 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-20T20:57:54.476Z,1534798674.476 [Rowe_600LCM] No Fault, FailCount= 4
2018-08-20T20:57:54.753Z,1534798674.753 [Rowe_600LCM](INFO): Initializing
2018-08-20T20:57:54.753Z,1534798674.753 [Rowe_600LCM](INFO): Checking LCM
2018-08-20T20:57:54.754Z,1534798674.754 [Rowe_600LCM](INFO): LCM OK
2018-08-20T20:57:54.754Z,1534798674.754 [Rowe_600LCM](INFO): Powering up
2018-08-20T20:57:59.002Z,1534798679.002 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-20T20:57:59.071Z,1534798679.071 [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-20T20:57:59.073Z,1534798679.073 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-20T20:57:59.073Z,1534798679.073 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-20T20:57:59.074Z,1534798679.074 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-20T20:59:32.202Z,1534798772.202 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-20T20:59:32.203Z,1534798772.203 [Default:CheckIn:C.Wait] Stopped
2018-08-20T20:59:32.203Z,1534798772.203 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-20T20:59:32.203Z,1534798772.203 [Default:CheckIn:D] Running Loop=1
2018-08-20T20:59:32.590Z,1534798772.590 [Default:CheckIn:D] Stopped
2018-08-20T20:59:32.590Z,1534798772.590 [Default:CheckIn:E] Running Loop=1
2018-08-20T20:59:33.007Z,1534798773.007 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.502325 min 
2018-08-20T20:59:33.008Z,1534798773.008 [Default:CheckIn:E] Stopped
2018-08-20T20:59:33.008Z,1534798773.008 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-20T20:59:33.008Z,1534798773.008 [Default:CheckIn] Stopped
2018-08-20T20:59:33.008Z,1534798773.008 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-20T20:59:33.008Z,1534798773.008 [Default:CheckIn](INFO): Running loop #6
2018-08-20T20:59:33.008Z,1534798773.008 [Default:CheckIn] Running Loop=6
2018-08-20T20:59:33.009Z,1534798773.009 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-20T20:59:33.009Z,1534798773.009 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-20T20:59:36.785Z,1534798776.785 [NAL9602](INFO): Powering up
2018-08-20T20:59:47.699Z,1534798787.699 [NAL9602](INFO): NAL9602 initialized
2018-08-20T20:59:55.293Z,1534798795.293 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-20T20:59:55.293Z,1534798795.293 [Rowe_600LCM] Communications Fault, FailCount= 5
2018-08-20T20:59:55.293Z,1534798795.293 [Rowe_600LCM](ERROR): Communications Fault
2018-08-20T20:59:55.408Z,1534798795.408 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-20T20:59:55.408Z,1534798795.408 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2018-08-20T20:59:55.697Z,1534798795.697 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-20T20:59:55.949Z,1534798795.949 [Rowe_600LCM](INFO): Powering down
2018-08-20T21:00:06.500Z,1534798806.500 [NAL9602](INFO): SBD MO Status=0, MOMSN=8068, MT Status=0, MTMSN=0
2018-08-20T21:00:06.500Z,1534798806.500 [NAL9602](INFO): No messages in MT queue
2018-08-20T21:00:28.102Z,1534798828.102 [NAL9602](INFO): GPS fix at 20180820T210026: (36.805368, -121.785415)
2018-08-20T21:00:28.180Z,1534798828.180 [Default:CheckIn:Read_GPS] Stopped
2018-08-20T21:00:28.181Z,1534798828.181 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-20T21:00:32.553Z,1534798832.553 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20180820T200908/Courier0034.lzma
2018-08-20T21:00:33.327Z,1534798833.327 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Courier0034.lzma.bak
2018-08-20T21:00:33.327Z,1534798833.327 [DataOverHttps](INFO): SBD MOMSN=8430691
2018-08-20T21:00:42.734Z,1534798842.734 [DataOverHttps](INFO): Sending 268 bytes from file Logs/20180820T200908/Express0035.lzma
2018-08-20T21:00:43.519Z,1534798843.519 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Express0035.lzma.bak
2018-08-20T21:00:43.519Z,1534798843.519 [DataOverHttps](INFO): SBD MOMSN=8430694
2018-08-20T21:00:44.284Z,1534798844.284 [Default:CheckIn:Read_Iridium] Stopped
2018-08-20T21:00:44.284Z,1534798844.284 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-20T21:00:44.284Z,1534798844.284 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-20T21:01:02.950Z,1534798862.950 [NAL9602](INFO): Powering down
2018-08-20T21:05:44.581Z,1534799144.581 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-20T21:05:44.581Z,1534799144.581 [Default:CheckIn:C.Wait] Stopped
2018-08-20T21:05:44.581Z,1534799144.581 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-20T21:05:44.582Z,1534799144.582 [Default:CheckIn:D] Running Loop=1
2018-08-20T21:05:44.983Z,1534799144.983 [Default:CheckIn:D] Stopped
2018-08-20T21:05:44.983Z,1534799144.983 [Default:CheckIn:E] Running Loop=1
2018-08-20T21:05:45.385Z,1534799145.385 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.708870 min 
2018-08-20T21:05:45.386Z,1534799145.386 [Default:CheckIn:E] Stopped
2018-08-20T21:05:45.386Z,1534799145.386 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-20T21:05:45.386Z,1534799145.386 [Default:CheckIn] Stopped
2018-08-20T21:05:45.386Z,1534799145.386 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-20T21:05:45.386Z,1534799145.386 [Default:CheckIn](INFO): Running loop #7
2018-08-20T21:05:45.386Z,1534799145.386 [Default:CheckIn] Running Loop=7
2018-08-20T21:05:45.386Z,1534799145.386 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-20T21:05:45.387Z,1534799145.387 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-20T21:05:48.626Z,1534799148.626 [NAL9602](INFO): Powering up
2018-08-20T21:05:59.771Z,1534799159.771 [NAL9602](INFO): NAL9602 initialized
2018-08-20T21:06:13.768Z,1534799173.768 [NAL9602](INFO): SBD MO Status=0, MOMSN=8069, MT Status=0, MTMSN=0
2018-08-20T21:06:13.768Z,1534799173.768 [NAL9602](INFO): No messages in MT queue
2018-08-20T21:06:32.970Z,1534799192.970 [NAL9602](INFO): GPS fix at 20180820T210631: (36.805002, -121.801813)
2018-08-20T21:06:33.046Z,1534799193.046 [Default:CheckIn:Read_GPS] Stopped
2018-08-20T21:06:33.047Z,1534799193.047 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-08-20T21:06:37.461Z,1534799197.461 [DataOverHttps](INFO): Sending 65 bytes from file Logs/20180820T200908/Courier0037.lzma
2018-08-20T21:06:38.247Z,1534799198.247 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Courier0037.lzma.bak
2018-08-20T21:06:38.247Z,1534799198.247 [DataOverHttps](INFO): SBD MOMSN=8430702
2018-08-20T21:06:47.575Z,1534799207.575 [DataOverHttps](INFO): Sending 133 bytes from file Logs/20180820T200908/Express0038.lzma
2018-08-20T21:06:48.375Z,1534799208.375 [DataOverHttps](INFO): Moved sent file to Logs/20180820T200908/Express0038.lzma.bak
2018-08-20T21:06:48.376Z,1534799208.376 [DataOverHttps](INFO): SBD MOMSN=8430705
2018-08-20T21:06:49.238Z,1534799209.238 [Default:CheckIn:Read_Iridium] Stopped
2018-08-20T21:06:49.238Z,1534799209.238 [Default:CheckIn:C.Wait] Running Loop=1
2018-08-20T21:06:49.239Z,1534799209.239 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-08-20T21:07:07.830Z,1534799227.830 [NAL9602](INFO): Powering down
2018-08-20T21:09:55.507Z,1534799395.507 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-20T21:09:55.507Z,1534799395.507 [Rowe_600LCM] No Fault, FailCount= 5
2018-08-20T21:09:55.806Z,1534799395.806 [Rowe_600LCM](INFO): Initializing
2018-08-20T21:09:55.806Z,1534799395.806 [Rowe_600LCM](INFO): Checking LCM
2018-08-20T21:09:55.806Z,1534799395.806 [Rowe_600LCM](INFO): LCM OK
2018-08-20T21:09:55.806Z,1534799395.806 [Rowe_600LCM](INFO): Powering up
2018-08-20T21:10:00.064Z,1534799400.064 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-20T21:10:00.144Z,1534799400.144 [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-20T21:10:00.145Z,1534799400.145 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-20T21:10:00.146Z,1534799400.146 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-20T21:10:00.146Z,1534799400.146 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-20T21:11:49.592Z,1534799509.592 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-08-20T21:11:49.592Z,1534799509.592 [Default:CheckIn:C.Wait] Stopped
2018-08-20T21:11:49.592Z,1534799509.592 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-08-20T21:11:49.592Z,1534799509.592 [Default:CheckIn:D] Running Loop=1
2018-08-20T21:11:50.023Z,1534799510.023 [Default:CheckIn:D] Stopped
2018-08-20T21:11:50.024Z,1534799510.024 [Default:CheckIn:E] Running Loop=1
2018-08-20T21:11:50.407Z,1534799510.407 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.792875 min 
2018-08-20T21:11:50.408Z,1534799510.408 [Default:CheckIn:E] Stopped
2018-08-20T21:11:50.408Z,1534799510.408 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-08-20T21:11:50.408Z,1534799510.408 [Default:CheckIn] Stopped
2018-08-20T21:11:50.408Z,1534799510.408 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-08-20T21:11:50.408Z,1534799510.408 [Default:CheckIn](INFO): Running loop #8
2018-08-20T21:11:50.408Z,1534799510.408 [Default:CheckIn] Running Loop=8
2018-08-20T21:11:50.408Z,1534799510.408 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-08-20T21:11:50.409Z,1534799510.409 [Default:CheckIn:Read_GPS] Running Loop=1
2018-08-20T21:11:54.209Z,1534799514.209 [NAL9602](INFO): Powering up
2018-08-20T21:11:56.369Z,1534799516.369 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-20T21:11:56.369Z,1534799516.369 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-08-20T21:11:56.369Z,1534799516.369 [Rowe_600LCM](ERROR): Communications Fault
2018-08-20T21:11:56.439Z,1534799516.439 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-20T21:11:56.773Z,1534799516.773 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-20T21:11:56.986Z,1534799516.986 [Rowe_600LCM](INFO): Powering down
2018-08-20T21:11:58.402Z,1534799518.402 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-20T21:11:58.402Z,1534799518.402 [Rowe_600LCM] No Fault, FailCount= 1
2018-08-20T21:11:58.601Z,1534799518.601 [Rowe_600LCM](INFO): Initializing
2018-08-20T21:11:58.601Z,1534799518.601 [Rowe_600LCM](INFO): Checking LCM
2018-08-20T21:11:58.602Z,1534799518.602 [Rowe_600LCM](INFO): LCM OK
2018-08-20T21:11:58.602Z,1534799518.602 [Rowe_600LCM](INFO): Powering up
2018-08-20T21:12:02.781Z,1534799522.781 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-20T21:12:02.940Z,1534799522.940 [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-20T21:12:02.941Z,1534799522.941 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-20T21:12:02.942Z,1534799522.942 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-20T21:12:02.942Z,1534799522.942 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-20T21:12:05.130Z,1534799525.130 [NAL9602](INFO): NAL9602 initialized
2018-08-20T21:12:23.933Z,1534799543.933 [NAL9602](INFO): SBD MO Status=0, MOMSN=8070, MT Status=0, MTMSN=0
2018-08-20T21:12:23.933Z,1534799543.933 [NAL9602](INFO): No messages in MT queue
2018-08-20T21:13:57.099Z,1534799637.099 [DataOverHttps](IMPORTANT): SBD MTMSN=20180820T211356
2018-08-20T21:13:59.385Z,1534799639.385 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-20T21:13:59.385Z,1534799639.385 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-08-20T21:13:59.385Z,1534799639.385 [Rowe_600LCM](ERROR): Communications Fault
2018-08-20T21:13:59.789Z,1534799639.789 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-20T21:14:00.003Z,1534799640.003 [Rowe_600LCM](INFO): Powering down
2018-08-20T21:14:00.809Z,1534799640.809 [Rowe_600LCM](FAULT): LCB fault:  Software Overcurrent.
2018-08-20T21:14:00.809Z,1534799640.809 [Rowe_600LCM] Hardware Fault, FailCount= 2
2018-08-20T21:14:00.809Z,1534799640.809 [Rowe_600LCM](ERROR): Hardware Fault
2018-08-20T21:14:01.566Z,1534799641.566 [CBIT](ERROR): Hardware Fault in component: Rowe_600LCM
2018-08-20T21:14:01.566Z,1534799641.566 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-20T21:14:01.566Z,1534799641.566 [Rowe_600LCM] No Fault, FailCount= 2
2018-08-20T21:14:01.582Z,1534799641.582 [DataOverHttps](INFO): Received command:restart logs