Hi Rich, Thank you for your quick response!
I'll use the information you provided and file a bug on JNDI. Do you think this "UnavailableCriticalExtension" is the cause of why connection not being closed successfully? I am trying to figure out which end is the issue (Client or Server). For testing purpose, I just downloaded OpenDS and installed it. I ran the same test scenario for about 20 times, and I don't see any CLOSE_WAIT connection on the OpenDS process. - David On Fri, Feb 19, 2010 at 4:39 PM, Rich Megginson <rmegg...@redhat.com> wrote: > Chun Tat David Chu wrote: > > Hi Rich, > > > > That was quick response! Thank you! > > > > >> That seems like a bug in JNDI - can you file a bug? > > Yes I can do that but I'll need more information to backup my case. > > For example, which RFC stated that application shouldn't send a LDAP > > Abandon request for control that is marked as CRITICAL. I couldn't > > find that information in RFC 22551. > http://www.faqs.org/rfcs/rfc2251.html > The problem will happen with any request - if the client sends any > request (except Unbind) to the server, and attaches a control that is > marked as CRITICAL, and the server does not support that control, the > server returns unavailableCriticalExtension. > > http://www.ietf.org/rfc/rfc4511.txt - 4.1.11. Controls > "Specifically, the criticality field is applied as follows: > > - If the server does not recognize the control type, determines that > it is not appropriate for the operation, or is otherwise unwilling > to perform the operation with the control, and if the criticality > field is TRUE, the server MUST NOT perform the operation, and for > operations that have a response message, it MUST return with the > resultCode set to unavailableCriticalExtension." > > So the problem here is that > 1) JNDI is sending the Abandon request with a control not supported for > the Abandon operation and/or not supported by the server > - solution - change the Abandon request to send only controls supported > by the server (I'm not even sure why it is attempting to send a control > with Abandon) > 2) JNDI is marking the control as CRITICAL > - solution - mark the control as non-critical > 3) JNDI does not know how to handle this standard result in a more > graceful manner > - solution - catch unavailableCriticalExtension and resubmit the request > without the control or with the control marked non-critical > > > > >> Is there some way to verify that? Because the behavior you > > describe below would seem to suggest that not all operation results > > have been completely read by the client. > > :-( I am stuck on this part. I am not sure what is the best way to > > verify this because JNDI hides so much from me. I spend the last two > > hours looking at tcpdump trying to see if there's any special messages > > that was sent across but nothing pops up to me. > > > > >> Do you only see the problem when persistent search is used? Do you > > see the problem when you don't use persistent search? This would also > > lead me to believe the problem is that the client has not completed > > all operations successfully, and is therefore attempting to submit an > > Abandon request to abandon those uncompleted operations. > > Yes, from my observation, this only happen with persistent search. I > > tried different test scenarios such as 1) Create connection, do > > nothing, close connection and 2) Create connection, add NamingListener > > (Persistent Search), remove NamingListener, close connection. I ran > > these two scenarios many times, and only when I add/remove > > NamingListener will trigger the CLOSE_WAIT connection on the slapd > > process. > > > > I did found something very interesting... > > If I put a sleep say 6 seconds after I established a LDAP connection > > and before I add a NamingListener then the connection will always > > clean-up successfully when the application exit. However, if I don't > > put the sleep and add a NamingListener right after establishing the > > LDAP connection then when I my application exits, the slapd process > > will always end up with a CLOSE_WAIT connection. I tried this test > > scenario about 20 times and I always get the same result. Below is > > the code snippet and I'll re-attach the test case I use in this e-mail. > > > > // Establish a context to LDAP. > > LDAP_CONTEXT = > > (EventDirContext) new InitialDirContext( > > ldapEnvironmentHashtable).lookup(CONTEXT); > > Thread.sleep(6000); > > LDAP_CONTEXT.addNamingListener( > > SANDBOX_CONTEXT, EventContext.SUBTREE_SCOPE, > > myListener); > interesting > > > > Thanks for reading! > > > > - David > > > > > > > > On Fri, Feb 19, 2010 at 1:31 PM, Rich Megginson <rmegg...@redhat.com > > <mailto:rmegg...@redhat.com>> wrote: > > > > Chun Tat David Chu wrote: > > > Hi Rich, > > > > > > Thanks for your response. I very appreciate it. > > > > > > >> see if you can specify that no controls are to be sent with the > > > Abandon request > > > I looked at the JNDI API documentation and I don't see there's a > > way I > > > can do this. I did verify by reviewing the OpenJDK source code > that > > > it is setting the control as CRITICAL, and it is set in the > > > com.sun.jndi.ldap.NamingEventNotifier class. > > That seems like a bug in JNDI - can you file a bug? > > > > > > >> if you wait for all of the operations and results to be read by > > > your app, JNDI might notice this and just do an Unbind instead of > an > > > Abandon. > > > The test application that I use done things in a sequential > > order so I > > > believe all the operations and results had already been read. > > Is there some way to verify that? Because the behavior you describe > > below would seem to suggest that not all operation results have been > > completely read by the client. > > > > > > I did more testings today using the same test I attached in my > > > original e-mail and found out that this problem happen very > > often but > > > sometime the connection does cleaned up correctly. Here's two > > > snippets of the errors log with "Connection management" log level > > > enabled. The difference is that when it does work, I see the > > > "sasl_io_cleanup for connection" debug statement and it appears > that > > > slapd tries to release the connection and operation in all cases > > > except often time it doesn't work (when persistent search is used) > > Do you only see the problem when persistent search is used? Do > > you see > > the problem when you don't use persistent search? This would also > > lead > > me to believe the problem is that the client has not completed all > > operations successfully, and is therefore attempting to submit an > > Abandon request to abandon those uncompleted operations. > > > and the connection get into a CLOSE_WAIT state. > > > > > > I will do more testing and poke more on the JAVA client. > > > > > > Thanks, > > > > > > David > > > > > > ###### WORKING LOG ###### > > > [19/Feb/2010:13:12:49 -0500] - activity on 68r > > > [19/Feb/2010:13:12:49 -0500] - read activity on 68 > > > [19/Feb/2010:13:12:49 -0500] - listener got signaled > > > [19/Feb/2010:13:12:49 -0500] - get_ldapmessage_controls failed: 12 > > > (Unavailable critical extension) (op=Abandon) > > > [19/Feb/2010:13:13:18 -0500] - activity on 68r > > > [19/Feb/2010:13:13:18 -0500] - read activity on 68 > > > [19/Feb/2010:13:13:18 -0500] - conn 98 activity level = 3 > > > [19/Feb/2010:13:13:18 -0500] - listener got signaled > > > [19/Feb/2010:13:13:18 -0500] Persistent Search - conn=98 op=2 The > > > operation has been abandoned > > > [19/Feb/2010:13:13:18 -0500] - conn 98 turbo rank = 3 out of 5 > conns > > > [19/Feb/2010:13:13:18 -0500] Persistent Search - conn=98 op=2 > > > Releasing the connection and operation > > > [19/Feb/2010:13:13:18 -0500] - sasl_io_cleanup for connection 0 > > > [19/Feb/2010:13:13:18 -0500] - sasl_pop_IO_layer: no SASL IO layer > > > [19/Feb/2010:13:13:18 -0500] - listener got signaled > > > > > > ###### NOT WORKING LOG ###### > > > [19/Feb/2010:13:14:33 -0500] - activity on 68r > > > [19/Feb/2010:13:14:33 -0500] - read activity on 68 > > > [19/Feb/2010:13:14:33 -0500] - conn 99 activity level = 2 > > > [19/Feb/2010:13:14:33 -0500] - conn 99 turbo rank = 3 out of 5 > conns > > > [19/Feb/2010:13:14:34 -0500] - get_ldapmessage_controls failed: 12 > > > (Unavailable critical extension) (op=Abandon) > > > [19/Feb/2010:13:14:35 -0500] - listener got signaled > > > [19/Feb/2010:13:14:39 -0500] - activity on 68r > > > [19/Feb/2010:13:14:39 -0500] - read activity on 68 > > > [19/Feb/2010:13:14:39 -0500] - conn 99 activity level = 2 > > > [19/Feb/2010:13:14:39 -0500] - conn 99 turbo rank = 3 out of 5 > conns > > > [19/Feb/2010:13:14:39 -0500] Persistent Search - conn=99 op=2 The > > > operation has been abandoned > > > [19/Feb/2010:13:14:39 -0500] Persistent Search - conn=99 op=2 > > > Releasing the connection and operation > > > [19/Feb/2010:13:14:39 -0500] - listener got signaled > > > > > > > > > > > > On Thu, Feb 18, 2010 at 8:14 PM, Rich Megginson > > <rmegg...@redhat.com <mailto:rmegg...@redhat.com> > > > <mailto:rmegg...@redhat.com <mailto:rmegg...@redhat.com>>> wrote: > > > > > > Chun Tat David Chu wrote: > > > > Hi All, > > > > > > > > I am running 389 DS version 1.2.5, build number > > 2010.012.2034 on > > > RHEL 5.2. > > > > > > > > I have a problem that slapd didn't close a connection and > > eventually > > > > get into a CLOSE_WAIT state after my JAVA application exit. > > > > > > > > The scenario only happen when my application registers a > > > > NamingListener via the JAVA JNDI (Java Naming Directory > > > Interface). I > > > > believe the NamingListener is equivalent to the Persistent > > Search. > > > > This problem doesn't exist if I don't use the JNDI > > NamingListener > > > > capability. > > > > > > > > From my understanding, I did everything correctly in my > > application. > > > > I create a context, add a listener, do some stuffs, remove > the > > > > listener and then close the context. > > > > > > > > One thing I notice is that in the slapd's error log, I see > the > > > > following... > > > > "-get_ldapmessage_controls failed: 12 (Unavailable critical > > > extension) > > > > (op=Abandon)". > > > > This message prints out right after I remove the listener > > and before > > > > my application closes the context. > > > > > > > > The closest bug report I found is this and it said the > > problem has > > > > been resolved. > > > > https://bugzilla.redhat.com/show_bug.cgi?id=450575 > > > > > > > > At this point, I'm clueless. :-( > > > > Can someone help me or give me some recommendation that I > > could try? > > > It looks as though the app is sending an LDAP Abandon > > request with > > > controls that are marked as critical, and the server does > > not support > > > them. This is standard LDAPv3 behavior. I'm not sure why > > it is using > > > Abandon, perhaps to Abandon any outstanding search or other > > requests > > > that have not completed. Some things to check: > > > * see if you can specify that no controls are to be sent > > with the > > > Abandon request > > > * if you wait for all of the operations and results to be > > read by your > > > app, JNDI might notice this and just do an Unbind instead of an > > > Abandon. > > > > > > > > I will attach my JAVA JNDI replicator along with this > > e-mail. You > > > > will need to modify 2-3 lines of code to get it running in > > your > > > > environment. Search for "MODIFY ME" and that should be the > > > lines that > > > > you need to modify. > > > > > > > > Thanks! > > > > > > > > David > > > > > > > > > > > > > > > > > > ------------------------------------------------------------------------ > > > > > > > > -- > > > > 389 users mailing list > > > > 389-users@lists.fedoraproject.org > > <mailto:389-users@lists.fedoraproject.org> > > > <mailto:389-users@lists.fedoraproject.org > > <mailto:389-users@lists.fedoraproject.org>> > > > > https://admin.fedoraproject.org/mailman/listinfo/389-users > > > > > > -- > > > 389 users mailing list > > > 389-users@lists.fedoraproject.org > > <mailto:389-users@lists.fedoraproject.org> > > > <mailto:389-users@lists.fedoraproject.org > > <mailto:389-users@lists.fedoraproject.org>> > > > https://admin.fedoraproject.org/mailman/listinfo/389-users > > > > > > > > > > > > ------------------------------------------------------------------------ > > > > > > -- > > > 389 users mailing list > > > 389-users@lists.fedoraproject.org > > <mailto:389-users@lists.fedoraproject.org> > > > https://admin.fedoraproject.org/mailman/listinfo/389-users > > > > -- > > 389 users mailing list > > 389-users@lists.fedoraproject.org > > <mailto:389-users@lists.fedoraproject.org> > > https://admin.fedoraproject.org/mailman/listinfo/389-users > > > > > > ------------------------------------------------------------------------ > > > > -- > > 389 users mailing list > > 389-users@lists.fedoraproject.org > > https://admin.fedoraproject.org/mailman/listinfo/389-users > > -- > 389 users mailing list > 389-users@lists.fedoraproject.org > https://admin.fedoraproject.org/mailman/listinfo/389-users >
-- 389 users mailing list 389-users@lists.fedoraproject.org https://admin.fedoraproject.org/mailman/listinfo/389-users
