5:14 p.m.
I have somewhat of a complex issue, hoping someone here may have some
insight.
I have a beowulf cluster of systems for a scientific application we run.
This cluster consists of 32 diskless slaves running fc4 w/ a monolithic
kernel, and a master node running FC4 with a custom kernel. The master
issues rsh commands to the slaves to grab a chunk of a job and process it,
then return it.
My issue is this -- we have an old RH9 cluster that is similar in design,
and the rsh commands (measured using `time rsh node2 uname -a`) takes
around 0.050s to complete. On the FC4 system, we are running around
0.650-1.35s to complete the same command. I've traced the delay to xinetd or
in.rshd, but am at a loss going any further. I've run some straces and I can
see the delay occur. I've pasted the straces below for reference.
Does anyone have any idea why this delay is happening? These systems are all
wired up over gig-e (0.1-0.2ms pings round trip) and running dual 3.4ghz
Xeons w/ 2mb cache and 1gb mem in each slave, 4gb mem in the master. There
is a lot of processing power here, so I can't see a reason for the delay.
The PAM, rhosts, hosts.equiv, etc are all identical among the nodes (and the
clusters).
Here's the strace of the rsh command to a node:
============================ start strace ==========================
[14:51:42 - root@xxxx:/etc] strace -T -tt rsh node2 uname -a
16:18:55.277044 execve("/usr/bin/rsh", ["rsh", "node2",
"uname", "-a"], [/*
20 vars */]) = 0 <0.000128>
16:18:55.277525 brk(0) = 0x80003000 <0.000034>
16:18:55.277668 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f67000>
16:18:55.277825 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file
or directory) <0.000034>
16:18:55.277984 open("/etc/ld.so.cache", O_RDONLY) = 3 <0.000037>
16:18:55.278109 fstat64(3, {st_mode=S_IFREG|0644, st_size=60812, ...}) = 0
<0.000031>
16:18:55.278276 old_mmap(NULL, 60812, PROT_READ, MAP_PRIVATE, 3, 0) =
0xb7f58000 <0.000044>
16:18:55.278415 close(3) = 0 <0.000040>
16:18:55.278546 open("/lib/libcrypt.so.1", O_RDONLY) = 3 <0.000048>
16:18:55.278680 read(3,
"\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\360\7H"..., 512) = 512
<0.000042>
16:18:55.278821 fstat64(3, {st_mode=S_IFREG|0755, st_size=27660, ...}) = 0
<0.000033>
16:18:55.278988 old_mmap(NULL, 184604, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb7f2a000>
16:18:55.279131 old_mmap(0xb7f2f000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, >
16:18:55.279281 old_mmap(0xb7f31000, 155932, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, ->
16:18:55.279423 close(3) = 0 <0.000030>
16:18:55.279538 open("/lib/libutil.so.1", O_RDONLY) = 3 <0.000040>
16:18:55.279662 read(3,
"\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\260|\310"..., 512) = 512
<0.0000>
16:18:55.279793 fstat64(3, {st_mode=S_IFREG|0755, st_size=15080, ...}) = 0
<0.000030>
16:18:55.279937 old_mmap(NULL, 12432, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb7f26000 >
16:18:55.280067 old_mmap(0xb7f28000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, >
16:18:55.280222 close(3) = 0 <0.000030>
16:18:55.280334 open("/lib/libc.so.6", O_RDONLY) = 3 <0.000035>
16:18:55.280448 read(3,
"\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\n_B\000"..., 512) = 512
<0.00003>
16:18:55.280579 fstat64(3, {st_mode=S_IFREG|0755, st_size=1489572, ...}) = 0
<0.000030>
16:18:55.280725 old_mmap(NULL, 1219548, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb7dfc00>
16:18:55.280854 old_mmap(0xb7f20000, 16384, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3,>
16:18:55.280994 old_mmap(0xb7f24000, 7132, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1,>
16:18:55.281128 close(3) = 0 <0.000031>
16:18:55.281251 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7dfb000>
16:18:55.281391 set_thread_area({entry_number:-1 -> 6, base_addr:0xb7dfb9e0,
limit:1048575, seg_32bit:1, >
16:18:55.281665 mprotect(0xb7f20000, 8192, PROT_READ) = 0 <0.000035>
16:18:55.281780 mprotect(0xb7f28000, 4096, PROT_READ) = 0 <0.000034>
16:18:55.281892 mprotect(0xb7f2f000, 4096, PROT_READ) = 0 <0.000033>
16:18:55.282008 mprotect(0x409000, 4096, PROT_READ) = 0 <0.000034>
16:18:55.282115 munmap(0xb7f58000, 60812) = 0 <0.000037>
16:18:55.282278 getuid32() = 0 <0.000031>
16:18:55.282424 brk(0) = 0x80003000 <0.000030>
16:18:55.282526 brk(0x80024000) = 0x80024000 <0.000035>
16:18:55.282652 socket(PF_FILE, SOCK_STREAM, 0) = 3 <0.000040>
16:18:55.282764 fcntl64(3, F_GETFL) = 0x2 (flags O_RDWR) <0.000024>
16:18:55.282857 fcntl64(3, F_SETFL, O_RDWR|O_NONBLOCK) = 0 <0.000024>
16:18:55.282952 connect(3, {sa_family=AF_FILE, path="/var/run/nscd/socket"},
110) = -1 ENOENT (No such fi>
16:18:55.283097 close(3) = 0 <0.000027>
16:18:55.283195 socket(PF_FILE, SOCK_STREAM, 0) = 3 <0.000037>
16:18:55.283322 fcntl64(3, F_GETFL) = 0x2 (flags O_RDWR) <0.000033>
16:18:55.283438 fcntl64(3, F_SETFL, O_RDWR|O_NONBLOCK) = 0 <0.000031>
16:18:55.283551 connect(3, {sa_family=AF_FILE, path="/var/run/nscd/socket"},
110) = -1 ENOENT (No such fi>
16:18:55.283706 close(3) = 0 <0.000033>
16:18:55.283823 open("/etc/nsswitch.conf", O_RDONLY) = 3 <0.000035>
16:18:55.283948 fstat64(3, {st_mode=S_IFREG|0644, st_size=1686, ...}) = 0
<0.000030>
16:18:55.284094 mmap2(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f66000 <0>
16:18:55.284213 read(3, "#\n# /etc/nsswitch.conf\n#\n# An ex"..., 4096) =
1686 <0.000046>
16:18:55.284374 read(3, "", 4096) = 0 <0.000031>
16:18:55.284479 close(3) = 0 <0.000031>
16:18:55.284586 munmap(0xb7f66000, 4096) = 0 <0.000035>
16:18:55.284715 open("/etc/ld.so.cache", O_RDONLY) = 3 <0.000034>
16:18:55.284830 fstat64(3, {st_mode=S_IFREG|0644, st_size=60812, ...}) = 0
<0.000030>
16:18:55.284974 old_mmap(NULL, 60812, PROT_READ, MAP_PRIVATE, 3, 0) =
0xb7f58000 <0.000033>
16:18:55.285113 close(3) = 0 <0.000033>
16:18:55.285238 open("/lib/libnss_files.so.2", O_RDONLY) = 3 <0.000042>
16:18:55.285365 read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0
\33\0\000"..., 512) = 512 <0.000>
16:18:55.285518 fstat64(3, {st_mode=S_IFREG|0755, st_size=46552, ...}) = 0
<0.000031>
16:18:55.285669 old_mmap(NULL, 41616, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb7df0000 >
16:18:55.285800 old_mmap(0xb7df9000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, >
16:18:55.285949 close(3) = 0 <0.000031>
16:18:55.286073 mprotect(0xb7df9000, 4096, PROT_READ) = 0 <0.000036>
16:18:55.286220 munmap(0xb7f58000, 60812) = 0 <0.000036>
16:18:55.286367 open("/etc/passwd", O_RDONLY) = 3 <0.000034>
16:18:55.286486 fcntl64(3, F_GETFD) = 0 <0.000031>
16:18:55.286590 fcntl64(3, F_SETFD, FD_CLOEXEC) = 0 <0.000031>
16:18:55.286696 fstat64(3, {st_mode=S_IFREG|0644, st_size=2107, ...}) = 0
<0.000031>
16:18:55.286840 mmap2(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f66000 <0>
16:18:55.286949 read(3, "root:x:0:0:root:/root:/bin/bash\n"..., 4096) = 2107
<0.000045>
16:18:55.287095 close(3) = 0 <0.000031>
16:18:55.287198 munmap(0xb7f66000, 4096) = 0 <0.000037>
16:18:55.287319 open("/etc/services", O_RDONLY) = 3 <0.000027>
16:18:55.287424 fcntl64(3, F_GETFD) = 0 <0.000024>
16:18:55.287513 fcntl64(3, F_SETFD, FD_CLOEXEC) = 0 <0.000023>
16:18:55.287601 fstat64(3, {st_mode=S_IFREG|0644, st_size=20385, ...}) = 0
<0.000023>
16:18:55.287730 mmap2(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f66000 <0>
16:18:55.287823 read(3, "# /etc/services:\n# $Id: services"..., 4096) = 4096
<0.000037>
16:18:55.287991 read(3, "otocol\nntp\t\t123/tcp\nntp\t\t123/udp"..., 4096) =
4096 <0.000028>
16:18:55.288156 read(3, "67/udp\nrsync\t\t873/tcp\t\t\t\t# rsync"..., 4096)
= 4096 <0.000027>
16:18:55.288269 close(3) = 0 <0.000023>
16:18:55.288358 munmap(0xb7f66000, 4096) = 0 <0.000027>
16:18:55.288456 getpid() = 10358 <0.000023>
16:18:55.288577 gettimeofday({1130977135, 288621}, NULL) = 0 <0.000023>
16:18:55.288674 open("/etc/resolv.conf", O_RDONLY) = 3 <0.000027>
16:18:55.288776 fstat64(3, {st_mode=S_IFREG|0644, st_size=68, ...}) = 0
<0.000023>
16:18:55.288905 mmap2(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f66000 <0>
16:18:55.288999 read(3, "search accentopto.com\nnameserver"..., 4096) = 68
<0.000036>
16:18:55.289151 read(3, "", 4096) = 0 <0.000031>
16:18:55.289261 close(3) = 0 <0.000031>
16:18:55.289367 munmap(0xb7f66000, 4096) = 0 <0.000034>
16:18:55.289488 socket(PF_FILE, SOCK_STREAM, 0) = 3 <0.000034>
16:18:55.289596 fcntl64(3, F_GETFL) = 0x2 (flags O_RDWR) <0.000031>
16:18:55.289702 fcntl64(3, F_SETFL, O_RDWR|O_NONBLOCK) = 0 <0.000032>
16:18:55.289811 connect(3, {sa_family=AF_FILE, path="/var/run/nscd/socket"},
110) = -1 ENOENT (No such fi>
16:18:55.289965 close(3) = 0 <0.000033>
16:18:55.290076 socket(PF_FILE, SOCK_STREAM, 0) = 3 <0.000036>
16:18:55.290185 fcntl64(3, F_GETFL) = 0x2 (flags O_RDWR) <0.000031>
16:18:55.290290 fcntl64(3, F_SETFL, O_RDWR|O_NONBLOCK) = 0 <0.000031>
16:18:55.290399 connect(3, {sa_family=AF_FILE, path="/var/run/nscd/socket"},
110) = -1 ENOENT (No such fi>
16:18:55.290555 close(3) = 0 <0.000037>
16:18:55.290670 open("/etc/host.conf", O_RDONLY) = 3 <0.000034>
16:18:55.290786 fstat64(3, {st_mode=S_IFREG|0644, st_size=17, ...}) = 0
<0.000031>
16:18:55.290930 mmap2(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f66000 <0>
16:18:55.291038 read(3, "order hosts,bind\n", 4096) = 17 <0.000039>
16:18:55.291163 read(3, "", 4096) = 0 <0.000031>
16:18:55.291267 close(3) = 0 <0.000030>
16:18:55.291370 munmap(0xb7f66000, 4096) = 0 <0.000035>
16:18:55.291480 open("/etc/hosts", O_RDONLY) = 3 <0.000037>
16:18:55.291596 fcntl64(3, F_GETFD) = 0 <0.000031>
16:18:55.291699 fcntl64(3, F_SETFD, FD_CLOEXEC) = 0 <0.000031>
16:18:55.291809 fstat64(3, {st_mode=S_IFREG|0644, st_size=1819, ...}) = 0
<0.000030>
16:18:55.291953 mmap2(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f66000 <0>
16:18:55.292061 read(3, "# Do not remove the following li"..., 4096) = 1819
<0.000053>
16:18:55.292227 close(3) = 0 <0.000031>
16:18:55.292332 munmap(0xb7f66000, 4096) = 0 <0.000034>
16:18:55.292447 open("/etc/hosts", O_RDONLY) = 3 <0.000033>
16:18:55.292559 fcntl64(3, F_GETFD) = 0 <0.000031>
16:18:55.292663 fcntl64(3, F_SETFD, FD_CLOEXEC) = 0 <0.000031>
16:18:55.292766 fstat64(3, {st_mode=S_IFREG|0644, st_size=1819, ...}) = 0
<0.000030>
16:18:55.292910 mmap2(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f66000 <0>
16:18:55.293018 read(3, "# Do not remove the following li"..., 4096) = 1819
<0.000035>
16:18:55.293142 close(3) = 0 <0.000031>
16:18:55.293249 munmap(0xb7f66000, 4096) = 0 <0.000034>
16:18:55.293365 rt_sigprocmask(SIG_BLOCK, [URG], [], 8) = 0 <0.000032>
16:18:55.293492 socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 3 <0.000038>
16:18:55.293609 bind(3, {sa_family=AF_INET, sin_port=htons(1023),
sin_addr=inet_addr("0.0.0.0")}, 16) = ->
16:18:55.293738 bind(3, {sa_family=AF_INET, sin_port=htons(1022),
sin_addr=inet_addr("0.0.0.0")}, 16) = 0>
16:18:55.293855 fcntl64(3, F_SETOWN, 10358) = 0 <0.000031>
16:18:55.293963 connect(3, {sa_family=AF_INET, sin_port=htons(514),
sin_addr=inet_addr("192.168.101.2")},>
16:18:55.294279 socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 4 <0.000036>
16:18:55.294399 bind(4, {sa_family=AF_INET, sin_port=htons(1021),
sin_addr=inet_addr("0.0.0.0")}, 16) = 0>
16:18:55.294522 listen(4, 1) = 0 <0.000040>
16:18:55.294636 write(3, "1021\0", 5) = 5 <0.000037>
16:18:55.294754 poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN,
revents=POLLIN}], 2, -1) = 1 <0.002044>
16:18:55.296918 accept(4, {sa_family=AF_INET, sin_port=htons(1023),
sin_addr=inet_addr("192.168.101.2")},>
16:18:55.297084 close(4) = 0 <0.000038>
16:18:55.297196 writev(3, [{"root\0", 5}, {"root\0", 5}, {"uname
-a\0", 9}],
3) = 19 <0.000038>
16:18:55.297332 read(3, "\0", 1) = 1 <0.632181>
16:18:55.929633 rt_sigprocmask(SIG_SETMASK, [], [URG], 8) = 0 <0.000039>
16:18:55.929763 setuid32(0) = 0 <0.000039>
16:18:55.929866 rt_sigprocmask(SIG_BLOCK, [INT QUIT TERM], [], 8) = 0
<0.000047>
16:18:55.929991 rt_sigaction(SIGINT, {SIG_IGN}, {SIG_DFL}, 8) = 0 <0.000044>
16:18:55.930116 rt_sigaction(SIGINT, {0x80000d44, [INT], SA_RESTART},
{SIG_IGN}, 8) = 0 <0.000051>
16:18:55.930253 rt_sigaction(SIGQUIT, {SIG_IGN}, {SIG_DFL}, 8) = 0
<0.000046>
16:18:55.930377 rt_sigaction(SIGQUIT, {0x80000d44, [QUIT], SA_RESTART},
{SIG_IGN}, 8) = 0 <0.000042>
16:18:55.930499 rt_sigaction(SIGTERM, {SIG_IGN}, {SIG_DFL}, 8) = 0
<0.000049>
16:18:55.930627 rt_sigaction(SIGTERM, {0x80000d44, [TERM], SA_RESTART},
{SIG_IGN}, 8) = 0 <0.000045>
16:18:55.930758 clone(child_stack=0,
flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=>
16:18:55.931071 ioctl(5, FIONBIO, [1]) = 0 <0.000037>
16:18:55.931190 ioctl(3, FIONBIO, [1]) = 0 <0.000037>
16:18:55.931304 rt_sigprocmask(SIG_SETMASK, [], [INT QUIT TERM], 8) = 0
<0.000038>
16:18:55.931429 select(6, [3 5], NULL, NULL, NULL) = 2 (in [3 5]) <0.012086>
16:18:55.943612 read(5, "", 8192) = 0 <0.000043>
16:18:55.943722 read(3, "Linux node2.pcm3.cluster 2.6.13."..., 8192) = 95
<0.000039>
16:18:55.943842 write(1, "Linux node2.pcm3.cluster 2.6.13."..., 95Linux
node2.pcm3.cluster 2.6.13.2 #1 SMx
) = 95 <0.000038>
16:18:55.943930 select(6, [3], NULL, NULL, NULL) = 1 (in [3]) <0.000008>
16:18:55.943977 read(3, "", 8192) = 0 <0.000007>
16:18:55.944018 kill(10359, SIGKILL) = 0 <0.000008>
16:18:55.944096 exit_group(0) = ?
==================================== end strace
=================================
Here you can clearly see the delay happen:
<cut and paste section of interest from above>
16:18:55.297196 writev(3, [{"root\0", 5}, {"root\0", 5}, {"uname
-a\0", 9}],
3) = 19 <0.000038>
16:18:55.297332 read(3, "\0", 1) = 1 <0.632181>
16:18:55.929633 rt_sigprocmask(SIG_SETMASK, [], [URG], 8) = 0 <0.000039>
16:18:55.929763 setuid32(0) = 0 <0.000039>
<end cut and paste>
It looks like it takes .63s to write the data to the socket and get the
response, which I find hard to fathom (especially since anything outside of
xinetd's realm appears to be really fast over the network).
Thoughts?
-Tim
5:30 p.m.
On Mon, 2005-11-07 at 17:14, Tim Prendergast wrote:
My issue is this -- we have an old RH9 cluster that is similar in
design,
and the rsh commands (measured using `time rsh node2 uname -a`) takes
around 0.050s to complete. On the FC4 system, we are running around
0.650-1.35s to complete the same command. I've traced the delay to xinetd or
in.rshd, but am at a loss going any further. I've run some straces and I can
see the delay occur. I've pasted the straces below for reference.
Does anyone have any idea why this delay is happening?
The server side is probably issuing an IDENT query so it can
log the name of the owner of the initiating socket, which you
are probably firewalling or ignoring somewhere in between.
Does your xinetd entry for rsh mention USERID? If you don't
need it, take it out.
--
Les Mikesell
lesmikesell(a)gmail.com
5:54 p.m.
Yes, it does... here's the rsh file in /etc/xinetd.d
[root@]more /etc/xinetd.d/rsh
# default: on
# description: The rshd server is the server for the rcmd(3) routine and, \
# consequently, for the rsh(1) program. The server provides \
# remote execution facilities with authentication based on \
# privileged port numbers from trusted hosts.
service shell
{
disable = no
socket_type = stream
wait = no
user = root
log_on_success += USERID
log_on_failure += USERID
server = /usr/sbin/in.rshd
cps = 1000 5
}
The oddity is that the other system also has the USERID entries. I removed
them just now to test, restarted xinetd.d, and ran the same 'time rsh
localhost uname -a' with the same results as before. This would indicate to
me that the IDENT request is taking nearly no time at all (0.001s difference
in the times with or without the log lines present).
-Tim
----- Original Message -----
From: "Les Mikesell" <lesmikesell(a)gmail.com>
The server side is probably issuing an IDENT query so it can
log the name of the owner of the initiating socket, which you
are probably firewalling or ignoring somewhere in between.
Does your xinetd entry for rsh mention USERID? If you don't
need it, take it out.
--
Les Mikesell
lesmikesell(a)gmail.com
11:32 p.m.
On Mon, 2005-11-07 at 17:54, Tim Prendergast wrote:
Yes, it does... here's the rsh file in /etc/xinetd.d
[root@]more /etc/xinetd.d/rsh
# default: on
# description: The rshd server is the server for the rcmd(3) routine and, \
# consequently, for the rsh(1) program. The server provides \
# remote execution facilities with authentication based on \
# privileged port numbers from trusted hosts.
service shell
{
disable = no
socket_type = stream
wait = no
user = root
log_on_success += USERID
log_on_failure += USERID
server = /usr/sbin/in.rshd
cps = 1000 5
}
The oddity is that the other system also has the USERID entries. I removed
them just now to test, restarted xinetd.d, and ran the same 'time rsh
localhost uname -a' with the same results as before. This would indicate to
me that the IDENT request is taking nearly no time at all (0.001s difference
in the times with or without the log lines present).
Yes IDENT is normally fast if it either completes or isn't running
and you get an ICMP rejection. The thing that might have made
it slow would be if you had a firewall dropping the packets
so you'd get a timeout instead. Another thing that happens
during a connection is a reverse DNS lookup to log the
connecting host name and perhaps a check against hosts.allow
and hosts.deny. How fast does your DNS respond?
--
Les Mikesell
lesmikesell(a)gmail.com
12:27 p.m.
There is also no iptables installed, so firewall is out of the equation.
There should be no DNS involved because every host it talks to in the
process is in the /etc/hosts file, and the /etc/host.conf is 'order
hosts,bind'. My /etc/nsswitch.conf has files then dns listed as the args
after hosts... Technically, this should disable any lookups outside of
resolving in the hosts file for everything in the hosts file. We all know
that isn't always the case, which is why I'm asking here on the list. TCP
wrappers should be minimal, considering I just opened up a ALL:ALL in
hosts.allow to eliminate that possibility.
-Tim
----- Original Message -----
From: "Les Mikesell" <lesmikesell(a)gmail.com>
Yes IDENT is normally fast if it either completes or isn't running
and you get an ICMP rejection. The thing that might have made
it slow would be if you had a firewall dropping the packets
so you'd get a timeout instead. Another thing that happens
during a connection is a reverse DNS lookup to log the
connecting host name and perhaps a check against hosts.allow
and hosts.deny. How fast does your DNS respond?
--
Les Mikesell
1:27 p.m.
On Tue, 2005-11-08 at 12:27, Tim Prendergast wrote:
There is also no iptables installed, so firewall is out of the
equation.
There should be no DNS involved because every host it talks to in the
process is in the /etc/hosts file, and the /etc/host.conf is 'order
hosts,bind'. My /etc/nsswitch.conf has files then dns listed as the args
after hosts... Technically, this should disable any lookups outside of
resolving in the hosts file for everything in the hosts file. We all know
that isn't always the case, which is why I'm asking here on the list. TCP
wrappers should be minimal, considering I just opened up a ALL:ALL in
hosts.allow to eliminate that possibility.
If it is practical, strace xinetd through accepting a connection
(with -f to see if your rsh is doing any checks of its own
after the connection is up).
--
Les Mikesell
lesmikesell(a)gmail.com
3:31 p.m.
>There is also no iptables installed, so firewall is out of the
equation.
>There should be no DNS involved because every host it talks to in the
If it is practical, strace xinetd through accepting a connection
(with -f to see if your rsh is doing any checks of its own
after the connection is up).
A tcpdump watching all this isn't going to hurt either...
-Andy
5:32 p.m.
Working on getting time to tcpdump etc... IPv6 disabled in the
/etc/sysconfig/network on all boxes. Also have:
alias net-pf-10 off
alias ipv6 off
at the end of /etc/modprobe.conf.
-Tim
----- Original Message -----
From: "Andy Green" <andy(a)warmcat.com>
To: "For users of Fedora Core releases" <fedora-list(a)redhat.com>
Sent: Tuesday, November 08, 2005 1:45 PM
Subject: Re: xinetd delays in in.rshd responses (cluster problem, long)
--
fedora-list mailing list
fedora-list(a)redhat.com
To unsubscribe: https://www.redhat.com/mailman/listinfo/fedora-list
5:26 p.m.
Here's a strace from both sides of the connection -- server first, then
client.
I appreciate all of your help so far, this is proving to be very productive.
-Tim
=============== STRACE OFF SERVER XINETD ===============
[15:23:54 - root@xxx:~]strace -T -ttt -p 24001
Process 24001 attached - interrupt to quit
1131578642.371074 select(11, [3 5 6 8 9 10], NULL, NULL, NULL) = 1 (in [9])
<0.309762>
1131578642.680997 accept(9, {sa_family=AF_INET, sin_port=htons(1023),
sin_addr=inet_addr("192.168.101.2")}, [16]) = 11 <0.000045>
1131578642.681189 time(NULL) = 1131578642 <0.000036>
1131578642.681296 clone(child_stack=0,
flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0xb7d5a708) = 18935 <0.000554>
1131578642.681935 time([1131578642]) = 1131578642 <0.000033>
1131578642.682073 time([1131578642]) = 1131578642 <0.000095>
1131578642.682247 stat64("/etc/localtime", {st_mode=S_IFREG|0644,
st_size=1017, ...}) = 0 <0.000037>
1131578642.682408 stat64("/etc/localtime", {st_mode=S_IFREG|0644,
st_size=1017, ...}) = 0 <0.000035>
1131578642.682540 stat64("/etc/localtime", {st_mode=S_IFREG|0644,
st_size=1017, ...}) = 0 <0.000035>
1131578642.682682 send(7, "<86>Nov 9 15:24:02 xinetd[24001"..., 76,
MSG_NOSIGNAL) = 76 <0.000039>
1131578642.682864 close(11) = 0 <0.000034>
1131578642.682950 select(11, [3 5 6 8 9 10], NULL, NULL, NULL) = ?
ERESTARTNOHAND (To be restarted) <1.209783>
1131578643.892837 --- SIGCHLD (Child exited) @ 0 (0) ---
1131578643.892905 write(4, "\21", 1) = 1 <0.000038>
1131578643.893010 sigreturn() = ? (mask now []) <0.000033>
1131578643.893146 select(11, [3 5 6 8 9 10], NULL, NULL, NULL) = 1 (in [3])
<0.000038>
1131578643.893257 ioctl(3, FIONREAD, [1]) = 0 <0.000036>
1131578643.893354 read(3, "\21", 1) = 1 <0.000046>
1131578643.893457 waitpid(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}],
WNOHANG) = 18935 <0.000057>
1131578643.893575 close(-1) = -1 EBADF (Bad file descriptor)
<0.000042>
1131578643.893675 waitpid(-1, 0xbff04aa8, WNOHANG) = -1 ECHILD (No child
processes) <0.000034>
1131578643.893774 select(11, [3 5 6 8 9 10], NULL, NULL, NULL <unfinished
...>
Process 24001 detached
================= END SERVER STRACE ====================
================= START CLIENT STRACE ===================
[15:23:55 - root@node2:~]strace -ttt -f rsh master uname -a
1131578641.494993 execve("/usr/bin/rsh", ["rsh", "master",
"uname", "-a"],
[/* 20 vars */]) = 0
1131578641.495364 brk(0) = 0x80003000
1131578641.495429 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f4b000
1131578641.495504 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such
file or directory)
1131578641.495577 open("/etc/ld.so.cache", O_RDONLY) = 3
1131578641.495620 fstat64(3, {st_mode=S_IFREG|0644, st_size=57813, ...}) = 0
1131578641.495709 old_mmap(NULL, 57813, PROT_READ, MAP_PRIVATE, 3, 0) =
0xb7f3c000
1131578641.495761 close(3) = 0
1131578641.495810 open("/lib/libcrypt.so.1", O_RDONLY) = 3
1131578641.495857 read(3,
"\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\360\7H"..., 512) = 512
1131578641.495915 fstat64(3, {st_mode=S_IFREG|0755, st_size=27660, ...}) = 0
1131578641.495987 old_mmap(NULL, 184604, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb7f0e000
1131578641.496047 old_mmap(0xb7f13000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x4000) = 0xb7f13000
1131578641.496119 old_mmap(0xb7f15000, 155932, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb7f15000
1131578641.496184 close(3) = 0
1131578641.496229 open("/lib/libutil.so.1", O_RDONLY) = 3
1131578641.496273 read(3,
"\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\260|\310"..., 512) = 512
1131578641.496328 fstat64(3, {st_mode=S_IFREG|0755, st_size=15080, ...}) = 0
1131578641.496399 old_mmap(NULL, 12432, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb7f0a000
1131578641.496457 old_mmap(0xb7f0c000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1000) = 0xb7f0c000
1131578641.496531 close(3) = 0
1131578641.496571 open("/lib/libc.so.6", O_RDONLY) = 3
1131578641.496613 read(3,
"\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\n_B\000"..., 512) = 512
1131578641.496668 fstat64(3, {st_mode=S_IFREG|0755, st_size=1489572, ...}) =
0
1131578641.496742 old_mmap(NULL, 1219548, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb7de0000
1131578641.496800 old_mmap(0xb7f04000, 16384, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x124000) = 0xb7f04000
1131578641.496870 old_mmap(0xb7f08000, 7132, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb7f08000
1131578641.496934 close(3) = 0
1131578641.496986 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7ddf000
1131578641.497049 set_thread_area({entry_number:-1 -> 6,
base_addr:0xb7ddf9e0, limit:1048575, seg_32bit:1, contents:0,
read_exec_only:0, limit_in_pages:1, seg_not_present:0, useable:1}) = 0
1131578641.497205 mprotect(0xb7f04000, 8192, PROT_READ) = 0
1131578641.497247 mprotect(0xb7f0c000, 4096, PROT_READ) = 0
1131578641.497285 mprotect(0xb7f13000, 4096, PROT_READ) = 0
1131578641.497332 mprotect(0x409000, 4096, PROT_READ) = 0
1131578641.497368 munmap(0xb7f3c000, 57813) = 0
1131578641.497447 getuid32() = 0
1131578641.497523 brk(0) = 0x80003000
1131578641.497555 brk(0x80024000) = 0x80024000
1131578641.497611 socket(PF_FILE, SOCK_STREAM, 0) = 3
1131578641.497652 fcntl64(3, F_GETFL) = 0x2 (flags O_RDWR)
1131578641.497688 fcntl64(3, F_SETFL, O_RDWR|O_NONBLOCK) = 0
1131578641.497729 connect(3, {sa_family=AF_FILE,
path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
1131578641.497811 close(3) = 0
1131578641.497856 socket(PF_FILE, SOCK_STREAM, 0) = 3
1131578641.497891 fcntl64(3, F_GETFL) = 0x2 (flags O_RDWR)
1131578641.497926 fcntl64(3, F_SETFL, O_RDWR|O_NONBLOCK) = 0
1131578641.497966 connect(3, {sa_family=AF_FILE,
path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
1131578641.498043 close(3) = 0
1131578641.498091 open("/etc/nsswitch.conf", O_RDONLY) = 3
1131578641.498143 fstat64(3, {st_mode=S_IFREG|0644, st_size=1698, ...}) = 0
1131578641.498220 mmap2(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f4a000
1131578641.498264 read(3, "#\n# /etc/nsswitch.conf\n#\n# An ex"..., 4096) =
1698
1131578641.498345 read(3, "", 4096) = 0
1131578641.498381 close(3) = 0
1131578641.498413 munmap(0xb7f4a000, 4096) = 0
1131578641.498466 open("/etc/ld.so.cache", O_RDONLY) = 3
1131578641.498509 fstat64(3, {st_mode=S_IFREG|0644, st_size=57813, ...}) = 0
1131578641.498580 old_mmap(NULL, 57813, PROT_READ, MAP_PRIVATE, 3, 0) =
0xb7f3c000
1131578641.498639 close(3) = 0
1131578641.498686 open("/lib/libnss_files.so.2", O_RDONLY) = 3
1131578641.498733 read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0
\33\0\000"..., 512) = 512
1131578641.498789 fstat64(3, {st_mode=S_IFREG|0755, st_size=46552, ...}) = 0
1131578641.498861 old_mmap(NULL, 41616, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb7dd4000
1131578641.498922 old_mmap(0xb7ddd000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x8000) = 0xb7ddd000
1131578641.498994 close(3) = 0
1131578641.499041 mprotect(0xb7ddd000, 4096, PROT_READ) = 0
1131578641.499080 munmap(0xb7f3c000, 57813) = 0
1131578641.499126 open("/etc/passwd", O_RDONLY) = 3
1131578641.499173 fcntl64(3, F_GETFD) = 0
1131578641.499207 fcntl64(3, F_SETFD, FD_CLOEXEC) = 0
1131578641.499242 fstat64(3, {st_mode=S_IFREG|0644, st_size=2064, ...}) = 0
1131578641.499316 mmap2(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f4a000
1131578641.499354 read(3, "root:x:0:0:root:/root:/bin/bash\n"..., 4096) =
2064
1131578641.499424 close(3) = 0
1131578641.499458 munmap(0xb7f4a000, 4096) = 0
1131578641.499515 open("/etc/services", O_RDONLY) = 3
1131578641.499559 fcntl64(3, F_GETFD) = 0
1131578641.499593 fcntl64(3, F_SETFD, FD_CLOEXEC) = 0
1131578641.499627 fstat64(3, {st_mode=S_IFREG|0644, st_size=20385, ...}) = 0
1131578641.499699 mmap2(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f4a000
1131578641.499736 read(3, "# /etc/services:\n# $Id: services"..., 4096) =
4096
1131578641.499843 read(3, "otocol\nntp\t\t123/tcp\nntp\t\t123/udp"..., 4096)
= 4096
1131578641.499943 read(3, "67/udp\nrsync\t\t873/tcp\t\t\t\t# rsync"...,
4096) = 4096
1131578641.499998 close(3) = 0
1131578641.500030 munmap(0xb7f4a000, 4096) = 0
1131578641.500072 getpid() = 16041
1131578641.500136 gettimeofday({1131578641, 500148}, NULL) = 0
1131578641.500177 open("/etc/resolv.conf", O_RDONLY) = 3
1131578641.500221 fstat64(3, {st_mode=S_IFREG|0644, st_size=68, ...}) = 0
1131578641.500292 mmap2(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f4a000
1131578641.500329 read(3, "search accentopto.com\nnameserver"..., 4096) = 68
1131578641.500384 read(3, "", 4096) = 0
1131578641.500418 close(3) = 0
1131578641.500452 munmap(0xb7f4a000, 4096) = 0
1131578641.500497 socket(PF_FILE, SOCK_STREAM, 0) = 3
1131578641.500537 fcntl64(3, F_GETFL) = 0x2 (flags O_RDWR)
1131578641.500573 fcntl64(3, F_SETFL, O_RDWR|O_NONBLOCK) = 0
1131578641.500613 connect(3, {sa_family=AF_FILE,
path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
1131578641.500692 close(3) = 0
1131578641.500731 socket(PF_FILE, SOCK_STREAM, 0) = 3
1131578641.500768 fcntl64(3, F_GETFL) = 0x2 (flags O_RDWR)
1131578641.500803 fcntl64(3, F_SETFL, O_RDWR|O_NONBLOCK) = 0
1131578641.500843 connect(3, {sa_family=AF_FILE,
path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
1131578641.500925 close(3) = 0
1131578641.500965 open("/etc/host.conf", O_RDONLY) = 3
1131578641.501010 fstat64(3, {st_mode=S_IFREG|0644, st_size=17, ...}) = 0
1131578641.501079 mmap2(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f4a000
1131578641.501118 read(3, "order hosts,bind\n", 4096) = 17
1131578641.501169 read(3, "", 4096) = 0
1131578641.501203 close(3) = 0
1131578641.501236 munmap(0xb7f4a000, 4096) = 0
1131578641.501273 open("/etc/hosts", O_RDONLY) = 3
1131578641.501314 fcntl64(3, F_GETFD) = 0
1131578641.501348 fcntl64(3, F_SETFD, FD_CLOEXEC) = 0
1131578641.501388 fstat64(3, {st_mode=S_IFREG|0644, st_size=1683, ...}) = 0
1131578641.501459 mmap2(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f4a000
1131578641.501496 read(3, "# Do not remove the following li"..., 4096) =
1683
1131578641.501556 close(3) = 0
1131578641.501590 munmap(0xb7f4a000, 4096) = 0
1131578641.501633 open("/etc/hosts", O_RDONLY) = 3
1131578641.501675 fcntl64(3, F_GETFD) = 0
1131578641.501708 fcntl64(3, F_SETFD, FD_CLOEXEC) = 0
1131578641.501741 fstat64(3, {st_mode=S_IFREG|0644, st_size=1683, ...}) = 0
1131578641.501814 mmap2(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f4a000
1131578641.501851 read(3, "# Do not remove the following li"..., 4096) =
1683
1131578641.501904 close(3) = 0
1131578641.501938 munmap(0xb7f4a000, 4096) = 0
1131578641.501978 rt_sigprocmask(SIG_BLOCK, [URG], [], 8) = 0
1131578641.502031 socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 3
1131578641.502075 bind(3, {sa_family=AF_INET, sin_port=htons(1023),
sin_addr=inet_addr("0.0.0.0")}, 16) = 0
1131578641.502126 fcntl64(3, F_SETOWN, 16041) = 0
1131578641.502164 connect(3, {sa_family=AF_INET, sin_port=htons(514),
sin_addr=inet_addr("192.168.101.1")}, 16) = 0
1131578641.502454 socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 4
1131578641.502529 bind(4, {sa_family=AF_INET, sin_port=htons(1022),
sin_addr=inet_addr("0.0.0.0")}, 16) = 0
1131578641.502597 listen(4, 1) = 0
1131578641.502660 write(3, "1022\0", 5) = 5
1131578641.502725 poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN,
revents=POLLIN}], 2, -1) = 1
1131578641.505699 accept(4, {sa_family=AF_INET, sin_port=htons(1022),
sin_addr=inet_addr("192.168.101.1")}, [16]) = 5
1131578641.505813 close(4) = 0
1131578641.505870 writev(3, [{"root\0", 5}, {"root\0", 5},
{"uname -a\0",
9}], 3) = 19
1131578641.505963 read(3, "\0", 1) = 1
1131578642.493984 rt_sigprocmask(SIG_SETMASK, [], [URG], 8) = 0
1131578642.494064 setuid32(0) = 0
1131578642.494113 rt_sigprocmask(SIG_BLOCK, [INT QUIT TERM], [], 8) = 0
1131578642.494174 rt_sigaction(SIGINT, {SIG_IGN}, {SIG_DFL}, 8) = 0
1131578642.494239 rt_sigaction(SIGINT, {0x80000cf4, [INT], SA_RESTART},
{SIG_IGN}, 8) = 0
1131578642.494305 rt_sigaction(SIGQUIT, {SIG_IGN}, {SIG_DFL}, 8) = 0
1131578642.494365 rt_sigaction(SIGQUIT, {0x80000cf4, [QUIT], SA_RESTART},
{SIG_IGN}, 8) = 0
1131578642.494431 rt_sigaction(SIGTERM, {SIG_IGN}, {SIG_DFL}, 8) = 0
1131578642.494491 rt_sigaction(SIGTERM, {0x80000cf4, [TERM], SA_RESTART},
{SIG_IGN}, 8) = 0
1131578642.494561 clone(Process 16042 attached
child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0xb7ddfa28) = 16042
[pid 16041] 1131578642.494784 ioctl(5, FIONBIO, [1]) = 0
[pid 16041] 1131578642.494844 ioctl(3, FIONBIO, [1]) = 0
[pid 16041] 1131578642.494903 rt_sigprocmask(SIG_SETMASK, [], [INT QUIT
TERM], 8) = 0
[pid 16041] 1131578642.494965 select(6, [3 5], NULL, NULL, NULL <unfinished
...>
[pid 16042] 1131578642.495036 ioctl(5, FIONBIO, [1]) = 0
[pid 16042] 1131578642.495085 ioctl(3, FIONBIO, [1]) = 0
[pid 16042] 1131578642.495138 close(5) = 0
[pid 16042] 1131578642.495190 read(0, <unfinished ...>
[pid 16041] 1131578642.507190 <... select resumed> ) = 1 (in [3])
[pid 16041] 1131578642.507233 read(3, "Linux xxx.xxx.com 2.6.1"..., 8192) =
101
[pid 16041] 1131578642.507315 write(1, "Linux xxx.xxx.com 2.6.1"...,
101Linux xxx.xxx.com 2.6.13web100 #1 SMP Fri Oct 28 09:58:58 PDT 2005 i686
i686 i386 GNU/Linux
) = 101
[pid 16041] 1131578642.507385 select(6, [3 5], NULL, NULL, NULL) = 2 (in [3
5])
[pid 16041] 1131578642.507441 read(5, "", 8192) = 0
[pid 16041] 1131578642.507497 read(3, "", 8192) = 0
[pid 16041] 1131578642.507554 kill(16042, SIGKILL) = 0
[pid 16041] 1131578642.507645 exit_group(0) = ?
1131578642.507739 <... read resumed> 0xbf849480, 8192) = ? ERESTARTSYS (To
be restarted)
1131578642.507834 +++ killed by SIGKILL +++
====================== END CLIENT STRACE ================
----- Original Message -----
From: "Les Mikesell" <lesmikesell(a)gmail.com>
If it is practical, strace xinetd through accepting a connection
(with -f to see if your rsh is doing any checks of its own
after the connection is up).
--
Les Mikesell
lesmikesell(a)gmail.com
3:26 a.m.
Tim Prendergast wrote:
I have somewhat of a complex issue, hoping someone here may have
some
insight.
I have a beowulf cluster of systems for a scientific application we run.
This cluster consists of 32 diskless slaves running fc4 w/ a monolithic
kernel, and a master node running FC4 with a custom kernel. The master
issues rsh commands to the slaves to grab a chunk of a job and process it,
then return it.
My issue is this -- we have an old RH9 cluster that is similar in design,
and the rsh commands (measured using `time rsh node2 uname -a`) takes
around 0.050s to complete. On the FC4 system, we are running around
0.650-1.35s to complete the same command. I've traced the delay to
xinetd or
in.rshd, but am at a loss going any further. I've run some straces and I
can
see the delay occur. I've pasted the straces below for reference.
Does anyone have any idea why this delay is happening? These systems are
all
wired up over gig-e (0.1-0.2ms pings round trip) and running dual 3.4ghz
Xeons w/ 2mb cache and 1gb mem in each slave, 4gb mem in the master. There
is a lot of processing power here, so I can't see a reason for the delay.
The PAM, rhosts, hosts.equiv, etc are all identical among the nodes (and
the
clusters).
[snip]
========================
Here you can clearly see the delay happen:
<cut and paste section of interest from above>
16:18:55.297196 writev(3, [{"root\0", 5}, {"root\0", 5}, {"uname
-a\0",
9}],
3) = 19 <0.000038>
16:18:55.297332 read(3, "\0", 1) = 1 <0.632181>
16:18:55.929633 rt_sigprocmask(SIG_SETMASK, [], [URG], 8) = 0 <0.000039>
16:18:55.929763 setuid32(0) = 0 <0.000039>
<end cut and paste>
It looks like it takes .63s to write the data to the socket and get the
response, which I find hard to fathom (especially since anything outside of
xinetd's realm appears to be really fast over the network).
Thoughts?
-Tim
Can you strace the server-side, and also capture the packets on both interfaces
to see what times they are sent/received.
The delay comes when the client sends the login information with the username.
It could be a delay in mapping a username to a userid. What authentication
mechanism is running on both systems? Is nscd running to cache the user
information on both systems, or does it require a network lookup from NIS, LDAP etc?
--
Nigel Wade, System Administrator, Space Plasma Physics Group,
University of Leicester, Leicester, LE1 7RH, UK
E-mail : nmw(a)ion.le.ac.uk
Phone : +44 (0)116 2523548, Fax : +44 (0)116 2523555
5:17 p.m.
The master and slaves all share the same original passwd file, and no new
users have been added. We have several application users that are the same
name and UID across all slaves and the master.
----- Original Message -----
From: "Nigel Wade" <nmw(a)ion.le.ac.uk>
Can you strace the server-side, and also capture the packets on both
interfaces to see what times they are sent/received.
The delay comes when the client sends the login information with the
username. It could be a delay in mapping a username to a userid. What
authentication mechanism is running on both systems? Is nscd running to
cache the user information on both systems, or does it require a network
lookup from NIS, LDAP etc?
--
Nigel Wade, System Administrator, Space Plasma Physics Group,
6743
days inactive
6745
days old
11 comments
4 participants
participants (4)
-
Andy Green -
Les Mikesell -
Nigel Wade -
Tim Prendergast