[Samba] winbindd running amok
Bernd Schubert
bschubert at q-leap.de
Fri Jul 6 18:21:22 GMT 2007
Hi,
on a customer system samba/winbindd is used for windows and unix
authentication.
I just tuned searches of the ldap backend to speedup by factor 20-200 and
slapd now doesn't seem to be the bottleneck anymore.
Don't know how well the windows authentication now works, since this is
presently done by the heartbeat failover server.
However, simply starting 'mc' as root makes winbindd running amok and I have
no idea what actually happens.
I know this is ancient version 3.0.22, but upgrading without knowing
regressions is not so easy and so far we have no idea how to properly test
it first.
Below are 'strace -f mc' logs and winbindd logs. The ldap database has
about 50000 entries.
Any help is greately appreciated!
Thanks in advance,
Bernd
# /etc/nsswitch.conf
#
# GNU Name Service Switch configuration for NIS client with NIS shadow
support.
# Information about this file is available in the `libc6-doc' package.
passwd: files winbind
group: files winbind
shadow: files
strace -f mc
[...]
open("/lib/libnss_winbind.so.2", O_RDONLY) = 4
read(4, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0@\22\0\000"..., 512)
= 512
fstat64(4, {st_mode=S_IFREG|0644, st_size=17840, ...}) = 0
old_mmap(NULL, 26588, PROT_READ|PROT_EXEC, MAP_PRIVATE, 4, 0) = 0xb7cd6000
old_mmap(0xb7cda000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 4,
0x4000) = 0xb7cda000
old_mmap(0xb7cdb000, 6108, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED
MAP_ANONYMOUS, -1, 0) = 0xb7cdb000
close(4) = 0
munmap(0xb7f1e000, 24450) = 0
getpid() = 8795
getpid() = 8795
getpid() = 8795
lstat64("/tmp/.winbindd", {st_mode=S_IFDIR|0755, st_size=72, ...}) = 0
lstat64("/tmp/.winbindd/pipe", {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0
socket(PF_FILE, SOCK_STREAM, 0) = 4
fcntl64(4, F_GETFL) = 0x2 (flags O_RDWR)
fcntl64(4, F_SETFL, O_RDWR|O_NONBLOCK) = 0
fcntl64(4, F_GETFD) = 0
fcntl64(4, F_SETFD, FD_CLOEXEC) = 0
connect(4, {sa_family=AF_FILE, path="/tmp/.winbindd/pipe"}, 110) = 0
getpid() = 8795
getpid() = 8795
select(5, [4], NULL, NULL, {0, 0}) = 0 (Timeout)
write(4, ",\7\0\0\0\0\0\0[\"\0\0\0\10\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1836)
= 1836
select(5, [4], NULL, NULL, {5, 0}) = 1 (in [4], left {4, 792000})
read(4, "\24\5\0\0\2\0\0\0\v\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1300)
= 1300
getpid() = 8795
getpid() = 8795
select(5, [4], NULL, NULL, {0, 0}) = 0 (Timeout)
write(4, ",\7\0\0%\0\0\0[\"\0\0\0\10\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1836)
= 1836
select(5, [4], NULL, NULL, {5, 0}) = 1 (in [4], left {5, 0})
read(4, "3\5\0\0\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1300)
= 1300
select(5, [4], NULL, NULL, {5, 0}) = 1 (in [4], left {5, 0})
read(4, "/var/locks/winbindd_privileged\0", 31) = 31
lstat64("/var/locks/winbindd_privileged", {st_mode=S_IFDIR|0750,
st_size=72, ...}) = 0
lstat64("/var/locks/winbindd_privileged/pipe", {st_mode=S_IFSOCK|0777,
st_size=0, ...}) = 0
==============================================================================
winbind -i -d1000 -s /etc/samba/smb.conf
[...]
sid_to_gid: sid = [S-1-5-21-1895577662-1677200029-1617787245-301210]
db_get_id_from_sid
internal_get_id_from_sid: fetching record
S-1-5-21-1895577662-1677200029-1617787245-301210 of type 0x2
internal_get_id_from_sid: record
S-1-5-21-1895577662-1677200029-1617787245-301210 -> GID 22066
internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-1895577662-1677200029-1617787245-301210 -> GID 22066
internal_get_sid_from_id: fetching record GID 22066
internal_get_sid_from_id: fetching record GID 22066 ->
S-1-5-21-1895577662-1677200029-1617787245-301210
idmap_sid_to_gid: gid = [22066]
got gid 22066 for group 301210
group SID S-1-5-21-1895577662-1677200029-1617787245-301210
refresh_sequence_number: TUE time ok
refresh_sequence_number: TUE seq number is now 697668363
lookup_groupmem: [Cached] - doing backend query for info for domain TUE
ads: lookup_groupmem TUE
sid=S-1-5-21-1895577662-1677200029-1617787245-301210
Current tickets expire at 1183781357, time is now 1183745371
Searching for attrs[0] = member, attrs[1] = usnChanged
Search for
(objectSid=\01\05\00\00\00\00\00\05\15\00\00\00\3E\38\FC\70\9D\0A\F8\63\6D\79\6D\60\9A\98\04\00)
gave 1 replies
ads: dn_lookup
Search for (objectclass=*) gave 1 replies
ads: dn_lookup
Search for (objectclass=*) gave 1 replies
ads lookup_groupmem for sid=S-1-5-21-1895577662-1677200029-1617787245-301210
refresh_sequence_number: TUE time ok
refresh_sequence_number: TUE seq number is now 697668363
looked up 2 names
sdkruijf S-1-5-21-1895577662-1677200029-1617787245-17353
1
MKurtic S-1-5-21-1895577662-1677200029-1617787245-9320
1
processing name sdkruijf
buf_len + 13 = 13
processing name MKurtic
buf_len + 12 = 25
processing name sdkruijf
appending TUE+sdkruijf at ndx 12
processing name MKurtic
appending TUE+mkurtic at ndx 11
num_mem = 2, len = 25, mem = TUE+sdkruijf,TUE+mkurtic
fill_grent_mem returning 1
list_len = 755, mem_len = 25
adding group num_entries = 9
entry_index = 10, num_entries = 111511
sid_to_gid: sid = [S-1-5-21-1895577662-1677200029-1617787245-299969]
db_get_id_from_sid
internal_get_id_from_sid: fetching record
S-1-5-21-1895577662-1677200029-1617787245-299969 of type 0x2
internal_get_id_from_sid: record
S-1-5-21-1895577662-1677200029-1617787245-299969 -> GID 22067
internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-1895577662-1677200029-1617787245-299969 -> GID 22067
internal_get_sid_from_id: fetching record GID 22067
internal_get_sid_from_id: fetching record GID 22067 ->
S-1-5-21-1895577662-1677200029-1617787245-299969
idmap_sid_to_gid: gid = [22067]
got gid 22067 for group 299969
group SID S-1-5-21-1895577662-1677200029-1617787245-299969
refresh_sequence_number: TUE time ok
refresh_sequence_number: TUE seq number is now 697668363
lookup_groupmem: [Cached] - doing backend query for info for domain TUE
ads: lookup_groupmem TUE
sid=S-1-5-21-1895577662-1677200029-1617787245-299969
Current tickets expire at 1183781357, time is now 1183745371
Searching for attrs[0] = member, attrs[1] = usnChanged
Search for
(objectSid=\01\05\00\00\00\00\00\05\15\00\00\00\3E\38\FC\70\9D\0A\F8\63\6D\79\6D\60\C1\93\04\00)
gave 1 replies
ads: dn_lookup
Search for (objectclass=*) gave 1 replies
ads lookup_groupmem for sid=S-1-5-21-1895577662-1677200029-1617787245-299969
refresh_sequence_number: TUE time ok
refresh_sequence_number: TUE seq number is now 697668363
looked up 1 names
lkaufman S-1-5-21-1895577662-1677200029-1617787245-5671
1
processing name lkaufman
buf_len + 13 = 13
processing name lkaufman
appending TUE+lkaufman at ndx 12
num_mem = 1, len = 13, mem = TUE+lkaufman
fill_grent_mem returning 1
list_len = 780, mem_len = 13
adding group num_entries = 10
entry_index = 11, num_entries = 111511
sid_to_gid: sid = [S-1-5-21-1895577662-1677200029-1617787245-299968]
db_get_id_from_sid
internal_get_id_from_sid: fetching record
S-1-5-21-1895577662-1677200029-1617787245-299968 of type 0x2
internal_get_id_from_sid: record
S-1-5-21-1895577662-1677200029-1617787245-299968 -> GID 22068
internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-1895577662-1677200029-1617787245-299968 -> GID 22068
internal_get_sid_from_id: fetching record GID 22068
internal_get_sid_from_id: fetching record GID 22068 ->
S-1-5-21-1895577662-1677200029-1617787245-299968
idmap_sid_to_gid: gid = [22068]
got gid 22068 for group 299968
group SID S-1-5-21-1895577662-1677200029-1617787245-299968
refresh_sequence_number: TUE time ok
refresh_sequence_number: TUE seq number is now 697668363
lookup_groupmem: [Cached] - doing backend query for info for domain TUE
ads: lookup_groupmem TUE
sid=S-1-5-21-1895577662-1677200029-1617787245-299968
Current tickets expire at 1183781357, time is now 1183745371
Searching for attrs[0] = member, attrs[1] = usnChanged
Search for
(objectSid=\01\05\00\00\00\00\00\05\15\00\00\00\3E\38\FC\70\9D\0A\F8\63\6D\79\6D\60\C0\93\04\00)
gave 1 replies
ads: dn_lookup
Search for (objectclass=*) gave 1 replies
ads lookup_groupmem for sid=S-1-5-21-1895577662-1677200029-1617787245-299968
refresh_sequence_number: TUE time ok
refresh_sequence_number: TUE seq number is now 697668363
looked up 1 names
atijhuis S-1-5-21-1895577662-1677200029-1617787245-5570
1
processing name atijhuis
buf_len + 13 = 13
processing name atijhuis
appending TUE+atijhuis at ndx 12
num_mem = 1, len = 13, mem = TUE+atijhuis
fill_grent_mem returning 1
list_len = 793, mem_len = 13
adding group num_entries = 11
entry_index = 12, num_entries = 111511
sid_to_gid: sid = [S-1-5-21-1895577662-1677200029-1617787245-299967]
db_get_id_from_sid
internal_get_id_from_sid: fetching record
S-1-5-21-1895577662-1677200029-1617787245-299967 of type 0x2
internal_get_id_from_sid: record
S-1-5-21-1895577662-1677200029-1617787245-299967 -> GID 22069
internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-1895577662-1677200029-1617787245-299967 -> GID 22069
internal_get_sid_from_id: fetching record GID 22069
internal_get_sid_from_id: fetching record GID 22069 ->
S-1-5-21-1895577662-1677200029-1617787245-299967
idmap_sid_to_gid: gid = [22069]
got gid 22069 for group 299967
group SID S-1-5-21-1895577662-1677200029-1617787245-299967
refresh_sequence_number: TUE time ok
refresh_sequence_number: TUE seq number is now 697668363
lookup_groupmem: [Cached] - doing backend query for info for domain TUE
ads: lookup_groupmem TUE
sid=S-1-5-21-1895577662-1677200029-1617787245-299967
Current tickets expire at 1183781357, time is now 1183745371
Searching for attrs[0] = member, attrs[1] = usnChanged
Search for
(objectSid=\01\05\00\00\00\00\00\05\15\00\00\00\3E\38\FC\70\9D\0A\F8\63\6D\79\6D\60\BF\93\04\00)
gave 1 replies
ads: dn_lookup
Search for (objectclass=*) gave 1 replies
ads lookup_groupmem for sid=S-1-5-21-1895577662-1677200029-1617787245-299967
refresh_sequence_number: TUE time ok
refresh_sequence_number: TUE seq number is now 697668363
looked up 1 names
msmit S-1-5-21-1895577662-1677200029-1617787245-17281
1
processing name msmit
buf_len + 10 = 10
processing name msmit
appending TUE+msmit at ndx 9
num_mem = 1, len = 10, mem = TUE+msmit
fill_grent_mem returning 1
list_len = 806, mem_len = 10
adding group num_entries = 12
entry_index = 13, num_entries = 111511
sid_to_gid: sid = [S-1-5-21-1895577662-1677200029-1617787245-299966]
db_get_id_from_sid
internal_get_id_from_sid: fetching record
S-1-5-21-1895577662-1677200029-1617787245-299966 of type 0x2
internal_get_id_from_sid: record
S-1-5-21-1895577662-1677200029-1617787245-299966 -> GID 22070
internal_get_id_from_sid: ID_GROUPID fetching record
S-1-5-21-1895577662-1677200029-1617787245-299966 -> GID 22070
internal_get_sid_from_id: fetching record GID 22070
internal_get_sid_from_id: fetching record GID 22070 ->
S-1-5-21-1895577662-1677200029-1617787245-299966
idmap_sid_to_gid: gid = [22070]
got gid 22070 for group 299966
group SID S-1-5-21-1895577662-1677200029-1617787245-299966
refresh_sequence_number: TUE time ok
refresh_sequence_number: TUE seq number is now 697668363
lookup_groupmem: [Cached] - doing backend query for info for domain TUE
ads: lookup_groupmem TUE
sid=S-1-5-21-1895577662-1677200029-1617787245-299966
Current tickets expire at 1183781357, time is now 1183745371
Searching for attrs[0] = member, attrs[1] = usnChanged
Search for
(objectSid=\01\05\00\00\00\00\00\05\15\00\00\00\3E\38\FC\70\9D\0A\F8\63\6D\79\6D\60\BE\93\04\00)
gave 1 replies
ads: dn_lookup
Search for (objectclass=*) gave 1 replies
ads lookup_groupmem for sid=S-1-5-21-1895577662-1677200029-1617787245-299966
refresh_sequence_number: TUE time ok
refresh_sequence_number: TUE seq number is now 697668363
looked up 1 names
efledder S-1-5-21-1895577662-1677200029-1617787245-55501
1
Any idea whats going on? I think its cycling through every of the ~50000
entries in the ldap database, but what for?
Thanks,
Bernd
More information about the samba
mailing list