Ich betreibe zu Hause einen Server mit Ubuntu 14.04. Ich habe zwei Benutzer auf der Maschine, sagen wir user1und user2, die sich beide per SSH mit der Box verbinden können. user1Die Anmeldung erfolgt sehr schnell, user2dauert aber etwa 20 Sekunden. Dasselbe Verhalten tritt auf, unabhängig davon, welcher Benutzer sich von einer bestimmten Maschine aus anmeldet.
user2Wenn Sie sich mit anmelden, ssh -vwird angezeigt, dass die Hauptpause nach dieser Meldung auftritt:
debug1: Sending environment.
Die .bashrcDateien für die beiden Benutzer sind identisch. (Ein diffauf ihnen erzeugt keine Ausgabe.) Dasselbe gilt für die .profileDateien für user1und user2.
Auf dem Server gibt es eine Zeile /etc/ssh/sshd_configmit AllowUsers user1 user2. Dieselbe Datei enthält UseDNS nobereits . (Ich erwähne das nur, weil auf den meisten Seiten, die ich bei der Suche nach einer Lösung gefunden habe, das Hinzufügen dieser Zeile empfohlen wurde.)
Dieses Problem trat erst vor etwa einer Woche auf. In den letzten Jahren, in denen ich die Maschine betrieben habe, hatte ich keine derartigen Probleme.
Aus einer Laune heraus habe ich einen neuen Benutzer erstellt, user3diesem Benutzer durch entsprechende Bearbeitung SSH-Zugriff gewährt sshd_configund die Anmeldung für den neuen Benutzer geht schnell. Es scheint also wirklich etwas mit der Art und Weise zu tun zu haben, wie user2es konfiguriert wird. Aber was?
Wo muss ich nach der Grundursache für die Verzögerung beim Anmelden suchen user2?
BEARBEITEN: Unten sind die Ergebnisse der tail -f /var/log/auth.logAnmeldungen user2:
Jun 21 11:27:10 topo sshd[18386]: Connection from re.mo.te.ip port XXXXX on se.rv.er.ip port XX
Jun 21 11:27:21 topo sshd[18386]: Accepted password for user2 from re.mo.te.ip port XXXXX ssh2
Jun 21 11:27:21 topo sshd[18386]: pam_unix(sshd:session): session opened for user user2 by (uid=0)
Jun 21 11:27:21 topo systemd-logind[3347]: New session 25 of user user2.
Jun 21 11:28:03 topo sshd[18386]: User child is on pid XXXXX
Jun 21 11:28:03 topo sshd[18455]: Starting session: shell on pts/6 for user2 from re.mo.te.ip port XXXXX
Beachten Sie die Zeitstempel. Die Verzögerung tritt hier nach der letzten Nachricht auf. Sobald Sie user2sich endgültig angemeldet haben, werden keine Nachrichten mehr in auth.log angezeigt.
EDIT: Nachfolgend sind einige Ergebnisse aufgeführt, bei strace -f -p <sshd pid> -o out.tx -ttdenen es zu Verzögerungen kommt.
22733 12:59:10.414388 open("/usr/lib/python2.7/dist-packages/twisted/python/compat.x86_64-linux-gnu.so", O_RDONLY) = -1 ENOENT (No such file or directory)
22733 12:59:10.840303 open("/usr/lib/python2.7/dist-packages/twisted/python/compat.so", O_RDONLY) = -1 ENOENT (No such file or directory)
22733 12:59:11.264716 open("/usr/lib/python2.7/dist-packages/twisted/python/compatmodule.so", O_RDONLY) = -1 ENOENT (No such file or directory)
22733 12:59:11.717471 open("/usr/lib/python2.7/dist-packages/twisted/python/compat.py", O_RDONLY) = 4
22733 12:59:12.660275 fstat(4, {st_mode=S_IFREG|0644, st_size=11146, ...}) = 0
...
22733 12:59:12.661502 open("/usr/lib/python2.7/dist-packages/twisted/python/__future__.x86_64-linux-gnu.so", O_RDONLY) = -1 ENOENT (No such file or directory)
22733 12:59:13.212844 open("/usr/lib/python2.7/dist-packages/twisted/python/__future__.so", O_RDONLY) = -1 ENOENT (No such file or directory)
...
22733 12:59:14.441963 open("/usr/bin/dis.py", O_RDONLY) = -1 ENOENT (No such file or directory)
22733 12:59:14.900322 open("/usr/bin/dis.pyc", O_RDONLY) = -1 ENOENT (No such file or directory)
22733 12:59:15.401750 stat("/usr/lib/python2.7/dis", 0x7ffcb599ddd0) = -1 ENOENT (No such file or directory)
...
22733 12:59:17.315288 open("/usr/lib/python2.7/dist-packages/twisted/internet/termios.so", O_RDONLY) = -1 ENOENT (No such file or directory)
22733 12:59:17.967173 open("/usr/lib/python2.7/dist-packages/twisted/internet/termiosmodule.so", O_RDONLY) = -1 ENOENT (No such file or directory)
22733 12:59:18.511526 open("/usr/lib/python2.7/dist-packages/twisted/internet/termios.py", O_RDONLY) = -1 ENOENT (No such file or directory)
...
22733 12:59:25.993287 open("/usr/lib/python2.7/dist-packages/landscape/monitor/time.x86_64-linux-gnu.so", O_RDONLY) = -1 ENOENT (No such file or directory)
22733 12:59:26.612018 open("/usr/lib/python2.7/dist-packages/landscape/monitor/time.so", O_RDONLY) = -1 ENOENT (No such file or directory)
...
22733 12:59:29.688166 open("/proc/37/stat", O_RDONLY) = 9
22733 12:59:30.239695 fstat(9, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
...
22733 12:59:30.240450 open("/proc/uptime", O_RDONLY) = 10
22733 12:59:31.634404 fstat(10, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
...
22733 12:59:34.287758 open("/proc/557/stat", O_RDONLY) = 9
22733 12:59:34.851662 fstat(9, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
...
22758 12:59:39.500397 open(".", O_RDONLY) = 3
22758 12:59:40.377193 fchdir(3) = 0
22758 12:59:40.377312 newfstatat(AT_FDCWD, "/var/lib/apt//lists/", {st_mode=S_IFDIR|0755, st_size=12288, ...}, AT_SYMLINK_NOFOLLOW) = 0
22758 12:59:40.377378 open(".", O_RDONLY|O_NOCTTY|O_NONBLOCK|O_DIRECTORY|O_NOFOLLOW) = 4
22758 12:59:40.878676 fchdir(4) = 0
...
22759 12:59:41.680427 open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
22759 12:59:42.249796 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P \2\0\0\0\0\0"..., 832) = 832
...
22759 12:59:46.019309 open("/etc/lsb-release", O_RDONLY|O_CLOEXEC) = 64
22759 12:59:46.948115 fstat(64, {st_mode=S_IFREG|0644, st_size=105, ...}) = 0
...
22786 12:59:50.251281 open("/dev/null", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3
22786 12:59:50.970074 fcntl(1, F_GETFD) = 0
...
22785 12:59:53.338632 select(10, [3 4 6], [], NULL, NULL) = 1 (in [3])
22785 12:59:53.771002 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
Vieles davon scheint mit Python-Bibliotheken zusammenzuhängen. Sie werden jedoch auch beim user1Anmelden geladen, nur ohne diese 0,5-Sekunden-Pausen.