RE: Asyn/StreamDevice for HP3458A through Agilent E5810 LAN/GPIB Gateway

[Mark Rivers via Tech-talk <tech-talk at aps.anl.gov>]

Hi Yong,

 

Ø   2) Could you briefly explain what these mean: queueRequest timeout, vxiSetEos 1, vxiSetEos 0?

 

-          queueRequest timeout

 

The message is actually “schedule queueRequest timeout”

2020/07/08 15:16:31.567 L0 schedule queueRequest timeout

 

That message means that asynManager is queueing an I/O request but scheduling a timeout in case the queued request does not run before the timeout.

 

-          vxiSetEos 1

 

This is the message:

***************************

2020/07/08 15:16:31.569 asynManager::portThread port=L0 callback

2020/07/08 15:16:31.569 L0 vxiSetEos 1

 

 

\n

 

0a

***************************

 

This is the code that writes the first part of that message.

    asynPrintIO(pasynUser, ASYN_TRACE_FLOW, eos, eoslen,

            "%s vxiSetEos %d\n",pvxiPort->portName,eoslen);

    switch (eoslen) {

    default:

        asynPrint(pasynUser,ASYN_TRACE_ERROR,

           "%s vxiSetEos illegal eoslen %d\n",pvxiPort->portName,eoslen);

        return asynError;

    case 1:

        pdevLink->eos = (unsigned char)eos[0];

        break;

    case 0:

        pdevLink->eos = -1;

        break;

    }

 

So that part of the message means that eoslen=1.  It appears that the VXI-11 driver only allows single-character EOS strings, whereas in general asyn allows 2-character EOS strings.  What puzzles me is that in your protocol file you have this line:

 

Terminator = "\r\n";

 

So that is asking for a 2 character terminator, and the first character is \r.  How come drvVxi11.c is getting a 1 character terminator that is \n?  Is streamDevice smart enough to know that VXI11 only allows single-character terminators and changes it?

 

The second part of the message above it shows the terminator both in escape form (\n) and in hex (0a).  I cannot find any code that is printing that. You said you are running asyn 4.23.0.  I wonder if there could be some local edit that is printing the EOS character itself in drvVXI11.c:: vxiSetEos()?

 

Ø  The time difference between “vxiRead” and “vxiSetEos 1” is 3.4 seconds, which means it takes 3.4 seconds to read a floating number “-4.008121752E+00”.

 

That may be because, as Michael Davidsaver said yesterday, you are actually using the wrong command to request the reading.  Perhaps the “DCV 10, 1E-6” command actually takes a long time for the device to execute, and if were sending the correct command it would be faster.

 

Mark

 

 

 

From: Hu, Yong <yhu at bnl.gov>
Sent: Wednesday, July 8, 2020 6:24 PM
To: Mark Rivers <rivers at cars.uchicago.edu>
Cc: tech-talk at aps.anl.gov
Subject: Re: Asyn/StreamDevice for HP3458A through Agilent E5810 LAN/GPIB Gateway

 

Hi Mark R.,

 

Thanks for your suggestion. Yes, I found the version in /usr/lib/epics/include/asynDriver.h: 4.23.0.

Yes, you are right. Both Asyn and StreamDevice are very old. I am going to upgrade them to the latest releases.

 

I have set the trace mask to 0xFF. Attached please find the detailed output messages for a few cycles. Below is the simplified version with important timestamps highlighted.

 

1) The record is scanned at every 5-second so that we get 2020/07/08 15:16:31.567 à 2020/07/08 15:16:36.567 à 2020/07/08 15:16:41.567, which makes perfect sense. Then it jumps to 2020/07/08 15:16:51.567, which is 10-second gap meaning one scan is skipped. This kind of skipping is confirmed by Michael’s suggestion of setting TPRO. I guess “scan5: Active SR:C03-BI{DMM:1}V-I_” means the record is scanned at 5-second and its PACT is true so that the record processing is simply skipped and it waits for the next scan.

 

2) Could you briefly explain what these mean: queueRequest timeout, vxiSetEos 1, vxiSetEos 0? I am surprised to see “\n 0a” after vxiSetEos 1. The time difference between “vxiRead” and “vxiSetEos 1” is 3.4 seconds, which means it takes 3.4 seconds to read a floating number “-4.008121752E+00”.

 

scan5: Process SR:C03-BI{DMM:1}V-I_

scan5: Process SR:C03-BI{DMM:1}V-I_

scan5: Process SR:C03-BI{DMM:1}V-I_

scan5: Active SR:C03-BI{DMM:1}V-I_

scan5: Process SR:C03-BI{DMM:1}V-I_

scan5: Process SR:C03-BI{DMM:1}V-I_

scan5: Process SR:C03-BI{DMM:1}V-I_

scan5: Active SR:C03-BI{DMM:1}V-I_

 

 

2020/07/08 15:16:31.567 L0 addr 6 queueRequest priority 0 not lockHolder

2020/07/08 15:16:31.567 L0 schedule queueRequest timeout

2020/07/08 15:16:31.567 asynManager::portThread port=L0 callback

2020/07/08 15:16:31.567 L0 addr 6 queueRequest priority 0 not lockHolder

2020/07/08 15:16:31.567 L0 schedule queueRequest timeout

2020/07/08 15:16:31.567 asynManager::portThread port=L0 callback

2020/07/08 15:16:31.567 L0 6 vxiWrite numchars 14

2020/07/08 15:16:31.569 L0 6 vxiWrite

DCV 10, 1E-6

 

DCV 10, 1E-6\r\n

 

44 43 56 20 31 30 2c 20 31 45 2d 36 0d 0a 

2020/07/08 15:16:31.569 L0 addr 6 queueRequest priority 0 from lockHolder

2020/07/08 15:16:31.569 L0 schedule queueRequest timeout

2020/07/08 15:16:31.569 asynManager::portThread port=L0 callback

2020/07/08 15:16:31.569 L0 vxiSetEos 1

 

 

\n

 

0a 

2020/07/08 15:16:34.961 L0 6 vxiRead

-4.008121752E+00

 

-4.008121752E+00\r\n

 

2d 34 2e 30 30 38 31 32 31 37 35 32 45 2b 30 30 0d 0a 

2020/07/08 15:16:34.961 L0 vxiSetEos 0

 

2020/07/08 15:16:36.567 L0 addr 6 queueRequest priority 0 not lockHolder

……

2020/07/08 15:16:40.407 L0 vxiSetEos 0

 

2020/07/08 15:16:41.567 L0 addr 6 queueRequest priority 0 not lockHolder

……

2020/07/08 15:16:46.957 L0 vxiSetEos 0

 

2020/07/08 15:16:51.567 L0 addr 6 queueRequest priority 0 not lockHolder ##note: one scan is skipped

……

2020/07/08 15:16:55.007 L0 vxiSetEos 0

 

2020/07/08 15:16:56.567 L0 addr 6 queueRequest priority 0 not lockHolder

……

 

 

From: Mark Rivers <rivers at cars.uchicago.edu>
Date: Wednesday, July 8, 2020 at 10:12 AM
To: "Hu, Yong" <yhu at bnl.gov>
Cc: "tech-talk at aps.anl.gov" <tech-talk at aps.anl.gov>
Subject: RE: Asyn/StreamDevice for HP3458A through Agilent E5810 LAN/GPIB Gateway

 

Hi Yong,

 

Ø  PS: I had difficulty finding the exact version number of asyn/streamdevice since I built my IOC against Michael Davidsaver’s Debian packages (https://epics.nsls2.bnl.gov/debian/ ) and the packages provide everything under /usr/lib/epics/

 

The Debian packages must also install the asyn header files, probably in /usr/include/epics.  Look at asynDriver.h, it should contain lines like the following:

 

#define ASYN_VERSION       4

#define ASYN_REVISION     39

#define ASYN_MODIFICATION  0

 

Let me know what version it is.  Since your streamDevice is more than 7 years old I suspect that asyn is very old as well.  If so, there have been quite a few fixes to the asyn VXI-11 support since 2013.  I suggest you build a test IOC with the latest version of asyn and streamDevice and see if he problem still occurs.

 

You should probably enable all of the asyn trace flags on that driver, i.e. set the trace mask to 0xFF.  There may be some hints as to the timing issues if you do that.

 

Mark

 

From: Tech-talk <tech-talk-bounces at aps.anl.gov> On Behalf Of Hu, Yong via Tech-talk
Sent: Wednesday, July 8, 2020 8:38 AM
To: tech-talk at aps.anl.gov
Subject: Asyn/StreamDevice for HP3458A through Agilent E5810 LAN/GPIB Gateway

 

Hello everyone,

 

I have a simple StreamDevice protocol for an old GPIB-based device HP3458A which is connected to Agilent E5810 LAN/GPIB Gateway (100 Mbps) talking to a softIOC. Here is the record to read the voltage data at 0.2Hz (5 second).

 

#only showing the must-have fields

record(ai, "SR:C03-BI{DMM:1}V-I_")

{              

    field(DTYP, "stream")

    field(INP,  "@hp3458a.proto ReadData L0 6")

    field(SCAN, "5 second")

}

#StreamDevice protocol

ReadData {

         out "DCV  10, 1E-6";

         in "%f";

}

 

And this is the EPICS shell output after I turn on the Asyn trace.

2020/07/07 17:55:46.280 L0 6 vxiWrite

DCV  10, 1E-6

2020/07/07 17:55:49.630 L0 6 vxiRead

-4.016502336E+00

2020/07/07 17:55:52.396 L0 6 vxiWrite

DCV  10, 1E-6

2020/07/07 17:55:55.756 L0 6 vxiRead

-4.015675668E+00

2020/07/07 17:56:00.680 L0 6 vxiWrite

DCV  10, 1E-6

2020/07/07 17:56:04.030 L0 6 vxiRead

-4.014579704E+00

 

I get the expected response (i.e. -4.016502336E+00) after the command (DCV  10, 1E-6) is sent. However, as you see from the timestamps for each vxiWrite, the command is not sent at every 5-second. It takes more than 5 seconds and it has a pattern: 6.116, 8.284, 6.116, 8.284, …. ; the response time (vxiRead – vxiWrite) is consistent at 3.35 seconds although it seems ridiculously slow.

 

So, the system is slower than expected. However, I am surprised that there is no any alarm for the record and no any warning message from the EPICS shell output when that record can not keep up its scanning rate. Is this kind of silence supposed to be? Just to be clear, the softIOC itself and the physical server are perfectly fine: I added the classical “dbExample1.db” and its calc record can be scanned at exactly 5-second.

 

This system used to work as expected at 0.2Hz (5 second) despite it is ridiculously slow. Now it becomes even slower after our ITD upgraded the network switch. If anyone has experience on these old devices (HP3458A, E5810), please advise what I should do next.

 

If the version of Asyn/StreamDevice matters for this case, here we go:

epics> dbior

Driver: drvAsyn

L0 multiDevice:Yes canBlock:Yes autoConnect:Yes

    vxi11, host name: 10.0.132.67

Driver: stream

  StreamDevice 2.6.0 built May 29 2013 18:45:57

  registered bus interfaces:

    DebugInterface

    DummyInterface

AsynDriverInterface

 

PS: I had difficulty finding the exact version number of asyn/streamdevice since I built my IOC against Michael Davidsaver’s Debian packages (https://epics.nsls2.bnl.gov/debian/ ) and the packages provide everything under /usr/lib/epics/. I am sure there are many ways (ldd, strings, configure/RELEASE, etc.) to find out the version number of EPICS support module. I just found “dbior” seems a handy tool for reporting EPICS driver’s version. I am not sure if Mark Rivers has added this kind of report in his latest Asyn release.

 

Best regards,

Yong Hu

NSLS-II Controls Group