Re: Problems with StreamDevice

[Dirk Zimoch via Tech-talk <tech-talk@aps.anl.gov>]

>  2)      If I have an error in my protocol file I am not seeing any error messages.  I used to see them in previous versions.
> If I break the protocol by changing CHN to CHAN
>
> readChans {
>    out "CHAN:?";
>    in "CHAN:%d";
> }
> then this is what I see with asynTrace on.  Note that the CHAN:? command returned NAK:00 which the protocol won’t parse.
This is of course a perfectly valid protocol. Thus the protocol parser 
would not write any errors. Only your device cannot handle it. Switch on 
"var streamError 1" and you will see the messages you are looking for.
The idea was to turn on errors during commissioning of a new device to 
see any wrong protocols and such, but leave it turned off later during 
normal operation and only use check record severity and status.
Dirk


On 15.02.19 20:46, Mark Rivers wrote:
> Hi Dirk,
>
> Thanks for the reply.
>
> Are there release notes for StreamDevice somewhere?  I cannot find them 
> on Github or on the PSI web site.  This change in error behavior seems 
> to me something that should be documented.
> I think the protocol error reporting is not fixed in 2.8.8.
>
> ØI always wanted to rework the error and debug message system, in 
> particular to allow filtering per record, but I never found the time.
> I suggested some time back that it would be good for streamDevice to 
> print messages using ASYN_TRACE_ERROR, ASYN_TRACE_FLOW, and 
> ASYN_TRACEIO_DEVICE for the underlying asyn port.  Then at least users 
> have control over the error and debugging information on a per-port 
> basis.  I understand that the core of Stream is intended to be 
> independent of asyn.  But in practice I think only asyn is used?  The 
> error handling could be made to hide asyn, so that is uses asyn if 
> available, and something else if not.
> Thanks,
>
> Mark
>
> *From:* Zimoch Dirk (PSI) <dirk.zimoch@psi.ch>
> *Sent:* Friday, February 15, 2019 1:20 PM
> *To:* Mark Rivers <rivers@cars.uchicago.edu>
> *Cc:* tech-talk@aps.anl.gov
> *Subject:* Re: Problems with StreamDevice
>
> People here at PSI had complained about error message flooding when 
> devices go crazy or are offline. Softiocs had filled their disks with 
> logs and such.
> Thus I have heavily reduced the amount of error output.
>
> StreamDevice sets asynTraceMask to 0. This has already been reported as 
> a bug arguing it is not StreamsDevice‘s responsibility to silence other 
> code. And it does so in iocInit, so that user settings in the startup 
> script are ignored. I am somewhat convinced that this is a valid 
> argument and will change it soon.
> StreamDevice suppresses its own error messages by default now. You can 
> re-enable error messages with var streamError 1.
> In the first 2.8 versions this also suppressed parsing errors which was 
> very inconvenient. This should not happen any more. Errors are enabled 
> while reading the protocol file. I will check in which version this is 
> the case on Monday. But I thought this was already fixed in 2.8.8.
> I always wanted to rework the error and debug message system, in 
> particular to allow filtering per record, but I never found the time.
> Dirk
>
>
> Am 15.02.2019 um 19:17 schrieb Mark Rivers <rivers@cars.uchicago.edu 
> <mailto:rivers@cars.uchicago.edu>>:
>     I am running StreamDevice 2.8.8.  I am having 3 issues.  I don’t
>     know if these are bugs or features, because I cannot find the
>     release notes for StreamDevice.  Where are they located?
>
>     1)StreamDevice seems to set asynTraceMask to 0 for the port.
>
>     This is my startup script.
>
>     **************************
>
>     < envPaths
>
>     # Tell EPICS all about the record types, device-support modules,
>     drivers,
>
>     # etc. in this build from CARS
>
>     dbLoadDatabase("../../dbd/CARSLinux.dbd")
>
>     CARSLinux_registerRecordDeviceDriver(pdbbase)
>
>     drvAsynIPPortConfigure("PORT","gse-tetramm2:10001",0,0,0)
>
>     asynOctetSetInputEos(PORT, 0, "\r\n")
>
>     asynOctetSetOutputEos(PORT, 0, "\r")
>
>     asynSetTraceIOMask(PORT, 0, 2)
>
>     asynSetTraceMask(PORT, 0, 9)
>
>     asynSetOption(PORT, 0, "disconnectOnReadTimeout", "Y")
>
>     dbLoadRecords("stream2.db", "P=13TEST:, R=R:, PORT=PORT")
>
>     dbLoadRecords("$(ASYN)/db/asynRecord.db", "P=13TEST:, R=asyn1,
>     PORT=PORT, ADDR=0, IMAX=80, OMAX=80")
>
>     iocInit
>
>     **************************
>
>     Note that it sets the trace mask to 9 with asynSetTraceMask. 
>     However, when I boot and look at the trace mask with asynReport it
>     is 0.  The TraceIOMask is 2 like I set it, but the traceMask is 0.
>
>     **************************
>
>     epics> asynReport 10
>
>     PORT multiDevice:No canBlock:Yes autoConnect:Yes
>
>          enabled:Yes connected:Yes numberConnects 1
>
>          nDevices 0 nQueued 0 blocked:No
>
>          asynManagerLock:No synchronousLock:No
>
>          exceptionActive:No exceptionUsers 5 exceptionNotifys 0
>
>          traceMask:0x0 traceIOMask:0x2 traceInfoMask:0x1
>
>          interposeInterfaceList
>
>              asynOctet pinterface 0x1da89e0 drvPvt 0x3624870
>
>          interfaceList
>
>              asynCommon pinterface 0x1ce6770 drvPvt 0x3620c10
>
>              asynOption pinterface 0x1ce6790 drvPvt 0x3620c10
>
>              asynOctet pinterface 0x3620d30 drvPvt 0x3620c10
>
>          Port gse-tetramm2:10001: Connected
>
>                          fd: 5
>
>          Characters written: 152
>
>             Characters read: 208
>
>     **************************
>
>     If I uncomment the line that loads the StreamDevice records then
>     asynTrace is set correctly when I boot.
>
>     #dbLoadRecords("stream2.db", "P=13TEST:, R=R:, PORT=PORT")
>
>     **************************
>
>     epics> asynReport 10
>
>     PORT multiDevice:No canBlock:Yes autoConnect:Yes
>
>          enabled:Yes connected:Yes numberConnects 1
>
>          nDevices 0 nQueued 0 blocked:No
>
>          asynManagerLock:No synchronousLock:No
>
>          exceptionActive:No exceptionUsers 2 exceptionNotifys 0
>
>          traceMask:0x9 traceIOMask:0x2 traceInfoMask:0x1
>
>          interposeInterfaceList
>
>              asynOctet pinterface 0x1da89e0 drvPvt 0x2c6b830
>
>          interfaceList
>
>              asynCommon pinterface 0x1ce6770 drvPvt 0x2c67bd0
>
>              asynOption pinterface 0x1ce6790 drvPvt 0x2c67bd0
>
>              asynOctet pinterface 0x2c67cf0 drvPvt 0x2c67bd0
>
>          Port gse-tetramm2:10001: Connected
>
>                          fd: 6
>
>          Characters written: 0
>
>             Characters read: 0
>
>     **************************
>
>     If I put the asynSetTraceMask after iocInit it works.  Is this
>     indeed something StreamDevice is doing?
>
>     2)If I have an error in my protocol file I am not seeing any error
>     messages.  I used to see them in previous versions.
>
>     This is what the protocol should be, command is CHN.
>
>     readChans {
>
>         out "CHN:?";
>
>         in "CHN:%d";
>
>     }
>
>     If I break the protocol by changing CHN to CHAN
>
>     readChans {
>
>         out "CHAN:?";
>
>         in "CHAN:%d";
>
>     }
>
>     then this is what I see with asynTrace on.  Note that the CHAN:?
>     command returned NAK:00 which the protocol won’t parse.
>
>     2019/02/15 12:07:15.074 gse-tetramm2:10001 write 7
>
>     CHAN:?\r
>
>     2019/02/15 12:07:15.075 gse-tetramm2:10001 read 8
>
>     NAK:00\r\n
>
>     2019/02/15 12:07:15.077 gse-tetramm2:10001 write 6
>
>     HVV:?\r
>
>     2019/02/15 12:07:15.078 gse-tetramm2:10001 read 10
>
>     HVV:0.00\r\n
>
>     The record is indeed in invalid alarm but I don’t see any error
>     messages from StreamDevice (STAT=CALC, SEVR=INVALID).  Is this new
>     behavior to see no errors?
>
>     epics> dbpr 13TEST:R:Chans 3
>
>     ACKS: INVALID       ACKT: YES           ADEL: 0             AFTC: 0
>
>     AFVL: 0             ALST: 0             AOFF: 0             ASG :
>
>     ASLO: 1             BKPT: 00            DESC:               DISA: 0
>
>     DISP: 0             DISS: NO_ALARM      DISV: 1             DTYP: stream
>
>     EGU :               EGUF: 0             EGUL: 0             EOFF: 0
>
>     ESLO: 1             EVNT:               FLNK: CONSTANT      HHSV:
>     NO_ALARM
>
>     HIGH: 0             HIHI: 0             HOPR: 0             HSV :
>     NO_ALARM
>
>     HYST: 0             INIT: 0
>
>     INP : INST_IO @stream2.proto readChans PORT 0 0             LALM: 0
>
>     LBRK: 0             LCNT: 0             LINR: NO CONVERSION LLSV:
>     NO_ALARM
>
>     LOLO: 0             LOPR: 0             LOW : 0             LSV :
>     NO_ALARM
>
>     MDEL: 0             MLST: 0             NAME: 13TEST:R:Chans
>
>     NSEV: NO_ALARM      NSTA: NO_ALARM      ORAW: 0             PACT: 0
>
>     PHAS: 0             PINI: NO            PREC: 0             PRIO: LOW
>
>     PROC: 0             PUTF: 0             ROFF: 0             RPRO: 0
>
>     RVAL: 0             SCAN: 1 second      SDIS: CONSTANT      SDLY: -1
>
>     SEVR: INVALID       SIML: CONSTANT      SIMM: NO            SIMS:
>     NO_ALARM
>
>     SIOL: CONSTANT      SMOO: 0             SSCN: <nil>         STAT: CALC
>
>     SVAL: 0             TIME: 2019-02-15 12:10:16.524791659     TPRO: 0
>
>     TSE : 0             TSEL: CONSTANT      UDF : 1             UDFS:
>     INVALID
>
>     VAL : 0
>
>     3)If I have a communications error I don’t see any error messages. 
>     I used to see them in previous versions.  This is what I see when I
>     disconnect the cable to my device.
>
>     2019/02/15 12:12:18.494 gse-tetramm2:10001 read 10
>
>     HVV:0.00\r\n
>
>     2019/02/15 12:12:19.488 gse-tetramm2:10001 write 7  CABLE DISCONNECTED
>
>     TEMP:?\r
>
>     2019/02/15 12:12:36.488 gse-tetramm2:10001 write 7
>
>     TEMP:?\r
>
>     2019/02/15 12:12:36.489 gse-tetramm2:10001 read 9
>
>     There are no error messages from StreamDevice.  This is with
>     disconnectOnReadTimeout=Y, but there are no messages with that not
>     set either.
>
>     Thanks,
>
>     Mark