2019-08-22T18:04:46.751Z,1566497086.751 [Supervisor](DEBUG): Initializing supervisor.
2019-08-22T18:04:46.754Z,1566497086.754 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-08-22T18:04:46.754Z,1566497086.754 [SyncHandler](INFO): Protected caller Thread ID is 1273
2019-08-22T18:04:46.755Z,1566497086.755 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-08-22T18:04:46.755Z,1566497086.755 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-08-22T18:04:46.756Z,1566497086.756 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1274
2019-08-22T18:04:46.759Z,1566497086.759 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-08-22T18:04:46.771Z,1566497086.771 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-08-22T18:04:46.772Z,1566497086.772 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-08-22T18:04:46.772Z,1566497086.772 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1275
2019-08-22T18:04:46.773Z,1566497086.773 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-08-22T18:04:46.774Z,1566497086.774 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-08-22T18:04:46.775Z,1566497086.775 [logger ThreadHandler](INFO): Protected caller Thread ID is 1276
2019-08-22T18:04:46.777Z,1566497086.777 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-08-22T18:04:46.777Z,1566497086.777 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-08-22T18:04:46.779Z,1566497086.779 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-08-22T18:04:46.874Z,1566497086.874 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-08-22T18:04:46.875Z,1566497086.875 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-08-22T18:04:47.123Z,1566497087.123 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-08-22T18:04:47.124Z,1566497087.124 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-08-22T18:04:47.417Z,1566497087.417 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-08-22T18:04:47.418Z,1566497087.418 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-08-22T18:04:47.997Z,1566497087.997 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-08-22T18:04:47.998Z,1566497087.998 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-08-22T18:04:48.452Z,1566497088.452 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-08-22T18:04:48.453Z,1566497088.453 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-08-22T18:04:48.940Z,1566497088.940 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-08-22T18:04:48.941Z,1566497088.941 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-08-22T18:04:49.258Z,1566497089.258 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-08-22T18:04:49.258Z,1566497089.258 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-08-22T18:04:49.601Z,1566497089.601 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-08-22T18:04:49.601Z,1566497089.601 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-08-22T18:04:50.005Z,1566497090.005 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-08-22T18:04:50.006Z,1566497090.006 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-08-22T18:04:50.157Z,1566497090.157 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-08-22T18:04:50.157Z,1566497090.157 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-08-22T18:04:50.263Z,1566497090.263 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-08-22T18:04:50.263Z,1566497090.263 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-08-22T18:04:50.344Z,1566497090.344 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-08-22T18:04:50.447Z,1566497090.447 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-08-22T18:04:50.448Z,1566497090.448 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-08-22T18:04:50.649Z,1566497090.649 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-08-22T18:04:50.649Z,1566497090.649 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-08-22T18:04:50.860Z,1566497090.860 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-08-22T18:04:50.862Z,1566497090.862 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2019-08-22T18:04:50.863Z,1566497090.863 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2019-08-22T18:04:50.947Z,1566497090.947 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2019-08-22T18:04:51.178Z,1566497091.178 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-08-22T18:04:51.179Z,1566497091.179 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2019-08-22T18:04:51.276Z,1566497091.276 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2019-08-22T18:04:51.452Z,1566497091.452 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2019-08-22T18:04:51.671Z,1566497091.671 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2019-08-22T18:04:51.757Z,1566497091.757 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2019-08-22T18:04:51.860Z,1566497091.860 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2019-08-22T18:04:51.955Z,1566497091.955 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2019-08-22T18:04:52.118Z,1566497092.118 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2019-08-22T18:04:52.574Z,1566497092.574 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2019-08-22T18:04:52.827Z,1566497092.827 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-08-22T18:04:52.842Z,1566497092.842 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-08-22T18:04:52.941Z,1566497092.941 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-08-22T18:04:52.942Z,1566497092.942 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-08-22T18:04:53.071Z,1566497093.071 [BuoyancyServo] Loaded
2019-08-22T18:04:53.071Z,1566497093.071 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-08-22T18:04:53.086Z,1566497093.086 [ElevatorServo] Loaded
2019-08-22T18:04:53.087Z,1566497093.087 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-08-22T18:04:53.101Z,1566497093.101 [MassServo] Loaded
2019-08-22T18:04:53.102Z,1566497093.102 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-08-22T18:04:53.117Z,1566497093.117 [RudderServo] Loaded
2019-08-22T18:04:53.117Z,1566497093.117 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-08-22T18:04:53.132Z,1566497093.132 [ThrusterServo] Loaded
2019-08-22T18:04:53.132Z,1566497093.132 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-08-22T18:04:53.132Z,1566497093.132 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-08-22T18:04:53.133Z,1566497093.133 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-08-22T18:04:53.271Z,1566497093.271 [SBIT](DEBUG): Construct Startup Built In Test.
2019-08-22T18:04:53.301Z,1566497093.301 [SBIT] Loaded
2019-08-22T18:04:53.301Z,1566497093.301 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-08-22T18:04:53.302Z,1566497093.302 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-08-22T18:04:53.330Z,1566497093.330 [IBIT] Loaded
2019-08-22T18:04:53.330Z,1566497093.330 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-08-22T18:04:53.333Z,1566497093.333 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-08-22T18:04:53.727Z,1566497093.727 [CBIT] Loaded
2019-08-22T18:04:53.728Z,1566497093.727 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-08-22T18:04:53.728Z,1566497093.728 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-08-22T18:04:53.728Z,1566497093.728 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-08-22T18:04:53.914Z,1566497093.914 [Aanderaa_O2] Loaded
2019-08-22T18:04:53.914Z,1566497093.914 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-08-22T18:04:53.923Z,1566497093.923 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-08-22T18:04:53.929Z,1566497093.929 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-08-22T18:04:53.930Z,1566497093.930 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-08-22T18:04:53.935Z,1566497093.935 [CTD_Seabird](INFO): created writer for : depth
2019-08-22T18:04:53.936Z,1566497093.936 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-08-22T18:04:53.941Z,1566497093.941 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-08-22T18:04:53.942Z,1566497093.942 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-08-22T18:04:53.947Z,1566497093.947 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-08-22T18:04:53.947Z,1566497093.947 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-08-22T18:04:53.952Z,1566497093.952 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-08-22T18:04:53.953Z,1566497093.953 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-08-22T18:04:53.959Z,1566497093.959 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-08-22T18:04:53.959Z,1566497093.959 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-08-22T18:04:53.964Z,1566497093.964 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-08-22T18:04:53.991Z,1566497093.991 [CTD_Seabird] Loaded
2019-08-22T18:04:53.991Z,1566497093.991 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-08-22T18:04:53.992Z,1566497093.992 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4066B4E0
2019-08-22T18:04:53.992Z,1566497093.992 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1355
2019-08-22T18:04:54.024Z,1566497094.024 [ESPComponent] Loaded
2019-08-22T18:04:54.024Z,1566497094.024 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-08-22T18:04:54.038Z,1566497094.038 [PAR_Licor] Loaded
2019-08-22T18:04:54.039Z,1566497094.039 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-08-22T18:04:54.087Z,1566497094.087 [WetLabsBB2FL] Loaded
2019-08-22T18:04:54.088Z,1566497094.088 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-08-22T18:04:54.089Z,1566497094.089 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4069B4E0
2019-08-22T18:04:54.089Z,1566497094.089 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1356
2019-08-22T18:04:54.090Z,1566497094.090 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-08-22T18:04:54.090Z,1566497094.090 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-08-22T18:04:54.132Z,1566497094.132 [DepthRateCalculator] Loaded
2019-08-22T18:04:54.133Z,1566497094.133 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-08-22T18:04:54.138Z,1566497094.138 [PitchRateCalculator] Loaded
2019-08-22T18:04:54.139Z,1566497094.139 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-08-22T18:04:54.155Z,1566497094.155 [SpeedCalculator] Loaded
2019-08-22T18:04:54.155Z,1566497094.155 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-08-22T18:04:54.179Z,1566497094.179 [TempGradientCalculator] Loaded
2019-08-22T18:04:54.180Z,1566497094.180 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-08-22T18:04:54.186Z,1566497094.186 [YawRateCalculator] Loaded
2019-08-22T18:04:54.186Z,1566497094.186 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-08-22T18:04:54.219Z,1566497094.219 [ElevatorOffsetCalculator] Loaded
2019-08-22T18:04:54.220Z,1566497094.220 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-08-22T18:04:54.220Z,1566497094.220 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-08-22T18:04:54.221Z,1566497094.221 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-08-22T18:04:54.252Z,1566497094.252 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-08-22T18:04:54.253Z,1566497094.253 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-08-22T18:04:54.358Z,1566497094.358 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-08-22T18:04:54.358Z,1566497094.358 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-08-22T18:04:54.379Z,1566497094.379 [NavChart] Loaded
2019-08-22T18:04:54.380Z,1566497094.380 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-08-22T18:04:54.384Z,1566497094.384 [UniversalFixResidualReporter] Loaded
2019-08-22T18:04:54.384Z,1566497094.384 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-08-22T18:04:54.384Z,1566497094.384 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-08-22T18:04:54.385Z,1566497094.385 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-08-22T18:04:54.739Z,1566497094.739 [AHRS_M2] Loaded
2019-08-22T18:04:54.739Z,1566497094.739 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-08-22T18:04:54.818Z,1566497094.818 [DataOverHttps] Loaded
2019-08-22T18:04:54.818Z,1566497094.818 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-08-22T18:04:54.819Z,1566497094.819 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409744E0
2019-08-22T18:04:54.820Z,1566497094.820 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1357
2019-08-22T18:04:54.833Z,1566497094.833 [Depth_Keller] Loaded
2019-08-22T18:04:54.833Z,1566497094.833 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-08-22T18:04:54.838Z,1566497094.838 [DropWeight] Loaded
2019-08-22T18:04:54.838Z,1566497094.838 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-08-22T18:04:54.930Z,1566497094.930 [NAL9602] Loaded
2019-08-22T18:04:54.930Z,1566497094.930 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-08-22T18:04:54.936Z,1566497094.936 [Onboard] Loaded
2019-08-22T18:04:54.936Z,1566497094.936 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-08-22T18:04:54.939Z,1566497094.939 [Radio_Surface] Loaded
2019-08-22T18:04:54.940Z,1566497094.940 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-08-22T18:04:54.941Z,1566497094.941 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409A44E0
2019-08-22T18:04:54.941Z,1566497094.941 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1358
2019-08-22T18:04:55.070Z,1566497095.070 [DAT] Loaded
2019-08-22T18:04:55.070Z,1566497095.070 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2019-08-22T18:04:56.361Z,1566497096.361 [BPC1] Loaded
2019-08-22T18:04:56.361Z,1566497096.361 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-08-22T18:04:56.362Z,1566497096.362 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-08-22T18:04:56.362Z,1566497096.362 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-08-22T18:04:56.432Z,1566497096.432 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-08-22T18:04:56.432Z,1566497096.432 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-08-22T18:04:56.498Z,1566497096.498 [VerticalControl](DEBUG): Construct VerticalControl.
2019-08-22T18:04:56.584Z,1566497096.584 [VerticalControl] Loaded
2019-08-22T18:04:56.584Z,1566497096.584 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-08-22T18:04:56.585Z,1566497096.585 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-08-22T18:04:56.643Z,1566497096.643 [HorizontalControl] Loaded
2019-08-22T18:04:56.644Z,1566497096.644 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-08-22T18:04:56.644Z,1566497096.644 [SpeedControl](DEBUG): Construct SpeedControl.
2019-08-22T18:04:56.646Z,1566497096.646 [SpeedControl] Loaded
2019-08-22T18:04:56.646Z,1566497096.646 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-08-22T18:04:56.647Z,1566497096.647 [LoopControl](DEBUG): Construct LoopControl.
2019-08-22T18:04:56.647Z,1566497096.647 [LoopControl] Loaded
2019-08-22T18:04:56.648Z,1566497096.648 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-08-22T18:04:56.648Z,1566497096.648 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-08-22T18:04:56.649Z,1566497096.649 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-08-22T18:04:56.662Z,1566497096.662 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-08-22T18:04:56.662Z,1566497096.662 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-08-22T18:04:56.956Z,1566497096.956 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-08-22T18:04:56.960Z,1566497096.960 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-08-22T18:04:56.961Z,1566497096.961 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-08-22T18:04:56.968Z,1566497096.968 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-08-22T18:04:56.969Z,1566497096.969 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ADF4E0
2019-08-22T18:04:56.969Z,1566497096.969 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1359
2019-08-22T18:04:56.974Z,1566497096.974 [Supervisor](INFO): Main Thread ID is 802
2019-08-22T18:04:56.974Z,1566497096.974 [Supervisor](DEBUG): Running supervisor.
2019-08-22T18:04:56.975Z,1566497096.975 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1360
2019-08-22T18:04:56.977Z,1566497096.977 [controlThread ThreadHandler](INFO): Handler Thread ID is 1361
2019-08-22T18:04:56.977Z,1566497096.977 [controlThread](DEBUG): Initializing ControlThread
2019-08-22T18:04:56.979Z,1566497096.979 [SBIT](INFO): Initialize SBIT Component.
2019-08-22T18:04:56.980Z,1566497096.980 [SBIT](IMPORTANT): git: 2019-08-13
2019-08-22T18:04:56.980Z,1566497096.980 [SBIT](INFO): git hash: 6b080875362fb71081cecd990260e30fa66d1cc0
2019-08-22T18:04:56.980Z,1566497096.980 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-08-22T18:04:56.982Z,1566497096.982 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-08-22T18:04:56.983Z,1566497096.983 [SBIT](INFO): Beginning SBIT in 63.000000 seconds.
2019-08-22T18:04:56.983Z,1566497096.983 [IBIT](INFO): Initialize IBIT Component.
2019-08-22T18:04:56.984Z,1566497096.984 [CBIT](DEBUG): Initialize CBIT Component.
2019-08-22T18:04:56.985Z,1566497096.985 [logger ThreadHandler](INFO): Handler Thread ID is 1362
2019-08-22T18:04:56.997Z,1566497096.997 [CBIT](DEBUG): Initialized mux pins.
2019-08-22T18:04:56.997Z,1566497096.997 [CBIT](DEBUG): Initializing the watchdog timer.
2019-08-22T18:04:57.005Z,1566497097.005 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1363
2019-08-22T18:04:57.006Z,1566497097.006 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-08-22T18:04:57.009Z,1566497097.009 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-08-22T18:04:57.011Z,1566497097.011 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1365
2019-08-22T18:04:57.012Z,1566497097.012 [WetLabsBB2FL](INFO): Powering down
2019-08-22T18:04:57.021Z,1566497097.021 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-08-22T18:04:57.021Z,1566497097.021 [CBIT](DEBUG): Initializing heartbeat.
2019-08-22T18:04:57.041Z,1566497097.041 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1366
2019-08-22T18:04:57.042Z,1566497097.042 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-08-22T18:04:57.053Z,1566497097.053 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1367
2019-08-22T18:04:57.069Z,1566497097.069 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1368
2019-08-22T18:04:57.072Z,1566497097.072 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-08-22T18:04:57.072Z,1566497097.072 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-08-22T18:04:57.073Z,1566497097.073 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-08-22T18:04:57.073Z,1566497097.073 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-08-22T18:04:57.073Z,1566497097.073 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-08-22T18:04:57.073Z,1566497097.073 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-08-22T18:04:57.074Z,1566497097.074 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-08-22T18:04:57.074Z,1566497097.074 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-08-22T18:04:57.074Z,1566497097.074 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-08-22T18:04:57.074Z,1566497097.074 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-08-22T18:04:57.074Z,1566497097.074 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-08-22T18:04:57.075Z,1566497097.075 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-08-22T18:04:57.075Z,1566497097.075 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-08-22T18:04:57.075Z,1566497097.075 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-08-22T18:04:57.075Z,1566497097.075 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-08-22T18:04:57.075Z,1566497097.075 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-08-22T18:04:57.093Z,1566497097.093 [CBIT](DEBUG): Deactivating GF circuits.
2019-08-22T18:04:57.093Z,1566497097.093 [CBIT](DEBUG): Deactivating emergency mode.
2019-08-22T18:04:57.129Z,1566497097.129 [CBIT](DEBUG): Backplane powered.
2019-08-22T18:04:57.133Z,1566497097.133 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-08-22T18:04:57.134Z,1566497097.134 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-08-22T18:04:57.134Z,1566497097.134 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-08-22T18:04:57.134Z,1566497097.134 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-08-22T18:04:57.135Z,1566497097.135 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-08-22T18:04:57.135Z,1566497097.135 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-08-22T18:04:57.136Z,1566497097.136 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-08-22T18:04:57.137Z,1566497097.137 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-08-22T18:04:57.143Z,1566497097.143 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-08-22T18:04:57.149Z,1566497097.149 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-08-22T18:04:57.150Z,1566497097.150 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-08-22T18:04:57.151Z,1566497097.151 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-08-22T18:04:57.151Z,1566497097.151 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-08-22T18:04:57.186Z,1566497097.186 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-08-22T18:04:57.221Z,1566497097.221 [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>


2019-08-22T18:04:57.222Z,1566497097.222 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-08-22T18:04:57.299Z,1566497097.299 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-08-22T18:04:57.300Z,1566497097.300 [Default:A.Wait](DEBUG): Construct Wait.
2019-08-22T18:04:57.318Z,1566497097.318 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-08-22T18:04:57.344Z,1566497097.344 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-08-22T18:04:57.347Z,1566497097.347 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-08-22T18:04:57.362Z,1566497097.362 [Default:E.Execute](DEBUG): Construct Execute.
2019-08-22T18:04:57.390Z,1566497097.390 [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 on</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>


2019-08-22T18:04:57.394Z,1566497097.394 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,DAT,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-08-22T18:04:57.430Z,1566497097.430 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-08-22T18:04:57.457Z,1566497097.457 [Radio_Surface](INFO): Powering up
2019-08-22T18:04:57.462Z,1566497097.462 [Depth_Keller](ERROR): Pressure reading out of range: 1895.684326 decibar
2019-08-22T18:04:57.480Z,1566497097.480 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-08-22T18:04:57.480Z,1566497097.480 [DAT](INFO): Powering up
2019-08-22T18:04:57.480Z,1566497097.480 [DAT](DEBUG): Initializing DAT.
2019-08-22T18:04:57.526Z,1566497097.526 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-08-22T18:04:57.562Z,1566497097.562 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-08-22T18:04:57.569Z,1566497097.569 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-08-22T18:04:57.570Z,1566497097.570 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-08-22T18:04:57.573Z,1566497097.573 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-08-22T18:04:57.605Z,1566497097.605 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-08-22T18:04:57.606Z,1566497097.606 [MassServo](DEBUG): Initializing EZServoServo.
2019-08-22T18:04:57.613Z,1566497097.613 [MassServo](DEBUG): Initializing MassServo.
2019-08-22T18:04:57.614Z,1566497097.614 [RudderServo](DEBUG): Initializing EZServoServo.
2019-08-22T18:04:57.625Z,1566497097.625 [RudderServo](DEBUG): Initializing RudderServo.
2019-08-22T18:04:57.626Z,1566497097.626 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-08-22T18:04:57.637Z,1566497097.637 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-08-22T18:04:58.573Z,1566497098.573 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-08-22T18:04:58.573Z,1566497098.573 [RudderServo](FAULT): Rudder failed to initialize
2019-08-22T18:04:58.573Z,1566497098.573 [RudderServo] Communications Fault, FailCount= 1
2019-08-22T18:04:58.573Z,1566497098.573 [RudderServo](ERROR): Communications Fault
2019-08-22T18:04:58.685Z,1566497098.685 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-08-22T18:04:58.886Z,1566497098.886 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-08-22T18:04:58.886Z,1566497098.886 [RudderServo](INFO): Powering down
2019-08-22T18:04:59.615Z,1566497099.615 [RudderServo](DEBUG): Initializing EZServoServo.
2019-08-22T18:04:59.734Z,1566497099.734 [RudderServo](DEBUG): Initializing RudderServo.
2019-08-22T18:04:59.738Z,1566497099.738 [CBIT](INFO): Clearing failed state for component RudderServo
2019-08-22T18:04:59.738Z,1566497099.738 [RudderServo] No Fault, FailCount= 1
2019-08-22T18:05:00.829Z,1566497100.829 [Aanderaa_O2](INFO): Powering down
2019-08-22T18:05:04.077Z,1566497104.077 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2019-08-22T18:05:12.857Z,1566497112.857 [DAT](INFO): setting local address to 3
2019-08-22T18:05:13.262Z,1566497113.262 [DAT](INFO): set local address to 3
2019-08-22T18:05:24.962Z,1566497124.962 [NAL9602](INFO): Powering up NAL9602
2019-08-22T18:05:35.870Z,1566497135.870 [NAL9602](INFO): NAL9602 initialized
2019-08-22T18:05:36.685Z,1566497136.685 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:06:00.554Z,1566497160.554 [SBIT](IMPORTANT): Beginning Startup BIT
2019-08-22T18:06:00.561Z,1566497160.561 [CBIT](IMPORTANT): Beginning ground fault scan
2019-08-22T18:06:11.281Z,1566497171.281 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.040883
CHAN A1 (24V): 0.073621
CHAN A2 (12V): 0.039955
CHAN A3 (5V): 0.005667
CHAN B0 (3.3V): 0.003183
CHAN B1 (3.15aV): 0.002458
CHAN B2 (3.15bV): 0.002641
CHAN B3 (GND): -0.001701
OPEN: 0.007680
Full Scale Calc: 4.765 mA, -1.589 mA
2019-08-22T18:06:52.560Z,1566497212.560 [NAL9602](INFO): SBD MO Status=0, MOMSN=32530, MT Status=0, MTMSN=0
2019-08-22T18:06:52.560Z,1566497212.560 [NAL9602](INFO): No messages in MT queue
2019-08-22T18:06:53.381Z,1566497213.381 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:06:54.226Z,1566497214.226 [SBIT](IMPORTANT): SBIT PASSED
2019-08-22T18:06:54.282Z,1566497214.282 [CommandLine](IMPORTANT): got command configSet list
2019-08-22T18:06:54.282Z,1566497214.282 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-08-22T18:06:54.283Z,1566497214.283 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2019-08-22T18:06:54.283Z,1566497214.283 [CommandLine](IMPORTANT): BuoyancyServo.fastPumpDepth=6 meter;

2019-08-22T18:06:54.283Z,1566497214.283 [CommandLine](IMPORTANT): CBIT.stopDepth=10 meter;

2019-08-22T18:06:54.283Z,1566497214.283 [CommandLine](IMPORTANT): CTD_Seabird.minSalinityBound=0.01 practical_salinity_unit;

2019-08-22T18:06:54.283Z,1566497214.283 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2019-08-22T18:06:54.283Z,1566497214.283 [CommandLine](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_salinity;

2019-08-22T18:06:54.284Z,1566497214.284 [CommandLine](IMPORTANT): Express linearApproximation CTD_Seabird.sea_water_electrical_conductivity 0.001000 siemens_per_meter;

2019-08-22T18:06:54.284Z,1566497214.284 [CommandLine](IMPORTANT): Express linearApproximation mass_concentration_of_oxygen_in_sea_water 750.000000 microgram_per_liter;

2019-08-22T18:06:54.284Z,1566497214.284 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=325 cubic_centimeter;

2019-08-22T18:06:54.284Z,1566497214.284 [CommandLine](IMPORTANT): VerticalControl.elevDeadband=0.1 degree;

2019-08-22T18:06:54.284Z,1566497214.284 [CommandLine](IMPORTANT): VerticalControl.kiDepthBuoy=0.3 reciprocal_second;

2019-08-22T18:06:54.284Z,1566497214.284 [CommandLine](IMPORTANT): VerticalControl.kiPitchMass=0.00075 reciprocal_second;

2019-08-22T18:06:54.284Z,1566497214.284 [CommandLine](IMPORTANT): VerticalControl.massDeadband=0.25 millimeter;

2019-08-22T18:06:54.284Z,1566497214.284 [CommandLine](IMPORTANT): VerticalControl.massDefault=11 millimeter;

2019-08-22T18:06:54.606Z,1566497214.606 [MissionManager](IMPORTANT): Started mission Startup
2019-08-22T18:06:54.607Z,1566497214.607 [Startup] Running Loop=1
2019-08-22T18:06:54.607Z,1566497214.607 [Startup](DEBUG): Aggregate::initialize Startup
2019-08-22T18:06:54.607Z,1566497214.607 [Startup:A.GoToSurface] Running Loop=1
2019-08-22T18:06:54.607Z,1566497214.607 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-22T18:06:54.608Z,1566497214.608 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-22T18:06:54.608Z,1566497214.608 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-22T18:06:54.608Z,1566497214.608 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-22T18:06:54.610Z,1566497214.610 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-22T18:06:54.610Z,1566497214.610 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-22T18:06:54.611Z,1566497214.611 [Startup:StartupSatComms] Running Loop=1
2019-08-22T18:06:54.611Z,1566497214.611 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-08-22T18:06:54.612Z,1566497214.612 [Startup:StartupSatComms:A] Running Loop=1
2019-08-22T18:06:55.017Z,1566497215.017 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-08-22T18:06:55.805Z,1566497215.805 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:06:58.633Z,1566497218.633 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:07:01.861Z,1566497221.861 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:07:04.693Z,1566497224.693 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:07:07.925Z,1566497227.925 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:07:10.749Z,1566497230.749 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:07:13.981Z,1566497233.981 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:07:16.825Z,1566497236.825 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:07:20.045Z,1566497240.045 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:07:22.869Z,1566497242.869 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:07:26.101Z,1566497246.101 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:07:26.496Z,1566497246.496 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180720.00,A,4149.69383,N,08324.71336,W,0.019,195.07,220819,,,A*70
2019-08-22T18:07:26.500Z,1566497246.500 [NAL9602](INFO): GPS fix at 20190822T180720: (41.828230, -83.411889)
2019-08-22T18:07:26.548Z,1566497246.548 [Startup:StartupSatComms:A] Stopped
2019-08-22T18:07:26.548Z,1566497246.548 [Startup:StartupSatComms:B] Running Loop=1
2019-08-22T18:07:26.956Z,1566497246.956 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-08-22T18:07:37.658Z,1566497257.658 [NAL9602](INFO): SBD MO Status=1, MOMSN=32531, MT Status=0, MTMSN=0
2019-08-22T18:07:37.717Z,1566497257.717 [NAL9602](INFO): Sent 25 bytes from file Logs/20190822T173441/Courier0037.lzma
2019-08-22T18:07:37.717Z,1566497257.717 [NAL9602](INFO): Packets left to send: 0
2019-08-22T18:07:48.589Z,1566497268.589 [NAL9602](INFO): SBD MO Status=1, MOMSN=32532, MT Status=0, MTMSN=0
2019-08-22T18:07:48.645Z,1566497268.645 [NAL9602](INFO): Sent 25 bytes from file Logs/20190822T173441/Courier0040.lzma
2019-08-22T18:07:48.645Z,1566497268.645 [NAL9602](INFO): Packets left to send: 0
2019-08-22T18:08:00.523Z,1566497280.523 [NAL9602](INFO): SBD MO Status=1, MOMSN=32533, MT Status=0, MTMSN=0
2019-08-22T18:08:00.573Z,1566497280.573 [NAL9602](INFO): Sent 213 bytes from file Logs/20190822T180446/Courier0000.lzma
2019-08-22T18:08:00.573Z,1566497280.573 [NAL9602](INFO): Packets left to send: 0
2019-08-22T18:08:22.565Z,1566497302.565 [NAL9602](INFO): SBD MO Status=2, MOMSN=32534, MT Status=2, MTMSN=0
2019-08-22T18:08:22.565Z,1566497302.565 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-22T18:08:26.630Z,1566497306.630 [Startup:StartupSatComms:B](INFO): Timed out from 2019-08-22T18:07:26.5Z
2019-08-22T18:08:26.630Z,1566497306.630 [Startup:StartupSatComms:B] Stopped
2019-08-22T18:08:26.631Z,1566497306.631 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-08-22T18:08:26.631Z,1566497306.631 [Startup:StartupSatComms] Stopped
2019-08-22T18:08:26.632Z,1566497306.632 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-08-22T18:08:26.634Z,1566497306.634 [Startup](INFO): Completed Startup
2019-08-22T18:08:26.634Z,1566497306.634 [MissionManager](INFO): Startup is completed.
2019-08-22T18:08:26.634Z,1566497306.634 [MissionManager](INFO): Uninitializing Mission Startup
2019-08-22T18:08:26.634Z,1566497306.634 [Startup] Stopped
2019-08-22T18:08:26.634Z,1566497306.634 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-08-22T18:08:26.635Z,1566497306.635 [Startup:A.GoToSurface] Stopped
2019-08-22T18:08:26.635Z,1566497306.635 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-22T18:08:27.051Z,1566497307.051 [MissionManager](IMPORTANT): Started mission Default
2019-08-22T18:08:27.051Z,1566497307.051 [Default] Running Loop=1
2019-08-22T18:08:27.052Z,1566497307.052 [Default](DEBUG): Aggregate::initialize Default
2019-08-22T18:08:27.052Z,1566497307.052 [Default:B.GoToSurface] Running Loop=1
2019-08-22T18:08:27.052Z,1566497307.052 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-22T18:08:27.052Z,1566497307.052 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-22T18:08:27.052Z,1566497307.052 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-22T18:08:27.053Z,1566497307.053 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-22T18:08:27.053Z,1566497307.053 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-22T18:08:27.054Z,1566497307.054 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-22T18:08:27.054Z,1566497307.054 [Default:A.Wait] Running Loop=1
2019-08-22T18:08:27.054Z,1566497307.054 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-08-22T18:08:37.751Z,1566497317.751 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004984
2019-08-22T18:08:40.123Z,1566497320.123 [Default:A.Wait](INFO): Done Waiting.
2019-08-22T18:08:40.123Z,1566497320.123 [Default:A.Wait] Stopped
2019-08-22T18:08:40.123Z,1566497320.123 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-08-22T18:08:40.515Z,1566497320.515 [Default:CheckIn] Running Loop=1
2019-08-22T18:08:40.515Z,1566497320.515 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-22T18:08:40.515Z,1566497320.515 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-22T18:08:40.906Z,1566497320.906 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-08-22T18:08:43.307Z,1566497323.307 [NAL9602](INFO): SBD MO Status=1, MOMSN=32534, MT Status=0, MTMSN=0
2019-08-22T18:08:43.365Z,1566497323.365 [NAL9602](INFO): Sent 133 bytes from file Logs/20190822T173441/Express0038.lzma
2019-08-22T18:08:43.365Z,1566497323.365 [NAL9602](INFO): Packets left to send: 0
2019-08-22T18:08:44.121Z,1566497324.121 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:08:44.520Z,1566497324.520 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180838.00,A,4149.69313,N,08324.71327,W,0.019,195.07,220819,,,A*7F
2019-08-22T18:08:44.522Z,1566497324.522 [NAL9602](INFO): GPS fix at 20190822T180838: (41.828219, -83.411888)
2019-08-22T18:08:44.546Z,1566497324.546 [Default:CheckIn:Read_GPS] Stopped
2019-08-22T18:08:44.546Z,1566497324.546 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-22T18:08:44.968Z,1566497324.968 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-08-22T18:08:52.128Z,1566497332.128 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190822T180446/Courier0004.lzma
2019-08-22T18:08:52.934Z,1566497332.934 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Courier0004.lzma.bak
2019-08-22T18:08:52.935Z,1566497332.935 [DataOverHttps](INFO): SBD MOMSN=11669235
2019-08-22T18:09:04.876Z,1566497344.876 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190822T173441/Express0041.lzma
2019-08-22T18:09:05.682Z,1566497345.682 [DataOverHttps](INFO): Moved sent file to Logs/20190822T173441/Express0041.lzma.bak
2019-08-22T18:09:05.683Z,1566497345.683 [DataOverHttps](INFO): SBD MOMSN=11669240
2019-08-22T18:09:16.824Z,1566497356.824 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-22T18:09:19.350Z,1566497359.350 [DataOverHttps](INFO): Sending 1092 bytes from file Logs/20190822T180446/Express0001.lzma
2019-08-22T18:09:20.154Z,1566497360.154 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Express0001.lzma.bak
2019-08-22T18:09:20.154Z,1566497360.154 [DataOverHttps](INFO): SBD MOMSN=11669242
2019-08-22T18:09:32.128Z,1566497372.128 [DataOverHttps](INFO): Sending 94 bytes from file Logs/20190822T180446/Express0005.lzma
2019-08-22T18:09:32.934Z,1566497372.934 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Express0005.lzma.bak
2019-08-22T18:09:32.935Z,1566497372.935 [DataOverHttps](INFO): SBD MOMSN=11669270
2019-08-22T18:09:34.651Z,1566497374.651 [Default:CheckIn:Read_Iridium] Stopped
2019-08-22T18:09:34.651Z,1566497374.651 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-22T18:09:34.651Z,1566497374.651 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-22T18:12:36.063Z,1566497556.063 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2019-08-22T18:12:36.064Z,1566497556.064 [BPC1](ERROR): Battery stick #39 (s/n: 00F0) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2019-08-22T18:12:36.065Z,1566497556.065 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5.
2019-08-22T18:12:36.068Z,1566497556.068 [BPC1](INFO): Received data from all battery sticks.
2019-08-22T18:14:35.222Z,1566497675.222 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-22T18:14:35.223Z,1566497675.223 [Default:CheckIn:C.Wait] Stopped
2019-08-22T18:14:35.223Z,1566497675.223 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-22T18:14:35.223Z,1566497675.223 [Default:CheckIn:D] Running Loop=1
2019-08-22T18:14:35.648Z,1566497675.648 [Default:CheckIn:D] Stopped
2019-08-22T18:14:35.648Z,1566497675.648 [Default:CheckIn:E] Running Loop=1
2019-08-22T18:14:36.038Z,1566497676.038 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.143267 min 
2019-08-22T18:14:36.038Z,1566497676.038 [Default:CheckIn:E] Stopped
2019-08-22T18:14:36.038Z,1566497676.038 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-22T18:14:36.038Z,1566497676.038 [Default:CheckIn] Stopped
2019-08-22T18:14:36.039Z,1566497676.039 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-22T18:14:36.039Z,1566497676.039 [Default:CheckIn](INFO): Running loop #2
2019-08-22T18:14:36.039Z,1566497676.039 [Default:CheckIn] Running Loop=2
2019-08-22T18:14:36.039Z,1566497676.039 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-22T18:14:36.039Z,1566497676.039 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-22T18:14:37.637Z,1566497677.637 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:14:38.026Z,1566497678.026 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181431.00,A,4149.69264,N,08324.71312,W,0.019,195.07,220819,,,A*7C
2019-08-22T18:14:38.028Z,1566497678.028 [NAL9602](INFO): GPS fix at 20190822T181431: (41.828211, -83.411885)
2019-08-22T18:14:38.051Z,1566497678.051 [Default:CheckIn:Read_GPS] Stopped
2019-08-22T18:14:38.051Z,1566497678.051 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-22T18:14:43.785Z,1566497683.785 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20190822T180446/Courier0007.lzma
2019-08-22T18:14:44.590Z,1566497684.590 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Courier0007.lzma.bak
2019-08-22T18:14:44.591Z,1566497684.591 [DataOverHttps](INFO): SBD MOMSN=11669303
2019-08-22T18:14:49.008Z,1566497689.008 [NAL9602](INFO): SBD MO Status=0, MOMSN=32535, MT Status=0, MTMSN=0
2019-08-22T18:14:49.008Z,1566497689.008 [NAL9602](INFO): No messages in MT queue
2019-08-22T18:14:58.108Z,1566497698.108 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20190822T180446/Express0008.lzma
2019-08-22T18:14:58.914Z,1566497698.914 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Express0008.lzma.bak
2019-08-22T18:14:58.915Z,1566497698.915 [DataOverHttps](INFO): SBD MOMSN=11669306
2019-08-22T18:15:00.347Z,1566497700.347 [Default:CheckIn:Read_Iridium] Stopped
2019-08-22T18:15:00.347Z,1566497700.347 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-22T18:15:00.347Z,1566497700.347 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-22T18:15:19.694Z,1566497719.694 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-22T18:20:00.915Z,1566498000.915 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-22T18:20:00.915Z,1566498000.915 [Default:CheckIn:C.Wait] Stopped
2019-08-22T18:20:00.915Z,1566498000.915 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-22T18:20:00.915Z,1566498000.915 [Default:CheckIn:D] Running Loop=1
2019-08-22T18:20:01.313Z,1566498001.313 [Default:CheckIn:D] Stopped
2019-08-22T18:20:01.314Z,1566498001.314 [Default:CheckIn:E] Running Loop=1
2019-08-22T18:20:01.725Z,1566498001.725 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.571032 min 
2019-08-22T18:20:01.725Z,1566498001.725 [Default:CheckIn:E] Stopped
2019-08-22T18:20:01.726Z,1566498001.726 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-22T18:20:01.726Z,1566498001.726 [Default:CheckIn] Stopped
2019-08-22T18:20:01.726Z,1566498001.726 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-22T18:20:01.726Z,1566498001.726 [Default:CheckIn](INFO): Running loop #3
2019-08-22T18:20:01.726Z,1566498001.726 [Default:CheckIn] Running Loop=3
2019-08-22T18:20:01.726Z,1566498001.726 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-22T18:20:01.726Z,1566498001.726 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-22T18:20:03.317Z,1566498003.317 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:20:03.708Z,1566498003.708 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181956.00,A,4149.69604,N,08324.71423,W,0.019,295.31,220819,,,A*71
2019-08-22T18:20:03.711Z,1566498003.711 [NAL9602](INFO): GPS fix at 20190822T181956: (41.828267, -83.411904)
2019-08-22T18:20:03.733Z,1566498003.733 [Default:CheckIn:Read_GPS] Stopped
2019-08-22T18:20:03.733Z,1566498003.733 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-22T18:20:09.596Z,1566498009.596 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190822T180446/Courier0010.lzma
2019-08-22T18:20:10.402Z,1566498010.402 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Courier0010.lzma.bak
2019-08-22T18:20:10.402Z,1566498010.402 [DataOverHttps](INFO): SBD MOMSN=11669335
2019-08-22T18:20:24.244Z,1566498024.244 [DataOverHttps](INFO): Sending 118 bytes from file Logs/20190822T180446/Express0011.lzma
2019-08-22T18:20:25.050Z,1566498025.050 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Express0011.lzma.bak
2019-08-22T18:20:25.051Z,1566498025.051 [DataOverHttps](INFO): SBD MOMSN=11669338
2019-08-22T18:20:26.767Z,1566498026.767 [Default:CheckIn:Read_Iridium] Stopped
2019-08-22T18:20:26.767Z,1566498026.767 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-22T18:20:26.767Z,1566498026.767 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-22T18:20:32.413Z,1566498032.413 [NAL9602](INFO): SBD MO Status=0, MOMSN=32536, MT Status=0, MTMSN=0
2019-08-22T18:20:32.413Z,1566498032.413 [NAL9602](INFO): No messages in MT queue
2019-08-22T18:21:03.103Z,1566498063.103 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-22T18:25:27.348Z,1566498327.348 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-22T18:25:27.348Z,1566498327.348 [Default:CheckIn:C.Wait] Stopped
2019-08-22T18:25:27.348Z,1566498327.348 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-22T18:25:27.348Z,1566498327.348 [Default:CheckIn:D] Running Loop=1
2019-08-22T18:25:27.760Z,1566498327.760 [Default:CheckIn:D] Stopped
2019-08-22T18:25:27.760Z,1566498327.760 [Default:CheckIn:E] Running Loop=1
2019-08-22T18:25:28.164Z,1566498328.164 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.011801 min 
2019-08-22T18:25:28.164Z,1566498328.164 [Default:CheckIn:E] Stopped
2019-08-22T18:25:28.164Z,1566498328.164 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-22T18:25:28.164Z,1566498328.164 [Default:CheckIn] Stopped
2019-08-22T18:25:28.164Z,1566498328.164 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-22T18:25:28.164Z,1566498328.164 [Default:CheckIn](INFO): Running loop #4
2019-08-22T18:25:28.164Z,1566498328.164 [Default:CheckIn] Running Loop=4
2019-08-22T18:25:28.165Z,1566498328.165 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-22T18:25:28.165Z,1566498328.165 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-22T18:25:29.773Z,1566498329.773 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:25:30.158Z,1566498330.158 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182522.00,A,4149.69432,N,08324.71336,W,0.039,295.31,220819,,,D*7E
2019-08-22T18:25:30.160Z,1566498330.160 [NAL9602](INFO): GPS fix at 20190822T182522: (41.828239, -83.411889)
2019-08-22T18:25:30.202Z,1566498330.202 [Default:CheckIn:Read_GPS] Stopped
2019-08-22T18:25:30.202Z,1566498330.202 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-22T18:25:36.008Z,1566498336.008 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190822T180446/Courier0013.lzma
2019-08-22T18:25:36.814Z,1566498336.814 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Courier0013.lzma.bak
2019-08-22T18:25:36.815Z,1566498336.815 [DataOverHttps](INFO): SBD MOMSN=11669381
2019-08-22T18:25:43.498Z,1566498343.498 [NAL9602](INFO): SBD MO Status=0, MOMSN=32537, MT Status=0, MTMSN=0
2019-08-22T18:25:43.498Z,1566498343.498 [NAL9602](INFO): No messages in MT queue
2019-08-22T18:25:48.592Z,1566498348.592 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20190822T180446/Express0014.lzma
2019-08-22T18:25:49.398Z,1566498349.398 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Express0014.lzma.bak
2019-08-22T18:25:49.398Z,1566498349.398 [DataOverHttps](INFO): SBD MOMSN=11669384
2019-08-22T18:25:50.796Z,1566498350.796 [Default:CheckIn:Read_Iridium] Stopped
2019-08-22T18:25:50.796Z,1566498350.796 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-22T18:25:50.796Z,1566498350.796 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-22T18:26:14.274Z,1566498374.274 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-22T18:30:51.408Z,1566498651.408 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-22T18:30:51.408Z,1566498651.408 [Default:CheckIn:C.Wait] Stopped
2019-08-22T18:30:51.408Z,1566498651.408 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-22T18:30:51.408Z,1566498651.408 [Default:CheckIn:D] Running Loop=1
2019-08-22T18:30:51.811Z,1566498651.811 [Default:CheckIn:D] Stopped
2019-08-22T18:30:51.811Z,1566498651.811 [Default:CheckIn:E] Running Loop=1
2019-08-22T18:30:52.210Z,1566498652.210 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.412657 min 
2019-08-22T18:30:52.210Z,1566498652.210 [Default:CheckIn:E] Stopped
2019-08-22T18:30:52.210Z,1566498652.210 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-22T18:30:52.210Z,1566498652.210 [Default:CheckIn] Stopped
2019-08-22T18:30:52.210Z,1566498652.210 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-22T18:30:52.211Z,1566498652.211 [Default:CheckIn](INFO): Running loop #5
2019-08-22T18:30:52.211Z,1566498652.211 [Default:CheckIn] Running Loop=5
2019-08-22T18:30:52.211Z,1566498652.211 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-22T18:30:52.211Z,1566498652.211 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-22T18:30:53.817Z,1566498653.817 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:30:54.210Z,1566498654.210 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183045.00,A,4149.69549,N,08324.71500,W,0.039,295.31,220819,,,A*70
2019-08-22T18:30:54.212Z,1566498654.212 [NAL9602](INFO): GPS fix at 20190822T183045: (41.828258, -83.411917)
2019-08-22T18:30:54.261Z,1566498654.261 [Default:CheckIn:Read_GPS] Stopped
2019-08-22T18:30:54.261Z,1566498654.261 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-22T18:31:00.088Z,1566498660.088 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190822T180446/Courier0016.lzma
2019-08-22T18:31:00.894Z,1566498660.894 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Courier0016.lzma.bak
2019-08-22T18:31:00.895Z,1566498660.895 [DataOverHttps](INFO): SBD MOMSN=11669454
2019-08-22T18:31:09.972Z,1566498669.972 [NAL9602](INFO): SBD MO Status=0, MOMSN=32538, MT Status=0, MTMSN=0
2019-08-22T18:31:09.972Z,1566498669.972 [NAL9602](INFO): No messages in MT queue
2019-08-22T18:31:13.808Z,1566498673.808 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20190822T180446/Express0017.lzma
2019-08-22T18:31:14.614Z,1566498674.614 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Express0017.lzma.bak
2019-08-22T18:31:14.615Z,1566498674.615 [DataOverHttps](INFO): SBD MOMSN=11669458
2019-08-22T18:31:16.086Z,1566498676.086 [Default:CheckIn:Read_Iridium] Stopped
2019-08-22T18:31:16.086Z,1566498676.086 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-22T18:31:16.086Z,1566498676.086 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-22T18:31:40.664Z,1566498700.664 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-22T18:36:16.631Z,1566498976.631 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-22T18:36:16.631Z,1566498976.631 [Default:CheckIn:C.Wait] Stopped
2019-08-22T18:36:16.631Z,1566498976.631 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-22T18:36:16.631Z,1566498976.631 [Default:CheckIn:D] Running Loop=1
2019-08-22T18:36:17.030Z,1566498977.030 [Default:CheckIn:D] Stopped
2019-08-22T18:36:17.030Z,1566498977.030 [Default:CheckIn:E] Running Loop=1
2019-08-22T18:36:17.440Z,1566498977.440 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.832969 min 
2019-08-22T18:36:17.440Z,1566498977.440 [Default:CheckIn:E] Stopped
2019-08-22T18:36:17.440Z,1566498977.440 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-22T18:36:17.440Z,1566498977.440 [Default:CheckIn] Stopped
2019-08-22T18:36:17.440Z,1566498977.440 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-22T18:36:17.440Z,1566498977.440 [Default:CheckIn](INFO): Running loop #6
2019-08-22T18:36:17.441Z,1566498977.441 [Default:CheckIn] Running Loop=6
2019-08-22T18:36:17.441Z,1566498977.441 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-22T18:36:17.441Z,1566498977.441 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-22T18:36:19.045Z,1566498979.045 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:36:19.439Z,1566498979.439 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183610.00,A,4149.63516,N,08324.16689,W,7.095,96.91,220819,,,D*4A
2019-08-22T18:36:19.442Z,1566498979.442 [NAL9602](INFO): GPS fix at 20190822T183610: (41.827253, -83.402782)
2019-08-22T18:36:19.464Z,1566498979.464 [Default:CheckIn:Read_GPS] Stopped
2019-08-22T18:36:19.464Z,1566498979.464 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-22T18:36:25.256Z,1566498985.256 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190822T180446/Courier0019.lzma
2019-08-22T18:36:26.062Z,1566498986.062 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Courier0019.lzma.bak
2019-08-22T18:36:26.063Z,1566498986.063 [DataOverHttps](INFO): SBD MOMSN=11669486
2019-08-22T18:36:33.585Z,1566498993.585 [NAL9602](INFO): SBD MO Status=0, MOMSN=32539, MT Status=0, MTMSN=0
2019-08-22T18:36:33.586Z,1566498993.586 [NAL9602](INFO): No messages in MT queue
2019-08-22T18:36:40.548Z,1566499000.548 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20190822T180446/Express0020.lzma
2019-08-22T18:36:41.354Z,1566499001.354 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Express0020.lzma.bak
2019-08-22T18:36:41.354Z,1566499001.354 [DataOverHttps](INFO): SBD MOMSN=11669489
2019-08-22T18:36:42.904Z,1566499002.904 [Default:CheckIn:Read_Iridium] Stopped
2019-08-22T18:36:42.904Z,1566499002.904 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-22T18:36:42.904Z,1566499002.904 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-22T18:37:04.288Z,1566499024.288 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-22T18:41:43.479Z,1566499303.479 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-22T18:41:43.480Z,1566499303.480 [Default:CheckIn:C.Wait] Stopped
2019-08-22T18:41:43.480Z,1566499303.480 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-22T18:41:43.480Z,1566499303.480 [Default:CheckIn:D] Running Loop=1
2019-08-22T18:41:43.883Z,1566499303.883 [Default:CheckIn:D] Stopped
2019-08-22T18:41:43.883Z,1566499303.883 [Default:CheckIn:E] Running Loop=1
2019-08-22T18:41:44.279Z,1566499304.279 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.280524 min 
2019-08-22T18:41:44.279Z,1566499304.279 [Default:CheckIn:E] Stopped
2019-08-22T18:41:44.279Z,1566499304.279 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-22T18:41:44.279Z,1566499304.279 [Default:CheckIn] Stopped
2019-08-22T18:41:44.279Z,1566499304.279 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-22T18:41:44.280Z,1566499304.280 [Default:CheckIn](INFO): Running loop #7
2019-08-22T18:41:44.280Z,1566499304.280 [Default:CheckIn] Running Loop=7
2019-08-22T18:41:44.280Z,1566499304.280 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-22T18:41:44.280Z,1566499304.280 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-22T18:41:45.889Z,1566499305.889 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:41:46.285Z,1566499306.285 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184137.00,A,4149.49479,N,08322.81976,W,15.590,90.65,220819,,,A*73
2019-08-22T18:41:46.287Z,1566499306.287 [NAL9602](INFO): GPS fix at 20190822T184137: (41.824913, -83.380329)
2019-08-22T18:41:46.327Z,1566499306.327 [Default:CheckIn:Read_GPS] Stopped
2019-08-22T18:41:46.327Z,1566499306.327 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-22T18:41:52.092Z,1566499312.092 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190822T180446/Courier0022.lzma
2019-08-22T18:41:52.898Z,1566499312.898 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Courier0022.lzma.bak
2019-08-22T18:41:52.899Z,1566499312.899 [DataOverHttps](INFO): SBD MOMSN=11669514
2019-08-22T18:42:01.637Z,1566499321.637 [NAL9602](INFO): SBD MO Status=0, MOMSN=32540, MT Status=0, MTMSN=0
2019-08-22T18:42:01.637Z,1566499321.637 [NAL9602](INFO): No messages in MT queue
2019-08-22T18:42:04.692Z,1566499324.692 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20190822T180446/Express0023.lzma
2019-08-22T18:42:05.498Z,1566499325.498 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Express0023.lzma.bak
2019-08-22T18:42:05.499Z,1566499325.499 [DataOverHttps](INFO): SBD MOMSN=11669517
2019-08-22T18:42:06.944Z,1566499326.944 [Default:CheckIn:Read_Iridium] Stopped
2019-08-22T18:42:06.944Z,1566499326.944 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-22T18:42:06.944Z,1566499326.944 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-22T18:42:32.338Z,1566499352.338 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-22T18:47:07.485Z,1566499627.485 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-22T18:47:07.485Z,1566499627.485 [Default:CheckIn:C.Wait] Stopped
2019-08-22T18:47:07.485Z,1566499627.485 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-22T18:47:07.485Z,1566499627.485 [Default:CheckIn:D] Running Loop=1
2019-08-22T18:47:07.886Z,1566499627.886 [Default:CheckIn:D] Stopped
2019-08-22T18:47:07.886Z,1566499627.886 [Default:CheckIn:E] Running Loop=1
2019-08-22T18:47:08.304Z,1566499628.304 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.680583 min 
2019-08-22T18:47:08.304Z,1566499628.304 [Default:CheckIn:E] Stopped
2019-08-22T18:47:08.305Z,1566499628.305 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-22T18:47:08.305Z,1566499628.305 [Default:CheckIn] Stopped
2019-08-22T18:47:08.305Z,1566499628.305 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-22T18:47:08.305Z,1566499628.305 [Default:CheckIn](INFO): Running loop #8
2019-08-22T18:47:08.305Z,1566499628.305 [Default:CheckIn] Running Loop=8
2019-08-22T18:47:08.305Z,1566499628.305 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-22T18:47:08.306Z,1566499628.306 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-22T18:47:09.905Z,1566499629.905 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:47:10.299Z,1566499630.299 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184700.00,A,4149.30979,N,08320.96166,W,15.842,96.77,220819,,,A*78
2019-08-22T18:47:10.302Z,1566499630.302 [NAL9602](INFO): GPS fix at 20190822T184700: (41.821830, -83.349361)
2019-08-22T18:47:10.344Z,1566499630.344 [Default:CheckIn:Read_GPS] Stopped
2019-08-22T18:47:10.344Z,1566499630.344 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-22T18:47:17.308Z,1566499637.308 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190822T180446/Courier0025.lzma
2019-08-22T18:47:18.114Z,1566499638.114 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Courier0025.lzma.bak
2019-08-22T18:47:18.115Z,1566499638.115 [DataOverHttps](INFO): SBD MOMSN=11669567
2019-08-22T18:47:31.540Z,1566499651.540 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20190822T180446/Express0026.lzma
2019-08-22T18:47:32.346Z,1566499652.346 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Express0026.lzma.bak
2019-08-22T18:47:32.347Z,1566499652.347 [DataOverHttps](INFO): SBD MOMSN=11669571
2019-08-22T18:47:33.764Z,1566499653.764 [Default:CheckIn:Read_Iridium] Stopped
2019-08-22T18:47:33.764Z,1566499653.764 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-22T18:47:33.764Z,1566499653.764 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-22T18:47:39.387Z,1566499659.387 [NAL9602](INFO): SBD MO Status=2, MOMSN=32541, MT Status=2, MTMSN=0
2019-08-22T18:47:39.387Z,1566499659.387 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-22T18:47:57.157Z,1566499677.157 [NAL9602](INFO): SBD MO Status=2, MOMSN=32541, MT Status=2, MTMSN=0
2019-08-22T18:47:57.157Z,1566499677.157 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-22T18:48:28.270Z,1566499708.270 [NAL9602](INFO): SBD MO Status=2, MOMSN=32541, MT Status=2, MTMSN=0
2019-08-22T18:48:28.270Z,1566499708.270 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-22T18:48:53.315Z,1566499733.315 [NAL9602](INFO): SBD MO Status=0, MOMSN=32541, MT Status=0, MTMSN=0
2019-08-22T18:48:53.315Z,1566499733.315 [NAL9602](INFO): No messages in MT queue
2019-08-22T18:49:24.016Z,1566499764.016 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-22T18:52:34.342Z,1566499954.342 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-22T18:52:34.342Z,1566499954.342 [Default:CheckIn:C.Wait] Stopped
2019-08-22T18:52:34.342Z,1566499954.342 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-22T18:52:34.342Z,1566499954.342 [Default:CheckIn:D] Running Loop=1
2019-08-22T18:52:34.755Z,1566499954.755 [Default:CheckIn:D] Stopped
2019-08-22T18:52:34.755Z,1566499954.755 [Default:CheckIn:E] Running Loop=1
2019-08-22T18:52:35.160Z,1566499955.160 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.128398 min 
2019-08-22T18:52:35.160Z,1566499955.160 [Default:CheckIn:E] Stopped
2019-08-22T18:52:35.160Z,1566499955.160 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-22T18:52:35.160Z,1566499955.160 [Default:CheckIn] Stopped
2019-08-22T18:52:35.160Z,1566499955.160 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-22T18:52:35.160Z,1566499955.160 [Default:CheckIn](INFO): Running loop #9
2019-08-22T18:52:35.161Z,1566499955.161 [Default:CheckIn] Running Loop=9
2019-08-22T18:52:35.161Z,1566499955.161 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-22T18:52:35.161Z,1566499955.161 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-22T18:52:36.757Z,1566499956.757 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:52:37.152Z,1566499957.152 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185226.00,A,4149.12744,N,08319.13545,W,15.454,109.49,220819,,,A*4B
2019-08-22T18:52:37.154Z,1566499957.154 [NAL9602](INFO): GPS fix at 20190822T185226: (41.818791, -83.318924)
2019-08-22T18:52:37.188Z,1566499957.188 [Default:CheckIn:Read_GPS] Stopped
2019-08-22T18:52:37.188Z,1566499957.188 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-22T18:52:43.828Z,1566499963.828 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190822T180446/Courier0028.lzma
2019-08-22T18:52:44.634Z,1566499964.634 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Courier0028.lzma.bak
2019-08-22T18:52:44.634Z,1566499964.634 [DataOverHttps](INFO): SBD MOMSN=11669609
2019-08-22T18:52:50.491Z,1566499970.491 [NAL9602](INFO): SBD MO Status=0, MOMSN=32542, MT Status=0, MTMSN=0
2019-08-22T18:52:50.491Z,1566499970.491 [NAL9602](INFO): No messages in MT queue
2019-08-22T18:52:56.684Z,1566499976.684 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20190822T180446/Express0029.lzma
2019-08-22T18:52:57.486Z,1566499977.486 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Express0029.lzma.bak
2019-08-22T18:52:57.487Z,1566499977.487 [DataOverHttps](INFO): SBD MOMSN=11669612
2019-08-22T18:52:59.011Z,1566499979.011 [Default:CheckIn:Read_Iridium] Stopped
2019-08-22T18:52:59.011Z,1566499979.011 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-22T18:52:59.011Z,1566499979.011 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-22T18:53:21.181Z,1566500001.181 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-22T18:57:59.601Z,1566500279.601 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-22T18:57:59.601Z,1566500279.601 [Default:CheckIn:C.Wait] Stopped
2019-08-22T18:57:59.601Z,1566500279.601 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-22T18:57:59.602Z,1566500279.602 [Default:CheckIn:D] Running Loop=1
2019-08-22T18:57:59.985Z,1566500279.985 [Default:CheckIn:D] Stopped
2019-08-22T18:57:59.985Z,1566500279.985 [Default:CheckIn:E] Running Loop=1
2019-08-22T18:58:00.396Z,1566500280.396 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.548893 min 
2019-08-22T18:58:00.396Z,1566500280.396 [Default:CheckIn:E] Stopped
2019-08-22T18:58:00.396Z,1566500280.396 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-22T18:58:00.396Z,1566500280.396 [Default:CheckIn] Stopped
2019-08-22T18:58:00.396Z,1566500280.396 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-22T18:58:00.396Z,1566500280.396 [Default:CheckIn](INFO): Running loop #10
2019-08-22T18:58:00.397Z,1566500280.397 [Default:CheckIn] Running Loop=10
2019-08-22T18:58:00.397Z,1566500280.397 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-22T18:58:00.397Z,1566500280.397 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-22T18:58:02.005Z,1566500282.005 [NAL9602](DEBUG): Fix Requested
2019-08-22T18:58:02.395Z,1566500282.395 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185751.00,A,4148.84732,N,08317.34807,W,15.317,98.04,220819,,,A*71
2019-08-22T18:58:02.409Z,1566500282.409 [NAL9602](INFO): GPS fix at 20190822T185751: (41.814122, -83.289135)
2019-08-22T18:58:02.432Z,1566500282.432 [Default:CheckIn:Read_GPS] Stopped
2019-08-22T18:58:02.432Z,1566500282.432 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-22T18:58:08.268Z,1566500288.268 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190822T180446/Courier0031.lzma
2019-08-22T18:58:09.074Z,1566500289.074 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Courier0031.lzma.bak
2019-08-22T18:58:09.075Z,1566500289.075 [DataOverHttps](INFO): SBD MOMSN=11669688
2019-08-22T18:58:20.804Z,1566500300.804 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20190822T180446/Express0032.lzma
2019-08-22T18:58:21.610Z,1566500301.610 [DataOverHttps](INFO): Moved sent file to Logs/20190822T180446/Express0032.lzma.bak
2019-08-22T18:58:21.611Z,1566500301.611 [DataOverHttps](INFO): SBD MOMSN=11669691
2019-08-22T18:58:23.058Z,1566500303.058 [Default:CheckIn:Read_Iridium] Stopped
2019-08-22T18:58:23.058Z,1566500303.058 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-22T18:58:23.058Z,1566500303.058 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-22T18:58:28.651Z,1566500308.651 [NAL9602](INFO): SBD MO Status=0, MOMSN=32543, MT Status=0, MTMSN=0
2019-08-22T18:58:28.652Z,1566500308.652 [NAL9602](INFO): No messages in MT queue
2019-08-22T18:58:59.353Z,1566500339.353 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-22T19:00:29.929Z,1566500429.929 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:01:00.633Z,1566500460.633 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:01:31.337Z,1566500491.337 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:02:02.041Z,1566500522.041 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:02:32.745Z,1566500552.745 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:02:35.573Z,1566500555.573 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.183731
2019-08-22T19:03:23.619Z,1566500603.619 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-22T19:03:23.619Z,1566500603.619 [Default:CheckIn:C.Wait] Stopped
2019-08-22T19:03:23.619Z,1566500603.619 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-22T19:03:23.620Z,1566500603.620 [Default:CheckIn:D] Running Loop=1
2019-08-22T19:03:24.026Z,1566500604.026 [Default:CheckIn:D] Stopped
2019-08-22T19:03:24.026Z,1566500604.026 [Default:CheckIn:E] Running Loop=1
2019-08-22T19:03:24.414Z,1566500604.414 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.949569 min 
2019-08-22T19:03:24.414Z,1566500604.414 [Default:CheckIn:E] Stopped
2019-08-22T19:03:24.414Z,1566500604.414 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-22T19:03:24.414Z,1566500604.414 [Default:CheckIn] Stopped
2019-08-22T19:03:24.415Z,1566500604.415 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-22T19:03:24.415Z,1566500604.415 [Default:CheckIn](INFO): Running loop #11
2019-08-22T19:03:24.415Z,1566500604.415 [Default:CheckIn] Running Loop=11
2019-08-22T19:03:24.415Z,1566500604.415 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-22T19:03:24.415Z,1566500604.415 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-22T19:03:26.033Z,1566500606.033 [NAL9602](DEBUG): Fix Requested
2019-08-22T19:03:26.422Z,1566500606.422 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190315.00,A,4148.61243,N,08315.53340,W,15.201,93.80,220819,,,D*76
2019-08-22T19:03:26.425Z,1566500606.425 [NAL9602](INFO): GPS fix at 20190822T190315: (41.810207, -83.258890)
2019-08-22T19:03:26.447Z,1566500606.447 [Default:CheckIn:Read_GPS] Stopped
2019-08-22T19:03:26.447Z,1566500606.447 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-22T19:03:33.749Z,1566500613.749 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:03:48.888Z,1566500628.888 [NAL9602](INFO): SBD MO Status=1, MOMSN=32544, MT Status=0, MTMSN=0
2019-08-22T19:03:48.937Z,1566500628.937 [NAL9602](INFO): Sent 63 bytes from file Logs/20190822T180446/Courier0034.lzma
2019-08-22T19:03:48.937Z,1566500628.937 [NAL9602](INFO): Packets left to send: 0
2019-08-22T19:03:57.941Z,1566500637.941 [NAL9602](INFO): SBD MO Status=1, MOMSN=32545, MT Status=0, MTMSN=0
2019-08-22T19:03:57.997Z,1566500637.997 [NAL9602](INFO): Sent 136 bytes from file Logs/20190822T180446/Express0035.lzma
2019-08-22T19:03:57.997Z,1566500637.997 [NAL9602](INFO): Packets left to send: 0
2019-08-22T19:04:04.473Z,1566500644.473 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:04:05.683Z,1566500645.683 [NAL9602](INFO): SBD MO Status=0, MOMSN=32546, MT Status=0, MTMSN=0
2019-08-22T19:04:05.787Z,1566500645.787 [Default:CheckIn:Read_Iridium] Stopped
2019-08-22T19:04:05.788Z,1566500645.788 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-22T19:04:05.788Z,1566500645.788 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-22T19:04:35.178Z,1566500675.178 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:04:36.382Z,1566500676.382 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-22T19:05:05.883Z,1566500705.883 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:05:36.585Z,1566500736.585 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:06:07.290Z,1566500767.290 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:06:37.994Z,1566500797.994 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:07:08.698Z,1566500828.698 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:07:39.402Z,1566500859.402 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:08:10.107Z,1566500890.107 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:08:40.809Z,1566500920.809 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:09:06.274Z,1566500946.274 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-22T19:09:06.275Z,1566500946.275 [Default:CheckIn:C.Wait] Stopped
2019-08-22T19:09:06.275Z,1566500946.275 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-22T19:09:06.275Z,1566500946.275 [Default:CheckIn:D] Running Loop=1
2019-08-22T19:09:06.685Z,1566500946.685 [Default:CheckIn:D] Stopped
2019-08-22T19:09:06.685Z,1566500946.685 [Default:CheckIn:E] Running Loop=1
2019-08-22T19:09:07.091Z,1566500947.091 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.660563 min 
2019-08-22T19:09:07.092Z,1566500947.092 [Default:CheckIn:E] Stopped
2019-08-22T19:09:07.092Z,1566500947.092 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-22T19:09:07.092Z,1566500947.092 [Default:CheckIn] Stopped
2019-08-22T19:09:07.092Z,1566500947.092 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-22T19:09:07.092Z,1566500947.092 [Default:CheckIn](INFO): Running loop #12
2019-08-22T19:09:07.092Z,1566500947.092 [Default:CheckIn] Running Loop=12
2019-08-22T19:09:07.092Z,1566500947.092 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-22T19:09:07.092Z,1566500947.092 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-22T19:09:08.689Z,1566500948.689 [NAL9602](DEBUG): Fix Requested
2019-08-22T19:09:09.082Z,1566500949.082 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190857.00,A,4148.34595,N,08313.61771,W,15.240,100.48,220819,,,A*49
2019-08-22T19:09:09.084Z,1566500949.084 [NAL9602](INFO): GPS fix at 20190822T190857: (41.805766, -83.226962)
2019-08-22T19:09:09.107Z,1566500949.107 [Default:CheckIn:Read_GPS] Stopped
2019-08-22T19:09:09.107Z,1566500949.107 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-22T19:09:11.514Z,1566500951.514 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:09:22.661Z,1566500962.661 [NAL9602](INFO): SBD MO Status=1, MOMSN=32547, MT Status=0, MTMSN=0
2019-08-22T19:09:22.717Z,1566500962.717 [NAL9602](INFO): Sent 64 bytes from file Logs/20190822T180446/Courier0037.lzma
2019-08-22T19:09:22.717Z,1566500962.717 [NAL9602](INFO): Packets left to send: 0
2019-08-22T19:09:36.597Z,1566500976.597 [NAL9602](INFO): SBD MO Status=1, MOMSN=32548, MT Status=0, MTMSN=0
2019-08-22T19:09:36.653Z,1566500976.653 [NAL9602](INFO): Sent 134 bytes from file Logs/20190822T180446/Express0038.lzma
2019-08-22T19:09:36.653Z,1566500976.653 [NAL9602](INFO): Packets left to send: 0
2019-08-22T19:09:42.217Z,1566500982.217 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:10:12.921Z,1566501012.921 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:10:24.330Z,1566501024.330 [NAL9602](INFO): SBD MO Status=2, MOMSN=32549, MT Status=2, MTMSN=0
2019-08-22T19:10:24.330Z,1566501024.330 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-22T19:10:35.785Z,1566501035.785 [NAL9602](INFO): SBD MO Status=0, MOMSN=32549, MT Status=0, MTMSN=0
2019-08-22T19:10:35.891Z,1566501035.891 [Default:CheckIn:Read_Iridium] Stopped
2019-08-22T19:10:35.891Z,1566501035.891 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-22T19:10:35.891Z,1566501035.891 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-22T19:10:43.625Z,1566501043.625 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:11:06.480Z,1566501066.480 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-22T19:11:14.333Z,1566501074.333 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:11:45.037Z,1566501105.037 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:12:15.741Z,1566501135.741 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:12:46.445Z,1566501166.445 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:13:17.149Z,1566501197.149 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:13:47.853Z,1566501227.853 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:14:18.557Z,1566501258.557 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:14:49.261Z,1566501289.261 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:15:19.965Z,1566501319.965 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:15:36.400Z,1566501336.400 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-22T19:15:36.400Z,1566501336.400 [Default:CheckIn:C.Wait] Stopped
2019-08-22T19:15:36.400Z,1566501336.400 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-22T19:15:36.400Z,1566501336.400 [Default:CheckIn:D] Running Loop=1
2019-08-22T19:15:36.790Z,1566501336.790 [Default:CheckIn:D] Stopped
2019-08-22T19:15:36.790Z,1566501336.790 [Default:CheckIn:E] Running Loop=1
2019-08-22T19:15:37.200Z,1566501337.200 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.162305 min 
2019-08-22T19:15:37.200Z,1566501337.200 [Default:CheckIn:E] Stopped
2019-08-22T19:15:37.200Z,1566501337.200 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-22T19:15:37.200Z,1566501337.200 [Default:CheckIn] Stopped
2019-08-22T19:15:37.200Z,1566501337.200 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-22T19:15:37.201Z,1566501337.201 [Default:CheckIn](INFO): Running loop #13
2019-08-22T19:15:37.201Z,1566501337.201 [Default:CheckIn] Running Loop=13
2019-08-22T19:15:37.201Z,1566501337.201 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-22T19:15:37.201Z,1566501337.201 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-22T19:15:38.805Z,1566501338.805 [NAL9602](DEBUG): Fix Requested
2019-08-22T19:15:39.205Z,1566501339.205 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191526.00,A,4148.07463,N,08311.51163,W,3.460,161.87,220819,,,D*7D
2019-08-22T19:15:39.207Z,1566501339.207 [NAL9602](INFO): GPS fix at 20190822T191526: (41.801244, -83.191861)
2019-08-22T19:15:39.230Z,1566501339.230 [Default:CheckIn:Read_GPS] Stopped
2019-08-22T19:15:39.230Z,1566501339.230 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-22T19:15:50.669Z,1566501350.669 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:16:03.277Z,1566501363.277 [NAL9602](INFO): SBD MO Status=1, MOMSN=32550, MT Status=0, MTMSN=0
2019-08-22T19:16:03.325Z,1566501363.325 [NAL9602](INFO): Sent 64 bytes from file Logs/20190822T180446/Courier0040.lzma
2019-08-22T19:16:03.325Z,1566501363.325 [NAL9602](INFO): Packets left to send: 0
2019-08-22T19:16:11.162Z,1566501371.162 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=32551, MT Status=1, MTMSN=2133
2019-08-22T19:16:11.209Z,1566501371.209 [NAL9602](INFO): Sent 136 bytes from file Logs/20190822T180446/Express0041.lzma
2019-08-22T19:16:11.209Z,1566501371.209 [NAL9602](INFO): Packets left to send: 0
2019-08-22T19:16:11.654Z,1566501371.654 [NAL9602](INFO): Received command:Ibit
2019-08-22T19:16:11.753Z,1566501371.753 [CommandLine](IMPORTANT): got command ibit
2019-08-22T19:16:12.017Z,1566501372.017 [IBIT](IMPORTANT): Beginning Initiated BIT
2019-08-22T19:16:12.017Z,1566501372.017 [IBIT](IMPORTANT): Beginning control surface checks.
2019-08-22T19:16:12.021Z,1566501372.021 [CBIT](IMPORTANT): Beginning ground fault scan
2019-08-22T19:16:12.793Z,1566501372.793 [NAL9602](DEBUG): Fix Requested
2019-08-22T19:16:13.179Z,1566501373.179 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191600.00,A,4148.07155,N,08311.52018,W,1.050,278.06,220819,,,D*73
2019-08-22T19:16:13.181Z,1566501373.181 [NAL9602](INFO): GPS fix at 20190822T191600: (41.801192, -83.192003)
2019-08-22T19:16:21.373Z,1566501381.373 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:16:22.365Z,1566501382.365 [NAL9602](INFO): SBD MO Status=0, MOMSN=32552, MT Status=0, MTMSN=0
2019-08-22T19:16:23.185Z,1566501383.185 [NAL9602](DEBUG): Fix Requested
2019-08-22T19:16:23.582Z,1566501383.582 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191611.00,A,4148.07037,N,08311.52326,W,0.778,224.60,220819,,,D*7D
2019-08-22T19:16:23.584Z,1566501383.584 [NAL9602](INFO): GPS fix at 20190822T191611: (41.801173, -83.192054)
2019-08-22T19:16:24.423Z,1566501384.423 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.005673
CHAN A1 (24V): 0.048725
CHAN A2 (12V): 0.026865
CHAN A3 (5V): 0.003975
CHAN B0 (3.3V): 0.001921
CHAN B1 (3.15aV): 0.001838
CHAN B2 (3.15bV): 0.002181
CHAN B3 (GND): -0.000015
OPEN: 0.006824
Full Scale Calc: 4.765 mA, -1.589 mA
2019-08-22T19:16:48.532Z,1566501408.532 [NAL9602](INFO): SBD MO Status=2, MOMSN=32553, MT Status=2, MTMSN=0
2019-08-22T19:16:48.532Z,1566501408.532 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-22T19:16:49.349Z,1566501409.349 [NAL9602](DEBUG): Fix Requested
2019-08-22T19:16:49.738Z,1566501409.738 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191637.00,A,4148.06948,N,08311.52730,W,1.263,252.45,220819,,,D*72
2019-08-22T19:16:49.740Z,1566501409.740 [NAL9602](INFO): GPS fix at 20190822T191637: (41.801158, -83.192122)
2019-08-22T19:16:52.077Z,1566501412.077 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:16:54.293Z,1566501414.293 [NAL9602](DEBUG): Fix Requested
2019-08-22T19:16:54.686Z,1566501414.686 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191642.00,A,4148.06781,N,08311.52998,W,1.322,219.84,220819,,,D*71
2019-08-22T19:16:54.688Z,1566501414.688 [NAL9602](INFO): GPS fix at 20190822T191642: (41.801130, -83.192166)
2019-08-22T19:17:02.816Z,1566501422.816 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 4
Latitude: 41.801128 Longitude: -83.192169
2019-08-22T19:17:03.705Z,1566501423.705 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 365.110840
Voltage: 16.685709
2019-08-22T19:17:03.705Z,1566501423.705 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2019-08-22T19:17:03.705Z,1566501423.705 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2019-08-22T19:17:05.837Z,1566501425.837 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2019-08-22T19:17:05.837Z,1566501425.837 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2019-08-22T19:17:05.838Z,1566501425.838 [IBIT](IMPORTANT): Pressure:10.064472 PSI
2019-08-22T19:17:05.838Z,1566501425.838 [IBIT](IMPORTANT): Humidity:23.367109 %
2019-08-22T19:17:06.001Z,1566501426.001 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2019-08-22T19:17:06.001Z,1566501426.001 [IBIT](IMPORTANT): buoyancyNeutral: 325.000000 cc
2019-08-22T19:17:06.002Z,1566501426.002 [IBIT](IMPORTANT): massDefault: 1.100000 cm
2019-08-22T19:17:06.002Z,1566501426.002 [IBIT](IMPORTANT): stopDepth: 10.000000 m
2019-08-22T19:17:06.002Z,1566501426.002 [IBIT](IMPORTANT): abortDepth: 50.000000 m
2019-08-22T19:17:06.002Z,1566501426.002 [IBIT](IMPORTANT): IBIT PASSED
2019-08-22T19:17:21.217Z,1566501441.217 [NAL9602](INFO): SBD MO Status=2, MOMSN=32553, MT Status=2, MTMSN=0
2019-08-22T19:17:21.217Z,1566501441.217 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-22T19:17:22.781Z,1566501442.781 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:17:40.560Z,1566501460.560 [NAL9602](INFO): SBD MO Status=1, MOMSN=32553, MT Status=0, MTMSN=0
2019-08-22T19:17:40.613Z,1566501460.613 [NAL9602](INFO): Sent 62 bytes from file Logs/20190822T180446/Courier0043.lzma
2019-08-22T19:17:40.613Z,1566501460.613 [NAL9602](INFO): Packets left to send: 0
2019-08-22T19:17:50.026Z,1566501470.026 [NAL9602](INFO): SBD MO Status=1, MOMSN=32554, MT Status=0, MTMSN=0
2019-08-22T19:17:50.085Z,1566501470.085 [NAL9602](INFO): Sent 244 bytes from file Logs/20190822T180446/Express0044.lzma
2019-08-22T19:17:50.085Z,1566501470.085 [NAL9602](INFO): Packets left to send: 0
2019-08-22T19:17:53.485Z,1566501473.485 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:17:58.602Z,1566501478.602 [NAL9602](INFO): SBD MO Status=0, MOMSN=32555, MT Status=0, MTMSN=0
2019-08-22T19:17:58.703Z,1566501478.703 [Default:CheckIn:Read_Iridium] Stopped
2019-08-22T19:17:58.703Z,1566501478.703 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-22T19:17:58.703Z,1566501478.703 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-22T19:18:24.205Z,1566501504.205 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:18:29.310Z,1566501509.310 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-22T19:18:54.909Z,1566501534.909 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:19:25.629Z,1566501565.629 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:19:56.349Z,1566501596.349 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:20:15.193Z,1566501615.193 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2019-08-22T19:20:15.194Z,1566501615.194 [BPC1](ERROR): Battery stick #39 (s/n: 00F0) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2019-08-22T19:20:15.194Z,1566501615.194 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5.
2019-08-22T19:20:15.197Z,1566501615.197 [BPC1](INFO): Received data from all battery sticks.
2019-08-22T19:20:27.053Z,1566501627.053 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:20:57.757Z,1566501657.757 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:21:28.461Z,1566501688.461 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:21:59.165Z,1566501719.165 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:22:29.869Z,1566501749.869 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:22:59.228Z,1566501779.228 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-22T19:22:59.228Z,1566501779.228 [Default:CheckIn:C.Wait] Stopped
2019-08-22T19:22:59.228Z,1566501779.228 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-22T19:22:59.228Z,1566501779.228 [Default:CheckIn:D] Running Loop=1
2019-08-22T19:22:59.632Z,1566501779.632 [Default:CheckIn:D] Stopped
2019-08-22T19:22:59.632Z,1566501779.632 [Default:CheckIn:E] Running Loop=1
2019-08-22T19:23:00.028Z,1566501780.028 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.543001 min 
2019-08-22T19:23:00.028Z,1566501780.028 [Default:CheckIn:E] Stopped
2019-08-22T19:23:00.029Z,1566501780.029 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-22T19:23:00.029Z,1566501780.029 [Default:CheckIn] Stopped
2019-08-22T19:23:00.029Z,1566501780.029 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-22T19:23:00.029Z,1566501780.029 [Default:CheckIn](INFO): Running loop #14
2019-08-22T19:23:00.029Z,1566501780.029 [Default:CheckIn] Running Loop=14
2019-08-22T19:23:00.029Z,1566501780.029 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-22T19:23:00.029Z,1566501780.029 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-22T19:23:00.573Z,1566501780.573 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:23:01.629Z,1566501781.629 [NAL9602](DEBUG): Fix Requested
2019-08-22T19:23:02.022Z,1566501782.022 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192249.00,A,4147.87937,N,08309.76993,W,16.348,95.78,220819,,,D*73
2019-08-22T19:23:02.024Z,1566501782.024 [NAL9602](INFO): GPS fix at 20190822T192249: (41.797989, -83.162832)
2019-08-22T19:23:02.047Z,1566501782.047 [Default:CheckIn:Read_GPS] Stopped
2019-08-22T19:23:02.047Z,1566501782.047 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-22T19:23:04.047Z,1566501784.047 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-08-22T19:23:28.082Z,1566501808.082 [NAL9602](INFO): SBD MO Status=1, MOMSN=32556, MT Status=0, MTMSN=0
2019-08-22T19:23:28.129Z,1566501808.129 [NAL9602](INFO): Sent 81 bytes from file Logs/20190822T180446/Courier0046.lzma
2019-08-22T19:23:28.129Z,1566501808.129 [NAL9602](INFO): Packets left to send: 0
2019-08-22T19:23:31.277Z,1566501811.277 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:23:40.807Z,1566501820.807 [NAL9602](INFO): SBD MO Status=1, MOMSN=32557, MT Status=0, MTMSN=0
2019-08-22T19:23:40.857Z,1566501820.857 [NAL9602](INFO): Sent 332 bytes from file Logs/20190822T180446/Express0047.lzma
2019-08-22T19:23:40.857Z,1566501820.857 [NAL9602](INFO): Packets left to send: 1
2019-08-22T19:24:01.981Z,1566501841.981 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:24:04.443Z,1566501844.443 [NAL9602](INFO): SBD MO Status=1, MOMSN=32558, MT Status=0, MTMSN=0
2019-08-22T19:24:04.493Z,1566501844.493 [NAL9602](INFO): Sent 298 bytes from file Logs/20190822T180446/Express0047.lzma
2019-08-22T19:24:04.493Z,1566501844.493 [NAL9602](INFO): Packets left to send: 0
2019-08-22T19:24:20.683Z,1566501860.683 [NAL9602](INFO): SBD MO Status=2, MOMSN=32559, MT Status=2, MTMSN=0
2019-08-22T19:24:20.684Z,1566501860.684 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-22T19:24:32.507Z,1566501872.507 [NAL9602](INFO): SBD MO Status=0, MOMSN=32559, MT Status=0, MTMSN=0
2019-08-22T19:24:32.591Z,1566501872.591 [Default:CheckIn:Read_Iridium] Stopped
2019-08-22T19:24:32.591Z,1566501872.591 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-22T19:24:32.591Z,1566501872.591 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-22T19:24:32.686Z,1566501872.686 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:25:03.212Z,1566501903.212 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-22T19:25:03.389Z,1566501903.389 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:25:15.628Z,1566501915.628 [CommandLine](IMPORTANT): got command failComponent
2019-08-22T19:25:15.628Z,1566501915.628 [CommandLine](IMPORTANT): Failed components:
2019-08-22T19:25:15.628Z,1566501915.628 [CommandLine](IMPORTANT): No failed Components.
2019-08-22T19:25:34.093Z,1566501934.093 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:26:04.797Z,1566501964.797 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:26:35.501Z,1566501995.501 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:27:06.205Z,1566502026.205 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:27:36.909Z,1566502056.909 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:28:07.613Z,1566502087.613 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:28:38.317Z,1566502118.317 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:29:09.021Z,1566502149.021 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:29:33.095Z,1566502173.095 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-22T19:29:33.095Z,1566502173.095 [Default:CheckIn:C.Wait] Stopped
2019-08-22T19:29:33.095Z,1566502173.095 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-22T19:29:33.095Z,1566502173.095 [Default:CheckIn:D] Running Loop=1
2019-08-22T19:29:33.506Z,1566502173.506 [Default:CheckIn:D] Stopped
2019-08-22T19:29:33.506Z,1566502173.506 [Default:CheckIn:E] Running Loop=1
2019-08-22T19:29:33.912Z,1566502173.912 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.107568 min 
2019-08-22T19:29:33.912Z,1566502173.912 [Default:CheckIn:E] Stopped
2019-08-22T19:29:33.912Z,1566502173.912 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-22T19:29:33.912Z,1566502173.912 [Default:CheckIn] Stopped
2019-08-22T19:29:33.912Z,1566502173.912 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-22T19:29:33.913Z,1566502173.913 [Default:CheckIn](INFO): Running loop #15
2019-08-22T19:29:33.913Z,1566502173.913 [Default:CheckIn] Running Loop=15
2019-08-22T19:29:33.913Z,1566502173.913 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-22T19:29:33.913Z,1566502173.913 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-22T19:29:35.521Z,1566502175.521 [NAL9602](DEBUG): Fix Requested
2019-08-22T19:29:35.906Z,1566502175.906 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192922.00,A,4147.63470,N,08307.99312,W,0.447,126.32,220819,,,D*75
2019-08-22T19:29:35.908Z,1566502175.908 [NAL9602](INFO): GPS fix at 20190822T192922: (41.793912, -83.133219)
2019-08-22T19:29:35.955Z,1566502175.955 [Default:CheckIn:Read_GPS] Stopped
2019-08-22T19:29:35.955Z,1566502175.955 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-22T19:29:39.725Z,1566502179.725 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:30:05.733Z,1566502205.733 [NAL9602](INFO): SBD MO Status=2, MOMSN=32560, MT Status=2, MTMSN=0
2019-08-22T19:30:05.733Z,1566502205.733 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-22T19:30:10.429Z,1566502210.429 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:30:29.015Z,1566502229.015 [NAL9602](INFO): SBD MO Status=2, MOMSN=32560, MT Status=2, MTMSN=0
2019-08-22T19:30:29.016Z,1566502229.016 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-22T19:30:41.133Z,1566502241.133 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:30:52.309Z,1566502252.309 [NAL9602](INFO): SBD MO Status=2, MOMSN=32560, MT Status=2, MTMSN=0
2019-08-22T19:30:52.310Z,1566502252.310 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-22T19:31:11.837Z,1566502271.837 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:31:20.462Z,1566502280.462 [NAL9602](INFO): SBD MO Status=2, MOMSN=32560, MT Status=2, MTMSN=0
2019-08-22T19:31:20.462Z,1566502280.462 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-22T19:31:42.541Z,1566502302.541 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:31:48.640Z,1566502308.639 [NAL9602](INFO): SBD MO Status=1, MOMSN=32560, MT Status=0, MTMSN=0
2019-08-22T19:31:48.689Z,1566502308.689 [NAL9602](INFO): Sent 64 bytes from file Logs/20190822T180446/Courier0049.lzma
2019-08-22T19:31:48.689Z,1566502308.689 [NAL9602](INFO): Packets left to send: 0
2019-08-22T19:31:58.941Z,1566502318.941 [NAL9602](INFO): SBD MO Status=1, MOMSN=32561, MT Status=0, MTMSN=0
2019-08-22T19:31:58.996Z,1566502318.996 [NAL9602](INFO): Sent 191 bytes from file Logs/20190822T180446/Express0050.lzma
2019-08-22T19:31:58.997Z,1566502318.997 [NAL9602](INFO): Packets left to send: 0
2019-08-22T19:32:12.764Z,1566502332.764 [NAL9602](INFO): SBD MO Status=0, MOMSN=32562, MT Status=0, MTMSN=0
2019-08-22T19:32:12.855Z,1566502332.855 [Default:CheckIn:Read_Iridium] Stopped
2019-08-22T19:32:12.855Z,1566502332.855 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-22T19:32:12.855Z,1566502332.855 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-22T19:32:13.245Z,1566502333.245 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:32:43.467Z,1566502363.467 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-22T19:32:43.949Z,1566502363.949 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:33:14.701Z,1566502394.701 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:33:45.421Z,1566502425.421 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:34:16.125Z,1566502456.125 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:34:46.829Z,1566502486.829 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:35:17.533Z,1566502517.533 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:35:48.237Z,1566502548.237 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:36:18.941Z,1566502578.941 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:36:49.645Z,1566502609.645 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:37:13.365Z,1566502633.365 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-22T19:37:13.365Z,1566502633.365 [Default:CheckIn:C.Wait] Stopped
2019-08-22T19:37:13.365Z,1566502633.365 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-22T19:37:13.365Z,1566502633.365 [Default:CheckIn:D] Running Loop=1
2019-08-22T19:37:13.776Z,1566502633.776 [Default:CheckIn:D] Stopped
2019-08-22T19:37:13.776Z,1566502633.776 [Default:CheckIn:E] Running Loop=1
2019-08-22T19:37:14.182Z,1566502634.182 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 88.778743 min 
2019-08-22T19:37:14.182Z,1566502634.182 [Default:CheckIn:E] Stopped
2019-08-22T19:37:14.182Z,1566502634.182 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-22T19:37:14.183Z,1566502634.183 [Default:CheckIn] Stopped
2019-08-22T19:37:14.183Z,1566502634.183 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-22T19:37:14.183Z,1566502634.183 [Default:CheckIn](INFO): Running loop #16
2019-08-22T19:37:14.183Z,1566502634.183 [Default:CheckIn] Running Loop=16
2019-08-22T19:37:14.183Z,1566502634.183 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-22T19:37:14.183Z,1566502634.183 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-22T19:37:15.773Z,1566502635.773 [NAL9602](DEBUG): Fix Requested
2019-08-22T19:37:16.171Z,1566502636.171 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193701.00,A,4147.62068,N,08308.00491,W,1.050,197.86,220819,,,D*72
2019-08-22T19:37:16.174Z,1566502636.174 [NAL9602](INFO): GPS fix at 20190822T193701: (41.793678, -83.133415)
2019-08-22T19:37:16.196Z,1566502636.196 [Default:CheckIn:Read_GPS] Stopped
2019-08-22T19:37:16.196Z,1566502636.196 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-22T19:37:20.349Z,1566502640.349 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:37:35.050Z,1566502655.050 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=32563, MT Status=1, MTMSN=2134
2019-08-22T19:37:35.110Z,1566502655.110 [NAL9602](INFO): Sent 64 bytes from file Logs/20190822T180446/Courier0052.lzma
2019-08-22T19:37:35.110Z,1566502655.110 [NAL9602](INFO): Packets left to send: 0
2019-08-22T19:37:36.017Z,1566502656.017 [NAL9602](INFO): Received command:sched asap "load Science/esp_kiss.xml;set esp_kiss.ESPCartridgeType_2 -15 count;set esp_kiss.SettleTime 10 minute;set esp_kiss.ApproachSpeed 0.85 meter_per_second;set esp_kiss.MinAltitude 0.001 meter;set esp_kiss.MinOffshore 0.01 kilometer" 1l2cw 1 2
2019-08-22T19:37:36.098Z,1566502656.098 [CommandLine](IMPORTANT): got command schedule asap "load Science/esp_kiss.xml;set esp_kiss.ESPCartridgeType_2 -15 count;set esp_kiss.SettleTime 10 minute;set esp_kiss.ApproachSpeed 0.85 meter_per_second;set esp_kiss.MinAltitude 0.001 meter;set esp_kiss.MinOffshore 0.01 kilometer" 1l2cw 1 2.000000
2019-08-22T19:37:36.099Z,1566502656.099 [CommandLine](IMPORTANT): Scheduling command #1 of 2 with id=1l2cw
2019-08-22T19:37:36.100Z,1566502656.100 [CommandLine](IMPORTANT): Scheduled #1 (#1 of 2 with id='1l2cw'): "load Science/esp_kiss.xml;set esp_kiss.ESPCartridgeType_2 -15 count;set esp_kiss.SettleTime 10 minute;set esp_kiss.ApproachSpeed 0.85 meter_per_second;set esp_kiss.MinAltitude 0.001 meter;set esp_kiss.MinOffshore 0.01 kilometer" ASAP
2019-08-22T19:37:51.069Z,1566502671.069 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:37:52.981Z,1566502672.981 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=32564, MT Status=1, MTMSN=2135
2019-08-22T19:37:53.029Z,1566502673.029 [NAL9602](INFO): Sent 128 bytes from file Logs/20190822T180446/Express0053.lzma
2019-08-22T19:37:53.029Z,1566502673.029 [NAL9602](INFO): Packets left to send: 0
2019-08-22T19:37:53.501Z,1566502673.501 [NAL9602](INFO): Received command:sched asap "run " 1l2cw 2 2
2019-08-22T19:37:53.515Z,1566502673.515 [CommandLine](IMPORTANT): got command schedule asap "run " 1l2cw 2 2.000000
2019-08-22T19:37:53.515Z,1566502673.515 [CommandLine](IMPORTANT): Scheduling command #2 of 2 with id=1l2cw
2019-08-22T19:37:53.516Z,1566502673.516 [CommandLine](IMPORTANT): Scheduled #2 (#2 of 2 with id='1l2cw'): "run " ASAP
2019-08-22T19:37:53.684Z,1566502673.684 [CommandLine](IMPORTANT): got command load ./Missions/Science/esp_kiss.xml
2019-08-22T19:37:53.684Z,1566502673.684 [MissionManager](INFO): Loading Mission: ./Missions/Science/esp_kiss.xml
2019-08-22T19:37:53.901Z,1566502673.901 [MissionManager](INFO): DefineArg esp_kiss.MissionTimeout = 4.000000 h
2019-08-22T19:37:53.904Z,1566502673.904 [MissionManager](INFO): DefineArg esp_kiss.TargetDepth = 3.000000 m
2019-08-22T19:37:53.907Z,1566502673.907 [MissionManager](INFO): DefineArg esp_kiss.ESPCartridgeType_1 = -4.000000 count
2019-08-22T19:37:53.911Z,1566502673.911 [MissionManager](INFO): DefineArg esp_kiss.ESPCartridgeType_2 = -9.000000 count
2019-08-22T19:37:53.914Z,1566502673.914 [MissionManager](INFO): DefineArg esp_kiss.ESPCartridgeType_3 = nan count
2019-08-22T19:37:53.917Z,1566502673.917 [MissionManager](INFO): DefineArg esp_kiss.ESPCartridgeType_4 = nan count
2019-08-22T19:37:53.921Z,1566502673.921 [MissionManager](INFO): DefineArg esp_kiss.SettleTime = 3.000000 min
2019-08-22T19:37:53.924Z,1566502673.924 [MissionManager](INFO): DefineArg esp_kiss.Speed = 0.000000 m/s
2019-08-22T19:37:53.927Z,1566502673.927 [MissionManager](INFO): DefineArg esp_kiss.ApproachDepth = 2.000000 m
2019-08-22T19:37:53.930Z,1566502673.930 [MissionManager](INFO): DefineArg esp_kiss.ApproachSpeed = 0.700000 m/s
2019-08-22T19:37:53.934Z,1566502673.934 [MissionManager](INFO): DefineArg esp_kiss.ApproachDepthRate = 0.050000 m/s
2019-08-22T19:37:53.937Z,1566502673.937 [MissionManager](INFO): DefineArg esp_kiss.ApproachPitchLimit = 10.000000 arcdeg
2019-08-22T19:37:53.940Z,1566502673.940 [MissionManager](INFO): DefineArg esp_kiss.ApproachSettleTimePreDive = 1.000000 min
2019-08-22T19:37:53.961Z,1566502673.961 [MissionManager](INFO): DefineArg esp_kiss.ApproachSettleTimePostDive = 1.000000 min
2019-08-22T19:37:53.964Z,1566502673.964 [MissionManager](INFO): DefineArg esp_kiss.ApproachDepthTimeout = 15.000000 min
2019-08-22T19:37:53.972Z,1566502673.972 [MissionManager](INFO): DefineArg esp_kiss.kpDepth = 0.070000 rad/m
2019-08-22T19:37:53.979Z,1566502673.979 [MissionManager](INFO): DefineArg esp_kiss.DepthDeadband = 0.010000 m
2019-08-22T19:37:53.984Z,1566502673.984 [MissionManager](INFO): DefineArg esp_kiss.MinAltitude = 2.000000 m
2019-08-22T19:37:53.999Z,1566502673.999 [MissionManager](INFO): DefineArg esp_kiss.MaxDepth = 5.000000 m
2019-08-22T19:37:54.007Z,1566502674.007 [MissionManager](INFO): DefineArg esp_kiss.MinOffshore = 1.000000 km
2019-08-22T19:37:54.014Z,1566502674.014 [MissionManager](INFO): DefineOutput esp_kiss.ESPCartridgeType = nan count
2019-08-22T19:37:54.015Z,1566502674.015 [esp_kiss:A.AbortSample](DEBUG): Construct.
2019-08-22T19:37:54.016Z,1566502674.016 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2019-08-22T19:37:54.052Z,1566502674.052 [MissionManager](INFO): DefineArg esp_kiss:StandardEnvelopes.MinAltitude = 5.000000 m
2019-08-22T19:37:54.064Z,1566502674.064 [MissionManager](INFO): DefineArg esp_kiss:StandardEnvelopes.MaxDepth = 200.000000 m
2019-08-22T19:37:54.071Z,1566502674.071 [MissionManager](INFO): DefineArg esp_kiss:StandardEnvelopes.MinOffshore = 2000.000000 m
2019-08-22T19:37:54.072Z,1566502674.072 [esp_kiss:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2019-08-22T19:37:54.084Z,1566502674.084 [esp_kiss:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2019-08-22T19:37:54.113Z,1566502674.113 [esp_kiss:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2019-08-22T19:37:54.142Z,1566502674.142 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2019-08-22T19:37:54.285Z,1566502674.285 [MissionManager](INFO): DefineArg esp_kiss:NeedComms.DiveInterval = 3.000000 h
2019-08-22T19:37:54.288Z,1566502674.288 [MissionManager](INFO): DefineArg esp_kiss:NeedComms.WaitForPitchUp = 10.000000 min
2019-08-22T19:37:54.296Z,1566502674.296 [MissionManager](INFO): DefineArg esp_kiss:NeedComms.SurfacePitch = 20.000000 arcdeg
2019-08-22T19:37:54.304Z,1566502674.304 [MissionManager](INFO): DefineArg esp_kiss:NeedComms.SurfaceDepthRate = nan m/s
2019-08-22T19:37:54.311Z,1566502674.311 [MissionManager](INFO): DefineArg esp_kiss:NeedComms.SurfaceSpeed = 1.000000 m/s
2019-08-22T19:37:54.315Z,1566502674.315 [MissionManager](INFO): DefineArg esp_kiss:NeedComms.GPSTimeout = 7.000000 min
2019-08-22T19:37:54.326Z,1566502674.326 [MissionManager](INFO): DefineArg esp_kiss:NeedComms.CommsTimeout = 30.000000 min
2019-08-22T19:37:54.341Z,1566502674.341 [esp_kiss:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-08-22T19:37:54.402Z,1566502674.402 [esp_kiss:SampleESP:sample:B.Wait](DEBUG): Construct Wait.
2019-08-22T19:37:54.408Z,1566502674.408 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature
2019-08-22T19:37:54.408Z,1566502674.408 [MissionManager](ERROR): Slate does not contain celsius
2019-08-22T19:37:54.422Z,1566502674.422 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2019-08-22T19:37:54.810Z,1566502674.810 [MissionManager](INFO): DefineArg esp_kiss:Science.SampleISUS = 0 bool
2019-08-22T19:37:54.813Z,1566502674.813 [MissionManager](INFO): DefineArg esp_kiss:Science.SampleISUSmaxPitch = 60.000000 arcdeg
2019-08-22T19:37:54.816Z,1566502674.816 [MissionManager](INFO): DefineArg esp_kiss:Science.SampleISUSminPitch = -60.000000 arcdeg
2019-08-22T19:37:54.819Z,1566502674.819 [MissionManager](INFO): DefineArg esp_kiss:Science.PeakDetectChlActive = 0 bool
2019-08-22T19:37:54.822Z,1566502674.822 [MissionManager](INFO): DefineArg esp_kiss:Science.TimeWindowPeakReport = nan min
2019-08-22T19:37:54.842Z,1566502674.842 [MissionManager](INFO): DefineArg esp_kiss:Science.HighestChlPeakReportActive = 0 bool
2019-08-22T19:37:54.844Z,1566502674.844 [MissionManager](INFO): DefineArg esp_kiss:Science.PatchTracking = 0 bool
2019-08-22T19:37:54.847Z,1566502674.847 [MissionManager](INFO): DefineArg esp_kiss:Science.FilterWidthHorizontal = 3.000000 count
2019-08-22T19:37:54.850Z,1566502674.850 [MissionManager](INFO): DefineArg esp_kiss:Science.NumProfilesSlidingwindow = 100.000000 count
2019-08-22T19:37:54.873Z,1566502674.873 [MissionManager](INFO): DefineArg esp_kiss:Science.OffPeakFractionHorizontal = 80.000000 %
2019-08-22T19:37:54.876Z,1566502674.876 [MissionManager](INFO): DefineArg esp_kiss:Science.PeakDetectNO3Active = 0 bool
2019-08-22T19:37:54.879Z,1566502674.879 [MissionManager](INFO): DefineArg esp_kiss:Science.PeakDetectOilActive = 0 bool
2019-08-22T19:37:54.881Z,1566502674.881 [MissionManager](INFO): DefineArg esp_kiss:Science.PeakDetectFDOMActive = 0 bool
2019-08-22T19:37:54.884Z,1566502674.884 [MissionManager](INFO): DefineArg esp_kiss:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2019-08-22T19:37:54.888Z,1566502674.888 [MissionManager](INFO): DefineArg esp_kiss:Science.EnabledAanderaaO2 = 1.000000 bool
2019-08-22T19:37:54.891Z,1566502674.891 [MissionManager](INFO): DefineArg esp_kiss:Science.EnabledNeilBrown = 0.000000 bool
2019-08-22T19:37:54.894Z,1566502674.894 [MissionManager](INFO): DefineArg esp_kiss:Science.EnabledSeabird = 1.000000 bool
2019-08-22T19:37:54.922Z,1566502674.922 [MissionManager](INFO): DefineArg esp_kiss:Science.EnabledTurbulence_NPS = 0.000000 bool
2019-08-22T19:37:54.925Z,1566502674.925 [MissionManager](INFO): DefineArg esp_kiss:Science.EnabledWetLabsBB2FL = 1.000000 bool
2019-08-22T19:37:54.929Z,1566502674.929 [MissionManager](INFO): DefineArg esp_kiss:Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool
2019-08-22T19:37:54.932Z,1566502674.932 [MissionManager](INFO): DefineArg esp_kiss:Science.EnabledWetLabsUBAT = 0.000000 bool
2019-08-22T19:37:54.937Z,1566502674.937 [MissionManager](INFO): DefineArg esp_kiss:Science.EnabledISUS = 0.000000 bool
2019-08-22T19:37:54.940Z,1566502674.940 [MissionManager](INFO): DefineArg esp_kiss:Science.LowPassWindowLength = 20.000000 count
2019-08-22T19:37:54.943Z,1566502674.943 [MissionManager](INFO): DefineArg esp_kiss:Science.MedianFilterLen = 5.000000 count
2019-08-22T19:37:54.970Z,1566502674.970 [MissionManager](INFO): DefineArg esp_kiss:Science.PeakChlShallowBound = nan m
2019-08-22T19:37:54.973Z,1566502674.973 [MissionManager](INFO): DefineArg esp_kiss:Science.PeakChlDeepBound = nan m
2019-08-22T19:37:54.976Z,1566502674.976 [MissionManager](INFO): DefineArg esp_kiss:Science.PeakShallowBound = nan m
2019-08-22T19:37:54.978Z,1566502674.978 [MissionManager](INFO): DefineArg esp_kiss:Science.PeakDeepBound = nan m
2019-08-22T19:37:55.033Z,1566502675.033 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakChl = 0.000000 ug/l
2019-08-22T19:37:55.036Z,1566502675.036 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakChlDepth = 0.000000 m
2019-08-22T19:37:55.051Z,1566502675.051 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakChlTemperature = 0.000000 degC
2019-08-22T19:37:55.060Z,1566502675.060 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakChlLatitude = nan arcdeg
2019-08-22T19:37:55.072Z,1566502675.072 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakChlLongitude = nan arcdeg
2019-08-22T19:37:55.085Z,1566502675.085 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakNO3 = 0.000000 umol/l
2019-08-22T19:37:55.088Z,1566502675.088 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakNO3Depth = 0.000000 m
2019-08-22T19:37:55.095Z,1566502675.095 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakNO3Latitude = nan arcdeg
2019-08-22T19:37:55.099Z,1566502675.099 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakNO3Longitude = nan arcdeg
2019-08-22T19:37:55.111Z,1566502675.111 [MissionManager](INFO): DefineOutput esp_kiss:Science.PatchChl = 0.000000 m
2019-08-22T19:37:55.114Z,1566502675.114 [MissionManager](INFO): DefineOutput esp_kiss:Science.PatchChlDepth = 0.000000 m
2019-08-22T19:37:55.125Z,1566502675.125 [MissionManager](INFO): DefineOutput esp_kiss:Science.PatchChlLatitude = nan arcdeg
2019-08-22T19:37:55.133Z,1566502675.133 [MissionManager](INFO): DefineOutput esp_kiss:Science.PatchChlLongitude = nan arcdeg
2019-08-22T19:37:55.136Z,1566502675.136 [MissionManager](INFO): DefineOutput esp_kiss:Science.PatchChlDistance = nan m
2019-08-22T19:37:55.143Z,1566502675.143 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakOil = 0.000000 kg/m3
2019-08-22T19:37:55.148Z,1566502675.148 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakOilDepth = 0.000000 m
2019-08-22T19:37:55.163Z,1566502675.163 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakOilLatitude = nan arcdeg
2019-08-22T19:37:55.175Z,1566502675.175 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakOilLongitude = nan arcdeg
2019-08-22T19:37:55.182Z,1566502675.182 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakFDOM = 0.000000 ppb
2019-08-22T19:37:55.189Z,1566502675.189 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakFDOMDepth = 0.000000 m
2019-08-22T19:37:55.197Z,1566502675.197 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakFDOMLatitude = nan arcdeg
2019-08-22T19:37:55.200Z,1566502675.200 [MissionManager](INFO): DefineOutput esp_kiss:Science.PeakFDOMLongitude = nan arcdeg
2019-08-22T19:37:55.207Z,1566502675.207 [MissionManager](INFO): DefineOutput esp_kiss:Science.PatchFDOMDistance = nan m
2019-08-22T19:37:55.246Z,1566502675.246 [esp_kiss:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-08-22T19:37:55.270Z,1566502675.270 [esp_kiss:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2019-08-22T19:37:55.302Z,1566502675.302 [esp_kiss:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-08-22T19:37:55.325Z,1566502675.325 [esp_kiss:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-08-22T19:37:55.344Z,1566502675.344 [esp_kiss:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-08-22T19:37:55.375Z,1566502675.375 [esp_kiss:InitialDive:C.Pitch](DEBUG): Construct.
2019-08-22T19:37:55.446Z,1566502675.446 [esp_kiss:InitialDive:D.Point](DEBUG): Construct.
2019-08-22T19:37:55.469Z,1566502675.469 [esp_kiss:InitialDive:E.Buoyancy](DEBUG): Construct Buoyancy.
2019-08-22T19:37:55.478Z,1566502675.478 [esp_kiss:InitialDive:G.Wait](DEBUG): Construct Wait.
2019-08-22T19:37:55.486Z,1566502675.486 [esp_kiss:InitialDive:ApproachDepth:A.SetSpeed](DEBUG): Construct.
2019-08-22T19:37:55.490Z,1566502675.490 [esp_kiss:InitialDive:ApproachDepth:B.Pitch](DEBUG): Construct.
2019-08-22T19:37:55.514Z,1566502675.514 [esp_kiss:InitialDive:ApproachDepth:B.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-08-22T19:37:55.523Z,1566502675.523 [esp_kiss:SettleAtDepth:B.Pitch](DEBUG): Construct.
2019-08-22T19:37:55.544Z,1566502675.544 [esp_kiss:SettleAtDepth:C.Wait](DEBUG): Construct Wait.
2019-08-22T19:37:55.547Z,1566502675.547 [esp_kiss:SampleAtTargetDepth:A.SetSpeed](DEBUG): Construct.
2019-08-22T19:37:55.564Z,1566502675.564 [esp_kiss:SampleAtTargetDepth:B.Pitch](DEBUG): Construct.
2019-08-22T19:37:55.570Z,1566502675.570 [esp_kiss:SampleAtTargetDepth:Spinout:HoldMassPosition.Pitch](DEBUG): Construct.
2019-08-22T19:37:55.599Z,1566502675.599 [esp_kiss:SampleAtTargetDepth:Spinout:HoldBuoyancyPosition.Buoyancy](DEBUG): Construct Buoyancy.
2019-08-22T19:37:55.602Z,1566502675.602 [esp_kiss:SampleAtTargetDepth:Spinout:HoldRudderAngle.Point](DEBUG): Construct.
2019-08-22T19:37:55.716Z,1566502675.716 [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:Control="Tethys/Control"
         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/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                             Tethys/Science http://okeanids.mbari.org/tethys/Xml/Science.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="esp_kiss">

    <Description>
        This mission takes ESP samples at the designated depth.
    </Description>

    <DefineArg Name="MissionTimeout"><Description>
        Maximum duration of mission.
    </Description><Units:hour/><Value>4</Value></DefineArg>

    <DefineArg Name="TargetDepth"><Description>
        Depth to sample at. Initialized to 3 m.
    </Description><Units:meter/><Value>3</Value></DefineArg>

    <DefineArg Name="ESPCartridgeType_1"><Description>
        Specifies ESP cartridge type code for sample# 1. Set to NaN to skip this sample.
    </Description><Units:count/><Value>-4</Value></DefineArg>

    <DefineArg Name="ESPCartridgeType_2"><Description>
        Specifies ESP cartridge type code for sample# 2. Set to NaN to skip this sample.
    </Description><Units:count/><Value>-9</Value></DefineArg>

    <DefineArg Name="ESPCartridgeType_3"><Description>
        Specifies ESP cartridge type code for sample# 3. Set to NaN to skip this sample.
    </Description><Units:count/><Value>NaN</Value></DefineArg>

    <DefineArg Name="ESPCartridgeType_4"><Description>
        Specifies ESP cartridge type code for sample# 4. Set to NaN to skip this sample.
    </Description><Units:count/><Value>NaN</Value></DefineArg>

    <DefineArg Name="SettleTime"><Description>
        How long to wait between samples. This starts *before* the first sample.
    </Description><Units:minute/><Value>3</Value></DefineArg>

    <DefineArg Name="Speed"><Description>
        Vehicle speed while sampling. Set to zero to maintain depth using VBS (drift).
    </Description><Units:meter_per_second/><Value>0</Value></DefineArg>

    <DefineArg Name="ApproachDepth"><Description>
        Depth for initial descent form the surface. Initialized to 3 m.
    </Description><Units:meter/><Value>2</Value></DefineArg>

    <DefineArg Name="ApproachSpeed"><Description>
        Vehicle speed for initial descent form the surface to target depth. Set to zero
        to disable the thruster and descend using VBS (drift).
    </Description><Units:meter_per_second/><Value>0.7</Value></DefineArg>

    <DefineArg Name="ApproachDepthRate"><Description>
        Descent depth rate (Positive depth rate means going down).
    </Description><Units:meter_per_second/><Value>0.05</Value></DefineArg>

    <DefineArg Name="ApproachPitchLimit"><Description>
        Max vehicle pitch (+/-) when decending from the surface.
    </Description><Units:degree/><Value>10</Value></DefineArg>

    <DefineArg Name="ApproachSettleTimePreDive"><Description>
        Time duration for the vehicle to pump down the VBS *BEFORE* leaving the surface.
    </Description><Units:minute/><Value>1</Value></DefineArg>

    <DefineArg Name="ApproachSettleTimePostDive"><Description>
        Time duration for the vehicle to settle *AFTER* reaching the target depth.
    </Description><Units:minute/><Value>1</Value></DefineArg>

    <DefineArg Name="ApproachDepthTimeout"><Description>
        Maximum time duration for the vehicle to reach the target depth.
    </Description><Units:minute/><Value>15</Value></DefineArg>

    <DefineArg Name="kpDepth"><Description>
        Dive loop proportional gain (applied only while the vehicle is descending to target depth).
    </Description><Units:radian_per_meter/><Value>0.07</Value></DefineArg>

    <DefineArg Name="DepthDeadband"><Description>
        How much vertical drift from the specified depth is allowed while sampling.
    </Description><Units:meter/><Value>0.01</Value></DefineArg>

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

    <DefineArg Name="MaxDepth"><Description>
        Maximum allowable depth during the mission.
    </Description><Units:meter/><Value>5</Value></DefineArg>

    <DefineArg Name="MinOffshore"><Description>
        Minimum distance from the shoreline to maintain.
    </Description><Units:kilometer/><Value>1</Value></DefineArg>

    <DefineOutput Name="ESPCartridgeType"><Description>
        Mission parameter (don't change). Specifies ESP cartridge type code.
    </Description><Units:count/><Value>NaN</Value></DefineOutput>
    
    <!-- Mission timeout -->

    <Timeout Duration="MissionTimeout"/>

    <!-- Safety nets and surfacing behaviors -->

    <Trigger:AbortSample>
        <Parallel/>
    </Trigger:AbortSample>

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

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

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

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


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

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

    <Assign><Sequence/><Arg Name="NeedComms:WaitForPitchUp"/><Units:minute/><Value>0</Value></Assign>


    <Assign><Parallel/><Control:VerticalControl.depthDeadband/><Arg Name="DepthDeadband"/></Assign>

        
    <!-- Callable aggregate -->

    <Aggregate Id="SampleESP">
        
        <When>
            <Called/>
        </When>

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

            <Syslog Severity="Important">At <Universal:depth/><Units:meter/>, settling for <Arg Name="SettleTime"/><Units:minute/></Syslog>

            <Guidance:Wait>
                <Sequence/>
                <Setting><Guidance:Wait.duration/><Arg Name="SettleTime"/></Setting>
            </Guidance:Wait>

            <Syslog Severity="Important">Requesting ESP cartridge type:<Arg Name="ESPCartridgeType"/><Units:count/></Syslog>

            <Assign><Sequence/><Science:ESPComponent.cartridge/><Arg Name="ESPCartridgeType"/></Assign>

            <ReadDatum Id="TriggerESP">
                <Science:ESPComponent.sampling/>
            </ReadDatum>

            <Syslog Severity="Important">ESP sampling at <Universal:depth/><Units:meter/> in <Science:CTD_NeilBrown.bin_mean_sea_water_temperature/><Units:celsius/> water with <Science:WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water/><Units:microgram_per_liter/>chlorophyll fluorescence.</Syslog>

            <ReadDatum Id="WaitForESP">
                <Science:ESPComponent.sample_number/>
            </ReadDatum>
        </Aggregate>

    </Aggregate>


    <!-- Start mission sequence -->

    <Call Id="StartingMission" RefId="NeedComms"/>
    
    <Insert Filename="Insert/Science.xml"></Insert>

    <Aggregate Id="InitialDive">
        <Description>
            Descend from the surface to approach depth at ApproachSpeed, limit pitch,
            depth-rate, and hold the rudder.
        </Description>

        <Sequence/>

        <Assign><Parallel/><Control:VerticalControl.pitchLimit/><Arg Name="ApproachPitchLimit"/></Assign>

        <Assign><Parallel/><Control:VerticalControl.kpDepth/><Arg Name="kpDepth"/></Assign>

        <Guidance:Pitch>
            <Parallel/>
            <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
        </Guidance:Pitch>

        <Guidance:Point>
            <Parallel/>
            <Setting><Guidance:Point.rudderAngle/><Units:degree/><Value>13</Value></Setting>
        </Guidance:Point>
        
        <Guidance:Buoyancy>
            <Parallel/>
            <Setting><Guidance:Buoyancy.position/><Control:VerticalControl.buoyancyNeutral/></Setting>
        </Guidance:Buoyancy>

        <Syslog Severity="Info">Waiting for <Arg Name="ApproachSettleTimePreDive"/><Units:minute/>while pumping down to neutral.</Syslog>

        <Guidance:Wait>
            <Description>Take a few moments to ensure the VBS reaches neutral.</Description>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Arg Name="ApproachSettleTimePreDive"/></Setting>
        </Guidance:Wait>

        <Syslog>Moving to <Arg Name="ApproachDepth"/><Units:meter/></Syslog>

        <Aggregate Id="ApproachDepth">

            <Sequence/>

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

            <Guidance:Pitch>
                <Sequence/>

                <Timeout Duration="ApproachDepthTimeout">
                    <Syslog Severity="Important">Timed out while trying to reach target depth at current depth of <Universal:depth/><Units:meter/>.</Syslog>
                    <Guidance:Execute>
                        <Sequence/>
                        <Setting><Guidance:Execute.command/><String>stop</String></Setting>
                    </Guidance:Execute>
                </Timeout>

                <Setting><Guidance:Pitch.depth/><Arg Name="ApproachDepth"/></Setting>
                <Setting><Guidance:Pitch.depthRate/><Arg Name="ApproachDepthRate"/></Setting>
            </Guidance:Pitch>

        </Aggregate>

    </Aggregate>

    <Aggregate Id="SettleAtDepth">
        <Description>
            Take a few more moments here to ensure the vechile is settled at the target depth.
        </Description>

        <Sequence/>

        <Syslog Severity="Info">Reached <Universal:depth/><Units:meter/>, settling for <Arg Name="ApproachSettleTimePostDive"/><Units:minute/></Syslog>

        <Guidance:Pitch>
            <Parallel/>
            <Setting><Guidance:Pitch.depth/><Arg Name="TargetDepth"/></Setting>
        </Guidance:Pitch>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Arg Name="ApproachSettleTimePostDive"/></Setting>
        </Guidance:Wait>

    </Aggregate>

    <Aggregate Id="SampleAtTargetDepth">
        <Description>
            Maintain target depth and acquire ESP samples.
        </Description>

        <Sequence/>

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

        <Guidance:Pitch>
            <Parallel/>
            <Setting><Guidance:Pitch.depth/><Arg Name="TargetDepth"/></Setting>
        </Guidance:Pitch>
        
        <Aggregate Id="Spinout">
            <Description>
                A speed has been specified, spin in circels while sampling.
            </Description>
            
            <While>
                <Arg Name="Speed"/><Gt><Units:meter_per_second/><Value>0.0</Value></Gt>
            </While>
            
            <Guidance:Pitch Id="HoldMassPosition">
                <Parallel/>
                <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
            </Guidance:Pitch>
            
            <Guidance:Buoyancy Id="HoldBuoyancyPosition">
                <Parallel/>
                <Setting><Guidance:Buoyancy.position/><Control:VerticalControl.buoyancyNeutral/></Setting>
            </Guidance:Buoyancy>

            <Guidance:Point Id="HoldRudderAngle">
                <Setting><Guidance:Point.rudderAngle/><Units:degree/><Value>8</Value></Setting>
            </Guidance:Point>

        </Aggregate>

        <Aggregate Id="GrabSamples">

            <Sequence/>

            <Aggregate Id="Sample1">
                <Break>
                    <IsNaN><Arg Name="ESPCartridgeType_1"/></IsNaN>
                </Break>

                <Assign><Sequence/><Arg Name="ESPCartridgeType"/><Arg Name="ESPCartridgeType_1"/></Assign>

                <Call RefId="SampleESP"/>
            </Aggregate>


            <Aggregate Id="Sample2">
                <Break>
                    <IsNaN><Arg Name="ESPCartridgeType_2"/></IsNaN>
                </Break>

                <Assign><Sequence/><Arg Name="ESPCartridgeType"/><Arg Name="ESPCartridgeType_2"/></Assign>

                <Call RefId="SampleESP"/>
            </Aggregate>


            <Aggregate Id="Sample3">
                <Break>
                    <IsNaN><Arg Name="ESPCartridgeType_3"/></IsNaN>
                </Break>
                
                <Assign><Sequence/><Arg Name="ESPCartridgeType"/><Arg Name="ESPCartridgeType_3"/></Assign>
                
                <Call RefId="SampleESP"/>
            </Aggregate>


            <Aggregate Id="Sample4">
                <Break>
                    <IsNaN><Arg Name="ESPCartridgeType_4"/></IsNaN>
                </Break>

                <Assign><Sequence/><Arg Name="ESPCartridgeType"/><Arg Name="ESPCartridgeType_4"/></Assign>

                <Call RefId="SampleESP"/>
            </Aggregate>

        </Aggregate>

    </Aggregate>

</Mission>


2019-08-22T19:37:55.717Z,1566502675.717 [CommandLine](IMPORTANT): Loaded ./Missions/Science/esp_kiss.xml
2019-08-22T19:38:06.410Z,1566502686.410 [CommandLine](IMPORTANT): got command set esp_kiss.ESPCartridgeType_2 -15.000000 count
2019-08-22T19:38:06.411Z,1566502686.411 [CommandLine](IMPORTANT): got command set esp_kiss.SettleTime 10.000000 minute
2019-08-22T19:38:06.412Z,1566502686.412 [CommandLine](IMPORTANT): got command set esp_kiss.ApproachSpeed 0.850000 meter_per_second
2019-08-22T19:38:06.413Z,1566502686.413 [CommandLine](IMPORTANT): got command set esp_kiss.MinAltitude 0.001000 meter
2019-08-22T19:38:06.414Z,1566502686.414 [CommandLine](IMPORTANT): got command set esp_kiss.MinOffshore 0.010000 kilometer
2019-08-22T19:38:06.617Z,1566502686.617 [CommandLine](IMPORTANT): got command run 
2019-08-22T19:38:06.620Z,1566502686.620 [CommandLine](IMPORTANT): Running 
2019-08-22T19:38:06.963Z,1566502686.963 [Default] Stopped
2019-08-22T19:38:06.963Z,1566502686.963 [Default](DEBUG): Aggregate::uninitialize Default
2019-08-22T19:38:06.963Z,1566502686.963 [Default:B.GoToSurface] Stopped
2019-08-22T19:38:06.963Z,1566502686.963 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-22T19:38:06.963Z,1566502686.963 [Default:CheckIn] Stopped
2019-08-22T19:38:06.964Z,1566502686.964 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-22T19:38:06.964Z,1566502686.964 [Default:CheckIn:Read_Iridium] Stopped
2019-08-22T19:38:06.964Z,1566502686.964 [MissionManager](IMPORTANT): Started mission esp_kiss
2019-08-22T19:38:06.964Z,1566502686.964 [esp_kiss] Running Loop=1
2019-08-22T19:38:06.964Z,1566502686.964 [esp_kiss](DEBUG): Aggregate::initialize esp_kiss
2019-08-22T19:38:06.964Z,1566502686.964 [esp_kiss:A.AbortSample] Running Loop=1
2019-08-22T19:38:06.964Z,1566502686.964 [esp_kiss:A.AbortSample](INFO): Initializing AbortSample.
2019-08-22T19:38:06.965Z,1566502686.965 [esp_kiss:StandardEnvelopes] Running Loop=1
2019-08-22T19:38:06.965Z,1566502686.965 [esp_kiss:StandardEnvelopes](DEBUG): Aggregate::initialize esp_kiss:StandardEnvelopes
2019-08-22T19:38:06.965Z,1566502686.965 [esp_kiss:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-08-22T19:38:06.965Z,1566502686.965 [esp_kiss:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2019-08-22T19:38:06.965Z,1566502686.965 [esp_kiss:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-08-22T19:38:06.965Z,1566502686.965 [esp_kiss:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2019-08-22T19:38:06.966Z,1566502686.966 [esp_kiss:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-08-22T19:38:06.966Z,1566502686.966 [esp_kiss:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2019-08-22T19:38:06.966Z,1566502686.966 [esp_kiss:I] Running Loop=1
2019-08-22T19:38:06.966Z,1566502686.966 [esp_kiss:Science] Running Loop=1
2019-08-22T19:38:06.966Z,1566502686.966 [esp_kiss:Science](DEBUG): Aggregate::initialize esp_kiss:Science
2019-08-22T19:38:06.966Z,1566502686.966 [esp_kiss:Science:A] Running Loop=1
2019-08-22T19:38:06.966Z,1566502686.966 [esp_kiss:Science:B] Running Loop=1
2019-08-22T19:38:06.966Z,1566502686.966 [esp_kiss:Science:C] Running Loop=1
2019-08-22T19:38:06.966Z,1566502686.966 [esp_kiss:Science:D] Running Loop=1
2019-08-22T19:38:06.966Z,1566502686.966 [esp_kiss:Science:E] Running Loop=1
2019-08-22T19:38:06.966Z,1566502686.966 [esp_kiss:Science:F] Running Loop=1
2019-08-22T19:38:06.966Z,1566502686.966 [esp_kiss:Science:G] Running Loop=1
2019-08-22T19:38:06.966Z,1566502686.967 [esp_kiss:Science:H] Running Loop=1
2019-08-22T19:38:06.967Z,1566502686.967 [esp_kiss:Science:Read_Oil] Running Loop=1
2019-08-22T19:38:06.967Z,1566502686.967 [esp_kiss:Science:PeakDetectChl] Running Loop=1
2019-08-22T19:38:06.967Z,1566502686.967 [esp_kiss:Science:PeakDetectChl](DEBUG): Aggregate::initialize esp_kiss:Science:PeakDetectChl
2019-08-22T19:38:06.967Z,1566502686.967 [esp_kiss:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2019-08-22T19:38:06.967Z,1566502686.967 [esp_kiss:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-08-22T19:38:06.969Z,1566502686.969 [esp_kiss:Science:HighestChlPeakReport] Running Loop=1
2019-08-22T19:38:06.969Z,1566502686.969 [esp_kiss:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize esp_kiss:Science:HighestChlPeakReport
2019-08-22T19:38:06.969Z,1566502686.969 [esp_kiss:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2019-08-22T19:38:06.969Z,1566502686.969 [esp_kiss:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2019-08-22T19:38:06.970Z,1566502686.970 [esp_kiss:Science:PeakDetectNO3] Running Loop=1
2019-08-22T19:38:06.970Z,1566502686.970 [esp_kiss:Science:PeakDetectNO3](DEBUG): Aggregate::initialize esp_kiss:Science:PeakDetectNO3
2019-08-22T19:38:06.970Z,1566502686.970 [esp_kiss:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2019-08-22T19:38:06.970Z,1566502686.970 [esp_kiss:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-08-22T19:38:06.972Z,1566502686.972 [esp_kiss:Science:PeakDetectOil] Running Loop=1
2019-08-22T19:38:06.972Z,1566502686.972 [esp_kiss:Science:PeakDetectOil](DEBUG): Aggregate::initialize esp_kiss:Science:PeakDetectOil
2019-08-22T19:38:06.972Z,1566502686.972 [esp_kiss:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2019-08-22T19:38:06.972Z,1566502686.972 [esp_kiss:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-08-22T19:38:06.974Z,1566502686.974 [esp_kiss:Science:PeakDetectFDOM] Running Loop=1
2019-08-22T19:38:06.974Z,1566502686.974 [esp_kiss:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize esp_kiss:Science:PeakDetectFDOM
2019-08-22T19:38:06.975Z,1566502686.975 [esp_kiss:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2019-08-22T19:38:06.975Z,1566502686.975 [esp_kiss:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-08-22T19:38:06.976Z,1566502686.976 [esp_kiss:C] Running Loop=1
2019-08-22T19:38:06.977Z,1566502686.977 [esp_kiss:Science] Running Loop=1
2019-08-22T19:38:06.978Z,1566502686.978 [esp_kiss:Science:PeakDetectFDOM] Stopped
2019-08-22T19:38:06.978Z,1566502686.978 [esp_kiss:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize esp_kiss:Science:PeakDetectFDOM
2019-08-22T19:38:06.978Z,1566502686.978 [esp_kiss:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2019-08-22T19:38:06.979Z,1566502686.979 [esp_kiss:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-08-22T19:38:06.979Z,1566502686.979 [esp_kiss:Science:PeakDetectOil] Stopped
2019-08-22T19:38:06.979Z,1566502686.979 [esp_kiss:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize esp_kiss:Science:PeakDetectOil
2019-08-22T19:38:06.979Z,1566502686.979 [esp_kiss:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2019-08-22T19:38:06.979Z,1566502686.979 [esp_kiss:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-08-22T19:38:06.979Z,1566502686.979 [esp_kiss:Science:PeakDetectNO3] Stopped
2019-08-22T19:38:06.979Z,1566502686.979 [esp_kiss:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize esp_kiss:Science:PeakDetectNO3
2019-08-22T19:38:06.979Z,1566502686.979 [esp_kiss:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2019-08-22T19:38:06.979Z,1566502686.979 [esp_kiss:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-08-22T19:38:06.979Z,1566502686.979 [esp_kiss:Science:HighestChlPeakReport] Stopped
2019-08-22T19:38:06.979Z,1566502686.979 [esp_kiss:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize esp_kiss:Science:HighestChlPeakReport
2019-08-22T19:38:06.979Z,1566502686.979 [esp_kiss:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2019-08-22T19:38:06.979Z,1566502686.979 [esp_kiss:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2019-08-22T19:38:06.980Z,1566502686.980 [esp_kiss:Science:PeakDetectChl] Stopped
2019-08-22T19:38:06.980Z,1566502686.980 [esp_kiss:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize esp_kiss:Science:PeakDetectChl
2019-08-22T19:38:06.980Z,1566502686.980 [esp_kiss:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2019-08-22T19:38:06.980Z,1566502686.980 [esp_kiss:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-08-22T19:38:06.980Z,1566502686.980 [esp_kiss:Science:Read_Oil] Stopped
2019-08-22T19:38:06.980Z,1566502686.980 [esp_kiss:Science:H] Stopped
2019-08-22T19:38:06.980Z,1566502686.980 [esp_kiss:Science:G] Running Loop=1
2019-08-22T19:38:06.981Z,1566502686.981 [esp_kiss:Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2019-08-22T19:38:06.981Z,1566502686.981 [esp_kiss:Science:F] Stopped
2019-08-22T19:38:06.981Z,1566502686.981 [esp_kiss:Science:E] Stopped
2019-08-22T19:38:06.981Z,1566502686.981 [esp_kiss:Science:D] Running Loop=1
2019-08-22T19:38:06.982Z,1566502686.982 [esp_kiss:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2019-08-22T19:38:06.982Z,1566502686.982 [esp_kiss:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2019-08-22T19:38:06.982Z,1566502686.982 [esp_kiss:Science:C] Running Loop=1
2019-08-22T19:38:06.983Z,1566502686.983 [esp_kiss:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2019-08-22T19:38:06.984Z,1566502686.984 [esp_kiss:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2019-08-22T19:38:06.984Z,1566502686.984 [esp_kiss:Science:B] Stopped
2019-08-22T19:38:06.984Z,1566502686.984 [esp_kiss:Science:A] Running Loop=1
2019-08-22T19:38:06.984Z,1566502686.984 [esp_kiss:Science:A](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_oxygen_in_sea_water
2019-08-22T19:38:06.985Z,1566502686.985 [esp_kiss:I] Running Loop=1
2019-08-22T19:38:06.985Z,1566502686.985 [esp_kiss:C] Stopped
2019-08-22T19:38:06.985Z,1566502686.985 [esp_kiss:D] Running Loop=1
2019-08-22T19:38:06.985Z,1566502686.985 [esp_kiss:StandardEnvelopes] Running Loop=1
2019-08-22T19:38:06.986Z,1566502686.986 [esp_kiss:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-08-22T19:38:06.986Z,1566502686.986 [esp_kiss:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-08-22T19:38:06.987Z,1566502686.987 [esp_kiss:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-08-22T19:38:06.987Z,1566502686.987 [esp_kiss:A.AbortSample] Running Loop=1
2019-08-22T19:38:07.114Z,1566502687.114 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-08-22T19:38:07.366Z,1566502687.366 [esp_kiss:D] Stopped
2019-08-22T19:38:07.366Z,1566502687.366 [esp_kiss:E] Running Loop=1
2019-08-22T19:38:07.414Z,1566502687.414 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2019-08-22T19:38:07.414Z,1566502687.414 [WetLabsBB2FL](INFO): Powering up
2019-08-22T19:38:07.760Z,1566502687.760 [esp_kiss:E] Stopped
2019-08-22T19:38:07.760Z,1566502687.760 [esp_kiss:G] Running Loop=1
2019-08-22T19:38:08.176Z,1566502688.176 [esp_kiss:G] Stopped
2019-08-22T19:38:08.176Z,1566502688.176 [esp_kiss:H] Running Loop=1
2019-08-22T19:38:08.574Z,1566502688.574 [esp_kiss:H] Stopped
2019-08-22T19:38:08.574Z,1566502688.574 [esp_kiss:StartingMission] Running Loop=1
2019-08-22T19:38:08.574Z,1566502688.574 [esp_kiss:StartingMission](DEBUG): Aggregate::initialize esp_kiss:StartingMission
2019-08-22T19:38:08.575Z,1566502688.575 [esp_kiss:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2019-08-22T19:38:08.987Z,1566502688.987 [esp_kiss:NeedComms] Running Loop=1
2019-08-22T19:38:08.987Z,1566502688.987 [esp_kiss:NeedComms](DEBUG): Aggregate::initialize esp_kiss:NeedComms
2019-08-22T19:38:08.987Z,1566502688.987 [esp_kiss:NeedComms:B.GoToSurface] Running Loop=1
2019-08-22T19:38:08.988Z,1566502688.988 [esp_kiss:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-22T19:38:08.988Z,1566502688.988 [esp_kiss:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2019-08-22T19:38:08.989Z,1566502688.989 [esp_kiss:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2019-08-22T19:38:08.989Z,1566502688.989 [esp_kiss:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2019-08-22T19:38:08.990Z,1566502688.990 [esp_kiss:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-22T19:38:08.990Z,1566502688.990 [esp_kiss:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-22T19:38:08.991Z,1566502688.991 [esp_kiss:NeedComms:A] Running Loop=1
2019-08-22T19:38:08.992Z,1566502688.992 [esp_kiss:NeedComms:A](INFO): last time_fix was: 1566502621.000000 second since 1970/01/01T00:00:00Z 
2019-08-22T19:38:08.992Z,1566502688.992 [esp_kiss:NeedComms:A] Stopped
2019-08-22T19:38:09.586Z,1566502689.586 [esp_kiss:NeedComms:C] Running Loop=1
2019-08-22T19:38:09.889Z,1566502689.889 [esp_kiss:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-08-22T19:38:10.126Z,1566502690.126 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2019-08-22T19:38:10.214Z,1566502690.214 [NAL9602](INFO): SBD MO Status=0, MOMSN=32565, MT Status=0, MTMSN=0
2019-08-22T19:38:11.453Z,1566502691.453 [NAL9602](DEBUG): Fix Requested
2019-08-22T19:38:11.841Z,1566502691.841 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193757.00,A,4147.62024,N,08308.00474,W,0.311,159.29,220819,,,A*77
2019-08-22T19:38:11.844Z,1566502691.844 [NAL9602](INFO): GPS fix at 20190822T193757: (41.793671, -83.133412)
2019-08-22T19:38:11.878Z,1566502691.878 [esp_kiss:NeedComms:C] Stopped
2019-08-22T19:38:11.878Z,1566502691.878 [esp_kiss:NeedComms:D] Running Loop=1
2019-08-22T19:38:12.336Z,1566502692.336 [esp_kiss:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-08-22T19:38:21.773Z,1566502701.773 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:38:25.553Z,1566502705.553 [NAL9602](INFO): SBD MO Status=1, MOMSN=32566, MT Status=0, MTMSN=0
2019-08-22T19:38:25.609Z,1566502705.609 [NAL9602](INFO): Sent 25 bytes from file Logs/20190822T180446/Courier0055.lzma
2019-08-22T19:38:25.609Z,1566502705.609 [NAL9602](INFO): Packets left to send: 0
2019-08-22T19:38:34.798Z,1566502714.798 [NAL9602](INFO): SBD MO Status=1, MOMSN=32567, MT Status=0, MTMSN=0
2019-08-22T19:38:34.853Z,1566502714.853 [NAL9602](INFO): Sent 63 bytes from file Logs/20190822T180446/Courier0058.lzma
2019-08-22T19:38:34.853Z,1566502714.853 [NAL9602](INFO): Packets left to send: 0
2019-08-22T19:38:50.060Z,1566502730.060 [NAL9602](INFO): SBD MO Status=2, MOMSN=32568, MT Status=2, MTMSN=0
2019-08-22T19:38:50.061Z,1566502730.061 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-22T19:38:52.483Z,1566502732.483 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:39:23.209Z,1566502763.209 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:39:24.304Z,1566502764.304 [NAL9602](INFO): SBD MO Status=1, MOMSN=32568, MT Status=0, MTMSN=0
2019-08-22T19:39:24.353Z,1566502764.353 [NAL9602](INFO): Sent 332 bytes from file Logs/20190822T180446/Express0056.lzma
2019-08-22T19:39:24.353Z,1566502764.353 [NAL9602](INFO): Packets left to send: 1
2019-08-22T19:39:42.361Z,1566502782.361 [NAL9602](INFO): SBD MO Status=1, MOMSN=32569, MT Status=0, MTMSN=0
2019-08-22T19:39:42.409Z,1566502782.409 [NAL9602](INFO): Sent 203 bytes from file Logs/20190822T180446/Express0056.lzma
2019-08-22T19:39:42.409Z,1566502782.409 [NAL9602](INFO): Packets left to send: 0
2019-08-22T19:39:53.913Z,1566502793.913 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:39:59.604Z,1566502799.604 [NAL9602](INFO): SBD MO Status=2, MOMSN=32570, MT Status=2, MTMSN=0
2019-08-22T19:39:59.604Z,1566502799.604 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-22T19:40:24.617Z,1566502824.617 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:40:27.573Z,1566502827.573 [NAL9602](INFO): SBD MO Status=2, MOMSN=32570, MT Status=2, MTMSN=0
2019-08-22T19:40:27.573Z,1566502827.573 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-22T19:40:49.289Z,1566502849.289 [NAL9602](INFO): SBD MO Status=1, MOMSN=32570, MT Status=0, MTMSN=0
2019-08-22T19:40:49.341Z,1566502849.341 [NAL9602](INFO): Sent 279 bytes from file Logs/20190822T180446/Express0059.lzma
2019-08-22T19:40:49.341Z,1566502849.341 [NAL9602](INFO): Packets left to send: 0
2019-08-22T19:40:55.329Z,1566502855.329 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-22T19:41:04.824Z,1566502864.824 [NAL9602](INFO): SBD MO Status=0, MOMSN=32571, MT Status=0, MTMSN=0
2019-08-22T19:41:04.945Z,1566502864.945 [esp_kiss:NeedComms:D] Stopped
2019-08-22T19:41:04.946Z,1566502864.946 [esp_kiss:NeedComms:E] Running Loop=1
2019-08-22T19:41:05.261Z,1566502865.261 [esp_kiss:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix