Problem beim Einloggen

[Rüdiger Kupper]

z.B. gestern in 5.02: Nach Login hängt der Rechner erst und dann landet man wieder an der Anmeldemaske. Neustart hilft.

[Rüdiger Kupper]

Im Syslog steht, dass die LDAP-Credentials nicht gestimmt haben. Ursache?

[Rüdiger Kupper]

Ist dieses Problem noch einmal aufgetreten? Sonst würde ich es unter vorübergehende Netzwerkprobleme verbuchen.

[bau]

z.B. #3508

[Rüdiger Kupper]

Murphy's Law: Ausgerechnet heute am Tag des mündlichen Abiturs ist das Problem in der Hälfte der Prüfungsräume aufgetreten. Ursache könnten kleine Netzerkausfälle sein. Außerdem haben wir das (veraltete) Paket linuxmuster-client-auth in Verdacht, dass die /etc/ldap.conf beim Hochfahren patcht (oder auch nicht).

-> genauer unter die Lupe nehmen.

Probe: Den LDAP-Patch-Dienst deaktivieren in /etc/linuxmuster-client/auth/config und prüfen, ob das Problem noch auftritt (nicht vergessen, die ldap.conf wieder auf den Standard zurückzusetzen!). Eventuell das linuxmuster-Paket entfernen und den PAM-LDAP-Dienst manuell installieren.

[Rüdiger Kupper]

Habe

• in /etc/ldap.conf "bind_limit" von 5 auf 60 Sekunden hochgesetzt
• in /etc/linuxmuster-client/auth/config das Patchen von ldap.conf abgeschaltet

Die Dateien verteile ich nachher auf alle Rechner.

[Rüdiger Kupper]

Dateien wurden heute Abend an alle erreichbaren Rechner verteilt und sind auch bereits im neuen Image. Morgen prüfen, ob das Problem noch auftritt.

[Rüdiger Kupper]

Heute keinen Rechner mit Anmeldeproblem gesehen.

[bau]

Als ich den PC in 5.33 gestern ins Lehrernetz hängte (/etc/hosts angepasst) konnte ich mich nicht einloggen. Ich habe dann mal in /etc/ldap.conf und /etc/ldap/ldap.conf die IP eingetragen, dann ging es auf anhieb - habe das aber nicht reproduziert.

[Rüdiger Kupper]

Es ist eher unwahrscheinlich, dass es mit er IP zu tun hat.
Grund: Im Lehrernetz wurde bisher *immer* der Name durch "10.16.112.4" ersetzt, das haben wir ja gerade erst abgestellt. Da das Problem auch früher auftrat, kann es nicht die Ursache sein.

[Rüdiger Kupper]

Die Beobachtung, dass es einmal funktionierte, hat leider keine Aussagekraft. Da wir es hier mit einem statistisch auftretenden Problem zu tun haben, ist nur eine 100%-Aussage maßgeblich.

[Rüdiger Kupper]

Jetzt wohl unser vordringliches Problem.

• wir brauchen einen Rechner, der sich in diesem Zustand befindet um das Problem zu analysieren.
• noch besser: wissen, wie man das Problem gezielt hervorrufen kann.
• nebenbei die Vermutung mit den kurzzeitigen Netzwerkausfällen im Auge behalten.

[bau]

Als Test wäre vielleicht möglich:
ssh schuelte@rechner-X-Y
per Script - bei rechner-5-30 dauerte das gerade zunächst verdächtig lange. Beim Wiederholten Versuch ebenso, beim dritten Mal nicht mehr.Vor Ort: Keine Tastatur/Maus benutzbar, Bildschirme sind schwarz.

[Rüdiger Kupper]

Bin grade noch auf dem Rechner eingeloggt, bei dem sich schuelte nicht einloggen kann. Und der Rechner glaubt tatsächlich, dass es diesen User überhaupt nicht gibt:

root@rechner-5-27-06:~# id lehrer
id: »lehrer“: Einen solchen Benutzer gibt es nicht
root@rechner-5-27-06:~# id schuelte
id: »schuelte“: Einen solchen Benutzer gibt es nicht
root@rechner-5-27-06:~# id kup
uid=12083(kup) gid=10000(teachers) Gruppen=20(dialout),10000(teachers),10018(10b),10140(p_handy),10069(a),10107(p_robotik),10127(12c),10145(svn),10146(p_info_kupper),10183(p_mikromakro),10202(p_informatikag),10254(p_mikrocontr_kup),10288(p_wifi),10290(p_medizintec_kup)
root@rechner-5-27-06:~# id bau
uid=10839(bau) gid=10000(teachers) Gruppen=10003(6a),10007(11a),10010(8c),10011(9a),10116(12b),10000(teachers),10012(9c),10013(10a),10014(7b),10015(11c),10016(9b),10017(8a),10018(10b),10020(7a),10021(6c),10022(5a),10024(11b),10025(7c),10027(10c),10028(6b),10029(5b),10032(5c),10037(8b),10132(5d),10140(p_handy),10078(p_portfoliored),10084(6d),10079(p_portfolioadm),10066(p_qmh),10069(a),10074(p_abizeitung),10107(p_robotik),10119(8d),10129(12d),10141(9d),10145(svn),10160(10d),10161(7d),10162(5e),10183(p_mikromakro),10199(p_dgiss),10202(p_informatikag),10242(6e),10269(7e),10288(p_wifi),10289(8e),10294(p_informatik),10304(p_vertretung),10316(p_chj1bad)

In der Nutzerdatenbank taucht er tatsächlich nicht auf:

root@rechner-5-27-06:~# getent passwd lehrer
root@rechner-5-27-06:~# getent passwd schueler
root@rechner-5-27-06:~# getent passwd kup
kup:x:12083:10000:Ruediger DrKupper:/home/teachers/kup:/bin/bash
root@rechner-5-27-06:~# getent passwd bau
bau:x:10839:10000:Jens Baumgaertner:/home/teachers/bau:/bin/bash

Die Authentifizierung schlägt also nicht fehl – es gibt die Nutzer schuelte und lehrer zur Zeit gar nicht auf dem Rechner!

Der LDAP-Fehler "incorrect credentials" ist dann nur ein Folgefehler, das ist z.B. hier beschrieben:

• ​https://serverfault.com/questions/482493/pam-ldap-authentication-failure-with-correct-credentials-on-freebsd
• ​https://unix.stackexchange.com/questions/163213/while-trying-to-ssh-pam-ldap-always-sends-the-password-incorrect-causing-bind

Also warum ist der Nutzer unbekannt??!

[Rüdiger Kupper]

Die LDAP-Abfrage funktioniert aber:

root@rechner-5-27-06:~# ldapsearch -x -LLL -b "uid=schuelte,ou=accounts,dc=kg-fds,dc=de"
dn: uid=schuelte,ou=accounts,dc=kg-fds,dc=de
cn: Test Schueler
uidNumber: 12815
sambaPrimaryGroupSID: S-1-5-21-3878879208-3767656771-1509607135-21139
gecos: Test Schueler
mail: schuelte@kg-fds.de
sophomorixstatus: A
displayName: Test Schueler
uid: schuelte
sambaPwdCanChange: 0
sambaHomePath: \\paedml\schuelte
homeDirectory: /home/students/a/schuelte
sambaLogoffTime: 2147483647
description: Test Schueler
objectClass: inetOrgPerson
objectClass: posixAccount
objectClass: shadowAccount
objectClass: top
objectClass: sambaSamAccount
objectClass: sophomorixData
sambaLogonTime: 0
gidNumber: 10069
sambaSID: S-1-5-21-3878879208-3767656771-1509607135-26630
sambaHomeDrive: H:
sambaKickoffTime: 2147483647
sn: Schueler
givenName: Test
loginShell: /bin/bash

Dennoch:

root@rechner-5-27-06:~# id schuelte
id: »schuelte“: Einen solchen Benutzer gibt es nicht

[Rüdiger Kupper]

Vermutlich müssen wir den Fehler eher im Bereich "nss" suchen:

• ​https://wiki.debian.org/LDAP/NSS
• ​https://tldp.org/HOWTO/archived/LDAP-Implementation-HOWTO/pamnss.html
• ​https://manpages.debian.org/testing/libnss-ldap/libnss-ldap.conf.5.en.html

[Rüdiger Kupper]

Auf einer dieser Seiten wird empfohlen, zum Debuggen den "Name Service Caching Daemon" (nscd) Abzuschalten. Die zugehörige systemd-Unit sagt folgendes:

root@rechner-5-27-06:~# systemctl status nscd
● nscd.service - Name Service Cache Daemon
     Loaded: loaded (/lib/systemd/system/nscd.service; enabled; vendor preset: enabled)
     Active: active (running) since Mon 2020-09-28 17:36:38 CEST; 45min left
   Main PID: 1393 (nscd)
      Tasks: 10 (limit: 19019)
     Memory: 6.9M
     CGroup: /system.slice/nscd.service
             └─1393 /usr/sbin/nscd

Sep 28 17:37:01 rechner-5-27-06 nscd[1393]: nss-ldap: do_open: do_start_tls failed:stat=-1
Sep 28 17:37:01 rechner-5-27-06 nscd[1393]: nss_ldap: could not search LDAP server - Server is unavailable
Sep 28 17:37:01 rechner-5-27-06 nscd[1393]: nss-ldap: do_open: do_start_tls failed:stat=-1
Sep 28 17:37:01 rechner-5-27-06 nscd[1393]: nss_ldap: reconnecting to LDAP server...
Sep 28 17:37:01 rechner-5-27-06 nscd[1393]: nss-ldap: do_open: do_start_tls failed:stat=-1
Sep 28 17:37:01 rechner-5-27-06 nscd[1393]: nss_ldap: reconnecting to LDAP server (sleeping 1 seconds)...
Sep 28 17:37:02 rechner-5-27-06 nscd[1393]: nss-ldap: do_open: do_start_tls failed:stat=-1
Sep 28 17:37:02 rechner-5-27-06 nscd[1393]: nss_ldap: could not search LDAP server - Server is unavailable
Sep 28 17:37:07 rechner-5-27-06 nscd[1393]: 1393 inotify Event für Datei »/etc/resolv.conf« ignoriert (Datei existiert)
Sep 28 17:37:07 rechner-5-27-06 nscd[1393]: 1393 inotify Event für Datei »/etc/resolv.conf« ignoriert (Datei existiert)

Das sagt eindeutig: "nss_ldap: could not search LDAP server - Server is unavailable".

Zu der Zeit, als diese Unit aktiviert wurde, war also der paedml nicht erreichbar.

[Rüdiger Kupper]

Jepp!! Das müsste das Problem sein: Der nscd kontaktiert beim Hochfahren einmal den paedml und cached alle Nutzerdaten. Ab da werden die Anfragen aus diesem Cache beantwortet. Schaltet man den mal ab, ist der User auf einmal bekannt:

root@rechner-5-27-06:~# id schuelte
id: »schuelte“: Einen solchen Benutzer gibt es nicht
root@rechner-5-27-06:~# systemctl stop nscd
root@rechner-5-27-06:~# id schuelte
uid=12815(schuelte) gid=10069(a) Gruppen=10069(a)

[Rüdiger Kupper]

Man muss also dem nscd sagen, er soll seinen Cache erneuern:

root@rechner-5-27-06:~# id schuelte
id: »schuelte“: Einen solchen Benutzer gibt es nicht
root@rechner-5-27-06:~# nscd -i passwd
root@rechner-5-27-06:~# id schuelte
uid=12815(schuelte) gid=10069(a) Gruppen=10069(a)

[Rüdiger Kupper]

Also:

1. Hat ein Rechner dieses Problem, nscd -i passwd aufrufen! (Oder systemctl reload nscd, macht das ebenfalls)
2. Wir müssen rausfinden, warum der LDAP-Server beim Hochfahren der Rechner manchmal nicht erreichbar ist. Kann es einfache Überlastung sein, weil alle Rechner gleichzeitig hochfahren und ihre passwd-Caches füllen?
3. Wenn ja, könnte es helfen, die Rechner morgens nicht gleichzeitig hochzufahren, sondern in Abständen.

[Rüdiger Kupper]

Allerdings – die beiden Rechner im Computerraum habe ich ja in der Mittagspause hochgefahren, da dürfte nicht viel Netzlast gewesen sein …

[Rüdiger Kupper]

systemctl-Log für dienst nscd

[Rüdiger Kupper]

Heute Morgen sah es in 5.27/5.28 so aus:
attachment:status-nscd--2020-09-30--8-05​
Fast alle Rechner hatten Probleme, den LDAP-Server zu erreichen. Viele schaffen es nach zwei weiteren Versuchen ("reconnected to LDAP server"), doch manche geben offenbar auf. Vermutlich sind das dann die, an denen die Probleme auftreten.

Woran kann es liegen, dass der Server nicht erreichbar ist??

[Rüdiger Kupper]

Außer dem nscd hat auch der systemd-logind genau das selbe Problem. Die Fehlermeldung ist immer die selbe:

nss-ldap: do_open: do_start_tls failed:stat=-1

Tritt jetzt grade am rechner-5-27-07 auf.

[Rüdiger Kupper]

Ich habe nun mal probeweise in der /etc/ldap.conf das SSL abgestellt. Nun ist die Fehlermeldung eine andere, aber auch nicht besser:

Okt 01 14:59:03 rechner-5-27-07 nscd[1092]: nss_ldap: reconnecting to LDAP server...
Okt 01 14:59:03 rechner-5-27-07 nscd[1092]: nss_ldap: could not connect to any LDAP server as (null) - Can't contact LDAP server
Okt 01 14:59:03 rechner-5-27-07 nscd[1092]: nss_ldap: failed to bind to LDAP server ldap://paedml.kg-fds.de/: Can't contact LDAP ser
Okt 01 14:59:03 rechner-5-27-07 nscd[1092]: nss_ldap: reconnecting to LDAP server (sleeping 1 seconds)...
Okt 01 14:59:04 rechner-5-27-07 nscd[1092]: nss_ldap: reconnected to LDAP server ldap://paedml.kg-fds.de/ after 2 attempts

Jetzt sagt es, es kann den Server gar nicht erreichen, hier hat es dann aber nach zwei Anläufen geklappt.
Das heißt, das SSL ist nicht das Problem. Der Server antwortet wirklich nicht verlässlich.

[Rüdiger Kupper]

Wenn ich mir das syslog auf dem paedml anschaue, besteht das fast nur aus Meldungen von cyrus/imap. Das sieht auch nicht gesund aus …

[Rüdiger Kupper]

Ich hab's hoffentlich!

Habe mich gefragt, wieso das Starten des nscd beim Boot fehlschlägt, der Reloas später aber klappt. Bekanntes Problem: Die systemd-Unit "nscd.service" wurde eventuell gestartet, bevor das Netzwerk verfügbar ist. Das dumme systemd ist einfach zu schnell. (Oder besser gesagt, wer die Unit-Files geschrieben hat, hat nicht daran gedacht, dass das Netzwerk vielleicht noch gar nicht da ist.)

Abhilfe: Datei /etc/systemd/system/nscd.service.d/override.conf anlegen mit Inhalt

[Unit]
After=network-online.target
Wants=network-online.target

Das habe ich eben auf allen erreichbaren Rechnern gemacht. Ein Neustart aller Rechner in 5.27/5.28 hat dann ergeben: Der nscd.service startet jetzt beim Boot ohne Fehler.

Sofern das wirklich die Ursache für unser Login-Problem war, dürfte es ab morgen nicht mehr auftreten. Hoffen wir mal, dass es das war!

[lehm]

5.30 klappt heute (Freitag, 2.10.) Morgen leider nicht. Nach Eingabe der 6stelligen TAN passiert nichts :-(

[ast]

Konnte mich heute (2.10.) weder in 5.30 noch 5.45 einloggen

[Rüdiger Kupper]

Ich war noch bis halb acht an der Schule und habe herumprobiert. Beobachtungen:

Deine Zertifikatserneuerung hat das Problem leider nicht behoben. Zwar waren plötzlich sämtliche Fehlermeldungen beim Hochfahren weg, doch beim Login kamen sie dann wieder. Es wurde sogar schlimmer: nach einem Reboot aller Rechner konnte sich Nutzer lehrer in 1.10 überhaupt nirgends mehr einloggen. Viele Rechner sind minutenlang eingefroren.

Schüießlich habe ich die Rechner in den Computerräumen neu gesynct und damit meine gestrigen Änderungen rückgängig gemacht. Ergebnis: keiner ist mehr eingefroren, dafür wie gehabt ein gewisser Prozentsatz, wo sich lehrer nicht anmelden konnte. (Bei anderen gings).

Oben schien die Lage wieder etwas besser zu sein, als unten.

Dann kam mir der Gedanke, dass ich an den Rechnern mit neuem Image das Problem vielleicht noch gar nicht beobachtet hatte. Habe also 5.27/5.28 komplett aufs neue Image umgestellt (ohne meine Anpassung von gestern). Ergebnis: Kein Rechner friert ein und ich konnte mich an allen nacheinander als lehrer einloggen. Manchmal hat es etwas gedauert, doch es hat an jedem Rechner auf Anhieb geklappt.

Keine Ahnung, ob das Problem im neuen Image wirklich weg ist. Vielleicht hatte sich auch gerade das Netzwerk irgendwie erholt. Doch das ist jetzt meine neue Strategie: übers WE das Image notdürftig fertig stellen und alle Rechner syncen. Vielleicht sind wir das Problem dann los – wissen allerdings auch nicht wirklich, was der Grund war.

[Rüdiger Kupper]

Übrigens ist das etwas, was etwa um die Zeit passiert sein dürfte, als die Probleme zuerst auftraten: ich habe das finale Image von Henrike verteilt und dann die Arbeit an Inge begonnen.

[bau]

Na immerhin ein Lichtblick!
Ich wünsche uns, dass wir tatsächlich Ruhe bekommen durch das neue Image.

[bau]

Machen wir eigentlich von den Clients aus einen anonymous-bind oder nutzen wir den administrativen Zugang mit dem Passwort aus /etc/ldap/slapd.conf?

Bei ersterem: Ich würde mich nun wundern, warum das überhaupt tut, denn das müsste erstmal in der config für die IP's freigegeben werden.

[Rüdiger Kupper]

Äh, ich kann als normaler Nutzer kup eine LDAP-Anfrage absetzen:

kup@rechner-5-28-01:~$ ldapsearch -x -LLL -b "uid=bau,ou=accounts,dc=kg-fds,dc=de"
dn: uid=bau,ou=accounts,dc=kg-fds,dc=de
cn: Jens Baumgaertner
uidNumber: 10839
sambaPrimaryGroupSID: S-1-5-21-3878879208-3767656771-1509607135-21001
gecos: Jens Baumgaertner
mail: bau@kg-fds.de
sophomorixstatus: U
displayName: Jens Baumgaertner
uid: bau
sambaPwdCanChange: 0
sambaHomePath: \\paedml\bau
homeDirectory: /home/teachers/bau
sambaLogoffTime: 2147483647
description: Jens Baumgaertner
objectClass: inetOrgPerson
objectClass: posixAccount
objectClass: shadowAccount
objectClass: top
objectClass: sambaSamAccount
objectClass: sophomorixData
sambaLogonTime: 0
gidNumber: 10000
sambaSID: S-1-5-21-3878879208-3767656771-1509607135-22678
sambaHomeDrive: H:
sambaKickoffTime: 2147483647
sn: Baumgaertner
givenName: Jens
loginShell: /bin/bash

Scheint ohne Passwort zu klappen. Thunderbird kann ja auch ohne Admin-Passwort das Adressbuch abfragen. Dürfte also anonym sein.

[Rüdiger Kupper]

Das einzige, was in der /etc/ldap/ldap.conf steht, ist das Server-Zertifikat:

TLS_CACERT      /etc/ssl/certs/ca-certificates.crt
TLS_REQCERT never

Bin aber nicht sicher, was die zweite Zeile bedeutet?

[Rüdiger Kupper]

Ah, hier steht es, in /etc/ldap.conf:

# The credentials to bind with. 
# Optional: default is no credential.
#bindpw secret

Also wirklich anonym.

[Rüdiger Kupper]

Auf dem paedml steht in /usr/share/slapd/slapd.conf

# The userPassword by default can be changed
# by the entry owning it if they are authenticated.
# Others should not be able to see it, except the
# admin entry below
# These access lines apply to database #1 only
access to attrs=userPassword,shadowLastChange
        by dn="@ADMIN@" write
        by anonymous auth
        by self write
        by * none

[Rüdiger Kupper]

Ah, das ist vermutlich das falsche conf-File. Das richtige müsste /etc/ldap/slapd.conf sein.

[Rüdiger Kupper]

Ich komme grade von der Schule, nach einem fünf-Stunden-Einsatz.

Stand: Alle Rechner sind mit dem Inge-Image gesynct, dort scheint das Problem nicht aufzutreten(?). Jedenfalls konnte ich mich an jedem einzelnen Rechner in 1.09 anmelden. Am Freitag hatte ich das bereits in 5.27/5.28 getestet: kein einziger Fehler. Allerdings war ich beide Male allein im Schulhaus, morgen früh kann das wieder ganz anders aussehen. Hoffen wir mal.

Ausnahme: die Rechner aus der Gruppe „schueleralt“ haben zu kleine Platten für das Inge-Image. Dort wollte ich das Henrike-Image neu syncen. Das ist leider fatal schief gegangen: auch die altuelle Version von Henrike war zu groß für die Platten. Danach waren also alle Rechner in den Fachräumen und der BK dysfunktional. Ich fürchtete schon, sie so lassen zu müssen, konnte dann aber durch umpartitionieren (kleinerer Cache, weniger Swap) die entscheidenden Gigabyte freischsufeln. Hat leider sehr lange gedauert, weil ich jedes Mal testen musste.

Ich habe alle Rechner im Schulhaus abgelaufen, die Fachräume und BK sogar zwei mal. Es müssteb morgen alle laufen. Im Henrike-Image tritt das Anmeldeproblem allerdings nach wie vor auf. Wenn morgen also Klagen aus Fachräumen und BK kommen: das ist zu erwarten. Aus allen anderen Räumen kommen hoffentlich keine Klagen mehr. Hoffe ich jedenfalls inständig.

Morgen tauschen wir in den „schueleralt“-Rechnern die Platten (besser: die ganzen Rechner) und dann können auch die das Inge-Image bekommen und das Problem ist dann hoffentlich Geschichte.

Übrigens: Im Inge-Image startet Chromium für Schüler nicht (bei Lehrern geht's). Doch das schien mir nun wirklich ein untergeordnetes Problem zu sein. Gibt ja nach wie vor Firefox.

[bau]

Mein Chemierechner hängt grade mit einer ominösen Fehlermeldung, da kann man aber doch irgendwie lesen:
LDAP autoconfiguration. crash.signatures nicht möglich: Daei oder Verzeichnis nicht gefunden

Spukt da noch so ein unnötiges Script rum?

[Rüdiger Kupper]

Da hast Du ein noch älteres Image, das ist das Paket linuxmuster-auth, haben wir bereits deaktiviert.

[Rüdiger Kupper]

Äh, nein, dieses Ticket ist natürlich an sich nicht ungültig. Doch mit dem neuen Image hoffentlich erledigt. Müssen nur noch die letzten Rechner tauschen.

[lehm]

Erledigt?

[Rüdiger Kupper]

Ja.