Re: Frequent disconnect and auto-reconnects with Serial ASYN and Stream controlled device

["Zimoch Dirk \(PSI\) via Tech-talk" <tech-talk at aps.anl.gov>]

Hello Ashish,

The messages

2022/02/17 20:53:15.933 /dev/magnetPSC read
2022/02/17 20:53:15.933 Close /dev/magnetPSC connection.

both come from drvAsynSerialPort.c. In its readIt() function, I see that is prints "<portname> read" at the beginning.
It then should have shown "<portname> read <number of bytes>, return <status>" but doesn't. Instread it seems to go into
the error branch which then calls closeConnection().

The next message
2022/02/17 20:53:15.933 SERIALPORT read from low-level driver returned 3

comes from asynInterposeEos.c, reporting an error while trying to read the terminator.

Unfortunately StreamDevice does not print any error message from asyn in the case that read() fails and the device ends
up disconnected (AsynDriverInterface.cc line 1083). Maybe you want to change the code to see the error message:

diff --git a/src/AsynDriverInterface.cc b/src/AsynDriverInterface.cc
index 312324b..91c12df 100644
--- a/src/AsynDriverInterface.cc
+++ b/src/AsynDriverInterface.cc
@@ -1081,8 +1081,8 @@ readHandler()
                 break;
             case asynError:
                 if (!connected) {
-                    error("%s: device %s disconnected\n",
-                        clientName(), name());
+                    error("%s: device %s disconnected: %s\n",
+                        clientName(), name(), pasynUser->errorMessage);
                         disconnectCallback();
                 }
                 else

I suspect that there is some problem reading from your /dev/magnetPSC. However, I do not know how your magnetPSC is
supposed to behave.

Dirk


On Tue, 2022-02-22 at 12:07 +0530, Ashish Sharma via Tech-talk wrote:
> Hello,
> 
> I have a magnet PS controller which is a Raspberry Pi machine with an IOC server. This server connects to multiple
> RS232 controlled magnet power supplies. The st.cmd file is as follows:
> 
> *********************************************************************************************************************
> !../../bin/linux-arm/magnetPSControlIOC
> 
> #- You may have to change magnetPSControlIOC to something else
> #- everywhere it appears in this file
> 
> < envPaths
> epicsEnvSet(STREAM_PROTOCOL_PATH,"/root/Apps/epics/magnetPSControlIOC/magnetPSControlIOCApp/Db")
> 
> cd "${TOP}"
> 
> ## Register all support components
> dbLoadDatabase "dbd/magnetPSControlIOC.dbd"
> magnetPSControlIOC_registerRecordDeviceDriver pdbbase
> 
> ## Configure the Serial Port
> drvAsynSerialPortConfigure("SERIALPORT","/dev/magnetPSC",0,0,0)
> asynSetOption("SERIALPORT",-1,"baud","500000")
> asynSetOption("SERIALPORT",-1,"bits","8")
> asynSetOption("SERIALPORT",-1,"parity","none")
> asynSetOption("SERIALPORT",-1,"stop","1")
> asynSetOption("SERIALPORT",-1,"clocal","Y")
> asynSetOption("SERIALPORT",-1,"crtscts","N")
> 
> ## Load record instances
> dbLoadRecords("db/magnetPSC.db","PORT=SERIALPORT")
> 
> asynSetTraceMask( "SERIALPORT",0,255)
> 
> cd "${TOP}/iocBoot/${IOC}"
> iocInit
> 
> *******************************************************************************************************
> 
> the .db and .proto file entries are as follows:
> 
> record(bo, PS1:on) {
>         field(DESC, "Turn ON Power Supply 1")
>         field(DTYP, "stream")
>         field(OUT, "@magnetPSC.proto turnON_PS(1) $(PORT)")
>         field(ONAM, "1")
>         field(ZNAM, "0")
>         field(PINI, "NO")
> }
> 
> record(bo, PS1:off) {
>         field(DESC, "Turn OFF Power Supply 1")
>         field(DTYP, "stream")
>         field(OUT, "@magnetPSC.proto turnOFF_PS(1) $(PORT)")
>         field(ONAM, "1")
>         field(ZNAM, "0")
>         field(PINI, "NO")
> }
> 
> *****************************************************************************************************
> turnOFF_PS {
>         out 250 $1;
>         out "F";
>         wait 300;
>         in "X:";
>         in "OK";
>         ExtraInput = Ignore;
> }
> 
> turnON_PS {
>         out 250 $1;
>         out "N";
>         wait 300;
>         in "X:";
>         in "OK";
>         ExtraInput = Ignore;
> }
> 
> *********************************************************************************
> 
> If I do repeated ON / OFF from the GUI, the SERIALPORT gets disconnected and after some time get auto-reconnected. It
> makes this controller very unreliable. With asynSetTraceMask being set, following are the traces I am getting. I can
> see, if I do quick ON/OFF or even do fast analog write (not shown here), then port goes into not connected or
> disconnected mode. After some time it automatically gets connected.
> 
> 
> *************************************************************************************
> 2022/02/17 20:53:15.105 SERIALPORT addr -1 queueRequest priority 0 not lockHolder
> 2022/02/17 20:53:15.105 SERIALPORT schedule queueRequest timeout in 5.000000 seconds
> 2022/02/17 20:53:15.106 asynManager::portThread port=SERIALPORT callback
> 2022/02/17 20:53:15.106 SERIALPORT addr -1 queueRequest priority 0 not lockHolder
> 2022/02/17 20:53:15.106 SERIALPORT schedule queueRequest timeout in 0.100000 seconds
> 2022/02/17 20:53:15.106 asynManager::portThread port=SERIALPORT callback
> 2022/02/17 20:53:15.106 /dev/magnetPSC read.
> 2022/02/17 20:53:15.106 /dev/magnetPSC read 0, return 1
> 2022/02/17 20:53:15.106 SERIALPORT read from low-level driver returned 1
> 2022/02/17 20:53:15.106 SERIALPORT get Eos 0
> 
> 2022/02/17 20:53:15.107 SERIALPORT set Eos 0
> 
> 2022/02/17 20:53:15.107 /dev/magnetPSC write.
> 2022/02/17 20:53:15.107 /dev/magnetPSC write 3
> 
> 2022/02/17 20:53:15.107 wrote 3 to /dev/magnetPSC, return asynSuccess
> 2022/02/17 20:53:15.107 SERIALPORT wrote
> 
> 2022/02/17 20:53:15.107 SERIALPORT set Eos 0
> 
> 2022/02/17 20:53:15.107 SERIALPORT addr -1 queueRequest priority 0 from lockHolder
> 2022/02/17 20:53:15.108 SERIALPORT schedule queueRequest timeout in 0.100000 seconds
> 2022/02/17 20:53:15.108 asynManager::portThread port=SERIALPORT callback
> 2022/02/17 20:53:15.108 /dev/magnetPSC read.
> 2022/02/17 20:53:15.108 /dev/magnetPSC read 0, return 1
> 2022/02/17 20:53:15.108 SERIALPORT read from low-level driver returned 1
> 2022/02/17 20:53:15.108 SERIALPORT get Eos 0
> 
> 2022/02/17 20:53:15.108 SERIALPORT set Eos 0
> 
> 2022/02/17 20:53:15.108 /dev/magnetPSC write.
> 2022/02/17 20:53:15.108 /dev/magnetPSC write 2
> 
> 2022/02/17 20:53:15.109 wrote 2 to /dev/magnetPSC, return asynSuccess
> 2022/02/17 20:53:15.109 SERIALPORT wrote
> 
> 2022/02/17 20:53:15.109 SERIALPORT set Eos 0
> 
> 2022/02/17 20:53:15.404 SERIALPORT addr -1 queueRequest priority 3 from lockHolder
> 2022/02/17 20:53:15.404 asynManager connect queueCallback port:SERIALPORT
> 2022/02/17 20:53:15.404 /dev/magnetPSC disconnect
> 2022/02/17 20:53:15.404 Close /dev/magnetPSC connection.
> 2022/02/17 20:53:15.421699 scanOnce PS1:on lockRequest: port SERIALPORT not connected
> 2022/02/17 20:53:15.427 SERIALPORT addr -1 queueRequest priority 3 not lockHolder
> 2022/02/17 20:53:15.427 asynManager connect queueCallback port:SERIALPORT
> 2022/02/17 20:53:15.427 Open connection to /dev/magnetPSC
> 2022/02/17 20:53:15.428 Opened connection to /dev/magnetPSC
> 2022/02/17 20:53:15.633 SERIALPORT addr -1 queueRequest priority 0 not lockHolder
> 2022/02/17 20:53:15.633 SERIALPORT schedule queueRequest timeout in 5.000000 seconds
> 2022/02/17 20:53:15.633 asynManager::portThread port=SERIALPORT callback
> 2022/02/17 20:53:15.633 SERIALPORT addr -1 queueRequest priority 0 not lockHolder
> 2022/02/17 20:53:15.634 SERIALPORT schedule queueRequest timeout in 0.100000 seconds
> 2022/02/17 20:53:15.634 asynManager::portThread port=SERIALPORT callback
> 2022/02/17 20:53:15.634 /dev/magnetPSC read.
> 2022/02/17 20:53:15.634 /dev/magnetPSC read 0, return 1
> 2022/02/17 20:53:15.634 SERIALPORT read from low-level driver returned 1
> 2022/02/17 20:53:15.634 SERIALPORT get Eos 0
> 
> 2022/02/17 20:53:15.634 SERIALPORT set Eos 0
> 
> 2022/02/17 20:53:15.634 /dev/magnetPSC write.
> 2022/02/17 20:53:15.634 /dev/magnetPSC write 3
> 
> 2022/02/17 20:53:15.635 wrote 3 to /dev/magnetPSC, return asynSuccess
> 2022/02/17 20:53:15.635 SERIALPORT wrote
> 
> 2022/02/17 20:53:15.635 SERIALPORT set Eos 0
> 
> 2022/02/17 20:53:15.635 SERIALPORT addr -1 queueRequest priority 0 from lockHolder
> 2022/02/17 20:53:15.635 SERIALPORT schedule queueRequest timeout in 0.100000 seconds
> 2022/02/17 20:53:15.635 asynManager::portThread port=SERIALPORT callback
> 2022/02/17 20:53:15.635 /dev/magnetPSC read.
> 2022/02/17 20:53:15.636 /dev/magnetPSC read 3
> 
> 2022/02/17 20:53:15.636 /dev/magnetPSC read 3, return 0
> 2022/02/17 20:53:15.636 SERIALPORT read 3 bytes eom=0
> 
> 2022/02/17 20:53:15.636 /dev/magnetPSC read.
> 2022/02/17 20:53:15.636 /dev/magnetPSC read 0, return 1
> 2022/02/17 20:53:15.636 SERIALPORT read from low-level driver returned 1
> 2022/02/17 20:53:15.636 SERIALPORT get Eos 0
> 
> 2022/02/17 20:53:15.636 SERIALPORT set Eos 0
> 
> 2022/02/17 20:53:15.636 /dev/magnetPSC write.
> 2022/02/17 20:53:15.636 /dev/magnetPSC write 2
> 
> 2022/02/17 20:53:15.637 wrote 2 to /dev/magnetPSC, return asynSuccess
> 2022/02/17 20:53:15.637 SERIALPORT wrote
> 
> 2022/02/17 20:53:15.637 SERIALPORT set Eos 0
> 
> 2022/02/17 20:53:15.932 SERIALPORT addr -1 queueRequest priority 0 from lockHolder
> 2022/02/17 20:53:15.932 SERIALPORT schedule queueRequest timeout in 1.000000 seconds
> 2022/02/17 20:53:15.933 asynManager::portThread port=SERIALPORT callback
> 2022/02/17 20:53:15.933 SERIALPORT get Eos 0
> 
> 2022/02/17 20:53:15.933 SERIALPORT set Eos 1
> 
> 2022/02/17 20:53:15.933 /dev/magnetPSC read.
> 2022/02/17 20:53:15.933 Close /dev/magnetPSC connection.
> 2022/02/17 20:53:15.933 SERIALPORT read from low-level driver returned 3
> 2022/02/17 20:53:15.933335 SERIALPORT PS1:off: device SERIALPORT 0 disconnected
> 2022/02/17 20:53:15.933 SERIALPORT set Eos 0
> 
> 2022/02/17 20:53:15.938 SERIALPORT addr -1 queueRequest priority 3 not lockHolder
> 2022/02/17 20:53:15.938 asynManager connect queueCallback port:SERIALPORT
> 2022/02/17 20:53:15.939 Open connection to /dev/magnetPSC
> 2022/02/17 20:53:16.718964 CAS-client PS1:off lockRequest: port SERIALPORT not connected
> 2022/02/17 20:53:35.934 SERIALPORT addr -1 queueRequest priority 3 not lockHolder
> 2022/02/17 20:53:35.934 asynManager connect queueCallback port:SERIALPORT
> 2022/02/17 20:53:35.934 Open connection to /dev/magnetPSC
> 2022/02/17 20:53:35.938 Opened connection to /dev/magnetPSC
> 
> *****************************************************************************************
> 
> 
> In some of your previous posts, I tried to use PINI field with "NO", even I tried to forcibly "disconnect" in .proto
> file. But, the behavior is still the same. It is making the machine operation highly unreliable as we don't know when
> it is responding and when it is not.
> 
> I request you to Please suggest a remedy here.
> 
> My  EPICS base is 7.0.3
> ASYN-4.38
> STREAM 2.4
> 
> Thanks. 
> 
> --
> Ashish Sharma
> Inter-University Accelerator Centre, 
> New Delhi, India
>