Skip to content

TETHYS-612

Jira: https://mbari1.atlassian.net/browse/TETHYS-612

PR: https://bitbucket.org/mbari/lrauv-application/pull-requests/204/

This snippet summarizes one of LRAUV<->ESP sessions with simulators to test changes to address TETHYS-612.

(Same basic scheme of preparations and running steps as described in https://bitbucket.org/snippets/carueda/8KR6B)

Preparations

On bufflehead

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

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

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

These preparations are just to later on allow an actual connection and successfull sampling after a couple of attempts from LRAUV to accept a connection (as explained below).

Here, we just get ready with the following command but do not launching it just yet:

  $ ESPclient=tethyscode:9998 ESPcmdPort=7777 esp

On tethyscode:

Under ~tethysadmin/workspace/lrauv-application-carlos I have a clone with the branch associated to the PR.

Running the mission:

[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"

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)**

You can issue the following command to speed up the test:

maintain sensor depth_keller.depth 1 cm

Also, in one other tethyscode terminal, let's tail Logs/latest/syslog to inspect the key debug lines indicating the wait before a power-up/connection sequence:

tethysadmin@tethyscode: lrauv-application-carlos$ tail -f Logs/latest/syslog

We let the Waiting for ESP to connect line in the main LRAUV console to show up a couple of times, then finally launch the ESP command above for a complete sample to proceed.

This all completes OK.

Let's look at some key lines in syslog.

The relevant lines related with the first power-up/connection are:

...
2020-08-20T21:20:51.849Z,1597958451.849 [ESPComponent](IMPORTANT): Setting regex for ESP Log summary: 'Selecting Cartridge|Sampled|Error|Underpressure|Overpressure|Fail|Retry|Cmd::|Sampler::'
2020-08-20T21:20:51.849Z,1597958451.849 [ESPComponent](INFO): compiled regex: "Selecting Cartridge|Sampled|Error|Underpressure|Overpressure|Fail|Retry|Cmd::|Sampler::"
2020-08-20T21:20:51.849Z,1597958451.849 [ESPComponent](DEBUG): (612) Will wait for 10.0000 before power-up/connection sequence
...
2020-08-20T21:21:01.851Z,1597958461.851 [ESPComponent](DEBUG): ESPComponent::starting: startState_=SS_INIT
2020-08-20T21:21:01.851Z,1597958461.851 [ESPComponent](DEBUG): (612) Done with wait. Will continue with general power-up/connection sequence
2020-08-20T21:21:01.851Z,1597958461.851 [ESPComponent](DEBUG): ESPComm: ESPComm::open: opening server socket on port 9998
2020-08-20T21:21:01.851Z,1597958461.851 [ESPComponent](IMPORTANT): powerUpESP IGNORED because manualEsp_
2020-08-20T21:21:01.851Z,1597958461.851 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=30.0000)
2020-08-20T21:21:02.251Z,1597958462.251 [ESPComponent](DEBUG): ESPComponent::starting: startState_=SS_WAITING_FOR_ESP_TO_CONNECT
...
2020-08-20T21:21:31.858Z,1597958491.858 [ESPComponent](FAULT): Timeout while waiting for ESP to connect (elapsed=30.0064)
2020-08-20T21:21:31.858Z,1597958491.858 [ESPComponent] Communications Fault, FailCount= 1
2020-08-20T21:21:31.858Z,1597958491.858 [ESPComponent](ERROR): Communications Fault
2020-08-20T21:21:31.860Z,1597958491.860 [CBIT](ERROR): Communications Fault in component: ESPComponent
2020-08-20T21:21:32.258Z,1597958492.258 [ESPComponent](DEBUG): ESPComponent::stop startState_=SS_WAITING_FOR_ESP_TO_CONNECT
2020-08-20T21:21:32.258Z,1597958492.258 [ESPComponent](IMPORTANT): powerDownESP IGNORED because manualEsp_
2020-08-20T21:21:32.658Z,1597958492.658 [ESPComponent](DEBUG): ESPComponent::stopping
2020-08-20T21:21:33.058Z,1597958493.058 [ESPComponent](DEBUG): ESPComponent::stopped
2020-08-20T21:21:33.060Z,1597958493.060 [CBIT](INFO): Clearing failed state for component ESPComponent
2020-08-20T21:21:33.060Z,1597958493.060 [ESPComponent] No Fault, FailCount= 1
2020-08-20T21:21:33.458Z,1597958493.458 [ESPComponent](DEBUG): start  simulateHardware()=0
2020-08-20T21:21:33.458Z,1597958493.458 [ESPComponent](DEBUG): (612) Will wait for 10.0000 before power-up/connection sequence
...

That is:

  • 21:20:51 - first "Will wait for 10s before power-up..."
  • 21:21:01 - done with the wait
  • 21:21:01 - power up (simulated in this case)
  • 21:21:01 - waiting for ESP to connect (timeout=30)
  • 21:21:31 - timeout 30s later as expected (we are not yet launching the ESP program)
  • 21:21:32 - power down as part of the expected sequence after the timeout
  • 21:21:33 - new wait (for 10s) toward a second attempt (all of this as part of the regular failCount/allowable failures mechanisms that has traditionally been in place)

Similar events as above can be seen for a second attempt, and then we launch the ESP after the third "Waiting for ESP to connect" at which point a successful typical sample is started and then completed.