Hi Markus,
thank you very much for your help.
I changed MAX_AUTHTOKEN_LEN to 64 KB and recompiled squid.
After that there are no longer any hanging negotiate_kerberos_auth
helper processes.
This problem is fixed now.
For the memory problem I tried to debug with valgrind and I hope
I did it in the right way:
./negotiate_kerberos_auth_test proxyk1.spb.de testuser | valgrind
--log-file=/tmp/negotiate_kerberos_auth.val --leak-check=full
--show-reachable=yes -v ./negotiate_kerberos_auth -r -s GSS_C_NO_NAME
Here the last part of the output:
==26714== HEAP SUMMARY:
==26714== in use at exit: 14 bytes in 1 blocks
==26714== total heap usage: 59 allocs, 58 frees, 6,863 bytes allocated
==26714==
==26714== Searching for pointers to 1 not-freed blocks
==26714== Checked 318,728 bytes
==26714==
==26714== 14 bytes in 1 blocks are definitely lost in loss record 1 of 1
==26714== at 0x4A069EE: malloc (vg_replace_malloc.c:270)
==26714== by 0x403384: xmalloc (in
/usr/lib64/squid/negotiate_kerberos_auth)
==26714== by 0x40359B: xstrdup (in
/usr/lib64/squid/negotiate_kerberos_auth)
==26714== by 0x401ADE: main (in /usr/lib64/squid/negotiate_kerberos_auth)
==26714==
==26714== LEAK SUMMARY:
==26714== definitely lost: 14 bytes in 1 blocks
==26714== indirectly lost: 0 bytes in 0 blocks
==26714== possibly lost: 0 bytes in 0 blocks
==26714== still reachable: 0 bytes in 0 blocks
==26714== suppressed: 0 bytes in 0 blocks
==26714==
==26714== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 6 from 6)
--26714--
--26714-- used_suppression: 4 U1004-ARM-_dl_relocate_object
--26714-- used_suppression: 2 glibc-2.5.x-on-SUSE-10.2-(PPC)-2a
==26714==
==26714== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 6 from 6)
It shows a lost of bytes.
Please tell me what I should do for further informations.
Klaus
Hi Klaus
If the token is to big then you need to update the source here:
src/auth/UserRequest.h:#define MAX_AUTHTOKEN_LEN 32768
I am curious about the memory leak as I run it through valgrind ( I
noticed some underlying Kerberos library leaks, but no leaks in the helper
itself). Can you run valgrind against the helper if I give you the
instructions ?
Markus
"Klaus Walter" <klaus.walter@xxxxxx> wrote in message
news:20130802163540.207140vakmhtvcu8@xxxxxxxxxxxxxxxxxxxxxx...
Hi Amos,
2013/07/30 08:48:04 kid1| Starting new negotiateauthenticator
helpers...
2013/07/30 08:48:04 kid1| helperOpenServers: Starting 1/500
'negotiate_kerberos_auth' processes
2013/07/30 08:48:04 kid1| ipcCreate: fork: (12) Cannot allocate memory
That is bad, it is unrelated to the helpers getting locked up though.
How much RAM is the Squid worker process using at the time this
appears?
Starting helpers with fork() requires Squid to be allocated virtual
memory 2x that being used at the time by the worker process.
And how much memory is currently in use by each of those 8 BUSY
helpers?
So it seems that we have two different problems:
The first problem is that our kerberos credentials from AD that are
greater
than 32 KB cause hanging helpers (see my last email).
The other problem seems to be a memory leak in kerberos authentication.
I also tested the latest negotiate_kerberos_auth helper comming with
squid 3.3.8
together with my older squid, but the memory usage ist also increasing
until there is
no free memory available.
Here you can see the memory usage when squid cannot allocate more
memory:
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 8027 0.0 0.0 74932 292 ? Ss Aug01 0:00 squid
-f
/etc/squid/squid-C.conf
squid 27950 0.8 67.8 13404452 8262560 ? S Aug01 6:34 \_
(squid-1) -f /etc/squid/squid-C.conf
squid 27951 0.0 0.0 76828 1864 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27952 0.0 0.0 76828 1516 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27953 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27954 0.0 0.0 72484 992 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27955 0.0 0.0 72484 992 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27956 0.0 0.0 76704 1788 ? S Aug01 0:01 \_
(ext_kerberos_ldap_group_acl)
squid 27957 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27958 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27959 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27960 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27961 0.0 0.0 76704 1800 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27962 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27963 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27964 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27965 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27966 0.0 0.0 76660 1512 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27967 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27968 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27969 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27970 0.0 0.0 72484 992 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27971 0.0 0.0 72484 992 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27972 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27973 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27974 0.0 0.0 72484 992 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27975 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27976 0.0 0.0 76660 1668 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27977 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27978 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27979 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27980 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27981 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27982 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27983 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27984 0.0 0.0 72484 992 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27985 0.0 0.0 72484 988 ? S Aug01 0:00 \_
(ext_kerberos_ldap_group_acl)
squid 27986 0.0 0.0 26484 448 ? S Aug01 0:00 \_
(unlinkd)
squid 27987 0.0 0.0 27000 744 ? S Aug01 0:02 \_
diskd 28620804 28620805 28620806
squid 27988 0.0 0.0 27000 748 ? S Aug01 0:02 \_
diskd 28620808 28620809 28620810
squid 27989 0.0 0.0 27000 764 ? S Aug01 0:02 \_
diskd 28620812 28620813 28620814
squid 27990 0.0 0.0 27000 756 ? S Aug01 0:02 \_
diskd 28620816 28620817 28620818
squid 28010 0.4 0.0 44916 1116 ? S Aug01 3:42 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 28058 0.1 0.0 44992 1116 ? S Aug01 1:11 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 29643 0.0 0.0 44976 1132 ? S Aug01 0:36 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 29644 0.0 0.0 44936 1120 ? S Aug01 0:26 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 29645 0.0 0.0 44944 1124 ? S Aug01 0:17 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 29646 0.0 0.0 44944 1116 ? S Aug01 0:12 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 21264 0.0 0.0 45192 1356 ? S 02:30 0:26 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 16792 0.1 0.0 45164 1120 ? S 06:11 0:20 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 20254 0.0 0.0 45056 1120 ? S 06:42 0:09 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 20291 0.0 0.0 45068 1120 ? S 06:43 0:07 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 20486 0.1 0.0 45092 1188 ? S 06:44 0:33 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 20487 0.1 0.0 45080 1320 ? S 06:44 0:20 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 23102 0.3 0.0 44896 1124 ? S 07:07 0:54 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 23103 0.1 0.0 44976 1148 ? S 07:07 0:23 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 23104 0.0 0.0 44972 1124 ? S 07:07 0:14 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 23105 0.0 0.0 44980 1180 ? S 07:07 0:09 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 23106 0.0 0.0 44972 1208 ? S 07:07 0:09 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 23107 0.0 0.0 44980 1164 ? S 07:07 0:12 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 23108 0.0 0.0 45084 1156 ? S 07:07 0:13 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 23109 0.0 0.0 45080 1128 ? S 07:07 0:08 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 23433 0.0 0.0 45068 1240 ? S 07:10 0:09 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 23434 0.0 0.0 45168 1276 ? S 07:10 0:12 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 23435 0.3 0.0 45200 1316 ? S 07:10 0:59 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 23436 0.2 0.0 45064 1152 ? S 07:10 0:33 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 23437 0.1 0.0 45072 1160 ? S 07:10 0:17 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 23438 0.1 0.0 45172 1116 ? S 07:10 0:23 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 25002 0.0 0.0 45168 1120 ? S 07:24 0:14 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 25824 0.0 0.0 141528 6152 ? S 07:31 0:00 \_
/usr/bin/perl -w /usr/local/squid/bin/authenticator.pl
squid 26539 0.0 0.0 45248 1144 ? S 07:37 0:09 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 26540 0.1 0.0 45248 1128 ? S 07:37 0:17 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 26544 0.0 0.0 45244 1152 ? S 07:37 0:12 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 26545 0.0 0.0 45240 1144 ? S 07:37 0:09 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 29535 0.1 0.0 45240 1128 ? S 08:03 0:18 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 29536 0.1 0.0 45236 1416 ? S 08:03 0:24 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 29670 0.1 0.0 45304 1348 ? S 08:04 0:15 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 29771 0.5 0.0 45468 1524 ? S 08:05 1:08 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 29772 0.2 0.0 45496 1320 ? S 08:05 0:37 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 30614 0.2 0.0 45556 1764 ? S 08:13 0:30 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 30615 0.4 0.0 45808 1748 ? S 08:13 0:57 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 30616 0.1 0.0 45556 1976 ? S 08:13 0:15 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 1114 0.4 0.0 45588 1940 ? S 08:36 0:47 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 1115 0.2 0.0 45600 2140 ? S 08:36 0:28 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 1116 0.1 0.0 45616 2396 ? S 08:37 0:19 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 1120 0.1 0.0 45644 2396 ? S 08:37 0:14 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 1121 0.0 0.0 45640 2328 ? S 08:37 0:10 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 1122 0.0 0.0 45632 2292 ? S 08:37 0:08 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 1200 0.2 0.0 45192 2008 ? S 08:37 0:31 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 1201 0.2 0.0 45196 2000 ? S 08:37 0:28 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 1202 0.0 0.0 45552 2340 ? S 08:37 0:04 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 3674 0.1 0.0 45188 2060 ? S 08:56 0:11 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 3675 0.0 0.0 45220 2084 ? S 08:56 0:08 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 3676 0.0 0.0 45184 2020 ? S 08:56 0:07 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 3982 0.0 0.0 45264 2152 ? S 08:59 0:05 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 3983 0.0 0.0 45264 2148 ? S 08:59 0:03 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 3987 0.0 0.0 45268 2140 ? S 08:59 0:03 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 3988 0.0 0.0 45260 2144 ? S 08:59 0:03 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 3989 0.0 0.0 45264 2052 ? S 08:59 0:02 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 3990 0.0 0.0 45260 2100 ? S 08:59 0:01 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 3991 0.0 0.0 45260 2152 ? S 08:59 0:02 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 3992 0.0 0.0 45268 2136 ? S 08:59 0:02 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 3993 0.0 0.0 45264 2148 ? S 08:59 0:01 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 3994 0.0 0.0 45264 2084 ? S 08:59 0:01 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 3995 0.0 0.0 45276 2160 ? S 08:59 0:01 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 3996 0.0 0.0 45280 2156 ? S 08:59 0:01 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 3997 0.0 0.0 45276 2156 ? S 08:59 0:04 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 3998 0.0 0.0 45276 2148 ? S 08:59 0:05 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 3999 0.0 0.0 45276 2168 ? S 08:59 0:01 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 4000 0.0 0.0 45320 2200 ? S 08:59 0:05 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 4001 0.0 0.0 45320 2196 ? S 08:59 0:02 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 4002 0.0 0.0 45328 2140 ? S 08:59 0:01 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 5727 0.3 0.0 45704 2520 ? S 09:13 0:28 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 5728 0.0 0.0 45700 2480 ? S 09:13 0:04 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
squid 5729 0.0 0.0 45700 2436 ? S 09:13 0:02 \_
(negotiate_kerberos_auth) -r -s GSS_C_NO_NAME
The server has 12 GB physical memory and 2 GB swap.
Klaus
