directory-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Isenhour, Justin" <Justin.Isenh...@compass-usa.com>
Subject RE: [Ext] Re: [ApacheDS] How to clear cached authentication on change of custom attribute
Date Mon, 11 Dec 2017 15:10:56 GMT
Here is a link to log files in dropbox

https://www.dropbox.com/sh/74r8m4yog5zti6i/AACZM3iOfVXAwtReBPYtdjeia?dl=0 

Justin Isenhour | Lead Developer, Systems and Technology Group | Compass Group USA |  2400
Yorkmont Road | Charlotte, NC 28217 | 704.328.5804 | justin.isenhour@compass-usa.com




-----Original Message-----
From: Emmanuel Lécharny [mailto:elecharny@gmail.com] 
Sent: Monday, December 11, 2017 9:18 AM
To: users@directory.apache.org
Subject: Re: [Ext] Re: [ApacheDS] How to clear cached authentication on change of custom attribute

Hi Justin,

Sorry, I can't tell what's going on, there is not enough logs.

What I'd like to have is teh complete log for ApacheDS (it may be verbose), including the
BindRequest dump.

Can you provide that ? (using pastebin or anything like that ?)

Le 10/12/2017 à 16:55, Isenhour, Justin a écrit :
> 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.isenhour@compass-usa.com
> 
> 
> 
> 
> -----Original Message-----
> From: Emmanuel Lecharny [mailto:elecharny@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.Isenhour@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.AAIMSAuthenticationIntercept
>> o
>> r] - Intercepting bind operation
>> INFO   | jvm 1    | 2017/12/10 08:55:11 | [08:55:11] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o 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.AAIMSAuthenticationIntercept
>> o 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.AAIMSAuthenticationIntercept
>> o
>> r] - Executing custom bind events
>> INFO   | jvm 1    | 2017/12/10 08:55:11 | [08:55:11] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o 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.AAIMSAuthenticationIntercept
>> o
>> r] - Intercepting bind operation
>> INFO   | jvm 1    | 2017/12/10 08:55:11 | [08:55:11] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o r] - Attempting to invalidate the cache for 
>> uid=justin.isenhour@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.AAIMSAuthenticationIntercept
>> o 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.AAIMSAuthenticationIntercept
>> o
>> r] - Executing custom bind events
>> INFO   | jvm 1    | 2017/12/10 08:55:11 | [08:55:11] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o r] - Attempting to validate status attribute for uId 
>> justin.isenhour@compass-usa.com
>> INFO   | jvm 1    | 2017/12/10 08:55:11 | [08:55:11] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o r] - Status for justin.isenhour@compass-usa.com is active
>> INFO   | jvm 1    | 2017/12/10 08:55:11 | [08:55:11] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o r] - Attempting to validate pwdResetattribute for uId 
>> justin.isenhour@compass-usa.com
>> INFO   | jvm 1    | 2017/12/10 08:55:11 | [08:55:11] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o r] - pwdReset for justin.isenhour@compass-usa.com is FALSE
>> INFO   | jvm 1    | 2017/12/10 08:55:11 | [08:55:11] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o r] - Attempting to invalidate the cache for 
>> uid=justin.isenhour@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.AAIMSAuthenticationIntercept
>> o r] - Attempting to set lastLogon attribute for uId 
>> justin.isenhour@compass-usa.com
>> INFO   | jvm 1    | 2017/12/10 08:55:11 | [08:55:11] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o
>> 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.AAIMSAuthenticationIntercept
>> o 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.AAIMSAuthenticationIntercept
>> o
>> r] - Intercepting bind operation
>> INFO   | jvm 1    | 2017/12/10 08:55:11 | [08:55:11] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o 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.AAIMSAuthenticationIntercept
>> o 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.AAIMSAuthenticationIntercept
>> o
>> r] - Executing custom bind events
>> INFO   | jvm 1    | 2017/12/10 08:55:11 | [08:55:11] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o 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.FilteringOp
>> e
>> 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.FilteringOp
>> e
>> 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.AAIMSAuthenticationIntercept
>> o
>> r] - Intercepting bind operation
>> INFO   | jvm 1    | 2017/12/10 08:55:35 | [08:55:35] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o 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.AAIMSAuthenticationIntercept
>> o 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.AAIMSAuthenticationIntercept
>> o
>> r] - Executing custom bind events
>> INFO   | jvm 1    | 2017/12/10 08:55:35 | [08:55:35] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o 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.AAIMSAuthenticationIntercept
>> o
>> r] - Intercepting bind operation
>> INFO   | jvm 1    | 2017/12/10 08:55:42 | [08:55:42] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o 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.AAIMSAuthenticationIntercept
>> o 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.AAIMSAuthenticationIntercept
>> o
>> r] - Executing custom bind events
>> INFO   | jvm 1    | 2017/12/10 08:55:42 | [08:55:42] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o 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.AAIMSAuthenticationIntercept
>> o
>> r] - Intercepting modify operation
>> INFO   | jvm 1    | 2017/12/10 08:55:46 | [08:55:46] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o r] - Attempting to invalidate the cache for 
>> uid=justin.isenhour@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.AAIMSAuthenticationIntercept
>> o 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.AAIMSAuthenticationIntercept
>> o
>> r] - Executing custom modify events
>> INFO   | jvm 1    | 2017/12/10 08:55:46 | [08:55:46] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o r] - Attempting to invalidate the cache for 
>> uid=justin.isenhour@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.AAIMSAuthenticationIntercept
>> o
>> r] - Intercepting bind operation
>> INFO   | jvm 1    | 2017/12/10 08:56:47 | [08:56:47] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o 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.AAIMSAuthenticationIntercept
>> o 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.AAIMSAuthenticationIntercept
>> o
>> r] - Executing custom bind events
>> INFO   | jvm 1    | 2017/12/10 08:56:47 | [08:56:47] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o 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.FilteringOp
>> e
>> 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.FilteringOp
>> e
>> 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.isenhour@compass-usa.com
>>
>>
>>
>>
>> -----Original Message-----
>> From: Emmanuel Lécharny [mailto:elecharny@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.AAIMSAuthenticationIntercept
>> o
>> r] - Intercepting bind operation
>>> INFO   | jvm 1    | 2017/12/08 13:18:06 | [13:18:05] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o 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.AAIMSAuthenticationIntercept
>> o
>> r] - Executing custom bind events
>>> INFO   | jvm 1    | 2017/12/08 13:18:06 | [13:18:05] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o r] - Attempting to validate status attribute for uId 
>> justin.isenhour@compass-usa.com
>>> INFO   | jvm 1    | 2017/12/08 13:18:06 | [13:18:05] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o r] - Status for justin.isenhour@compass-usa.com is active
>>> INFO   | jvm 1    | 2017/12/08 13:18:06 | [13:18:05] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o r] - Attempting to validate pwdReset attribute for uId 
>> justin.isenhour@compass-usa.com
>>> INFO   | jvm 1    | 2017/12/08 13:18:06 | [13:18:05] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o r] - pwdReset for justin.isenhour@compass-usa.com is FALSE
>>> INFO   | jvm 1    | 2017/12/08 13:18:06 | [13:18:05] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o r] - Attempting to invalidate the cache for 
>> uid=justin.isenhour@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.AAIMSAuthenticationIntercept
>> o r] - Attempting to set lastLogon attribute for uId 
>> justin.isenhour@compass-usa.com
>>> INFO   | jvm 1    | 2017/12/08 13:18:06 | [13:18:05] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o
>> 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.AAIMSAuthenticationIntercept
>> o 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.AAIMSAuthenticationIntercept
>> o
>> r] - Intercepting bind operation
>>> INFO   | jvm 1    | 2017/12/08 13:18:06 | [13:18:06] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o 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.AAIMSAuthenticationIntercept
>> o
>> r] - Executing custom bind events
>>> INFO   | jvm 1    | 2017/12/08 13:18:06 | [13:18:06] INFO
>> [com.cga.aaims.ldap.apacheds.interceptor.AAIMSAuthenticationIntercept
>> o 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.FilteringOp
>> e
>> 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.FilteringOp
>> e
>> 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.FilteringOp
>> e
>> 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.FilteringOp
>> e
>> 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.isenhour@compass-usa.com
>>>
>>>
>>>
>>>
>>> -----Original Message-----
>>> From: Emmanuel Lécharny [mailto:elecharny@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%7C06dfb4b89a654dc3c59308d5
> 3fe45f28%7Ccd62b7dd4b4844bd90e7e143a22c8ead%7C0%7C0%7C6364851724487608
> 41&sdata=MsRKrwDpKiGPCNxGMKt2ohHBJTsPqLDTcAXUiL8J3Jg%3D&reserved=0
> 

--
Emmanuel Lecharny

Symas.com
directory.apache.org

Mime
View raw message