Experimental Physics and
Industrial Control System

Zimoch Dirk via Tech-talk <tech-talk at aps.anl.gov> · Thu, 1 Feb 2024 10:15:19 +0000

Hi Maximilian,

I see in your debug output: "lockRequest failed. Device is offline."
That means asyn still sees the port disconnected. To be exact, pasynManager-
>queueRequest() failed.

Later I see: "lockRequest: status returned to normal"
At this time asyn sees the port connected. Now things should start to work.
Writing seems successful but no reply is received within the ReplyTimeout.

Maybe you use the asynDriver debugging to see what it tries to send on the wire
and what it receives? If also asyn reports to send the command but received
nothing, the problem seems to be somewhere down the USB-RS485-device path. Can
you tap the RS485 bus to see what is going over the wire?

I have used StreamDevice with RS485 over USB successfully on Linux hosts and
switching on the device late worked. Thus, I cannot imagine a fundamental
problem in asyn or StreamDevice with this setup. But I neither have your device
type to test with nor a Windows host.

I guess your COM port is still there when your device is switched off, since you
would not switch off the USB/RHE485 converter, right?

Does your device require any kind of initialization to start replying? Anything
that you send at IOC start only (e.g. using PINI=YES) which is missed when
device is switched on later?

Dirk

On Thu, 2024-02-01 at 10:26 +0100, Maximilian Scharpey via Tech-talk wrote:
> Hi all,
>  
> I am trying to implement the communication to a voltage source (CAEN N1470A) using Stream Device. The communication is done via USB using an RS485 protocol and I use EPICS base 7 on Windows. So far, communication is successfully established but only if the IOC is started while the source is already turned ON. As it is planned to use the source only for short periods on a larger setup (which has an IOC running day and night), it would be nice if one would not have to kill the IOC every time one wants to use the voltage source.
> As I am not very experienced with Stream Device, maybe someone of you can help me out. I do not think, it is a problem of too many communication attempts as the issue also occurs if only one PV is used regarding the voltage source.
>  
> In the following I copied the excerpts of the .db, .proto, and .cmd files for a minimal example, I am currently running on an external PC. I also copied the messages of the IOC console in the streamDebug mode.
>  
> module.db:
> record(bi, "$(P):MOD$(MOD):CTRMODE"){
>     field(DTYP, "stream")
>     field(INP, "@CAEN_N14xx.proto getControlMode($(MOD)) $(BUS)")
>     field(ZNAM, "LOCAL")
>     field(ONAM, "REMOTE")
>     field(PINI, "YES")
>     field(SCAN, "2 second")
>     field(ASG, "$(ASG)")
> }
>  
> CAEN_N14xx.proto:
> Terminator=CR LF;
>  
> getControlMode{
>   out "$BD:\$1,CMD:MON,PAR:BDCTR";
>   in "#BD:\$1,CMD:OK,VAL:%{LOCAL|REMOTE}";
> }
>  
> CAEN_N14xx.cmd (executed by the st.cmd):
> drvAsynSerialPortConfigure("ttyCAEN", "\\\\.\\COM4")
> asynSetOption( "ttyCAEN", 0, "baud", "38400" )
> asynSetOption( "ttyCAEN", 0, "bits", "8" )
> asynSetOption( "ttyCAEN", 0, "parity", "none" )
> asynSetOption( "ttyCAEN", 0, "stop", "1" )
> asynSetOption( "ttyCAEN", 0, "clocal", "Y" )
> asynSetOption( "ttyCAEN", 0, "crtscts", "N" )
> asynSetOption( "ttyCAEN", 0, "ixon", "N" )
> asynSetOption( "ttyCAEN", 0, "ixoff", "N" )
>  
> # CAEN N1470A
> dbLoadRecords("$(TOP)\db\CAEN_N14xx_module.db", "P=${P}:CAEN_N1470a, MOD=01, BUS=ttyCAEN", ASG=${ASG})
> echo 'CAEN \n'
>  
>  
> Console Output Voltage source is turned ON while IOC is running:
> 2024/02/01 10:15:03.066110 scan-2 C:\opt\epics\modules\streamdevice\src\StreamEpics.cc:908: Stream::process(PIKP612:CAEN_N1470a:MOD01:CTRMODE)
> 2024/02/01 10:15:03.069764 scan-2 C:\opt\epics\modules\streamdevice\src\StreamEpics.cc:934: Stream::process(PIKP612:CAEN_N1470a:MOD01:CTRMODE) start
> 2024/02/01 10:15:03.072676 scan-2 C:\opt\epics\modules\streamdevice\src\StreamCore.cc:429: StreamCore::startProtocol(PIKP612:CAEN_N1470a:MOD01:CTRMODE, startMode=StartNormal)
> 2024/02/01 10:15:03.075936 scan-2 C:\opt\epics\modules\streamdevice\src\StreamCore.cc:564: StreamCore::evalCommand(PIKP612:CAEN_N1470a:MOD01:CTRMODE): activeCommand = out
> 2024/02/01 10:15:03.079136 scan-2 C:\opt\epics\modules\streamdevice\src\StreamCore.cc:612: StreamCore::evalOut: outputLine = "$BD:01,CMD:MON,PAR:BDCTR<0d><0a>"
> 2024/02/01 10:15:03.083628 scan-2 C:\opt\epics\modules\streamdevice\src\StreamCore.cc:623: StreamCore::evalOut(PIKP612:CAEN_N1470a:MOD01:CTRMODE): lockRequest(5000)
> 2024/02/01 10:15:03.087973 scan-2 C:\opt\epics\modules\streamdevice\src\AsynDriverInterface.cc:549: AsynDriverInterface::lockRequest(PIKP612:CAEN_N1470a:MOD01:CTRMODE, 5000 msec)
> 2024/02/01 10:15:03.091592 scan-2 C:\opt\epics\modules\streamdevice\src\StreamCore.cc:629: StreamCore::evalOut(PIKP612:CAEN_N1470a:MOD01:CTRMODE): lockRequest failed. Device is offline.
> 2024/02/01 10:15:03.095039 scan-2 C:\opt\epics\modules\streamdevice\src\StreamCore.cc:465: StreamCore::finishProtocol(PIKP612:CAEN_N1470a:MOD01:CTRMODE, Offline) not bus owner
> 2024/02/01 10:15:03.099590 scan-2 C:\opt\epics\modules\streamdevice\src\AsynDriverInterface.cc:1468: AsynDriverInterface::finish(PIKP612:CAEN_N1470a:MOD01:CTRMODE) start
> 2024/02/01 10:15:03.103732 scan-2 C:\opt\epics\modules\streamdevice\src\AsynDriverInterface.cc:1478: AsynDriverInterface::finish(PIKP612:CAEN_N1470a:MOD01:CTRMODE) done
> 2024/02/01 10:15:03.106943 scan-2 C:\opt\epics\modules\streamdevice\src\StreamEpics.cc:1034: Stream::protocolFinishHook(PIKP612:CAEN_N1470a:MOD01:CTRMODE, Offline)
> 2024/02/01 10:15:03.110014 scan-2 C:\opt\epics\modules\streamdevice\src\StreamEpics.cc:939: Stream::process(PIKP612:CAEN_N1470a:MOD01:CTRMODE): could not start protocol, status=COMM (9)
> 2024/02/01 10:15:04.471844 ttyCAEN C:\opt\epics\modules\streamdevice\src\AsynDriverInterface.cc:1316: AsynDriverInterface::exceptionHandler(PIKP612:CAEN_N1470a:MOD01:CTRMODE, Connect)
> 2024/02/01 10:15:04.475524 ttyCAEN C:\opt\epics\modules\streamdevice\src\AsynDriverInterface.cc:1322: AsynDriverInterface::exceptionHandler(PIKP612:CAEN_N1470a:MOD01:CTRMODE) ttyCAEN 0 connected. ioAction: None
> 2024/02/01 10:15:04.479496 ttyCAEN C:\opt\epics\modules\streamdevice\src\StreamCore.cc:1736: StreamCore::connectCallback(PIKP612:CAEN_N1470a:MOD01:CTRMODE, StreamIoSuccess) activeCommand: end
> 2024/02/01 10:15:04.483956 ttyCAEN C:\opt\epics\modules\streamdevice\src\StreamCore.cc:429: StreamCore::startProtocol(PIKP612:CAEN_N1470a:MOD01:CTRMODE, startMode=StartInit)
> 2024/02/01 10:15:05.064406 scan-2 C:\opt\epics\modules\streamdevice\src\StreamEpics.cc:908: Stream::process(PIKP612:CAEN_N1470a:MOD01:CTRMODE)
> 2024/02/01 10:15:05.068045 scan-2 C:\opt\epics\modules\streamdevice\src\StreamEpics.cc:934: Stream::process(PIKP612:CAEN_N1470a:MOD01:CTRMODE) start
> 2024/02/01 10:15:05.070964 scan-2 C:\opt\epics\modules\streamdevice\src\StreamCore.cc:429: StreamCore::startProtocol(PIKP612:CAEN_N1470a:MOD01:CTRMODE, startMode=StartNormal)
> 2024/02/01 10:15:05.074244 scan-2 C:\opt\epics\modules\streamdevice\src\StreamCore.cc:564: StreamCore::evalCommand(PIKP612:CAEN_N1470a:MOD01:CTRMODE): activeCommand = out
> 2024/02/01 10:15:05.077638 scan-2 C:\opt\epics\modules\streamdevice\src\StreamCore.cc:612: StreamCore::evalOut: outputLine = "$BD:01,CMD:MON,PAR:BDCTR<0d><0a>"
> 2024/02/01 10:15:05.082365 scan-2 C:\opt\epics\modules\streamdevice\src\StreamCore.cc:623: StreamCore::evalOut(PIKP612:CAEN_N1470a:MOD01:CTRMODE): lockRequest(5000)
> 2024/02/01 10:15:05.086921 scan-2 C:\opt\epics\modules\streamdevice\src\AsynDriverInterface.cc:549: AsynDriverInterface::lockRequest(PIKP612:CAEN_N1470a:MOD01:CTRMODE, 5000 msec)
> 2024/02/01 10:15:05.090557 scan-2 PIKP612:CAEN_N1470a:MOD01:CTRMODE lockRequest: status returned to normal
> 2024/02/01 10:15:05.090563 ttyCAEN C:\opt\epics\modules\streamdevice\src\AsynDriverInterface.cc:590: AsynDriverInterface::lockHandler(PIKP612:CAEN_N1470a:MOD01:CTRMODE)
> 2024/02/01 10:15:05.092753 scan-2 C:\opt\epics\modules\streamdevice\src\StreamEpics.cc:948: Stream::process(PIKP612:CAEN_N1470a:MOD01:CTRMODE): protocol started
> 2024/02/01 10:15:05.102839 ttyCAEN C:\opt\epics\modules\streamdevice\src\StreamCore.cc:832: StreamCore::lockCallback(PIKP612:CAEN_N1470a:MOD01:CTRMODE, StreamIoSuccess)
> 2024/02/01 10:15:05.106172 ttyCAEN C:\opt\epics\modules\streamdevice\src\AsynDriverInterface.cc:627: AsynDriverInterface::writeRequest(PIKP612:CAEN_N1470a:MOD01:CTRMODE, "$BD:01,CMD:MON,PAR:BDCTR<0d><0a>", 100 msec)
> 2024/02/01 10:15:05.110291 ttyCAEN C:\opt\epics\modules\streamdevice\src\AsynDriverInterface.cc:649: AsynDriverInterface::writeHandler(PIKP612:CAEN_N1470a:MOD01:CTRMODE)
> 2024/02/01 10:15:05.114659 ttyCAEN C:\opt\epics\modules\streamdevice\src\AsynDriverInterface.cc:667: AsynDriverInterface::writeHandler(PIKP612:CAEN_N1470a:MOD01:CTRMODE): reading old input
> 2024/02/01 10:15:05.118347 ttyCAEN C:\opt\epics\modules\streamdevice\src\AsynDriverInterface.cc:715: AsynDriverInterface::writeHandler(PIKP612:CAEN_N1470a:MOD01:CTRMODE): write(..., "$BD:01,CMD:MON,PAR:BDCTR<0d><0a>", outputSize=26, written=26) [timeout=0.1 sec] = asynSuccess
> 2024/02/01 10:15:05.123681 ttyCAEN C:\opt\epics\modules\streamdevice\src\StreamCore.cc:877: StreamCore::writeCallback(PIKP612:CAEN_N1470a:MOD01:CTRMODE, StreamIoSuccess)
> 2024/02/01 10:15:05.126886 ttyCAEN C:\opt\epics\modules\streamdevice\src\StreamCore.cc:564: StreamCore::evalCommand(PIKP612:CAEN_N1470a:MOD01:CTRMODE): activeCommand = in
> 2024/02/01 10:15:05.131769 ttyCAEN C:\opt\epics\modules\streamdevice\src\AsynDriverInterface.cc:806: AsynDriverInterface::readRequest(PIKP612:CAEN_N1470a:MOD01:CTRMODE, 1000 msec reply, 100 msec read, expect 0 bytes, async=no)
> 2024/02/01 10:15:05.135975 ttyCAEN C:\opt\epics\modules\streamdevice\src\AsynDriverInterface.cc:831: AsynDriverInterface::readRequest PIKP612:CAEN_N1470a:MOD01:CTRMODE: queueRequest(..., priority=0, queueTimeout=1 sec) = asynSuccess [async=false]
> 2024/02/01 10:15:06.149378 ttyCAEN C:\opt\epics\modules\streamdevice\src\AsynDriverInterface.cc:951: AsynDriverInterface::readHandler(PIKP612:CAEN_N1470a:MOD01:CTRMODE): ioAction=Read read(1 bytes, timeout=1 sec) returned status asynTimeout: received=0 bytes, eomReason=NONE, buffer=""
> 2024/02/01 10:15:06.155608 ttyCAEN C:\opt\epics\modules\streamdevice\src\AsynDriverInterface.cc:1044: AsynDriverInterface::readHandler(PIKP612:CAEN_N1470a:MOD01:CTRMODE): no reply
> 2024/02/01 10:15:06.158981 ttyCAEN C:\opt\epics\modules\streamdevice\src\StreamCore.cc:963: StreamCore::readCallback(PIKP612:CAEN_N1470a:MOD01:CTRMODE, StreamIoNoReply input="", size=0)
> 2024/02/01 10:15:06.162449 ttyCAEN PIKP612:CAEN_N1470a:MOD01:CTRMODE: No reply within 1000 ms to "$BD:01,CMD:MON,PAR:BDCTR<0d><0a>"
> 2024/02/01 10:15:06.165361 ttyCAEN C:\opt\epics\modules\streamdevice\src\StreamCore.cc:465: StreamCore::finishProtocol(PIKP612:CAEN_N1470a:MOD01:CTRMODE, ReplyTimeout) bus owner
> 2024/02/01 10:15:06.168668 ttyCAEN C:\opt\epics\modules\streamdevice\src\StreamCore.cc:534: starting exception handler
> 2024/02/01 10:15:06.171005 ttyCAEN C:\opt\epics\modules\streamdevice\src\StreamCore.cc:564: StreamCore::evalCommand(PIKP612:CAEN_N1470a:MOD01:CTRMODE): activeCommand = end
> 2024/02/01 10:15:06.174203 ttyCAEN C:\opt\epics\modules\streamdevice\src\StreamCore.cc:465: StreamCore::finishProtocol(PIKP612:CAEN_N1470a:MOD01:CTRMODE, Success) bus owner
> 2024/02/01 10:15:06.177446 ttyCAEN C:\opt\epics\modules\streamdevice\src\AsynDriverInterface.cc:610: AsynDriverInterface::unlock(PIKP612:CAEN_N1470a:MOD01:CTRMODE)
> 2024/02/01 10:15:06.182009 ttyCAEN C:\opt\epics\modules\streamdevice\src\AsynDriverInterface.cc:1468: AsynDriverInterface::finish(PIKP612:CAEN_N1470a:MOD01:CTRMODE) start
> 2024/02/01 10:15:06.185846 ttyCAEN C:\opt\epics\modules\streamdevice\src\AsynDriverInterface.cc:1478: AsynDriverInterface::finish(PIKP612:CAEN_N1470a:MOD01:CTRMODE) done
> 2024/02/01 10:15:06.189048 ttyCAEN C:\opt\epics\modules\streamdevice\src\StreamEpics.cc:1034: Stream::protocolFinishHook(PIKP612:CAEN_N1470a:MOD01:CTRMODE, ReplyTimeout)
> 2024/02/01 10:15:06.192313 cbLow C:\opt\epics\modules\streamdevice\src\StreamEpics.cc:1112: recordProcessCallback(PIKP612:CAEN_N1470a:MOD01:CTRMODE) processing record
> 2024/02/01 10:15:06.197327 cbLow C:\opt\epics\modules\streamdevice\src\StreamEpics.cc:908: Stream::process(PIKP612:CAEN_N1470a:MOD01:CTRMODE)
> 2024/02/01 10:15:06.201432 cbLow C:\opt\epics\modules\streamdevice\src\StreamEpics.cc:914: Stream::process(PIKP612:CAEN_N1470a:MOD01:CTRMODE) error status=TIMEOUT (10)
> 2024/02/01 10:15:06.204718 cbLow C:\opt\epics\modules\streamdevice\src\StreamEpics.cc:1116: recordProcessCallback(PIKP612:CAEN_N1470a:MOD01:CTRMODE) processing record done
>  

Experimental Physics and Industrial Control System

Experimental Physics and
Industrial Control System