[squid-users] Kerberos negotiate slow avg service time

[Amos Jeffries]

On 24/02/18 06:29, erdosain9 wrote:
> Hi to all.
> I dont know why i have this bad values. My network is woking fine. How i can
> do to fix this. I think is a high value.
> 
> HTTP/1.1 200 OK
> Server: squid/3.5.27
> Mime-Version: 1.0
> Date: Fri, 23 Feb 2018 17:16:25 GMT
> Content-Type: text/plain;charset=utf-8
> Expires: Fri, 23 Feb 2018 17:16:25 GMT
> Last-Modified: Fri, 23 Feb 2018 17:16:25 GMT
> X-Cache: MISS from proxy.mydomain.lan
> X-Cache-Lookup: MISS from proxy.mydomain.lan:3128
> Via: 1.1 proxy.mydomain.lan (squid/3.5.27)
> Connection: close
> 
> Negotiate Authenticator Statistics:
> program: /lib64/squid/negotiate_kerberos_auth
> number active: 50 of 50 (0 shutting down)
> requests sent: 4106
> replies received: 4105
> queue length: 0
> avg service time: 82 msec

The above "avg service time" is not bad for a system as complicated as
Kerberos. Note that this is significantly less than the outstanding
requests listed below in the report. That is a sign that a very large
number of the lookups are performed very, very fast.

In other words; what you see in the report is _only_ the odd ones that
do go slow enough to show up there. With maybe, at most, a few of the
faster ones that happened by chance to be partially done at the instant
the report was generated.


Be aware that it is normal for a helper which has not been used much to
require time to refresh its internal state in order to process a
request. Avoiding that problem is why you see the clear pattern of
#Requests going to one helper, with a second getting most of the
remainder and so on. Squid intentionally biases lookups towards the most
recently used/updated helper. Also, the longer delay times visible being
for the later helpers down the list is another side effect of that problem.


As Yuri cryptically asked, did this come to your attention due to
customer complaints? or just while observing the reports?
 if it is not causing observable issues to the clients I would not worry.

If you want to tune the helpers better than default, you can maybe
further reduce that state refresh by configuring the helper with
explicit details about what backed server to be contacting. A lot of the
delays are caused by sequences of DNS lookups and parsing + processing
the machine KeyTab files. The debug (-d) option of the helper itself can
assist you with identifying which of its internal processes is going
slowest. Just try not to drown in the flood of data from those very,
very fast ones.


> 
>    ID #	     FD	    PID	 # Requests	  # Replies	 Flags	   Time	 Offset
> Request
>      21	     18	  57259	       1183	       1182	B R  	  0.293	      0	(none)
>      22	     22	  57260	        652	        652	     	  0.164	      0	(none)
...

> 
> 
> ###Kerberos Auth with ActiveDirectory###
> auth_param negotiate program /lib64/squid/negotiate_kerberos_auth -s
> HTTP/proxy.empddh.lan at EMPDDH.LAN
> auth_param negotiate children 50 startup=0 idle=1
> auth_param basic credentialsttl 2 hours
> auth_param negotiate keep_alive on
>