Snippets

Carlos Rueda ESPComponent testing with LRAUV and ESP simulators

You are viewing an old version of this snippet. View the current version.
Revised by Carlos Rueda f0d0ce9
snippet.markdown
Raw

ESPComponent<->ESP testing with simulators on tethyscode and bufflehead

Accounts and machines

  • tethysadmin @ tethyscode
  • carueda @ bufflehead

Preparations

On bufflehead

Using ESP master branch per Brent.

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

$ cd esp2
$ git pull origin master
$ . ESPenv auv honu
$ ESPmode=simrapid

I created a special mode analogous to simreal called simrapid. If you replace simreal with simrapid in your existing instructions, you should get the accelerated sim. No more need to tweak the source code.

ESP simulator with available "dry" cartridges.

To make sure we have "dry" cartridges:

$ esp

-> slots spare: 10
-> slots All => [:dry, :archiveHiBiomass_bac]

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"

Exit the ESP simulator for what follows

Then, in this bufflehead session, prepare the following command but do not launch it yet:

  $ 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.

On tethyscode:

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/tethysadmin/ to override relevant configs for the sim vehicle:

[tethysadmin@tethyscode lrauv-application]$ ls -lrt Config/sim/tethysadmin/
total 16
-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/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.socketServerPort       = 9998 count;

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:

  • 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'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:

      ESPComponent.espServerHost    = "bufflehead:7777"

    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.

Running the mission:

On tethyscode

Make sure SimDaemon is running; if not already:

[tethysadmin@tethyscode lrauv-application]$ bin/SimDaemon

Using Maintenance/sample.xml for the testing.

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:

[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):

...
... [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:

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.

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

@13:39:00.94PDT12-Aug-20 <simrapid> Simulated gateway v3.24 for core bus
Simulated secondary gateway v3.24 for cartridge bus
@13:39:01.06
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
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
Gate.power :analytic1,:ON
Gate.power :analytic2,:ON
@13:39:05.17 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
ExtraPump.configure :default
@13:39:05.22 Toroid.configure :default
Carousel.configure :default
@13:39:05.23 Pressure.configure :default
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
<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
<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
<Plunge_home> Plunge.home.jog 0
<Toroid_home> Toroid.reconfigure :default
@13:39:05.30 <PinPort_home> PinPort.home.jog 0
<Toroid_home> Toroid.home.jog 0
@13:39:05.34 <Archive_home> Archive.setRawPosition! 50
Archive.reconfigure :homing
@13:39:05.35 Archive.seek :home
<Air_home> Air.setRawPosition! 50
Air.reconfigure :homing
@13:39:05.36 Air.seek :home
@13:39:05.37 <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
Lysis1.reconfigure :homing
Lysis1.seek :home
@13:39:05.41 <Lysis2_home> Lysis2.setRawPosition! 50
Lysis2.reconfigure :homing
@13:39:05.42 Lysis2.seek :home
@13:39:05.43 <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
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
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
SamplePump.setPosition! 0ml
Bypass.open
@13:39:42.70 Intake.open
@13:39:44.20 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
Pressure.reconfigure :default
@13:39:46.73 Pressure.hold
@13:39:46.81 SamplePump.reconfigure :prime
SamplePump.seek 1.5ml,38 seconds
@13:39:48.58 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)
SamplePump.reconfigure :prime
@13:39:53.07 SamplePump.seek 5ml,56 seconds
@13:39:57.80 Pressure.coast
Bypass.open
@13:39:59.30 Intake.close
@13:40:00.80 Toroid.reconfigure :hold
Toroid.seek :crack
@13:40:01.60 Toroid.reconfigure :default
Toroid.seek :clear
@13:40:03.11 Toroid.reconfigure :hold
Toroid.seek :cartridge
@13:40:04.92 Toroid.reconfigure :default
Toroid.seek :clear
@13:40:06.75 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
SamplePump.seek 0.2ml,32 seconds
@13:40:11.96 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
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
<closeExhaust> Exhaust.close
@13:40:26.52 <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
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
Air.coast
@13:44:24.40 Lysis1.coast
Lysis2.coast
Plunge.coast
SamplePump.coast
Toroid.coast
@13:44:24.41 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
Gate.power :core,:OFF
Gate.power :analytic1,:OFF
Gate.power :analytic2,:OFF
Gate.power :analytic3,:OFF
@13:44:24.49 Gate.power :main,:OFF
Safely stopped and ready to power off
@13:49:33.31 Session Ended
@13:49:52.00 <simrapid> -> exit
carueda@bufflehead:~/esp2$ ESPclient=tethyscode:9998 ESPcmdPort=7777 esp
@13:59:19.17PDT12-Aug-20 <simrapid> Simulated gateway v3.24 for core bus
Simulated secondary gateway v3.24 for cartridge bus
@13:59:19.29
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
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
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
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
Gate.power :motor,:ON
@13:59:23.57 <Archive_home> Archive.reconfigure :default
@13:59:23.58 Archive.home.jog 0
<Air_home> Air.reconfigure :default
@13:59:23.59 Air.home.jog 0
<Lysis1_home> Lysis1.reconfigure :default
@13:59:23.60 <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.home.jog 0
<Toroid_home> Toroid.reconfigure :default
@13:59:23.62 <PinPort_home> PinPort.home.jog 0
<Toroid_home> Toroid.home.jog 0
@13:59:23.66 <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
Air.seek :home
@13:59:23.69 <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
PinPort.seek :home
@13:59:23.72 <Lysis1_home> Lysis1.setRawPosition! 50
Lysis1.reconfigure :homing
@13:59:23.73 Lysis1.seek :home
@13:59:23.74 <Lysis2_home> Lysis2.setRawPosition! 50
Lysis2.reconfigure :homing
Lysis2.seek :home
@13:59:23.75 <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
Carousel.home.jog 0
@13:59:25.97 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
Gate.power :cartridge,:OFF
@13:59:38.26 Lysis1.seek :locked
@13:59:42.33 <Plunge> Plunge.seek :locked
<Air> Air.seek :locked
@13:59:46.40 <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
SamplePump.setPosition! 0ml
Bypass.open
@14:00:01.03 Intake.open
@14:00:02.53 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
Pressure.hold
@14:00:05.14 SamplePump.reconfigure :prime
SamplePump.seek 1.5ml,38 seconds
@14:00:06.91 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
SamplePump.seek 5ml,56 seconds
@14:00:16.14 Pressure.coast
Bypass.open
@14:00:17.63 Intake.close
@14:00:19.14 Toroid.reconfigure :hold
Toroid.seek :crack
@14:00:19.94 Toroid.reconfigure :default
Toroid.seek :clear
@14:00:21.44 Toroid.reconfigure :hold
Toroid.seek :cartridge
@14:00:23.26 Toroid.reconfigure :default
Toroid.seek :clear
@14:00:25.08 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
SamplePump.seek 0.2ml,32 seconds
@14:00:30.29 Pressure.coast
@14:00:30.30 Sampling 10.0ml
SamplePump.setPosition! 0ml
Exhaust.open
@14:00:31.80 Pressure.hold
@14:00:31.88 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
<closeIntake> Intake.close
@14:00:44.86 <closeExhaust> Exhaust.close
<FILTERING> Toroid.reconfigure :hold
Toroid.seek :bypass
@14:00:46.48 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
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
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
Air.coast
@14:04:42.73 Lysis1.coast
Lysis2.coast
Plunge.coast
SamplePump.coast
Toroid.coast
@14:04:42.74 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
Gate.power :core,:OFF
Gate.power :analytic1,:OFF
Gate.power :analytic2,:OFF
Gate.power :analytic3,:OFF
@14:04:42.82 Gate.power :main,:OFF
Safely stopped and ready to power off
@14:09:51.63 Session Ended
@14:24:48.05 <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"
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.
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.
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
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.
...

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:

[tethysadmin@tethyscode lrauv-application]$ cat Logs/latest/ESP.log

##-- file opened 2020-08-12T20:39:02.361Z
<unknown> LRAUV
<unknown> \200
 <prompt> \200
 <prompt> \204
    <log> @13:39:03.56 -> showStatus
    <log> \201
 <result> true\200
 <prompt> \204
    <log> @13:39:05.16 -> Cmd.loadCartridge -4
    <log> \207
 <status> STOPPED-->IDLE
 <status> \204
    <log> 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 :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> 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> 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> <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> <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> <Plunge_home> Plunge.home.jog 0
    <log> <Toroid_home> Toroid.reconfigure :default
    <log> @13:39:05.30 <PinPort_home> PinPort.home.jog 0
    <log> <Toroid_home> Toroid.home.jog 0
    <log> @13:39:05.34 <Archive_home> Archive.setRawPosition! 50
    <log> Archive.reconfigure :homing
    <log> @13:39:05.35 Archive.seek :home
    <log> <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> 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> Lysis1.reconfigure :homing
    <log> Lysis1.seek :home
    <log> @13:39:05.41 <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> 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> Carousel.seek :home
    <log> @13:39:07.95 Carousel.reconfigure :default
    <log> @13:39:08.20 Carousel.seek 1
    <log> \207
 <status> IDLE-->LOADING
 <status> LOADING-->LOADING@58,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> Gate.power :cartridge,:OFF
    <log> @13:39:28.79 Mounted archive Cartridge
    <log> \207
 <status> LOADING-->READY@58,archiveHiBiomass_bac
 <status> \201
 <result> 58\200
 <prompt> \204
    <log> @13:39:41.97 -> 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> 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> 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> Pressure.reconfigure :default
    <log> @13:39:46.73 Pressure.hold
    <log> @13:39:46.81 SamplePump.reconfigure :prime
    <log> SamplePump.seek 1.5ml,38 seconds
    <log> @13:39:48.58 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> SamplePump.reconfigure :prime
    <log> @13:39:53.07 SamplePump.seek 5ml,56 seconds
    <log> @13:39:57.80 Pressure.coast
    <log> Bypass.open
    <log> @13:39:59.30 Intake.close
    <log> @13:40:00.80 Toroid.reconfigure :hold
    <log> Toroid.seek :crack
    <log> @13:40:01.60 Toroid.reconfigure :default
    <log> Toroid.seek :clear
    <log> @13:40:03.11 Toroid.reconfigure :hold
    <log> Toroid.seek :cartridge
    <log> @13:40:04.92 Toroid.reconfigure :default
    <log> Toroid.seek :clear
    <log> @13:40:06.75 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> SamplePump.seek 0.2ml,32 seconds
    <log> @13:40:11.96 Pressure.coast
    <log> Sampling 10.0ml
    <log> SamplePump.setPosition! 0ml
    <log> @13:40:11.97 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> 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> <closeExhaust> Exhaust.close
    <log> @13:40:26.52 <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> \207
 <status> FILTERING-->PAUSED@10.0
 <status> \204
    <log> @13:40:31.18 <LRAUV> -> Cmd.startProcessing
    <log> \207
 <status> PAUSED-->PROCESSING@58,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> 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> \207
 <status> PROCESSING-->PROCESSED@58,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> Air.coast
    <log> @13:44:24.40 Lysis1.coast
    <log> Lysis2.coast
    <log> Plunge.coast
    <log> SamplePump.coast
    <log> Toroid.coast
    <log> @13:44:24.41 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> Gate.power :core,:OFF
    <log> Gate.power :analytic1,:OFF
    <log> Gate.power :analytic2,:OFF
    <log> Gate.power :analytic3,:OFF
    <log> @13:44:24.49 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 opened 2020-08-12T20:59:20.692Z
 <prompt> LRAUV
 <prompt> \200
 <prompt> \200
 <prompt> \204
    <log> @13:59:21.49 -> showStatus
    <log> \201
 <result> true\200
 <prompt> \204
    <log> @13:59:23.49 -> Cmd.loadCartridge -4
    <log> \207
 <status> STOPPED-->IDLE
 <status> \204
    <log> 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> 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> Gate.power :motor,:ON
    <log> @13:59:23.57 <Archive_home> Archive.reconfigure :default
    <log> @13:59:23.58 Archive.home.jog 0
    <log> <Air_home> Air.reconfigure :default
    <log> @13:59:23.59 Air.home.jog 0
    <log> <Lysis1_home> Lysis1.reconfigure :default
    <log> @13:59:23.60 <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.home.jog 0
    <log> <Toroid_home> Toroid.reconfigure :default
    <log> @13:59:23.62 <PinPort_home> PinPort.home.jog 0
    <log> <Toroid_home> Toroid.home.jog 0
    <log> @13:59:23.66 <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> Air.seek :home
    <log> @13:59:23.69 <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> PinPort.seek :home
    <log> @13:59:23.72 <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> Lysis2.reconfigure :homing
    <log> Lysis2.seek :home
    <log> @13:59:23.75 <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> Carousel.home.jog 0
    <log> @13:59:25.97 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> \207
 <status> IDLE-->LOADING
 <status> LOADING-->LOADING@57,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> Gate.power :cartridge,:OFF
    <log> @13:59:38.26 Lysis1.seek :locked
    <log> @13:59:42.33 <Plunge> Plunge.seek :locked
    <log> <Air> Air.seek :locked
    <log> @13:59:46.40 <LRAUV> Gate.power :cartridge,:ON
    <log> Gate.power :cartridge,:OFF
    <log> Gate.power :cartridge,:OFF
    <log> @13:59:46.90 Mounted archive Cartridge
    <log> \207
 <status> LOADING-->READY@57,archiveHiBiomass_bac
 <status> \201
 <result> 57\200
 <prompt> \204
    <log> @14:00:00.30 -> 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> 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> 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> Pressure.hold
    <log> @14:00:05.14 SamplePump.reconfigure :prime
    <log> SamplePump.seek 1.5ml,38 seconds
    <log> @14:00:06.91 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> SamplePump.seek 5ml,56 seconds
    <log> @14:00:16.14 Pressure.coast
    <log> Bypass.open
    <log> @14:00:17.63 Intake.close
    <log> @14:00:19.14 Toroid.reconfigure :hold
    <log> Toroid.seek :crack
    <log> @14:00:19.94 Toroid.reconfigure :default
    <log> Toroid.seek :clear
    <log> @14:00:21.44 Toroid.reconfigure :hold
    <log> Toroid.seek :cartridge
    <log> @14:00:23.26 Toroid.reconfigure :default
    <log> Toroid.seek :clear
    <log> @14:00:25.08 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> SamplePump.seek 0.2ml,32 seconds
    <log> @14:00:30.29 Pressure.coast
    <log> @14:00:30.30 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> 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> <closeIntake> Intake.close
    <log> @14:00:44.86 <closeExhaust> Exhaust.close
    <log> <FILTERING> Toroid.reconfigure :hold
    <log> Toroid.seek :bypass
    <log> @14:00:46.48 Toroid.reconfigure :default
    <log> Toroid.seek :clear
    <log> @14:00:48.10 Sampled  10.0ml
    <log> \207
 <status> FILTERING-->PAUSED@10.0
 <status> \204
    <log> @14:00:49.51 <LRAUV> -> Cmd.startProcessing
    <log> \207
 <status> PAUSED-->PROCESSING@57,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> 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> \207
 <status> PROCESSING-->PROCESSED@57,archiveHiBiomass_bac
 <status> \204
    <log> @14:04:23.96 <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> Air.coast
    <log> @14:04:42.73 Lysis1.coast
    <log> Lysis2.coast
    <log> Plunge.coast
    <log> SamplePump.coast
    <log> Toroid.coast
    <log> @14:04:42.74 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> 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> 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
HTTPS SSH

You can clone a snippet to your computer for local editing. Learn more.