RE: [SQU] NTLM: Not authenticating users

Understanding NTLM squid logs 101. :]

For a backgrounder have a look at
http://squid.sourceforge.net/ntlm/squid_helper_protocol.html which
describes the helper protocol.

> -----Original Message-----
> From: David Gameau [mailto:David.Gameau@unisa.edu.au]
> Sent: Wednesday, 10 January 2001 4:26 PM
> To: 'squid-users@ircache.net'
> Subject: [SQU] NTLM: Not authenticating users
>
>
> Squid: 2.5DEVEL-NTLM
> OS: Solaris 7
> Client machine: WinNT 4.0 (SP6) w/IE 5.5(SP1)
>
> In squid.conf, I have the following entries:
> auth_param ntlm program <squid_path>/bin/ntlm_auth staff\unistaff2
> auth_param ntlm children 1
> auth_param ntlm max_challenge_reuses 0
> auth_param ntlm max_challenge_lifetime 2 minutes
>
> acl ie_test proxy_auth REQUIRED
> http_access allow ie_test
>
> Accessing a page from Internet Explorer never returns (and
> Squid does not
> return an 'Access Denied' error page, either).
>
> Switching on debug (29,9) produces some possibly relevant output:
> ntlm-auth[19355](ntlm_auth.c:207): ntlm authenticator. Got
> 'YR' from Squid

YR gets a challenge.

> ntlm-auth[19355](libntlmssp.c:111): Connecting to server
> UNISTAFF2 domain STAFF
> ntlm-auth[19355](ntlm_auth.c:293): sending 'TT TlRM...ZG' to squid

the TT T1RM... is the challenge, in base64 coding. The challenge is
retrieved from your DC. So the DC is at least partially working.

> ntlm-auth[19355](ntlm_auth.c:332): managing requests
> 2001/01/10 14:44:14| helperStatefulHandleRead: 64 bytes from
> ntlmauthenticator
> #1.
> 2001/01/10 14:44:14| helperStatefulHandleRead: end of reply found
> 2001/01/10 14:44:14| authenticateNTLMHandleReply: Helper:
> '2195888' {TT
> TlRM...ZG}
> 2001/01/10 14:44:14| authenticateNTLMHandleReply: helper '2195888'

The challenge has been recieved by squid.

> 2001/01/10 14:44:14| authenticateValidateUser: Validating
> Auth_user request
> '4396472'.
> 2001/01/10 14:44:14| authenticateValidateUser: Validated
> Auth_user request
> '4396472'.
> 2001/01/10 14:44:14| authenticateValidateUser: Validating
> Auth_user request
> '4396472'.
> 2001/01/10 14:44:14| authenticateValidateUser: Validated
> Auth_user request
> '4396472'.
> 2001/01/10 14:44:14| User not fully authenticated.

This means that the Access control code cannot execute yet because the
user has neither successfully logged in, nor failed to login.

> 2001/01/10 14:44:14| authenticateValidateUser: Validating
> Auth_user request
> '4396472'.
> 2001/01/10 14:44:14| authenticateValidateUser: Validated
> Auth_user request
> '4396472'.
> 2001/01/10 14:44:14| User not fully authenticated.

This second call is a from the auth framework establishing the direction
the request needs to flow in: to a helper or back to the client. If the
user us authenticated, then the request gets passed back to the acl
code.

> 2001/01/10 14:44:14| authenticateAuthUserRequestUnlock
> auth_user request
> '4396472'.
> 2001/01/10 14:44:14| authenticateAuthUserRequestUnlock
> auth_user_request
> '4396472' now at '1'.
> 2001/01/10 14:44:14| authenticateAuthUserRequestLock auth_user request
> '4396472'.
> 2001/01/10 14:44:14| authenticateAuthUserRequestLock auth_user request
> '4396472' now at '2'.
> 2001/01/10 14:44:14| authenticateFixHeader: headertype:34
> authuser:4396472

This is where 401/407 headers get created (and Authentication Info
headers if you are running digest authentication/)

> 2001/01/10 14:44:14| authenticateNTLMFixErrorHeader: Sending
> type:34 header:
> 'NTLM TlRM...ZG'

this is the second 407 to the user. NTLM uses two 407's to perform a
login, as opposed to the single 407 used by Basic or Digest. This is one
of violations of HTTP spec done by NTLM. The browser should respond to
this challenge with a NTLM authenticate request (same HTTP request, the
NTLM authenticate request goes in the authentication header).

> 2001/01/10 14:44:14| authenticateAuthUserRequestUnlock
> auth_user request
> '4396472'.
> 2001/01/10 14:44:14| authenticateAuthUserRequestUnlock
> auth_user_request
> '4396472' now at '1'.
> 2001/01/10 14:44:14| NTLM HandleReply, telling stateful helper : 3
> 2001/01/10 14:44:14| StatefulHandleRead: reserving
> ntlmauthenticator #1 for
> deferred requests.

This is normal: we want to ensure that the helper is still connected to
the DC with the same challenge until the browser comes back and logs
in/timesout the connection.

> 2001/01/10 14:44:14| StatefulGetFirstAvailable: Running servers 1.
> 2001/01/10 14:44:14| authenticateNTLMHelperServerAvailable:
> not starving -
> returning 1

The above lines are normal maintenance for the stateful helpers.

> 2001/01/10 14:44:14| authenticateNTLMReleasehelper: releasing
> helper '2195888'
> 2001/01/10 14:44:14| authenticateNTLMOnCloseConnection:
> Unlocking auth_user
> from the connection.

The Client side connection has closed - this will prevent the browser
from logging in via NTLM. Do you have persistent client connections
enabled or disabled?

> 2001/01/10 14:44:14| authenticateAuthUserRequestUnlock
> auth_user request
> '4396472'.
> 2001/01/10 14:44:14| authenticateAuthUserRequestUnlock
> auth_user_request
> '4396472' now at '0'.
> 2001/01/10 14:44:14| authenticateAuthUserRequestFree: freeing
> request 4396472
> 2001/01/10 14:44:14| authenticateAuthUserUnlock auth_user '4441480'.
> 2001/01/10 14:44:14| authenticateAuthUserUnlock auth_user
> '4441480' now at '0'.
> 2001/01/10 14:44:14| authenticateFreeProxyAuthUser: Freeing
> auth_user '4441480'
> with refcount '0'.
> 2001/01/10 14:44:14| authenticateNTLMFreeUser: Clearing NTLM
> scheme data

The above are automatic housekeeping freeing up the unneeded user data.

> 2001/01/10 14:44:14| authenticateProxyUserCacheCleanup:
> Cleaning the user cache
> now
> 2001/01/10 14:44:14| authenticateProxyUserCacheCleanup:
> Current time: 979103641
> 2001/01/10 14:44:14| authenticateProxyUserCacheCleanup:
> Finished cleaning the
> user cache
>
> Is the 'User not fully authenticated' a problem, or it that
> just the initial
> 407 from Squid to the browser?

The user not fully authenticated is business as usual. The Connection
closing at the same second as the error is sent is not - and shouldn't
happen unless client side persistent connections are turned of.

>
> Is there any way to confirm that the authenticators are
> talking to the NT
> Domain servers successfully?

You would see errors, or the helpers stuck on YR in the cache mgr. Yours
are not causing this problem AFAICT.

Rob

--
To unsubscribe, see http://www.squid-cache.org/mailing-lists.html