LDAP Synchronization was Succcessfull but User's e-mail does not change

Levent Kalay

2018-05-02 09:58:22,975 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DbCachingRemoteDirectory] INCREMENTAL synchronisation for directory [ 10000 ] starting
2018-05-02 09:58:22,975 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DbCachingRemoteDirectory] Attempting INCREMENTAL synchronisation for directory [ 10000 ]
2018-05-02 09:58:22,975 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DbCachingRemoteDirectory] Incremental synchronisation for directory [ 10000 ] was not completed, falling back to a full synchronisation
2018-05-02 09:58:22,975 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DbCachingRemoteDirectory] INCREMENTAL synchronisation for directory [ 10000 ] was not successful, attempting FULL
2018-05-02 09:58:25,300 Caesium-1-1 INFO ServiceRunner [c.a.c.directory.ldap.SpringLdapTemplateWrapper] Timed call for search with handler on ou=Users,dc=dpt,dc=gov,dc=tr took 2324ms
2018-05-02 09:58:25,315 Caesium-1-1 INFO ServiceRunner [c.a.c.d.ldap.cache.RemoteDirectoryCacheRefresher] found [ 60192 ] remote users in [ 2339 ms ]
2018-05-02 09:58:26,237 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DbCachingRemoteChangeOperations] scanned and compared [ 60192 ] users for delete in DB cache in [ 922ms ]
2018-05-02 09:58:26,238 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DbCachingRemoteChangeOperations] deleting [ 3 ] users
2018-05-02 09:58:26,249 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DbCachingRemoteChangeOperations] deleted [ 3 ] users in [ 11ms ]
2018-05-02 09:58:26,249 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DbCachingRemoteChangeOperations] scanned for deleted users in [ 934ms ]
2018-05-02 09:58:26,783 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DbCachingRemoteChangeOperations] scanning [ 60192 ] users to add or update
2018-05-02 09:58:26,819 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DirectoryCacheImplUsingChangeOperations] scanned and compared [ 60192 ] users for update in DB cache in [ 570ms ]
2018-05-02 09:58:26,819 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DbCachingRemoteChangeOperations] updating [ 1 ] users
2018-05-02 09:58:26,830 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DbCachingRemoteChangeOperations] updated [ 1 ] users successfully in [ 11ms ]
2018-05-02 09:58:26,830 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DbCachingRemoteChangeOperations] adding [ 10 ] users
2018-05-02 09:58:26,925 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DbCachingRemoteChangeOperations] added [ 10 ] users successfully in [ 95ms ]
2018-05-02 09:58:26,925 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DirectoryCacheImplUsingChangeOperations] synchronised [ 60192 ] users in [ 676ms ]
2018-05-02 09:58:30,895 Caesium-1-1 INFO ServiceRunner [c.a.c.directory.ldap.SpringLdapTemplateWrapper] Timed call for search with handler on ou=Groups,dc=dpt,dc=gov,dc=tr took 3970ms
2018-05-02 09:58:30,895 Caesium-1-1 INFO ServiceRunner [c.a.c.d.ldap.cache.RemoteDirectoryCacheRefresher] found [ 33 ] remote groups in [ 3970 ms ]
2018-05-02 09:58:30,898 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DbCachingRemoteChangeOperations] scanned and compared [ 33 ] groups for delete in DB cache in [ 3ms ]
2018-05-02 09:58:30,898 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DirectoryCacheImplUsingChangeOperations] scanning [ 33 ] groups to add or update
2018-05-02 09:58:30,900 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DbCachingRemoteChangeOperations] scanned and compared [ 33 ] groups for update in DB cache in [ 2ms ]
2018-05-02 09:58:30,900 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DirectoryCacheImplUsingChangeOperations] synchronized [ 33 ] groups in [ 2ms ]
2018-05-02 09:58:30,912 Caesium-1-1 INFO ServiceRunner [c.a.c.d.ldap.cache.AbstractCacheRefresher] finished group attribute sync with 0 failures in [ 12ms ]
2018-05-02 09:58:33,310 Caesium-1-1 INFO ServiceRunner [c.a.c.directory.ldap.SpringLdapTemplateWrapper] Timed call for search with handler on ou=Users,dc=dpt,dc=gov,dc=tr took 2398ms
2018-05-02 09:58:34,553 Caesium-1-1 INFO ServiceRunner [c.a.c.directory.ldap.SpringLdapTemplateWrapper] Timed call for search with handler on ou=Users,dc=dpt,dc=gov,dc=tr took 1050ms
2018-05-02 09:58:35,566 Caesium-1-1 INFO ServiceRunner [c.a.c.directory.ldap.SpringLdapTemplateWrapper] Timed call for search with handler on ou=Users,dc=dpt,dc=gov,dc=tr took 1008ms
2018-05-02 09:58:36,611 Caesium-1-1 INFO ServiceRunner [c.a.c.directory.ldap.SpringLdapTemplateWrapper] Timed call for search with handler on ou=Users,dc=dpt,dc=gov,dc=tr took 1041ms
2018-05-02 09:58:45,950 Caesium-1-1 INFO ServiceRunner [c.a.c.directory.ldap.SpringLdapTemplateWrapper] Timed call for search with handler on ou=Users,dc=dpt,dc=gov,dc=tr took 1161ms
2018-05-02 09:58:46,992 Caesium-1-1 INFO ServiceRunner [c.a.c.directory.ldap.SpringLdapTemplateWrapper] Timed call for search with handler on ou=Users,dc=dpt,dc=gov,dc=tr took 1040ms
2018-05-02 09:58:48,020 Caesium-1-1 INFO ServiceRunner [c.a.c.directory.ldap.SpringLdapTemplateWrapper] Timed call for search with handler on ou=Users,dc=dpt,dc=gov,dc=tr took 1027ms
2018-05-02 09:58:50,837 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DbCachingRemoteChangeOperations] removed [ 1 ] user members from [ IKY ] in [ 7ms ]
2018-05-02 09:58:58,355 Caesium-1-1 INFO ServiceRunner [c.a.c.directory.ldap.SpringLdapTemplateWrapper] Timed call for search with handler on ou=Users,dc=dpt,dc=gov,dc=tr took 1002ms
2018-05-02 09:59:02,149 Caesium-1-1 INFO ServiceRunner [c.a.c.directory.ldap.SpringLdapTemplateWrapper] Timed call for search with handler on ou=Users,dc=dpt,dc=gov,dc=tr took 1048ms
2018-05-02 09:59:05,791 Caesium-1-1 INFO ServiceRunner [c.a.c.directory.ldap.SpringLdapTemplateWrapper] Timed call for lookup with mapper on cn=BS,ou=Groups,dc=dpt,dc=gov,dc=tr took 3641ms
2018-05-02 09:59:06,510 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DbCachingRemoteChangeOperations] removed [ 1 ] user members from [ BS ] in [ 40ms ]
2018-05-02 09:59:08,618 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DbCachingRemoteChangeOperations] removed [ 1 ] user members from [ PYB ] in [ 12ms ]
2018-05-02 09:59:10,403 Caesium-1-1 INFO ServiceRunner [c.a.crowd.directory.DbCachingRemoteDirectory] FULL synchronisation complete for directory [ 10000 ] in [ 47428ms ]

Andy Heinzer

This particular log does not indicate what records might have been changed.  But it does show users getting both added and other removed.    I would be interested to see what the Jira database has in regards to both the old email address and the new email address in question.   You could use a SQL query such as:

select * from cwd_user where lower_email_address='user@example.com';

You could then change the email address there and see what results come back in the system.   If you have a user record with the old email, and another new record with the new email address, then it would appear that Jira is syncing this data, but it could be creating a new account in order to do so.  I only really see this when the username is changed, This tends to happen when the directory setup in Jira is not using the correct UniqueID value for the LDAP directory type.   But I would also be interested to learn if this username exists in both LDAP and in the Jira internal directory.  If this happens, LDAP can update user accounts that only exist in that directory, but if the account also exists in the internal Jira user directory, an LDAP sync might not change the values for that user account.    When you run that SQL query, it will return a directory_id value for each record.  A value of 1 here is the Jira internal directory.  It looks like your LDAP has a directory_id value of 10000 for this directory.

However if you cannot find any user accounts with this new email address, and you are sure it has been changed on this LDAP instance, then I would instead focus on the particular settings you have in Jira for this user directory, but this time look for the 'User Email Attribute'.  This is the attribute in your LDAP that identifies which field contains the user's email address.  I suspect that either Jira is configured to look at the incorrect LDAP attribute, or that the LDAP server might have different attributes to store this data.