Kerberos negotiate slow avg service time

classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|

Kerberos negotiate slow avg service time

erdosain9
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

   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)
     23     42  57261        440        440      0.163      0 (none)
     24     46  57262        307        307      0.962      0 (none)
     25     48  57263        223        223      0.642      0 (none)
     26     50  57264        180        180      0.642      0 (none)
     27     55  57265        138        138      1.048      0 (none)
     28     59  57266        115        115      1.158      0 (none)
     29     65  57267         90         90      1.193      0 (none)
     30     56  57268         77         77      1.193      0 (none)
     31     74  57269         69         69      1.193      0 (none)
     32     76  57270         64         64      1.039      0 (none)
     33     78  57271         56         56      1.015      0 (none)
     34     80  57272         54         54      0.993      0 (none)
     35     82  57273         46         46      0.956      0 (none)
     36     84  57274         39         39      0.763      0 (none)
     37     79  57275         37         37      0.763      0 (none)
     38     83  57276         31         31      0.690      0 (none)
     39     94  57277         28         28      0.635      0 (none)
     40     96  57278         26         26      0.624      0 (none)
     41     98  57279         25         25      0.577      0 (none)
     42    100  57280         23         23      0.504      0 (none)
     43    102  57281         20         20      1.262      0 (none)
     44     99  57282         20         20      1.259      0 (none)
     45    122  57283         17         17      1.252      0 (none)
     46    124  57284         16         16      0.836      0 (none)
     47    126  57285         14         14      0.796      0 (none)
     48    128  57286         14         14      0.543      0 (none)
     49    119  57287         13         13      0.520      0 (none)
     50    125  57288         11         11      0.942      0 (none)
     52    222  57292          8          8      0.900      0 (none)
     53    224  57293          7          7      0.921      0 (none)
     54    227  57294          6          6      0.740      0 (none)
     55    230  57295          5          5      1.912      0 (none)
     56    231  57296          4          4      1.979      0 (none)
     57    233  57297          5          5      1.857      0 (none)
     58    236  57298          5          5      1.665      0 (none)
     59    237  57299          5          5      1.652      0 (none)
     60    239  57300          4          4      1.659      0 (none)
     61    241  57301          5          5      1.614      0 (none)
     62    243  57304          5          5      1.499      0 (none)
     63    245  57305          5          5      1.308      0 (none)
     71    450  57317          3          3      0.855      0 (none)
     72    452  57318          2          2      0.515      0 (none)
     73    453  57319          1          1      3.052      0 (none)
     74    455  57320          2          2      0.703      0 (none)
     75    457  57321          2          2      0.572      0 (none)
     76    458  57322          1          1      2.999      0 (none)
     77    352  57323          1          1      2.964      0 (none)
     78    460  57324          2          2      0.426      0 (none)

Flags key:

   B = BUSY
   C = CLOSING
   R = RESERVED
   S = SHUTDOWN PENDING
   P = PLACEHOLDER


###Kerberos Auth with ActiveDirectory###
auth_param negotiate program /lib64/squid/negotiate_kerberos_auth -s
HTTP/[hidden email]
auth_param negotiate children 50 startup=0 idle=1
auth_param basic credentialsttl 2 hours
auth_param negotiate keep_alive on


HTTP/1.1 200 OK
Server: squid/3.5.27
Mime-Version: 1.0
Date: Fri, 23 Feb 2018 17:25:58 GMT
Content-Type: text/plain;charset=utf-8
Expires: Fri, 23 Feb 2018 17:25:58 GMT
Last-Modified: Fri, 23 Feb 2018 17:25:58 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

Squid Object Cache: Version 3.5.27
Build Info:
Service Name: squid
Start Time: Fri, 23 Feb 2018 17:03:13 GMT
Current Time: Fri, 23 Feb 2018 17:25:58 GMT
Connection information for squid:
        Number of clients accessing cache: 55
        Number of HTTP requests received: 36896
        Number of ICP messages received: 0
        Number of ICP messages sent: 0
        Number of queued ICP replies: 0
        Number of HTCP messages received: 0
        Number of HTCP messages sent: 0
        Request failure ratio: 0.00
        Average HTTP requests per minute since start: 1621.0
        Average ICP messages per minute since start: 0.0
        Select loop called: 812404 times, 1.681 ms avg
Cache information for squid:
        Hits as % of all requests: 5min: 6.8%, 60min: 5.5%
        Hits as % of bytes sent: 5min: 4.9%, 60min: 6.7%
        Memory hits as % of hit requests: 5min: 10.2%, 60min: 13.4%
        Disk hits as % of hit requests: 5min: 56.6%, 60min: 58.4%
        Storage Swap size: 1790456 KB
        Storage Swap capacity: 11.7% used, 88.3% free
        Storage Mem size: 217812 KB
        Storage Mem capacity: 42.5% used, 57.5% free
        Mean Object Size: 18.76 KB
        Requests given to unlinkd: 6
Median Service Times (seconds)  5 min    60 min:
        HTTP Requests (All):   0.13498  0.15048
        Cache Misses:          0.16775  0.17711
        Cache Hits:            0.00091  0.00091
        Near Hits:             0.12783  0.19742
        Not-Modified Replies:  0.00000  0.00000
        DNS Lookups:           0.00573  0.02033
        ICP Queries:           0.00000  0.00000
Resource usage for squid:
        UP Time: 1365.713 seconds
        CPU Time: 169.409 seconds
        CPU Usage: 12.40%
        CPU Usage, 5 minute avg: 10.84%
        CPU Usage, 60 minute avg: 12.42%
        Maximum Resident Size: 3199584 KB
        Page faults with physical i/o: 0
Memory accounted for:
        Total accounted:       285660 KB
        memPoolAlloc calls:   9250370
        memPoolFree calls:    9301413
File descriptor usage for squid:
        Maximum number of file descriptors:   16384
        Largest file desc currently in use:   1078
        Number of file desc currently in use:  694
        Files queued for open:                   0
        Available number of file descriptors: 15690
        Reserved number of file descriptors:   100
        Store Disk files open:                   0
Internal Data Structures:
         95930 StoreEntries
         12101 StoreEntries with MemObjects
         11735 Hot Object Cache Items
         95464 on-disk objects





--
Sent from: http://squid-web-proxy-cache.1019090.n4.nabble.com/Squid-Users-f1019091.html
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Kerberos negotiate slow avg service time

Yuri Voinov
Users complains?


23.02.2018 23:29, erdosain9 пишет:

> 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
>
>    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)
>      23     42  57261        440        440      0.163      0 (none)
>      24     46  57262        307        307      0.962      0 (none)
>      25     48  57263        223        223      0.642      0 (none)
>      26     50  57264        180        180      0.642      0 (none)
>      27     55  57265        138        138      1.048      0 (none)
>      28     59  57266        115        115      1.158      0 (none)
>      29     65  57267         90         90      1.193      0 (none)
>      30     56  57268         77         77      1.193      0 (none)
>      31     74  57269         69         69      1.193      0 (none)
>      32     76  57270         64         64      1.039      0 (none)
>      33     78  57271         56         56      1.015      0 (none)
>      34     80  57272         54         54      0.993      0 (none)
>      35     82  57273         46         46      0.956      0 (none)
>      36     84  57274         39         39      0.763      0 (none)
>      37     79  57275         37         37      0.763      0 (none)
>      38     83  57276         31         31      0.690      0 (none)
>      39     94  57277         28         28      0.635      0 (none)
>      40     96  57278         26         26      0.624      0 (none)
>      41     98  57279         25         25      0.577      0 (none)
>      42    100  57280         23         23      0.504      0 (none)
>      43    102  57281         20         20      1.262      0 (none)
>      44     99  57282         20         20      1.259      0 (none)
>      45    122  57283         17         17      1.252      0 (none)
>      46    124  57284         16         16      0.836      0 (none)
>      47    126  57285         14         14      0.796      0 (none)
>      48    128  57286         14         14      0.543      0 (none)
>      49    119  57287         13         13      0.520      0 (none)
>      50    125  57288         11         11      0.942      0 (none)
>      52    222  57292          8          8      0.900      0 (none)
>      53    224  57293          7          7      0.921      0 (none)
>      54    227  57294          6          6      0.740      0 (none)
>      55    230  57295          5          5      1.912      0 (none)
>      56    231  57296          4          4      1.979      0 (none)
>      57    233  57297          5          5      1.857      0 (none)
>      58    236  57298          5          5      1.665      0 (none)
>      59    237  57299          5          5      1.652      0 (none)
>      60    239  57300          4          4      1.659      0 (none)
>      61    241  57301          5          5      1.614      0 (none)
>      62    243  57304          5          5      1.499      0 (none)
>      63    245  57305          5          5      1.308      0 (none)
>      71    450  57317          3          3      0.855      0 (none)
>      72    452  57318          2          2      0.515      0 (none)
>      73    453  57319          1          1      3.052      0 (none)
>      74    455  57320          2          2      0.703      0 (none)
>      75    457  57321          2          2      0.572      0 (none)
>      76    458  57322          1          1      2.999      0 (none)
>      77    352  57323          1          1      2.964      0 (none)
>      78    460  57324          2          2      0.426      0 (none)
>
> Flags key:
>
>    B = BUSY
>    C = CLOSING
>    R = RESERVED
>    S = SHUTDOWN PENDING
>    P = PLACEHOLDER
>
>
> ###Kerberos Auth with ActiveDirectory###
> auth_param negotiate program /lib64/squid/negotiate_kerberos_auth -s
> HTTP/[hidden email]
> auth_param negotiate children 50 startup=0 idle=1
> auth_param basic credentialsttl 2 hours
> auth_param negotiate keep_alive on
>
>
> HTTP/1.1 200 OK
> Server: squid/3.5.27
> Mime-Version: 1.0
> Date: Fri, 23 Feb 2018 17:25:58 GMT
> Content-Type: text/plain;charset=utf-8
> Expires: Fri, 23 Feb 2018 17:25:58 GMT
> Last-Modified: Fri, 23 Feb 2018 17:25:58 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
>
> Squid Object Cache: Version 3.5.27
> Build Info:
> Service Name: squid
> Start Time: Fri, 23 Feb 2018 17:03:13 GMT
> Current Time: Fri, 23 Feb 2018 17:25:58 GMT
> Connection information for squid:
> Number of clients accessing cache: 55
> Number of HTTP requests received: 36896
> Number of ICP messages received: 0
> Number of ICP messages sent: 0
> Number of queued ICP replies: 0
> Number of HTCP messages received: 0
> Number of HTCP messages sent: 0
> Request failure ratio: 0.00
> Average HTTP requests per minute since start: 1621.0
> Average ICP messages per minute since start: 0.0
> Select loop called: 812404 times, 1.681 ms avg
> Cache information for squid:
> Hits as % of all requests: 5min: 6.8%, 60min: 5.5%
> Hits as % of bytes sent: 5min: 4.9%, 60min: 6.7%
> Memory hits as % of hit requests: 5min: 10.2%, 60min: 13.4%
> Disk hits as % of hit requests: 5min: 56.6%, 60min: 58.4%
> Storage Swap size: 1790456 KB
> Storage Swap capacity: 11.7% used, 88.3% free
> Storage Mem size: 217812 KB
> Storage Mem capacity: 42.5% used, 57.5% free
> Mean Object Size: 18.76 KB
> Requests given to unlinkd: 6
> Median Service Times (seconds)  5 min    60 min:
> HTTP Requests (All):   0.13498  0.15048
> Cache Misses:          0.16775  0.17711
> Cache Hits:            0.00091  0.00091
> Near Hits:             0.12783  0.19742
> Not-Modified Replies:  0.00000  0.00000
> DNS Lookups:           0.00573  0.02033
> ICP Queries:           0.00000  0.00000
> Resource usage for squid:
> UP Time: 1365.713 seconds
> CPU Time: 169.409 seconds
> CPU Usage: 12.40%
> CPU Usage, 5 minute avg: 10.84%
> CPU Usage, 60 minute avg: 12.42%
> Maximum Resident Size: 3199584 KB
> Page faults with physical i/o: 0
> Memory accounted for:
> Total accounted:       285660 KB
> memPoolAlloc calls:   9250370
> memPoolFree calls:    9301413
> File descriptor usage for squid:
> Maximum number of file descriptors:   16384
> Largest file desc currently in use:   1078
> Number of file desc currently in use:  694
> Files queued for open:                   0
> Available number of file descriptors: 15690
> Reserved number of file descriptors:   100
> Store Disk files open:                   0
> Internal Data Structures:
> 95930 StoreEntries
> 12101 StoreEntries with MemObjects
> 11735 Hot Object Cache Items
> 95464 on-disk objects
>
>
>
>
>
> --
> Sent from: http://squid-web-proxy-cache.1019090.n4.nabble.com/Squid-Users-f1019091.html
> _______________________________________________
> squid-users mailing list
> [hidden email]
> http://lists.squid-cache.org/listinfo/squid-users
--
*****************************
* C++20 : Bug to the future *
*****************************



_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users

signature.asc (673 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: Kerberos negotiate slow avg service time

Amos Jeffries
Administrator
In reply to this post by erdosain9

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/[hidden email]
> auth_param negotiate children 50 startup=0 idle=1
> auth_param basic credentialsttl 2 hours
> auth_param negotiate keep_alive on
>

_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Kerberos negotiate slow avg service time

erdosain9
Thank you Amos (sorry again Yuri).

And yes, the user are complains.

The problem is this (and sorry for be recurrent with this).

That value avg ms for some times goes up to 3000... and in that moment all
stop.

in the cache.log sometimes, im getting this.

support_sasl.cc(276): pid=3729 :2018/02/27 14:44:35| kerberos_ldap_group:
ERROR: ldap_sasl_interactive_bind_s error: Can't contact LDAP server
support_ldap.cc(957): pid=3729 :2018/02/27 14:44:35| kerberos_ldap_group:
ERROR: Error while binding to ldap server with SASL/GSSAPI: Can't contact
LDAP server
2018/02/27 14:44:49 kid1| Error negotiating SSL on FD 45:
error:00000000:lib(0):func(0):reason(0) (5/-1/104)
support_sasl.cc(276): pid=3719 :2018/02/27 14:46:56| kerberos_ldap_group:
ERROR: ldap_sasl_interactive_bind_s error: Can't contact LDAP server
support_ldap.cc(957): pid=3719 :2018/02/27 14:46:56| kerberos_ldap_group:
ERROR: Error while binding to ldap server with SASL/GSSAPI: Can't contact
LDAP server
support_sasl.cc(276): pid=3719 :2018/02/27 14:47:18| kerberos_ldap_group:
ERROR: ldap_sasl_interactive_bind_s error: Can't contact LDAP server
support_ldap.cc(957): pid=3719 :2018/02/27 14:47:18| kerberos_ldap_group:
ERROR: Error while binding to ldap server with SASL/GSSAPI: Can't contact
LDAP server
support_sasl.cc(276): pid=3729 :2018/02/27 14:47:28| kerberos_ldap_group:
ERROR: ldap_sasl_interactive_bind_s error: Can't contact LDAP server
support_ldap.cc(957): pid=3729 :2018/02/27 14:47:28| kerberos_ldap_group:
ERROR: Error while binding to ldap server with SASL/GSSAPI: Can't contact
LDAP server
support_sasl.cc(276): pid=3719 :2018/02/27 14:47:36| kerberos_ldap_group:
ERROR: ldap_sasl_interactive_bind_s error: Can't contact LDAP server
support_ldap.cc(957): pid=3719 :2018/02/27 14:47:36| kerberos_ldap_group:
ERROR: Error while binding to ldap server with SASL/GSSAPI: Can't contact
LDAP server


Is impossible that this problem happend from the squid side? Im thinking
that is a problem in the AD (windows server 2012).

With more log (-d) i got a lot of this... (just a little). This is working
negotiate_kerberos_pac.cc(376): pid=3973 :2018/02/27 12:08:33|
negotiate_kerberos_auth: INFO: Got PAC data of lengh 584
negotiate_kerberos_pac.cc(180): pid=3973 :2018/02/27 12:08:33|
negotiate_kerberos_auth: INFO: Found 4 rids
negotiate_kerberos_pac.cc(188): pid=3973 :2018/02/27 12:08:33|
negotiate_kerberos_auth: Info: Got rid: 1168
negotiate_kerberos_pac.cc(188): pid=3973 :2018/02/27 12:08:33|
negotiate_kerberos_auth: Info: Got rid: 512
negotiate_kerberos_pac.cc(188): pid=3973 :2018/02/27 12:08:33|
negotiate_kerberos_auth: Info: Got rid: 513
negotiate_kerberos_pac.cc(188): pid=3973 :2018/02/27 12:08:33|
negotiate_kerberos_auth: Info: Got rid: 1132
negotiate_kerberos_pac.cc(256): pid=3973 :2018/02/27 12:08:33|
negotiate_kerberos_auth: INFO: Got DomainLogonId
S-1-5-21-3939648023-1419124151
-3306617744
negotiate_kerberos_pac.cc(278): pid=3973 :2018/02/27 12:08:33|
negotiate_kerberos_auth: INFO: Found 1 ExtraSIDs
negotiate_kerberos_pac.cc(327): pid=3973 :2018/02/27 12:08:33|
negotiate_kerberos_auth: INFO: Got ExtraSid S-1-18-1
negotiate_kerberos_pac.cc(456): pid=3973 :2018/02/27 12:08:33|
negotiate_kerberos_auth: INFO: Read 540 of 584 bytes
negotiate_kerberos_auth.cc(778): pid=3973 :2018/02/27 12:08:33|
negotiate_kerberos_auth: DEBUG: Groups
group=AQUAAAAAAAUVAAAAF0LS6rcdllSQ+xbFk
AQAAA== group=AQUAAAAAAAUVAAAAF0LS6rcdllSQ+xbFAAIAAA==
group=AQUAAAAAAAUVAAAAF0LS6rcdllSQ+xbFAQIAAA==
group=AQUAAAAAAAUVAAAAF0LS6rcdllSQ+xbFbA
QAAA== group=AQEAAAAAABIBAAAA
negotiate_kerberos_auth.cc(783): pid=3973 :2018/02/27 12:08:33|
negotiate_kerberos_auth: DEBUG: AF
oYG2MIGzoAMKAQChCwYJKoZIgvcSAQICooGeBIGbYIG
YBgkqhkiG9xIBAgICAG+BiDCBhaADAgEFoQMCAQ+ieTB3oAMCARKicARub5MOjpO177M/gXJcAdluTnj+29wfwmcbZJVIFDyiXBKLScmwPhaPd2sH4IvcEiBhgddiTbURTRfM7OsWlql7+
uS2I4WWSke5bcRYRIaprvgl3wtCoX9PjSQEmYL0H8LIBL0sQh2fbYftAXyxMGs=
[hidden email]
negotiate_kerberos_auth.cc(610): pid=3973 :2018/02/27 12:08:37|
negotiate_kerberos_auth: DEBUG: Got 'YR
YIIHJQYGKwYBBQUCoIIHGTCCBxWgMDAuBgkqhk
iC9xIBAgIGCSqGSIb3EgECAgYKKwYBBAGCNwICHgYKKwYBBAGCNwICCqKCBt8EggbbYIIG1wYJKoZIhvcSAQICAQBuggbGMIIGwqADAgEFoQMCAQ6iBwMFACAAAACjggUDYYIE/zCCBPug
AwIBBaEMGwpFTVBEREguTEFOoiMwIaADAgECoRowGBsESFRUUBsQcHJveHkuZW1wZGRoLmxhbqOCBL8wggS7oAMCARKhAwIBA6KCBK0EggSpV5Ofs3WVdVBcsFv+Hm0rIqwv8Lnra2qZOa
8cldCaPT4j6lGbmhe4JphrdI8H+dJbZI42SC1WLj6ettPI1OB5JPc340A6q3X7f9Zjp1rplc/6/n2mNooCah+Epq83CeI2w1bjX24sIwv5Vj5fNv9l5tzRI2vm5hry828+jNNGEamR0Vi5
1wy1HpFRVm39xExs9HiIdVRuVLC2sgXPf3PLLlmE5pKPATPW074v045VnrYXFERgyFN45Le4oBqavwtQ4yxdnVt/3wHzx9B2jYckYp0EMbS4yHMH8trwNJwYWji7zTINkD1s81EMCl0t0R
bQBwt8rLbcYLurOpj95nicRZbfSAkNozbVo1i4sYApjqxZG1xPK1JdNYc927kCayiTSa6emuD2LbXaY47phntoGg77k8JvaSeqL/yNMhPS8/k5PuE1qSaQjSvatAiqUF8fWQRu9O8f4uhQ
LyseKPkBiO6Ll/NgQFXhAQOwxyvunbLZhVz568UsP1EMw8IRU8m6CRXoyHB9xFQVS+QI3PBYXzD3eFtYfofbXJjYm97VZrB+CmmU5K72Azm/bQzwybSbDhqLo9FyKAR2K9lFp0q3/Gt/Gf
+A7z2JR02Nl0spHVjsvJpLJ9G7QeJ/N2ByUs6oHC+95RTIZzpnTi8o+0eRBeG1QXR08OymGsiHPe7QAG90KFe0bGbmS3Q/nVy2kvcBnmnrDpmgkO6Q5pXQmg/25+nw20Cp0nTKSdmaXhcZ
JqiHh8loktMJxwtx1OlOcqy+Rrn2z+Ebp5WRiaBUZA2x95Bxx8QAc6PnPO0jHNyYZBuHO6UPzm71EkC5Af6CEHmXJoIp+/ipCgnMi/8LVRti3RDd/g3tHyk7AvOeGznqfJk0u1feL0oC/v
hx6uUxEG42YTuo7kYEwcYzENFNuqKEWCW8pLPLuw0P6CX76mpwbMSikV9qRcjB1bzDtS5YCkPXYjrCEYam1PcWYC/df8n+364LDDHHGCVWN4dLDaOqGy5xiek7mA6xdR7F0DH4BmzF89Hu
ZHhearwgpOH2gQci8YCwCrZUYbb7VepoXRG1WhiCLXpItF1uC96ERZreCh3FMv9WsOvuZ9W5LkzM6gHtTMRgNi9jQF5Y/OqN9zbAJq2/pFg5CCJA2UMjyrOv+rDq0c48d1ECTc+RYy2ISL
VtvTIQyXe4mxQ7Lmzrej5a3JhMxbICvmVj9tNLoe8JKcbUP0/gV3x8QpRGK7yx7+Zn0v6DCEIyD2cX1LMp0++n5j7rKNjcx9Kq6bkwH1T5qecmScmWf57nVgASGcWtC5fFKW4qpjtC2A74
Nu5lC+z90iGKOIlfXdyJHeQW/LufQDm8h4p731wFR22WD2ki0Z1eavTVibafZOKZIZuMNBfPSmKY9f0rmzCbv9Syxel/tU0Z87tyDid/m8qC2t9krg4Yr/5bAoVXMcDW31PwlSwInxom16
E1aSMarQ0oLo7rx0TSrC1QZj0/DsMWsacy2L1qhylYRU+poQsJaGJhTgZqqIHfoklR0MKN6i0hWJe1PXhvH/QZr4Ftif483pxd8Koq9UYM1aHjw/KSdo2Y1q/KZ2gdH0gIDoVYQNOkggGk
MIIBoKADAgESooIBlwSCAZPiK9yyDUJajCbaipq/vKOjP2JAo4TWDL66hZ2p37D0Y7eLah8oxghut6psDK9rmoUnpgZjZ8uRLDa73+6tlEOpdTyAafyftG5egQXvDzCzluLEnjg4NpQ+Y0
NgrpOYSkUpOijbLrl4jdsAmg9TEDI3qpfSC4Vm22xcs/XUFIwoXGRBRsCriirSNPOqGaayDuP0wJsyq3ldMPYCHmN3K+gsOmuWeJqg5xmjOlCLWarJXg7ZKy9cbgfmFDZNNuq0ihXP7CvT
sH2LSAsr8XLFNbEfR8UQkfGVwnvDsl68FQzSzR4bVkKE5sFJOsloM51R2i2y60TA8q7O4GYmUEXBJEkLWElRc9X4EMq9XCN49+VRxZEFXYP/62gGXfr3kC9sbFm2r4KkozuEEqt5ngjXjHH5+5RklbSDwKhoqnMRmOn8mdPc6ZTqCMahmxbJEJNOvbhQQaI17H46MVt8uBxMbMGXor0i95SOKtnJGlbUkxP6/GDJu/KmzwdJQC7Oa8C7avx/QHKj2LYyVkFkB3kUE5CSJsR0'
from squid (length: 2447).


But, in some moments i get again the :
kerberos_ldap_group: ERROR: Error while binding to ldap server with
SASL/GSSAPI: Can't contact LDAP server

This is probably a Windows server, i repeat, but i ask for if someone know
what can i do. (and maybe ensure that is not a squid problem)

(Again sorry with continue with this).



--
Sent from: http://squid-web-proxy-cache.1019090.n4.nabble.com/Squid-Users-f1019091.html
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Kerberos negotiate slow avg service time

Amos Jeffries
Administrator
On 28/02/18 07:43, erdosain9 wrote:

> Thank you Amos (sorry again Yuri).
>
> And yes, the user are complains.
>
> The problem is this (and sorry for be recurrent with this).
>
> That value avg ms for some times goes up to 3000... and in that moment all
> stop.
>
> in the cache.log sometimes, im getting this.
>
> support_sasl.cc(276): pid=3729 :2018/02/27 14:44:35| kerberos_ldap_group:
> ERROR: ldap_sasl_interactive_bind_s error: Can't contact LDAP server
> support_ldap.cc(957): pid=3729 :2018/02/27 14:44:35| kerberos_ldap_group:
> ERROR: Error while binding to ldap server with SASL/GSSAPI: Can't contact
> LDAP server
> 2018/02/27 14:44:49 kid1| Error negotiating SSL on FD 45:
> error:00000000:lib(0):func(0):reason(0) (5/-1/104)
> support_sasl.cc(276): pid=3719 :2018/02/27 14:46:56| kerberos_ldap_group:
> ERROR: ldap_sasl_interactive_bind_s error: Can't contact LDAP server
> support_ldap.cc(957): pid=3719 :2018/02/27 14:46:56| kerberos_ldap_group:
> ERROR: Error while binding to ldap server with SASL/GSSAPI: Can't contact
> LDAP server
> support_sasl.cc(276): pid=3719 :2018/02/27 14:47:18| kerberos_ldap_group:
> ERROR: ldap_sasl_interactive_bind_s error: Can't contact LDAP server
> support_ldap.cc(957): pid=3719 :2018/02/27 14:47:18| kerberos_ldap_group:
> ERROR: Error while binding to ldap server with SASL/GSSAPI: Can't contact
> LDAP server
> support_sasl.cc(276): pid=3729 :2018/02/27 14:47:28| kerberos_ldap_group:
> ERROR: ldap_sasl_interactive_bind_s error: Can't contact LDAP server
> support_ldap.cc(957): pid=3729 :2018/02/27 14:47:28| kerberos_ldap_group:
> ERROR: Error while binding to ldap server with SASL/GSSAPI: Can't contact
> LDAP server
> support_sasl.cc(276): pid=3719 :2018/02/27 14:47:36| kerberos_ldap_group:
> ERROR: ldap_sasl_interactive_bind_s error: Can't contact LDAP server
> support_ldap.cc(957): pid=3719 :2018/02/27 14:47:36| kerberos_ldap_group:
> ERROR: Error while binding to ldap server with SASL/GSSAPI: Can't contact
> LDAP server
>
>
> Is impossible that this problem happend from the squid side? Im thinking
> that is a problem in the AD (windows server 2012).

The Squid helper is using a SASL library on your system to contact the
LDAP server. Those error messages are sadly all the info which Squid or
its helper have about the failure.

A quick search for the message though, brings up this document about
LDAP listing quite a few reasons that message may appear (ie places to
check):
 <http://www.openldap.org/faq/data/cache/1432.html>

Note: I have no knowledge of its accuracy, it just seems like a useful
list of things for you to check up on.

From the sounds of it the problem is usually a lot more harsh and fatal
than what yo are seeing. It is kind of odd that it only affects an
occasional request - as shown by your cachemgr report earlier *most*
requests go straight through nice and quickly.


This may be quite different, but: I saw similar weird "sometimes"
failures with an IMAP service last year. It turned out that fail2ban was
set with a slightly too-low threshold and was banning a particular
client on flakey Dial-Up internet connection when it was raining in
their neighbourhood. Their TCP connection losses caused a ban which we
were seeing only as failure to re-login some minutes later once the
clients mail program wanted to re-check new mail.



>
> With more log (-d) i got a lot of this... (just a little). This is working
> negotiate_kerberos_pac.cc(376): pid=3973 :2018/02/27 12:08:33|
> negotiate_kerberos_auth: INFO: Got PAC data of lengh 584
> negotiate_kerberos_pac.cc(180): pid=3973 :2018/02/27 12:08:33|
> negotiate_kerberos_auth: INFO: Found 4 rids
> negotiate_kerberos_pac.cc(188): pid=3973 :2018/02/27 12:08:33|
> negotiate_kerberos_auth: Info: Got rid: 1168
> negotiate_kerberos_pac.cc(188): pid=3973 :2018/02/27 12:08:33|
> negotiate_kerberos_auth: Info: Got rid: 512
> negotiate_kerberos_pac.cc(188): pid=3973 :2018/02/27 12:08:33|
> negotiate_kerberos_auth: Info: Got rid: 513
> negotiate_kerberos_pac.cc(188): pid=3973 :2018/02/27 12:08:33|
> negotiate_kerberos_auth: Info: Got rid: 1132
> negotiate_kerberos_pac.cc(256): pid=3973 :2018/02/27 12:08:33|
> negotiate_kerberos_auth: INFO: Got DomainLogonId
> S-1-5-21-3939648023-1419124151
> -3306617744
> negotiate_kerberos_pac.cc(278): pid=3973 :2018/02/27 12:08:33|
> negotiate_kerberos_auth: INFO: Found 1 ExtraSIDs
> negotiate_kerberos_pac.cc(327): pid=3973 :2018/02/27 12:08:33|
> negotiate_kerberos_auth: INFO: Got ExtraSid S-1-18-1
> negotiate_kerberos_pac.cc(456): pid=3973 :2018/02/27 12:08:33|
> negotiate_kerberos_auth: INFO: Read 540 of 584 bytes
> negotiate_kerberos_auth.cc(778): pid=3973 :2018/02/27 12:08:33|
> negotiate_kerberos_auth: DEBUG: Groups
> group=AQUAAAAAAAUVAAAAF0LS6rcdllSQ+xbFk
> AQAAA== group=AQUAAAAAAAUVAAAAF0LS6rcdllSQ+xbFAAIAAA==
> group=AQUAAAAAAAUVAAAAF0LS6rcdllSQ+xbFAQIAAA==
> group=AQUAAAAAAAUVAAAAF0LS6rcdllSQ+xbFbA
> QAAA== group=AQEAAAAAABIBAAAA
> negotiate_kerberos_auth.cc(783): pid=3973 :2018/02/27 12:08:33|
> negotiate_kerberos_auth: DEBUG: AF ...
> [hidden email]
> negotiate_kerberos_auth.cc(610): pid=3973 :2018/02/27 12:08:37|
> negotiate_kerberos_auth: DEBUG: Got 'YR...
> from squid (length: 2447).

This is mostly the data flow between Squid and the helper. That one
appears to be successful (found the groups=* lists).

There may be something about user credentials that breaks the LDAP
lookup, but AFAICT the failure is happening at the connect/bind stage
before any of the user info is sent to LDAP (I may be wrong there, my
knowledge of LDAP is low).


>
> But, in some moments i get again the :
> kerberos_ldap_group: ERROR: Error while binding to ldap server with
> SASL/GSSAPI: Can't contact LDAP server
>
> This is probably a Windows server, i repeat, but i ask for if someone know
> what can i do. (and maybe ensure that is not a squid problem)
>
> (Again sorry with continue with this).

Don't be sorry, help is part of what this list is for.
I just hope that someone with better LDAP know-how can assist you better
or the above clues give you an idea.


Amos
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users