0013632: LDAP user backend: groups are not synced

[Gloirin]

Reported by kneip on 20 Nov 2017 16:50

Version: 2017.08.8 Community Edition

Neue Installation, Benutzerverwaltung via LDAP. Login für die Nutzer funktioniert.
Nach dem initialen Import eines Users werden die Gruppenmitgliedschaften nicht mehr synchronisiert.
Um einen Nutzer in neue Gruppen hinzuzufügen, muss

1. er gelöscht und danach

2. php /usr/share/tine20/setup.php -c /etc/tine20/config.inc.php --sync_accounts_from_ldap

erneut ausgeführt werden.

Steps to reproduce: Benutzerverwaltung via LDAP einrichten, Gruppenmitgliedschaften nach erstem Import ändern.

php /usr/share/tine20/setup.php -c /etc/tine20/config.inc.php --sync_accounts_from_ldap ausführen, wundern, warum die Gruppenmitgliedschaften nicht aktualisiert werden.

Additional information: 389ds, free-ipa

[Gloirin]

Comment posted by lab-at-nohl on 21 Nov 2017 11:17

Unterstützt 389ds das Attribut "entryUUID", oder ist das was openLdap spezifisches? Wenn du in die Datenbank schaust, wie sehen die Id der Benutzer und Gruppen aus?

Alternativ kann man im Setup einstellen, dass der Benutzer/Gruppen-Sync nach Name, nicht nach Id erfolgt. Schafft das Abhilfe?

[Gloirin]

Comment posted by kneip on 24 Nov 2017 09:03

Moin,

389ds nutzt hier in der vorliegenden Umgebung gidNumber/uidNumber, das lässt sich ja auch im Setup konfigurieren.
Beim initialen Sync nach dem Anlegen eines Users passen ja auch die Gruppenmitgliedschaften, nur weitere Veränderungen an den Gruppen-Mitgliedschaften im LDAP spiegeln sich in tine20 nicht wieder.
Wenn man den betreffenden Nutzer in tine20 löscht (noch ist tine20 hier nicht produktiv) und danach erneut den sync triggert, passen auch wieder die Gruppenmitgliedschaften.

Etwas DEBUG-Log versuche ich gerade zusammenzustellen.

Viele Grüße,

Bernhard

[Gloirin]

Comment posted by kneip on 24 Nov 2017 09:25

Hier ein interessantes Stück Log:

Test-User "headroom" (UID 4999) existiert in tine20, wurde im LDAP aus der Gruppe "developers" (GID 1001) entfernt und darauf ein erneuter Sync angestoßen. Das Log zeigt das Entfernen aus der Gruppe bei den User-Attributen, das Entfernen des Nutzers aus der Member-Liste der Gruppe, dann in den letzten beiden Log-Einträgen ist die UID jedoch wieder dabei - so meine laienhafte Interpretation des Logs. Am Schluss bleibt der User headroom zumindestens im UI Mitglied der Gruppe "developers".

9166d setupuser - 2017-11-24T08:57:11+00:00 TRACE (8): Tinebase_Group_Ldap::getGroupMembershipsFromSyncBackend::1019 ldap search filter: (&(objectclass=posixgroup)(|(memberuid=headroom)(member=uid=headroom,cn=users,cn=accounts,dc=ipa,dc=example,dc=com)))
9166d setupuser - 2017-11-24T08:57:11+00:00 TRACE (8): Tinebase_Group_Ldap::getGroupMembershipsFromSyncBackend::1042 group memberships: Array
(
[0] => 100
[1] => 1002
)

9166d setupuser - 2017-11-24T08:57:11+00:00 DEBUG (7): Tinebase_Group::syncMemberships::190 Set new group memberships: Array
(
[0] => 100
[1] => 1002
)

9166d setupuser - 2017-11-24T08:57:11+00:00 TRACE (8): Tinebase_Group_Sql::setGroupMembershipsInSqlBackend::305 current groupmemberships: Array
(
[0] => 100
[1] => 1001
[2] => 1002
)

9166d setupuser - 2017-11-24T08:57:11+00:00 TRACE (8): Tinebase_Group_Sql::setGroupMembershipsInSqlBackend::306 new groupmemberships: Array
(
[0] => 100
[1] => 1002
)

9166d setupuser - 2017-11-24T08:57:11+00:00 TRACE (8): Tinebase_Group_Sql::setGroupMembershipsInSqlBackend::307 added groupmemberships: Array
(
)

9166d setupuser - 2017-11-24T08:57:11+00:00 TRACE (8): Tinebase_Group_Sql::setGroupMembershipsInSqlBackend::308 removed groupmemberships: Array
(
[1] => 1001
)

9166d setupuser - 2017-11-24T08:57:11+00:00 DEBUG (7): Tinebase_Controller_Record_ModlogTrait::_writeModLog::71 Writing modlog for Tinebase_Model_Group
9166d setupuser - 2017-11-24T08:57:11+00:00 TRACE (8): Tinebase_Record_Abstract::diff::1053 Found diff for members(this/other):Array
(
[0] => 2000
[1] => 2001
[2] => 2005
[3] => 2018
[4] => 2022
[5] => 2023
[6] => 2032
[7] => 2039
[8] => 2043
[9] => 2047
[10] => 2049
[11] => 2050
[12] => 2054
[13] => 2064
[14] => 2065
[15] => 2067
[16] => 2068
[17] => 2069
[18] => 2070
[19] => 4999
)
/Array
(
[0] => 2000
[1] => 2001
[2] => 2005
[3] => 2018
[4] => 2022
[5] => 2023
[6] => 2032
[7] => 2039
[8] => 2043
[9] => 2047
[10] => 2049
[11] => 2050
[12] => 2054
[13] => 2064
[14] => 2065
[15] => 2067
[16] => 2068
[17] => 2069
[18] => 2070
)

9166d setupuser - 2017-11-24T08:57:11+00:00 TRACE (8): Tinebase_Record_RecordSet::_getMatchingRecords::592 Filtering field 'name' of 'Tinebase_Model_Application' without indices, expecting slow results
9166d setupuser - 2017-11-24T08:57:11+00:00 TRACE (8): Tinebase_Timemachine_ModificationLog::writeModLog::846 Diffs: Array
(
[members] => Array
(
[0] => 2000
[1] => 2001
[2] => 2005
[3] => 2018
[4] => 2022
[5] => 2023
[6] => 2032
[7] => 2039
[8] => 2043
[9] => 2047
[10] => 2049
[11] => 2050
[12] => 2054
[13] => 2064
[14] => 2065
[15] => 2067
[16] => 2068
[17] => 2069
[18] => 2070
)

)

9166d setupuser - 2017-11-24T08:57:11+00:00 TRACE (8): Tinebase_Timemachine_ModificationLog::writeModLog::848 CurRecord: Array
(
[id] => 1001
[members] => Array
(
[0] => 2000
[1] => 2001
[2] => 2005
[3] => 2018
[4] => 2022
[5] => 2023
[6] => 2032
[7] => 2039
[8] => 2043
[9] => 2047
[10] => 2049
[11] => 2050
[12] => 2054
[13] => 2064
[14] => 2065
[15] => 2067
[16] => 2068
[17] => 2069
[18] => 2070
[19] => 4999
)

)

9166d setupuser - 2017-11-24T08:57:11+00:00 TRACE (8): Tinebase_Timemachine_ModificationLog::writeModLog::850 NewRecord: Array
(
[id] => 1001
[members] => Array
(
[0] => 2000
[1] => 2001
[2] => 2005
[3] => 2018
[4] => 2022
[5] => 2023
[6] => 2032
[7] => 2039
[8] => 2043
[9] => 2047
[10] => 2049
[11] => 2050
[12] => 2054
[13] => 2064
[14] => 2065
[15] => 2067
[16] => 2068
[17] => 2069
[18] => 2070
)

)

9166d setupuser - 2017-11-24T08:57:11+00:00 TRACE (8): Tinebase_Timemachine_ModificationLog::writeModLog::852 Common modlog: Array
(
[application_id] => 351eedbde20d97c0fe0d139e0bc122f07b10427c
[record_id] => 1001
[record_type] => Tinebase_Model_Group
[record_backend] => Sql
[modification_time] => 2017-11-24 08:57:11
[modification_account] => dbe631cf7bf90d7b3d429499f61664eb45a8f796
[seq] => 0
[client] => - no http user agent present
[new_value] => {"id":"1001","model":"Tinebase_Model_Group","diff":{"members":["2000","2001","2005","2018","2022","2023","2032","2039","2043","2047","2049","2050","2054","2064","2065","2067","2068","2069","2070"]},"oldData":{"members":["2000","2001","2005","2018","2022","2023","2032","2039","2043","2047","2049","2050","2054","2064","2065","2067","2068","2069","2070","4999"]}}
[change_type] => updated
)

9166d setupuser - 2017-11-24T08:57:11+00:00 TRACE (8): Tinebase_Timemachine_ModificationLog::setModification::488 Inserting modlog: Array
(
[change_type] => updated
[application_id] => 351eedbde20d97c0fe0d139e0bc122f07b10427c
[record_id] => 1001
[record_type] => Tinebase_Model_Group
[record_backend] => Sql
[modification_time] => 2017-11-24 08:57:11
[modification_account] => dbe631cf7bf90d7b3d429499f61664eb45a8f796
[new_value] => {"id":"1001","model":"Tinebase_Model_Group","diff":{"members":["2000","2001","2005","2018","2022","2023","2032","2039","2043","2047","2049","2050","2054","2064","2065","2067","2068","2069","2070"]},"oldData":{"members":["2000","2001","2005","2018","2022","2023","2032","2039","2043","2047","2049","2050","2054","2064","2065","2067","2068","2069","2070","4999"]}}
[seq] => 0
[client] => - no http user agent present
[id] => 1c6e23b976eae1da5b45c96d2cf3b592b693d72a
)

[Gloirin]

Comment posted by kneip on 29 Nov 2017 14:29

Fehlt hier noch etwas von meiner Seite? Das Debug-Log habe ich als private Notiz hinzugefügt, dies ist doch für Euch einsehbar?

Viele Grüße,
Bernhard

[Gloirin]

Comment posted by kneip on 1 Dec 2017 10:40

Beobachtung:

Ein Lauf von
php /usr/share/tine20/setup.php -c /etc/tine20/config.inc.php --sync_accounts_from_ldap

updated zwar die Tabelle "tine20_group_members" korrekt, jedoch wird zumindest im Admin-Modul nicht der Status der aktualisierten Tabelle wiedergespiegelt.
Browser-Cache kann ich ausschließen (mit anderem Browser getestet).

Folgender Ablauf zum Nachstellen:

User headroom Mitglied der Gruppen 100, 1001, 1002, finden sich in der sql Tabelle und auch im Webinterface wieder:

MariaDB [tine20]> select * from tine20_group_members where account_id='4999';

+----------+------------+
| group_id | account_id |
+----------+------------+
| 100 | 4999 |
| 1001 | 4999 |
| 1002 | 4999 |
+----------+------------+
3 rows in set (0.00 sec)

• User headroom wird im LDAP aus der Gruppe 1001 entfernt, ein Lauf von
  php /usr/share/tine20/setup.php -c /etc/tine20/config.inc.php --sync_accounts_from_ldap
  ausgeführt.

Korrekt aktualisiert in der Tabelle:
MariaDB [tine20]> select * from tine20_group_members where account_id='4999';
+----------+------------+
| group_id | account_id |
+----------+------------+
| 100 | 4999 |
| 1002 | 4999 |
+----------+------------+
2 rows in set (0.01 sec)

Jedoch NICHT im Webinterface selber.

[Gloirin]

Comment posted by kneip on 1 Dec 2017 10:48

Caching als Ursache ausgemacht:

cd /var/lib/tine20/cache
mkdir backup
mv zend* backup

Nun sind die Gruppen auch effektiv aktualisiert.
Vorschlag: Cache nach der Synchronisation zumindestens bei veränderten Gruppenmitgliedschaften invalidieren.

[Gloirin]

Comment posted by pschuele on 4 Jan 2018 14:17

> Vorschlag: Cache nach der Synchronisation zumindestens bei veränderten Gruppenmitgliedschaften invalidieren.

ja, dem stimme ich zu. werde mich darum kümmern.

[Gloirin]

Comment posted by pschuele on 4 Jan 2018 14:41

https://gerrit.tine20.com/customers/7269