Re: Large slowdowns / networking related

[Joshua Eichorn <jeichorn joshuaeichorn com>]

I saw the original problem on a redhat 8 machine but i reproduced things 
on redhat 9 with a bunch of updated gnome packages.

To reproduce i just added 192.168.1.1 (ip doesn't exist) as the first 
name server in my resolv.conf.  After that starting any gnome app took 
around 3 seconds longer, the same problem was not see when running xterm.

The area around the slowdown when running an strace on gedit is pasted 
below.


uname({sys="Linux", node="rasch.cisco.com", ...}) = 0
gettimeofday({1054571034, 706915}, NULL) = 0
getpid()                                = 17174
open("/etc/resolv.conf", O_RDONLY)      = 8
fstat64(8, {st_mode=S_IFREG|0644, st_size=129, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 
0) = 0x4001f000
read(8, "; generated by /sbin/dhclient-sc"..., 4096) = 129
read(8, "", 4096)                       = 0
close(8)                                = 0
munmap(0x4001f000, 4096)                = 0
socket(PF_UNIX, SOCK_STREAM, 0)         = 8
connect(8, {sa_family=AF_UNIX, path="/var/run/.nscd_socket"}, 110) = -1 
ENOENT (No such file or directory)
close(8)                                = 0
open("/etc/host.conf", O_RDONLY)        = 8
fstat64(8, {st_mode=S_IFREG|0644, st_size=17, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 
0) = 0x4001f000
read(8, "order hosts,bind\n", 4096)     = 17
read(8, "", 4096)                       = 0
close(8)                                = 0
munmap(0x4001f000, 4096)                = 0
futex(0x42133480, FUTEX_WAKE, 2147483647, NULL) = 0
open("/etc/hosts", O_RDONLY)            = 8
fcntl64(8, F_GETFD)                     = 0
fcntl64(8, F_SETFD, FD_CLOEXEC)         = 0
fstat64(8, {st_mode=S_IFREG|0644, st_size=146, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 
0) = 0x4001f000
read(8, "# Do not remove the following li"..., 4096) = 146
read(8, "", 4096)                       = 0
close(8)                                = 0
munmap(0x4001f000, 4096)                = 0
open("/etc/ld.so.cache", O_RDONLY)      = 8
fstat64(8, {st_mode=S_IFREG|0644, st_size=63069, ...}) = 0
old_mmap(NULL, 63069, PROT_READ, MAP_PRIVATE, 8, 0) = 0x4131d000
close(8)                                = 0
open("/lib/libnss_dns.so.2", O_RDONLY)  = 8
read(8, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\220\16"..., 
512) = 512
fstat64(8, {st_mode=S_IFREG|0755, st_size=18436, ...}) = 0
old_mmap(NULL, 12700, PROT_READ|PROT_EXEC, MAP_PRIVATE, 8, 0) = 0x4001f000
old_mmap(0x40022000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 
8, 0x3000) = 0x40022000
close(8)                                = 0
munmap(0x4131d000, 63069)               = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 8
connect(8, {sa_family=AF_INET, sin_port=htons(53), 
sin_addr=inet_addr("192.168.1.1")}, 28) = 0
send(8, "\360p\1\0\0\1\0\0\0\0\0\0\5rasch\5cisco\3com\0\0\1\0"..., 33, 
0) = 33
gettimeofday({1054571034, 755483}, NULL) = 0
poll([{fd=8, events=POLLIN}], 1, 5000)  = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 9
connect(9, {sa_family=AF_INET, sin_port=htons(53), 
sin_addr=inet_addr("144.254.71.184")}, 28) = 0
send(9, "\17\357\1\0\0\1\0\0\0\0\0\0\5rasch\5cisco\3com\0\0\1\0"..., 33, 
0) = 33
gettimeofday({1054571196, 665995}, NULL) = 0
poll([{fd=9, events=POLLIN, revents=POLLIN}], 1, 3000) = 1
ioctl(9, FIONREAD, [117])               = 0
recvfrom(9, "\17\357\205\200\0\1\0\1\0\2\0\2\5rasch\5cisco\3com\0\0"..., 
1024, 0, {sa_family=AF_INET, sin_port=htons(53), 
sin_addr=inet_addr("144.254.71.184")}, [16]) = 117
close(8)                                = 0
close(9)                                = 0
socket(PF_UNIX, SOCK_STREAM, 0)         = 8
connect(8, {sa_family=AF_UNIX, path="/var/run/.nscd_socket"}, 110) = -1 
ENOENT (No such file or directory)
close(8)                                = 0
open("/etc/hosts", O_RDONLY)            = 8
fcntl64(8, F_GETFD)                     = 0
fcntl64(8, F_SETFD, FD_CLOEXEC)         = 0
fstat64(8, {st_mode=S_IFREG|0644, st_size=146, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 
0) = 0x40023000
read(8, "# Do not remove the following li"..., 4096) = 146
read(8, "", 4096)                       = 0
close(8)                                = 0
munmap(0x40023000, 4096)                = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 8
connect(8, {sa_family=AF_INET, sin_port=htons(53), 
sin_addr=inet_addr("192.168.1.1")}, 28) = 0
send(8, "\17\360\1\0\0\1\0\0\0\0\0\0\00230\003115\003101\00264\7"..., 
44, 0) = 44
gettimeofday({1054571196, 834913}, NULL) = 0
poll([{fd=8, events=POLLIN}], 1, 5000)  = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 9
connect(9, {sa_family=AF_INET, sin_port=htons(53), 
sin_addr=inet_addr("144.254.71.184")}, 28) = 0
send(9, "\17\360\1\0\0\1\0\0\0\0\0\0\00230\003115\003101\00264\7"..., 
44, 0) = 44
gettimeofday({1054571201, 835973}, NULL) = 0
poll([{fd=9, events=POLLIN, revents=POLLIN}], 1, 3000) = 1
ioctl(9, FIONREAD, [141])               = 0
recvfrom(9, 
"\17\360\205\200\0\1\0\1\0\2\0\2\00230\003115\003101\002"..., 1024, 0, 
{sa_family=AF_INET, sin_port=htons(53), 
sin_addr=inet_addr("144.254.71.184")}, [16]) = 141
close(8)                                = 0
close(9)  


Michael Meeks wrote:

> Hi Joshua,
>
> On Thu, 2003-05-29 at 21:53, Joshua Eichorn wrote:
>  
>
> > I actually just ran into this on a co-workers redhat 8 machine.  He 
> > added a bogus nameserver to the top of his resolv.conf and every app 
> > took 3 or 4 seconds to start.  Might be hard to detect but if looking up 
> > your own hostname takes a long time things do slow down.
> >    
>
> 	OTOH, it should be possible to detect this relatively easily with a
> simple test program; we can simply time a couple of lookups of your own
> hostname, and throw up a warning at login time if it's a real problem.
>
> 	Having said that, I'm keen to know where we're doing that lookup, since
> there should be no real need to do so; can you get an strace /
> stack-trace of the offending lookup ?
>
> 	Thanks,
>
> 		Michael.
>
>