Linuxclient Anmeldung ldap geht nicht mehr LMN6.2

ChristianWd · 16. Februar 2021 um 18:48

Hallo miteinander,

heute habe ich die Lehrerrechner umformatiert und anschließend festgestellt, dass ich mich als Domänennutzer am Linuxclient nicht mehr anmelden kann. Es betrifft mein veraltetes Ubuntu 16.04 hier aus der Liste irgendwann einmal und auch ein upgedatetes Ubuntu 20.04, das aber auch schon mal lief. Am Windows Client kann ich mich noch anmelden, ebenso an den nach außen geöffneten Diensten wie Nextcloud und Moodle.

Auf dem Client selbst sehe ich nur diese Fehlermeldung:

pam_ldap: error trying to bind as user "uid=mopsot,ou=accounts,dc=pg-bs,dc=de" (Invalid credentials)

Weil vorhin die Diskussion dazu lief: es ist lightdm als Anmeldemanager eingestellt.

Jetzt ist die Frage: wo kann ich anfangen zu suchen? Hat jemand eine Idee?

VG
Christian

P.S. LMN6.2

ChristianWd · 16. Februar 2021 um 20:30

Ein bisschen probiert man doch immer noch weiter.
Das Image und die Clients hatte ich seit Ende Dezember nicht mehr angefasst. Aber am Server waren die letsencrypt - Zertifikate für die subdomain ausgelaufen. Ich hatte auf das Wildcard-Zertifikat umgestellt (ist zwar Handarbeit aber dafür überall das gleiche). Es kann sein, dass ich diese Änderung auf dem Server auch erst in den Weihnachtsferien für /etc/ldap/slapd.conf gemacht habe. Die Zertifikate sind müssen manchmal in einer ganz bestimmten Form vorliegen … kann es das sein?

baumhof · 16. Februar 2021 um 20:54

Hallo Christian,

Ein bisschen probiert man doch immer noch weiter.
Das Image und die Clients hatte ich seit Ende Dezember nicht mehr
angefasst. Aber am Server waren die letsencrypt - Zertifikate für die
subdomain ausgelaufen. Ich hatte auf das Wildcard-Zertifikat umgestellt
(ist zwar Handarbeit aber dafür überall das gleiche). Es kann sein, dass
ich diese Änderung auf dem Server auch erst in den Weihnachtsferien für
|/etc/ldap/slapd.conf| gemacht habe. Die Zertifikate sind müssen
manchmal in einer ganz bestimmten Form vorliegen … kann es das sein?
dann mach mal eine neue Domänenaufnahme am Client: dabei werden, meine ich, Zertifikatsdateien auf den Client geholt…

Ich mache das an einem speziellen (virtualisierten) client, weil der danach auch weiterhin in der Domäne bleiben muss: mit dem selben Namen!.
Der Grund dafür liegt in einer nicht ganz ausgereiften Domänenaufnahmemechanismus (es ist also ein Workaround).
Vor Domänenbeitritt die /etc/kbr??key?? Datei auf dem Client löschen, dann linuxmuster-client-adsso ausführen und dnach ein Image erstellen.

LG

Holger

Arnaud · 16. Februar 2021 um 21:16

Hallo Holger,

Er spricht von LMN 6.2.
@ChristianWd : gab es ein Update von Samba ?
Ich würde auf dem Server die Ldap-Logs aktivieren und schauen ob in /var/log/slapd.log etwas interessant steht.

Gruß

Arnaud

ChristianWd · 17. Februar 2021 um 06:57

Hallo Holger und Arnaud,

es handelt sich wirklich nur um die LDAP Anmeldung, kein Domänenbeitritt. Die Datei /var/log/slapd.log gibt es bei mir nicht. Aber wenn ich in slapd.conf das loglevel auf -1 setze kommen einige Nachrichten in /var/log/syslog. Das sieht dann so aus:

Feb 17 07:53:58 server slapd[21476]: daemon: activity on 1 descriptor
Feb 17 07:53:58 server slapd[21476]: daemon: activity on:
Feb 17 07:53:58 server slapd[21476]:
Feb 17 07:53:58 server slapd[21476]: slap_listener_activate(8):
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=8 busy
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Feb 17 07:53:58 server slapd[21476]: >>> slap_listener(ldap:///)
Feb 17 07:53:58 server slapd[21476]: daemon: listen=8, new connection on 19
Feb 17 07:53:58 server slapd[21476]: daemon: added 19r (active) listener=(nil)
Feb 17 07:53:58 server slapd[21476]: conn=1310 fd=19 ACCEPT from IP=10.76.1.1:52738 (IP=0.0.0.0:389)
Feb 17 07:53:58 server slapd[21476]: daemon: activity on 2 descriptors
Feb 17 07:53:58 server slapd[21476]: daemon: activity on:
Feb 17 07:53:58 server slapd[21476]: 19r
Feb 17 07:53:58 server slapd[21476]:
Feb 17 07:53:58 server slapd[21476]: daemon: read active on 19
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Feb 17 07:53:58 server slapd[21476]: connection_get(19)
Feb 17 07:53:58 server slapd[21476]: connection_get(19): got connid=1310
Feb 17 07:53:58 server slapd[21476]: connection_read(19): checking for input on id=1310
Feb 17 07:53:58 server slapd[21476]: op tag 0x77, time 1613544838
Feb 17 07:53:58 server slapd[21476]: daemon: activity on 1 descriptor
Feb 17 07:53:58 server slapd[21476]: daemon: activity on:
Feb 17 07:53:58 server slapd[21476]:
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Feb 17 07:53:58 server slapd[21476]: conn=1310 op=0 do_extended
Feb 17 07:53:58 server slapd[21476]: conn=1310 op=0 EXT oid=1.3.6.1.4.1.1466.20037
Feb 17 07:53:58 server slapd[21476]: do_extended: oid=1.3.6.1.4.1.1466.20037
Feb 17 07:53:58 server slapd[21476]: conn=1310 op=0 STARTTLS
Feb 17 07:53:58 server slapd[21476]: send_ldap_extended: err=0 oid= len=0
Feb 17 07:53:58 server slapd[21476]: send_ldap_response: msgid=1 tag=120 err=0
Feb 17 07:53:58 server slapd[21476]: conn=1310 op=0 RESULT oid= err=0 text=
Feb 17 07:53:58 server slapd[21476]: daemon: activity on 1 descriptor
Feb 17 07:53:58 server slapd[21476]: daemon: activity on:
Feb 17 07:53:58 server slapd[21476]: 19r
Feb 17 07:53:58 server slapd[21476]:
Feb 17 07:53:58 server slapd[21476]: daemon: read active on 19
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Feb 17 07:53:58 server slapd[21476]: connection_get(19)
Feb 17 07:53:58 server slapd[21476]: connection_get(19): got connid=1310
Feb 17 07:53:58 server slapd[21476]: connection_read(19): checking for input on id=1310
Feb 17 07:53:58 server slapd[21476]: daemon: activity on 1 descriptor
Feb 17 07:53:58 server slapd[21476]: daemon: activity on:
Feb 17 07:53:58 server slapd[21476]:
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Feb 17 07:53:58 server slapd[21476]: daemon: activity on 1 descriptor
Feb 17 07:53:58 server slapd[21476]: daemon: activity on:
Feb 17 07:53:58 server slapd[21476]: 19r
Feb 17 07:53:58 server slapd[21476]:
Feb 17 07:53:58 server slapd[21476]: daemon: read active on 19
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Feb 17 07:53:58 server slapd[21476]: connection_get(19)
Feb 17 07:53:58 server slapd[21476]: connection_get(19): got connid=1310
Feb 17 07:53:58 server slapd[21476]: connection_read(19): checking for input on id=1310
Feb 17 07:53:58 server slapd[21476]: connection_read(19): unable to get TLS client DN, error=49 id=1310
Feb 17 07:53:58 server slapd[21476]: conn=1310 fd=19 TLS established tls_ssf=128 ssf=128
Feb 17 07:53:58 server slapd[21476]: daemon: activity on 1 descriptor
Feb 17 07:53:58 server slapd[21476]: daemon: activity on:
Feb 17 07:53:58 server slapd[21476]:
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Feb 17 07:53:58 server slapd[21476]: daemon: activity on 1 descriptor
Feb 17 07:53:58 server slapd[21476]: daemon: activity on:
Feb 17 07:53:58 server slapd[21476]: 19r
Feb 17 07:53:58 server slapd[21476]:
Feb 17 07:53:58 server slapd[21476]: daemon: read active on 19
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Feb 17 07:53:58 server slapd[21476]: connection_get(19)
Feb 17 07:53:58 server slapd[21476]: connection_get(19): got connid=1310
Feb 17 07:53:58 server slapd[21476]: connection_read(19): checking for input on id=1310
Feb 17 07:53:58 server slapd[21476]: op tag 0x60, time 1613544838
Feb 17 07:53:58 server slapd[21476]: daemon: activity on 1 descriptor
Feb 17 07:53:58 server slapd[21476]: daemon: activity on:
Feb 17 07:53:58 server slapd[21476]:
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Feb 17 07:53:58 server slapd[21476]: conn=1310 op=1 do_bind
Feb 17 07:53:58 server slapd[21476]: >>> dnPrettyNormal: <>
Feb 17 07:53:58 server slapd[21476]: <<< dnPrettyNormal: <>, <>
Feb 17 07:53:58 server slapd[21476]: conn=1310 op=1 BIND dn="" method=128
Feb 17 07:53:58 server slapd[21476]: do_bind: version=3 dn="" method=128
Feb 17 07:53:58 server slapd[21476]: send_ldap_result: conn=1310 op=1 p=3
Feb 17 07:53:58 server slapd[21476]: send_ldap_result: err=0 matched="" text=""
Feb 17 07:53:58 server slapd[21476]: send_ldap_response: msgid=2 tag=97 err=0
Feb 17 07:53:58 server slapd[21476]: conn=1310 op=1 RESULT tag=97 err=0 text=
Feb 17 07:53:58 server slapd[21476]: do_bind: v3 anonymous bind
Feb 17 07:53:58 server slapd[21476]: daemon: activity on 1 descriptor
Feb 17 07:53:58 server slapd[21476]: daemon: activity on:
Feb 17 07:53:58 server slapd[21476]: 19r
Feb 17 07:53:58 server slapd[21476]:
Feb 17 07:53:58 server slapd[21476]: daemon: read active on 19
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Feb 17 07:53:58 server slapd[21476]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Feb 17 07:53:58 server slapd[21476]: connection_get(19)
Feb 17 07:53:58 server slapd[21476]: connection_get(19): got connid=1310
Feb 17 07:53:58 server slapd[21476]: connection_read(19): checking for input on id=1310
Feb 17 07:53:58 server slapd[21476]: op tag 0x63, time 1613544838
Feb 17 07:53:58 server slapd[21476]: conn=1310 op=2 do_search
Feb 17 07:53:58 server slapd[21476]: >>> dnPrettyNormal: <dc=pg-bs,dc=de>
Feb 17 07:53:58 server slapd[21476]: <<< dnPrettyNormal: <dc=pg-bs,dc=de>, <dc=pg-bs,dc=de>
Feb 17 07:53:58 server slapd[21476]: SRCH „dc=pg-bs,dc=de“ 2 0
Feb 17 07:53:58 server slapd[21476]: 1 5 0
Feb 17 07:53:58 server slapd[21476]: begin get_filter
Feb 17 07:53:58 server slapd[21476]: EQUALITY
Feb 17 07:53:58 server slapd[21476]: end get_filter 0
Feb 17 07:53:58 server slapd[21476]: filter: (uid=wd)
Feb 17 07:53:58 server slapd[21476]: attrs:
Feb 17 07:53:58 server slapd[21476]:
Feb 17 07:53:58 server slapd[21476]: conn=1310 op=2 SRCH base=„dc=pg-bs,dc=de“ scope=2 deref=0 filter="(uid=wd)"
Feb 17 07:53:58 server slapd[21476]: ==> limits_get: conn=1310 op=2 self="[anonymous]" this=„dc=pg-bs,dc=de“
Feb 17 07:53:58 server slapd[21476]: => hdb_search
Feb 17 07:53:58 server slapd[21476]: bdb_dn2entry(„dc=pg-bs,dc=de“)
Feb 17 07:53:58 server slapd[21476]: => access_allowed: search access to „dc=pg-bs,dc=de“ „entry“ requested
Feb 17 07:53:58 server slapd[21476]: => acl_get: [2] attr entry
Feb 17 07:53:58 server slapd[21476]: => acl_mask: access to entry „dc=pg-bs,dc=de“, attr „entry“ requested
Feb 17 07:53:58 server slapd[21476]: => acl_mask: to all values by „“, (=0)
Feb 17 07:53:58 server slapd[21476]: <= check a_dn_pat: *
Feb 17 07:53:58 server slapd[21476]: <= acl_mask: [1] applying read(=rscxd) (stop)
Feb 17 07:53:58 server slapd[21476]: <= acl_mask: [1] mask: read(=rscxd)
Feb 17 07:53:58 server slapd[21476]: => slap_access_allowed: search access granted by read(=rscxd)
Feb 17 07:53:58 server slapd[21476]: => access_allowed: search access granted by read(=rscxd)
Feb 17 07:53:58 server slapd[21476]: search_candidates: base=„dc=pg-bs,dc=de“ (0x00000001) scope=2
Feb 17 07:53:58 server slapd[21476]: => hdb_dn2idl(„dc=pg-bs,dc=de“)
Feb 17 07:53:58 server slapd[21476]: => bdb_filter_candidates
Feb 17 07:53:58 server slapd[21476]: #011AND
Feb 17 07:53:58 server slapd[21476]: => bdb_list_candidates 0xa0
Feb 17 07:53:58 server slapd[21476]: => bdb_filter_candidates
Feb 17 07:53:58 server slapd[21476]: #011OR
Feb 17 07:53:58 server slapd[21476]: => bdb_list_candidates 0xa1
Feb 17 07:53:58 server slapd[21476]: => bdb_filter_candidates
Feb 17 07:53:58 server slapd[21476]: #011EQUALITY
Feb 17 07:53:58 server slapd[21476]: => bdb_equality_candidates (objectClass)
Feb 17 07:53:58 server slapd[21476]: => key_read
Feb 17 07:53:58 server slapd[21476]: bdb_idl_fetch_key: [b49d1940]
Feb 17 07:53:58 server slapd[21476]: <= bdb_index_read: failed (-30987)
Feb 17 07:53:58 server slapd[21476]: <= bdb_equality_candidates: id=0, first=0, last=0
Feb 17 07:53:58 server slapd[21476]: <= bdb_filter_candidates: id=0 first=0 last=0
Feb 17 07:53:58 server slapd[21476]: => bdb_filter_candidates
Feb 17 07:53:58 server slapd[21476]: #011EQUALITY
Feb 17 07:53:58 server slapd[21476]: => bdb_equality_candidates (uid)
Feb 17 07:53:58 server slapd[21476]: => key_read
Feb 17 07:53:58 server slapd[21476]: bdb_idl_fetch_key: [88c0bae4]
Feb 17 07:53:58 server slapd[21476]: <= bdb_index_read 1 candidates
Feb 17 07:53:58 server slapd[21476]: <= bdb_equality_candidates: id=1, first=11, last=11
Feb 17 07:53:58 server slapd[21476]: <= bdb_filter_candidates: id=1 first=11 last=11
Feb 17 07:53:58 server slapd[21476]: <= bdb_list_candidates: id=1 first=11 last=11
Feb 17 07:53:58 server slapd[21476]: <= bdb_filter_candidates: id=1 first=11 last=11
Feb 17 07:53:58 server slapd[21476]: <= bdb_list_candidates: id=1 first=11 last=11
Feb 17 07:53:58 server slapd[21476]: <= bdb_filter_candidates: id=1 first=11 last=11
Feb 17 07:53:58 server slapd[21476]: bdb_search_candidates: id=1 first=11 last=11
Feb 17 07:53:58 server slapd[21476]: => test_filter
Feb 17 07:53:58 server slapd[21476]: EQUALITY
Feb 17 07:53:58 server slapd[21476]: => access_allowed: search access to „uid=wd,ou=accounts,dc=pg-bs,dc=de“ „uid“ requested
Feb 17 07:53:58 server slapd[21476]: => acl_get: [2] attr uid
Feb 17 07:53:58 server slapd[21476]: => acl_mask: access to entry „uid=wd,ou=accounts,dc=pg-bs,dc=de“, attr „uid“ requested
Feb 17 07:53:58 server slapd[21476]: => acl_mask: to value by „“, (=0)
Feb 17 07:53:58 server slapd[21476]: <= check a_dn_pat: *
Feb 17 07:53:58 server slapd[21476]: <= acl_mask: [1] applying read(=rscxd) (stop)
Feb 17 07:53:58 server slapd[21476]: <= acl_mask: [1] mask: read(=rscxd)
Feb 17 07:53:58 server slapd[21476]: => slap_access_allowed: search access granted by read(=rscxd)
Feb 17 07:53:58 server slapd[21476]: => access_allowed: search access granted by read(=rscxd)
Feb 17 07:53:58 server slapd[21476]: <= test_filter 6
Feb 17 07:53:58 server slapd[21476]: => send_search_entry: conn 1310 dn=„uid=wd,ou=accounts,dc=pg-bs,dc=de“
Feb 17 07:53:58 server slapd[21476]: => access_allowed: read access to „uid=wd,ou=accounts,dc=pg-bs,dc=de“ „entry“ requested
Feb 17 07:53:58 server slapd[21476]: => acl_get: [2] attr entry
Feb 17 07:53:58 server slapd[21476]: => acl_mask: access to entry „uid=wd,ou=accounts,dc=pg-bs,dc=de“, attr „entry“ requested
Feb 17 07:53:58 server slapd[21476]: => acl_mask: to all values by „“, (=0)
Feb 17 07:53:58 server slapd[21476]: <= check a_dn_pat: *
Feb 17 07:53:58 server slapd[21476]: <= acl_mask: [1] applying read(=rscxd) (stop)
Feb 17 07:53:58 server slapd[21476]: <= acl_mask: [1] mask: read(=rscxd)
Feb 17 07:53:58 server slapd[21476]: => slap_access_allowed: read access granted by read(=rscxd)
Feb 17 07:53:58 server slapd[21476]: => access_allowed: read access granted by read(=rscxd)
Feb 17 07:53:58 server slapd[21476]: => access_allowed: result not in cache (cn)
Feb 17 07:53:58 server slapd[21476]: => access_allowed: read access to „uid=wd,ou=accounts,dc=pg-bs,dc=de“ „cn“ requested
Feb 17 07:53:58 server slapd[21476]: => acl_get: [2] attr cn
Feb 17 07:53:58 server slapd[21476]: => acl_mask: access to entry „uid=wd,ou=accounts,dc=pg-bs,dc=de“, attr „cn“ requested
Feb 17 07:53:58 server slapd[21476]: => acl_mask: to value by „“, (=0)
Feb 17 07:53:58 server slapd[21476]: <= check a_dn_pat: *
Feb 17 07:53:58 server slapd[21476]: <= acl_mask: [1] applying read(=rscxd) (stop)
Feb 17 07:53:58 server slapd[21476]: <= acl_mask: [1] mask: read(=rscxd)
Feb 17 07:53:58 server slapd[21476]: => slap_access_allowed: read access granted by read(=rscxd)
Feb 17 07:53:58 server slapd[21476]: => access_allowed: read access granted by read(=rscxd)
Feb 17 07:53:58 server slapd[21476]: => access_allowed: result not in cache (uidNumber)
Feb 17 07:53:58 server slapd[21476]: => access_allowed: read access to „uid=wd,ou=accounts,dc=pg-bs,dc=de“ „uidNumber“ requested
Feb 17 07:53:58 server slapd[21476]: => acl_get: [2] attr uidNumber
Feb 17 07:53:58 server slapd[21476]: => acl_mask: access to entry „uid=wd,ou=accounts,dc=pg-bs,dc=de“, attr „uidNumber“ requested
Feb 17 07:53:58 server slapd[21476]: => acl_mask: to value by „“, (=0)
Feb 17 07:53:58 server slapd[21476]: <= check a_dn_pat: *
Feb 17 07:53:58 server slapd[21476]: <= acl_mask: [1] applying read(=rscxd) (stop)
Feb 17 07:53:58 server slapd[21476]: <= acl_mask: [1] mask: read(=rscxd)
Feb 17 07:53:58 server slapd[21476]: => slap_access_allowed: read access granted by read(=rscxd)
Feb 17 07:53:58 server slapd[21476]: => access_allowed: read access granted by read(=rscxd)
Feb 17 07:53:58 server slapd[21476]: => access_allowed: result not in cache (sambaPrimaryGroupSID)
Feb 17 07:53:58 server slapd[21476]: => access_allowed: read access to „uid=wd,ou=accounts,dc=pg-bs,dc=de“ „sambaPrimaryGroupSID“ requested
Feb 17 07:53:58 server slapd[21476]: => acl_get: [2] attr sambaPrimaryGroupSID
Feb 17 07:53:58 server rsyslogd-2177: imuxsock begins to drop messages from pid 21476 due to rate-limiting

Ich kann damit jetzt nicht direkt was anfangen. Liegt es irgendwie doch noch an Samba?

VG
Christian

ChristianWd · 17. Februar 2021 um 07:19

Aha,
ich habe spaßeshalber die IP meines virtuellen Clients in
/etc/ldap/slapd.conf
ergänzt. Die Anmeldung geht nun damit. Aber das war nicht grundsätzlich nötig, oder?

VG
Christian

P.S.: Ich hatte eine Zeile mit dem Hashtag # auskommentiert. Dadurch wurden die Zeilen darunter nicht mehr abgearbeitet, vermute ich. Jedenfalls geht die Anmeldung nun wieder.

Danke fürs Mitdenken.

jrichter · 17. Februar 2021 um 08:07

Hallo Christian,

das ist in der Tat eine Falle: Wenn eine Zeile mit einem Leerzeichen beginnt, dann gilt sie als Fortsetzung der vorherigen. Und ab einem # ist alles bis zum Ende der Zeile ein Kommentar. Und zwar in dieser Reihenfolge. Also wird aus:

Zeile 1
  Zeile 2
  # Zeile 3
  Zeile 4

in einem ersten Schritt:

Zeile 1  Zeile 2  # Zeile 3  Zeile 4

und somit ist auch Zeile 4 im Kommentar.

Beste Grüße

Jörg

ChristianWd · 17. Februar 2021 um 08:10

Hallo Jörg,

genau so war es. Danke für die Erklärung. Dann mache ich den Fehler hoffentlich kein zweites Mal.

Schöne Grüße
Christian