[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

sshd hinter NAT-Router läßt mich 10 s warten



Hallo,

ich möchte mich per SSH mit einem Server in einem LAN verbinden.

Ich kann das LAN entweder über VPN erreichen oder den Server auf Port 22 »von 
außen« über einen NAT-Router mit Portforwarding.

Verbinde ich mich über VPN, funktioniert alles normal, verbinde ich mich zur 
externen IP des Netzes, also über Portforwarding, klappt nur das *erste* 
Einloggen nach einer längeren Pause (ca. 1 h); bei jedem weiteren Login 
entsteht eine Pause von exakt 10 Sekunden.

Dies gilt auch bei Verbindungen vom Server zu sich selbst, wenn er über den 
Router geht.


Auf einem Client sieht das so aus:

-------- 8< --------
14:29:12 OpenSSH_3.8.1p1 Debian-8.sarge.4, OpenSSL 0.9.7e 25 Oct 2004
14:29:12 debug1: Reading configuration data /etc/ssh/ssh_config
14:29:12 debug1: Connecting to xxxx [xx.xx.xx.xx] port 22102.
14:29:12 debug1: Connection established.
14:29:12 debug1: identity file /home/xx/.ssh/identity type -1
14:29:12 debug1: identity file /home/xx/.ssh/id_rsa type -1
14:29:12 debug1: identity file /home/xx/.ssh/id_dsa type -1
14:29:12 debug1: Remote protocol version 2.0, remote software version 
OpenSSH_4.1p1 Debian-7ubuntu4.1
14:29:12 debug1: match: OpenSSH_4.1p1 Debian-7ubuntu4.1 pat OpenSSH*
14:29:12 debug1: Enabling compatibility mode for protocol 2.0
14:29:12 debug1: Local version string SSH-2.0-OpenSSH_3.8.1p1 Debian-8.sarge.4
14:29:12 debug1: SSH2_MSG_KEXINIT sent
14:29:12 debug1: SSH2_MSG_KEXINIT received
14:29:12 debug1: kex: server->client aes128-cbc hmac-md5 none
14:29:12 debug1: kex: client->server aes128-cbc hmac-md5 none
14:29:12 debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(1024<1024<8192) sent
14:29:12 debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
14:29:12 debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
14:29:12 debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
14:29:12 debug1: Host 'xxxx' is known and matches the RSA host key.
14:29:12 debug1: Found key in /home/xx/.ssh/known_hosts:1
14:29:12 debug1: ssh_rsa_verify: signature correct
14:29:12 debug1: SSH2_MSG_NEWKEYS sent
14:29:12 debug1: expecting SSH2_MSG_NEWKEYS
14:29:12 debug1: SSH2_MSG_NEWKEYS received
14:29:12 debug1: SSH2_MSG_SERVICE_REQUEST sent
14:29:12 debug1: SSH2_MSG_SERVICE_ACCEPT received
14:29:22 xx@xxxx's password:
14:29:22 debug1: Authentications that can continue: publickey,password
14:29:22 debug1: Next authentication method: publickey
14:29:22 debug1: Trying private key: /home/xx/.ssh/identity
14:29:22 debug1: Trying private key: /home/xx/.ssh/id_rsa
14:29:22 debug1: Trying private key: /home/xx/.ssh/id_dsa
14:29:22 debug1: Next authentication method: password
-------- >8 --------

Ein strace auf dem Client ergibt auch nur genau die Pause (hier zwischen 
14:29:12 und 14:29:22).

Das ganze passiert genauso, wenn ich mich per Public Key authentifiziere.

Auf dem Server gibt es während der Wartezeit zwei Prozesse:

-------- 8< --------
root     19426  0.0  0.8   5096  1832 ?        Ss   12:55   0:00 sshd: root 
[priv]
sshd     19427  0.0  0.7   4912  1712 ?        S    12:55   0:00 sshd: root 
[net]
-------- >8 --------

Ich habe mal versucht, diese zu tracen:

-------- 8< --------
14:29:12 Process 24757 attached - interrupt to quit
14:29:12 gettimeofday({1147955352, 808103}, NULL) = 0
14:29:12 gettimeofday({1147955352, 808143}, NULL) = 0
14:29:17 poll([{fd=4, events=POLLIN}], 1, 4942) = 0
14:29:17 gettimeofday({1147955357, 751242}, NULL) = 0
14:29:17 poll([{fd=4, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
14:29:17 send(4, "yj1001000000003756893678934759002847in-a"..., 44, 0) = 44
14:29:17 poll([{fd=4, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
14:29:17 ioctl(4, FIONREAD, [88]) = 0

***************************
14:29:17 recvfrom(4, "yj2052006568935760031227"..., 1024, 0, 
{sa_family=AF_INET, \
    sin_port=htons(53), sin_addr=inet_addr("192.168.0.10")}, [16]) = 88
***************************

14:29:17 gettimeofday({1147955357, 752057}, NULL) = 0
14:29:22 poll([{fd=4, events=POLLIN}], 1, 4999) = 0
14:29:22 close(4) = 0
14:29:22 read(6, "00033", 4) = 4
14:29:22 read(6, "300016ssh-connection00000000", 27) = 27
14:29:22 read(6, "0005", 4) = 4
14:29:22 read(6, "n0000", 5) = 5
14:29:22 write(6, "0005v", 5) = 5
14:29:22 write(6, "0000", 4) = 4
14:29:22 read(6, "000246", 4) = 4
14:29:22 read(6, "240002000000000002250007ssh-rsa0"..., 166) = 166
14:29:22 geteuid32() = 0
14:29:22 getegid32() = 0
14:29:22 getgroups32(0, []) = 0
14:29:22 open("/proc/sys/kernel/ngroups_max", O_RDONLY) = 4
14:29:22 read(4, "65536n", 31) = 6
14:29:22 close(4) = 0
14:29:22 socket(PF_FILE, SOCK_STREAM, 0) = 4
14:29:22 fcntl64(4, F_GETFL) = 0x2 (flags O_RDWR)
14:29:22 fcntl64(4, F_SETFL, O_RDWR|O_NONBLOCK) = 0
... 
-------- >8 --------


Da passiert also irgendwas mit DNS.

Ich habe dann mal mit tcpdump auf dem Server überwacht, woher die Pakete 
kommen, die der Router von außen nach innen weiterleitet. Mein Verdacht, er 
würde sich selbst als Absender einsetzen und Antwortpakete des Servers dann 
wieder modifizieren und nach außen schicken, hat sich nicht bestätigt: Die 
Pakete kommen ganz sauber von der IP des Clients.
Zum Zeitpunkt an dem dieses sin_addr=inet_addr("192.168.0.10") auftaucht, 
zeigt mir tcpdump folgende Anfrage (die Pause war hier zwischen 16:12:03 und 
16:12:13):

// 192.168.0.102: SSH-Server
// 192.168.0.10:  Router
// ww.xx.yy.zz:   Client von außen


-------- 8< --------
16:12:03.168211 IP 192.168.0.102.1269 > 192.168.0.10.53:  9205+ PTR? 
zz.yy.xx.ww.in-addr.arpa. (44)
16:12:03.168645 IP 192.168.0.10.53 > 192.168.0.102.1269:  9205* 1/0/0 (88)
16:12:03.204862 IP 192.168.0.102.22 > ww.xx.yy.zz.49968: . ack 946 win 1752 
<nop,nop,timesta...

16:12:08.167226 IP 192.168.0.102.1269 > 192.168.0.10.53:  9205+ PTR? 
zz.yy.xx.ww.in-addr.arpa. (44)
16:12:08.167663 IP 192.168.0.10.53 > 192.168.0.102.1269:  9205* 1/0/0 (88)

16:12:13.166759 IP 192.168.0.102.22 > ww.xx.yy.zz.49968: P 1345:1409(64) ack 
946 win 1752 <no...
16:12:13.260007 IP ww.xx.yy.zz.49968 > 192.168.0.102.22: P 946:1186(240) ack 
1409 win 8320 <n...
-------- >8 --------

Er sendet die Anfrage also nach 5 Sekunden nochmal, nach weiteren 5 Sekunden 
geht's dann weiter.
Mache ich die Anfrage selbst, geht es schneller:

-------- 8< --------
~# time nslookup ww.xx.yy.zz
Server:         192.168.0.10
Address:        192.168.0.10#53

ww.xx.yy.zz.in-addr.arpa      name = pCCDDEEFF.dip0.t-ipconnect.de.


real    0m0.008s
user    0m0.004s
sys     0m0.003s
-------- >8 --------



Interessanterweise zeigt er mir aber die IP richtig rum an 
(ww.xx.yy.zz.in-addr...) und nicht rückwärts wie in der tcpdump-ausgabe 
(zz.yy.xx.ww.in-addr...). 
Wandelt das nslookup für mich um? 
Fragt der ssh-Prozess falsch? 

Was ist hier los?



Reply to: