Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

LDAP Existing user data not updated on Background Sync #13069

Open
ohmonster opened this issue Jan 3, 2019 · 9 comments
Open

LDAP Existing user data not updated on Background Sync #13069

ohmonster opened this issue Jan 3, 2019 · 9 comments
Assignees

Comments

@ohmonster
Copy link
Contributor

Description:

We use LDAP exclusively for user data and authentication. When an existing user logs in, any changes on the LDAP side (avatars and data we map to custom fields), get updated. When we perform a background sync -- manually from Administration or from the cron job -- new users are added. However, users that already exist do not have their data updated.

Steps to reproduce:

  1. Identify an existing user in your RocketChat install.
  2. Change their avatar in Active Directory/LDAP.
  3. Go to Administration>LDAP>Sync/Import
  4. Click Execute Synchronization Now.

Expected behavior:

I expect the user in step 1 above to have a new avatar, matching the one in LDAP. With tracing turned on, I expect to see a log line indicating an avatar was updated.

Actual behavior:

No update to the user takes place. No errors are logged.

Server Setup Information:

  • Version of Rocket.Chat Server: 0.73.1
  • Operating System: Linux Ubuntu 16.04.5 LTS
  • Deployment Method: tar, manual deployment
  • Number of Running Instances: 4
  • DB Replicaset Oplog:
  • NodeJS Version: 8.11.4
  • MongoDB Version: 3.6.6

LDAP settings

LDAP Enable: true
Login Fallback: false
Find user after login: true
Merge Existing users: true
Logging: trace
Sync user data: true
Sync user avatar: true
Background sync: true
Background Sync import new users: true
Background sync update existing users: true

Relevant logs:

Here is the log from the code that doesn't work.
�[34mI20190103-16:39:39.300(-6) LDAP ➔ Connection.info Init setup �[34mI20190103-16:39:39.304(-6) LDAP ➔ Connection.info Connecting ldap://corp.perfect-10.tv:389 �[34mI20190103-16:39:39.310(-6) LDAP ➔ Connection.info LDAP connected �[34mI20190103-16:39:39.311(-6) LDAP ➔ Bind.info Binding UserDN MIS_Wiki@corp.perfect-10.tv �[34mI20190103-16:39:39.316(-6) LDAP ➔ Search.info Searching user * �[34mI20190103-16:39:40.874(-6) LDAP ➔ Search.info Page �[34mI20190103-16:39:40.874(-6) LDAP ➔ Search.info Page �[34mI20190103-16:39:41.289(-6) LDAPSync ➔ info Import running. Users imported until now: 100 �[34mI20190103-16:39:41.405(-6) LDAPSync ➔ info Import running. Users imported until now: 200 �[34mI20190103-16:39:42.168(-6) LDAP ➔ Search.info Final Page �[34mI20190103-16:39:42.170(-6) LDAP ➔ Search.info Final Page �[34mI20190103-16:39:42.204(-6) LDAPSync ➔ info Import running. Users imported until now: 300 �[34mI20190103-16:39:42.273(-6) LDAPSync ➔ info Import running. Users imported until now: 400 �[34mI20190103-16:39:42.344(-6) LDAPSync ➔ info Import running. Users imported until now: 500 �[34mI20190103-16:39:42.407(-6) LDAPSync ➔ info Import running. Users imported until now: 600 �[34mI20190103-16:39:42.455(-6) LDAPSync ➔ info Import finished. Users imported: 662 �[34mI20190103-16:39:42.456(-6) LDAPSync ➔ info Import finished. Users imported: 662 �[34mI20190103-16:39:43.456(-6) LDAP ➔ Search.info Idle �[34mI20190103-16:39:43.458(-6) LDAP ➔ Connection.info Disconecting �[34mI20190103-16:39:43.460(-6) LDAP ➔ Search.info Closed

@ohmonster
Copy link
Contributor Author

FYI, I have a commit pending for this -- I just have to sort out my fork's branches.

@reetp
Copy link

reetp commented Jan 4, 2019

What a perfect bug report.
This should be used as an example to others.

@ohmonster
Copy link
Contributor Author

@reetp I wrote it backwards. I identified the code, fixed it, and then wrote the bug report. I put the references to the lines of code in the PR to make the issue more readable, to increase the chance a less technical person could recognize their own situation.

I don’t consider it a stellar bug report example precisely because I wrote it with hindsight on my side and the code ready to go. I knew what details were relevant from my own hunt. And I was freed from needing to sell the bug as valid and solvable.

The ldap sync features have so many permutations of chat server and ldap server configs that it is more likely it would have been closed due to the obnoxiousness of reproducing it.

What this issue does do is offer insight to justify my PR. Which is why I followed the template.

@rodrigok
Copy link
Member

@ohmonster did you marked the setting Background Sync Update Existing Users as true?

@ohmonster
Copy link
Contributor Author

Yes

@rodrigok
Copy link
Member

@ohmonster what happens if you disable the Background Sync Import New Users, keep Background Sync Update Existing Users enabled, go to Logs > Log Level and set to 2 and run the LDAP import again? What are the logs?

@ohmonster
Copy link
Contributor Author

@rodrigok when I make those changes, and click the button on the LDAP settings page, it has essentially the same effect -- users I expect to see updated are not updated, but new users are imported.

However, in looking at the code again, it looks as if the cron job uses a code block not called by anything else -- sync.js, function sync().

So I bumped my Background Sync Interval to a higher frequency, and watched that. At that point, users I would expect to have updates. But the logs aren't very informative. Here's a sample: �[34mI20190121-15:10:47.637(-6) �[34mLDAPSync ➔ info Syncing user data �[34mI20190121-15:10:47.638(-6) �[34mLDAPSync ➔ debug user { email: undefined, _id: 'xqRDTM3v4fjPjfP5S' } �[34mI20190121-15:10:47.639(-6) �[34mLDAPSync ➔ debug ldapUser undefined �[34mI20190121-15:10:47.640(-6) �[34mTemplateVarHandler ➔ debug user does not have attribute: facsimileTelephoneNumber �[34mI20190121-15:10:47.641(-6) �[34mTemplateVarHandler ➔ debug user does not have attribute: mobile �[34mI20190121-15:10:47.643(-6) �[34mLDAP ➔ Search.info Searching by id 8228fbab1cd83342ac1fbcaaaf991c89 �[34mI20190121-15:10:47.645(-6) �[34mLDAP ➔ Search.debug search filter (objectGUID=�\28����3B��������) �[34mI20190121-15:10:47.646(-6) �[34mLDAP ➔ Search.debug BaseDN OU=Domain Users,DC=Corp,DC=Perfect-10,DC=tv �[34mI20190121-15:10:47.654(-6) �[34mLDAP ➔ Search.info Search result count 1 �[34mI20190121-15:10:47.656(-6) �[34mLDAPSync ➔ info Syncing user data �[34mI20190121-15:10:47.657(-6) �[34mLDAPSync ➔ debug user { email: undefined, _id: 'TSKybZ9iGrXYPCPEE' } �[34mI20190121-15:10:47.658(-6) �[34mLDAPSync ➔ debug ldapUser undefined �[34mI20190121-15:10:47.659(-6) �[34mTemplateVarHandler ➔ debug user does not have attribute: telephoneNumber �[34mI20190121-15:10:47.660(-6) �[34mTemplateVarHandler ➔ debug user does not have attribute: ipPhone �[34mI20190121-15:10:47.661(-6) �[34mTemplateVarHandler ➔ debug user does not have attribute: homePhone �[34mI20190121-15:10:47.663(-6) �[34mTemplateVarHandler ➔ debug user does not have attribute: facsimileTelephoneNumber �[34mI20190121-15:10:47.664(-6) �[34mSyncedCron ➔ info Finished "LDAP_Sync".

@saschafoerster
Copy link

+1

@Hudell Hudell self-assigned this Aug 21, 2019
@rodrigok rodrigok assigned pierre-lehnen-rc and unassigned Hudell Sep 19, 2019
@github88-sys
Copy link

same problem. mark.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

7 participants