Slow network connection in -current

Kai Grossjohann kai.grossjohann at gmx.net
Sun Sep 28 13:02:52 PDT 2003


I've noticed a certain slowness in doing network connections with
-current.  Can't explain this.  While /usr/src/UPDATING does speak of
slowness that I need to expect, this smells of another problem.

I type "host mail.gmx.net" and it immediately comes back with an
answer.

I type "telnet mail.gmx.net pop3" and it takes many seconds before a
connection is established.  Once the connection is established,
I see the greeting from the remote server quickly enough.  I can't
explain why it takes such a long time to establish the connection.

I tried to investigate using "truss -f telnet mail.gmx.net pop3", but
that produces an error message:

kai at slowfox$ truss -f -d -o truss.out telnet mail.gmx.net pop3 
truss: get_struct 0x0: Bad address
kai at slowfox$ 

As you can see, I get a new prompt.  However, after some seconds
(sufficient for me to write this paragraph), I get more output which
shows the greeting from the remote server.  Hm.  Indeed, a telnet
process is running, says ps.  Hmmm...  Ah!  Here is the additional
output:

kai at slowfox$ truss -f -d -o truss.out telnet mail.gmx.net pop3 
truss: get_struct 0x0: Bad address
kai at slowfox$ psg telnet
kai       977  0.0  0.4  3500 2208  p0  S    10:00PM   0:00.04 telnet mail.gmx.net pop3
kai at slowfox$ Trying 213.165.64.20...
Connected to mail.gmx.net.
Escape character is '^]'.
psg telnet+OK GMX POP3 StreamProxy ready <25890.1064779259 at mp002>

Looks weird, doesn't it?  The "psg telnet" in the last line comes
from me hitting Ctrl-P in bash at just the time the output arrived.

In case you're interested in truss.out, I'm appending it to this
message.

Any ideas what might be wrong?

tia,
Kai

-------------- next part --------------
  977: 0.002124013 mmap(0x0,3480,0x3,0x1000,-1,0x0) = 671633408 (0x28085000)
  977: 0.003305728 munmap(0x28085000,0xd98)	 = 0 (0x0)
  977: 0.004165334 __sysctl(0xbfbff5ac,0x2,0x28082e2c,0xbfbff5a8,0x0,0x0) = 0 (0x0)
  977: 0.005117410 mmap(0x0,32768,0x3,0x1002,-1,0x0) = 671633408 (0x28085000)
  977: 0.005854934 issetugid()			 = 0 (0x0)
  977: 0.007448433 open("/etc/libmap.conf",0x0,0666) ERR#2 'No such file or directory'
  977: 0.008945830 open("/var/run/ld-elf.so.hints",0x0,00) = 4 (0x4)
  977: 0.009809347 read(0x4,0xbfbff644,0x80)	 = 128 (0x80)
  977: 0.010828471 lseek(4,0x80,0)		 = 128 (0x80)
  977: 0.011622986 read(0x4,0x28089000,0x56)	 = 86 (0x56)
  977: 0.012491253 close(4)			 = 0 (0x0)
  977: 0.013809576 access("/lib/libncurses.so.5",0) = 0 (0x0)
  977: 0.015083761 open("/lib/libncurses.so.5",0x0,027757773234) = 4 (0x4)
  977: 0.015894479 fstat(4,0xbfbff684)		 = 0 (0x0)
  977: 0.016713577 read(0x4,0x28081d80,0x1000)	 = 4096 (0x1000)
  977: 0.018038326 mmap(0x0,262144,0x5,0x20002,4,0x0) = 671666176 (0x2808d000)
  977: 0.018868041 mprotect(0x280c3000,0x1000,0x7) = 0 (0x0)
  977: 0.019754187 mprotect(0x280c3000,0x1000,0x5) = 0 (0x0)
  977: 0.020808790 mmap(0x280c4000,32768,0x3,0x12,4,0x37000) = 671891456 (0x280c4000)
  977: 0.021858924 mmap(0x280cc000,4096,0x3,0x1012,-1,0x0) = 671924224 (0x280cc000)
  977: 0.022688917 close(4)			 = 0 (0x0)
  977: 0.023943825 access("/lib/libipsec.so.1",0) = 0 (0x0)
  977: 0.025212702 open("/lib/libipsec.so.1",0x0,027757773234) = 4 (0x4)
  977: 0.026015038 fstat(4,0xbfbff684)		 = 0 (0x0)
  977: 0.026833578 read(0x4,0x28081d80,0x1000)	 = 4096 (0x1000)
  977: 0.027847115 mmap(0x0,28672,0x5,0x20002,4,0x0) = 671928320 (0x280cd000)
  977: 0.028638277 mprotect(0x280d2000,0x1000,0x7) = 0 (0x0)
  977: 0.029568004 mprotect(0x280d2000,0x1000,0x5) = 0 (0x0)
  977: 0.030571204 mmap(0x280d3000,4096,0x3,0x12,4,0x5000) = 671952896 (0x280d3000)
  977: 0.031491153 close(4)			 = 0 (0x0)
  977: 0.032812550 access("/lib/libmp.so.4",0)	 ERR#2 'No such file or directory'
  977: 0.034070811 access("/usr/lib/libmp.so.4",0) = 0 (0x0)
  977: 0.035338011 open("/usr/lib/libmp.so.4",0x0,027757773234) = 4 (0x4)
  977: 0.036142303 fstat(4,0xbfbff684)		 = 0 (0x0)
  977: 0.036962240 read(0x4,0x28081d80,0x1000)	 = 4096 (0x1000)
  977: 0.037973821 mmap(0x0,16384,0x5,0x20002,4,0x0) = 671956992 (0x280d4000)
  977: 0.038798227 mprotect(0x280d6000,0x1000,0x7) = 0 (0x0)
  977: 0.039680183 mprotect(0x280d6000,0x1000,0x5) = 0 (0x0)
  977: 0.040688412 mmap(0x280d7000,4096,0x3,0x12,4,0x2000) = 671969280 (0x280d7000)
  977: 0.041609758 close(4)			 = 0 (0x0)
  977: 0.042859079 access("/lib/libcrypto.so.3",0) = 0 (0x0)
  977: 0.044106444 open("/lib/libcrypto.so.3",0x0,027757773234) = 4 (0x4)
  977: 0.044904590 fstat(4,0xbfbff684)		 = 0 (0x0)
  977: 0.045713911 read(0x4,0x28081d80,0x1000)	 = 4096 (0x1000)
  977: 0.046692247 mmap(0x0,1110016,0x5,0x20002,4,0x0) = 671973376 (0x280d8000)
  977: 0.047481174 mprotect(0x281d0000,0x1000,0x7) = 0 (0x0)
  977: 0.048350559 mprotect(0x281d0000,0x1000,0x5) = 0 (0x0)
  977: 0.049602114 mmap(0x281d1000,81920,0x3,0x12,4,0xf8000) = 672993280 (0x281d1000)
  977: 0.050668172 mmap(0x281e5000,8192,0x3,0x1012,-1,0x0) = 673075200 (0x281e5000)
  977: 0.051495931 close(4)			 = 0 (0x0)
  977: 0.052829620 access("/lib/libcrypt.so.2",0) = 0 (0x0)
  977: 0.054076426 open("/lib/libcrypt.so.2",0x0,027757773234) = 4 (0x4)
  977: 0.054877645 fstat(4,0xbfbff684)		 = 0 (0x0)
  977: 0.055693671 read(0x4,0x28081d80,0x1000)	 = 4096 (0x1000)
  977: 0.056741010 mmap(0x0,102400,0x5,0x20002,4,0x0) = 673083392 (0x281e7000)
  977: 0.057535804 mprotect(0x281ed000,0x1000,0x7) = 0 (0x0)
  977: 0.058413290 mprotect(0x281ed000,0x1000,0x5) = 0 (0x0)
  977: 0.059486052 mmap(0x281ee000,4096,0x3,0x12,4,0x7000) = 673112064 (0x281ee000)
  977: 0.060539817 mmap(0x281ef000,69632,0x3,0x1012,-1,0x0) = 673116160 (0x281ef000)
  977: 0.061364783 close(4)			 = 0 (0x0)
  977: 0.062613545 access("/lib/libpam.so.2",0)	 ERR#2 'No such file or directory'
  977: 0.063873761 access("/usr/lib/libpam.so.2",0) = 0 (0x0)
  977: 0.065182586 open("/usr/lib/libpam.so.2",0x0,027757773234) = 4 (0x4)
  977: 0.065989113 fstat(4,0xbfbff684)		 = 0 (0x0)
  977: 0.066808212 read(0x4,0x28081d80,0x1000)	 = 4096 (0x1000)
  977: 0.067834040 mmap(0x0,28672,0x5,0x20002,4,0x0) = 673185792 (0x28200000)
  977: 0.068629952 mprotect(0x28205000,0x1000,0x7) = 0 (0x0)
  977: 0.069540123 mprotect(0x28205000,0x1000,0x5) = 0 (0x0)
  977: 0.070532708 mmap(0x28206000,4096,0x3,0x12,4,0x6000) = 673210368 (0x28206000)
  977: 0.071450143 close(4)			 = 0 (0x0)
  977: 0.072716784 access("/lib/libkrb5.so.6",0) ERR#2 'No such file or directory'
  977: 0.073968060 access("/usr/lib/libkrb5.so.6",0) = 0 (0x0)
  977: 0.075229673 open("/usr/lib/libkrb5.so.6",0x0,027757773234) = 4 (0x4)
  977: 0.076036200 fstat(4,0xbfbff684)		 = 0 (0x0)
  977: 0.076854740 read(0x4,0x28081d80,0x1000)	 = 4096 (0x1000)
  977: 0.078136188 mmap(0x0,245760,0x5,0x20002,4,0x0) = 673214464 (0x28207000)
  977: 0.078980429 mprotect(0x2823f000,0x1000,0x7) = 0 (0x0)
  977: 0.079878309 mprotect(0x2823f000,0x1000,0x5) = 0 (0x0)
  977: 0.080884861 mmap(0x28240000,8192,0x3,0x12,4,0x39000) = 673447936 (0x28240000)
  977: 0.081959300 mmap(0x28242000,4096,0x3,0x1012,-1,0x0) = 673456128 (0x28242000)
  977: 0.082792087 close(4)			 = 0 (0x0)
  977: 0.084043643 access("/lib/libasn1.so.6",0) ERR#2 'No such file or directory'
  977: 0.085300227 access("/usr/lib/libasn1.so.6",0) = 0 (0x0)
  977: 0.086564354 open("/usr/lib/libasn1.so.6",0x0,027757773234) = 4 (0x4)
  977: 0.087363618 fstat(4,0xbfbff684)		 = 0 (0x0)
  977: 0.088203110 read(0x4,0x28081d80,0x1000)	 = 4096 (0x1000)
  977: 0.089442373 mmap(0x0,155648,0x5,0x20002,4,0x0) = 673460224 (0x28243000)
  977: 0.090241358 mprotect(0x28267000,0x1000,0x7) = 0 (0x0)
  977: 0.091114653 mprotect(0x28267000,0x1000,0x5) = 0 (0x0)
  977: 0.092104444 mmap(0x28268000,4096,0x3,0x12,4,0x24000) = 673611776 (0x28268000)
  977: 0.093022996 close(4)			 = 0 (0x0)
  977: 0.094268685 access("/lib/libcom_err.so.2",0) ERR#2 'No such file or directory'
  977: 0.095544825 access("/usr/lib/libcom_err.so.2",0) = 0 (0x0)
  977: 0.096805600 open("/usr/lib/libcom_err.so.2",0x0,027757773234) = 4 (0x4)
  977: 0.097662133 fstat(4,0xbfbff684)		 = 0 (0x0)
  977: 0.098803340 read(0x4,0x28081d80,0x1000)	 = 4096 (0x1000)
  977: 0.099820787 mmap(0x0,8192,0x5,0x20002,4,0x0) = 673615872 (0x28269000)
  977: 0.100608038 mprotect(0x28269000,0x1000,0x7) = 0 (0x0)
  977: 0.101481054 mprotect(0x28269000,0x1000,0x5) = 0 (0x0)
  977: 0.102480343 mmap(0x2826a000,4096,0x3,0x12,4,0x1000) = 673619968 (0x2826a000)
  977: 0.103419010 close(4)			 = 0 (0x0)
  977: 0.104667493 access("/lib/libroken.so.6",0) ERR#2 'No such file or directory'
  977: 0.105929106 access("/usr/lib/libroken.so.6",0) = 0 (0x0)
  977: 0.107194350 open("/usr/lib/libroken.so.6",0x0,027757773234) = 4 (0x4)
  977: 0.107998922 fstat(4,0xbfbff684)		 = 0 (0x0)
  977: 0.108902947 read(0x4,0x28081d80,0x1000)	 = 4096 (0x1000)
  977: 0.109988560 mmap(0x0,57344,0x5,0x20002,4,0x0) = 673624064 (0x2826b000)
  977: 0.110785589 mprotect(0x28277000,0x1000,0x7) = 0 (0x0)
  977: 0.111681513 mprotect(0x28277000,0x1000,0x5) = 0 (0x0)
  977: 0.112686948 mmap(0x28278000,4096,0x3,0x12,4,0xd000) = 673677312 (0x28278000)
  977: 0.113616116 close(4)			 = 0 (0x0)
  977: 0.114876612 access("/lib/libc.so.5",0)	 = 0 (0x0)
  977: 0.116157780 open("/lib/libc.so.5",0x0,027757773234) = 4 (0x4)
  977: 0.116964307 fstat(4,0xbfbff684)		 = 0 (0x0)
  977: 0.117779495 read(0x4,0x28081d80,0x1000)	 = 4096 (0x1000)
  977: 0.118971266 mmap(0x0,892928,0x5,0x20002,4,0x0) = 673681408 (0x28279000)
  977: 0.119799304 mprotect(0x2833b000,0x1000,0x7) = 0 (0x0)
  977: 0.120676790 mprotect(0x2833b000,0x1000,0x5) = 0 (0x0)
  977: 0.121696752 mmap(0x2833c000,20480,0x3,0x12,4,0xc2000) = 674480128 (0x2833c000)
  977: 0.122753590 mmap(0x28341000,73728,0x3,0x1012,-1,0x0) = 674500608 (0x28341000)
  977: 0.123587495 close(4)			 = 0 (0x0)
  977: 0.124639584 mmap(0x0,1384,0x3,0x1000,-1,0x0) = 674574336 (0x28353000)
  977: 0.125441641 munmap(0x28353000,0x568)	 = 0 (0x0)
  977: 0.126395115 mmap(0x0,4616,0x3,0x1000,-1,0x0) = 674574336 (0x28353000)
  977: 0.128270213 munmap(0x28353000,0x1208)	 = 0 (0x0)
  977: 0.129309452 mmap(0x0,776,0x3,0x1000,-1,0x0) = 674574336 (0x28353000)
  977: 0.130264042 munmap(0x28353000,0x308)	 = 0 (0x0)
  977: 0.131217236 mmap(0x0,688,0x3,0x1000,-1,0x0) = 674574336 (0x28353000)
  977: 0.132165122 munmap(0x28353000,0x2b0)	 = 0 (0x0)
  977: 0.133118036 mmap(0x0,22008,0x3,0x1000,-1,0x0) = 674574336 (0x28353000)
  977: 0.136117859 munmap(0x28353000,0x55f8)	 = 0 (0x0)
  977: 0.137096754 mmap(0x0,600,0x3,0x1000,-1,0x0) = 674574336 (0x28353000)
  977: 0.138027040 munmap(0x28353000,0x258)	 = 0 (0x0)
  977: 0.139009288 mmap(0x0,1048,0x3,0x1000,-1,0x0) = 674574336 (0x28353000)
  977: 0.139953821 munmap(0x28353000,0x418)	 = 0 (0x0)
  977: 0.140905059 mmap(0x0,6192,0x3,0x1000,-1,0x0) = 674574336 (0x28353000)
  977: 0.142088729 munmap(0x28353000,0x1830)	 = 0 (0x0)
  977: 0.143074609 mmap(0x0,2840,0x3,0x1000,-1,0x0) = 674574336 (0x28353000)
  977: 0.143990368 munmap(0x28353000,0xb18)	 = 0 (0x0)
  977: 0.144941327 mmap(0x0,408,0x3,0x1000,-1,0x0) = 674574336 (0x28353000)
  977: 0.145859041 munmap(0x28353000,0x198)	 = 0 (0x0)
  977: 0.146814470 mmap(0x0,2048,0x3,0x1000,-1,0x0) = 674574336 (0x28353000)
  977: 0.147764590 munmap(0x28353000,0x800)	 = 0 (0x0)
  977: 0.148593187 mprotect(0x28279000,0xc3000,0x7) = 0 (0x0)
  977: 0.149572362 mmap(0x0,21264,0x3,0x1000,-1,0x0) = 674574336 (0x28353000)
  977: 0.152214597 munmap(0x28353000,0x5310)	 = 0 (0x0)
  977: 0.153014699 mprotect(0x28279000,0xc3000,0x5) = 0 (0x0)
  977: 0.154138585 sigaction(SIGILL,0xbfbff6c4,0xbfbff6a4) = 0 (0x0)
  977: 0.154912426 sigprocmask(0x1,0x0,0x28081cdc) = 0 (0x0)
  977: 0.155706941 sigaction(SIGILL,0xbfbff6a4,0x0) = 0 (0x0)
  977: 0.156842281 sigprocmask(0x1,0x28081c80,0xbfbff6d4) = 0 (0x0)
  977: 0.157622827 sigprocmask(0x3,0x28081c90,0x0) = 0 (0x0)
  977: 0.159588719 readlink("/etc/malloc.conf",0xbfbff4d0,63) ERR#2 'No such file or directory'
  977: 0.160280706 issetugid()			 = 0 (0x0)
  977: 0.160878548 getuid()			 = 1001 (0x3e9)
  977: 0.161478624 getgid()			 = 1001 (0x3e9)
  977: 0.162454167 mmap(0x0,4096,0x3,0x1002,-1,0x0) = 674574336 (0x28353000)
  977: 0.163327742 break(0x806a000)		 = 0 (0x0)
  977: 0.164230370 break(0x806b000)		 = 0 (0x0)
  977: 0.165148085 break(0x806c000)		 = 0 (0x0)
  977: 0.166027805 break(0x806d000)		 = 0 (0x0)
  977: 0.166898866 break(0x806e000)		 = 0 (0x0)
  977: 0.167899552 __sysctl(0xbfbff578,0x2,0xbfbff5c0,0xbfbff594,0x0,0x0) = 0 (0x0)
  977: 0.169088530 ioctl(0,TIOCGETA,0x80662e0)	 = 0 (0x0)
  977: 0.170163247 sigprocmask(0x1,0x0,0x8067ebc) = 0 (0x0)
  977: 0.171626562 open("/etc/services",0x0,0666) = 4 (0x4)
  977: 0.172511311 fstat(4,0xbfbff3f0)		 = 0 (0x0)
  977: 0.173299679 break(0x8072000)		 = 0 (0x0)
  977: 0.174348695 read(0x4,0x806e000,0x4000)	 = 16384 (0x4000)
  977: 0.175605000 close(4)			 = 0 (0x0)
  977: 0.176947350 open("/etc/services",0x0,0666) = 4 (0x4)
  977: 0.177767007 fstat(4,0xbfbff3b0)		 = 0 (0x0)
  977: 0.178628848 read(0x4,0x806e000,0x4000)	 = 16384 (0x4000)
  977: 0.179924823 close(4)			 = 0 (0x0)
  977: 0.181281979 open("/etc/services",0x0,0666) = 4 (0x4)
  977: 0.182135998 fstat(4,0xbfbff340)		 = 0 (0x0)
  977: 0.183009573 read(0x4,0x806e000,0x4000)	 = 16384 (0x4000)
  977: 0.184066132 close(4)			 = 0 (0x0)
  977: 0.185409040 open("/etc/services",0x0,0666) = 4 (0x4)
  977: 0.186225903 fstat(4,0xbfbff3b0)		 = 0 (0x0)
  977: 0.187088303 read(0x4,0x806e000,0x4000)	 = 16384 (0x4000)
  977: 0.188141510 close(4)			 = 0 (0x0)
  977: 0.189520735 open("/etc/services",0x0,0666) = 4 (0x4)
  977: 0.190338158 fstat(4,0xbfbff340)		 = 0 (0x0)
  977: 0.191199161 read(0x4,0x806e000,0x4000)	 = 16384 (0x4000)
  977: 0.192244825 close(4)			 = 0 (0x0)
  977: 0.193582984 open("/etc/services",0x0,0666) = 4 (0x4)
  977: 0.194398171 fstat(4,0xbfbff3f0)		 = 0 (0x0)
  977: 0.195261968 read(0x4,0x806e000,0x4000)	 = 16384 (0x4000)
  977: 0.196317130 close(4)			 = 0 (0x0)
  977: 0.197635454 open("/etc/services",0x0,0666) = 4 (0x4)
  977: 0.198474387 fstat(4,0xbfbff3b0)		 = 0 (0x0)
  977: 0.199384559 read(0x4,0x806e000,0x4000)	 = 16384 (0x4000)
  977: 0.200433575 close(4)			 = 0 (0x0)
  977: 0.201747988 open("/etc/services",0x0,0666) = 4 (0x4)
  977: 0.202567086 fstat(4,0xbfbff340)		 = 0 (0x0)
  977: 0.203432280 read(0x4,0x806e000,0x4000)	 = 16384 (0x4000)
  977: 0.204480179 close(4)			 = 0 (0x0)
  977: 0.205817499 open("/etc/services",0x0,0666) = 4 (0x4)
  977: 0.206629055 fstat(4,0xbfbff3b0)		 = 0 (0x0)
  977: 0.207493690 read(0x4,0x806e000,0x4000)	 = 16384 (0x4000)
  977: 0.208546338 close(4)			 = 0 (0x0)
  977: 0.209904890 open("/etc/services",0x0,0666) = 4 (0x4)
  977: 0.210723709 fstat(4,0xbfbff340)		 = 0 (0x0)
  977: 0.211589462 read(0x4,0x806e000,0x4000)	 = 16384 (0x4000)
  977: 0.212658313 close(4)			 = 0 (0x0)
  977: 0.213974681 stat("/etc/nsswitch.conf",0xbfbff470) ERR#2 'No such file or directory'
  977: 0.215382402 open("/etc/hosts",0x0,0666)	 = 4 (0x4)
  977: 0.216247875 fstat(4,0xbfbfd340)		 = 0 (0x0)
  977: 0.217097145 read(0x4,0x806e000,0x4000)	 = 1085 (0x43d)
  977: 0.217907863 read(0x4,0x806e000,0x4000)	 = 0 (0x0)
  977: 0.218817476 close(4)			 = 0 (0x0)
  977: 0.219658085 break(0x8082000)		 = 0 (0x0)
  977: 0.221022504 break(0x8092000)		 = 0 (0x0)
  977: 0.222497552 gettimeofday(0xbfbfef18,0x0)	 = 0 (0x0)
  977: 0.223130594 getpid()			 = 977 (0x3d1)
  977: 0.223739051 issetugid()			 = 0 (0x0)
  977: 0.225008486 open("/etc/resolv.conf",0x0,0666) = 4 (0x4)
  977: 0.225823953 fstat(4,0xbfbfee30)		 = 0 (0x0)
  977: 0.226666518 read(0x4,0x806e000,0x4000)	 = 23 (0x17)
  977: 0.227555737 read(0x4,0x806e000,0x4000)	 = 0 (0x0)
  977: 0.228458086 close(4)			 = 0 (0x0)
  977: 0.229435305 __sysctl(0xbfbfef18,0x2,0xbfbfefd0,0xbfbfef34,0x0,0x0) = 0 (0x0)
  977: 0.230103547 issetugid()			 = 0 (0x0)
  977: 0.230886887 break(0x80a2000)		 = 0 (0x0)
  977: 0.232266112 kqueue()			 = 4 (0x4)
  977: 0.233182988 socket(0x2,0x2,0x0)		 = 5 (0x5)
  977: 0.234911700 connect(0x5,{ AF_INET 192.168.0.1:53 },16) = 0 (0x0)


More information about the freebsd-questions mailing list