Updated by Carlos Rueda 2020-09-29

File snippet.markdown Modified

 ... **[ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=30.0000)**

+To speed up the test, you can run:

+```

+maintain sensor depth_keller.depth 1 cm

+```

 ## On bufflehead

 As soon as you see that line, launch the ESP simulator command indicated above (`ESPclient=tethyscode:9998 ESPcmdPort=7777 esp`). You should see interaction activity on both sides:

Updated by Carlos Rueda 2020-08-19

View revision

File snippet.markdown Modified

 ... **[ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=30.0000)**

-## on bufflehead

+## On bufflehead

 As soon as you see that line, launch the ESP simulator command indicated above (`ESPclient=tethyscode:9998 ESPcmdPort=7777 esp`). You should see interaction activity on both sides:

Updated by Carlos Rueda 2020-08-13

View revision

File snippet.markdown Modified

 ## On bufflehead

-Using [ESP master branch](https://github.com/MBARI-ESP/ESP2Gscript/) per Brent.

+Using [ESP master branch](https://github.com/MBARI-ESP/ESP2Gscript/) per Brent (2020-08-12).

 As usual I have the code under carueda's account on bufflehead:

 **Note**:

 - `archiveHiBiomass_bac` is the default ESP cartridge type code in the the mission used below, `Maintenance/sample.xml`

-- An "archive" type is very convenient for the test to complete quicker than with an "lyse-n-go"

+- An "archive" type is very convenient for the test as it will complete quicker than with an "lyse-n-go" type.

 ### Exit the ESP simulator for what follows

   $ ESPclient=tethyscode:9998 ESPcmdPort=7777 esp

```

-This prepares the subsequent execution of the ESP system once the socket server (see below)

-is running on the simulated vehicle.

+This prepares the subsequent execution of the ESP system once the socket server

+is running on the simulated vehicle (see below).

 ## On tethyscode:

 **Note**:

 - Port 9998 on tethyscode is where the ESPComponent will listen as a server and wait for the ESP to connect.

-  (This port was opened so it is accessible from bufflehead.)

+  (This port was opened (by IS, years ago) so it is accessible from bufflehead.)

 - Created the `ESPlogs` subdir for the rsync command above, as well as added my tethyscode ssh pub key

   to bufflehead's `authorized_keys` and the corresponding files under tethyscode's `~/.ssh/`

 Parameters that can be adjusted for testing convenience are, for example `Depth = 1`, `NumberOfSamples = 2`.

-We need to tell the ESPComponent that we are running the ESP manually, so we set the `ESPCOMPONENT_MANUAL_ESP` environment variable for this purpose:

+We need to tell the ESPComponent that we are running the ESP manually,

+so we set the `ESPCOMPONENT_MANUAL_ESP` environment variable for this purpose

+(so the vehicle skips operations like powering-up/down the ESP):

     [tethysadmin@tethyscode lrauv-application]$ ESPCOMPONENT_MANUAL_ESP=1 bin/LRAUV -r -x \

          "load Maintenance/sample.xml;set sample.NumberOfSamples 2 count;set sample.Depth 1 centimeter;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.TargetDepth 1 centimeter;run"

-Wait for the following line in the output (it may take a few minutes):

+Look out for a "Waiting for ESP to connect" line like the following in the output (it may take a few minutes):

-    ...

-    ... [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=30.0000)

+... **[ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=30.0000)**

 ## on bufflehead

-Right away launch the ESP simulator and you will see interaction activity on both sides:

+As soon as you see that line, launch the ESP simulator command indicated above (`ESPclient=tethyscode:9998 ESPcmdPort=7777 esp`). You should see interaction activity on both sides:

-**Note**: `exit` issued at the ESP prompt below once 1st sample is completed, to prepare and then (manually again) re-launch `esp` (same command) for the 2nd sample per the tethyscode output captured below.

+**Note**: `exit` manually issued at the ESP prompt below once 1st sample is completed, to prepare and then (manually again) re-launch `esp` (same command) for the 2nd sample according to the tethyscode output (captured below as well).

```

 carueda@bufflehead:~/esp2$ ESPclient=tethyscode:9998 ESPcmdPort=7777 esp

-@13:39:00.94PDT12-Aug-20 <simrapid> Simulated gateway v3.24 for core bus

+@16:56:01.50PDT12-Aug-20 <simrapid> Simulated gateway v3.24 for core bus

 Simulated secondary gateway v3.24 for cartridge bus

-@13:39:01.06

+@16:56:01.62

 Configuration for honu by brent@mbari.org 3/11/20

 /home/carueda/esp2/type/auv/honu/configure.rb

-@13:39:01.13 Polling Can every 2:00

+@16:56:01.69 Polling Can every 2:00

 Clients may connect on TCP port 7777

-@13:39:01.14 Connecting to tethyscode:9998

-@13:39:01.16 <LRAUV> Session Begun

-@13:39:03.56 -> showStatus

-@13:39:05.16 -> Cmd.loadCartridge -4

-Gate.power :main,:ON

+Connecting to tethyscode:9998

+@16:56:02.00 <LRAUV> Session Begun

+@16:56:04.40 -> showStatus

+@16:56:06.00 -> Cmd.loadCartridge -4

+@16:56:06.01 Gate.power :main,:ON

 Gate.power :analytic1,:ON

 Gate.power :analytic2,:ON

-@13:39:05.17 Gate.power :analytic3,:ON

+Gate.power :analytic3,:ON

 Gate.power :core,:ON

-@13:39:05.18 Archive.configure :default

-@13:39:05.19 Air.configure :default

-Lysis1.configure :default

-@13:39:05.20 Lysis2.configure :default

-Plunge.configure :default

-@13:39:05.21 SamplePump.configure :default

+@16:56:06.03 Archive.configure :default

+Air.configure :default

+@16:56:06.04 Lysis1.configure :default

+@16:56:06.05 Lysis2.configure :default

+@16:56:06.06 Plunge.configure :default

+@16:56:06.07 SamplePump.configure :default

 ExtraPump.configure :default

-@13:39:05.22 Toroid.configure :default

-Carousel.configure :default

-@13:39:05.23 Pressure.configure :default

-PinPort.configure :default

+@16:56:06.08 Toroid.configure :default

+@16:56:06.09 Carousel.configure :default

+Pressure.configure :default

+@16:56:06.10 PinPort.configure :default

 All elf controllers running firmware version 4.99

-@13:39:05.24 Gate.power :motor,:ON

-@13:39:05.25 <Archive_home> Archive.reconfigure :default

-@13:39:05.26 Archive.home.jog 0

+Gate.power :motor,:ON

+@16:56:06.11 <Archive_home> Archive.reconfigure :default

+@16:56:06.12 Archive.home.jog 0

 <Air_home> Air.reconfigure :default

-@13:39:05.27 Air.home.jog 0

-<Lysis1_home> Lysis1.reconfigure :default

-@13:39:05.28 <Lysis2_home> Lysis2.reconfigure :default

+@16:56:06.13 Air.home.jog 0

+@16:56:06.14 <Lysis1_home> Lysis1.reconfigure :default

+<Lysis2_home> Lysis2.reconfigure :default

 <Lysis1_home> Lysis1.home.jog 0

 <Plunge_home> Plunge.reconfigure :default

-<Lysis2_home> Lysis2.home.jog 0

-@13:39:05.29 <PinPort_home> PinPort.reconfigure :default

+@16:56:06.15 <Lysis2_home> Lysis2.home.jog 0

+<PinPort_home> PinPort.reconfigure :default

 <Plunge_home> Plunge.home.jog 0

-<Toroid_home> Toroid.reconfigure :default

-@13:39:05.30 <PinPort_home> PinPort.home.jog 0

+@16:56:06.16 <Toroid_home> Toroid.reconfigure :default

+<PinPort_home> PinPort.home.jog 0

 <Toroid_home> Toroid.home.jog 0

-@13:39:05.34 <Archive_home> Archive.setRawPosition! 50

+@16:56:06.20 <Archive_home> Archive.setRawPosition! 50

 Archive.reconfigure :homing

-@13:39:05.35 Archive.seek :home

-<Air_home> Air.setRawPosition! 50

+@16:56:06.21 Archive.seek :home

+@16:56:06.22 <Air_home> Air.setRawPosition! 50

 Air.reconfigure :homing

-@13:39:05.36 Air.seek :home

-@13:39:05.37 <Plunge_home> Plunge.setRawPosition! 50

+Air.seek :home

+@16:56:06.23 <Plunge_home> Plunge.setRawPosition! 50

 Plunge.reconfigure :homing

 Plunge.seek :home

-@13:39:05.38 <PinPort_home> PinPort.setRawPosition! 0

-PinPort.reconfigure :homing

-@13:39:05.39 PinPort.seek :home

-@13:39:05.40 <Lysis1_home> Lysis1.setRawPosition! 50

+@16:56:06.24 <PinPort_home> PinPort.setRawPosition! 0

+@16:56:06.25 PinPort.reconfigure :homing

+PinPort.seek :home

+@16:56:06.26 <Lysis1_home> Lysis1.setRawPosition! 50

 Lysis1.reconfigure :homing

 Lysis1.seek :home

-@13:39:05.41 <Lysis2_home> Lysis2.setRawPosition! 50

+@16:56:06.27 <Lysis2_home> Lysis2.setRawPosition! 50

 Lysis2.reconfigure :homing

-@13:39:05.42 Lysis2.seek :home

-@13:39:05.43 <Toroid_home> Toroid.setRawPosition! 0

+@16:56:06.28 Lysis2.seek :home

+@16:56:06.29 <Toroid_home> Toroid.setRawPosition! 0

 Toroid.reconfigure :homing

 Toroid.seek :home

-@13:39:05.46 <PinPort_home> PinPort.reconfigure :default

-@13:39:05.50 <Toroid_home> Toroid.reconfigure :default

-@13:39:05.62 <Archive_home> Archive.reconfigure :default

-@13:39:05.63 <Air_home> Air.reconfigure :default

-@13:39:05.65 <Plunge_home> Plunge.reconfigure :default

-@13:39:05.68 <Lysis1_home> Lysis1.reconfigure :default

-@13:39:05.69 <Lysis2_home> Lysis2.reconfigure :default

-@13:39:05.95 <LRAUV> Toroid.seek :clear

-@13:39:07.56 Carousel.reconfigure :default

-@13:39:07.57 Carousel.home.jog 0

-@13:39:07.64 Carousel.setRawPosition! -53

-Carousel.reconfigure :homing

+@16:56:06.32 <PinPort_home> PinPort.reconfigure :default

+@16:56:06.36 <Toroid_home> Toroid.reconfigure :default

+@16:56:06.48 <Archive_home> Archive.reconfigure :default

+@16:56:06.50 <Air_home> Air.reconfigure :default

+@16:56:06.51 <Plunge_home> Plunge.reconfigure :default

+@16:56:06.54 <Lysis1_home> Lysis1.reconfigure :default

+@16:56:06.55 <Lysis2_home> Lysis2.reconfigure :default

+@16:56:06.81 <LRAUV> Toroid.seek :clear

+@16:56:08.43 Carousel.reconfigure :default

+Carousel.home.jog 0

+@16:56:08.50 Carousel.setRawPosition! -53

+@16:56:08.51 Carousel.reconfigure :homing

 Carousel.seek :home

-@13:39:07.95 Carousel.reconfigure :default

-@13:39:08.20 Carousel.seek 1

-@13:39:08.27 Selecting Cartridge 58

-@13:39:08.28 Carousel.seek 58

-@13:39:20.13 Gate.power :heat,:OFF

-@13:39:20.14 Gate.power :cartridge,:OFF

-Lysis1.seek :locked

-@13:39:24.21 <Plunge> Plunge.seek :locked

-@13:39:24.22 <Air> Air.seek :locked

-@13:39:28.28 <LRAUV> Gate.power :cartridge,:ON

-@13:39:28.29 Gate.power :cartridge,:OFF

+@16:56:08.81 Carousel.reconfigure :default

+@16:56:09.07 Carousel.seek 1

+@16:56:09.14 Selecting Cartridge 56

+@16:56:09.15 Carousel.seek 56

+@16:56:20.59 Gate.power :heat,:OFF

 Gate.power :cartridge,:OFF

-@13:39:28.79 Mounted archive Cartridge

-@13:39:41.97 -> Cmd.startFiltering

-@13:39:41.98 <FILTERING> Duration of filtering limited to 2:05:00

-@13:39:41.99 Priming sample loop w/5ml, bypass w/1.5ml

+@16:56:20.60 Lysis1.seek :locked

+@16:56:24.67 <Plunge> Plunge.seek :locked

+<Air> Air.seek :locked

+@16:56:28.74 <LRAUV> Gate.power :cartridge,:ON

+Gate.power :cartridge,:OFF

+Gate.power :cartridge,:OFF

+@16:56:29.25 Mounted archive Cartridge

+@16:56:42.81 -> Cmd.startFiltering

+@16:56:42.82 <FILTERING> Duration of filtering limited to 2:05:00

+@16:56:42.83 Priming sample loop w/5ml, bypass w/1.5ml

 SamplePump.setPosition! 0ml

 Bypass.open

-@13:39:42.70 Intake.open

-@13:39:44.20 Sea 5.7m deep (23.1psia)

+@16:56:43.54 Intake.open

+@16:56:45.04 Sea 5.7m deep (23.1psia)

 Waiting up to 20 seconds for sea pressure to stabilize +/-0.50psi

-@13:39:46.72 Vacuum tare is 10% of full scale

+@16:56:47.56 Vacuum tare is 10% of full scale

 Pressure.reconfigure :default

-@13:39:46.73 Pressure.hold

-@13:39:46.81 SamplePump.reconfigure :prime

+Pressure.hold

+@16:56:47.64 SamplePump.reconfigure :prime

 SamplePump.seek 1.5ml,38 seconds

-@13:39:48.58 Pressure.coast

+@16:56:49.41 Pressure.coast

 SamplePump.setPosition! 0ml

 Exhaust.open

-@13:39:50.78 <closeBypass> Bypass.close

-@13:39:52.99 <FILTERING> Pressure.hold

-@13:39:53.06 Sea 5.7m deep (23.1psia)

+@16:56:51.61 <closeBypass> Bypass.close

+@16:56:53.82 <FILTERING> Pressure.hold

+@16:56:53.89 Sea 5.7m deep (23.1psia)

 SamplePump.reconfigure :prime

-@13:39:53.07 SamplePump.seek 5ml,56 seconds

-@13:39:57.80 Pressure.coast

+SamplePump.seek 5ml,56 seconds

+@16:56:58.63 Pressure.coast

 Bypass.open

-@13:39:59.30 Intake.close

-@13:40:00.80 Toroid.reconfigure :hold

+@16:57:00.13 Intake.close

+@16:57:01.63 Toroid.reconfigure :hold

 Toroid.seek :crack

-@13:40:01.60 Toroid.reconfigure :default

+@16:57:02.43 Toroid.reconfigure :default

 Toroid.seek :clear

-@13:40:03.11 Toroid.reconfigure :hold

+@16:57:03.93 Toroid.reconfigure :hold

 Toroid.seek :cartridge

-@13:40:04.92 Toroid.reconfigure :default

+@16:57:05.75 Toroid.reconfigure :default

 Toroid.seek :clear

-@13:40:06.75 Pressurizing cartridge to 26psi above 23.1psia

+@16:57:07.57 Pressurizing cartridge to 26psi above 23.1psia

 SamplePump.setPosition! 0ml

 Intake.open

-@13:40:08.24 Bypass.close

-@13:40:09.74 Exhaust.close

-@13:40:11.24 Pressure.hold

-@13:40:11.35 SamplePump.reconfigure :charge

+@16:57:09.06 Bypass.close

+@16:57:10.60 Exhaust.close

+@16:57:12.07 Pressure.hold

+@16:57:12.14 SamplePump.reconfigure :charge

 SamplePump.seek 0.2ml,32 seconds

-@13:40:11.96 Pressure.coast

+@16:57:12.75 Pressure.coast

 Sampling 10.0ml

 SamplePump.setPosition! 0ml

-@13:40:11.97 Exhaust.open

-@13:40:13.46 Pressure.hold

-@13:40:13.54 Sea 5.7m deep (23.1psia)

-SamplePump.reconfigure :sample

+Exhaust.open

+@16:57:14.25 Pressure.hold

+@16:57:14.32 Sea 5.7m deep (23.1psia)

+@16:57:14.33 SamplePump.reconfigure :sample

 SamplePump.seek 10ml,1:21

-@13:40:16.47 <sampling> Cartridge 58 sampling 2/10ml at 0.83ml/s with 0.0psi vacuum 5.7m deep (23.1psia)

-@13:40:26.51 <FILTERING> Pressure.coast

-<closeIntake> Intake.close

+@16:57:17.25 <sampling> Cartridge 56 sampling 2/10ml at 0.83ml/s with 0.0psi vacuum 5.7m deep (23.1psia)

+@16:57:27.29 <FILTERING> Pressure.coast

+@16:57:27.30 <closeIntake> Intake.close

 <closeExhaust> Exhaust.close

-@13:40:26.52 <FILTERING> Toroid.reconfigure :hold

+@16:57:27.31 <FILTERING> Toroid.reconfigure :hold

 Toroid.seek :bypass

-@13:40:28.14 Toroid.reconfigure :default

-Toroid.seek :clear

-@13:40:29.75 Sampled  10.0ml

-@13:40:31.18 <LRAUV> -> Cmd.startProcessing

-@13:40:31.19 <PROCESSING> Plunge.seek :reagent

-@13:40:32.03 Sample loop closed. Ready to Deliver Reagents

+@16:57:28.92 Toroid.reconfigure :default

+@16:57:28.93 Toroid.seek :clear

+@16:57:30.54 Sampled  10.0ml

+@16:57:32.02 <LRAUV> -> Cmd.startProcessing

+@16:57:32.03 <PROCESSING> Plunge.seek :reagent

+@16:57:32.87 Sample loop closed. Ready to Deliver Reagents

 Archive.seek :sealed

-@13:40:36.30 Archive.seek :evac

-@13:40:50.28 delay 1:00

-@13:41:50.29 Archive.seek :clear

-@13:42:08.05 RNAlater soak for 45 seconds

-@13:42:53.06 Archive.seek :tVent

-@13:42:55.64 delay 1 second

-@13:42:56.64 Archive.seek :evac

-@13:43:12.31 delay 10 seconds

-@13:43:22.32 Archive.seek :tVent

-@13:43:37.99 delay 1 second

-@13:43:38.99 Archive.seek :evac

-@13:43:54.66 delay 10 seconds

-@13:44:04.66 Sample preserved and evacuated

-@13:44:05.63 <LRAUV> -> Cmd.stop

-@13:44:05.64 Gate.power :heat,:OFF

-Gate.power :cartridge,:OFF

-Carousel.seek 58

-@13:44:05.72 Plunge.seek :locked

-@13:44:06.55 PinPort.seek :clear

-@13:44:06.62 <Archive> Archive.seek :clear

-@13:44:06.63 <Air> Air.seek :clear

-@13:44:06.65 <Lysis1> Lysis1.seek :clear

-@13:44:24.39 <LRAUV> Archive.coast

+@16:57:37.14 Archive.seek :evac

+@16:57:51.12 delay 1:00

+@16:58:51.13 Archive.seek :clear

+@16:59:08.89 RNAlater soak for 45 seconds

+@16:59:53.90 Archive.seek :tVent

+@16:59:56.48 delay 1 second

+@16:59:57.48 Archive.seek :evac

+@17:00:13.14 delay 10 seconds

+@17:00:23.15 Archive.seek :tVent

+@17:00:38.82 delay 1 second

+@17:00:39.82 Archive.seek :evac

+@17:00:55.49 delay 10 seconds

+@17:01:05.50 Sample preserved and evacuated

+@17:01:06.47 <LRAUV> -> Cmd.stop

+Gate.power :heat,:OFF

+@17:01:06.48 Gate.power :cartridge,:OFF

+Carousel.seek 56

+@17:01:06.55 Plunge.seek :locked

+@17:01:07.39 PinPort.seek :clear

+@17:01:07.46 <Archive> Archive.seek :clear

+<Air> Air.seek :clear

+@17:01:07.48 <Lysis1> Lysis1.seek :clear

+@17:01:25.23 <LRAUV> Archive.coast

 Air.coast

-@13:44:24.40 Lysis1.coast

+Lysis1.coast

 Lysis2.coast

-Plunge.coast

+@17:01:25.24 Plunge.coast

 SamplePump.coast

 Toroid.coast

-@13:44:24.41 Carousel.coast

+Carousel.coast

 PinPort.coast

-@13:44:24.42 Gate.power :heat,:OFF

-@13:44:24.43 Gate.power :cartridge,:OFF

-@13:44:24.48 Gate.power :motor,:OFF

+@17:01:25.26 Gate.power :heat,:OFF

+Gate.power :cartridge,:OFF

+@17:01:25.31 Gate.power :motor,:OFF

 Gate.power :core,:OFF

 Gate.power :analytic1,:OFF

-Gate.power :analytic2,:OFF

+@17:01:25.32 Gate.power :analytic2,:OFF

 Gate.power :analytic3,:OFF

-@13:44:24.49 Gate.power :main,:OFF

+Gate.power :main,:OFF

 Safely stopped and ready to power off

-@13:49:33.31 Session Ended

-@13:49:52.00 <simrapid> -> exit

+@17:01:44.48 Session Ended

+@17:01:54.27 <simrapid> -> exit

+carueda@bufflehead:~/esp2$

+carueda@bufflehead:~/esp2$

 carueda@bufflehead:~/esp2$ ESPclient=tethyscode:9998 ESPcmdPort=7777 esp

-@13:59:19.17PDT12-Aug-20 <simrapid> Simulated gateway v3.24 for core bus

+@17:11:29.31PDT12-Aug-20 <simrapid> Simulated gateway v3.24 for core bus

 Simulated secondary gateway v3.24 for cartridge bus

-@13:59:19.29

+@17:11:29.43

 Configuration for honu by brent@mbari.org 3/11/20

 /home/carueda/esp2/type/auv/honu/configure.rb

-@13:59:19.36 Polling Can every 2:00

-@13:59:19.37 Clients may connect on TCP port 7777

+@17:11:29.51 Polling Can every 2:00

+Clients may connect on TCP port 7777

 Connecting to tethyscode:9998

-@13:59:19.49 <LRAUV> Session Begun

-@13:59:21.49 -> showStatus

-@13:59:23.49 -> Cmd.loadCartridge -4

-Gate.power :main,:ON

+@17:11:29.83 <LRAUV> Session Begun

+@17:11:31.82 -> showStatus

+@17:11:33.82 -> Cmd.loadCartridge -4

+@17:11:33.83 Gate.power :main,:ON

 Gate.power :analytic1,:ON

 Gate.power :analytic2,:ON

 Gate.power :analytic3,:ON

-Gate.power :core,:ON

-@13:59:23.50 Archive.configure :default

-@13:59:23.51 Air.configure :default

-Lysis1.configure :default

-@13:59:23.52 Lysis2.configure :default

-Plunge.configure :default

-@13:59:23.53 SamplePump.configure :default

+@17:11:33.84 Gate.power :core,:ON

+@17:11:33.85 Archive.configure :default

+Air.configure :default

+@17:11:33.86 Lysis1.configure :default

+@17:11:33.87 Lysis2.configure :default

+@17:11:33.88 Plunge.configure :default

+@17:11:33.89 SamplePump.configure :default

 ExtraPump.configure :default

-@13:59:23.54 Toroid.configure :default

-Carousel.configure :default

-@13:59:23.55 Pressure.configure :default

-PinPort.configure :default

-@13:59:23.56 All elf controllers running firmware version 4.99

+@17:11:33.90 Toroid.configure :default

+@17:11:33.91 Carousel.configure :default

+@17:11:33.92 Pressure.configure :default

+@17:11:33.93 PinPort.configure :default

+All elf controllers running firmware version 4.99

 Gate.power :motor,:ON

-@13:59:23.57 <Archive_home> Archive.reconfigure :default

-@13:59:23.58 Archive.home.jog 0

+@17:11:33.94 <Archive_home> Archive.reconfigure :default

+@17:11:33.95 Archive.home.jog 0

 <Air_home> Air.reconfigure :default

-@13:59:23.59 Air.home.jog 0

+@17:11:33.96 Air.home.jog 0

 <Lysis1_home> Lysis1.reconfigure :default

-@13:59:23.60 <Lysis2_home> Lysis2.reconfigure :default

+@17:11:33.97 <Lysis2_home> Lysis2.reconfigure :default

 <Lysis1_home> Lysis1.home.jog 0

-<Lysis2_home> Lysis2.home.jog 0

-@13:59:23.61 <Plunge_home> Plunge.reconfigure :default

-<PinPort_home> PinPort.reconfigure :default

+<Plunge_home> Plunge.reconfigure :default

+@17:11:33.98 <Lysis2_home> Lysis2.home.jog 0

 <Plunge_home> Plunge.home.jog 0

-<Toroid_home> Toroid.reconfigure :default

-@13:59:23.62 <PinPort_home> PinPort.home.jog 0

+<PinPort_home> PinPort.reconfigure :default

+@17:11:33.99 <Toroid_home> Toroid.reconfigure :default

+<PinPort_home> PinPort.home.jog 0

 <Toroid_home> Toroid.home.jog 0

-@13:59:23.66 <Archive_home> Archive.setRawPosition! 50

+@17:11:34.03 <Archive_home> Archive.setRawPosition! 50

 Archive.reconfigure :homing

-@13:59:23.67 Archive.seek :home

-<Air_home> Air.setRawPosition! 50

-@13:59:23.68 Air.reconfigure :homing

+@17:11:34.04 Archive.seek :home

+@17:11:34.05 <Air_home> Air.setRawPosition! 50

+Air.reconfigure :homing

 Air.seek :home

-@13:59:23.69 <Plunge_home> Plunge.setRawPosition! 50

+@17:11:34.06 <Plunge_home> Plunge.setRawPosition! 50

 Plunge.reconfigure :homing

-@13:59:23.70 Plunge.seek :home

-<PinPort_home> PinPort.setRawPosition! 0

-@13:59:23.71 PinPort.reconfigure :homing

+Plunge.seek :home

+@17:11:34.07 <PinPort_home> PinPort.setRawPosition! 0

+@17:11:34.08 PinPort.reconfigure :homing

 PinPort.seek :home

-@13:59:23.72 <Lysis1_home> Lysis1.setRawPosition! 50

+@17:11:34.09 <Lysis1_home> Lysis1.setRawPosition! 50

 Lysis1.reconfigure :homing

-@13:59:23.73 Lysis1.seek :home

-@13:59:23.74 <Lysis2_home> Lysis2.setRawPosition! 50

+Lysis1.seek :home

+@17:11:34.11 <Lysis2_home> Lysis2.setRawPosition! 50

 Lysis2.reconfigure :homing

 Lysis2.seek :home

-@13:59:23.75 <Toroid_home> Toroid.setRawPosition! 0

+@17:11:34.12 <Toroid_home> Toroid.setRawPosition! 0

 Toroid.reconfigure :homing

-@13:59:23.76 Toroid.seek :home

-@13:59:23.78 <PinPort_home> PinPort.reconfigure :default

-@13:59:23.83 <Toroid_home> Toroid.reconfigure :default

-@13:59:23.94 <Archive_home> Archive.reconfigure :default

-@13:59:23.96 <Air_home> Air.reconfigure :default

-@13:59:23.97 <Plunge_home> Plunge.reconfigure :default

-@13:59:24.00 <Lysis1_home> Lysis1.reconfigure :default

-@13:59:24.02 <Lysis2_home> Lysis2.reconfigure :default

-@13:59:24.27 <LRAUV> Toroid.seek :clear

-@13:59:25.89 Carousel.reconfigure :default

+Toroid.seek :home

+@17:11:34.15 <PinPort_home> PinPort.reconfigure :default

+@17:11:34.20 <Toroid_home> Toroid.reconfigure :default

+@17:11:34.31 <Archive_home> Archive.reconfigure :default

+@17:11:34.33 <Air_home> Air.reconfigure :default

+@17:11:34.34 <Plunge_home> Plunge.reconfigure :default

+@17:11:34.37 <Lysis1_home> Lysis1.reconfigure :default

+@17:11:34.39 <Lysis2_home> Lysis2.reconfigure :default

+@17:11:34.64 <LRAUV> Toroid.seek :clear

+@17:11:36.26 Carousel.reconfigure :default

 Carousel.home.jog 0

-@13:59:25.97 Carousel.setRawPosition! -53

+@17:11:36.33 Carousel.setRawPosition! -53

 Carousel.reconfigure :homing

-Carousel.seek :home

-@13:59:26.27 Carousel.reconfigure :default

-@13:59:26.53 Carousel.seek 1

-@13:59:26.60 Selecting Cartridge 57

-@13:59:26.61 Carousel.seek 57

-@13:59:38.25 Gate.power :heat,:OFF

+@17:11:36.34 Carousel.seek :home

+@17:11:36.64 Carousel.reconfigure :default

+@17:11:36.89 Carousel.seek 1

+@17:11:36.97 Selecting Cartridge 55

+@17:11:36.98 Carousel.seek 55

+@17:11:48.21 Gate.power :heat,:OFF

 Gate.power :cartridge,:OFF

-@13:59:38.26 Lysis1.seek :locked

-@13:59:42.33 <Plunge> Plunge.seek :locked

+@17:11:48.22 Lysis1.seek :locked

+@17:11:52.29 <Plunge> Plunge.seek :locked

 <Air> Air.seek :locked

-@13:59:46.40 <LRAUV> Gate.power :cartridge,:ON

+@17:11:56.36 <LRAUV> Gate.power :cartridge,:ON

 Gate.power :cartridge,:OFF

 Gate.power :cartridge,:OFF

-@13:59:46.90 Mounted archive Cartridge

-@14:00:00.30 -> Cmd.startFiltering

-@14:00:00.31 <FILTERING> Duration of filtering limited to 2:05:00

-@14:00:00.32 Priming sample loop w/5ml, bypass w/1.5ml

+@17:11:56.86 Mounted archive Cartridge

+@17:12:10.63 -> Cmd.startFiltering

+@17:12:10.64 <FILTERING> Duration of filtering limited to 2:05:00

+@17:12:10.65 Priming sample loop w/5ml, bypass w/1.5ml

 SamplePump.setPosition! 0ml

 Bypass.open

-@14:00:01.03 Intake.open

-@14:00:02.53 Sea 5.7m deep (23.1psia)

+@17:12:11.36 Intake.open

+@17:12:12.86 Sea 5.7m deep (23.1psia)

 Waiting up to 20 seconds for sea pressure to stabilize +/-0.50psi

-@14:00:05.05 Vacuum tare is 10% of full scale

-@14:00:05.06 Pressure.reconfigure :default

+@17:12:15.38 Vacuum tare is 10% of full scale

+@17:12:15.39 Pressure.reconfigure :default

 Pressure.hold

-@14:00:05.14 SamplePump.reconfigure :prime

+@17:12:15.46 SamplePump.reconfigure :prime

 SamplePump.seek 1.5ml,38 seconds

-@14:00:06.91 Pressure.coast

+@17:12:17.23 Pressure.coast

 SamplePump.setPosition! 0ml

-@14:00:06.92 Exhaust.open

-@14:00:09.11 <closeBypass> Bypass.close

-@14:00:11.32 <FILTERING> Pressure.hold

-@14:00:11.39 Sea 5.7m deep (23.1psia)

-@14:00:11.40 SamplePump.reconfigure :prime

+@17:12:17.24 Exhaust.open

+@17:12:19.43 <closeBypass> Bypass.close

+@17:12:21.64 <FILTERING> Pressure.hold

+@17:12:21.71 Sea 5.7m deep (23.1psia)

+@17:12:21.72 SamplePump.reconfigure :prime

 SamplePump.seek 5ml,56 seconds

-@14:00:16.14 Pressure.coast

+@17:12:26.45 Pressure.coast

 Bypass.open

-@14:00:17.63 Intake.close

-@14:00:19.14 Toroid.reconfigure :hold

+@17:12:27.95 Intake.close

+@17:12:29.45 Toroid.reconfigure :hold

 Toroid.seek :crack

-@14:00:19.94 Toroid.reconfigure :default

+@17:12:30.25 Toroid.reconfigure :default

 Toroid.seek :clear

-@14:00:21.44 Toroid.reconfigure :hold

+@17:12:31.76 Toroid.reconfigure :hold

 Toroid.seek :cartridge

-@14:00:23.26 Toroid.reconfigure :default

+@17:12:33.57 Toroid.reconfigure :default

 Toroid.seek :clear

-@14:00:25.08 Pressurizing cartridge to 26psi above 23.1psia

+@17:12:35.39 Pressurizing cartridge to 26psi above 23.1psia

 SamplePump.setPosition! 0ml

-Intake.open

-@14:00:26.57 Bypass.close

-@14:00:28.07 Exhaust.close

-@14:00:29.62 Pressure.hold

-@14:00:29.69 SamplePump.reconfigure :charge

+@17:12:35.40 Intake.open

+@17:12:36.89 Bypass.close

+@17:12:38.39 Exhaust.close

+@17:12:39.89 Pressure.hold

+@17:12:39.97 SamplePump.reconfigure :charge

 SamplePump.seek 0.2ml,32 seconds

-@14:00:30.29 Pressure.coast

-@14:00:30.30 Sampling 10.0ml

+@17:12:40.57 Pressure.coast

+@17:12:40.58 Sampling 10.0ml

 SamplePump.setPosition! 0ml

 Exhaust.open

-@14:00:31.80 Pressure.hold

-@14:00:31.88 Sea 5.7m deep (23.1psia)

+@17:12:42.08 Pressure.hold

+@17:12:42.15 Sea 5.7m deep (23.1psia)

 SamplePump.reconfigure :sample

-@14:00:31.89 SamplePump.seek 10ml,1:21

-@14:00:34.81 <sampling> Cartridge 57 sampling 2/10ml at 0.83ml/s with 0.0psi vacuum 5.7m deep (23.1psia)

-@14:00:44.85 <FILTERING> Pressure.coast

+@17:12:42.16 SamplePump.seek 10ml,1:21

+@17:12:45.08 <sampling> Cartridge 55 sampling 2/10ml at 0.83ml/s with 0.0psi vacuum 5.7m deep (23.1psia)

+@17:12:55.12 <FILTERING> Pressure.coast

 <closeIntake> Intake.close

-@14:00:44.86 <closeExhaust> Exhaust.close

+@17:12:55.13 <closeExhaust> Exhaust.close

 <FILTERING> Toroid.reconfigure :hold

 Toroid.seek :bypass

-@14:00:46.48 Toroid.reconfigure :default

+@17:12:56.75 Toroid.reconfigure :default

 Toroid.seek :clear

-@14:00:48.10 Sampled  10.0ml

-@14:00:49.51 <LRAUV> -> Cmd.startProcessing

-@14:00:49.53 <PROCESSING> Plunge.seek :reagent

-@14:00:50.37 Sample loop closed. Ready to Deliver Reagents

+@17:12:58.37 Sampled  10.0ml

+@17:12:59.84 <LRAUV> -> Cmd.startProcessing

+@17:12:59.86 <PROCESSING> Plunge.seek :reagent

+@17:13:00.69 Sample loop closed. Ready to Deliver Reagents

 Archive.seek :sealed

-@14:00:54.64 Archive.seek :evac

-@14:01:08.61 delay 1:00

-@14:02:08.62 Archive.seek :clear

-@14:02:26.39 RNAlater soak for 45 seconds

-@14:03:11.40 Archive.seek :tVent

-@14:03:13.98 delay 1 second

-@14:03:14.98 Archive.seek :evac

-@14:03:30.65 delay 10 seconds

-@14:03:40.65 Archive.seek :tVent

-@14:03:56.32 delay 1 second

-@14:03:57.32 Archive.seek :evac

-@14:04:12.99 delay 10 seconds

-@14:04:23.00 Sample preserved and evacuated

-@14:04:23.96 <LRAUV> -> Cmd.stop

+@17:13:04.96 Archive.seek :evac

+@17:13:18.94 delay 1:00

+@17:14:18.95 Archive.seek :clear

+@17:14:36.72 RNAlater soak for 45 seconds

+@17:15:21.72 Archive.seek :tVent

+@17:15:24.30 delay 1 second

+@17:15:25.31 Archive.seek :evac

+@17:15:40.97 delay 10 seconds

+@17:15:50.98 Archive.seek :tVent

+@17:16:06.65 delay 1 second

+@17:16:07.65 Archive.seek :evac

+@17:16:23.32 delay 10 seconds

+@17:16:33.33 Sample preserved and evacuated

+@17:16:34.29 <LRAUV> -> Cmd.stop

 Gate.power :heat,:OFF

 Gate.power :cartridge,:OFF

-Carousel.seek 57

-@14:04:24.04 Plunge.seek :locked

-@14:04:24.87 PinPort.seek :clear

-@14:04:24.95 <Archive> Archive.seek :clear

-@14:04:24.96 <Air> Air.seek :clear

-@14:04:24.98 <Lysis1> Lysis1.seek :clear

-@14:04:42.72 <LRAUV> Archive.coast

+@17:16:34.30 Carousel.seek 55

+@17:16:34.38 Plunge.seek :locked

+@17:16:35.21 PinPort.seek :clear

+@17:16:35.29 <Archive> Archive.seek :clear

+<Air> Air.seek :clear

+@17:16:35.31 <Lysis1> Lysis1.seek :clear

+@17:16:53.06 <LRAUV> Archive.coast

 Air.coast

-@14:04:42.73 Lysis1.coast

+Lysis1.coast

 Lysis2.coast

 Plunge.coast

 SamplePump.coast

-Toroid.coast

-@14:04:42.74 Carousel.coast

+@17:16:53.07 Toroid.coast

+Carousel.coast

 PinPort.coast

-@14:04:42.75 Gate.power :heat,:OFF

-@14:04:42.76 Gate.power :cartridge,:OFF

-@14:04:42.81 Gate.power :motor,:OFF

+@17:16:53.09 Gate.power :heat,:OFF

+Gate.power :cartridge,:OFF

+@17:16:53.14 Gate.power :motor,:OFF

 Gate.power :core,:OFF

 Gate.power :analytic1,:OFF

 Gate.power :analytic2,:OFF

-Gate.power :analytic3,:OFF

-@14:04:42.82 Gate.power :main,:OFF

+@17:16:53.15 Gate.power :analytic3,:OFF

+Gate.power :main,:OFF

 Safely stopped and ready to power off

-@14:09:51.63 Session Ended

-@14:24:48.05 <simrapid> -> exit

+@17:17:12.29 Session Ended

+@17:18:29.49 <simrapid> -> exit

```

 ## On tethyscode:

```

-...

-[tethysadmin@tethyscode lrauv-application]$ ESPCOMPONENT_MANUAL_ESP=1 bin/LRAUV -r -x    "load Maintenance/sample.xml;set sample.NumberOfSamples 2 count;set sample.Depth 1 centimeter;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.TargetDepth 1 centimeter;run"

+tethysadmin@tethyscode: lrauv-application-carlos$ ESPCOMPONENT_MANUAL_ESP=1 bin/LRAUV -r -x      "load Maintenance/sample.xml;set sample.NumberOfSamples 2 count;set sample.Depth 1 centimeter;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.TargetDepth 1 centimeter;run"

 Writer for level Courier will be LZMA encoded.

 Writer for level Express will be LZMA encoded.

 Writer for level Priority will not be LZMA encoded.

 Writer for level Normal will not be LZMA encoded.

-2020-08-12T20:34:22.848Z,1597264462.848 [SyncHandler](INFO): Protected caller Thread ID is 106985

-2020-08-12T20:34:22.848Z,1597264462.848 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 106986

-2020-08-12T20:34:22.848Z,1597264462.848 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 106987

-2020-08-12T20:34:22.848Z,1597264462.848 [logger ThreadHandler](INFO): Protected caller Thread ID is 106988

-2020-08-12T20:34:22.848Z,1597264462.848 [Supervisor](INFO): Looking for Config files in directory: Config/

-2020-08-12T20:34:22.849Z,1597264462.849 [Supervisor](INFO): Opening Config file at: Config/secure.cfg

-2020-08-12T20:34:22.853Z,1597264462.853 [Supervisor](INFO): Opening Config file at: Config/Science.cfg

-2020-08-12T20:34:22.858Z,1597264462.858 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg

-2020-08-12T20:34:22.864Z,1597264462.864 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg

-tethyscode>2020-08-12T20:34:22.869Z,1597264462.869 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg

-2020-08-12T20:34:22.873Z,1597264462.873 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg

-2020-08-12T20:34:22.876Z,1597264462.876 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg

-2020-08-12T20:34:22.880Z,1597264462.880 [Supervisor](INFO): Opening Config file at: Config/Control.cfg

-2020-08-12T20:34:22.884Z,1597264462.884 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg

-2020-08-12T20:34:22.887Z,1597264462.887 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg

-2020-08-12T20:34:22.890Z,1597264462.890 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg

-2020-08-12T20:34:22.894Z,1597264462.894 [Supervisor](INFO): Opening Config file at: Config/logger.cfg

-2020-08-12T20:34:22.898Z,1597264462.898 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg

-2020-08-12T20:34:22.901Z,1597264462.901 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg

-2020-08-12T20:34:22.904Z,1597264462.904 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg

-2020-08-12T20:34:22.911Z,1597264462.911 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg

-2020-08-12T20:34:22.915Z,1597264462.915 [Supervisor](INFO): Looking for Config files in directory: Config/tethyscode/

-2020-08-12T20:34:22.915Z,1597264462.915 [Supervisor](INFO): Looking for Config files in directory: Config/tethyscode/tethysadmin/

-2020-08-12T20:34:22.915Z,1597264462.915 [Supervisor](INFO): Looking for Config files in directory: Config/sim/

-2020-08-12T20:34:22.915Z,1597264462.915 [Supervisor](INFO): Opening Config file at: Config/sim/secure.cfg

-2020-08-12T20:34:22.918Z,1597264462.918 [Supervisor](INFO): Opening Config file at: Config/sim/Science.cfg

-2020-08-12T20:34:22.921Z,1597264462.921 [Supervisor](INFO): Opening Config file at: Config/sim/Simulator.cfg

-2020-08-12T20:34:22.923Z,1597264462.923 [Supervisor](INFO): Opening Config file at: Config/sim/vehicle.cfg

-2020-08-12T20:34:22.926Z,1597264462.926 [Supervisor](INFO): Opening Config file at: Config/sim/Servo.cfg

-2020-08-12T20:34:22.929Z,1597264462.929 [Supervisor](INFO): Opening Config file at: Config/sim/Sensor.cfg

-2020-08-12T20:34:22.932Z,1597264462.932 [Supervisor](INFO): Opening Config file at: Config/sim/Derivation.cfg

-2020-08-12T20:34:22.935Z,1597264462.935 [Supervisor](INFO): Looking for Config files in directory: Config/sim/tethysadmin/

-2020-08-12T20:34:22.935Z,1597264462.935 [Supervisor](INFO): Opening Config file at: Config/sim/tethysadmin/secure.cfg

-2020-08-12T20:34:22.937Z,1597264462.937 [Supervisor](INFO): Opening Config file at: Config/sim/tethysadmin/Science.cfg

-2020-08-12T20:34:22.938Z,1597264462.938 [Config/Science](ERROR): Could not parse value: The

-2020-08-12T20:34:22.940Z,1597264462.940 [Supervisor](INFO): Opening Config file at: Config/sim/tethysadmin/vehicle.cfg

-2020-08-12T20:34:22.943Z,1597264462.943 [Supervisor](INFO): Opening Config file at: Config/sim/tethysadmin/Sensor.cfg

-2020-08-12T20:34:22.946Z,1597264462.946 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg

-2020-08-12T20:34:22.951Z,1597264462.951 [ESPComponent](ERROR): Could not open device '/dev/loadA6' at ESPComponent.loadControl

-2020-08-12T20:34:22.971Z,1597264462.971 [ESPComponent](ERROR): Could not open device '/dev/loadA7' at ESPComponent.loadControl2

-2020-08-12T20:34:22.992Z,1597264462.992 [ESPComponent](IMPORTANT): ESPCOMPONENT_MANUAL_ESP INDICATED.

-2020-08-12T20:34:22.994Z,1597264462.994 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water

-2020-08-12T20:34:22.995Z,1597264462.995 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 107070

-2020-08-12T20:34:23.008Z,1597264463.008 [AHRS_M2](INFO): created writer for : platform_orientation

-2020-08-12T20:34:23.008Z,1597264463.008 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation

-2020-08-12T20:34:23.008Z,1597264463.008 [AHRS_M2](INFO): created writer for : platform_pitch_angle

-2020-08-12T20:34:23.008Z,1597264463.008 [AHRS_M2](INFO): created writer for : platform_roll_angle

-2020-08-12T20:34:23.010Z,1597264463.010 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 107071

-2020-08-12T20:34:23.011Z,1597264463.011 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/voltage_now

-2020-08-12T20:34:23.011Z,1597264463.011 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/current_now

-2020-08-12T20:34:23.011Z,1597264463.011 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_now

-2020-08-12T20:34:23.011Z,1597264463.011 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_full

-2020-08-12T20:34:23.011Z,1597264463.011 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/voltage_now

-2020-08-12T20:34:23.011Z,1597264463.011 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/current_now

-2020-08-12T20:34:23.011Z,1597264463.011 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_now

-2020-08-12T20:34:23.011Z,1597264463.011 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_full

-2020-08-12T20:34:23.011Z,1597264463.011 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 107072

-2020-08-12T20:34:23.012Z,1597264463.012 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 107073

-2020-08-12T20:34:23.020Z,1597264463.020 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 107074

-2020-08-12T20:34:23.021Z,1597264463.021 [Supervisor](INFO): Main Thread ID is 106984

-2020-08-12T20:34:23.021Z,1597264463.021 [Onboard ThreadHandler](INFO): Handler Thread ID is 107081

-2020-08-12T20:34:23.021Z,1597264463.021 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 107083

-2020-08-12T20:34:23.021Z,1597264463.021 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000

-2020-08-12T20:34:23.021Z,1597264463.021 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000

-2020-08-12T20:34:23.021Z,1597264463.021 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000

-2020-08-12T20:34:23.021Z,1597264463.021 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000

-2020-08-12T20:34:23.021Z,1597264463.021 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000

-2020-08-12T20:34:23.021Z,1597264463.021 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000

-2020-08-12T20:34:23.021Z,1597264463.021 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000

-2020-08-12T20:34:23.021Z,1597264463.021 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000

-2020-08-12T20:34:23.021Z,1597264463.021 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000

-2020-08-12T20:34:23.021Z,1597264463.021 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000

-2020-08-12T20:34:23.021Z,1597264463.021 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000

-2020-08-12T20:34:23.021Z,1597264463.021 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000

-2020-08-12T20:34:23.021Z,1597264463.021 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000

-2020-08-12T20:34:23.021Z,1597264463.021 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000

-2020-08-12T20:34:23.021Z,1597264463.021 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000

-2020-08-12T20:34:23.021Z,1597264463.021 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000

-2020-08-12T20:34:23.024Z,1597264463.024 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 107079

-2020-08-12T20:34:23.024Z,1597264463.024 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 107080

-2020-08-12T20:34:23.024Z,1597264463.024 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 107082

-2020-08-12T20:34:23.025Z,1597264463.025 [controlThread ThreadHandler](INFO): Handler Thread ID is 107076

-2020-08-12T20:34:23.025Z,1597264463.025 [logger ThreadHandler](INFO): Handler Thread ID is 107078

-2020-08-12T20:34:23.025Z,1597264463.025 [CommandLine ThreadHandler](INFO): Handler Thread ID is 107075

-2020-08-12T20:34:23.025Z,1597264463.025 [ExternalSim](INFO): ExternalSim initializing...

-2020-08-12T20:34:23.032Z,1597264463.032 [SBIT](INFO): Initialize SBIT Component.

-2020-08-12T20:34:23.032Z,1597264463.032 [SBIT](IMPORTANT): git: 2020-07-23-4-gf73e8ad

-2020-08-12T20:34:23.032Z,1597264463.032 [SBIT](INFO): git hash: f73e8ad95b55d34bdb49d5e5edbbb75e6888861e

-2020-08-12T20:34:23.032Z,1597264463.032 [SBIT](INFO): Kernel Reporting Different Release From Configuration.

+2020-08-12T23:51:45.697Z,1597276305.697 [SyncHandler](INFO): Protected caller Thread ID is 109681

+2020-08-12T23:51:45.697Z,1597276305.697 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 109682

+2020-08-12T23:51:45.698Z,1597276305.698 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 109683

+2020-08-12T23:51:45.698Z,1597276305.698 [logger ThreadHandler](INFO): Protected caller Thread ID is 109684

+2020-08-12T23:51:45.698Z,1597276305.698 [Supervisor](INFO): Looking for Config files in directory: Config/

+2020-08-12T23:51:45.698Z,1597276305.698 [Supervisor](INFO): Opening Config file at: Config/secure.cfg

+2020-08-12T23:51:45.703Z,1597276305.703 [Supervisor](INFO): Opening Config file at: Config/Science.cfg

+2020-08-12T23:51:45.708Z,1597276305.708 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg

+2020-08-12T23:51:45.714Z,1597276305.714 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg

+tethyscode>2020-08-12T23:51:45.719Z,1597276305.719 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg

+2020-08-12T23:51:45.723Z,1597276305.723 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg

+2020-08-12T23:51:45.726Z,1597276305.726 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg

+2020-08-12T23:51:45.730Z,1597276305.730 [Supervisor](INFO): Opening Config file at: Config/Control.cfg

+2020-08-12T23:51:45.735Z,1597276305.735 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg

+2020-08-12T23:51:45.738Z,1597276305.738 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg

+2020-08-12T23:51:45.742Z,1597276305.742 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg

+2020-08-12T23:51:45.745Z,1597276305.745 [Supervisor](INFO): Opening Config file at: Config/logger.cfg

+2020-08-12T23:51:45.749Z,1597276305.749 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg

+2020-08-12T23:51:45.753Z,1597276305.753 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg

+2020-08-12T23:51:45.756Z,1597276305.756 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg

+2020-08-12T23:51:45.763Z,1597276305.763 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg

+2020-08-12T23:51:45.767Z,1597276305.767 [Supervisor](INFO): Looking for Config files in directory: Config/tethyscode/

+2020-08-12T23:51:45.767Z,1597276305.767 [Supervisor](INFO): Looking for Config files in directory: Config/tethyscode/tethysadmin/

+2020-08-12T23:51:45.767Z,1597276305.767 [Supervisor](INFO): Looking for Config files in directory: Config/sim/

+2020-08-12T23:51:45.767Z,1597276305.767 [Supervisor](INFO): Opening Config file at: Config/sim/secure.cfg

+2020-08-12T23:51:45.770Z,1597276305.770 [Supervisor](INFO): Opening Config file at: Config/sim/Science.cfg

+2020-08-12T23:51:45.773Z,1597276305.773 [Supervisor](INFO): Opening Config file at: Config/sim/Simulator.cfg

+2020-08-12T23:51:45.776Z,1597276305.776 [Supervisor](INFO): Opening Config file at: Config/sim/vehicle.cfg

+2020-08-12T23:51:45.779Z,1597276305.779 [Supervisor](INFO): Opening Config file at: Config/sim/Servo.cfg

+2020-08-12T23:51:45.782Z,1597276305.782 [Supervisor](INFO): Opening Config file at: Config/sim/Sensor.cfg

+2020-08-12T23:51:45.785Z,1597276305.785 [Supervisor](INFO): Opening Config file at: Config/sim/Derivation.cfg

+2020-08-12T23:51:45.788Z,1597276305.788 [Supervisor](INFO): Looking for Config files in directory: Config/sim/tethysadmin/

+2020-08-12T23:51:45.788Z,1597276305.788 [Supervisor](INFO): Opening Config file at: Config/sim/tethysadmin/secure.cfg

+2020-08-12T23:51:45.791Z,1597276305.791 [Supervisor](INFO): Opening Config file at: Config/sim/tethysadmin/Science.cfg

+2020-08-12T23:51:45.794Z,1597276305.794 [Supervisor](INFO): Opening Config file at: Config/sim/tethysadmin/vehicle.cfg

+2020-08-12T23:51:45.797Z,1597276305.797 [Supervisor](INFO): Opening Config file at: Config/sim/tethysadmin/Sensor.cfg

+2020-08-12T23:51:45.800Z,1597276305.800 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg

+2020-08-12T23:51:45.805Z,1597276305.805 [ESPComponent](ERROR): Could not open device '/dev/loadA6' at ESPComponent.loadControl

+2020-08-12T23:51:45.825Z,1597276305.825 [ESPComponent](ERROR): Could not open device '/dev/loadA7' at ESPComponent.loadControl2

+2020-08-12T23:51:45.846Z,1597276305.846 [ESPComponent](IMPORTANT): ESPCOMPONENT_MANUAL_ESP INDICATED.

+2020-08-12T23:51:45.849Z,1597276305.849 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water

+2020-08-12T23:51:45.849Z,1597276305.849 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 109766

+2020-08-12T23:51:45.862Z,1597276305.862 [AHRS_M2](INFO): created writer for : platform_orientation

+2020-08-12T23:51:45.862Z,1597276305.862 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation

+2020-08-12T23:51:45.862Z,1597276305.862 [AHRS_M2](INFO): created writer for : platform_pitch_angle

+2020-08-12T23:51:45.862Z,1597276305.862 [AHRS_M2](INFO): created writer for : platform_roll_angle

+2020-08-12T23:51:45.865Z,1597276305.865 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 109767

+2020-08-12T23:51:45.866Z,1597276305.866 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/voltage_now

+2020-08-12T23:51:45.866Z,1597276305.866 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/current_now

+2020-08-12T23:51:45.866Z,1597276305.866 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_now

+2020-08-12T23:51:45.867Z,1597276305.867 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_full

+2020-08-12T23:51:45.867Z,1597276305.867 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/voltage_now

+2020-08-12T23:51:45.867Z,1597276305.867 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/current_now

+2020-08-12T23:51:45.867Z,1597276305.867 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_now

+2020-08-12T23:51:45.867Z,1597276305.867 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_full

+2020-08-12T23:51:45.867Z,1597276305.867 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 109768

+2020-08-12T23:51:45.867Z,1597276305.867 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 109769

+2020-08-12T23:51:45.874Z,1597276305.874 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 109770

+2020-08-12T23:51:45.874Z,1597276305.874 [Supervisor](INFO): Main Thread ID is 109680

+2020-08-12T23:51:45.875Z,1597276305.875 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 109776

+2020-08-12T23:51:45.875Z,1597276305.875 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 109778

+2020-08-12T23:51:45.875Z,1597276305.875 [logger ThreadHandler](INFO): Handler Thread ID is 109774

+2020-08-12T23:51:45.878Z,1597276305.878 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 109775

+2020-08-12T23:51:45.878Z,1597276305.878 [Onboard ThreadHandler](INFO): Handler Thread ID is 109777

+2020-08-12T23:51:45.878Z,1597276305.878 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 109779

+2020-08-12T23:51:45.878Z,1597276305.878 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000

+2020-08-12T23:51:45.878Z,1597276305.878 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000

+2020-08-12T23:51:45.878Z,1597276305.878 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000

+2020-08-12T23:51:45.878Z,1597276305.878 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000

+2020-08-12T23:51:45.878Z,1597276305.878 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000

+2020-08-12T23:51:45.878Z,1597276305.878 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000

+2020-08-12T23:51:45.878Z,1597276305.878 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000

+2020-08-12T23:51:45.878Z,1597276305.878 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000

+2020-08-12T23:51:45.878Z,1597276305.878 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000

+2020-08-12T23:51:45.878Z,1597276305.878 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000

+2020-08-12T23:51:45.878Z,1597276305.878 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000

+2020-08-12T23:51:45.878Z,1597276305.878 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000

+2020-08-12T23:51:45.878Z,1597276305.878 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000

+2020-08-12T23:51:45.878Z,1597276305.878 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000

+2020-08-12T23:51:45.878Z,1597276305.878 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000

+2020-08-12T23:51:45.878Z,1597276305.878 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000

+2020-08-12T23:51:45.881Z,1597276305.881 [CommandLine ThreadHandler](INFO): Handler Thread ID is 109773

+2020-08-12T23:51:45.883Z,1597276305.883 [controlThread ThreadHandler](INFO): Handler Thread ID is 109772

+2020-08-12T23:51:45.884Z,1597276305.884 [ExternalSim](INFO): ExternalSim initializing...

+2020-08-12T23:51:45.884Z,1597276305.884 [CommandLine ThreadHandler](INFO): Handler Thread ID is 109771

+2020-08-12T23:51:45.912Z,1597276305.912 [SBIT](INFO): Initialize SBIT Component.

+2020-08-12T23:51:45.912Z,1597276305.912 [SBIT](IMPORTANT): git: 2020-07-23-4-gf73e8ad

+2020-08-12T23:51:45.912Z,1597276305.912 [SBIT](INFO): git hash: f73e8ad95b55d34bdb49d5e5edbbb75e6888861e

+2020-08-12T23:51:45.912Z,1597276305.912 [SBIT](INFO): Kernel Reporting Different Release From Configuration.

 Kernel Expected: 2.6.32-45-generic-pae

 Kernel Reported: 2.6.32-754.29.1.el6.x86_64

-2020-08-12T20:34:23.032Z,1597264463.032 [SBIT](INFO): Kernel Reporting Different Version From Configuration.

+2020-08-12T23:51:45.912Z,1597276305.912 [SBIT](INFO): Kernel Reporting Different Version From Configuration.

 Kernel Expected: #102-Ubuntu SMP Wed Jan 2 22:10:16 UTC 2013

 Kernel Reported: #1 SMP Mon Apr 27 15:30:33 UTC 2020

-2020-08-12T20:34:23.032Z,1597264463.032 [SBIT](INFO): Beginning SBIT in 20.000000 seconds.

-2020-08-12T20:34:23.032Z,1597264463.032 [IBIT](INFO): Initialize IBIT Component.

-2020-08-12T20:34:23.033Z,1597264463.033 [CommandLine ThreadHandler](INFO): Handler Thread ID is 107077

-2020-08-12T20:34:23.062Z,1597264463.062 [CBIT](INFO): Last reboot was NOT due to watchdog timer.

-2020-08-12T20:34:23.062Z,1597264463.062 [MissionManager](INFO): Loading Mission: Missions/Startup.xml

-2020-08-12T20:34:23.062Z,1597264463.062 [MissionManager](INFO): Loading Mission: Missions/Default.xml

-2020-08-12T20:34:23.062Z,1597264463.062 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min

-tethyscode>load Maintenance2020-08-12T20:34:23.072Z,1597264463.072 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/sample.xml

-2020-08-12T20:34:23.072Z,1597264463.072 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/sample.xml

-2020-08-12T20:34:23.072Z,1597264463.072 [MissionManager](INFO): DefineArg sample.MissionTimeout = 90.000000 min

-2020-08-12T20:34:23.072Z,1597264463.072 [MissionManager](INFO): DefineArg sample.Depth = 7.000000 m

-2020-08-12T20:34:23.072Z,1597264463.072 [MissionManager](INFO): DefineArg sample.CartridgeType = -4.000000 count

-2020-08-12T20:34:23.072Z,1597264463.072 [MissionManager](INFO): DefineArg sample.NumberOfSamples = 1.000000 count

-2020-08-12T20:34:23.072Z,1597264463.072 [MissionManager](INFO): DefineArg sample.WaitBeforeSample = 3.000000 min

-2020-08-12T20:34:23.072Z,1597264463.072 [MissionManager](INFO): Inserting Stack: Missions/Insert/SampleAtDepth.xml

-2020-08-12T20:34:23.073Z,1597264463.073 [MissionManager](INFO): DefineArg sample:SampleAtDepth.TargetDepth = 5.000000 m

-2020-08-12T20:34:23.073Z,1597264463.073 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SettleTime = 10.000000 s

-2020-08-12T20:34:23.073Z,1597264463.073 [MissionManager](INFO): DefineArg sample:SampleAtDepth.MaxWaitNotReachingDepth = 3.000000 h

-2020-08-12T20:34:23.073Z,1597264463.073 [MissionManager](INFO): DefineArg sample:SampleAtDepth.RotateOnly = 0.000000 bool

-2020-08-12T20:34:23.073Z,1597264463.073 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseCANONSampler = 0.000000 bool

-2020-08-12T20:34:23.073Z,1597264463.073 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseESP = 1.000000 bool

-2020-08-12T20:34:23.073Z,1597264463.073 [MissionManager](INFO): DefineArg sample:SampleAtDepth.ESPCartridgeType = nan count

-2020-08-12T20:34:23.073Z,1597264463.073 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTriggerTimeout = 1.000000 min

-2020-08-12T20:34:23.073Z,1597264463.073 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTimeout = 6.000000 min

-2020-08-12T20:34:23.073Z,1597264463.073 [MissionManager](INFO): DefineArg sample:SampleAtDepth.BuoyancyNeutral = 500.000024 cc

-2020-08-12T20:34:23.073Z,1597264463.073 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature

-2020-08-12T20:34:23.073Z,1597264463.073 [MissionManager](ERROR): Slate does not contain celsius

-2020-08-12T20:34:23.073Z,1597264463.073 [MissionManager](ERROR): Slate does not contain CTD_Seabird.bin_mean_sea_water_temperature

-2020-08-12T20:34:23.073Z,1597264463.073 [MissionManager](ERROR): Slate does not contain celsius

-2020-08-12T20:34:23.073Z,1597264463.073 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/sample.xml

+2020-08-12T23:51:45.912Z,1597276305.912 [SBIT](INFO): Beginning SBIT in 20.000000 seconds.

+2020-08-12T23:51:45.912Z,1597276305.912 [IBIT](INFO): Initialize IBIT Component.

+tethyscode>load Maintenance2020-08-12T23:51:45.926Z,1597276305.926 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/sample.xml

+2020-08-12T23:51:45.926Z,1597276305.926 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/sample.xml

+2020-08-12T23:51:45.927Z,1597276305.927 [MissionManager](INFO): DefineArg sample.MissionTimeout = 90.000000 min

+2020-08-12T23:51:45.927Z,1597276305.927 [MissionManager](INFO): DefineArg sample.Depth = 7.000000 m

+2020-08-12T23:51:45.927Z,1597276305.927 [MissionManager](INFO): DefineArg sample.CartridgeType = -4.000000 count

+2020-08-12T23:51:45.927Z,1597276305.927 [MissionManager](INFO): DefineArg sample.NumberOfSamples = 1.000000 count

+2020-08-12T23:51:45.927Z,1597276305.927 [MissionManager](INFO): DefineArg sample.WaitBeforeSample = 3.000000 min

+2020-08-12T23:51:45.927Z,1597276305.927 [MissionManager](INFO): Inserting Stack: Missions/Insert/SampleAtDepth.xml

+2020-08-12T23:51:45.928Z,1597276305.928 [MissionManager](INFO): DefineArg sample:SampleAtDepth.TargetDepth = 5.000000 m

+2020-08-12T23:51:45.929Z,1597276305.929 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SettleTime = 10.000000 s

+2020-08-12T23:51:45.929Z,1597276305.929 [MissionManager](INFO): DefineArg sample:SampleAtDepth.MaxWaitNotReachingDepth = 3.000000 h

+2020-08-12T23:51:45.929Z,1597276305.929 [MissionManager](INFO): DefineArg sample:SampleAtDepth.RotateOnly = 0.000000 bool

+2020-08-12T23:51:45.929Z,1597276305.929 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseCANONSampler = 0.000000 bool

+2020-08-12T23:51:45.929Z,1597276305.929 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseESP = 1.000000 bool

+2020-08-12T23:51:45.929Z,1597276305.929 [MissionManager](INFO): DefineArg sample:SampleAtDepth.ESPCartridgeType = nan count

+2020-08-12T23:51:45.929Z,1597276305.929 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTriggerTimeout = 1.000000 min

+2020-08-12T23:51:45.929Z,1597276305.929 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTimeout = 6.000000 min

+2020-08-12T23:51:45.929Z,1597276305.929 [MissionManager](INFO): DefineArg sample:SampleAtDepth.BuoyancyNeutral = 500.000024 cc

+2020-08-12T23:51:45.930Z,1597276305.930 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature

+2020-08-12T23:51:45.930Z,1597276305.930 [MissionManager](ERROR): Slate does not contain celsius

+2020-08-12T23:51:45.933Z,1597276305.933 [MissionManager](ERROR): Slate does not contain CTD_Seabird.bin_mean_sea_water_temperature

+2020-08-12T23:51:45.933Z,1597276305.933 [MissionManager](ERROR): Slate does not contain celsius

+2020-08-12T23:51:45.934Z,1597276305.934 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/sample.xml

+2020-08-12T23:51:45.943Z,1597276305.943 [CBIT](INFO): Last reboot was NOT due to watchdog timer.

+2020-08-12T23:51:45.943Z,1597276305.943 [MissionManager](INFO): Loading Mission: Missions/Startup.xml

+2020-08-12T23:51:45.944Z,1597276305.944 [MissionManager](INFO): Loading Mission: Missions/Default.xml

+2020-08-12T23:51:45.944Z,1597276305.944 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min

 tethyscode>set sample.NumberOfSamples 2 count;set sample.Depth 1 centimeter;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.TargetDepth 1 centimeter;run

-2020-08-12T20:34:23.133Z,1597264463.133 [CommandLine](IMPORTANT): got command set sample.NumberOfSamples 2.000000 count

-2020-08-12T20:34:23.133Z,1597264463.133 [CommandLine](IMPORTANT): got command set sample.Depth 1.000000 centimeter

-2020-08-12T20:34:23.134Z,1597264463.134 [CommandLine](IMPORTANT): got command set sample.WaitBeforeSample 3.000000 second

-2020-08-12T20:34:23.134Z,1597264463.134 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.TargetDepth 1.000000 centimeter

-2020-08-12T20:34:23.134Z,1597264463.134 [CommandLine](IMPORTANT): got command run

-2020-08-12T20:34:23.134Z,1597264463.134 [CommandLine](IMPORTANT): Running

-2020-08-12T20:34:27.025Z,1597264467.025 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.000142

-2020-08-12T20:34:28.025Z,1597264468.025 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.

-2020-08-12T20:34:29.025Z,1597264469.025 [DataOverHttps](INFO): Radio surface powered ON.

-2020-08-12T20:34:43.470Z,1597264483.470 [SBIT](IMPORTANT): Beginning Startup BIT

-2020-08-12T20:34:57.473Z,1597264497.473 [NAL9602](INFO): GPS fix at 20200812T203457: (36.803404, -121.822207)

-2020-08-12T20:34:58.673Z,1597264498.673 [NAL9602](INFO): No messages in MT queue

-2020-08-12T20:35:29.094Z,1597264529.094 [NAL9602](INFO): Not Powering down - fast GPS

-2020-08-12T20:35:37.096Z,1597264537.096 [SBIT](IMPORTANT): SBIT PASSED

-2020-08-12T20:35:37.096Z,1597264537.096 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg

-2020-08-12T20:35:37.096Z,1597264537.096 [SBIT](IMPORTANT): No configSet variables persisted

-2020-08-12T20:35:37.496Z,1597264537.496 [MissionManager](IMPORTANT): Started mission Startup

-2020-08-12T20:35:37.496Z,1597264537.496 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.

-2020-08-12T20:35:42.296Z,1597264542.296 [NAL9602](INFO): GPS fix at 20200812T203542: (36.803409, -121.822216)

-2020-08-12T20:35:43.497Z,1597264543.497 [NAL9602](INFO): No messages in MT queue

-2020-08-12T20:35:46.037Z,1597264546.037 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20200812T203422/Courier0000.lzma

-2020-08-12T20:35:47.036Z,1597264547.036 [DataOverHttps](INFO): Moved sent file to Logs/20200812T203422/Courier0000.lzma.bak

-2020-08-12T20:35:47.036Z,1597264547.036 [DataOverHttps](INFO): SBD MOMSN=12488619

-2020-08-12T20:35:56.038Z,1597264556.038 [DataOverHttps](INFO): Sending 664 bytes from file Logs/20200812T183714/Express0001.lzma

-2020-08-12T20:35:57.037Z,1597264557.037 [DataOverHttps](INFO): Moved sent file to Logs/20200812T183714/Express0001.lzma.bak

-2020-08-12T20:35:57.037Z,1597264557.037 [DataOverHttps](INFO): SBD MOMSN=12488623

-2020-08-12T20:36:06.038Z,1597264566.038 [DataOverHttps](INFO): Sending 901 bytes from file Logs/20200812T183714/Express0005.lzma

-2020-08-12T20:36:07.038Z,1597264567.038 [DataOverHttps](INFO): Moved sent file to Logs/20200812T183714/Express0005.lzma.bak

-2020-08-12T20:36:07.038Z,1597264567.038 [DataOverHttps](INFO): SBD MOMSN=12488641

-2020-08-12T20:36:13.904Z,1597264573.904 [NAL9602](INFO): Not Powering down - fast GPS

-2020-08-12T20:36:16.042Z,1597264576.042 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20200812T183714/Express0008.lzma

-2020-08-12T20:36:17.042Z,1597264577.042 [DataOverHttps](INFO): Moved sent file to Logs/20200812T183714/Express0008.lzma.bak

-2020-08-12T20:36:17.042Z,1597264577.042 [DataOverHttps](INFO): SBD MOMSN=12488665

-2020-08-12T20:36:26.044Z,1597264586.044 [DataOverHttps](INFO): Sending 663 bytes from file Logs/20200812T185324/Express0001.lzma

-2020-08-12T20:36:27.044Z,1597264587.044 [DataOverHttps](INFO): Moved sent file to Logs/20200812T185324/Express0001.lzma.bak

-2020-08-12T20:36:27.044Z,1597264587.044 [DataOverHttps](INFO): SBD MOMSN=12488669

-2020-08-12T20:36:36.045Z,1597264596.045 [DataOverHttps](INFO): Sending 1303 bytes from file Logs/20200812T185324/Express0005.lzma

-2020-08-12T20:36:37.045Z,1597264597.045 [DataOverHttps](INFO): Moved sent file to Logs/20200812T185324/Express0005.lzma.bak

-2020-08-12T20:36:37.045Z,1597264597.045 [DataOverHttps](INFO): SBD MOMSN=12488687

-2020-08-12T20:36:42.311Z,1597264602.311 [Startup:StartupSatComms:B](INFO): Timed out from 2020-08-12T20:35:42.3Z

-2020-08-12T20:36:42.311Z,1597264602.311 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms

-2020-08-12T20:36:42.311Z,1597264602.311 [Startup](INFO): Completed Startup

-2020-08-12T20:36:42.311Z,1597264602.311 [MissionManager](INFO): Startup is completed.

-2020-08-12T20:36:42.311Z,1597264602.311 [MissionManager](INFO): Uninitializing Mission Startup

-2020-08-12T20:36:42.711Z,1597264602.711 [MissionManager](IMPORTANT): Started mission sample

-2020-08-12T20:36:42.711Z,1597264602.711 [sample:A.AbortSample](INFO): Initializing AbortSample.

-2020-08-12T20:36:43.913Z,1597264603.913 [sample:SampleAtDepth:ApproachDepth:A](INFO): Moving to 0.010000 m

-2020-08-12T20:36:46.046Z,1597264606.046 [DataOverHttps](INFO): Sending 125 bytes from file Logs/20200812T185324/Express0008.lzma

-2020-08-12T20:36:47.046Z,1597264607.046 [DataOverHttps](INFO): Moved sent file to Logs/20200812T185324/Express0008.lzma.bak

-2020-08-12T20:36:47.046Z,1597264607.046 [DataOverHttps](INFO): SBD MOMSN=12488740

-2020-08-12T20:38:53.561Z,1597264733.561 [sample:SampleAtDepth:ApproachDepth](INFO): Completed sample:SampleAtDepth:ApproachDepth

-2020-08-12T20:38:53.961Z,1597264733.961 [sample:SampleAtDepth:SampleWrapper:B](IMPORTANT): At 0.012480 m , settling for 0.050000 min

-2020-08-12T20:38:57.561Z,1597264737.561 [sample:SampleAtDepth:SampleWrapper:C.Wait](INFO): Done Waiting.

-2020-08-12T20:38:57.961Z,1597264737.961 [sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect](INFO): Initializing ESPCartridgeSelect.

-2020-08-12T20:38:58.361Z,1597264738.361 [sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect](INFO): Issuing request for ESP cartridge type: -4.

-2020-08-12T20:38:58.361Z,1597264738.361 [sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect](INFO): Uninitializing ESPCartridgeSelect.

-2020-08-12T20:38:58.361Z,1597264738.361 [sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge](INFO): Completed sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge

-2020-08-12T20:38:59.560Z,1597264739.560 [ESPComponent](IMPORTANT): Setting regex for ESP Log summary: 'Selecting Cartridge|Sampled|Error|Underpressure|Overpressure|Fail|Retry|Cmd::|Sampler::'

-2020-08-12T20:38:59.561Z,1597264739.561 [ESPComponent](INFO): compiled regex: "Selecting Cartridge|Sampled|Error|Underpressure|Overpressure|Fail|Retry|Cmd::|Sampler::"

-2020-08-12T20:38:59.960Z,1597264739.960 [ESPComponent](IMPORTANT): powerUpESP IGNORED because manualEsp_

-2020-08-12T20:38:59.960Z,1597264739.960 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=30.0000)

-2020-08-12T20:39:01.561Z,1597264741.561 [ESPComponent](IMPORTANT): ESP has connected as client

-2020-08-12T20:39:02.362Z,1597264742.362 [ESPComponent](IMPORTANT): [sample #1] Setting cartridge argument to -4

-2020-08-12T20:39:02.362Z,1597264742.362 [ESPComponent](IMPORTANT): [sample #1] ESP sampling sequence starting. Sampling state: S_WAITING_INITIAL_PROMPT

-2020-08-12T20:39:02.762Z,1597264742.762 [sample:SampleAtDepth:SampleWrapper:SampleESP:C](ERROR): data element is not active.

-2020-08-12T20:39:02.762Z,1597264742.762 [sample:SampleAtDepth:SampleWrapper:SampleESP:C](IMPORTANT): ESP sampling at 0.092633 m inwater with nan ug/l chlorophyll fluorescence.

-2020-08-12T20:39:03.561Z,1597264743.561 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PREPARING_SHOW_LOG

-2020-08-12T20:39:03.961Z,1597264743.961 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PREPARING_SHOW_STATUS

-2020-08-12T20:39:05.562Z,1597264745.562 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_LOADING_CARTRIDGE

-2020-08-12T20:39:42.372Z,1597264782.372 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PRIMING (@58,archiveHiBiomass_bac)

-2020-08-12T20:39:43.972Z,1597264783.972 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PRIMING (@5.0)

-2020-08-12T20:39:44.772Z,1597264784.772 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_FILTERING (@5.0)

-2020-08-12T20:40:15.179Z,1597264815.179 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_FILTERING (@0.0)

-2020-08-12T20:40:15.580Z,1597264815.580 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PAUSED (@0.0)

-2020-08-12T20:40:31.183Z,1597264831.183 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PAUSED (@10.0)

-2020-08-12T20:40:31.583Z,1597264831.583 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PROCESSING (@10.0)

-2020-08-12T20:40:33.983Z,1597264833.983 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PROCESSED (@58,archiveHiBiomass_bac)

-2020-08-12T20:44:06.038Z,1597265046.038 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_STOPPING (@58,archiveHiBiomass_bac)

-2020-08-12T20:44:32.844Z,1597265072.844 [ESPComponent](IMPORTANT): Syncing ESP logs with command: rsync -azPq --timeout=60 carueda@bufflehead:'/var/log/carueda/simrapid.* /var/log/carueda/*.spr' /home/carueda/lrauv-application/ESPlogs &

-2020-08-12T20:44:32.846Z,1597265072.846 [ESPComponent](INFO): closing pipe.

-2020-08-12T20:44:33.246Z,1597265073.246 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_STOPPED

-2020-08-12T20:49:32.914Z,1597265372.914 [ESPComponent](IMPORTANT): [sample #1] ESP sampling sequence completed normally.

-2020-08-12T20:49:32.916Z,1597265372.916 [sample:SampleAtDepth:SampleWrapper:SampleESP](INFO): Completed sample:SampleAtDepth:SampleWrapper:SampleESP

-2020-08-12T20:49:32.916Z,1597265372.916 [sample:SampleAtDepth:SampleWrapper](INFO): Completed sample:SampleAtDepth:SampleWrapper

-2020-08-12T20:49:32.916Z,1597265372.916 [sample:SampleAtDepth](INFO): Completed sample:SampleAtDepth

-2020-08-12T20:49:33.314Z,1597265373.314 [ESPComponent](IMPORTANT): [sample #1] ESP log summary report (2 messages):

-@13:39:08.27 Selecting Cartridge 58

-@13:40:29.75 Sampled  10.0ml

-2020-08-12T20:49:33.314Z,1597265373.314 [ESPComponent](IMPORTANT): powerDownESP IGNORED because manualEsp_

-2020-08-12T20:49:33.316Z,1597265373.316 [sample:SampleRepeater:Sample](INFO): Completed sample:SampleRepeater:Sample

-2020-08-12T20:49:33.316Z,1597265373.316 [sample:SampleRepeater](INFO): Completed sample:SampleRepeater

-2020-08-12T20:49:33.316Z,1597265373.316 [sample:SampleRepeater](INFO): Running loop #2

-2020-08-12T20:49:33.715Z,1597265373.715 [sample:SampleAtDepth:ApproachDepth:A](INFO): Moving to 0.010000 m

-2020-08-12T20:59:11.891Z,1597265951.891 [sample:SampleAtDepth:ApproachDepth](INFO): Completed sample:SampleAtDepth:ApproachDepth

-2020-08-12T20:59:12.291Z,1597265952.291 [sample:SampleAtDepth:SampleWrapper:B](IMPORTANT): At 0.008833 m , settling for 0.050000 min

-2020-08-12T20:59:15.892Z,1597265955.892 [sample:SampleAtDepth:SampleWrapper:C.Wait](INFO): Done Waiting.

-2020-08-12T20:59:16.293Z,1597265956.293 [sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect](INFO): Initializing ESPCartridgeSelect.

-2020-08-12T20:59:16.692Z,1597265956.692 [sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect](INFO): Issuing request for ESP cartridge type: -4.

-2020-08-12T20:59:16.692Z,1597265956.692 [sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect](INFO): Uninitializing ESPCartridgeSelect.

-2020-08-12T20:59:16.692Z,1597265956.692 [sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge](INFO): Completed sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge

-2020-08-12T20:59:18.292Z,1597265958.292 [ESPComponent](IMPORTANT): powerUpESP IGNORED because manualEsp_

-2020-08-12T20:59:18.292Z,1597265958.292 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=30.0000)

-2020-08-12T20:59:19.892Z,1597265959.892 [ESPComponent](IMPORTANT): ESP has connected as client

-2020-08-12T20:59:20.693Z,1597265960.693 [ESPComponent](IMPORTANT): [sample #2] Setting cartridge argument to -4

-2020-08-12T20:59:20.693Z,1597265960.693 [ESPComponent](IMPORTANT): [sample #2] ESP sampling sequence starting. Sampling state: S_WAITING_INITIAL_PROMPT

-2020-08-12T20:59:21.093Z,1597265961.093 [sample:SampleAtDepth:SampleWrapper:SampleESP:C](ERROR): data element is not active.

-2020-08-12T20:59:21.093Z,1597265961.093 [sample:SampleAtDepth:SampleWrapper:SampleESP:C](IMPORTANT): ESP sampling at 0.000588 m inwater with nan ug/l chlorophyll fluorescence.

-2020-08-12T20:59:21.492Z,1597265961.492 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_PREPARING_SHOW_LOG

-2020-08-12T20:59:21.892Z,1597265961.892 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_PREPARING_SHOW_STATUS

-2020-08-12T20:59:23.892Z,1597265963.892 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_LOADING_CARTRIDGE

-2020-08-12T21:00:00.700Z,1597266000.700 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_WAITING_FOR_PRIMING (@57,archiveHiBiomass_bac)

-2020-08-12T21:00:02.301Z,1597266002.301 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_PRIMING (@5.0)

-2020-08-12T21:00:03.101Z,1597266003.101 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_WAITING_FOR_FILTERING (@5.0)

-2020-08-12T21:00:33.511Z,1597266033.511 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_FILTERING (@0.0)

-2020-08-12T21:00:33.911Z,1597266033.911 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_WAITING_FOR_PAUSED (@0.0)

-2020-08-12T21:00:49.514Z,1597266049.514 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_PAUSED (@10.0)

-2020-08-12T21:00:49.914Z,1597266049.914 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_PROCESSING (@10.0)

-2020-08-12T21:00:52.315Z,1597266052.315 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_WAITING_FOR_PROCESSED (@57,archiveHiBiomass_bac)

-2020-08-12T21:04:24.361Z,1597266264.361 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_STOPPING (@57,archiveHiBiomass_bac)

-2020-08-12T21:04:51.167Z,1597266291.167 [ESPComponent](IMPORTANT): Syncing ESP logs with command: rsync -azPq --timeout=60 carueda@bufflehead:'/var/log/carueda/simrapid.* /var/log/carueda/*.spr' /home/carueda/lrauv-application/ESPlogs &

-2020-08-12T21:04:51.171Z,1597266291.171 [ESPComponent](INFO): closing pipe.

-2020-08-12T21:04:51.568Z,1597266291.568 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_STOPPED

-2020-08-12T21:09:51.236Z,1597266591.236 [ESPComponent](IMPORTANT): [sample #2] ESP sampling sequence completed normally.

-2020-08-12T21:09:51.237Z,1597266591.237 [sample:SampleAtDepth:SampleWrapper:SampleESP](INFO): Completed sample:SampleAtDepth:SampleWrapper:SampleESP

-2020-08-12T21:09:51.237Z,1597266591.237 [sample:SampleAtDepth:SampleWrapper](INFO): Completed sample:SampleAtDepth:SampleWrapper

-2020-08-12T21:09:51.237Z,1597266591.237 [sample:SampleAtDepth](INFO): Completed sample:SampleAtDepth

-2020-08-12T21:09:51.636Z,1597266591.636 [ESPComponent](IMPORTANT): [sample #2] ESP log summary report (2 messages):

-@13:59:26.60 Selecting Cartridge 57

-@14:00:48.10 Sampled  10.0ml

-2020-08-12T21:09:51.636Z,1597266591.636 [ESPComponent](IMPORTANT): powerDownESP IGNORED because manualEsp_

-2020-08-12T21:09:51.637Z,1597266591.637 [sample:SampleRepeater:Sample](INFO): Completed sample:SampleRepeater:Sample

-2020-08-12T21:09:51.637Z,1597266591.637 [sample:SampleRepeater](INFO): Completed sample:SampleRepeater

-2020-08-12T21:09:51.637Z,1597266591.637 [sample](INFO): Completed sample

-2020-08-12T21:09:51.637Z,1597266591.637 [MissionManager](INFO): sample is completed.

-...

+2020-08-12T23:51:45.984Z,1597276305.984 [CommandLine](IMPORTANT): got command set sample.NumberOfSamples 2.000000 count

+2020-08-12T23:51:45.985Z,1597276305.985 [CommandLine](IMPORTANT): got command set sample.Depth 1.000000 centimeter

+2020-08-12T23:51:45.985Z,1597276305.985 [CommandLine](IMPORTANT): got command set sample.WaitBeforeSample 3.000000 second

+2020-08-12T23:51:45.985Z,1597276305.985 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.TargetDepth 1.000000 centimeter

+2020-08-12T23:51:45.985Z,1597276305.985 [CommandLine](IMPORTANT): got command run

+2020-08-12T23:51:45.985Z,1597276305.985 [CommandLine](IMPORTANT): Running

+2020-08-12T23:51:49.875Z,1597276309.875 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.000134

+2020-08-12T23:51:50.875Z,1597276310.875 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.

+2020-08-12T23:51:51.875Z,1597276311.875 [DataOverHttps](INFO): Radio surface powered ON.

+2020-08-12T23:52:06.352Z,1597276326.352 [SBIT](IMPORTANT): Beginning Startup BIT

+2020-08-12T23:52:20.357Z,1597276340.357 [NAL9602](INFO): GPS fix at 20200812T235220: (36.803404, -121.822207)

+2020-08-12T23:52:21.557Z,1597276341.557 [NAL9602](INFO): No messages in MT queue

+2020-08-12T23:52:51.963Z,1597276371.963 [NAL9602](INFO): Not Powering down - fast GPS

+2020-08-12T23:52:59.965Z,1597276379.965 [SBIT](IMPORTANT): SBIT PASSED

+2020-08-12T23:52:59.965Z,1597276379.965 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg

+2020-08-12T23:52:59.965Z,1597276379.965 [SBIT](IMPORTANT): No configSet variables persisted

+2020-08-12T23:53:00.365Z,1597276380.365 [MissionManager](IMPORTANT): Started mission Startup

+2020-08-12T23:53:00.365Z,1597276380.365 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.

+2020-08-12T23:53:05.166Z,1597276385.166 [NAL9602](INFO): GPS fix at 20200812T235305: (36.803409, -121.822216)

+2020-08-12T23:53:06.366Z,1597276386.366 [NAL9602](INFO): No messages in MT queue

+2020-08-12T23:53:08.883Z,1597276388.883 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20200812T235145/Courier0000.lzma

+2020-08-12T23:53:09.883Z,1597276389.883 [DataOverHttps](INFO): Moved sent file to Logs/20200812T235145/Courier0000.lzma.bak

+2020-08-12T23:53:09.883Z,1597276389.883 [DataOverHttps](INFO): SBD MOMSN=12551506

+2020-08-12T23:53:18.884Z,1597276398.884 [DataOverHttps](INFO): Sending 400 bytes from file Logs/20200812T234630/Express0005.lzma

+2020-08-12T23:53:19.884Z,1597276399.884 [DataOverHttps](INFO): Moved sent file to Logs/20200812T234630/Express0005.lzma.bak

+2020-08-12T23:53:19.884Z,1597276399.884 [DataOverHttps](INFO): SBD MOMSN=12551510

+2020-08-12T23:53:28.885Z,1597276408.885 [DataOverHttps](INFO): Sending 125 bytes from file Logs/20200812T234630/Express0008.lzma

+2020-08-12T23:53:29.884Z,1597276409.884 [DataOverHttps](INFO): Moved sent file to Logs/20200812T234630/Express0008.lzma.bak

+2020-08-12T23:53:29.884Z,1597276409.884 [DataOverHttps](INFO): SBD MOMSN=12551521

+2020-08-12T23:53:36.772Z,1597276416.772 [NAL9602](INFO): Not Powering down - fast GPS

+2020-08-12T23:53:38.885Z,1597276418.885 [DataOverHttps](INFO): Sending 663 bytes from file Logs/20200812T235145/Express0001.lzma

+2020-08-12T23:53:39.885Z,1597276419.885 [DataOverHttps](INFO): Moved sent file to Logs/20200812T235145/Express0001.lzma.bak

+2020-08-12T23:53:39.885Z,1597276419.885 [DataOverHttps](INFO): SBD MOMSN=12551526

+2020-08-12T23:53:41.174Z,1597276421.174 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms

+2020-08-12T23:53:41.174Z,1597276421.174 [Startup](INFO): Completed Startup

+2020-08-12T23:53:41.174Z,1597276421.174 [MissionManager](INFO): Startup is completed.

+2020-08-12T23:53:41.174Z,1597276421.174 [MissionManager](INFO): Uninitializing Mission Startup

+2020-08-12T23:53:41.574Z,1597276421.574 [MissionManager](IMPORTANT): Started mission sample

+2020-08-12T23:53:41.574Z,1597276421.574 [sample:A.AbortSample](INFO): Initializing AbortSample.

+2020-08-12T23:53:42.774Z,1597276422.774 [sample:SampleAtDepth:ApproachDepth:A](INFO): Moving to 0.010000 m

+2020-08-12T23:55:52.404Z,1597276552.404 [sample:SampleAtDepth:ApproachDepth](INFO): Completed sample:SampleAtDepth:ApproachDepth

+2020-08-12T23:55:52.804Z,1597276552.804 [sample:SampleAtDepth:SampleWrapper:B](IMPORTANT): At 0.012824 m , settling for 0.050000 min

+2020-08-12T23:55:56.405Z,1597276556.405 [sample:SampleAtDepth:SampleWrapper:C.Wait](INFO): Done Waiting.

+2020-08-12T23:55:56.805Z,1597276556.805 [sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect](INFO): Initializing ESPCartridgeSelect.

+2020-08-12T23:55:57.205Z,1597276557.205 [sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect](INFO): Issuing request for ESP cartridge type: -4.

+2020-08-12T23:55:57.205Z,1597276557.205 [sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect](INFO): Uninitializing ESPCartridgeSelect.

+2020-08-12T23:55:57.205Z,1597276557.205 [sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge](INFO): Completed sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge

+2020-08-12T23:55:58.405Z,1597276558.405 [ESPComponent](IMPORTANT): Setting regex for ESP Log summary: 'Selecting Cartridge|Sampled|Error|Underpressure|Overpressure|Fail|Retry|Cmd::|Sampler::'

+2020-08-12T23:55:58.405Z,1597276558.405 [ESPComponent](INFO): compiled regex: "Selecting Cartridge|Sampled|Error|Underpressure|Overpressure|Fail|Retry|Cmd::|Sampler::"

+2020-08-12T23:55:58.805Z,1597276558.805 [ESPComponent](IMPORTANT): powerUpESP IGNORED because manualEsp_

+2020-08-12T23:55:58.805Z,1597276558.805 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=30.0000)

+2020-08-12T23:56:02.406Z,1597276562.406 [ESPComponent](IMPORTANT): ESP has connected as client

+2020-08-12T23:56:03.206Z,1597276563.206 [ESPComponent](IMPORTANT): [sample #1] Setting cartridge argument to -4

+2020-08-12T23:56:03.206Z,1597276563.206 [ESPComponent](IMPORTANT): [sample #1] ESP sampling sequence starting. Sampling state: S_WAITING_INITIAL_PROMPT

+2020-08-12T23:56:03.607Z,1597276563.607 [sample:SampleAtDepth:SampleWrapper:SampleESP:C](ERROR): data element is not active.

+2020-08-12T23:56:03.607Z,1597276563.607 [sample:SampleAtDepth:SampleWrapper:SampleESP:C](IMPORTANT): ESP sampling at 0.126759 m inwater with nan ug/l chlorophyll fluorescence.

+2020-08-12T23:56:04.406Z,1597276564.406 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PREPARING_SHOW_LOG

+2020-08-12T23:56:04.806Z,1597276564.806 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PREPARING_SHOW_STATUS

+2020-08-12T23:56:06.406Z,1597276566.406 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_LOADING_CARTRIDGE

+2020-08-12T23:56:43.214Z,1597276603.214 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PRIMING (@56,archiveHiBiomass_bac)

+2020-08-12T23:56:44.815Z,1597276604.815 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PRIMING (@5.0)

+2020-08-12T23:56:45.615Z,1597276605.615 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_FILTERING (@5.0)

+2020-08-12T23:57:16.021Z,1597276636.021 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_FILTERING (@0.0)

+2020-08-12T23:57:16.421Z,1597276636.421 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PAUSED (@0.0)

+2020-08-12T23:57:32.024Z,1597276652.024 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PAUSED (@10.0)

+2020-08-12T23:57:32.424Z,1597276652.424 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PROCESSING (@10.0)

+2020-08-12T23:57:34.825Z,1597276654.825 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PROCESSED (@56,archiveHiBiomass_bac)

+2020-08-13T00:01:06.875Z,1597276866.875 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_STOPPING (@56,archiveHiBiomass_bac)

+2020-08-13T00:01:33.681Z,1597276893.681 [ESPComponent](IMPORTANT): Syncing ESP logs with command: rsync -azPq --timeout=60 carueda@bufflehead:'/var/log/carueda/simrapid.* /var/log/carueda/*.spr' /home/tethysadmin/workspace/lrauv-application-carlos/ESPlogs &

+2020-08-13T00:01:33.685Z,1597276893.685 [ESPComponent](INFO): closing pipe.

+2020-08-13T00:01:34.082Z,1597276894.082 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_STOPPED

+2020-08-13T00:01:44.089Z,1597276904.089 [ESPComponent](IMPORTANT): [sample #1] ESP sampling sequence completed normally.

+2020-08-13T00:01:44.089Z,1597276904.089 [sample:SampleAtDepth:SampleWrapper:SampleESP](INFO): Completed sample:SampleAtDepth:SampleWrapper:SampleESP

+2020-08-13T00:01:44.089Z,1597276904.089 [sample:SampleAtDepth:SampleWrapper](INFO): Completed sample:SampleAtDepth:SampleWrapper

+2020-08-13T00:01:44.089Z,1597276904.089 [sample:SampleAtDepth](INFO): Completed sample:SampleAtDepth

+2020-08-13T00:01:44.489Z,1597276904.489 [ESPComponent](IMPORTANT): [sample #1] ESP log summary report (2 messages):

+@16:56:09.14 Selecting Cartridge 56

+@16:57:30.54 Sampled  10.0ml

+2020-08-13T00:01:44.489Z,1597276904.489 [ESPComponent](IMPORTANT): powerDownESP IGNORED because manualEsp_

+2020-08-13T00:01:44.490Z,1597276904.490 [sample:SampleRepeater:Sample](INFO): Completed sample:SampleRepeater:Sample

+2020-08-13T00:01:44.490Z,1597276904.490 [sample:SampleRepeater](INFO): Completed sample:SampleRepeater

+2020-08-13T00:01:44.490Z,1597276904.490 [sample:SampleRepeater](INFO): Running loop #2

+2020-08-13T00:01:44.889Z,1597276904.889 [sample:SampleAtDepth:ApproachDepth:A](INFO): Moving to 0.010000 m

+2020-08-13T00:11:21.026Z,1597277481.026 [sample:SampleAtDepth:ApproachDepth](INFO): Completed sample:SampleAtDepth:ApproachDepth

+2020-08-13T00:11:21.426Z,1597277481.426 [sample:SampleAtDepth:SampleWrapper:B](IMPORTANT): At 0.008778 m , settling for 0.050000 min

+2020-08-13T00:11:25.027Z,1597277485.027 [sample:SampleAtDepth:SampleWrapper:C.Wait](INFO): Done Waiting.

+2020-08-13T00:11:25.427Z,1597277485.427 [sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect](INFO): Initializing ESPCartridgeSelect.

+2020-08-13T00:11:25.827Z,1597277485.827 [sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect](INFO): Issuing request for ESP cartridge type: -4.

+2020-08-13T00:11:25.827Z,1597277485.827 [sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect](INFO): Uninitializing ESPCartridgeSelect.

+2020-08-13T00:11:25.827Z,1597277485.827 [sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge](INFO): Completed sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge

+2020-08-13T00:11:27.426Z,1597277487.426 [ESPComponent](IMPORTANT): powerUpESP IGNORED because manualEsp_

+2020-08-13T00:11:27.426Z,1597277487.426 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=30.0000)

+2020-08-13T00:11:30.227Z,1597277490.227 [ESPComponent](IMPORTANT): ESP has connected as client

+2020-08-13T00:11:31.028Z,1597277491.028 [ESPComponent](IMPORTANT): [sample #2] Setting cartridge argument to -4

+2020-08-13T00:11:31.028Z,1597277491.028 [ESPComponent](IMPORTANT): [sample #2] ESP sampling sequence starting. Sampling state: S_WAITING_INITIAL_PROMPT

+2020-08-13T00:11:31.428Z,1597277491.428 [sample:SampleAtDepth:SampleWrapper:SampleESP:C](ERROR): data element is not active.

+2020-08-13T00:11:31.428Z,1597277491.428 [sample:SampleAtDepth:SampleWrapper:SampleESP:C](IMPORTANT): ESP sampling at 0.001894 m inwater with nan ug/l chlorophyll fluorescence.

+2020-08-13T00:11:31.827Z,1597277491.827 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_PREPARING_SHOW_LOG

+2020-08-13T00:11:32.227Z,1597277492.227 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_PREPARING_SHOW_STATUS

+2020-08-13T00:11:34.228Z,1597277494.228 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_LOADING_CARTRIDGE

+2020-08-13T00:12:11.035Z,1597277531.035 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_WAITING_FOR_PRIMING (@55,archiveHiBiomass_bac)

+2020-08-13T00:12:12.636Z,1597277532.636 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_PRIMING (@5.0)

+2020-08-13T00:12:13.436Z,1597277533.436 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_WAITING_FOR_FILTERING (@5.0)

+2020-08-13T00:12:43.842Z,1597277563.842 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_FILTERING (@0.0)

+2020-08-13T00:12:44.242Z,1597277564.242 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_WAITING_FOR_PAUSED (@0.0)

+2020-08-13T00:12:59.845Z,1597277579.845 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_PAUSED (@10.0)

+2020-08-13T00:13:00.246Z,1597277580.246 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_PROCESSING (@10.0)

+2020-08-13T00:13:02.646Z,1597277582.646 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_WAITING_FOR_PROCESSED (@55,archiveHiBiomass_bac)

+2020-08-13T00:16:34.691Z,1597277794.691 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_STOPPING (@55,archiveHiBiomass_bac)

+2020-08-13T00:17:01.497Z,1597277821.497 [ESPComponent](IMPORTANT): Syncing ESP logs with command: rsync -azPq --timeout=60 carueda@bufflehead:'/var/log/carueda/simrapid.* /var/log/carueda/*.spr' /home/tethysadmin/workspace/lrauv-application-carlos/ESPlogs &

+2020-08-13T00:17:01.502Z,1597277821.502 [ESPComponent](INFO): closing pipe.

+2020-08-13T00:17:01.897Z,1597277821.897 [ESPComponent](IMPORTANT): [sample #2] ESP sampling state: S_STOPPED

+2020-08-13T00:17:11.899Z,1597277831.899 [ESPComponent](IMPORTANT): [sample #2] ESP sampling sequence completed normally.

+2020-08-13T00:17:11.900Z,1597277831.900 [sample:SampleAtDepth:SampleWrapper:SampleESP](INFO): Completed sample:SampleAtDepth:SampleWrapper:SampleESP

+2020-08-13T00:17:11.900Z,1597277831.900 [sample:SampleAtDepth:SampleWrapper](INFO): Completed sample:SampleAtDepth:SampleWrapper

+2020-08-13T00:17:11.900Z,1597277831.900 [sample:SampleAtDepth](INFO): Completed sample:SampleAtDepth

+2020-08-13T00:17:12.299Z,1597277832.299 [ESPComponent](IMPORTANT): [sample #2] ESP log summary report (2 messages):

+@17:11:36.97 Selecting Cartridge 55

+@17:12:58.37 Sampled  10.0ml

+2020-08-13T00:17:12.299Z,1597277832.299 [ESPComponent](IMPORTANT): powerDownESP IGNORED because manualEsp_

+2020-08-13T00:17:12.300Z,1597277832.300 [sample:SampleRepeater:Sample](INFO): Completed sample:SampleRepeater:Sample

+2020-08-13T00:17:12.300Z,1597277832.300 [sample:SampleRepeater](INFO): Completed sample:SampleRepeater

+2020-08-13T00:17:12.300Z,1597277832.300 [sample](INFO): Completed sample

+2020-08-13T00:17:12.300Z,1597277832.300 [MissionManager](INFO): sample is completed.

+2020-08-13T00:17:12.300Z,1597277832.300 [MissionManager](INFO): Uninitializing Mission sample

+2020-08-13T00:17:12.300Z,1597277832.300 [sample:A.AbortSample](INFO): Uninitializing AbortSample.

+2020-08-13T00:17:12.700Z,1597277832.700 [MissionManager](IMPORTANT): Started mission Default

+2020-08-13T00:17:12.700Z,1597277832.700 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.

+2020-08-13T00:17:25.902Z,1597277845.902 [Default:A.Wait](INFO): Done Waiting.

+tethyscode>quick on

+2020-08-13T00:17:29.514Z,1597277849.514 [CommandLine](IMPORTANT): got command quick on

+2020-08-13T00:17:29.514Z,1597277849.514 [CommandLine](IMPORTANT): Quicker than real-time state is on

+2020-08-13T00:17:31.103Z,1597277851.103 [NAL9602](INFO): GPS fix at 20200813T001731: (36.803540, -121.822477)

+2020-08-13T00:17:32.303Z,1597277852.303 [NAL9602](INFO): No messages in MT queue

+2020-08-13T00:17:35.039Z,1597277855.039 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20200812T235145/Courier0004.lzma

+2020-08-13T00:17:36.039Z,1597277856.039 [DataOverHttps](INFO): Moved sent file to Logs/20200812T235145/Courier0004.lzma.bak

+2020-08-13T00:17:36.039Z,1597277856.039 [DataOverHttps](INFO): SBD MOMSN=12551544

+2020-08-13T00:17:45.040Z,1597277865.040 [DataOverHttps](INFO): Sending 1376 bytes from file Logs/20200812T235145/Express0005.lzma

+2020-08-13T00:17:46.040Z,1597277866.040 [DataOverHttps](INFO): Moved sent file to Logs/20200812T235145/Express0005.lzma.bak

+2020-08-13T00:17:46.040Z,1597277866.040 [DataOverHttps](INFO): SBD MOMSN=12551547

+2020-08-13T00:18:02.710Z,1597277882.710 [NAL9602](INFO): Not Powering down - fast GPS

+tethyscode>exit

```

+**Note**: `quick on` issued above after to completion of the mission just to quickly make the vehicle send all data/events to the dash.

 ### Captured ESP.log on vehicle side (tethyscode)

 Below are the contents of the `ESP.log` file as captured by the LRAUV.

-Note, it shows all ESP streams due to my local config having `ESPComponent.debug = 1 bool`:

+Note, it shows all ESP streams due to local config having `ESPComponent.debug = 1 bool`:

```

-[tethysadmin@tethyscode lrauv-application]$ cat Logs/latest/ESP.log

-##-- file opened 2020-08-12T20:39:02.361Z

+tethysadmin@tethyscode: lrauv-application-carlos$ cat Logs/latest/ESP.log

+##-- file opened 2020-08-12T23:56:03.206Z

 <unknown> LRAUV

 <unknown> \200

  <prompt> \200

  <prompt> \204

-    <log> @13:39:03.56 -> showStatus

+    <log> @16:56:04.40 -> showStatus

     <log> \201

  <result> true\200

  <prompt> \204

-    <log> @13:39:05.16 -> Cmd.loadCartridge -4

+    <log> @16:56:06.00 -> Cmd.loadCartridge -4

     <log> \207

  <status> STOPPED-->IDLE

  <status> \204

-    <log> Gate.power :main,:ON

+    <log> @16:56:06.01 Gate.power :main,:ON

     <log> Gate.power :analytic1,:ON

     <log> Gate.power :analytic2,:ON

-    <log> @13:39:05.17 Gate.power :analytic3,:ON

+    <log> Gate.power :analytic3,:ON

     <log> Gate.power :core,:ON

-    <log> @13:39:05.18 Archive.configure :default

-    <log> @13:39:05.19 Air.configure :default

-    <log> Lysis1.configure :default

-    <log> @13:39:05.20 Lysis2.configure :default

-    <log> Plunge.configure :default

-    <log> @13:39:05.21 SamplePump.configure :default

+    <log> @16:56:06.03 Archive.configure :default

+    <log> Air.configure :default

+    <log> @16:56:06.04 Lysis1.configure :default

+    <log> @16:56:06.05 Lysis2.configure :default

+    <log> @16:56:06.06 Plunge.configure :default

+    <log> @16:56:06.07 SamplePump.configure :default

     <log> ExtraPump.configure :default

-    <log> @13:39:05.22 Toroid.configure :default

-    <log> Carousel.configure :default

-    <log> @13:39:05.23 Pressure.configure :default

-    <log> PinPort.configure :default

+    <log> @16:56:06.08 Toroid.configure :default

+    <log> @16:56:06.09 Carousel.configure :default

+    <log> Pressure.configure :default

+    <log> @16:56:06.10 PinPort.configure :default

     <log> All elf controllers running firmware version 4.99

-    <log> @13:39:05.24 Gate.power :motor,:ON

-    <log> @13:39:05.25 <Archive_home> Archive.reconfigure :default

-    <log> @13:39:05.26 Archive.home.jog 0

+    <log> Gate.power :motor,:ON

+    <log> @16:56:06.11 <Archive_home> Archive.reconfigure :default

+    <log> @16:56:06.12 Archive.home.jog 0

     <log> <Air_home> Air.reconfigure :default

-    <log> @13:39:05.27 Air.home.jog 0

-    <log> <Lysis1_home> Lysis1.reconfigure :default

-    <log> @13:39:05.28 <Lysis2_home> Lysis2.reconfigure :default

+    <log> @16:56:06.13 Air.home.jog 0

+    <log> @16:56:06.14 <Lysis1_home> Lysis1.reconfigure :default

+    <log> <Lysis2_home> Lysis2.reconfigure :default

     <log> <Lysis1_home> Lysis1.home.jog 0

     <log> <Plunge_home> Plunge.reconfigure :default

-    <log> <Lysis2_home> Lysis2.home.jog 0

-    <log> @13:39:05.29 <PinPort_home> PinPort.reconfigure :default

+    <log> @16:56:06.15 <Lysis2_home> Lysis2.home.jog 0

+    <log> <PinPort_home> PinPort.reconfigure :default

     <log> <Plunge_home> Plunge.home.jog 0

-    <log> <Toroid_home> Toroid.reconfigure :default

-    <log> @13:39:05.30 <PinPort_home> PinPort.home.jog 0

+    <log> @16:56:06.16 <Toroid_home> Toroid.reconfigure :default

+    <log> <PinPort_home> PinPort.home.jog 0

     <log> <Toroid_home> Toroid.home.jog 0

-    <log> @13:39:05.34 <Archive_home> Archive.setRawPosition! 50

+    <log> @16:56:06.20 <Archive_home> Archive.setRawPosition! 50

     <log> Archive.reconfigure :homing

-    <log> @13:39:05.35 Archive.seek :home

-    <log> <Air_home> Air.setRawPosition! 50

+    <log> @16:56:06.21 Archive.seek :home

+    <log> @16:56:06.22 <Air_home> Air.setRawPosition! 50

     <log> Air.reconfigure :homing

-    <log> @13:39:05.36 Air.seek :home

-    <log> @13:39:05.37 <Plunge_home> Plunge.setRawPosition! 50

+    <log> Air.seek :home

+    <log> @16:56:06.23 <Plunge_home> Plunge.setRawPosition! 50

     <log> Plunge.reconfigure :homing

     <log> Plunge.seek :home

-    <log> @13:39:05.38 <PinPort_home> PinPort.setRawPosition! 0

-    <log> PinPort.reconfigure :homing

-    <log> @13:39:05.39 PinPort.seek :home

-    <log> @13:39:05.40 <Lysis1_home> Lysis1.setRawPosition! 50

+    <log> @16:56:06.24 <PinPort_home> PinPort.setRawPosition! 0

+    <log> @16:56:06.25 PinPort.reconfigure :homing

+    <log> PinPort.seek :home

+    <log> @16:56:06.26 <Lysis1_home> Lysis1.setRawPosition! 50

     <log> Lysis1.reconfigure :homing

     <log> Lysis1.seek :home

-    <log> @13:39:05.41 <Lysis2_home> Lysis2.setRawPosition! 50

+    <log> @16:56:06.27 <Lysis2_home> Lysis2.setRawPosition! 50

     <log> Lysis2.reconfigure :homing

-    <log> @13:39:05.42 Lysis2.seek :home

-    <log> @13:39:05.43 <Toroid_home> Toroid.setRawPosition! 0

+    <log> @16:56:06.28 Lysis2.seek :home

+    <log> @16:56:06.29 <Toroid_home> Toroid.setRawPosition! 0

     <log> Toroid.reconfigure :homing

     <log> Toroid.seek :home

-    <log> @13:39:05.46 <PinPort_home> PinPort.reconfigure :default

-    <log> @13:39:05.50 <Toroid_home> Toroid.reconfigure :default

-    <log> @13:39:05.62 <Archive_home> Archive.reconfigure :default

-    <log> @13:39:05.63 <Air_home> Air.reconfigure :default

-    <log> @13:39:05.65 <Plunge_home> Plunge.reconfigure :default

-    <log> @13:39:05.68 <Lysis1_home> Lysis1.reconfigure :default

-    <log> @13:39:05.69 <Lysis2_home> Lysis2.reconfigure :default

-    <log> @13:39:05.95 <LRAUV> Toroid.seek :clear

-    <log> @13:39:07.56 Carousel.reconfigure :default

-    <log> @13:39:07.57 Carousel.home.jog 0

-    <log> @13:39:07.64 Carousel.setRawPosition! -53

-    <log> Carousel.reconfigure :homing

+    <log> @16:56:06.32 <PinPort_home> PinPort.reconfigure :default

+    <log> @16:56:06.36 <Toroid_home> Toroid.reconfigure :default

+    <log> @16:56:06.48 <Archive_home> Archive.reconfigure :default

+    <log> @16:56:06.50 <Air_home> Air.reconfigure :default

+    <log> @16:56:06.51 <Plunge_home> Plunge.reconfigure :default

+    <log> @16:56:06.54 <Lysis1_home> Lysis1.reconfigure :default

+    <log> @16:56:06.55 <Lysis2_home> Lysis2.reconfigure :default

+    <log> @16:56:06.81 <LRAUV> Toroid.seek :clear

+    <log> @16:56:08.43 Carousel.reconfigure :default

+    <log> Carousel.home.jog 0

+    <log> @16:56:08.50 Carousel.setRawPosition! -53

+    <log> @16:56:08.51 Carousel.reconfigure :homing

     <log> Carousel.seek :home

-    <log> @13:39:07.95 Carousel.reconfigure :default

-    <log> @13:39:08.20 Carousel.seek 1

+    <log> @16:56:08.81 Carousel.reconfigure :default

+    <log> @16:56:09.07 Carousel.seek 1

     <log> \207

  <status> IDLE-->LOADING

- <status> LOADING-->LOADING@58,archiveHiBiomass_bac

+ <status> LOADING-->LOADING@56,archiveHiBiomass_bac

  <status> \204

-    <log> @13:39:08.27 Selecting Cartridge 58

-    <log> @13:39:08.28 Carousel.seek 58

-    <log> @13:39:20.13 Gate.power :heat,:OFF

-    <log> @13:39:20.14 Gate.power :cartridge,:OFF

-    <log> Lysis1.seek :locked

-    <log> @13:39:24.21 <Plunge> Plunge.seek :locked

-    <log> @13:39:24.22 <Air> Air.seek :locked

-    <log> @13:39:28.28 <LRAUV> Gate.power :cartridge,:ON

-    <log> @13:39:28.29 Gate.power :cartridge,:OFF

+    <log> @16:56:09.14 Selecting Cartridge 56

+    <log> @16:56:09.15 Carousel.seek 56

+    <log> @16:56:20.59 Gate.power :heat,:OFF

+    <log> Gate.power :cartridge,:OFF

+    <log> @16:56:20.60 Lysis1.seek :locked

+    <log> @16:56:24.67 <Plunge> Plunge.seek :locked

+    <log> <Air> Air.seek :locked

+    <log> @16:56:28.74 <LRAUV> Gate.power :cartridge,:ON

+    <log> Gate.power :cartridge,:OFF

     <log> Gate.power :cartridge,:OFF

-    <log> @13:39:28.79 Mounted archive Cartridge

+    <log> @16:56:29.25 Mounted archive Cartridge

     <log> \207

- <status> LOADING-->READY@58,archiveHiBiomass_bac

+ <status> LOADING-->READY@56,archiveHiBiomass_bac

  <status> \201

- <result> 58\200

+ <result> 56\200

  <prompt> \204

-    <log> @13:39:41.97 -> Cmd.startFiltering

+    <log> @16:56:42.81 -> Cmd.startFiltering

     <log> \207

  <status> READY-->PRIMING@5.0

  <status> \201

  <result> :FILTERING\200

  <prompt> \204

-    <log> @13:39:41.98 <FILTERING> Duration of filtering limited to 2:05:00

-    <log> @13:39:41.99 Priming sample loop w/5ml, bypass w/1.5ml

+    <log> @16:56:42.82 <FILTERING> Duration of filtering limited to 2:05:00

+    <log> @16:56:42.83 Priming sample loop w/5ml, bypass w/1.5ml

     <log> SamplePump.setPosition! 0ml

     <log> Bypass.open

-    <log> @13:39:42.70 Intake.open

-    <log> @13:39:44.20 Sea 5.7m deep (23.1psia)

+    <log> @16:56:43.54 Intake.open

+    <log> @16:56:45.04 Sea 5.7m deep (23.1psia)

     <log> Waiting up to 20 seconds for sea pressure to stabilize +/-0.50psi

-    <log> @13:39:46.72 Vacuum tare is 10% of full scale

+    <log> @16:56:47.56 Vacuum tare is 10% of full scale

     <log> Pressure.reconfigure :default

-    <log> @13:39:46.73 Pressure.hold

-    <log> @13:39:46.81 SamplePump.reconfigure :prime

+    <log> Pressure.hold

+    <log> @16:56:47.64 SamplePump.reconfigure :prime

     <log> SamplePump.seek 1.5ml,38 seconds

-    <log> @13:39:48.58 Pressure.coast

+    <log> @16:56:49.41 Pressure.coast

     <log> SamplePump.setPosition! 0ml

     <log> Exhaust.open

-    <log> @13:39:50.78 <closeBypass> Bypass.close

-    <log> @13:39:52.99 <FILTERING> Pressure.hold

-    <log> @13:39:53.06 Sea 5.7m deep (23.1psia)

+    <log> @16:56:51.61 <closeBypass> Bypass.close

+    <log> @16:56:53.82 <FILTERING> Pressure.hold

+    <log> @16:56:53.89 Sea 5.7m deep (23.1psia)

     <log> SamplePump.reconfigure :prime

-    <log> @13:39:53.07 SamplePump.seek 5ml,56 seconds

-    <log> @13:39:57.80 Pressure.coast

+    <log> SamplePump.seek 5ml,56 seconds

+    <log> @16:56:58.63 Pressure.coast

     <log> Bypass.open

-    <log> @13:39:59.30 Intake.close

-    <log> @13:40:00.80 Toroid.reconfigure :hold

+    <log> @16:57:00.13 Intake.close

+    <log> @16:57:01.63 Toroid.reconfigure :hold

     <log> Toroid.seek :crack

-    <log> @13:40:01.60 Toroid.reconfigure :default

+    <log> @16:57:02.43 Toroid.reconfigure :default

     <log> Toroid.seek :clear

-    <log> @13:40:03.11 Toroid.reconfigure :hold

+    <log> @16:57:03.93 Toroid.reconfigure :hold

     <log> Toroid.seek :cartridge

-    <log> @13:40:04.92 Toroid.reconfigure :default

+    <log> @16:57:05.75 Toroid.reconfigure :default

     <log> Toroid.seek :clear

-    <log> @13:40:06.75 Pressurizing cartridge to 26psi above 23.1psia

+    <log> @16:57:07.57 Pressurizing cartridge to 26psi above 23.1psia

     <log> SamplePump.setPosition! 0ml

     <log> Intake.open

-    <log> @13:40:08.24 Bypass.close

-    <log> @13:40:09.74 Exhaust.close

-    <log> @13:40:11.24 Pressure.hold

-    <log> @13:40:11.35 SamplePump.reconfigure :charge

+    <log> @16:57:09.06 Bypass.close

+    <log> @16:57:10.60 Exhaust.close

+    <log> @16:57:12.07 Pressure.hold

+    <log> @16:57:12.14 SamplePump.reconfigure :charge

     <log> SamplePump.seek 0.2ml,32 seconds

-    <log> @13:40:11.96 Pressure.coast

+    <log> @16:57:12.75 Pressure.coast

     <log> Sampling 10.0ml

     <log> SamplePump.setPosition! 0ml

-    <log> @13:40:11.97 Exhaust.open

+    <log> Exhaust.open

     <log> \207

  <status> PRIMING-->FILTERING@0.0

  <status> \204

-    <log> @13:40:13.46 Pressure.hold

-    <log> @13:40:13.54 Sea 5.7m deep (23.1psia)

-    <log> SamplePump.reconfigure :sample

+    <log> @16:57:14.25 Pressure.hold

+    <log> @16:57:14.32 Sea 5.7m deep (23.1psia)

+    <log> @16:57:14.33 SamplePump.reconfigure :sample

     <log> SamplePump.seek 10ml,1:21

-    <log> @13:40:16.47 <sampling> Cartridge 58 sampling 2/10ml at 0.83ml/s with 0.0psi vacuum 5.7m deep (23.1psia)

-    <log> @13:40:26.51 <FILTERING> Pressure.coast

-    <log> <closeIntake> Intake.close

+    <log> @16:57:17.25 <sampling> Cartridge 56 sampling 2/10ml at 0.83ml/s with 0.0psi vacuum 5.7m deep (23.1psia)

+    <log> @16:57:27.29 <FILTERING> Pressure.coast

+    <log> @16:57:27.30 <closeIntake> Intake.close

     <log> <closeExhaust> Exhaust.close

-    <log> @13:40:26.52 <FILTERING> Toroid.reconfigure :hold

+    <log> @16:57:27.31 <FILTERING> Toroid.reconfigure :hold

     <log> Toroid.seek :bypass

-    <log> @13:40:28.14 Toroid.reconfigure :default

-    <log> Toroid.seek :clear

-    <log> @13:40:29.75 Sampled  10.0ml

+    <log> @16:57:28.92 Toroid.reconfigure :default

+    <log> @16:57:28.93 Toroid.seek :clear

+    <log> @16:57:30.54 Sampled  10.0ml

     <log> \207

  <status> FILTERING-->PAUSED@10.0

  <status> \204

-    <log> @13:40:31.18 <LRAUV> -> Cmd.startProcessing

+    <log> @16:57:32.02 <LRAUV> -> Cmd.startProcessing

     <log> \207

- <status> PAUSED-->PROCESSING@58,archiveHiBiomass_bac

+ <status> PAUSED-->PROCESSING@56,archiveHiBiomass_bac

  <status> \201

  <result> :PROCESSING\200

  <prompt> \204

-    <log> @13:40:31.19 <PROCESSING> Plunge.seek :reagent

-    <log> @13:40:32.03 Sample loop closed. Ready to Deliver Reagents

+    <log> @16:57:32.03 <PROCESSING> Plunge.seek :reagent

+    <log> @16:57:32.87 Sample loop closed. Ready to Deliver Reagents

     <log> Archive.seek :sealed

-    <log> @13:40:36.30 Archive.seek :evac

-    <log> @13:40:50.28 delay 1:00

-    <log> @13:41:50.29 Archive.seek :clear

-    <log> @13:42:08.05 RNAlater soak for 45 seconds

-    <log> @13:42:53.06 Archive.seek :tVent

-    <log> @13:42:55.64 delay 1 second

-    <log> @13:42:56.64 Archive.seek :evac

-    <log> @13:43:12.31 delay 10 seconds

-    <log> @13:43:22.32 Archive.seek :tVent

-    <log> @13:43:37.99 delay 1 second

-    <log> @13:43:38.99 Archive.seek :evac

-    <log> @13:43:54.66 delay 10 seconds

-    <log> @13:44:04.66 Sample preserved and evacuated

+    <log> @16:57:37.14 Archive.seek :evac

+    <log> @16:57:51.12 delay 1:00

+    <log> @16:58:51.13 Archive.seek :clear

+    <log> @16:59:08.89 RNAlater soak for 45 seconds

+    <log> @16:59:53.90 Archive.seek :tVent

+    <log> @16:59:56.48 delay 1 second

+    <log> @16:59:57.48 Archive.seek :evac

+    <log> @17:00:13.14 delay 10 seconds

+    <log> @17:00:23.15 Archive.seek :tVent

+    <log> @17:00:38.82 delay 1 second

+    <log> @17:00:39.82 Archive.seek :evac

+    <log> @17:00:55.49 delay 10 seconds

+    <log> @17:01:05.50 Sample preserved and evacuated

     <log> \207

- <status> PROCESSING-->PROCESSED@58,archiveHiBiomass_bac

+ <status> PROCESSING-->PROCESSED@56,archiveHiBiomass_bac

  <status> \204

-    <log> @13:44:05.63 <LRAUV> -> Cmd.stop

-    <log> @13:44:05.64 Gate.power :heat,:OFF

-    <log> Gate.power :cartridge,:OFF

-    <log> Carousel.seek 58

-    <log> @13:44:05.72 Plunge.seek :locked

-    <log> @13:44:06.55 PinPort.seek :clear

-    <log> @13:44:06.62 <Archive> Archive.seek :clear

-    <log> @13:44:06.63 <Air> Air.seek :clear

-    <log> @13:44:06.65 <Lysis1> Lysis1.seek :clear

-    <log> @13:44:24.39 <LRAUV> Archive.coast

+    <log> @17:01:06.47 <LRAUV> -> Cmd.stop

+    <log> Gate.power :heat,:OFF

+    <log> @17:01:06.48 Gate.power :cartridge,:OFF

+    <log> Carousel.seek 56

+    <log> @17:01:06.55 Plunge.seek :locked

+    <log> @17:01:07.39 PinPort.seek :clear

+    <log> @17:01:07.46 <Archive> Archive.seek :clear

+    <log> <Air> Air.seek :clear

+    <log> @17:01:07.48 <Lysis1> Lysis1.seek :clear

+    <log> @17:01:25.23 <LRAUV> Archive.coast

     <log> Air.coast

-    <log> @13:44:24.40 Lysis1.coast

+    <log> Lysis1.coast

     <log> Lysis2.coast

-    <log> Plunge.coast

+    <log> @17:01:25.24 Plunge.coast

     <log> SamplePump.coast

     <log> Toroid.coast

-    <log> @13:44:24.41 Carousel.coast

+    <log> Carousel.coast

     <log> PinPort.coast

-    <log> @13:44:24.42 Gate.power :heat,:OFF

-    <log> @13:44:24.43 Gate.power :cartridge,:OFF

-    <log> @13:44:24.48 Gate.power :motor,:OFF

+    <log> @17:01:25.26 Gate.power :heat,:OFF

+    <log> Gate.power :cartridge,:OFF

+    <log> @17:01:25.31 Gate.power :motor,:OFF

     <log> Gate.power :core,:OFF

     <log> Gate.power :analytic1,:OFF

-    <log> Gate.power :analytic2,:OFF

+    <log> @17:01:25.32 Gate.power :analytic2,:OFF

     <log> Gate.power :analytic3,:OFF

-    <log> @13:44:24.49 Gate.power :main,:OFF

+    <log> Gate.power :main,:OFF

     <log> Safely stopped and ready to power off

     <log> \207

  <status> PROCESSED-->STOPPED

  <status> \201

  <result> :STOPPED\200

  <prompt> 7777

-##-- file closed 2020-08-12T20:59:20.692Z

+##-- file closed 2020-08-13T00:11:31.027Z

-##-- file opened 2020-08-12T20:59:20.692Z

+##-- file opened 2020-08-13T00:11:31.028Z

  <prompt> LRAUV

  <prompt> \200

  <prompt> \200

  <prompt> \204

-    <log> @13:59:21.49 -> showStatus

+    <log> @17:11:31.82 -> showStatus

     <log> \201

  <result> true\200

  <prompt> \204

-    <log> @13:59:23.49 -> Cmd.loadCartridge -4

+    <log> @17:11:33.82 -> Cmd.loadCartridge -4

     <log> \207

  <status> STOPPED-->IDLE

  <status> \204

-    <log> Gate.power :main,:ON

+    <log> @17:11:33.83 Gate.power :main,:ON

     <log> Gate.power :analytic1,:ON

     <log> Gate.power :analytic2,:ON

     <log> Gate.power :analytic3,:ON

-    <log> Gate.power :core,:ON

-    <log> @13:59:23.50 Archive.configure :default

-    <log> @13:59:23.51 Air.configure :default

-    <log> Lysis1.configure :default

-    <log> @13:59:23.52 Lysis2.configure :default

-    <log> Plunge.configure :default

-    <log> @13:59:23.53 SamplePump.configure :default

+    <log> @17:11:33.84 Gate.power :core,:ON

+    <log> @17:11:33.85 Archive.configure :default

+    <log> Air.configure :default

+    <log> @17:11:33.86 Lysis1.configure :default

+    <log> @17:11:33.87 Lysis2.configure :default

+    <log> @17:11:33.88 Plunge.configure :default

+    <log> @17:11:33.89 SamplePump.configure :default

     <log> ExtraPump.configure :default

-    <log> @13:59:23.54 Toroid.configure :default

-    <log> Carousel.configure :default

-    <log> @13:59:23.55 Pressure.configure :default

-    <log> PinPort.configure :default

-    <log> @13:59:23.56 All elf controllers running firmware version 4.99

+    <log> @17:11:33.90 Toroid.configure :default

+    <log> @17:11:33.91 Carousel.configure :default

+    <log> @17:11:33.92 Pressure.configure :default

+    <log> @17:11:33.93 PinPort.configure :default

+    <log> All elf controllers running firmware version 4.99

     <log> Gate.power :motor,:ON

-    <log> @13:59:23.57 <Archive_home> Archive.reconfigure :default

-    <log> @13:59:23.58 Archive.home.jog 0

+    <log> @17:11:33.94 <Archive_home> Archive.reconfigure :default

+    <log> @17:11:33.95 Archive.home.jog 0

     <log> <Air_home> Air.reconfigure :default

-    <log> @13:59:23.59 Air.home.jog 0

+    <log> @17:11:33.96 Air.home.jog 0

     <log> <Lysis1_home> Lysis1.reconfigure :default

-    <log> @13:59:23.60 <Lysis2_home> Lysis2.reconfigure :default

+    <log> @17:11:33.97 <Lysis2_home> Lysis2.reconfigure :default

     <log> <Lysis1_home> Lysis1.home.jog 0

-    <log> <Lysis2_home> Lysis2.home.jog 0

-    <log> @13:59:23.61 <Plunge_home> Plunge.reconfigure :default

-    <log> <PinPort_home> PinPort.reconfigure :default

+    <log> <Plunge_home> Plunge.reconfigure :default

+    <log> @17:11:33.98 <Lysis2_home> Lysis2.home.jog 0

     <log> <Plunge_home> Plunge.home.jog 0

-    <log> <Toroid_home> Toroid.reconfigure :default

-    <log> @13:59:23.62 <PinPort_home> PinPort.home.jog 0

+    <log> <PinPort_home> PinPort.reconfigure :default

+    <log> @17:11:33.99 <Toroid_home> Toroid.reconfigure :default

+    <log> <PinPort_home> PinPort.home.jog 0

     <log> <Toroid_home> Toroid.home.jog 0

-    <log> @13:59:23.66 <Archive_home> Archive.setRawPosition! 50

+    <log> @17:11:34.03 <Archive_home> Archive.setRawPosition! 50

     <log> Archive.reconfigure :homing

-    <log> @13:59:23.67 Archive.seek :home

-    <log> <Air_home> Air.setRawPosition! 50

-    <log> @13:59:23.68 Air.reconfigure :homing

+    <log> @17:11:34.04 Archive.seek :home

+    <log> @17:11:34.05 <Air_home> Air.setRawPosition! 50

+    <log> Air.reconfigure :homing

     <log> Air.seek :home

-    <log> @13:59:23.69 <Plunge_home> Plunge.setRawPosition! 50

+    <log> @17:11:34.06 <Plunge_home> Plunge.setRawPosition! 50

     <log> Plunge.reconfigure :homing

-    <log> @13:59:23.70 Plunge.seek :home

-    <log> <PinPort_home> PinPort.setRawPosition! 0

-    <log> @13:59:23.71 PinPort.reconfigure :homing

+    <log> Plunge.seek :home

+    <log> @17:11:34.07 <PinPort_home> PinPort.setRawPosition! 0

+    <log> @17:11:34.08 PinPort.reconfigure :homing

     <log> PinPort.seek :home

-    <log> @13:59:23.72 <Lysis1_home> Lysis1.setRawPosition! 50

+    <log> @17:11:34.09 <Lysis1_home> Lysis1.setRawPosition! 50

     <log> Lysis1.reconfigure :homing

-    <log> @13:59:23.73 Lysis1.seek :home

-    <log> @13:59:23.74 <Lysis2_home> Lysis2.setRawPosition! 50

+    <log> Lysis1.seek :home

+    <log> @17:11:34.11 <Lysis2_home> Lysis2.setRawPosition! 50

     <log> Lysis2.reconfigure :homing

     <log> Lysis2.seek :home

-    <log> @13:59:23.75 <Toroid_home> Toroid.setRawPosition! 0

+    <log> @17:11:34.12 <Toroid_home> Toroid.setRawPosition! 0

     <log> Toroid.reconfigure :homing

-    <log> @13:59:23.76 Toroid.seek :home

-    <log> @13:59:23.78 <PinPort_home> PinPort.reconfigure :default

-    <log> @13:59:23.83 <Toroid_home> Toroid.reconfigure :default

-    <log> @13:59:23.94 <Archive_home> Archive.reconfigure :default

-    <log> @13:59:23.96 <Air_home> Air.reconfigure :default

-    <log> @13:59:23.97 <Plunge_home> Plunge.reconfigure :default

-    <log> @13:59:24.00 <Lysis1_home> Lysis1.reconfigure :default

-    <log> @13:59:24.02 <Lysis2_home> Lysis2.reconfigure :default

-    <log> @13:59:24.27 <LRAUV> Toroid.seek :clear

-    <log> @13:59:25.89 Carousel.reconfigure :default

+    <log> Toroid.seek :home

+    <log> @17:11:34.15 <PinPort_home> PinPort.reconfigure :default

+    <log> @17:11:34.20 <Toroid_home> Toroid.reconfigure :default

+    <log> @17:11:34.31 <Archive_home> Archive.reconfigure :default

+    <log> @17:11:34.33 <Air_home> Air.reconfigure :default

+    <log> @17:11:34.34 <Plunge_home> Plunge.reconfigure :default

+    <log> @17:11:34.37 <Lysis1_home> Lysis1.reconfigure :default

+    <log> @17:11:34.39 <Lysis2_home> Lysis2.reconfigure :default

+    <log> @17:11:34.64 <LRAUV> Toroid.seek :clear

+    <log> @17:11:36.26 Carousel.reconfigure :default

     <log> Carousel.home.jog 0

-    <log> @13:59:25.97 Carousel.setRawPosition! -53

+    <log> @17:11:36.33 Carousel.setRawPosition! -53

     <log> Carousel.reconfigure :homing

-    <log> Carousel.seek :home

-    <log> @13:59:26.27 Carousel.reconfigure :default

-    <log> @13:59:26.53 Carousel.seek 1

+    <log> @17:11:36.34 Carousel.seek :home

+    <log> @17:11:36.64 Carousel.reconfigure :default

+    <log> @17:11:36.89 Carousel.seek 1

     <log> \207

  <status> IDLE-->LOADING

- <status> LOADING-->LOADING@57,archiveHiBiomass_bac

+ <status> LOADING-->LOADING@55,archiveHiBiomass_bac

  <status> \204

-    <log> @13:59:26.60 Selecting Cartridge 57

-    <log> @13:59:26.61 Carousel.seek 57

-    <log> @13:59:38.25 Gate.power :heat,:OFF

+    <log> @17:11:36.97 Selecting Cartridge 55

+    <log> @17:11:36.98 Carousel.seek 55

+    <log> @17:11:48.21 Gate.power :heat,:OFF

     <log> Gate.power :cartridge,:OFF

-    <log> @13:59:38.26 Lysis1.seek :locked

-    <log> @13:59:42.33 <Plunge> Plunge.seek :locked

+    <log> @17:11:48.22 Lysis1.seek :locked

+    <log> @17:11:52.29 <Plunge> Plunge.seek :locked

     <log> <Air> Air.seek :locked

-    <log> @13:59:46.40 <LRAUV> Gate.power :cartridge,:ON

+    <log> @17:11:56.36 <LRAUV> Gate.power :cartridge,:ON

     <log> Gate.power :cartridge,:OFF

     <log> Gate.power :cartridge,:OFF

-    <log> @13:59:46.90 Mounted archive Cartridge

+    <log> @17:11:56.86 Mounted archive Cartridge

     <log> \207

- <status> LOADING-->READY@57,archiveHiBiomass_bac

+ <status> LOADING-->READY@55,archiveHiBiomass_bac

  <status> \201

- <result> 57\200

+ <result> 55\200

  <prompt> \204

-    <log> @14:00:00.30 -> Cmd.startFiltering

+    <log> @17:12:10.63 -> Cmd.startFiltering

     <log> \207

  <status> READY-->PRIMING@5.0

  <status> \201

  <result> :FILTERING\200

  <prompt> \204

-    <log> @14:00:00.31 <FILTERING> Duration of filtering limited to 2:05:00

-    <log> @14:00:00.32 Priming sample loop w/5ml, bypass w/1.5ml

+    <log> @17:12:10.64 <FILTERING> Duration of filtering limited to 2:05:00

+    <log> @17:12:10.65 Priming sample loop w/5ml, bypass w/1.5ml

     <log> SamplePump.setPosition! 0ml

     <log> Bypass.open

-    <log> @14:00:01.03 Intake.open

-    <log> @14:00:02.53 Sea 5.7m deep (23.1psia)

+    <log> @17:12:11.36 Intake.open

+    <log> @17:12:12.86 Sea 5.7m deep (23.1psia)

     <log> Waiting up to 20 seconds for sea pressure to stabilize +/-0.50psi

-    <log> @14:00:05.05 Vacuum tare is 10% of full scale

-    <log> @14:00:05.06 Pressure.reconfigure :default

+    <log> @17:12:15.38 Vacuum tare is 10% of full scale

+    <log> @17:12:15.39 Pressure.reconfigure :default

     <log> Pressure.hold

-    <log> @14:00:05.14 SamplePump.reconfigure :prime

+    <log> @17:12:15.46 SamplePump.reconfigure :prime

     <log> SamplePump.seek 1.5ml,38 seconds

-    <log> @14:00:06.91 Pressure.coast

+    <log> @17:12:17.23 Pressure.coast

     <log> SamplePump.setPosition! 0ml

-    <log> @14:00:06.92 Exhaust.open

-    <log> @14:00:09.11 <closeBypass> Bypass.close

-    <log> @14:00:11.32 <FILTERING> Pressure.hold

-    <log> @14:00:11.39 Sea 5.7m deep (23.1psia)

-    <log> @14:00:11.40 SamplePump.reconfigure :prime

+    <log> @17:12:17.24 Exhaust.open

+    <log> @17:12:19.43 <closeBypass> Bypass.close

+    <log> @17:12:21.64 <FILTERING> Pressure.hold

+    <log> @17:12:21.71 Sea 5.7m deep (23.1psia)

+    <log> @17:12:21.72 SamplePump.reconfigure :prime

     <log> SamplePump.seek 5ml,56 seconds

-    <log> @14:00:16.14 Pressure.coast

+    <log> @17:12:26.45 Pressure.coast

     <log> Bypass.open

-    <log> @14:00:17.63 Intake.close

-    <log> @14:00:19.14 Toroid.reconfigure :hold

+    <log> @17:12:27.95 Intake.close

+    <log> @17:12:29.45 Toroid.reconfigure :hold

     <log> Toroid.seek :crack

-    <log> @14:00:19.94 Toroid.reconfigure :default

+    <log> @17:12:30.25 Toroid.reconfigure :default

     <log> Toroid.seek :clear

-    <log> @14:00:21.44 Toroid.reconfigure :hold

+    <log> @17:12:31.76 Toroid.reconfigure :hold

     <log> Toroid.seek :cartridge

-    <log> @14:00:23.26 Toroid.reconfigure :default

+    <log> @17:12:33.57 Toroid.reconfigure :default

     <log> Toroid.seek :clear

-    <log> @14:00:25.08 Pressurizing cartridge to 26psi above 23.1psia

+    <log> @17:12:35.39 Pressurizing cartridge to 26psi above 23.1psia

     <log> SamplePump.setPosition! 0ml

-    <log> Intake.open

-    <log> @14:00:26.57 Bypass.close

-    <log> @14:00:28.07 Exhaust.close

-    <log> @14:00:29.62 Pressure.hold

-    <log> @14:00:29.69 SamplePump.reconfigure :charge

+    <log> @17:12:35.40 Intake.open

+    <log> @17:12:36.89 Bypass.close

+    <log> @17:12:38.39 Exhaust.close

+    <log> @17:12:39.89 Pressure.hold

+    <log> @17:12:39.97 SamplePump.reconfigure :charge

     <log> SamplePump.seek 0.2ml,32 seconds

-    <log> @14:00:30.29 Pressure.coast

-    <log> @14:00:30.30 Sampling 10.0ml

+    <log> @17:12:40.57 Pressure.coast

+    <log> @17:12:40.58 Sampling 10.0ml

     <log> SamplePump.setPosition! 0ml

     <log> Exhaust.open

     <log> \207

  <status> PRIMING-->FILTERING@0.0

  <status> \204

-    <log> @14:00:31.80 Pressure.hold

-    <log> @14:00:31.88 Sea 5.7m deep (23.1psia)

+    <log> @17:12:42.08 Pressure.hold

+    <log> @17:12:42.15 Sea 5.7m deep (23.1psia)

     <log> SamplePump.reconfigure :sample

-    <log> @14:00:31.89 SamplePump.seek 10ml,1:21

-    <log> @14:00:34.81 <sampling> Cartridge 57 sampling 2/10ml at 0.83ml/s with 0.0psi vacuum 5.7m deep (23.1psia)

-    <log> @14:00:44.85 <FILTERING> Pressure.coast

+    <log> @17:12:42.16 SamplePump.seek 10ml,1:21

+    <log> @17:12:45.08 <sampling> Cartridge 55 sampling 2/10ml at 0.83ml/s with 0.0psi vacuum 5.7m deep (23.1psia)

+    <log> @17:12:55.12 <FILTERING> Pressure.coast

     <log> <closeIntake> Intake.close

-    <log> @14:00:44.86 <closeExhaust> Exhaust.close

+    <log> @17:12:55.13 <closeExhaust> Exhaust.close

     <log> <FILTERING> Toroid.reconfigure :hold

     <log> Toroid.seek :bypass

-    <log> @14:00:46.48 Toroid.reconfigure :default

+    <log> @17:12:56.75 Toroid.reconfigure :default

     <log> Toroid.seek :clear

-    <log> @14:00:48.10 Sampled  10.0ml

+    <log> @17:12:58.37 Sampled  10.0ml

     <log> \207

  <status> FILTERING-->PAUSED@10.0

  <status> \204

-    <log> @14:00:49.51 <LRAUV> -> Cmd.startProcessing

+    <log> @17:12:59.84 <LRAUV> -> Cmd.startProcessing

     <log> \207

- <status> PAUSED-->PROCESSING@57,archiveHiBiomass_bac

+ <status> PAUSED-->PROCESSING@55,archiveHiBiomass_bac

  <status> \201

  <result> :PROCESSING\200

  <prompt> \204

-    <log> @14:00:49.53 <PROCESSING> Plunge.seek :reagent

-    <log> @14:00:50.37 Sample loop closed. Ready to Deliver Reagents

+    <log> @17:12:59.86 <PROCESSING> Plunge.seek :reagent

+    <log> @17:13:00.69 Sample loop closed. Ready to Deliver Reagents

     <log> Archive.seek :sealed

-    <log> @14:00:54.64 Archive.seek :evac

-    <log> @14:01:08.61 delay 1:00

-    <log> @14:02:08.62 Archive.seek :clear

-    <log> @14:02:26.39 RNAlater soak for 45 seconds

-    <log> @14:03:11.40 Archive.seek :tVent

-    <log> @14:03:13.98 delay 1 second

-    <log> @14:03:14.98 Archive.seek :evac

-    <log> @14:03:30.65 delay 10 seconds

-    <log> @14:03:40.65 Archive.seek :tVent

-    <log> @14:03:56.32 delay 1 second

-    <log> @14:03:57.32 Archive.seek :evac

-    <log> @14:04:12.99 delay 10 seconds

-    <log> @14:04:23.00 Sample preserved and evacuated

+    <log> @17:13:04.96 Archive.seek :evac

+    <log> @17:13:18.94 delay 1:00

+    <log> @17:14:18.95 Archive.seek :clear

+    <log> @17:14:36.72 RNAlater soak for 45 seconds

+    <log> @17:15:21.72 Archive.seek :tVent

+    <log> @17:15:24.30 delay 1 second

+    <log> @17:15:25.31 Archive.seek :evac

+    <log> @17:15:40.97 delay 10 seconds

+    <log> @17:15:50.98 Archive.seek :tVent

+    <log> @17:16:06.65 delay 1 second

+    <log> @17:16:07.65 Archive.seek :evac

+    <log> @17:16:23.32 delay 10 seconds

+    <log> @17:16:33.33 Sample preserved and evacuated

     <log> \207

- <status> PROCESSING-->PROCESSED@57,archiveHiBiomass_bac

+ <status> PROCESSING-->PROCESSED@55,archiveHiBiomass_bac

  <status> \204

-    <log> @14:04:23.96 <LRAUV> -> Cmd.stop

+    <log> @17:16:34.29 <LRAUV> -> Cmd.stop

     <log> Gate.power :heat,:OFF

     <log> Gate.power :cartridge,:OFF

-    <log> Carousel.seek 57

-    <log> @14:04:24.04 Plunge.seek :locked

-    <log> @14:04:24.87 PinPort.seek :clear

-    <log> @14:04:24.95 <Archive> Archive.seek :clear

-    <log> @14:04:24.96 <Air> Air.seek :clear

-    <log> @14:04:24.98 <Lysis1> Lysis1.seek :clear

-    <log> @14:04:42.72 <LRAUV> Archive.coast

+    <log> @17:16:34.30 Carousel.seek 55

+    <log> @17:16:34.38 Plunge.seek :locked

+    <log> @17:16:35.21 PinPort.seek :clear

+    <log> @17:16:35.29 <Archive> Archive.seek :clear

+    <log> <Air> Air.seek :clear

+    <log> @17:16:35.31 <Lysis1> Lysis1.seek :clear

+    <log> @17:16:53.06 <LRAUV> Archive.coast

     <log> Air.coast

-    <log> @14:04:42.73 Lysis1.coast

+    <log> Lysis1.coast

     <log> Lysis2.coast

     <log> Plunge.coast

     <log> SamplePump.coast

-    <log> Toroid.coast

-    <log> @14:04:42.74 Carousel.coast

+    <log> @17:16:53.07 Toroid.coast

+    <log> Carousel.coast

     <log> PinPort.coast

-    <log> @14:04:42.75 Gate.power :heat,:OFF

-    <log> @14:04:42.76 Gate.power :cartridge,:OFF

-    <log> @14:04:42.81 Gate.power :motor,:OFF

+    <log> @17:16:53.09 Gate.power :heat,:OFF

+    <log> Gate.power :cartridge,:OFF

+    <log> @17:16:53.14 Gate.power :motor,:OFF

     <log> Gate.power :core,:OFF

     <log> Gate.power :analytic1,:OFF

     <log> Gate.power :analytic2,:OFF

-    <log> Gate.power :analytic3,:OFF

-    <log> @14:04:42.82 Gate.power :main,:OFF

+    <log> @17:16:53.15 Gate.power :analytic3,:OFF

+    <log> Gate.power :main,:OFF

     <log> Safely stopped and ready to power off

     <log> \207

  <status> PROCESSED-->STOPPED

  <status> \201

  <result> :STOPPED\200

-##-- file closed 2020-08-12T21:33:13.994Z

+##-- file closed 2020-08-13T00:18:11.525Z

```

Updated by Carlos Rueda 2020-08-12

View revision

File snippet.markdown Modified

 - Port 9998 on tethyscode is where the ESPComponent will listen as a server and wait for the ESP to connect.

   (This port was opened so it is accessible from bufflehead.)

-- Created the `ESPlogs` subdir for the rsync command above, as well as added my tethyscode ssh pub key to bufflehead.

+- Created the `ESPlogs` subdir for the rsync command above, as well as added my tethyscode ssh pub key

+  to bufflehead's `authorized_keys` and the corresponding files under tethyscode's `~/.ssh/`

 - Alternatively (but much less frequently used), instead of having the LRAUV running as the server waiting for the ESP, you can set:

```

...

-[carueda@tethyscode lrauv-application]$ ESPCOMPONENT_MANUAL_ESP=1 bin/LRAUV -r -x    "load Maintenance/sample.xml;set sample.NumberOfSamples 2 count;set sample.Depth 1 centimeter;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.TargetDepth 1 centimeter;run"

+[tethysadmin@tethyscode lrauv-application]$ ESPCOMPONENT_MANUAL_ESP=1 bin/LRAUV -r -x    "load Maintenance/sample.xml;set sample.NumberOfSamples 2 count;set sample.Depth 1 centimeter;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.TargetDepth 1 centimeter;run"

 Writer for level Courier will be LZMA encoded.

 Writer for level Express will be LZMA encoded.

 Writer for level Priority will not be LZMA encoded.

 2020-08-12T20:34:22.904Z,1597264462.904 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg

 2020-08-12T20:34:22.911Z,1597264462.911 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg

 2020-08-12T20:34:22.915Z,1597264462.915 [Supervisor](INFO): Looking for Config files in directory: Config/tethyscode/

-2020-08-12T20:34:22.915Z,1597264462.915 [Supervisor](INFO): Looking for Config files in directory: Config/tethyscode/carueda/

+2020-08-12T20:34:22.915Z,1597264462.915 [Supervisor](INFO): Looking for Config files in directory: Config/tethyscode/tethysadmin/

 2020-08-12T20:34:22.915Z,1597264462.915 [Supervisor](INFO): Looking for Config files in directory: Config/sim/

 2020-08-12T20:34:22.915Z,1597264462.915 [Supervisor](INFO): Opening Config file at: Config/sim/secure.cfg

 2020-08-12T20:34:22.918Z,1597264462.918 [Supervisor](INFO): Opening Config file at: Config/sim/Science.cfg

 2020-08-12T20:34:22.926Z,1597264462.926 [Supervisor](INFO): Opening Config file at: Config/sim/Servo.cfg

 2020-08-12T20:34:22.929Z,1597264462.929 [Supervisor](INFO): Opening Config file at: Config/sim/Sensor.cfg

 2020-08-12T20:34:22.932Z,1597264462.932 [Supervisor](INFO): Opening Config file at: Config/sim/Derivation.cfg

-2020-08-12T20:34:22.935Z,1597264462.935 [Supervisor](INFO): Looking for Config files in directory: Config/sim/carueda/

-2020-08-12T20:34:22.935Z,1597264462.935 [Supervisor](INFO): Opening Config file at: Config/sim/carueda/secure.cfg

-2020-08-12T20:34:22.937Z,1597264462.937 [Supervisor](INFO): Opening Config file at: Config/sim/carueda/Science.cfg

+2020-08-12T20:34:22.935Z,1597264462.935 [Supervisor](INFO): Looking for Config files in directory: Config/sim/tethysadmin/

+2020-08-12T20:34:22.935Z,1597264462.935 [Supervisor](INFO): Opening Config file at: Config/sim/tethysadmin/secure.cfg

+2020-08-12T20:34:22.937Z,1597264462.937 [Supervisor](INFO): Opening Config file at: Config/sim/tethysadmin/Science.cfg

 2020-08-12T20:34:22.938Z,1597264462.938 [Config/Science](ERROR): Could not parse value: The

-2020-08-12T20:34:22.940Z,1597264462.940 [Supervisor](INFO): Opening Config file at: Config/sim/carueda/vehicle.cfg

-2020-08-12T20:34:22.943Z,1597264462.943 [Supervisor](INFO): Opening Config file at: Config/sim/carueda/Sensor.cfg

+2020-08-12T20:34:22.940Z,1597264462.940 [Supervisor](INFO): Opening Config file at: Config/sim/tethysadmin/vehicle.cfg

+2020-08-12T20:34:22.943Z,1597264462.943 [Supervisor](INFO): Opening Config file at: Config/sim/tethysadmin/Sensor.cfg

 2020-08-12T20:34:22.946Z,1597264462.946 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg

 2020-08-12T20:34:22.951Z,1597264462.951 [ESPComponent](ERROR): Could not open device '/dev/loadA6' at ESPComponent.loadControl

 2020-08-12T20:34:22.971Z,1597264462.971 [ESPComponent](ERROR): Could not open device '/dev/loadA7' at ESPComponent.loadControl2

 Note, it shows all ESP streams due to my local config having `ESPComponent.debug = 1 bool`:

```

-[carueda@tethyscode lrauv-application]$ cat Logs/latest/ESP.log

+[tethysadmin@tethyscode lrauv-application]$ cat Logs/latest/ESP.log

 ##-- file opened 2020-08-12T20:39:02.361Z

 <unknown> LRAUV

Updated by Carlos Rueda 2020-08-12

View revision

File snippet.markdown Modified

 # ESPComponent<->ESP testing with simulators on tethyscode and bufflehead

+## Accounts and machines

+- tethysadmin @ tethyscode

+- carueda @ bufflehead

 # Preparations

 ## On bufflehead

 ### ESP simulator with available "dry" cartridges.

+To make sure we have "dry" cartridges:

     $ esp

 ## On tethyscode:

-Under ~carueda/lrauv-application I have a copy of the latest nightly build as of 2020-08-12.

+Under `~tethysadmin/workspace/lrauv-application-carlos` I made a copy of the latest nightly build as of 2020-08-12.

-There, as usual, I have populated the following under Config/sim/carueda/ to override relevant configs for the **sim** vehicle:

+There, as usual, I have populated the following under `Config/sim/tethysadmin/` to override relevant configs for the **sim** vehicle:

```

-[carueda@tethyscode lrauv-application]$ ls -lrt Config/sim/carueda/

+[tethysadmin@tethyscode lrauv-application]$ ls -lrt Config/sim/tethysadmin/

 total 16

--rw-rw-r-- 1 carueda carueda  22 Aug 12 11:01 vehicle.cfg

--rw-rw-r-- 1 carueda carueda 163 Aug 12 11:01 Sensor.cfg

--rw-rw-r-- 1 carueda carueda 700 Aug 12 11:03 secure.cfg

--rw-rw-r-- 1 carueda carueda 240 Aug 12 11:05 Science.cfg

+-rw-rw-r-- 1 tethysadmin tethysadmin  22 Aug 12 11:01 vehicle.cfg

+-rw-rw-r-- 1 tethysadmin tethysadmin 163 Aug 12 11:01 Sensor.cfg

+-rw-rw-r-- 1 tethysadmin tethysadmin 700 Aug 12 11:03 secure.cfg

+-rw-rw-r-- 1 tethysadmin tethysadmin 662 Aug 12 16:01 Science.cfg

```

-In particular, `Config/sim/carueda/Science.cfg` has the following:

+In particular, `Config/sim/tethysadmin/Science.cfg` has the following:

+```

+tethysadmin@tethyscode: lrauv-application-carlos$ cat Config/sim/tethysadmin/Science.cfg

+ESPComponent.loadAtStartup          = 1 bool;

+ESPComponent.simulateHardware       = 0 bool;

-    ESPComponent.loadAtStartup          = 1 bool;

-    ESPComponent.simulateHardware       = 0 bool;

-    ESPComponent.socketServerPort       = 9998 count;

-    ESPComponent.debug                  = 1 bool;

-    ESPComponent.poTimeout              = 30 second;

+ESPComponent.socketServerPort       = 9998 count;

-    ESPComponent.upsyncTimeout          = 10 second;

-    ESPComponent.upsync                 = "rsync -azPq --timeout=60 carueda@bufflehead:'/var/log/carueda/simrapid.* /var/log/carueda/*.spr' /home/carueda/lrauv-application/ESPlogs";

+ESPComponent.debug                  = 1 bool;

+ESPComponent.poTimeout              = 30 second;

+ESPComponent.upsyncTimeout          = 10 second;

+ESPComponent.upsync                 = "rsync -azPq --timeout=60 carueda@bufflehead:'/var/log/carueda/simrapid.* /var/log/carueda/*.spr' /home/tethysadmin/workspace/lrauv-application-carlos/ESPlogs";

+```

 **Note**:

           ESPComponent.espServerHost    = "bufflehead:7777"

-    in `Config/sim/carueda/Science.cfg`

+    in `Config/sim/tethysadmin/Science.cfg`

     and immediately run the ESP command above. In this case, the LRAUV would immediately connect to the already running ESP server.

 Make sure `SimDaemon` is running; if not already:

-    [carueda@tethyscode lrauv-application]$ bin/SimDaemon

+    [tethysadmin@tethyscode lrauv-application]$ bin/SimDaemon

 Using `Maintenance/sample.xml` for the testing.

 We need to tell the ESPComponent that we are running the ESP manually, so we set the `ESPCOMPONENT_MANUAL_ESP` environment variable for this purpose:

-    [carueda@tethyscode lrauv-application]$ ESPCOMPONENT_MANUAL_ESP=1 bin/LRAUV -r -x \

+    [tethysadmin@tethyscode lrauv-application]$ ESPCOMPONENT_MANUAL_ESP=1 bin/LRAUV -r -x \

          "load Maintenance/sample.xml;set sample.NumberOfSamples 2 count;set sample.Depth 1 centimeter;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.TargetDepth 1 centimeter;run"

HTTPS

SSH

You can clone a snippet to your computer for local editing. Learn more.

Snippets

Carlos Rueda ESPComponent testing with LRAUV and ESP simulators

File snippet.markdown Modified

File snippet.markdown Modified

File snippet.markdown Modified

File snippet.markdown Modified

File snippet.markdown Modified