Re: connection_read no connection

[Tim Kay <tim@dcs.qmul.ac.uk>]

Dave Horsfall wrote:
> On Tue, 1 Aug 2006, Andreas Hasenack wrote:
>
>   
>>>> 2006-08-01T22:34:46.206+02:00 mta1 slapd[28378]: connection_read(39): no
>>>> connection! 2006-08-01T22:35:03.340+02:00 mta1 slapd[28378]:
>>>> connection_read(38): no connection!
>>>>         
>>  [...]
>> I'm getting these a lot with 2.3.25 when I use the "luma" client. I didn't 
>> investigate any further what exactly it is doing differently from ldapsearch 
>> or gq.
>>     
>
> I've found it generally means the client exited without the courtesy of an 
> unbind.
>
>   
It is strange. We get a lot of these and upping the logging verbosity
reveals:


Oct 3 12:42:37 custard slapd[18835]: conn=29 fd=43 ACCEPT from
PATH=/var/run/ldapi (PATH=/var/run/ldapi)
Oct 3 12:42:37 custard slapd[18835]: conn=29 op=0 BIND dn="" method=128
Oct 3 12:42:37 custard slapd[18835]: conn=29 op=0 RESULT tag=97 err=0 text=
Oct 3 12:42:37 custard slapd[18835]: conn=29 op=1 SRCH
base="ou=auto.home,dc=dcs,dc=qmul,dc=ac,dc=uk" scope=2 deref=0
filter="(&(objectClass=automount)(cn=2nd))"
Oct 3 12:42:37 custard slapd[18835]: conn=29 op=1 SRCH attr=cn
automountInformation
Oct 3 12:42:37 custard slapd[18835]: conn=29 op=1 SEARCH RESULT tag=101
err=0 nentries=1 text=
Oct 3 12:42:37 custard slapd[18835]: conn=29 op=2 UNBIND
Oct 3 12:42:37 custard slapd[18835]: conn=29 fd=43 closed
Oct 3 12:42:37 custard slapd[18835]: connection_read(43): no connection!

I don't see anything wrong with the client connection, it binds
anonymously, executes a search, unbinds and then closes the connection
only for the server to log "no connection!". As we're seeing about 50 of
these warnings every second in our log files during busy periods it's a
real pain:

Oct 3 12:31:38 custard slapd[20964]: connection_read(86): no connection!
Oct 3 12:31:39 custard last message repeated 15 times
Oct 3 12:31:39 custard slapd[20964]: connection_read(96): no connection!
Oct 3 12:31:39 custard slapd[20964]: connection_read(86): no connection!
Oct 3 12:31:39 custard last message repeated 2 times
Oct 3 12:31:39 custard slapd[20964]: connection_read(96): no connection!
Oct 3 12:31:39 custard slapd[20964]: connection_read(86): no connection!
Oct 3 12:31:39 custard last message repeated 2 times
Oct 3 12:31:39 custard slapd[20964]: connection_read(96): no connection!
Oct 3 12:31:39 custard slapd[20964]: connection_read(86): no connection!
Oct 3 12:31:39 custard last message repeated 9 times
Oct 3 12:31:39 custard slapd[20964]: connection_read(96): no connection!
Oct 3 12:31:39 custard slapd[20964]: connection_read(86): no connection!
Oct 3 12:31:39 custard last message repeated 4 times
Oct 3 12:31:39 custard slapd[20964]: connection_read(96): no connection!
Oct 3 12:31:39 custard slapd[20964]: connection_read(86): no connection!
Oct 3 12:31:39 custard slapd[20964]: connection_read(96): no connection!
Oct 3 12:31:39 custard slapd[20964]: connection_read(86): no connection!
Oct 3 12:31:39 custard last message repeated 3 times
Oct 3 12:31:39 custard slapd[20964]: connection_read(96): no connection!
Oct 3 12:31:39 custard slapd[20964]: connection_read(86): no connection!
Oct 3 12:31:39 custard slapd[20964]: connection_read(96): no connection!
Oct 3 12:31:39 custard slapd[20964]: connection_read(86): no connection!
Oct 3 12:31:41 custard last message repeated 13 times

All the errors are generated by autofs automount searches connecting
over a local socket, unfortunately setting a debug level high enough to
log individual function calls to get more info slows the server down to
an unacceptable level.

Tim


-- 
Tim Kay
Systems Programmer
Department of Computer Science
Queen Mary, University of London.
Tel: +44 (0) 207 882 7521
Fax: +44 (0) 208 980 6533