Question about changing authentication in a http session.

["Markus Moeller" <huaraz@xxxxxxxxxxxxxxxx>]

Hi,

 I am testing authenticating a XP machine with Kerberos, but the client 
tries Negotiate/NTLM first after which squid does not accept the change to 
Negotiate/Kerberos anymore.

If you look at the wireshark log you authentication attempts at 20:44:20 for 
Negotiate/NTLM and at 22:44:30 the client changed to Negotiate/Kerberos, but 
the cache.log file does not get any request after the 20:44:20 NTLM request. 
I can only see the deny entries in the access.log.

 I use squid 3.4.1 from the repository from 24 Dec 2013.

Is this an expected behavious ?

Thank you
Markus


GET http://news.bbc.co.uk/ HTTP/1.1
Accept: image/gif, image/jpeg, image/pjpeg, image/pjpeg,
application/x-shockwave-flash, application/x-ms-application,
application/x-ms-xbap, application/vnd.ms-xpsdocument, application/xaml+xml,
*/*
Accept-Language: en-gb
User-Agent: Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0;
.NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; .NET CLR
1.1.4322; .NET4.0C)
Accept-Encoding: gzip, deflate
Proxy-Connection: Keep-Alive
Host: news.bbc.co.uk
Cookie:
BBC-UID=4582dd30b7dfd41587c38e59c1d8f087a2ccb6ea4e784329c395daddc323d1800Moz
illa%2f4%2e0%20%28compatible%3b%20MSIE%208%2e0%3b%20Windows%20NT%205%2e1%3b%
20Trident%2f4%2e0%3b%20%2eNET%20CLR%202%2e0%2e50727%3b%20%2eNET%20CLR%203%2e
0%2e4506%2e2152%3b%20%2eNET%20CLR%203%2e5%2e30729%3b%20%2eNET%20CLR%201%2e1%
2e4322%3b%20%2eNET4%2e0C%29; ckns_policy=111;
BGUID=c5a2ed40977f45d659a9570ad113200757790dfdde9823b90385fa9dc3bef2c8;
s1=52D07F567F3F0256

HTTP/1.1 407 Proxy Authentication Required
Server: squid/3.4.1-BZR
Mime-Version: 1.0
Date: Sun, 02 Feb 2014 20:44:20 GMT
Content-Type: text/html
Content-Length: 4284
X-Squid-Error: ERR_CACHE_ACCESS_DENIED 0
Vary: Accept-Language
Content-Language: en-gb
Proxy-Authenticate: Negotiate
Proxy-Authenticate: NTLM
X-Cache: MISS from opensuse12.suse.home
X-Cache-Lookup: NONE from opensuse12.suse.home:3128
Via: 1.1 opensuse12.suse.home (squid/3.4.1-BZR)
Connection: keep-alive

GET http://news.bbc.co.uk/ HTTP/1.1
Accept: image/gif, image/jpeg, image/pjpeg, image/pjpeg,
application/x-shockwave-flash, application/x-ms-application,
application/x-ms-xbap, application/vnd.ms-xpsdocument, application/xaml+xml,
*/*
Accept-Language: en-gb
User-Agent: Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0;
.NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; .NET CLR
1.1.4322; .NET4.0C)
Accept-Encoding: gzip, deflate
Proxy-Connection: Keep-Alive
Cookie:
BBC-UID=4582dd30b7dfd41587c38e59c1d8f087a2ccb6ea4e784329c395daddc323d1800Moz
illa%2f4%2e0%20%28compatible%3b%20MSIE%208%2e0%3b%20Windows%20NT%205%2e1%3b%
20Trident%2f4%2e0%3b%20%2eNET%20CLR%202%2e0%2e50727%3b%20%2eNET%20CLR%203%2e
0%2e4506%2e2152%3b%20%2eNET%20CLR%203%2e5%2e30729%3b%20%2eNET%20CLR%201%2e1%
2e4322%3b%20%2eNET4%2e0C%29; ckns_policy=111;
BGUID=c5a2ed40977f45d659a9570ad113200757790dfdde9823b90385fa9dc3bef2c8;
s1=52D07F567F3F0256
Proxy-Authorization: Negotiate
TlRMTVNTUAABAAAAB4IIogAAAAAAAAAAAAAAAAAAAAAFASgKAAAADw==
Host: news.bbc.co.uk

HTTP/1.1 407 Proxy Authentication Required
Server: squid/3.4.1-BZR
Mime-Version: 1.0
Date: Sun, 02 Feb 2014 20:44:20 GMT
Content-Type: text/html
Content-Length: 4387
X-Squid-Error: ERR_CACHE_ACCESS_DENIED 0
Vary: Accept-Language
Content-Language: en-gb
Proxy-Authenticate: Negotiate
TlRMTVNTUAACAAAAEgASADgAAAAFgomidwZO3urOiHMAAAAAAAAAAHQAdABKAAAABgEAAAAAAA9X
AEkATgAyADAAMAAzAFIAMgACABIAVwBJAE4AMgAwADAAMwBSADIAAQAUAE8AUABFAE4AUwBVAFMA
RQAxADIABAASAHMAdQBzAGUALgBoAG8AbQBlAAMAKABvAHAAZQBuAHMAdQBzAGUAMQAyAC4AcwB1
AHMAZQAuAGgAbwBtAGUAAAAAAA==
X-Cache: MISS from opensuse12.suse.home
X-Cache-Lookup: NONE from opensuse12.suse.home:3128
Via: 1.1 opensuse12.suse.home (squid/3.4.1-BZR)
Connection: keep-alive

GET http://news.bbc.co.uk/ HTTP/1.1
Accept: image/gif, image/jpeg, image/pjpeg, image/pjpeg,
application/x-shockwave-flash, application/x-ms-application,
application/x-ms-xbap, application/vnd.ms-xpsdocument, application/xaml+xml,
*/*
Accept-Language: en-gb
User-Agent: Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0;
.NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; .NET CLR
1.1.4322; .NET4.0C)
Accept-Encoding: gzip, deflate
Proxy-Connection: Keep-Alive
Cookie:
BBC-UID=4582dd30b7dfd41587c38e59c1d8f087a2ccb6ea4e784329c395daddc323d1800Moz
illa%2f4%2e0%20%28compatible%3b%20MSIE%208%2e0%3b%20Windows%20NT%205%2e1%3b%
20Trident%2f4%2e0%3b%20%2eNET%20CLR%202%2e0%2e50727%3b%20%2eNET%20CLR%203%2e
0%2e4506%2e2152%3b%20%2eNET%20CLR%203%2e5%2e30729%3b%20%2eNET%20CLR%201%2e1%
2e4322%3b%20%2eNET4%2e0C%29; ckns_policy=111;
BGUID=c5a2ed40977f45d659a9570ad113200757790dfdde9823b90385fa9dc3bef2c8;
s1=52D07F567F3F0256
Host: news.bbc.co.uk
Proxy-Authorization: Negotiate
TlRMTVNTUAADAAAAGAAYAHAAAACkAKQAiAAAAAwADABIAAAAEAAQAFQAAAAMAAwAZAAAAAAAAAAs
AQAABYKIogUBKAoAAAAPVwBJAE4AWABQADIAbQBhAHIAawB1AHMALQBhAFcASQBOAFgAUAAyAOmv
r8DyncxUqwDSHwz5dmyjvLjyntOAlbYw7FoskZGLTcg6KCT5ARUBAQAAAAAAAFYzj5JXIM8Bo7y4
8p7TgJUAAAAAAgASAFcASQBOADIAMAAwADMAUgAyAAEAFABPAFAARQBOAFMAVQBTAEUAMQAyAAQA
EgBzAHUAcwBlAC4AaABvAG0AZQADACgAbwBwAGUAbgBzAHUAcwBlADEAMgAuAHMAdQBzAGUALgBo
AG8AbQBlAAAAAAAAAAAA

HTTP/1.1 407 Proxy Authentication Required
Server: squid/3.4.1-BZR
Mime-Version: 1.0
Date: Sun, 02 Feb 2014 20:44:20 GMT
Content-Type: text/html
Content-Length: 4727
X-Squid-Error: ERR_CACHE_ACCESS_DENIED 0
Vary: Accept-Language
Content-Language: en-gb
Proxy-Authenticate: Negotiate
Proxy-Authenticate: NTLM
X-Cache: MISS from opensuse12.suse.home
X-Cache-Lookup: NONE from opensuse12.suse.home:3128
Via: 1.1 opensuse12.suse.home (squid/3.4.1-BZR)
Connection: keep-alive

GET http://news.bbc.co.uk/ HTTP/1.1
Accept: image/gif, image/jpeg, image/pjpeg, image/pjpeg,
application/x-shockwave-flash, application/x-ms-application,
application/x-ms-xbap, application/vnd.ms-xpsdocument, application/xaml+xml,
*/*
Accept-Language: en-gb
User-Agent: Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0;
.NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; .NET CLR
1.1.4322; .NET4.0C)
Accept-Encoding: gzip, deflate
Proxy-Connection: Keep-Alive
Cookie:
BBC-UID=4582dd30b7dfd41587c38e59c1d8f087a2ccb6ea4e784329c395daddc323d1800Moz
illa%2f4%2e0%20%28compatible%3b%20MSIE%208%2e0%3b%20Windows%20NT%205%2e1%3b%
20Trident%2f4%2e0%3b%20%2eNET%20CLR%202%2e0%2e50727%3b%20%2eNET%20CLR%203%2e
0%2e4506%2e2152%3b%20%2eNET%20CLR%203%2e5%2e30729%3b%20%2eNET%20CLR%201%2e1%
2e4322%3b%20%2eNET4%2e0C%29; ckns_policy=111;
BGUID=c5a2ed40977f45d659a9570ad113200757790dfdde9823b90385fa9dc3bef2c8;
s1=52D07F567F3F0256
Proxy-Authorization: Negotiate
YIICkwYGKwYBBQUCoIIChzCCAoOgJDAiBgkqhkiC9xIBAgIGCSqGSIb3EgECAgYKKwYBBAGCNwIC
CqKCAlkEggJVYIICUQYJKoZIhvcSAQICAQBuggJAMIICPKADAgEFoQMCAQ6iBwMFACAAAACjggFq
YYIBZjCCAWKgAwIBBaELGwlTVVNFLkhPTUWiJzAloAMCAQKhHjAcGwRIVFRQGxRvcGVuc3VzZTEy
LnN1c2UuaG9tZaOCASMwggEfoAMCARehAwIBBKKCAREEggENSdnKDJADg4ygNwY4lV8R6HQ43xXH
vVbf/NBFBKj4vheQRu7fLFGPdVfY/dBE/M2pGOLHJ3aR5dLaGvZmCKkZTRxAZVoMeK/Q6wECU7j3
dT+TFC9Bu1RucX5oacDSLRkNwBXIbXqJGcZzPxJ36aV4bWoLBa2aymGM9mdlBEm7l9tP3gysWdz6
GnnsgomY3gfLHWmJFKCPkD+v6/QFNlrhqyU7Wsfls/QiQKu5ZI4LRNlr3D6VL7CjiID+iSI3PCPN
6VZFd7aM43Yh/UC9FXtNeJ1MbdyKT3z9JokzwOwboEu+2Fe4PZh4HEJYfHQOYyyb7an/n+UYnoyi
+dq84GbZpfmXUSCNmuFidO0a2vukgbgwgbWgAwIBF6KBrQSBqsL1kje9Jp/FDZav9/LERkB+Q0iv
qQjctoLGaOdKpmOtac0Y9t5/oL9PvfgCFwP+9e3wlrqOe1VRZKdWXKs8b96jacsKIhiELVNNV9H0
tPCivtv5TjZy0cowKCbon3FrAH9wgiCxHt+YjCQ1Eb2riX6bJscVE0j6yQOtIZDG4oxCS4sOUy72
hXoSTpXYxgTBlDFCeZTNlLj/pbZsGdjehA0dFaKZLqYaWFTr
Host: news.bbc.co.uk

HTTP/1.1 407 Proxy Authentication Required
Server: squid/3.4.1-BZR
Mime-Version: 1.0
Date: Sun, 02 Feb 2014 20:44:30 GMT
Content-Type: text/html
Content-Length: 5235
X-Squid-Error: ERR_CACHE_ACCESS_DENIED 0
Vary: Accept-Language
Content-Language: en-gb
Proxy-Authenticate: Negotiate
Proxy-Authenticate: NTLM
X-Cache: MISS from opensuse12.suse.home
X-Cache-Lookup: NONE from opensuse12.suse.home:3128
Via: 1.1 opensuse12.suse.home (squid/3.4.1-BZR)
Connection: keep-alive


    02/Feb/2014:20:44:20 +0000      1 192.168.1.5 TCP_DENIED/407 4772 GET
http://news.bbc.co.uk/ - HIER_NONE/- text/html
    02/Feb/2014:20:44:20 +0000      1 192.168.1.5 TCP_DENIED/407 5106 GET
http://news.bbc.co.uk/ - HIER_NONE/- text/html
    02/Feb/2014:20:44:20 +0000      2 192.168.1.5 TCP_DENIED/407 5215 GET
http://news.bbc.co.uk/ - HIER_NONE/- text/html
    02/Feb/2014:20:44:30 +0000      1 192.168.1.5 TCP_DENIED/407 5723 GET
http://news.bbc.co.uk/ - HIER_NONE/- text/html
    02/Feb/2014:20:44:32 +0000      0 192.168.1.5 TCP_DENIED/407 5715 GET
http://news.bbc.co.uk/ - HIER_NONE/- text/html
    02/Feb/2014:20:44:33 +0000      0 192.168.1.5 TCP_DENIED/407 5717 GET
http://news.bbc.co.uk/ - HIER_NONE/- text/html

2014/02/02 20:44:20| negotiate_wrapper: Got 'YR
TlRMTVNTUAABAAAAB4IIogAAAAAAAAAAAAAAAAAAAAAFASgKAAAADw==' from squid
(length: 59).
2014/02/02 20:44:20| negotiate_wrapper: Decode
'TlRMTVNTUAABAAAAB4IIogAAAAAAAAAAAAAAAAAAAAAFASgKAAAADw==' (decoded length:
40).
2014/02/02 20:44:20| negotiate_wrapper: received type 1 NTLM token
2014/02/02 20:44:20| negotiate_wrapper: Return 'TT
TlRMTVNTUAACAAAAEgASADgAAAAFgomidwZO3urOiHMAAAAAAAAAAHQAdABKAAAABgEAAAAAAA9X
AEkATgAyADAAMAAzAFIAMgACABIAVwBJAE4AMgAwADAAMwBSADIAAQAUAE8AUABFAE4AUwBVAFMA
RQAxADIABAASAHMAdQBzAGUALgBoAG8AbQBlAAMAKABvAHAAZQBuAHMAdQBzAGUAMQAyAC4AcwB1
AHMAZQAuAGgAbwBtAGUAAAAAAA==
'
2014/02/02 20:44:20| negotiate_wrapper: Got 'KK
TlRMTVNTUAADAAAAGAAYAHAAAACkAKQAiAAAAAwADABIAAAAEAAQAFQAAAAMAAwAZAAAAAAAAAAs
AQAABYKIogUBKAoAAAAPVwBJAE4AWABQADIAbQBhAHIAawB1AHMALQBhAFcASQBOAFgAUAAyAOmv
r8DyncxUqwDSHwz5dmyjvLjyntOAlbYw7FoskZGLTcg6KCT5ARUBAQAAAAAAAFYzj5JXIM8Bo7y4
8p7TgJUAAAAAAgASAFcASQBOADIAMAAwADMAUgAyAAEAFABPAFAARQBOAFMAVQBTAEUAMQAyAAQA
EgBzAHUAcwBlAC4AaABvAG0AZQADACgAbwBwAGUAbgBzAHUAcwBlADEAMgAuAHMAdQBzAGUALgBo
AG8AbQBlAAAAAAAAAAAA' from squid (length: 403).
2014/02/02 20:44:20| negotiate_wrapper: Decode
'TlRMTVNTUAADAAAAGAAYAHAAAACkAKQAiAAAAAwADABIAAAAEAAQAFQAAAAMAAwAZAAAAAAAAAA
sAQAABYKIogUBKAoAAAAPVwBJAE4AWABQADIAbQBhAHIAawB1AHMALQBhAFcASQBOAFgAUAAyAOm
vr8DyncxUqwDSHwz5dmyjvLjyntOAlbYw7FoskZGLTcg6KCT5ARUBAQAAAAAAAFYzj5JXIM8Bo7y
48p7TgJUAAAAAAgASAFcASQBOADIAMAAwADMAUgAyAAEAFABPAFAARQBOAFMAVQBTAEUAMQAyAAQ
AEgBzAHUAcwBlAC4AaABvAG0AZQADACgAbwBwAGUAbgBzAHUAcwBlADEAMgAuAHMAdQBzAGUALgB
oAG8AbQBlAAAAAAAAAAAA' (decoded length: 300).
2014/02/02 20:44:20| negotiate_wrapper: received type 3 NTLM token
2014/02/02 20:44:20| negotiate_wrapper: Return 'NA = NT_STATUS_NO_SUCH_USER
'
2014/02/02 20:56:58 kid1| Logfile: opening log
stdio:/var/log/squid-3.4.1/netdb.state