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.AAIMSAuthenticationInterceptor] - > Intercepting bind operation > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > Executing custom bind events > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > Intercepting bind operation > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > Executing custom bind events > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > lastLogon should be set now > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > Intercepting bind operation > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > Executing custom bind events > INFO | jvm 1 | 2017/12/10 08:55:11 | [08:55:11] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.FilteringOperationContext] > - 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.FilteringOperationContext] > - 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.AAIMSAuthenticationInterceptor] - > Intercepting bind operation > INFO | jvm 1 | 2017/12/10 08:55:35 | [08:55:35] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > Executing custom bind events > INFO | jvm 1 | 2017/12/10 08:55:35 | [08:55:35] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > Intercepting bind operation > INFO | jvm 1 | 2017/12/10 08:55:42 | [08:55:42] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > Executing custom bind events > INFO | jvm 1 | 2017/12/10 08:55:42 | [08:55:42] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > Intercepting modify operation > INFO | jvm 1 | 2017/12/10 08:55:46 | [08:55:46] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > Executing custom modify events > INFO | jvm 1 | 2017/12/10 08:55:46 | [08:55:46] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > Intercepting bind operation > INFO | jvm 1 | 2017/12/10 08:56:47 | [08:56:47] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > Executing custom bind events > INFO | jvm 1 | 2017/12/10 08:56:47 | [08:56:47] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.FilteringOperationContext] > - 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.FilteringOperationContext] > - 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.AAIMSAuthenticationInterceptor] - > Intercepting bind operation > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:05] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > Executing custom bind events > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:05] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > lastLogon should be set now > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:05] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > Intercepting bind operation > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:06] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.AAIMSAuthenticationInterceptor] - > Executing custom bind events > > INFO | jvm 1 | 2017/12/08 13:18:06 | [13:18:06] INFO > [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationInterceptor] - > 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.FilteringOperationContext] > - 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.FilteringOperationContext] > - 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.FilteringOperationContext] > - 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.FilteringOperationContext] > - 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 www.iktek.com
