Search squid archive

Re: authenticate_ttl not working for digest authentication scheme (v3.1.14)

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi,

can anybody confirm the problem I have?
And do you need more information?

Thanks,
Jan

On 07/21/11 18:39, Jan Sievers wrote:
> Hi everybody,
> 
> maybe somebody can enlighten me how re-validation of the HA1 digest
> works. I am struggling to get it the way I want.
> 
> To fight abuse, here we have to ensure, that blocked or deleted users,
> cannot log in to squid anymore after some not so long time.
> 
> Unfortunately, with squid 3.1.14 and digest authentication it seems,
> that logging in is possible endlessly until the squid daemon is restarted.
> 
> For testing I set
> 
> 
> 	authenticate_ttl 1 minute
> 
> 
> and expected, that after 1 minute, my digest helper script gets asked
> again for the HA1 hash of the user in question. But it does not happen.
> 
> After doing some tests I found out, that when I set
> 
> 
> 	authenticate_cache_garbage_interval 1 minute
> 
> 
> the digest backend is actually asked after 1 minute of *browsing
> inactivity* (That is understandable, since it's just a garbage collection).
> 
> This could be a workaround, but even for production I would have to set
> this value relatively low, since the backend gets only asked, if no
> browsing activity was recognized and browsers do a lot on there own
> these days. And for a strict abuse countermeasure it is not sufficient.
> 
> Maybe you can help me on that.
> 
> Here comes a commented debug log file with "debug_options 29,6":
> 
> [I removed some nonce related things, like
> authenticateDigestNonceCacheCleanup]
> 
> == First request without user in auth cache ==
> 
> 2011/07/21 15:58:48.109| authenticateValidateUser: Auth_user_request was
> NULL!
> 2011/07/21 15:58:48.109| authenticateAuthenticate: broken auth or no
> proxy_auth header. Requesting auth header.
> 2011/07/21 15:58:48.110| authenticateDigestNonceNew: created nonce
> 0x90700d0 at 1311256728
> 
> == User enters credentials ==
> 
> 2011/07/21 15:58:56.175| authenticateAuthenticate: no connection
> authentication type
> 2011/07/21 15:58:56.175| AuthUserRequest::AuthUserRequest: initialised
> request 0x9075fc0
> 2011/07/21 15:58:56.175| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 15:58:56.175| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 15:58:56.175| authenticateDigestAuthenticateuser: user
> 'testuser' validated OK
> 2011/07/21 15:58:56.175| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 15:58:56.175| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 15:58:56.175| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 15:58:56.175| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 15:58:56.176| AuthUserRequest::~AuthUserRequest: freeing
> request 0x9075fc0
> 
> == Auth cache cleanup: AuthUser still fresh - does not get deleted ==
> 
> 2011/07/21 15:59:02.136| AuthUser::cacheCleanup: Cleaning the user cache now
> 2011/07/21 15:59:02.136| AuthUser::cacheCleanup: Current time: 1311256742
> 2011/07/21 15:59:02.136| AuthUser::cacheCleanup: Cache entry:
>         Type: 3
>         Username: testuser
>         expires: 1311256796
>         references: 1
> 2011/07/21 15:59:02.136| AuthUser::cacheCleanup: Finished cleaning the
> user cache.
> 
> == Second request shortly after - the digest backend should not get asked ==
> 
> 2011/07/21 15:59:11.926| authenticateAuthenticate: no connection
> authentication type
> 2011/07/21 15:59:11.927| AuthUserRequest::AuthUserRequest: initialised
> request 0x9075fc0
> 2011/07/21 15:59:11.927| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 15:59:11.927| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 15:59:11.927| authenticateDigestAuthenticateuser: user
> 'testuser' validated OK
> 2011/07/21 15:59:11.927| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 15:59:11.927| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 15:59:11.927| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 15:59:11.930| AuthUserRequest::~AuthUserRequest: freeing
> request 0x9075fc0
> 
> == Auth cache cleanup: AuthUser still fresh - does not get deleted ==
> 
> 2011/07/21 16:00:02.136| AuthUser::cacheCleanup: Cleaning the user cache now
> 2011/07/21 16:00:02.136| AuthUser::cacheCleanup: Current time: 1311256802
> 2011/07/21 16:00:02.136| AuthUser::cacheCleanup: Cache entry:
>         Type: 3
>         Username: testuser
>         expires: 1311256811
>         references: 1
> 2011/07/21 16:00:02.136| AuthUser::cacheCleanup: Finished cleaning the
> user cache.
> 
> == Another request more than 60 seconds after asking the backend, it
> should ask again, but does not ==
> 
> 2011/07/21 16:00:05.726| authenticateAuthenticate: no connection
> authentication type
> 2011/07/21 16:00:05.727| AuthUserRequest::AuthUserRequest: initialised
> request 0x9075fc0
> 2011/07/21 16:00:05.727| authenticateDigestDecode: Unexpected or invalid
> nonce received
> 2011/07/21 16:00:05.727| AuthUser::AuthUser: Initialised auth_user
> '0x8d94238' with refcount '0'.
> 2011/07/21 16:00:05.727| authenticateValidateUser: Auth_user '0x8d94238'
> is broken for it's scheme.
> 2011/07/21 16:00:05.727| authenticateValidateUser: Auth_user '0x8d94238'
> is broken for it's scheme.
> 2011/07/21 16:00:05.727| authenticateDigestNonceNew: created nonce
> 0x90700d0 at 1311256805
> 2011/07/21 16:00:05.727| AuthUserRequest::~AuthUserRequest: freeing
> request 0x9075fc0
> 2011/07/21 16:00:05.727| AuthUser::~AuthUser: Freeing auth_user
> '0x8d94238' with refcount '0'.
> 2011/07/21 16:00:05.732| authenticateAuthenticate: no connection
> authentication type
> 2011/07/21 16:00:05.733| AuthUserRequest::AuthUserRequest: initialised
> request 0x9075fc0
> 2011/07/21 16:00:05.733| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 16:00:05.733| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 16:00:05.733| authenticateDigestAuthenticateuser: user
> 'testuser' validated OK
> 2011/07/21 16:00:05.733| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 16:00:05.733| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 16:00:05.733| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 16:00:05.733| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 16:00:05.735| AuthUserRequest::~AuthUserRequest: freeing
> request 0x9075fc0
> 
> == Cache cleanup: AuthUser is still fresh - does not get deleted ==
> 
> 2011/07/21 16:01:02.136| AuthUser::cacheCleanup: Cleaning the user cache now
> 2011/07/21 16:01:02.136| AuthUser::cacheCleanup: Current time: 1311256862
> 2011/07/21 16:01:02.136| AuthUser::cacheCleanup: Cache entry:
>         Type: 3
>         Username: testuser
>         expires: 1311256865
>         references: 1
> 2011/07/21 16:01:02.136| AuthUser::cacheCleanup: Finished cleaning the
> user cache.
> 
> == Cache cleanup: AuthUser is not fresh - does get deleted ==
> 
> 2011/07/21 16:02:02.136| AuthUser::cacheCleanup: Cleaning the user cache now
> 2011/07/21 16:02:02.136| AuthUser::cacheCleanup: Current time: 1311256922
> 2011/07/21 16:02:02.136| AuthUser::cacheCleanup: Cache entry:
>         Type: 3
>         Username: testuser
>         expires: 1311256865
>         references: 1
> 2011/07/21 16:02:02.136| AuthUser::cacheCleanup: Removing user testuser
> from cache due to timeout.
> 2011/07/21 16:02:02.136| AuthUser::~AuthUser: Freeing auth_user
> '0x9028ea8' with refcount '0'.
> 2011/07/21 16:02:02.137| AuthUser::~AuthUser: removing usernamehash
> entry '0x9032308'
> 2011/07/21 16:02:02.137| AuthUser::cacheCleanup: Finished cleaning the
> user cache.
> 
> == Another request: Digest backend gets asked again. ==
> 
> 2011/07/21 16:02:10.196| authenticateAuthenticate: no connection
> authentication type
> 2011/07/21 16:02:10.196| AuthUserRequest::AuthUserRequest: initialised
> request 0x9075fc0
> 2011/07/21 16:02:10.196| authenticateDigestDecode: Unexpected or invalid
> nonce received
> 2011/07/21 16:02:10.196| AuthUser::AuthUser: Initialised auth_user
> '0x9028ea8' with refcount '0'.
> 2011/07/21 16:02:10.196| authenticateValidateUser: Auth_user '0x9028ea8'
> is broken for it's scheme.
> 2011/07/21 16:02:10.196| authenticateValidateUser: Auth_user '0x9028ea8'
> is broken for it's scheme.
> 2011/07/21 16:02:10.196| authenticateDigestNonceNew: created nonce
> 0x90700d0 at 1311256930
> 2011/07/21 16:02:10.197| AuthUserRequest::~AuthUserRequest: freeing
> request 0x9075fc0
> 2011/07/21 16:02:10.197| AuthUser::~AuthUser: Freeing auth_user
> '0x9028ea8' with refcount '0'.
> 2011/07/21 16:02:10.200| authenticateAuthenticate: no connection
> authentication type
> 2011/07/21 16:02:10.201| AuthUserRequest::AuthUserRequest: initialised
> request 0x9075fc0
> 2011/07/21 16:02:10.201| AuthUser::AuthUser: Initialised auth_user
> '0x9028ea8' with refcount '0'.
> 2011/07/21 16:02:10.201| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 16:02:10.201| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 16:02:10.201| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 16:02:10.201| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 16:02:10.201| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 16:02:10.201| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 16:02:10.201| authenticateDigestAuthenticateuser: user
> 'testuser' validated OK
> 2011/07/21 16:02:10.201| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 16:02:10.201| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 16:02:10.201| authenticateAuthUserAddIp: user 'testuser' has
> been seen at a new IP address (192.0.2.1:50911)
> 2011/07/21 16:02:10.201| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 16:02:10.202| authenticateValidateUser: Validated Auth_user
> request '0x9075fc0'.
> 2011/07/21 16:02:10.205| AuthUserRequest::~AuthUserRequest: freeing
> request 0x9075fc0
> 
> 
> Thanks in advance for any help,
> Jan
> 

-- 
Jan Sievers                              |
Freie Universität Berlin                 | sievers@xxxxxxxxxxxxxxxxxx
Zentraleinrichtung für Datenverarbeitung | http://www.zedat.fu-berlin.de


[Index of Archives]     [Linux Audio Users]     [Samba]     [Big List of Linux Books]     [Linux USB]     [Yosemite News]

  Powered by Linux