>> All,
>>
>>      I have a Squid and NTLM implementation.  I've had one for years, and 
>> always have been pretty pleased with it.  There has always been one quirk, 
>> and I've decided to ask about it in case there is a known solution.
>>
>> Typically, NTLM requires a back and forth of authentication.  Whenever a 
>> site is very slow to respond, or down and times out, my browsers display an 
>> authentication prompt to the end user.   I noticed this happens sometimes, 
>> even,  after the full page is loaded, and an advertisement or some other 
>> element takes a long time to load.
>> This behaviour sounds more like the slowness is being caused by NTLM itself 
>> being slow or failing. The domain lookups and connections do not even start 
>> to happen until NTLM>login to the proxy is already successfully completed.
>> The prompt is a browser feature. Squid has nothing to do with it besides the 
>> coincidence that the browser may choose to do it whenever Squid asks for 
>> credentials. The modern>ones usually only try it after automatic logins like 
>> NTLM have been tried and failed.
>>
>> You would think that is the case, but it's not.  I can demonstrate this.  
>> I've created a PHP page that just loads text.
>> http://www.pendulus.org/loaddirect.php
>>
>> Squid logs:
>> 1329009688.461      0 192.168.71.117 TCP_DENIED/407 4051 GET 
>> http://www.pendulus.org/loaddirect.php - NONE/- text/html
>> 1329009688.552      1 192.168.71.117 TCP_DENIED/407 4308 GET 
>> http://www.pendulus.org/loaddirect.php - NONE/- text/html
>> 1329009688.822    187 192.168.71.117 TCP_MISS/200 330 GET 
>> http://www.pendulus.org/loaddirect.php jgauthier DIRECT/69.135.186.43 
>> text/html
>>
>> This worked exactly as expected.
>>
>> I created one with a 30 second delay:
>> http://www.pendulus.org/loadshortpause.php
>>
>> Squid logs:
>> 1329010018.324      1 192.168.71.117 TCP_DENIED/407 4067 GET 
>> http://www.pendulus.org/loadshortpause.php - NONE/- text/html
>> 1329010018.473      0 192.168.71.117 TCP_DENIED/407 4332 GET 
>> http://www.pendulus.org/loadshortpause.php - NONE/- text/html
>> 1329010048.720  30194 192.168.71.117 TCP_MISS/200 330 GET 
>> http://www.pendulus.org/loadshortpause.php jgauthier 
>> DIRECT/69.135.186.43 text/html
>>
>> Notice my username does not appear until *after* the 30 second pause that's 
>> inside the web page.

>Yes. Note how the requests which have incomplete NTLM have "NONE/-" 
>logged for the server details.

>What that log shows is that successful NTLM credentials were recieved by Squid 
>(jgauthier), then DNS was performed (DIRECT) , then the server
>(69.135.186.43) was contacted. The entire process took 30.194 seconds.

>>
>> Lastly, I created one with a 300 second delay in it.
>> http://www.pendulus.org/loadpause.php
>>
>> Squid logs:
>> 1329009789.283      0 192.168.71.117 TCP_DENIED/407 4047 GET 
>> http://www.pendulus.org/loadpause.php - NONE/- text/html
>> 1329009789.372      0 192.168.71.117 TCP_DENIED/407 4312 GET 
>> http://www.pendulus.org/loadpause.php - NONE/- text/html
>> 1329009909.439 120024 192.168.71.117 TCP_MISS/000 0 GET 
>> http://www.pendulus.org/loadpause.php jgauthier DIRECT/69.135.186.43 -
>> 1329009909.534      0 192.168.71.117 TCP_DENIED/407 4331 GET 
>> http://www.pendulus.org/loadpause.php - NONE/- text/html
>>
>> At the point the second two log entries are created, the browser also 
>> prompted me for credentials again.
>> The gap in time is two minutes.
>> After two minutes, I am re-prompted from the browser, this is what I am 
>> describing.  The situation I want to stop from occurring.
>
>>This one shows is that successful NTLM credentials were recieved by 
>>Squid (jgauthier), then DNS was performed (DIRECT) , then the server 
>>(69.135.186.43) was contacted. Then after 120.024 seconds the connection 
>>between Squid and client got closed ("/000" in column 4) before anything 
>>was received by the server for delivery (0 bytes in column 5).
>
>>The browser decides to do the popup based on what it is aware of: An 
>>NTLM login which never got a successful response to the final stage when 
>>full credentials were sent. Try again (with different credentials).
>
>>You can try increasing 
>>http://www.squid-cache.org/Doc/config/persistent_request_timeout/ if it 
>>was Squid. But be aware of simialr limits in TCP firewall state tracking 
>>and NAT systems, and timeouts in browser as well which all result in the 
>>same connection closure.

I understand what you're saying, but I don't think the process you've described 
works the way you've described it.
For instance, you've said:

"What that log shows is that successful NTLM credentials were recieved by Squid 
(jgauthier), then DNS was performed (DIRECT) , then the server
(69.135.186.43) was contacted. The entire process took 30.194 seconds."

In regards to this log entry:

1329010018.324      1 192.168.71.117 TCP_DENIED/407 4067 GET 
http://www.pendulus.org/loadshortpause.php - NONE/- text/html
1329010018.473      0 192.168.71.117 TCP_DENIED/407 4332 GET 
http://www.pendulus.org/loadshortpause.php - NONE/- text/html
1329010048.720  30194 192.168.71.117 TCP_MISS/200 330 GET 
http://www.pendulus.org/loadshortpause.php jgauthier DIRECT/69.135.186.43 
text/html

Except the server is contacted at 1329010018, not 1329010048.

Using the logs on a new connection:

1329053373.745      0 192.168.71.117 TCP_DENIED/407 4103 GET 
http://www.pendulus.org/loadshortpause.php - NONE/- text/html
1329053373.832      2 192.168.71.117 TCP_DENIED/407 4375 GET 
http://www.pendulus.org/loadshortpause.php - NONE/- text/html

date && netstat -an|grep 69.135
Sun Feb 12 08:29:46 EST 2012
tcp6       0      0 192.168.74.119:44708    69.135.186.43:80        ESTABLISHED

1329053404.104  30196 192.168.71.117 TCP_MISS/200 330 GET 
http://www.pendulus.org/loadshortpause.php jgauthier DIRECT/69.135.186.43 
text/html

As you can see, when I look at the netstat output the connection to 
65.135.184.43 is established long before the last log file entry, where you are 
indicating it was established according to squid.

Squid is logging the contact after the page is fully loaded.  Apache agrees 
that the contact time starts before squid logs it.
64.129.117.119 - - [12/Feb/2012:08:29:34 -0500] "GET /loadshortpause.php 
HTTP/1.1" 200 19


It does seem you are correct in this regard:
 "Then after 120.024 seconds the connection between Squid and client got closed 
("/000" in column 4) before anything was received by the server for delivery (0 
bytes in column 5)."

And maybe the option you mentioned will help correct that.

As far as NTLM goes, I've done monitoring on the server to determine that NTLM 
itself is not the bottleneck.
I will look into your option, to see if it helps with the two minute time out. 
Otherwise, I wish the browser would just "start over" :P

Jason





Reply via email to