Experimental Physics and
Industrial Control System

Mark Rivers <[email protected]> · Mon, 5 Mar 2018 22:32:26 +0000

> Our debian package says it is 2.6.

There is no 2.6 tag in StreamDevice.

corvette:~/devel/stream/StreamDevice>git tag
Release-2-5
Release-2-6
stream_2_2
stream_2_3
stream_2_3_1
stream_2_3_2
stream_2_3_4
stream_2_3_5
stream_2_4_0
stream_2_5_0
stream_2_5_1
stream_2_5_10
stream_2_5_11
stream_2_5_12
stream_2_5_2
stream_2_5_3
stream_2_5_4
stream_2_5_5
stream_2_5_7
stream_2_5_8
stream_2_5_9
stream_2_6_1
stream_2_6_10
stream_2_6_11
stream_2_6_2
stream_2_6_3
stream_2_6_4
stream_2_6_5
stream_2_6_6
stream_2_6_7
stream_2_6_8
stream_2_6_9
stream_2_7_0
stream_2_7_2
stream_2_7_3
stream_2_7_4
stream_2_7_5
stream_2_7_6
stream_2_7_7

There is a Release-2-6 tag.  Lots has changed since then. 

corvette:~/devel/stream/StreamDevice>git diff --name-status Release-2-6
A       .gitignore
A       GNUmakefile
D       MODULE
M       Makefile
D       doc/PSI.gif
A       doc/PSI.png
M       doc/aai.html
M       doc/aao.html
M       doc/ai.html
M       doc/ao.html
M       doc/bi.html
M       doc/bo.html
M       doc/calcout.html
M       doc/epics3_13.html
M       doc/formatconverter.html
M       doc/formats.html
M       doc/index.html
M       doc/longin.html
M       doc/longout.html
A       doc/makepdf
M       doc/mbbi.html
M       doc/mbbiDirect.html
M       doc/mbbo.html
M       doc/mbboDirect.html
M       doc/nav.html
M       doc/osinterface.html
M       doc/processing.html
M       doc/protocol.html
M       doc/recordinterface.html
M       doc/recordtypes.html
M       doc/scalcout.html
M       doc/setup.html
M       doc/stream.css
M       doc/stringin.html
M       doc/stringout.html
M       doc/tipsandtricks.html
M       doc/waveform.html
D       makefile
M       src/AsynDriverInterface.cc
M       src/BCDConverter.cc
M       src/BinaryConverter.cc
M       src/ChecksumConverter.cc
M       src/EnumConverter.cc
M       src/RawConverter.cc
M       src/RegexpConverter.cc
M       src/StreamBuffer.cc
M       src/StreamBuffer.h
M       src/StreamBusInterface.cc
M       src/StreamBusInterface.h
M       src/StreamCore.cc
M       src/StreamCore.h
M       src/StreamEpics.cc
M       src/StreamFormat.h
M       src/StreamFormatConverter.cc
M       src/StreamProtocol.cc
M       src/TimestampConverter.cc
M       src/devStream.h
M       src/devaaiStream.c
M       src/devaaoStream.c
M       src/devaiStream.c
M       src/devaoStream.c
M       src/devbiStream.c
M       src/devboStream.c
M       src/devcalcoutStream.c
M       src/devlonginStream.c
M       src/devlongoutStream.c
M       src/devmbbiDirectStream.c
M       src/devmbbiStream.c
M       src/devmbboDirectStream.c
M       src/devmbboStream.c
M       src/devstringinStream.c
M       src/devstringoutStream.c
M       src/devwaveformStream.c
M       streamApp/Makefile
M       streamApp/terminal.tcl
M       streamApp/tests/streamtestlib.tcl
M       streamApp/tests/testChecksum
M       streamApp/tests/testDouble
M       streamApp/tests/testEnum
M       streamApp/tests/testFormats
M       streamApp/tests/testInteger
A       streamApp/tests/testStrangesum
M       streamApp/tests/testStreamBuffer

src/AsynDriverInterface.cc has many changes, including some related to connection management.

Mark

> -----Original Message-----
> From: Daykin, Evan [mailto:[email protected]]
> Sent: Monday, March 05, 2018 3:27 PM
> To: Mark Rivers <[email protected]>; Torsten Bögershausen
> <[email protected]>; [email protected]
> Subject: RE: Asyn not automatically reconnecting
> 
> Our debian package says it is 2.6.
> 
> -----Original Message-----
> From: Mark Rivers [mailto:[email protected]]
> Sent: Monday, March 05, 2018 4:21 PM
> To: Daykin, Evan <[email protected]>; Torsten Bögershausen
> <[email protected]>; [email protected]
> Subject: RE: Asyn not automatically reconnecting
> 
> What is the version number of the "old" version of StreamDevice?
> 
> Mark
> 
> 
> > -----Original Message-----
> > From: Daykin, Evan [mailto:[email protected]]
> > Sent: Monday, March 05, 2018 3:19 PM
> > To: Mark Rivers <[email protected]>; Torsten Bögershausen
> > <[email protected]>; [email protected]
> > Subject: RE: Asyn not automatically reconnecting
> >
> > Sorry, I goofed. Asyn does, in fact, seem to be OK after a
> > clean-rebuild against the newest streamdevice and asyn, but not
> > against new asyn/old streamdevice. I am now trying to figure out exactly what was wrong
> with it.
> >
> >
> > -----Original Message-----
> > From: Mark Rivers [mailto:[email protected]]
> > Sent: Monday, March 05, 2018 9:03 AM
> > To: Daykin, Evan <[email protected]>; Torsten Bögershausen
> > <[email protected]>; [email protected]
> > Subject: Re: Asyn not automatically reconnecting
> >
> > Hi Evan,
> >
> >
> > I'm a bit confused.
> >
> >
> > > Some error output that never previously occurred:
> > > 2018/03/05 08:26:50.500618 TEST-RF-DCU- TEST:POWR_RD_FWD: write
> > > failed
> > because Connection to test-rf-dcu-n0001 closed.
> >  > connection was closed by device
> >
> >
> > Do you get this message when you use the package or when you build
> > from source?  This looks like it is a jumble of 2 messages:
> >
> >
> > This one from StreamDevice:
> >
> > ./StreamDevice/src/AsynDriverInterface.cc:        error("%s: write failed because
> connection
> > was closed by device\n",
> >
> > and some other message that starts with "Connection to".  I cannot
> > find the source code for that message in asyn or stream.
> >
> > Last week you said that when you build asyn from source the problem
> > went away and it behaves as expected.  Is this conclusion still true?
> >
> > Mark
> >
> >
> >
> >
> >
> > ________________________________
> > From: Daykin, Evan <[email protected]>
> > Sent: Monday, March 5, 2018 7:42 AM
> > To: Mark Rivers; Torsten Bögershausen; [email protected]
> > Subject: RE: Asyn not automatically reconnecting
> >
> > Aptitude claims the package is asyn 4-33.
> >
> > Some error output that never previously occurred:
> >
> > 2018/03/05 08:26:50.500618 TEST-RF-DCU- TEST:POWR_RD_FWD: write failed
> > because Connection to test-rf-dcu-n0001 closed.
> >  connection was closed by device
> >
> > Maybe it suggests this condition is not caught correctly in the package?
> >
> > -----Original Message-----
> > From: Mark Rivers [mailto:[email protected]]
> > Sent: Friday, March 02, 2018 5:47 PM
> > To: Daykin, Evan <[email protected]>; Torsten Bögershausen
> > <[email protected]>; [email protected]
> > Subject: RE: Asyn not automatically reconnecting
> >
> > > I have added the patch you suggested and built locally... It now works totally fine.
> >
> > OK, that's good news.  But I'm definitely interested to know what
> > version you were running from the package that has this problem.
> >
> > Thanks,
> > Mark
> >
> > > -----Original Message-----
> > > From: Daykin, Evan [mailto:[email protected]]
> > > Sent: Friday, March 02, 2018 4:11 PM
> > > To: Mark Rivers <[email protected]>; Torsten Bögershausen
> > > <[email protected]>; [email protected]
> > > Subject: RE: Asyn not automatically reconnecting
> > >
> > > I have added the patch you suggested and built locally... It now
> > > works totally fine. On Monday, I will investigate what's different
> > > between this asyn version and the package we have installed.
> > >
> > > > Can you simplify this further by removing all protocols from the
> > > > protocol file except
> > > getAmpValue?
> > >
> > > Terminator = LF;
> > > ReplyTimeout = 2000;
> > >
> > > getAmpValue {
> > >   ExtraInput = Ignore;
> > >   out "GET VALUE \$1 AMP \$2";
> > >   in "VALUE \$1 AMP \$2 %g";
> > > }
> > >
> > > > If this is "properly functioning" why are you getting a read error
> > > > and connection reset by
> > > peer?
> > > "Properly" meaning asyn is doing what it is supposed to after the client disconnects.
> > >
> > > Sorry, I omitted the normal output last time. Here is the record processing:
> > >
> > > 2018/03/02 16:32:38.225 TEST-RF-DCU-N0001 addr -1 queueRequest
> > > priority 0 not lockHolder
> > > 2018/03/02 16:32:38.225 TEST-RF-DCU-N0001 schedule queueRequest
> > > timeout
> > > 2018/03/02 16:32:38.225 asynManager::portThread
> > > port=TEST-RF-DCU-N0001 callback
> > > 2018/03/02 16:32:38.226 TEST-RF-DCU-N0001 addr -1 queueRequest
> > > priority 0 not lockHolder
> > > 2018/03/02 16:32:38.226 TEST-RF-DCU-N0001 schedule queueRequest
> > > timeout
> > > 2018/03/02 16:32:38.226 asynManager::portThread
> > > port=TEST-RF-DCU-N0001 callback
> > > 2018/03/02 16:32:38.226 test-rf-dcu-n0001.cts:5001 read.
> > > 2018/03/02 16:32:38.227 TEST-RF-DCU-N0001 get Eos 0
> > >
> > > 2018/03/02 16:32:38.227 TEST-RF-DCU-N0001 set Eos 0
> > >
> > > 2018/03/02 16:32:38.227 test-rf-dcu-n0001.cts:5001 write.
> > > 2018/03/02 16:32:38.227 test-rf-dcu-n0001.cts:5001 write 32 GET
> > > VALUE AMP_PWR_FORWARD AMP 1
> > >
> > > GET VALUE AMP_PWR_FORWARD AMP 1\n
> > >
> > > 47 45 54 20 56 41 4c 55 45 20 41 4d 50 5f 50 57 52 5f 46 4f
> > > 52 57 41 52 44 20 41 4d 50 20 31 0a
> > > 2018/03/02 16:32:38.227 wrote 32 to test-rf-dcu-n0001.cts:5001, return asynSuccess.
> > > 2018/03/02 16:32:38.227 TEST-RF-DCU-N0001 wrote GET VALUE
> > > AMP_PWR_FORWARD AMP 1
> > >
> > > GET VALUE AMP_PWR_FORWARD AMP 1\n
> > >
> > > 47 45 54 20 56 41 4c 55 45 20 41 4d 50 5f 50 57 52 5f 46 4f
> > > 52 57 41 52 44 20 41 4d 50 20 31 0a
> > > 2018/03/02 16:32:38.227 TEST-RF-DCU-N0001 set Eos 0
> > >
> > > 2018/03/02 16:32:38.227 TEST-RF-DCU-N0001 addr -1 queueRequest
> > > priority 0 from lockHolder
> > > 2018/03/02 16:32:38.227 TEST-RF-DCU-N0001 schedule queueRequest
> > > timeout
> > > 2018/03/02 16:32:38.227 asynManager::portThread
> > > port=TEST-RF-DCU-N0001 callback
> > > 2018/03/02 16:32:38.227 TEST-RF-DCU-N0001 get Eos 0
> > >
> > > 2018/03/02 16:32:38.227 TEST-RF-DCU-N0001 set Eos 1
> > >
> > >
> > > \n
> > >
> > > 0a
> > > 2018/03/02 16:32:38.227 test-rf-dcu-n0001.cts:5001 read.
> > > 2018/03/02 16:32:38.228 test-rf-dcu-n0001.cts:5001 read 30 VALUE
> > > AMP_PWR_FORWARD AMP 1 0
> > >
> > > VALUE AMP_PWR_FORWARD AMP 1 0\n
> > >
> > > 56 41 4c 55 45 20 41 4d 50 5f 50 57 52 5f 46 4f 52 57 41 52
> > > 44 20 41 4d 50 20 31 20 30 0a
> > > 2018/03/02 16:32:38.228 TEST-RF-DCU-N0001 read VALUE
> AMP_PWR_FORWARD
> > > AMP 1 0
> > >
> > > VALUE AMP_PWR_FORWARD AMP 1 0\n
> > >
> > > 56 41 4c 55 45 20 41 4d 50 5f 50 57 52 5f 46 4f 52 57 41 52
> > > 44 20 41 4d 50 20 31 20 30 0a
> > > 2018/03/02 16:32:38.228 TEST-RF-DCU-N0001 set Eos 0
> > >
> > >
> > > Thanks again for the help,
> > > -Evan
> > >
> > > -----Original Message-----
> > > From: Mark Rivers [mailto:[email protected]]
> > > Sent: Friday, March 02, 2018 4:10 PM
> > > To: Daykin, Evan <[email protected]>; Torsten Bögershausen
> > > <[email protected]>; [email protected]
> > > Subject: RE: Asyn not automatically reconnecting
> > >
> > > Hi Evan,
> > >
> > > Can you simplify this further by removing all protocols from the
> > > protocol file except getAmpValue?
> > >
> > > I don't understand the output you sent.  See my comments below.
> > >
> > > > -----Original Message-----
> > > > From: Daykin, Evan [mailto:[email protected]]
> > > > Sent: Thursday, March 01, 2018 3:34 PM
> > > > To: Mark Rivers <[email protected]>; Torsten Bögershausen
> > > > <[email protected]>; [email protected]
> > > > Subject: RE: Asyn not automatically reconnecting
> > > >
> > > > Sure,
> > > >
> > > > Database:
> > > >
> > > > record(asyn, "_$(HWUNIT):asyn") #resolves to PORT name {
> > > >   field(PORT, "$(HWUNIT)")
> > > >   field(IEOS, "\n")
> > > >   field(OEOS, "\n")
> > > >   field(ASG,  "$(ASGEXPERT)")
> > > > }
> > > >
> > > > record(ai, "TEST:POWR_RD_FWD")
> > > > {
> > > >   field(DESC, "AMP_PWR_FORWARD value")
> > > >   field(DTYP, "stream")
> > > >   field(SCAN, "5 second")
> > > >   field(EGU, "W")
> > > >   field(INP,  "@HBH-RF-Amp.proto getAmpValue(AMP_PWR_FORWARD,1)
> > > > TEST-
> > > > RF-DCU-N0001")
> > > >   info(archive, " ")
> > > > }
> > > >
> > > > Protocol file:
> > > >
> > > > Terminator = LF;
> > > > ReplyTimeout = 2000;
> > > >
> > > > #-----------------------------------------------------------------
> > > > --
> > > > --
> > > > --
> > > ...
> > > > #-----------------------------------------------------------------
> > > > --
> > > > --
> > > > --
> > > > getAmpValue {
> > > >   ExtraInput = Ignore;
> > > >   out "GET VALUE \$1 AMP \$2";
> > > >   in "VALUE \$1 AMP \$2 %g";
> > > > }
> > > >
> > > ...
> > > > getFirmwareVersionPallet {
> > > >   out "GET VALUE VERSION_SOFTWARE AMP \$1 DRAWER \$2 PALLET
> \$3";
> > > >   in "VALUE VERSION_SOFTWARE AMP \$1 DRAWER \$2 PALLET \$3 %s"; }
> > > >
> > >
> > > > Asyn IO output (properly functioning):
> > >
> > > > 2018/03/01 16:17:49.155 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynDriver/asynManager.c:1560]
> > > > [TEST-RF-DCU-N0001,0x6d72f0,50] TEST-RF-DCU-N0001 addr -1
> > > > queueRequest priority 0 from lockHolder
> > > > 2018/03/01 16:17:49.155 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynDriver/asynManager.c:1576]
> > > > [TEST-RF-DCU-N0001,0x6d72f0,50] TEST-RF-DCU-N0001 schedule
> > > > queueRequest timeout
> > > > 2018/03/01 16:17:49.155 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynDriver/asynManager.c:886]
> > > > [TEST-RF-DCU-N0001,0x6d72f0,50] asynManager::portThread
> > > > port=TEST-RF-DCU-N0001 callback
> > > > 2018/03/01 16:17:49.155 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/miscellaneous/asynInterposeEos.c:337]
> > > > [TEST-RF-DCU-N0001,0x6d72f0,50] TEST-RF-DCU-N0001 get Eos 0
> > > > 2018/03/01 16:17:49.155 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/miscellaneous/asynInterposeEos.c:295]
> > > > [TEST-RF-DCU-N0001,0x6d72f0,50] TEST-RF-DCU-N0001 set Eos 1 \n 0a
> > > > 2018/03/01 16:17:49.155 [TEST-RF-DCU-N0001,-1,0]
> > > [../../asyn/drvAsynSerial/drvAsynIPPort.c:674]
> > > [TEST-RF-DCU-N0001,0x6d72f0,50] test-
> > > rf-dcu-n0001.cts:5001 read.
> > > > 2018/03/01 16:17:50.320 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/drvAsynSerial/drvAsynIPPort.c:203]
> > > > [TEST-RF-DCU-N0001,0x6d72f0,50] Close test-rf-dcu-n0001.cts:5001
> > > > connection (fd 6): Read error
> > > > 2018/03/01 16:17:50.320 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynRecord/asynRecord.c:905]
> > > > [TEST-RF-DCU-N0001,0x6d72f0,50] _TEST-RF-DCU-N0001:asyn: exception
> > > > 0, asynExceptionConnect
> > > > 2018/03/01 16:17:50.319943 TEST-RF-DCU- TEST:POWR_RD_FWD:
> > > > asynError in
> > > > read:  test-rf-dcu-n0001.cts:5001 read error: Connection reset by
> > > > peer
> > > > 2018/03/01 16:17:50.319959 TEST-RF-DCU- TEST:POWR_RD_FWD: I/O
> > > > error after
> > > reading 0 bytes: ""
> > > > 2018/03/01 16:17:50.319981 TEST-RF-DCU- TEST:POWR_RD_FWD: Protocol
> > > > aborted
> > >
> > > If this is "properly functioning" why are you getting a read error
> > > and connection reset by peer?
> > >
> > > > 2018/03/01 16:17:50.320 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/miscellaneous/asynInterposeEos.c:295]
> > > > [TEST-RF-DCU-N0001,0x6d72f0,50] TEST-RF-DCU-N0001 set Eos 0
> > > > 2018/03/01 16:17:50.325 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynDriver/asynManager.c:1565]
> > > > [timerQueue,0x6d5fd0,60]
> > > > TEST-RF-DCU-N0001 addr -1 queueRequest priority 3 not lockHolder
> > > > 2018/03/01 16:17:50.325 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynDriver/asynManager.c:807]
> > > > [TEST-RF-DCU-N0001,0x6d72f0,50] asynManager connect queueCallback
> > > > port:TEST-RF-DCU-N0001
> > > > 2018/03/01 16:17:50.325 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/drvAsynSerial/drvAsynIPPort.c:402]
> > > > [TEST-RF-DCU-N0001,0x6d72f0,50] Open connection to
> > > > test-rf-dcu-n0001.cts:5001  reason:0  fd:-1
> > > > 2018/03/01 16:17:50.326 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/drvAsynSerial/drvAsynIPPort.c:508]
> > > > [TEST-RF-DCU-N0001,0x6d72f0,50] Opened connection to
> > > > test-rf-dcu-n0001.cts:5001
> > > > 2018/03/01 16:17:50.326 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynRecord/asynRecord.c:905]
> > > > [TEST-RF-DCU-N0001,0x6d72f0,50] _TEST-RF-DCU-N0001:asyn: exception
> > > > 0, asynExceptionConnect
> > > > 2018/03/01 16:17:54.153 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynDriver/asynManager.c:1565] [scan-5,0x718ec0,61]
> > > > TEST-RF-DCU-N0001 addr -1 queueRequest priority 0 not lockHolder
> > > > 2018/03/01 16:17:54.153 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynDriver/asynManager.c:1576] [scan-5,0x718ec0,61]
> > > > TEST-RF-DCU-N0001 schedule queueRequest timeout
> > > > 2018/03/01 16:17:54.153 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynDriver/asynManager.c:886]
> > > > [TEST-RF-DCU-N0001,0x6d72f0,50] asynManager::portThread
> > > > port=TEST-RF-DCU-N0001 callback
> > > > 2018/03/01 16:17:54.153 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynDriver/asynManager.c:1565]
> > > > [TEST-RF-DCU-N0001,0x6d72f0,50] TEST-RF-DCU-N0001 addr -1
> > > > queueRequest priority 0 not lockHolder
> > > > 2018/03/01 16:17:54.153 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynDriver/asynManager.c:1576]
> > > > [TEST-RF-DCU-N0001,0x6d72f0,50] TEST-RF-DCU-N0001 schedule
> > > > queueRequest timeout
> > > > 2018/03/01 16:17:54.154 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynDriver/asynManager.c:886]
> > > > [TEST-RF-DCU-N0001,0x6d72f0,50] asynManager::portThread
> > > > port=TEST-RF-DCU-N0001 callback
> > > > 2018/03/01 16:17:54.154 [TEST-RF-DCU-N0001,-1,0]
> > > [../../asyn/drvAsynSerial/drvAsynIPPort.c:674]
> > > [TEST-RF-DCU-N0001,0x6d72f0,50] test-
> > > rf-dcu-n0001.cts:5001 read.
> > > > 2018/03/01 16:17:54.154 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/drvAsynSerial/drvAsynIPPort.c:744]
> > > > [TEST-RF-DCU-N0001,0x6d72f0,50] test-rf-dcu-n0001.cts:5001 read 50
> > > > FRIB Control Unit (0.4.8 GU Jan  2 2018 21:32:44)
> > >
> > > I don't understand.  This does not appear to be the protocol
> > > getAmpValue.  It did not send the command to read the amp value, and
> > > the string it received is not the one for that protocol.
> > >
> > > Please send the output when the record TEST:POWR_RD_FWD processes a few times.
> > >
> > >
> > > > Asyn output (not working):
> > > >
> > >
> > > > 2018/03/01 16:29:14.902 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynDriver/asynManager.c:1565] [scan-5,0x264e600,61]
> > > > TEST-RF-DCU-N0001 addr -1 queueRequest priority 0 not lockHolder
> > > > 2018/03/01 16:29:14.902 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynDriver/asynManager.c:1576] [scan-5,0x264e600,61]
> > > > TEST-RF-DCU-N0001 schedule queueRequest timeout
> > > > 2018/03/01 16:29:14.902 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynDriver/asynManager.c:886]
> > > > [TEST-RF-DCU-N0001,0x260d420,50] asynManager::portThread
> > > > port=TEST-RF-DCU-N0001 callback
> > > > 2018/03/01 16:29:14.902 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynDriver/asynManager.c:1565]
> > > > [TEST-RF-DCU-N0001,0x260d420,50] TEST-RF-DCU-N0001 addr -1
> > > > queueRequest priority 0 not lockHolder
> > > > 2018/03/01 16:29:14.902 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynDriver/asynManager.c:1576]
> > > > [TEST-RF-DCU-N0001,0x260d420,50] TEST-RF-DCU-N0001 schedule
> > > > queueRequest timeout
> > > > 2018/03/01 16:29:14.902 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynDriver/asynManager.c:886]
> > > > [TEST-RF-DCU-N0001,0x260d420,50] asynManager::portThread
> > > > port=TEST-RF-DCU-N0001 callback
> > > > 2018/03/01 16:29:14.902 [TEST-RF-DCU-N0001,-1,0]
> > > [../../asyn/drvAsynSerial/drvAsynIPPort.c:674]
> > > [TEST-RF-DCU-N0001,0x260d420,50]
> > > test-rf-dcu-n0001.cts:5001 read.
> > > > 2018/03/01 16:29:14.902 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/drvAsynSerial/drvAsynIPPort.c:744]
> > > > [TEST-RF-DCU-N0001,0x260d420,50] test-rf-dcu-n0001.cts:5001 read 0
> > > >  2018/03/01 16:29:14.902 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/drvAsynSerial/drvAsynIPPort.c:203]
> > > > [TEST-RF-DCU-N0001,0x260d420,50] Close test-rf-dcu-n0001.cts:5001
> > > > connection (fd 18): Read from broken connection
> > > > 2018/03/01 16:29:14.902 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/asynRecord/asynRecord.c:905]
> > > > [TEST-RF-DCU-N0001,0x260d420,50] _TEST-RF-DCU-N0001:asyn:
> > > > exception 0, asynExceptionConnect
> > > > 2018/03/01 16:29:14.902 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/miscellaneous/asynInterposeEos.c:235]
> > > > [TEST-RF-DCU-N0001,0x260d420,50] TEST-RF-DCU-N0001 read
> > > >
> > > > 2018/03/01 16:29:14.902 [TEST-RF-DCU-N0001,-1,0]
> > > > [../../asyn/drvAsynSerial/drvAsynIPPort.c:674]
> > > > [TEST-RF-DCU-N0001,0x260d420,50] test-rf-dcu-n0001.cts:5001 read.
> > > > (Repeats forever)
> > >
> > > Note that the next to the last line is from the asynPrintIO call in
> > > asynInterposeEos.c
> > >
> > >     for (;;) {
> > >         if ((peosPvt->inBufTail != peosPvt->inBufHead)) { ...
> > >         status = peosPvt->poctet->read(peosPvt->octetPvt,
> > >              pasynUser,peosPvt->inBuf,peosPvt->inBufSize,&thisRead,&eom);
> > >         if(status==asynSuccess) {
> > >             asynPrintIO(pasynUser,ASYN_TRACEIO_FILTER,peosPvt->inBuf,thisRead,
> > >                 "%s read\n",peosPvt->portName);
> > >             /*
> > >              * Read could have returned with ASYN_EOM_CNT set in eom because
> > >              * the number of octets available exceeded inBufSize.  This is not
> > >              * a reason for us to stop reading.
> > >              */
> > >             eom &= ~ASYN_EOM_CNT;
> > >         }
> > >         if(status!=asynSuccess || thisRead==0) break;
> > >         peosPvt->inBufTail = 0;
> > >     }
> > >
> > > It is acting as if it is stuck in this loop which is what is causing
> > > your fast stream of error messages.  The peosPvt->poctet->read()
> > > call above is what calls
> > the drvAsynIPPort driver.
> > > However, I don't see how it could get stuck in the loop.  If the
> > > read() call returns asynSuccess it prints the message which you saw
> > > once.  If status is not asynSuccess then it breaks out of the loop.
> > > So either we should see the message from this function many times,
> > > or it should not call
> > peosPvt->poctet->read() multiple times.
> > >
> > > I'd like to see some more information from this function.  Can you
> > > please apply the following patch before you run the test again:
> > >
> > > diff --git a/asyn/miscellaneous/asynInterposeEos.c
> > > b/asyn/miscellaneous/asynInterposeEos.c
> > > index c9697ad..558c0a7 100644
> > > --- a/asyn/miscellaneous/asynInterposeEos.c
> > > +++ b/asyn/miscellaneous/asynInterposeEos.c
> > > @@ -232,13 +232,16 @@ static asynStatus readIt(void *ppvt,asynUser *pasynUser,
> > >               pasynUser,peosPvt->inBuf,peosPvt->inBufSize,&thisRead,&eom);
> > >          if(status==asynSuccess) {
> > >              asynPrintIO(pasynUser,ASYN_TRACEIO_FILTER,peosPvt->inBuf,thisRead,
> > > -                "%s read\n",peosPvt->portName);
> > > +                "%s read %d bytes eom=%d\n",peosPvt->portName,
> > > + thisRead, eom);
> > >              /*
> > >               * Read could have returned with ASYN_EOM_CNT set in eom because
> > >               * the number of octets available exceeded inBufSize.  This is not
> > >               * a reason for us to stop reading.
> > >               */
> > >              eom &= ~ASYN_EOM_CNT;
> > > +        } else {
> > > +           asynPrint(pasynUser, ASYN_TRACE_WARNING, "%s read from
> > > + low-level driver
> > > returned %d\n",
> > > +               peosPvt->portName, status);
> > >          }
> > >          if(status!=asynSuccess || thisRead==0) break;
> > >          peosPvt->inBufTail = 0;
> > >
> > > Mark
> > >
> > >
> > >
> > > >
> > > > -----Original Message-----
> > > > From: Mark Rivers [mailto:[email protected]]
> > > > Sent: Thursday, March 01, 2018 4:06 PM
> > > > To: Daykin, Evan <[email protected]>; Torsten Bögershausen
> > > > <[email protected]>; [email protected]
> > > > Subject: RE: Asyn not automatically reconnecting
> > > >
> > > > Can you post the database, protocol file, and asynTrace output
> > > > with all asynTrace bits
> > on?
> > > >
> > > > > -----Original Message-----
> > > > > From: Daykin, Evan [mailto:[email protected]]
> > > > > Sent: Thursday, March 01, 2018 3:04 PM
> > > > > To: Mark Rivers <[email protected]>; Torsten Bögershausen
> > > > > <[email protected]>; [email protected]
> > > > > Subject: RE: Asyn not automatically reconnecting
> > > > >
> > > > >
> > > > > I have tried a database with only a couple of records, and the behavior persists.
> > > > >
> > > > > -----Original Message-----
> > > > > From: Mark Rivers [mailto:[email protected]]
> > > > > Sent: Tuesday, February 27, 2018 4:57 PM
> > > > > To: Daykin, Evan <[email protected]>; Torsten Bögershausen
> > > > > <[email protected]>; [email protected]
> > > > > Subject: Re: Asyn not automatically reconnecting
> > > > >
> > > > > Can you try a very simple database with just one or two records
> > > > > talking to your server.  See if that works when the server shuts
> > > > > down gracefully.  If it does, but it fails with lots of records
> > > > > then we have a clue where
> > > to look.
> > > > >
> > > > >
> > > > > Mark
> > > > >
> > > > >
> > > > >
> > > > > ________________________________
> > > > > From: Daykin, Evan <[email protected]>
> > > > > Sent: Tuesday, February 27, 2018 3:53 PM
> > > > > To: Torsten Bögershausen; Mark Rivers; [email protected]
> > > > > Subject: RE: Asyn not automatically reconnecting
> > > > >
> > > > > >Sorry if this is the wrong question, but what is asyn 4.33-2 ?
> > > > > >"git tag" mentions R4-33, not "-2".
> > > > >
> > > > > That's the revision in our debian repo, it is asyn 4-33.
> > > > >
> > > > > > So from asyn everything seems to be OK.
> > > > > Maybe this is streamdevice and/or our vendor's software. We will
> > > > > investigate both
> > > > avenues.
> > > > >
> > > > > -----Original Message-----
> > > > > From: Torsten Bögershausen [mailto:[email protected]]
> > > > > Sent: Tuesday, February 27, 2018 3:37 PM
> > > > > To: Daykin, Evan <[email protected]>; Mark Rivers
> > > > > <[email protected]>; tech- [email protected]
> > > > > Subject: Re: Asyn not automatically reconnecting
> > > > >
> > > > >
> > > > >
> > > > > On 23/02/18 15:17, Daykin, Evan wrote:
> > > > > > Hi Mark,
> > > > > >
> > > > > > Thanks for the reply. We are using asyn 4.33-2 and Stream 2.6-3.
> > > > > > The protocol file has a ReplyTimeout of 2000ms.
> > > > >
> > > > > Sorry if this is the wrong question, but what is asyn 4.33-2 ?
> > > > > "git tag" mentions R4-33, not "-2".
> > > > >
> > > > > And to answer the other question:
> > > > >  >Here's something interesting: asyn behaves correctly for us
> > > > > *only* when the  >client application is killed with SIGKILL,
> > > > > rather than SIGTERM. This results  >in TCP retransmissions
> > > > > and/or refused connections, then normal operation after >a short while.
> > > > > Is it possible asyn is
> > > > [un]intentionally not retrying the >connection if it is closed gracefully?
> > > > >
> > > > >
> > > > > The code that I see producing "Read from broken connection" is this:
> > > > >
> > > > >      /* If recv() returns 0 on a SOCK_STREAM (TCP) socket, the
> > > > > connection has closed
> > > */
> > > > >      if ((thisRead == 0) && (tty->socketType == SOCK_STREAM)) {
> > > > >          epicsSnprintf(pasynUser->errorMessage,pasynUser->errorMessageSize,
> > > > >                        "%s connection closed",
> > > > >                        tty->IPDeviceName);
> > > > >          closeConnection(pasynUser,tty,"Read from broken
> > > > > connection");
> > > > >
> > > > > ----------
> > > > > And then
> > > > > closeConnection(asynUser *pasynUser,ttyController_t *tty,const char *why) {
> > > > >      asynPrint(pasynUser, ASYN_TRACE_FLOW,
> > > > >                "Close %s connection (fd %d): %s\n",
> > > > > tty->IPDeviceName,
> > > > > tty->fd, why);
> > > > >
> > > > > So from asyn everything seems to be OK.
> > > > >
> > > > > It seems that the problem described here:
> > > > >  >2018/02/23 09:51:47.089 test-rf-dcu-n0001.cts:5001 read.
> > > > >  >The last line then repeats rapidly forever.
> > > > >
> > > > > is caused by the caller into asyn, which is streamdevice ?
> > > > > There seem to be some improvements in streamdevice, but I am not
> > > > > familiar with the
> > > code.
> > > > >
> > > > > Dirk, does there ring a bell  ?

Experimental Physics and Industrial Control System

Experimental Physics and
Industrial Control System