LDAP(AD) Users sync fails - username not populated

Description:

2nd batch of LDAP (AD) users synced however username was not populated.

Server Setup Information:

• Version of Rocket.Chat Server:
  Version | 0.64.2
  Database Migration: 119

• Operating System: CentOS 7.5

• Deployment Method(snap/docker/tar/etc): Tar

• Number of Running Instances: 1

• DB Replicaset Oplog: Not Using Replicaset

• Node Version: 8.9.3

• mongoDB Version: db version v2.6.12 2018-05-29T03:52:04.477+0000 git version: d73c92b1c85703828b55c2916a5dd4ad46535f6a

Steps to Reproduce:

1. Sync Users based using s group filter (in this case memberof=cn=usstaff,ou=security groups,ou=....
2. Everything works
   3.Change User Search Filter to be (employeeid=*) (In my case i am now including all employees)
3. New users populate, however they do not have a username defined (Should be samaccountname just like original batch). email address is populated
4. confirmed no username was populated - in mongo i search for myself (db.getCollection('users').find({username:'mghicas'}) - and this works, when i search for anyone else from the second import.... nothing is returned

Should be noted that before i imported the second batch of users i did a slack message and user import - not sure if that was related - but even users that did not use Slack did not have accounts created correctly

Also - if i manually set a username the user works - but not possible for 1500 users, and the UI stops displaying users after loading more about 10 times

Happy to try this again from scratch -is there a way to dump the config of the RocketChat Server so i don't have to customize the whole thing again?

Expected behavior:

Users would be created with usernames if they don't exist
If they exist and records are incomplete they should update

Actual behavior:

Users created without username and not able to log in

Relevant logs:

Dump from Mongo:

Working User (First Batch) (changed to rxxxxn)
{ "_id" : "z5gvQP295haTvSHak", "createdAt" : { "$date" : "2018-05-25T02:35:16.748+0000" }, "services" : { "ldap" : { "id" : "3065ec1b9933e94aad958fc103f253a6", "idAttribute" : "objectGUID" } }, "username" : "rxxxxn", "emails" : [ { "address" : "RxxxySxxxxn@mycompany.com", "verified" : true } ], "type" : "user", "status" : "offline", "active" : true, "_updatedAt" : { "$date" : "2018-05-26T00:00:08.320+0000" }, "roles" : [ "user" ], "name" : "Rxxxy Sxxxxn", "ldap" : true, "avatarOrigin" : "ldap", "importIds" : [ "U8F5J676Z" ] }
exported 2106 records

Non-working User (2nd Batch):
{ "_id" : "9sL3PiCdqC8GDwSn6", "createdAt" : { "$date" : "2018-05-26T19:06:12.840+0000" }, "services" : { "ldap" : { "id" : "edc1ac0e1d030e40896433d8bfab40f7", "idAttribute" : "objectGUID" } }, "emails" : [ { "address" : "Mxxxxh.Gxxxxn@mycompany.com", "verified" : true } ], "type" : "user", "status" : "offline", "active" : true, "_updatedAt" : { "$date" : "2018-05-26T19:06:13.373+0000" }, "roles" : [ "user" ], "name" : "Mxxxxh Gxxxxxn", "ldap" : true, "avatarOrigin" : "ldap" }

The subsequent LDAP Sync jobs fail with:
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: rocketchat_logger rocketchat_logger.js:278 #033[31mLDAPSync ➔ error#033[39m Error creating user { Error: Email already exists. [403]
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: at handleError (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:189:17)
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: at checkForCaseInsensitiveDuplicates (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:334:7)
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: at createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1241:3)
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: at AccountsServer.Accounts.createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1302:10)
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: at addLdapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1273:31)
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: at ldapUsers.forEach.ldapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1335:9)
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: at Array.forEach (:null:null)
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: at ldap.searchUsersSync.Meteor.bindEnvironment (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1305:15)
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: at runWithEnvironment (packages/meteor.js:1238:24)
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: isClientSafe: true,
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: error: 403,
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: reason: 'Email already exists.',
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: details: undefined,
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: message: 'Email already exists. [403]',
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: errorType: 'Meteor.Error' }
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: rocketchat_logger rocketchat_logger.js:278 #033[31mLDAPSync ➔ error#033[39m Error creating user { Error: Email already exists. [403]
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: at handleError (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:189:17)
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: at checkForCaseInsensitiveDuplicates (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:334:7)
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: at createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1241:3)
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: at AccountsServer.Accounts.createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1302:10)
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: at addLdapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1273:31)
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: at ldapUsers.forEach.ldapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1335:9)
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: at Array.forEach (:null:null)
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: at ldap.searchUsersSync.Meteor.bindEnvironment (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1305:15)
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: at runWithEnvironment (packages/meteor.js:1238:24)
May 29 03:49:55 mghicas-test01 nodejs-rocketchat: isClientSafe: true,

Logs from console:
I20180529-03:28:46.838(0) Updating process.env.MAIL_URL
I20180529-03:28:47.284(0) Starting Email Intercepter...
I20180529-03:28:47.559(0) Will load cache for rocketchat_permissions
I20180529-03:28:47.561(0) 77 records load from rocketchat_permissions
I20180529-03:28:47.566(0) Will load cache for rocketchat_roles
I20180529-03:28:47.567(0) 11 records load from rocketchat_roles
I20180529-03:28:49.209(0) LocalStore: store created at
I20180529-03:28:49.210(0) LocalStore: store created at
I20180529-03:28:49.210(0) LocalStore: store created at
I20180529-03:28:49.588(0) Setting default file store to GridFS
I20180529-03:28:52.359(0) (rocketchat_migrations.js:160) Migrations: Not migrating, already at version 119
I20180529-03:28:52.942(0) Updating process.env.MAIL_URL
I20180529-03:28:53.061(0) Using GridFS for custom sounds storage
I20180529-03:28:53.065(0) Using GridFS for custom emoji storage
I20180529-03:28:54.666(0) ➔ System ➔ startup
I20180529-03:28:54.667(0) ➔ +-----------------------------------------------------+
I20180529-03:28:54.667(0) ➔ | SERVER RUNNING |
I20180529-03:28:54.667(0) ➔ +-----------------------------------------------------+
I20180529-03:28:54.668(0) ➔ | |
I20180529-03:28:54.668(0) ➔ | Rocket.Chat Version: 0.64.2 |
I20180529-03:28:54.668(0) ➔ | NodeJS Version: 8.9.3 - x64 |
I20180529-03:28:54.669(0) ➔ | Platform: linux |
I20180529-03:28:54.669(0) ➔ | Process Port: 3000 |
I20180529-03:28:54.669(0) ➔ | Site URL: https://rchat.dev.ipsoft.com |
I20180529-03:28:54.669(0) ➔ | ReplicaSet OpLog: Disabled |
I20180529-03:28:54.670(0) ➔ | Commit Hash: 105715ef27 |
I20180529-03:28:54.670(0) ➔ | Commit Branch: HEAD |
I20180529-03:28:54.670(0) ➔ | |
I20180529-03:28:54.670(0) ➔ +-----------------------------------------------------+
I20180529-03:31:25.568(0) rocketchat_logger rocketchat_logger.js:278 LDAPSync ➔ error Error creating user { Error: Email already exists. [403] at handleError (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:189:17) at checkForCaseInsensitiveDuplicates (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:334:7) at createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1241:3) at AccountsServer.Accounts.createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1302:10) at addLdapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1273:31) at ldapUsers.forEach.ldapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1335:9) at Array.forEach (:null:null) at ldap.searchUsersSync.Meteor.bindEnvironment (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1305:15) at runWithEnvironment (packages/meteor.js:1238:24) isClientSafe: true, error: 403, reason: 'Email already exists.', details: undefined, message: 'Email already exists. [403]', errorType: 'Meteor.Error' }
I20180529-03:31:25.573(0) rocketchat_logger rocketchat_logger.js:278 LDAPSync ➔ error Error creating user { Error: Email already exists. [403] at handleError (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:189:17) at checkForCaseInsensitiveDuplicates (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:334:7) at createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1241:3) at AccountsServer.Accounts.createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1302:10) at addLdapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1273:31) at ldapUsers.forEach.ldapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1335:9) at Array.forEach (:null:null) at ldap.searchUsersSync.Meteor.bindEnvironment (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1305:15) at runWithEnvironment (packages/meteor.js:1238:24) isClientSafe: true, error: 403, reason: 'Email already exists.', details: undefined, message: 'Email already exists. [403]', errorType: 'Meteor.Error' }
I20180529-03:31:25.578(0) rocketchat_logger rocketchat_logger.js:278 LDAPSync ➔ error Error creating user { Error: Email already exists. [403] at handleError (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:189:17) at checkForCaseInsensitiveDuplicates (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:334:7) at createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1241:3) at AccountsServer.Accounts.createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1302:10) at addLdapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1273:31) at ldapUsers.forEach.ldapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1335:9) at Array.forEach (:null:null) at ldap.searchUsersSync.Meteor.bindEnvironment (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1305:15) at runWithEnvironment (packages/meteor.js:1238:24) isClientSafe: true, error: 403, reason: 'Email already exists.', details: undefined, message: 'Email already exists. [403]', errorType: 'Meteor.Error' }
I20180529-03:31:25.591(0) rocketchat_logger rocketchat_logger.js:278 LDAPSync ➔ error Error creating user { Error: Email already exists. [403] at handleError (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:189:17) at checkForCaseInsensitiveDuplicates (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:334:7) at createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1241:3) at AccountsServer.Accounts.createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1302:10) at addLdapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1273:31) at ldapUsers.forEach.ldapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1335:9) at Array.forEach (:null:null) at ldap.searchUsersSync.Meteor.bindEnvironment (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1305:15) at runWithEnvironment (packages/meteor.js:1238:24) isClientSafe: true, error: 403, reason: 'Email already exists.', details: undefined, message: 'Email already exists. [403]', errorType: 'Meteor.Error' }
I20180529-03:31:25.612(0) rocketchat_logger rocketchat_logger.js:278 LDAPSync ➔ error Error creating user { Error: Email already exists. [403] at handleError (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:189:17) at checkForCaseInsensitiveDuplicates (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:334:7) at createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1241:3) at AccountsServer.Accounts.createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1302:10) at addLdapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1273:31) at ldapUsers.forEach.ldapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1335:9) at Array.forEach (:null:null) at ldap.searchUsersSync.Meteor.bindEnvironment (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1305:15) at runWithEnvironment (packages/meteor.js:1238:24) isClientSafe: true, error: 403, reason: 'Email already exists.', details: undefined, message: 'Email already exists. [403]', errorType: 'Meteor.Error' }
I20180529-03:31:25.615(0) rocketchat_logger rocketchat_logger.js:278 LDAPSync ➔ error Error creating user { Error: Email already exists. [403] at handleError (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:189:17) at checkForCaseInsensitiveDuplicates (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:334:7) at createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1241:3) at AccountsServer.Accounts.createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1302:10) at addLdapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1273:31) at ldapUsers.forEach.ldapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1335:9) at Array.forEach (:null:null) at ldap.searchUsersSync.Meteor.bindEnvironment (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1305:15) at runWithEnvironment (packages/meteor.js:1238:24) isClientSafe: true, error: 403, reason: 'Email already exists.', details: undefined, message: 'Email already exists. [403]', errorType: 'Meteor.Error' }
I20180529-03:31:25.618(0) rocketchat_logger rocketchat_logger.js:278 LDAPSync ➔ error Error creating user { Error: Email already exists. [403] at handleError (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:189:17) at checkForCaseInsensitiveDuplicates (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:334:7) at createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1241:3) at AccountsServer.Accounts.createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1302:10) at addLdapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1273:31) at ldapUsers.forEach.ldapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1335:9) at Array.forEach (:null:null) at ldap.searchUsersSync.Meteor.bindEnvironment (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1305:15) at runWithEnvironment (packages/meteor.js:1238:24) isClientSafe: true, error: 403, reason: 'Email already exists.', details: undefined, message: 'Email already exists. [403]', errorType: 'Meteor.Error' }
I20180529-03:31:25.620(0) rocketchat_logger rocketchat_logger.js:278 LDAPSync ➔ error Error creating user { Error: Email already exists. [403] at handleError (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:189:17) at checkForCaseInsensitiveDuplicates (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:334:7) at createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1241:3) at AccountsServer.Accounts.createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1302:10) at addLdapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1273:31) at ldapUsers.forEach.ldapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1335:9) at Array.forEach (:null:null) at ldap.searchUsersSync.Meteor.bindEnvironment (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1305:15) at runWithEnvironment (packages/meteor.js:1238:24) isClientSafe: true, error: 403, reason: 'Email already exists.', details: undefined, message: 'Email already exists. [403]', errorType: 'Meteor.Error' }
I20180529-03:31:25.634(0) rocketchat_logger rocketchat_logger.js:278 LDAPSync ➔ error Error creating user { Error: Email already exists. [403] at handleError (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:189:17) at checkForCaseInsensitiveDuplicates (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:334:7) at createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1241:3) at AccountsServer.Accounts.createUser (/apps/Rocket.Chat/programs/server/packages/accounts-password.js:1302:10) at addLdapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1273:31) at ldapUsers.forEach.ldapUser (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1335:9) at Array.forEach (:null:null) at ldap.searchUsersSync.Meteor.bindEnvironment (/apps/Rocket.Chat/programs/server/packages/rocketchat_ldap.js:1305:15) at runWithEnvironment (packages/meteor.js:1238:24) isClientSafe: true, error: 403, reason: 'Email already exists.', details: undefined, message: 'Email already exists. [403]', errorType: 'Meteor.Error' }

Start in packages/server/packages/rocketchat_ldap.js at addLdapUser and the LDAP sync callback, then follow the Accounts.createUser path shown in packages/server/packages/accounts-password.js. Reproduce the second-batch sync with an existing email and inspect how incomplete users are handled. Done means LDAP-created or updated users receive usernames and later syncs no longer fail with “Email already exists.”