RE: Issue with Stream Device. Timeout only on Reconnect

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

Hi Max,

This could be done outside of StreamDevice as well.

A simple database like this could be used.  The asyn record .CNCT field changes to 1 when the device reconnects.  A calcout record monitors that field and processes a sseq record when reconnects occur.  The sseq record writes the correct options using the asyn record.

record(asyn, "myAsyn") {
    field (PORT, "myPort")
}

record(calcout, "myCalcout") {
    field(INP, "myAsyn.CNCT CP MS")
    field(VAL, "1")
    field(OOPT, "Transition To Non-zero")
    field(OUT, "mySseq.PROC PP")
}

record(sseq, "mySseq") {
    field(LNK1, "myAsyn.BAUD PP")
    field(STR1, "9600")
    field(LNK2, "myAsyn.PRTY PP")
    field(STR2, "Even")
}


-----Original Message-----
From: Tech-talk <tech-talk-bounces at aps.anl.gov> On Behalf Of Zimoch Dirk via Tech-talk
Sent: Monday, February 5, 2024 8:56 AM
To: tech-talk at aps.anl.gov; mscharpey at uni-muenster.de
Subject: Re: Issue with Stream Device. Timeout only on Reconnect

Hi Max,

If the asyn port supports disconnect/connect exceptions, you can. I think that the Windows serial port implementation supports auto-connnect and sends asynExceptionConnect events when it (re-)connects. So it should be possible.

StreamDevice installs an exception callback which runs @init protocols on asynExceptionConnect events. This allows to put all the needed initialization into the @init handler of one record (not globally or it will run the handler once for every record connected to that port!). In that handler you can use the 'exec' command to run iocsh commands:

protocol_for_one_record {
 # [...] (The normal protocol)

 @init {
  exec "asynSetOption(ttyCAEN, 0, baud, 38400)";  } }

@init runs when the ioc starts (in iocInit) or restarts (iocRun after iocPause), when the asyn port driver sends asynExceptionConnect (i.e. calls pasynManager->
exceptionConnect) or when you write 2 into the .PROC field of the record.

Dirk

On Mon, 2024-02-05 at 12:41 +0100, Maximilian Scharpey wrote:
> Hi,
> 
> that was a very good idea. Indeed, the asyn Options are not properly set on reconnect. We tested it with the baud rate. Do you know, how we can also execute the asynSetOption commands in case of the  reconnect?
> 
> Regards Max
> 
> -----Original Message-----
> From: Zimoch Dirk <dirk.zimoch at psi.ch>
> Sent: Montag, 5. Februar 2024 11:53
> To: tech-talk at aps.anl.gov; mscharpey at uni-muenster.de
> Subject: Re: Issue with Stream Device. Timeout only on Reconnect
> 
> Hi Maximilian,
> 
> If the COM port is gone, it will probably not get the asynSetOption setups when it comes back (AFAIK). Thus any non-default setting, e.g. baud rate, may be wrong.
> 
> Try to check with asynShowOption if any settings have changed after the device was switched off.
> 
> Dirk
> 
> On Mon, 2024-02-05 at 10:52 +0100, Maximilian Scharpey wrote:
> > Hi Dirk,
> > thanks for your reply. I had some trouble getting into the asynDriver debugging, but now I was able to look into it. asyn shows basically the same symptom as StreamDevice. It is able to reconnect, successfully sends the command and then no reply comes back. I pasted the console output down below. To your other questions: I am not able to tap the RS485 as the USB/serial converter is installed inside the device. Therefore, the COM Port is gone, if the device is switched OFF as the converter is powered by the device.
> > The same behavior of the PV as before is observable if the PINI field of the PV is set to “NO”.
> >  
> > Console Output for device ON and communication working -> device OFF -> device ON communication not Working:
> > 2024/02/05 10:17:49.917 ttyCAEN set Eos 0
> > 2024/02/05 10:17:51.801 ttyCAEN addr -1 queueRequest priority 0 not 
> > lockHolder
> > 2024/02/05 10:17:51.803 ttyCAEN schedule queueRequest timeout in
> > 5.000000 seconds
> > 2024/02/05 10:17:51.805 asynManager::portThread port=ttyCAEN 
> > callback
> > 2024/02/05 10:17:51.806 ttyCAEN addr -1 queueRequest priority 0 not 
> > lockHolder
> > 2024/02/05 10:17:51.808 ttyCAEN schedule queueRequest timeout in
> > 0.100000 seconds
> > 2024/02/05 10:17:51.809 asynManager::portThread port=ttyCAEN 
> > callback
> > 2024/02/05 10:17:51.811 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.812 \\.\\\\\.\\COM4 read 0, return 1
> > 2024/02/05 10:17:51.813 ttyCAEN get Eos 0
> > 2024/02/05 10:17:51.814 ttyCAEN set Eos 0
> > 2024/02/05 10:17:51.814 \\.\\\\\.\\COM4 write.
> > 2024/02/05 10:17:51.815 \\.\\\\\.\\COM4 write 26 
> > $BD:01,CMD:MON,PAR:BDCTR
> >  
> > 2024/02/05 10:17:51.818 wrote 26 to \\.\\\\\.\\COM4, return 
> > asynSuccess
> > 2024/02/05 10:17:51.819 ttyCAEN set Eos 0
> > 2024/02/05 10:17:51.820 ttyCAEN addr -1 queueRequest priority 0 from 
> > lockHolder
> > 2024/02/05 10:17:51.821 ttyCAEN schedule queueRequest timeout in
> > 1.000000 seconds
> > 2024/02/05 10:17:51.823 asynManager::portThread port=ttyCAEN 
> > callback
> > 2024/02/05 10:17:51.824 ttyCAEN get Eos 0
> > 2024/02/05 10:17:51.825 ttyCAEN set Eos 2
> >  
> >  
> > 2024/02/05 10:17:51.826 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.837 \\.\\\\\.\\COM4 read 1 #
> > 2024/02/05 10:17:51.839 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.840 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.841 \\.\\\\\.\\COM4 read 1 B
> > 2024/02/05 10:17:51.842 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.843 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.844 \\.\\\\\.\\COM4 read 1 D
> > 2024/02/05 10:17:51.845 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.846 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.847 \\.\\\\\.\\COM4 read 1
> > :
> > 2024/02/05 10:17:51.849 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.850 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.851 \\.\\\\\.\\COM4 read 1
> > 0
> > 2024/02/05 10:17:51.852 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.853 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.854 \\.\\\\\.\\COM4 read 1
> > 1
> > 2024/02/05 10:17:51.855 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.856 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.857 \\.\\\\\.\\COM4 read 1 ,
> > 2024/02/05 10:17:51.858 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.859 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.860 \\.\\\\\.\\COM4 read 1 C
> > 2024/02/05 10:17:51.861 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.862 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.863 \\.\\\\\.\\COM4 read 1 M
> > 2024/02/05 10:17:51.865 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.866 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.867 \\.\\\\\.\\COM4 read 1 D
> > 2024/02/05 10:17:51.868 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.869 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.870 \\.\\\\\.\\COM4 read 1
> > :
> > 2024/02/05 10:17:51.871 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.872 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.873 \\.\\\\\.\\COM4 read 1 O
> > 2024/02/05 10:17:51.874 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.875 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.876 \\.\\\\\.\\COM4 read 1 K
> > 2024/02/05 10:17:51.877 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.878 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.880 \\.\\\\\.\\COM4 read 1 ,
> > 2024/02/05 10:17:51.881 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.882 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.883 \\.\\\\\.\\COM4 read 1 V
> > 2024/02/05 10:17:51.884 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.885 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.886 \\.\\\\\.\\COM4 read 1 A
> > 2024/02/05 10:17:51.887 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.888 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.889 \\.\\\\\.\\COM4 read 1 L
> > 2024/02/05 10:17:51.890 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.891 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.892 \\.\\\\\.\\COM4 read 1
> > :
> > 2024/02/05 10:17:51.893 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.894 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.895 \\.\\\\\.\\COM4 read 1 R
> > 2024/02/05 10:17:51.897 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.898 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.899 \\.\\\\\.\\COM4 read 1 E
> > 2024/02/05 10:17:51.900 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.901 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.902 \\.\\\\\.\\COM4 read 1 M
> > 2024/02/05 10:17:51.903 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.904 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.905 \\.\\\\\.\\COM4 read 1 O
> > 2024/02/05 10:17:51.906 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.907 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.908 \\.\\\\\.\\COM4 read 1 T
> > 2024/02/05 10:17:51.910 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.911 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.912 \\.\\\\\.\\COM4 read 1 E
> > 2024/02/05 10:17:51.914 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.914 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.915 \\.\\\\\.\\COM4 read 1
> >  
> > 2024/02/05 10:17:51.917 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.918 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:51.918 \\.\\\\\.\\COM4 read 1
> >  
> >  
> > 2024/02/05 10:17:51.920 \\.\\\\\.\\COM4 read 1, return 0
> > 2024/02/05 10:17:51.921 ttyCAEN set Eos 0
> > 2024/02/05 10:17:53.803 ttyCAEN addr -1 queueRequest priority 0 not 
> > lockHolder
> > 2024/02/05 10:17:53.805 ttyCAEN schedule queueRequest timeout in
> > 5.000000 seconds
> > 2024/02/05 10:17:53.807 asynManager::portThread port=ttyCAEN 
> > callback
> > 2024/02/05 10:17:53.809 ttyCAEN addr -1 queueRequest priority 0 not 
> > lockHolder
> > 2024/02/05 10:17:53.810 ttyCAEN schedule queueRequest timeout in
> > 0.100000 seconds
> > 2024/02/05 10:17:53.812 asynManager::portThread port=ttyCAEN 
> > callback
> > 2024/02/05 10:17:53.813 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:17:53.814 ttyCAEN get Eos 0
> > 2024/02/05 10:17:53.815 ttyCAEN set Eos 0
> > 2024/02/05 10:17:53.816 \\.\\\\\.\\COM4 write.
> > 2024/02/05 10:17:53.817 \\.\\\\\.\\COM4 write 26 
> > $BD:01,CMD:MON,PAR:BDCTR
> >  
> > 2024/02/05 10:17:53.819 Close \\.\\\\\.\\COM4 connection.
> > 2024/02/05 10:17:53.821 PIKP612asyn: exception 0, 
> > asynExceptionConnect
> > 2024/02/05 10:17:53.822 wrote 0 to \\.\\\\\.\\COM4, return asynError
> > 2024/02/05 10:17:53.823 Open connection to \\.\\\\\.\\COM4
> > 2024/02/05 10:17:53.824599 ttyCAEN PIKP612:CAEN_N1470a:MOD01:CTRMODE
> > connectToAsynPort: \\.\\\\\.\\COM4 Can't open  No error
> > 2024/02/05 10:17:53.825 ttyCAEN addr -1 queueRequest priority 3 not 
> > lockHolder
> > 2024/02/05 10:17:53.829 ttyCAEN set Eos 0
> > 2024/02/05 10:17:53.829388 ttyCAEN PIKP612:CAEN_N1470a:MOD01:CTRMODE: 
> > device ttyCAEN 0 disconnected
> > 2024/02/05 10:17:53.831 asynManager connect queueCallback 
> > port:ttyCAEN
> > 2024/02/05 10:17:53.833 Open connection to \\.\\\\\.\\COM4
> > 2024/02/05 10:17:55.804856 scan-2 PIKP612:CAEN_N1470a:MOD01:CTRMODE
> > lockRequest: port ttyCAEN not connected
> > 2024/02/05 10:18:13.827 ttyCAEN addr -1 queueRequest priority 3 not 
> > lockHolder
> > 2024/02/05 10:18:13.829 asynManager connect queueCallback 
> > port:ttyCAEN
> > 2024/02/05 10:18:13.831 Open connection to \\.\\\\\.\\COM4
> > 2024/02/05 10:18:13.848 Opened connection to \\.\\\\\.\\COM4
> > 2024/02/05 10:18:13.849 PIKP612asyn: exception 0, 
> > asynExceptionConnect
> > 2024/02/05 10:18:15.805 ttyCAEN addr -1 queueRequest priority 0 not 
> > lockHolder
> > 2024/02/05 10:18:15.807 ttyCAEN schedule queueRequest timeout in
> > 5.000000 seconds
> > 2024/02/05 10:18:15.808664 scan-2 PIKP612:CAEN_N1470a:MOD01:CTRMODE
> > lockRequest: status returned to normal
> > 2024/02/05 10:18:15.809 asynManager::portThread port=ttyCAEN 
> > callback
> > 2024/02/05 10:18:15.813 ttyCAEN addr -1 queueRequest priority 0 not 
> > lockHolder
> > 2024/02/05 10:18:15.814 ttyCAEN schedule queueRequest timeout in
> > 0.100000 seconds
> > 2024/02/05 10:18:15.816 asynManager::portThread port=ttyCAEN 
> > callback
> > 2024/02/05 10:18:15.817 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:18:15.818 \\.\\\\\.\\COM4 read 0, return 1
> > 2024/02/05 10:18:15.819 ttyCAEN get Eos 0
> > 2024/02/05 10:18:15.821 ttyCAEN set Eos 0
> > 2024/02/05 10:18:15.822 \\.\\\\\.\\COM4 write.
> > 2024/02/05 10:18:15.823 \\.\\\\\.\\COM4 write 26 
> > $BD:01,CMD:MON,PAR:BDCTR
> >  
> > 2024/02/05 10:18:15.824 wrote 26 to \\.\\\\\.\\COM4, return 
> > asynSuccess
> > 2024/02/05 10:18:15.826 ttyCAEN set Eos 0
> > 2024/02/05 10:18:15.827 ttyCAEN addr -1 queueRequest priority 0 from 
> > lockHolder
> > 2024/02/05 10:18:15.828 ttyCAEN schedule queueRequest timeout in
> > 1.000000 seconds
> > 2024/02/05 10:18:15.829 asynManager::portThread port=ttyCAEN 
> > callback
> > 2024/02/05 10:18:15.831 ttyCAEN get Eos 0
> > 2024/02/05 10:18:15.832 ttyCAEN set Eos 2
> >  
> >  
> > 2024/02/05 10:18:15.833 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:18:16.827 \\.\\\\\.\\COM4 timeout handler.
> > 2024/02/05 10:18:16.843 \\.\\\\\.\\COM4 read 0, return 1
> > 2024/02/05 10:18:16.844437 ttyCAEN PIKP612:CAEN_N1470a:MOD01:CTRMODE: No reply within 1000 ms to "$BD:01,CMD:MON,PAR:BDCTR<0d><0a>"
> > 2024/02/05 10:18:16.847 ttyCAEN set Eos 0
> > 2024/02/05 10:18:17.805 ttyCAEN addr -1 queueRequest priority 0 not 
> > lockHolder
> > 2024/02/05 10:18:17.806 ttyCAEN schedule queueRequest timeout in
> > 5.000000 seconds
> > 2024/02/05 10:18:17.808 asynManager::portThread port=ttyCAEN 
> > callback
> > 2024/02/05 10:18:17.810 ttyCAEN addr -1 queueRequest priority 0 not 
> > lockHolder
> > 2024/02/05 10:18:17.811 ttyCAEN schedule queueRequest timeout in
> > 0.100000 seconds
> > 2024/02/05 10:18:17.813 asynManager::portThread port=ttyCAEN 
> > callback
> > 2024/02/05 10:18:17.814 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:18:17.815 \\.\\\\\.\\COM4 read 0, return 1
> > 2024/02/05 10:18:17.816 ttyCAEN get Eos 0
> > 2024/02/05 10:18:17.817 ttyCAEN set Eos 0
> > 2024/02/05 10:18:17.818 \\.\\\\\.\\COM4 write.
> > 2024/02/05 10:18:17.819 \\.\\\\\.\\COM4 write 26 
> > $BD:01,CMD:MON,PAR:BDCTR
> >  
> > 2024/02/05 10:18:17.822 wrote 26 to \\.\\\\\.\\COM4, return 
> > asynSuccess
> > 2024/02/05 10:18:17.823 ttyCAEN set Eos 0
> > 2024/02/05 10:18:17.824 ttyCAEN addr -1 queueRequest priority 0 from 
> > lockHolder
> > 2024/02/05 10:18:17.826 ttyCAEN schedule queueRequest timeout in
> > 1.000000 seconds
> > 2024/02/05 10:18:17.827 asynManager::portThread port=ttyCAEN 
> > callback
> > 2024/02/05 10:18:17.828 ttyCAEN get Eos 0
> > 2024/02/05 10:18:17.829 ttyCAEN set Eos 2
> >  
> >  
> > 2024/02/05 10:18:17.830 \\.\\\\\.\\COM4 read.
> > 2024/02/05 10:18:18.824 \\.\\\\\.\\COM4 timeout handler.
> > 2024/02/05 10:18:18.840 \\.\\\\\.\\COM4 read 0, return 1
> > 2024/02/05 10:18:18.841311 ttyCAEN PIKP612:CAEN_N1470a:MOD01:CTRMODE: No reply within 1000 ms to "$BD:01,CMD:MON,PAR:BDCTR<0d><0a>"
> >  
> >  
> > -----Original Message-----
> > From: Zimoch Dirk <dirk.zimoch at psi.ch>
> > Sent: Donnerstag, 1. Februar 2024 11:15
> > To: tech-talk at aps.anl.gov; mscharpey at uni-muenster.de
> > Subject: Re: Issue with Stream Device. Timeout only on Reconnect
> >  
> > 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:CT
> > > RM
> > > OD
> > > E, Connect)
> > > 2024/02/01 10:15:04.475524 ttyCAEN
> > > C:\opt\epics\modules\streamdevice\src\AsynDriverInterface.cc:1322:
> > > AsynDriverInterface::exceptionHandler(PIKP612:CAEN_N1470a:MOD01:CT
> > > RM
> > > OD
> > > E) 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:CTRMOD
> > > E, "$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:CTRMOD
> > > E)
> > > 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
> > >