Log files attached. If you need any specific levels set for any specific packages please let me know and I will update and rerun. I performed the same 3 actions as I had in the prior tests: login with user with status active, login succeeded, change status to suspended, then login again. And again the second login attempt was successful and the authentication interceptor wasn't invoked.
Thanks, Justin Isenhour | Lead Developer, Systems and Technology Group | Compass Group USA | 2400 Yorkmont Road | Charlotte, NC 28217 | 704.328.5804 | justin.isenh...@compass-usa.com -----Original Message----- From: Emmanuel Lecharny [mailto:elecha...@apache.org] Sent: Sunday, December 10, 2017 10:40 AM To: users@directory.apache.org Subject: Re: [Ext] Re: [ApacheDS] How to clear cached authentication on change of custom attribute Ok, I’ll need the log for the requests being sent by the user. Le dim. 10 déc. 2017 à 15:04, Isenhour, Justin < justin.isenh...@compass-usa.com> a écrit : > I updated the code to invalidate the cache before calling super and I > am still seeing the same behavior. It looks like on the second login > the authentication interceptor is not getting called. > > > > First Login > > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Intercepting bind operation > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Attempting to invalidate the cache for uid=admin,ou=system > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Executing parent level bind events first > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Executing custom bind events > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Done with custom bind action, calling next operation > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Intercepting bind operation > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Attempting to invalidate the cache for > uid=justin.isenh...@compass-usa.com > ,ou=CommittedMembers,ou=people,dc=test,dc=com > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Executing parent level bind events first > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Executing custom bind events > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Attempting to validate status attribute for uId > justin.isenh...@compass-usa.com > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Status for justin.isenh...@compass-usa.com is active > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Attempting to validate pwdResetattribute for uId > justin.isenh...@compass-usa.com > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - pwdReset for justin.isenh...@compass-usa.com is FALSE > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Attempting to invalidate the cache for > uid=justin.isenh...@compass-usa.com > ,ou=CommittedMembers,ou=people,dc=test,dc=com > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Attempting to set lastLogon attribute for uId > justin.isenh...@compass-usa.com > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - lastLogon should be set now > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Done with custom bind action, calling next operation > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Intercepting bind operation > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Attempting to invalidate the cache for uid=admin,ou=system > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Executing parent level bind events first > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Executing custom bind events > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Done with custom bind action, calling next operation > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] WARN > [org.apache.directory.server.core.api.interceptor.context.FilteringOpe > rationContext] > - Requested attribute pwdLastSet does not exist in the schema, it will > be ignored > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] WARN > [org.apache.directory.server.core.api.interceptor.context.FilteringOpe > rationContext] > - Requested attribute pwdLastSet does not exist in the schema, it will > be ignored > > > Modify status > > INFO | jvm 1 | 2017/12/10 08:55:35 | [08:55:35] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Intercepting bind operation > INFO | jvm 1 | 2017/12/10 08:55:35 | [08:55:35] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Attempting to invalidate the cache for uid=admin,ou=system > INFO | jvm 1 | 2017/12/10 08:55:35 | [08:55:35] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Executing parent level bind events first > INFO | jvm 1 | 2017/12/10 08:55:35 | [08:55:35] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Executing custom bind events > INFO | jvm 1 | 2017/12/10 08:55:35 | [08:55:35] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Done with custom bind action, calling next operation > INFO | jvm 1 | 2017/12/10 08:55:42 | [08:55:42] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Intercepting bind operation > INFO | jvm 1 | 2017/12/10 08:55:42 | [08:55:42] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Attempting to invalidate the cache for uid=admin,ou=system > INFO | jvm 1 | 2017/12/10 08:55:42 | [08:55:42] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Executing parent level bind events first > INFO | jvm 1 | 2017/12/10 08:55:42 | [08:55:42] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Executing custom bind events > INFO | jvm 1 | 2017/12/10 08:55:42 | [08:55:42] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Done with custom bind action, calling next operation > INFO | jvm 1 | 2017/12/10 08:55:46 | [08:55:46] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Intercepting modify operation > INFO | jvm 1 | 2017/12/10 08:55:46 | [08:55:46] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Attempting to invalidate the cache for > uid=justin.isenh...@compass-usa.com > ,ou=CommittedMembers,ou=people,dc=test,dc=com > INFO | jvm 1 | 2017/12/10 08:55:46 | [08:55:46] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Executing parent level modify events first > INFO | jvm 1 | 2017/12/10 08:55:46 | [08:55:46] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Executing custom modify events > INFO | jvm 1 | 2017/12/10 08:55:46 | [08:55:46] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Attempting to invalidate the cache for > uid=justin.isenh...@compass-usa.com > ,ou=CommittedMembers,ou=people,dc=test,dc=com > > > Second Login > > INFO | jvm 1 | 2017/12/10 08:56:47 | [08:56:47] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Intercepting bind operation > INFO | jvm 1 | 2017/12/10 08:56:47 | [08:56:47] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Attempting to invalidate the cache for uid=admin,ou=system > INFO | jvm 1 | 2017/12/10 08:56:47 | [08:56:47] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Executing parent level bind events first > INFO | jvm 1 | 2017/12/10 08:56:47 | [08:56:47] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Executing custom bind events > INFO | jvm 1 | 2017/12/10 08:56:47 | [08:56:47] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Done with custom bind action, calling next operation > INFO | jvm 1 | 2017/12/10 08:56:47 | [08:56:47] WARN > [org.apache.directory.server.core.api.interceptor.context.FilteringOpe > rationContext] > - Requested attribute pwdLastSet does not exist in the schema, it will > be ignored > INFO | jvm 1 | 2017/12/10 08:56:47 | [08:56:47] WARN > [org.apache.directory.server.core.api.interceptor.context.FilteringOpe > rationContext] > - Requested attribute pwdLastSet does not exist in the schema, it will > be ignored > > > > > > > Justin Isenhour | Lead Developer, Systems and Technology Group | > Compass Group USA | 2400 Yorkmont Road | Charlotte, NC 28217 | > 704.328.5804 | justin.isenh...@compass-usa.com > > > > > -----Original Message----- > From: Emmanuel Lécharny [mailto:elecha...@gmail.com] > Sent: Friday, December 8, 2017 1:53 PM > To: users@directory.apache.org > Subject: Re: [Ext] Re: [ApacheDS] How to clear cached authentication > on change of custom attribute > > In the attached code, you invalidate the cache *after* the > super.bind() call. That won't work. Invalidate the cache before. > > Le 08/12/2017 à 19:32, Isenhour, Justin a écrit : > > Emmanuel, > > > > I tried this but it doesn't seem to work. I added the code you > recommended, when I login the first time I see the log statements > showing the attempt to invalidate the cache but when I try to login a > second time my custom authenticator is never invoked. I also tried > adding the modify event in an attempt to invalidate the cache when the > account is modified, I again see the log entries showing the attempt > to invalidate the cache but again when I try to login I do not see my > code getting called at all. Any other suggestions. Log entries below, > updated code attached. > > > > First Login > > > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:05] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Intercepting bind operation > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:05] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Executing parent level bind events first > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:05] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Executing custom bind events > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:05] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Attempting to validate status attribute for uId > justin.isenh...@compass-usa.com > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:05] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Status for justin.isenh...@compass-usa.com is active > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:05] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Attempting to validate pwdReset attribute for uId > justin.isenh...@compass-usa.com > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:05] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - pwdReset for justin.isenh...@compass-usa.com is FALSE > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:05] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Attempting to invalidate the cache for > uid=justin.isenh...@compass-usa.com > ,ou=CommittedMembers,ou=people,dc=test,dc=com > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:05] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Attempting to set lastLogon attribute for uId > justin.isenh...@compass-usa.com > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:05] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - lastLogon should be set now > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:05] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Done with custom bind action, calling next operation > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:06] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Intercepting bind operation > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:06] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Executing parent level bind events first > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:06] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Executing custom bind events > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:06] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercepto > r] - Done with custom bind action, calling next operation > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:06] WARN > [org.apache.directory.server.core.api.interceptor.context.FilteringOpe > rationContext] > - Requested attribute pwdLastSet does not exist in the schema, it will > be ignored > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:06] WARN > [org.apache.directory.server.core.api.interceptor.context.FilteringOpe > rationContext] > - Requested attribute pwdLastSet does not exist in the schema, it will > be ignored > > > > > > Second Login > > > > INFO | jvm 1 | 2017/12/08 13:19:00 | [13:19:00] WARN > [org.apache.directory.server.core.api.interceptor.context.FilteringOpe > rationContext] > - Requested attribute pwdLastSet does not exist in the schema, it will > be ignored > > INFO | jvm 1 | 2017/12/08 13:19:00 | [13:19:00] WARN > [org.apache.directory.server.core.api.interceptor.context.FilteringOpe > rationContext] > - Requested attribute pwdLastSet does not exist in the schema, it will > be ignored > > > > > > Thanks, > > Justin Isenhour | Lead Developer, Systems and Technology Group | > > Compass Group USA | 2400 Yorkmont Road | Charlotte, NC 28217 | > > 704.328.5804 | justin.isenh...@compass-usa.com > > > > > > > > > > -----Original Message----- > > From: Emmanuel Lécharny [mailto:elecha...@gmail.com] > > Sent: Thursday, December 7, 2017 5:35 PM > > To: users@directory.apache.org > > Subject: Re: [Ext] Re: [ApacheDS] How to clear cached authentication > > on change of custom attribute > > > > > > > > Le 07/12/2017 à 22:34, Isenhour, Justin a écrit : > >> A couple of things I have noticed. I am not able to access the > authenticator, my custom interceptor extends AuthenticationInterceptor > which has a collection of authenticators but that collection is private. > The other thing I have noticed is that if the user account in question > is already cached then my custom bind event is never called, so > changes made here would have no impact. Thoughts? > > > > Ah, right, my proposal was not crrect because you would have to have > access to an authenticator beforehand. > > > > But you can somehow fetch one using the getAuthenticators() method, > which is public in the AuthenticationInterceptor parent class, iterate > on each authenticator and call the invalidateCache() method on each one. > > That should work (yeah, I know, kind of a hack...) > > > > > > -- > > Emmanuel Lecharny > > > > Symas.com > > directory.apache.org > > > > -- > Emmanuel Lecharny > > Symas.com > directory.apache.org > > -- Regards, Cordialement, Emmanuel Lécharny https://na01.safelinks.protection.outlook.com/?url=www.iktek.com&data=02%7C01%7CJustin.Isenhour%40compass-usa.com%7C06dfb4b89a654dc3c59308d53fe45f28%7Ccd62b7dd4b4844bd90e7e143a22c8ead%7C0%7C0%7C636485172448760841&sdata=MsRKrwDpKiGPCNxGMKt2ohHBJTsPqLDTcAXUiL8J3Jg%3D&reserved=0
