RE: asyn/stream reconnect problems

["Mark Rivers" <rivers@cars.uchicago.edu>]

Benjamin,

I'd be interested to know if this problem is restricted to streamDevice,
or if it also happens if you use, for example, an asynRecord to talk to
the device.  Is it possible to test that, loading just an asyn record to
communicate with your device, and see if it re-connects after a power
cycle?

I have seen some behavior I don't understand with asyn autoconnect on IP
devices, and I've been meaning to work with Eric to track it down. 

Mark
 

> -----Original Message-----
> From: tech-talk-bounces@aps.anl.gov 
> [mailto:tech-talk-bounces@aps.anl.gov] On Behalf Of Benjamin Franksen
> Sent: Monday, January 28, 2008 4:43 AM
> To: tech-talk@aps.anl.gov
> Subject: asyn/stream reconnect problems
> 
> Strange things happen here:
> 
> When I turn off and on again a GPIB gateway (E5810A) 
> controlled via soft 
> IOC, asyn, and streamDevice, sometimes the connection is not 
> re-established. However, it reconnects as soon as I enable or 
> disable asyn 
> debug messages a la 
> 
>   asynSetTraceMask L3 20 0x0000
> 
> Here is a transcript that illustrates what happens:
> 
> epics> asynSetTraceMask L3 20 0x0010
> 
> [now I turn power off and on again]
> 
> epics> 2008/01/28 11:11:29.645 L3 vxi11 clientCall errno 
> Success clnt_stat 5
> L3 vxiWriteAddressed _? RPC error : RPC: Timed out
> 
> 2008/01/28 11:11:29.645 L3 callback
> 2008/01/28 11:11:29.645 L3 addr 20 queueRequest priority 0 
> not lockHolder
> 2008/01/28 11:11:29.645 L3 schedule queueRequest timeout
> 2008/01/28 11:11:29.645 L3 callback
> 2008/01/28 11:11:29.645 L3 20 vxiWrite numchars 17
> 2008/01/28 11:11:29.857 L3 asynManager:queueTimeoutCallback
> 2008/01/28 11:11:29.937 L3 asynManager:queueTimeoutCallback
> 2008/01/28 11:11:29.937 L3 addr 20 queueRequest priority 0 
> not lockHolder
> 2008/01/28 11:11:29.937 L3 schedule queueRequest timeout
> 2008/01/28 11:11:29.992 L3 addr 20 queueRequest priority 0 
> not lockHolder
> 2008/01/28 11:11:29.992 L3 schedule queueRequest timeout
> 2008/01/28 11:11:39.645 PAHRP:NRVD:rdPow(2): asynError in 
> write: L3 RPC 
> failed
> 
> 2008/01/28 11:11:39.645 PAHRP:NRVD:cmdGtl queueRequest
> 2008/01/28 11:11:39.645 L3 addr 20 queueRequest priority 0 
> not lockHolder
> 2008/01/28 11:11:39.645 L3 schedule queueRequest timeout
> 2008/01/28 11:11:39.645 L3 callback
> 2008/01/28 11:11:39.645 L3 addr 20 queueRequest priority 0 
> not lockHolder
> 2008/01/28 11:11:39.645 L3 schedule queueRequest timeout
> 2008/01/28 11:11:39.645 L3 callback
> 2008/01/28 11:11:39.645 L3 20 vxiWrite numchars 17
> 2008/01/28 11:11:39.993 L3 asynManager:queueTimeoutCallback
> 2008/01/28 11:11:40.032 L3 addr 20 queueRequest priority 0 
> not lockHolder
> 2008/01/28 11:11:40.032 L3 schedule queueRequest timeout
> 2008/01/28 11:11:45.674 L3 vxiDestroyDevLink RPC error : RPC: 
> Unable to 
> send; 
> errno = Broken pipe
> 
> 2008/01/28 11:11:45.674 L3 vxiDisconnectPort : RPC: Unable to 
> send; errno = 
> Broken pipe
> 
> 2008/01/28 11:11:47.681 L3 vxiDestroyDevLink RPC error : RPC: 
> Unable to 
> send; 
> errno = Broken pipe
> 
> L3 port not connected
> 2008/01/28 11:11:47.681 L3 asynGpib:pollAddr srqEnable
> 2008/01/28 11:11:47.681 PAHRP:NRVD:rdPow(1): asynError in 
> write: L3 RPC 
> failed
> 
> 2008/01/28 11:11:47.682 L3 addr 20 queueRequest priority 0 
> not lockHolder
> 2008/01/28 11:11:47.682 L3 schedule queueRequest timeout
> 2008/01/28 11:11:50.033 L3 asynManager:queueTimeoutCallback
> 2008/01/28 11:11:50.033 L3 addr 20 queueRequest priority 0 
> not lockHolder
> 2008/01/28 11:11:50.033 L3 schedule queueRequest timeout
> 2008/01/28 11:11:50.038 gpib0 vxiCreateDeviceLink abort 
> channel TCP port 
> changed from 1002 to 1005
> 2008/01/28 11:11:50.096 L3 addr 20 queueRequest priority 0 
> not lockHolder
> 2008/01/28 11:11:50.096 L3 schedule queueRequest timeout
> 2008/01/28 11:11:57.681 L3 asynManager:queueTimeoutCallback
> 2008/01/28 11:12:00.033 L3 asynManager:queueTimeoutCallback
> 
> [The last few lines repeat endlessly; device stays 
> INVALID/TIMEOUT; now I 
> do:]
> 
> asynSetTraceMask L3 20 0x0000
> 2008/01/28 11:17:12.557 L3 addr 20 queueRequest priority 3 
> not lockHolder
> 2008/01/28 11:17:12.557 asynManager connect queueCallback port:L3
> 2008/01/28 11:17:12.557 L3 addr 20 vxiConnect
> epics> 2008/01/28 11:17:12.559 gpib0,20 vxiCreateDeviceLink 
> abort channel 
> TCP 
> port changed from 1002 to 1005
> 
> 
> And suddenly connection is established again.
> 
> Is this a known problem? Is there a fix?
> 
> My setup: linux-x86, epicsBase3-14-8-2, asyn4-8, streamDevice2-2
> 
> Cheers
> Ben
>