RE: [SQU] Fw: NTLM authentication, recent logs for Robert Collins from Dr. Michael Weller on 2000-10-31 (squid-users)

From: Dr. Michael Weller <eowmob@dont-contact.us>
Date: Tue, 31 Oct 2000 12:06:35 +0100 (MEZ)

On Tue, 31 Oct 2000, Chemolli Francesco (USI) wrote:

> > For me yes. But: I still get an error every ~40 Minutes (or later).
> > I think the default setting for -k and -c should reconnect earlier and
> > choose new challenges.. so it should work with the default.
> >
> > I'm still testing this in the field (I'll check those logs
> > tonight). The
> > (accidental) setting of -k 3600 (default 60) and -c 1800 (default)
> > resulted in challenge refresh every 3600 seconds which did
> > not suffice to
> > get rid of ALL errors (but most.. I got no more complaints, I
> > only noticed
> > there were errors).
>
> 3600 SHOULD be the default setting.
> I have put it to 60 only for debugging/development purposes.

Well, from my experience you get a falsely denied authentication about
every 40 minutes for 1 authenticator then.

I had the system run with 60 1800 1.5 days under stress now and there
are no more authentication errors. Running with -k 3600 results in a
challenge refresh every 3600 seconds which is too slow.

Surprising for me -k and -c apparently influence each other, I don't know
if intentionally or not. A challenge refresh time of 60 minutes is much
too long, however.

I also get the following error on occasion (2-3 times per day with 15-20
active users). I have no reports on bad side effects, I'm just concerned:

Michael.

-----------------------
ntlm-auth[31306](ntlm_auth.c:381): status 0
ntlm-auth[31306](ntlm_auth.c:395): Closing connection to the DC for challenge renewal
ntlm-auth[31306](libntlmssp.c:150): Connecting to server
ntlm-auth[31306](ntlm_auth.c:520): managing request
2000/10/31 09:31:10| helperStatefulHandleRead: 80 bytes from ntlmauthenticator #1.
2000/10/31 09:31:10| helperStatefulHandleRead: end of reply found
2000/10/31 09:31:10| authenticateNTLMHandleReply: Helper: '136444208' {CH TlRMTVNTUAACAAAACQAJACgAAACCgkEAewIylKtZdHUAAAAAAAAAAElUWl9FU1NFTgAAAAAAAAAA}
2000/10/31 09:31:10| authenticateNTLMHandleReply: helper '136444208'
2000/10/31 09:31:10| aclLookupProxyStatefulAuthDone: result = TlRMTVNTUAACAAAACQAJACgAAACCgkEAewIylKtZdHUAAAAAAAAAAElUWl9FU1NFTgAAAAAAAAAA
2000/10/31 09:31:10| aclCheck: checking 'http_access allow SUPER_USERS'
2000/10/31 09:31:10| aclMatchAclList: checking SUPER_USERS
2000/10/31 09:31:10| aclMatchAcl: checking 'acl SUPER_USERS proxy_auth "/etc/squid_super_users"'
2000/10/31 09:31:10| aclMatchAcl:auth state State 1.
2000/10/31 09:31:10| aclMatchAcl:auth state type 1.
2000/10/31 09:31:10| aclMatchProxyAuth: auth state negotiate with header NTLM TlRMTVNTUAABAAAAB7IAAAkACQAqAAAACgAKACAAAABIRUxMTUFTVEVSSVRaX0VTU0VO.
2000/10/31 09:31:10| aclMatchProxyAuth: auth state negotiate with challenge TlRMTVNTUAACAAAACQAJACgAAACCgkEAewIylKtZdHUAAAAAAAAAAElUWl9FU1NFTgAAAAAAAAAA.
2000/10/31 09:31:10| aclmatchAcl:we need a second proxyauth header
2000/10/31 09:31:10| aclMatchAclList: returning 0
2000/10/31 09:31:10| aclCheck: requiring Proxy Auth header.
2000/10/31 09:31:10| aclCheck: match found, returning 2
2000/10/31 09:31:10| aclCheckCallback: answer=2
2000/10/31 09:31:10| errorpage:state:type 2:1.
2000/10/31 09:31:10| authenticateFixErrorHeader: Sending type:34 header: 'NTLM TlRMTVNTUAACAAAACQAJACgAAACCgkEAewIylKtZdHUAAAAAAAAAAElUWl9FU1NFTgAAAAAAAAAA'
2000/10/31 09:31:10| NTLM HandleReply, telling stateful helper : 1
2000/10/31 09:31:10| StatefulHandleRead: reserving ntlmauthenticator #1
2000/10/31 09:31:10| StatefulGetFirstAvailable: Running servers 1.
2000/10/31 09:31:10| aclCheck: checking 'http_access allow manager localhost'
2000/10/31 09:31:10| aclMatchAclList: checking manager
2000/10/31 09:31:10| aclMatchAcl: checking 'acl manager proto cache_object'
2000/10/31 09:31:10| aclMatchAclList: returning 0
2000/10/31 09:31:10| aclCheck: checking 'http_access deny manager'
2000/10/31 09:31:10| aclMatchAclList: checking manager
2000/10/31 09:31:10| aclMatchAcl: checking 'acl manager proto cache_object'
2000/10/31 09:31:10| aclMatchAclList: returning 0
2000/10/31 09:31:10| aclCheck: checking 'http_access deny interscan'
2000/10/31 09:31:10| aclMatchAclList: checking interscan
2000/10/31 09:31:10| aclMatchAcl: checking 'acl interscan dst 10.1.1.1/255.255.255.255 10.254.1.2/255.255.255.255'
2000/10/31 09:31:10| ipcache_gethostbyname: 'ad.de.doubleclick.net', flags=1
2000/10/31 09:31:10| ipcache_nbgethostbyname: Name 'ad.de.doubleclick.net'.
2000/10/31 09:31:10| aclMatchAcl: Can't yet compare 'interscan' ACL for 'ad.de.doubleclick.net'
2000/10/31 09:31:10| aclMatchAclList: returning 0
2000/10/31 09:31:10| ipcache_nbgethostbyname: Name 'ad.de.doubleclick.net'.
2000/10/31 09:31:10| ipcacheParse: #0 212.172.60.10
2000/10/31 09:31:10| ipcacheParse: #0 212.172.60.10
2000/10/31 09:31:10| aclCheck: checking 'http_access deny interscan'
2000/10/31 09:31:10| aclMatchAclList: checking interscan
2000/10/31 09:31:10| aclMatchAcl: checking 'acl interscan dst 10.1.1.1/255.255.255.255 10.254.1.2/255.255.255.255'
2000/10/31 09:31:10| ipcache_gethostbyname: 'ad.de.doubleclick.net', flags=1
2000/10/31 09:31:10| aclMatchIp: '212.172.60.10' NOT found
2000/10/31 09:31:10| aclMatchAclList: returning 0
2000/10/31 09:31:10| aclCheck: checking 'http_access allow SUPER_USERS'
2000/10/31 09:31:10| aclMatchAclList: checking SUPER_USERS
2000/10/31 09:31:10| aclMatchAcl: checking 'acl SUPER_USERS proxy_auth "/etc/squid_super_users"'
2000/10/31 09:31:10| aclMatchAcl:auth state State 2.
2000/10/31 09:31:10| aclMatchAcl:auth state type 1.
2000/10/31 09:31:10| aclMatchProxyAuth: auth state challenge with header NTLM TlRMTVNTUAADAAAAGAAYAFwAAAAYABgAdAAAAAkACQBAAAAACQAJAEkAAAAKAAoAUgAAAAAAAACMAAAAAoIBAElUWl9FU1NFTkRJR05BVFpFS0hFTExNQVNURVINl1fG0uOkY4GcabRUdIUT1f2p33/zpVti+Zo4I7YKH8mRM8udANMd7
oLya9CSnok=.
2000/10/31 09:31:10| aclMatchAclList: returning 0
2000/10/31 09:31:10| aclCheck: handing Proxy Auth header to stateful authenticator
2000/10/31 09:31:10| aclDecodeProxyAuth: header = 'NTLM TlRMTVNTUAADAAAAGAAYAFwAAAAYABgAdAAAAAkACQBAAAAACQAJAEkAAAAKAAoAUgAAAAAAAACMAAAAAoIBAElUWl9FU1NFTkRJR05BVFpFS0hFTExNQVNURVINl1fG0uOkY4GcabRUdIUT1f2p33/zpVti+Zo4I7YKH8mRM8udANMd7oLya9CSnok='
2000/10/31 09:31:10| aclLookupProxyStatefulAuthStart: going to ask NTLM authenticator on NTLM TlRMTVNTUAADAAAAGAAYAFwAAAAYABgAdAAAAAkACQBAAAAACQAJAEkAAAAKAAoAUgAAAAAAAACMAAAAAoIBAElUWl9FU1NFTkRJR05BVFpFS0hFTExNQVNURVINl1fG0uOkY4GcabRUdIUT1f2p33/zpVti+Zo4I
7YKH8mRM8udANMd7oLya9CSnok=
2000/10/31 09:31:10| aclLookupProxyStatefulAuthStart: Asking NTLM authenticator '136444208' on FD '24'
2000/10/31 09:31:10| authenticateNTLMStart: 'TlRMTVNTUAADAAAAGAAYAFwAAAAYABgAdAAAAAkACQBAAAAACQAJAEkAAAAKAAoAUgAAAAAAAACMAAAAAoIBAElUWl9FU1NFTkRJR05BVFpFS0hFTExNQVNURVINl1fG0uOkY4GcabRUdIUT1f2p33/zpVti+Zo4I7YKH8mRM8udANMd7oLya9CSnok='
2000/10/31 09:31:10| StatefulSubmit with lastserver 136444208
2000/10/31 09:31:10| helperStatefulDispatch: Request sent to ntlmauthenticator #1, 189 bytes
ntlm-auth[31306](ntlm_auth.c:327): ntlm authenticator. Got 'TlRMTVNTUAADAAAAGAAYAFwAAAAYABgAdAAAAAkACQBAAAAACQAJAEkAAAAKAAoAUgAAAAAAAACMAAAAAoIBAElUWl9FU1NFTkRJR05BVFpFS0hFTExNQVNURVINl1fG0uOkY4GcabRUdIUT1f2p33/zpVti+Zo4I7YKH8mRM8udANMd7oLya9CSnok=' from
cache
ntlm-auth[31306](ntlm_auth.c:426): Trying the fast-track way
ntlm-auth[31306](ntlm_auth.c:435): cache miss. taking the long route, stopping by Redmond.
ntlm-auth[31306](libntlmssp.c:258): checking domain: 'DOMAIN', user: 'DIGNATZEK', pass=' —WÆÒã¤cœi´Tt…Õý©ßó¥[€'
2000/10/31 09:31:10| aclCheckFast: list: 0x821d518
2000/10/31 09:31:10| aclMatchAclList: checking all
2000/10/31 09:31:10| aclMatchAcl: checking 'acl all src 0.0.0.0/0.0.0.0'
2000/10/31 09:31:10| aclMatchIp: '10.1.1.160' found
2000/10/31 09:31:10| aclMatchAclList: returning 1
SessSetupAndX response. Action = 0
ntlm-auth[31306](libntlmssp.c:262): result is 0
ntlm-auth[31306](libntlmssp.c:271): credentials: DOMAIN\DIGNATZEK
ntlm-auth[31306](ntlm_auth.c:461): 2000/10/31 09:31:10| aclCheck: checking 'http_access allow manager localhost'
sending OK for user domain\dignatzek
ntlm-auth[31306](ntlm_auth.c:463): storing in cache entry for creds
domain\dignatzek
2000/10/31 09:31:10| aclMatchAclList: checking manager
2000/10/31 09:31:10| aclMatchAcl: checking 'acl manager proto cache_object'
ntlm-auth[31306](ntlm_auth.c:520): 2000/10/31 09:31:10| aclMatchAclList: returning 0
managing request
2000/10/31 09:31:10| aclCheck: checking 'http_access deny manager'
2000/10/31 09:31:10| aclMatchAclList: checking manager
2000/10/31 09:31:10| aclMatchAcl: checking 'acl manager proto cache_object'
2000/10/31 09:31:10| aclMatchAclList: returning 0
2000/10/31 09:31:10| aclCheck: checking 'http_access deny interscan'
2000/10/31 09:31:10| aclMatchAclList: checking interscan
2000/10/31 09:31:10| aclMatchAcl: checking 'acl interscan dst 10.1.1.1/255.255.255.255 10.254.1.2/255.255.255.255'
2000/10/31 09:31:10| ipcache_gethostbyname: 'ad.de.doubleclick.net', flags=1
2000/10/31 09:31:10| ipcache_nbgethostbyname: Name 'ad.de.doubleclick.net'.
2000/10/31 09:31:10| aclMatchAcl: Can't yet compare 'interscan' ACL for 'ad.de.doubleclick.net'
2000/10/31 09:31:10| aclMatchAclList: returning 0
2000/10/31 09:31:10| ipcache_nbgethostbyname: Name 'ad.de.doubleclick.net'.
2000/10/31 09:31:10| connStateFree: FD 24 releasing helper 136444208.
2000/10/31 09:31:10| authenticateNTLMStart: 'RESET'
2000/10/31 09:31:10| StatefulSubmit with lastserver 136444208
2000/10/31 09:31:10| helperStatefulDispatch: Request sent to ntlmauthenticator #1, 6 bytes
2000/10/31 09:31:10| helperStatefulHandleRead: 23 bytes from ntlmauthenticator #1.
2000/10/31 09:31:10| helperStatefulHandleRead: end of reply found
2000/10/31 09:31:10| authenticateNTLMHandleReply: Helper: '136444208' {OK
domain\dignatzek}
2000/10/31 09:31:10| connStateFreeHelperDone: error resetting stateful
helper, result 'OK domain\dignatzek'.
2000/10/31 09:31:10| NTLM HandleReply, telling stateful helper : 2
2000/10/31 09:31:10| StatefulHandleRead: releasing ntlmauthenticator #1
2000/10/31 09:31:10| StatefulGetFirstAvailable: Running servers 1.
ntlm-auth[31306](ntlm_auth.c:327): ntlm authenticator. Got '!!' from cache
ntlm-auth: ERR not an NTLMSSP packet. What'cha talking 'bout, Willis?
2000/10/31 09:31:10| ipcacheParse: #0 212.172.60.10
ntlm-auth[31306](ntlm_auth.c:520): managing request
2000/10/31 09:31:10| ipcacheParse: #0 212.172.60.10
2000/10/31 09:31:10| aclCheck: checking 'http_access deny interscan'
2000/10/31 09:31:10| aclMatchAclList: checking interscan
2000/10/31 09:31:10| aclMatchAcl: checking 'acl interscan dst 10.1.1.1/255.255.255.255 10.254.1.2/255.255.255.255'
2000/10/31 09:31:10| ipcache_gethostbyname: 'ad.de.doubleclick.net', flags=1
2000/10/31 09:31:10| aclMatchIp: '212.172.60.10' NOT found
2000/10/31 09:31:10| aclMatchAclList: returning 0
2000/10/31 09:31:10| aclCheck: checking 'http_access allow SUPER_USERS'
2000/10/31 09:31:10| aclMatchAclList: checking SUPER_USERS
2000/10/31 09:31:10| aclMatchAcl: checking 'acl SUPER_USERS proxy_auth "/etc/squid_super_users"'
2000/10/31 09:31:10| aclMatchAcl:auth state State 0.
2000/10/31 09:31:10| aclMatchAcl:auth state type 0.
2000/10/31 09:31:10| aclMatchProxyAuth: auth state none with header NTLM TlRMTVNTUAABAAAAB7IAAAkACQAqAAAACgAKACAAAABIRUxMTUFTVEVSSVRaX0VTU0VO.
2000/10/31 09:31:10| aclDecodeProxyAuth: header = 'NTLM TlRMTVNTUAABAAAAB7IAAAkACQAqAAAACgAKACAAAABIRUxMTUFTVEVSSVRaX0VTU0VO'
2000/10/31 09:31:10| aclMatchProxyAuth: auth state type ntlm.
2000/10/31 09:31:10| aclMatchAclList: returning 0
2000/10/31 09:31:10| aclCheck: handing Proxy Auth header to stateful authenticator
2000/10/31 09:31:10| aclDecodeProxyAuth: header = 'NTLM TlRMTVNTUAABAAAAB7IAAAkACQAqAAAACgAKACAAAABIRUxMTUFTVEVSSVRaX0VTU0VO'
2000/10/31 09:31:10| aclLookupProxyStatefulAuthStart: going to ask NTLM authenticator on NTLM TlRMTVNTUAABAAAAB7IAAAkACQAqAAAACgAKACAAAABIRUxMTUFTVEVSSVRaX0VTU0VO
2000/10/31 09:31:10| authenticateNTLMStart: 'TlRMTVNTUAABAAAAB7IAAAkACQAqAAAACgAKACAAAABIRUxMTUFTVEVSSVRaX0VTU0VO'
2000/10/31 09:31:10| StatefulGetFirstAvailable: Running servers 1.
2000/10/31 09:31:10| helperStatefulDispatch: Request sent to ntlmauthenticator #1, 69 bytes
2000/10/31 09:31:10| aclCheckFast: list: 0x821d518
2000/10/31 09:31:10| aclMatchAclList: checking all
2000/10/31 09:31:10| aclMatchAcl: checking 'acl all src 0.0.0.0/0.0.0.0'
2000/10/31 09:31:10| aclMatchIp: '10.1.1.160' found
2000/10/31 09:31:10| aclMatchAclList: returning 1
2000/10/31 09:31:10| helperStatefulHandleRead: 59 bytes from ntlmauthenticator #1.
2000/10/31 09:31:10| helperStatefulHandleRead: end of reply found
2000/10/31 09:31:10| authenticateNTLMHandleReply: Helper: '136444208' {ERR not an NTLMSSP packet. What'cha talking 'bout, Willis?}
2000/10/31 09:31:10| aclLookupProxyStatefulAuthDone: result = ERR
2000/10/31 09:31:10| aclLookupProxyNTLMAuthDone: bad NTLM negotiate request recieved on FD:15.
2000/10/31 09:31:10| aclCheck: checking 'http_access allow SUPER_USERS'
2000/10/31 09:31:10| aclMatchAclList: checking SUPER_USERS
2000/10/31 09:31:10| aclMatchAcl: checking 'acl SUPER_USERS proxy_auth "/etc/squid_super_users"'
2000/10/31 09:31:10| aclMatchAcl:auth state State 0.
2000/10/31 09:31:10| aclMatchAcl:auth state type 2.
2000/10/31 09:31:10| aclmatchAcl:we need a proxyauth header
2000/10/31 09:31:10| aclMatchAclList: returning 0
2000/10/31 09:31:10| aclCheck: requiring Proxy Auth header.
2000/10/31 09:31:10| aclCheck: match found, returning 2
2000/10/31 09:31:10| aclCheckCallback: answer=2
2000/10/31 09:31:10| errorpage:state:type 0:0.
2000/10/31 09:31:10| authenticateFixErrorHeader: Sending type:34 header: 'NTLM'
2000/10/31 09:31:10| NTLM HandleReply, telling stateful helper : 2
2000/10/31 09:31:10| StatefulHandleRead: releasing ntlmauthenticator #1
2000/10/31 09:31:10| StatefulGetFirstAvailable: Running servers 1.
ntlm-auth[31306](ntlm_auth.c:327): ntlm authenticator. Got '°±ð±@ð±@UAABAAAAB7IAAAkACQAqAAAACgAKACAAAABIRUxMTUFTVEVSSVRaX0VTU0VO' from cache
ntlm-auth: ERR not an NTLMSSP packet. What'cha talking 'bout, Willis?
ntlm-auth[31306](ntlm_auth.c:520): managing request
2000/10/31 09:31:10| aclCheck: checking 'http_access allow manager localhost'
2000/10/31 09:31:10| aclMatchAclList: checking manager
2000/10/31 09:31:10| aclMatchAcl: checking 'acl manager proto cache_object'
2000/10/31 09:31:10| aclMatchAclList: returning 0
2000/10/31 09:31:10| aclCheck: checking 'http_access deny manager'
2000/10/31 09:31:10| aclMatchAclList: checking manager
2000/10/31 09:31:10| aclMatchAcl: checking 'acl manager proto cache_object'
2000/10/31 09:31:10| aclMatchAclList: returning 0
2000/10/31 09:31:10| aclCheck: checking 'http_access deny interscan'
2000/10/31 09:31:10| aclMatchAclList: checking interscan
2000/10/31 09:31:10| aclMatchAcl: checking 'acl interscan dst 10.1.1.1/255.255.255.255 10.254.1.2/255.255.255.255'
2000/10/31 09:31:10| ipcache_gethostbyname: 'www.ehammer.de', flags=1
2000/10/31 09:31:10| aclMatchIp: '194.162.243.67' NOT found
2000/10/31 09:31:10| aclMatchAclList: returning 0
2000/10/31 09:31:10| aclCheck: checking 'http_access allow SUPER_USERS'
2000/10/31 09:31:10| aclMatchAclList: checking SUPER_USERS
2000/10/31 09:31:10| aclMatchAcl: checking 'acl SUPER_USERS proxy_auth "/etc/squid_super_users"'

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

--
Michael Weller: eowmob@exp-math.uni-essen.de, eowmob@ms.exp-math.uni-essen.de,
or even mat42b@spi.power.uni-essen.de. If you encounter an eowmob account on
any machine in the net, it's very likely it's me.
--
To unsubscribe, see http://www.squid-cache.org/mailing-lists.html

Received on Tue Oct 31 2000 - 04:14:56 MST

This archive was generated by hypermail pre-2.1.9 : Tue Dec 09 2003 - 16:56:03 MST