[Date Prev][Date Next] [Chronological] [Thread] [Top]

Re: test039-glue-ldap-concurrency time...

Pierangelo Masarati wrote:
I think it is related to ITS#3832; I occasionally observed the behavior you mention with back-meta in test036, but I had isolated reports about test039 with back-ldap as well. Something that has to do with initiating operations, where the proxy backend waits for a response abter a bind, but the proxied server doesn't even know it has to send any. That's why all operations are now asynchronous, and get retried for some time before bailing out. I need to check if the behavior is consistent within back-ldap and back-meta; back-meta provides the "nretries" switch, I'm not sure about back-ldap. I'm also planning to add other parameters for further tuning, so that I can easily experiment a bit trying to reproduce that event in a manner that can be tracked.

test039 is hanging on my Linux box at the moment. It ran mostly to completion, and then stopped with 4 slapd-search instances outstanding. During this time, I noted this unread socket data recevied from port 9012:
netstat -n
Active Internet connections (w/o servers)
Proto Recv-Q Send-Q Local Address Foreign Address State
tcp 0 0 ::1:9012 ::1:38945 ESTABLISHED
tcp 0 0 ::1:9011 ::1:59707 ESTABLISHED
tcp 0 0 ::1:9011 ::1:59704 ESTABLISHED
tcp 0 0 ::1:9013 ::1:57102 ESTABLISHED
tcp 0 1 ::1:* ::1:9016 SYN_SENT
tcp 0 0 ::1:9011 ::1:59734 ESTABLISHED
tcp 0 0 ::1:9011 ::1:59739 ESTABLISHED
tcp 0 0 ::1:9013 ::1:57512 ESTABLISHED
tcp 0 0 ::1:9013 ::1:57487 ESTABLISHED
tcp 105 0 ::1:38945 ::1:9012 ESTABLISHED
tcp 0 0 ::1:39375 ::1:9012 ESTABLISHED
tcp 0 0 ::1:9011 ::1:60134 ESTABLISHED
tcp 0 0 ::1:57512 ::1:9013 ESTABLISHED
tcp 0 0 ::1:57487 ::1:9013 ESTABLISHED
tcp 0 0 ::1:60134 ::1:9011 ESTABLISHED
tcp 0 0 ::1:60109 ::1:9011 ESTABLISHED
tcp 0 0 ::1:59739 ::1:9011 ESTABLISHED
tcp 0 0 ::1:59734 ::1:9011 ESTABLISHED
tcp 0 0 ::1:59704 ::1:9011 ESTABLISHED
tcp 0 0 ::1:59707 ::1:9011 ESTABLISHED
tcp 0 0 ::1:9013 ::1:57084 ESTABLISHED
tcp 0 0 ::1:57102 ::1:9013 ESTABLISHED
tcp 0 0 ::1:57084 ::1:9013 ESTABLISHED
tcp 0 0 ::1:9012 ::1:39375 ESTABLISHED
tcp 0 0 ::1:9011 ::1:60109 ESTABLISHED

After several minutes of waiting, 3 of the slapd-search processes completed. There is still one outstanding now, and also some unread data from port 9013:
netstat -n
Active Internet connections (w/o servers)
Proto Recv-Q Send-Q Local Address Foreign Address State
tcp 0 0 ::1:9012 ::1:38945 ESTABLISHED
tcp 0 0 ::1:9011 ::1:59707 ESTABLISHED
tcp 0 1 ::1:* ::1:9016 SYN_SENT
tcp 0 0 ::1:9011 ::1:59734 ESTABLISHED
tcp 0 0 ::1:9013 ::1:57512 ESTABLISHED
tcp 0 0 ::1:38945 ::1:9012 ESTABLISHED
tcp 0 0 ::1:39375 ::1:9012 ESTABLISHED
tcp 0 0 ::1:9011 ::1:60134 ESTABLISHED
tcp 15 0 ::1:57512 ::1:9013 ESTABLISHED
tcp 0 0 ::1:60134 ::1:9011 ESTABLISHED
tcp 0 0 ::1:59734 ::1:9011 ESTABLISHED
tcp 0 0 ::1:59707 ::1:9011 ESTABLISHED
tcp 0 0 ::1:9012 ::1:39375 ESTABLISHED

It almost seems like select() isn't noticing there is data ready to be read.

--
 -- Howard Chu
 Chief Architect, Symas Corp.  http://www.symas.com
 Director, Highland Sun        http://highlandsun.com/hyc
 OpenLDAP Core Team            http://www.openldap.org/project/