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

findUser error: "In order to perform this operation a successful bind must be completed on the connection." #78

Closed
kevinleedrum opened this issue May 18, 2015 · 42 comments

Comments

@kevinleedrum
Copy link

This error occurred during findUser after updating to 0.6.5. I reinstalled 0.6.3, and the error went away.

@gheeres
Copy link
Owner

gheeres commented May 18, 2015

Can you post the sample code you are using?

I just went through my tests and I'm not getting any errors or failures.

@kevinleedrum
Copy link
Author

    var ad = activeDirectory({
        url: 'ldap://server',
        baseDN: 'DC=ABC,DC=LOCAL',
        username: 'ldapuser@abc',
        password: 'ldappass'
    });
    ad.authenticate('johndoe', 'johnspassword', function(err, auth) {
        if (auth) {
            ad.findUser('johndoe', function(err, user) {
                if (err) {
                    console.log(JSON.stringify(err));
                }
                // ...
            });
        }
    });

@gheeres
Copy link
Owner

gheeres commented May 18, 2015

Thanks for the code sample. But sorry, I still can't replicate the problem. That code works for me, although 'johndoe' needs to be a userPrincipalName (johndoe@abc) for the authenticate to work.

Do you have any referrals configured for active directory?

Can you post the full stack trace / error?

Optionally, can you enable the bunyan logging?

To configure bunyan, change your AD config to include a 'logging' property:

var adConfig = {
    url: url,
    baseDN: baseDN,
    username: username,
    password: password,
    logging: {
      name: 'ActiveDirectory',
      streams: [
        { level: 'debug',
          stream: process.stdout }
      ]
    }
  }

@kevinleedrum
Copy link
Author

OperationsError: 000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1
    at messageCallback (C:\fgsapps\node_modules\activedirectory\node_modules\ldapjs\lib\client\client.js:867:40)
    at Parser.onMessage (C:\fgsapps\node_modules\activedirectory\node_modules\ldapjs\lib\client\client.js:199:12)
    at Parser.emit (events.js:107:17)
    at Parser.write (C:\fgsapps\node_modules\activedirectory\node_modules\ldapjs\lib\messages\parser.js:105:8)
    at Socket.onData (C:\fgsapps\node_modules\activedirectory\node_modules\ldapjs\lib\client\client.js:155:24)
    at Socket.emit (events.js:107:17)
    at readableAddChunk (_stream_readable.js:163:16)
    at Socket.Readable.push (_stream_readable.js:126:10)
    at TCP.onread (net.js:538:20)


{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":6500,"level":30,"msg":"Using username/password (ldapuser@abc/********) to bind to ActiveDirectory (ldap://server).","time":"2015-05-19T13:21:43.781Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":6500,"level":30,"msg":"Referrals are disabled","time":"2015-05-19T13:21:43.782Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":6500,"level":30,"msg":"Default user attributes: [\"userPrincipalName\",\"sAMAccountName\",\"mail\",\"lockoutTime\",\"whenCreated\",\"pwdLastSet\",\"userAccountControl\",\"employeeID\",\"sn\",\"givenName\",\"initials\",\"cn\",\"displayName\",\"comment\",\"description\"]","time":"2015-05-19T13:21:43.783Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":6500,"level":30,"msg":"Default group attributes: [\"objectCategory\",\"distinguishedName\",\"cn\",\"description\",\"member\"]","time":"2015-05-19T13:21:43.783Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":6500,"level":20,"msg":"Creating ldapjs client for ldap://server. Opts: {}","time":"2015-05-19T13:21:43.784Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":6500,"level":30,"msg":"Authentication succeeded for \"ldap://server\" as \"johndoe@abc\" (password: \"********\")","time":"2015-05-19T13:21:43.799Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":6500,"level":20,"msg":"Creating ldapjs client for ldap://server. Opts: {\"filter\":\"(&(objectCategory=User)(|(sAMAccountName=johndoe)(userPrincipalName=johndoe)))\",\"scope\":\"sub\",\"attributes\":[\"userPrincipalName\",\"sAMAccountName\",\"mail\",\"lockoutTime\",\"whenCreated\",\"pwdLastSet\",\"userAccountControl\",\"employeeID\",\"sn\",\"givenName\",\"initials\",\"cn\",\"displayName\",\"comment\",\"description\"]}","time":"2015-05-19T13:21:43.801Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":6500,"level":20,"msg":"Adding PagedResultControl to search (DC=ABC,DC=LOCAL) with filter \"(&(objectCategory=User)(|(sAMAccountName=johndoe)(userPrincipalName=johndoe)))\" for [\"userPrincipalName\",\"sAMAccountName\",\"mail\",\"lockoutTime\",\"whenCreated\",\"pwdLastSet\",\"userAccountControl\",\"employeeID\",\"sn\",\"givenName\",\"initials\",\"cn\",\"displayName\",\"comment\",\"description\"]","time":"2015-05-19T13:21:43.803Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":6500,"level":20,"msg":"Querying active directory (DC=ABC,DC=LOCAL) with filter \"(&(objectCategory=User)(|(sAMAccountName=johndoe)(userPrincipalName=johndoe)))\" for [\"userPrincipalName\",\"sAMAccountName\",\"mail\",\"lockoutTime\",\"whenCreated\",\"pwdLastSet\",\"userAccountControl\",\"employeeID\",\"sn\",\"givenName\",\"initials\",\"cn\",\"displayName\",\"comment\",\"description\"]","time":"2015-05-19T13:21:43.804Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":6496,"level":50,"err":{"message":"000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1\u0000","name":"OperationsError","stack":"OperationsError: 000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1\u0000\n    at messageCallback (C:\\fgsapps\\node_modules\\activedirectory\\node_modules\\ldapjs\\lib\\client\\client.js:867:40)\n    at Parser.onMessage (C:\\fgsapps\\node_modules\\activedirectory\\node_modules\\ldapjs\\lib\\client\\client.js:199:12)\n    at Parser.emit (events.js:107:17)\n    at Parser.write (C:\\fgsapps\\node_modules\\activedirectory\\node_modules\\ldapjs\\lib\\messages\\parser.js:105:8)\n    at Socket.onData (C:\\fgsapps\\node_modules\\activedirectory\\node_modules\\ldapjs\\lib\\client\\client.js:155:24)\n    at Socket.emit (events.js:107:17)\n    at readableAddChunk (_stream_readable.js:163:16)\n    at Socket.Readable.push (_stream_readable.js:126:10)\n    at TCP.onread (net.js:538:20)","code":1},"msg":"[UNKNOWN] An error occurred performing the requested LDAP search on DC=ABC,DC=LOCAL ({\"filter\":\"(&(objectCategory=User)(|(sAMAccountName=johndoe)(userPrincipalName=johndoe)))\",\"scope\":\"sub\",\"attributes\":[\"userPrincipalName\",\"sAMAccountName\",\"mail\",\"lockoutTime\",\"whenCreated\",\"pwdLastSet\",\"userAccountControl\",\"employeeID\",\"sn\",\"givenName\",\"initials\",\"cn\",\"displayName\",\"comment\",\"description\"],\"controls\":[{\"_value\":{\"size\":1000},\"type\":\"1.2.840.113556.1.4.319\",\"criticality\":false,\"value\":{\"size\":1000},\"json\":{\"controlType\":\"1.2.840.113556.1.4.319\",\"criticality\":false,\"controlValue\":{\"size\":1000}}}]})","time":"2015-05-19T13:48:31.848Z","v":0}

@kevinleedrum
Copy link
Author

I installed 0.6.4, and without changing any code, this is the bunyan log (names have been changed to protect the innocent):

{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":7224,"level":30,"msg":"Using username/password (ldapuser@abc/********) to bind to ActiveDirectory (ldap://server).","time":"2015-05-19T14:00:08.119Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":7224,"level":30,"msg":"Referrals are disabled","time":"2015-05-19T14:00:08.120Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":7224,"level":30,"msg":"Default user attributes: [\"userPrincipalName\",\"sAMAccountName\",\"mail\",\"lockoutTime\",\"whenCreated\",\"pwdLastSet\",\"userAccountControl\",\"employeeID\",\"sn\",\"givenName\",\"initials\",\"cn\",\"displayName\",\"comment\",\"description\"]","time":"2015-05-19T14:00:08.121Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":7224,"level":30,"msg":"Default group attributes: [\"objectCategory\",\"distinguishedName\",\"cn\",\"description\",\"member\"]","time":"2015-05-19T14:00:08.121Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":7224,"level":20,"msg":"Creating ldapjs client for ldap://server. Opts: {\"baseDN\":\"DC=ABC,DC=LOCAL\",\"username\":\"ldapuser@abc\",\"password\":\"ldapuser\",\"maxConnections\":20}","time":"2015-05-19T14:00:08.122Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":7224,"level":30,"msg":"Authentication succeeded for \"ldap://server\" as \"johndoe@abc\" (password: \"********\")","time":"2015-05-19T14:00:08.161Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":7224,"level":20,"msg":"Creating ldapjs client for ldap://server. Opts: {\"baseDN\":\"DC=ABC,DC=LOCAL\",\"username\":\"ldapuser@abc\",\"password\":\"ldapuser\",\"maxConnections\":20}","time":"2015-05-19T14:00:08.163Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":7224,"level":20,"msg":"Adding PagedResultControl to search (DC=ABC,DC=LOCAL) with filter \"(&(objectCategory=User)(|(sAMAccountName=johndoe)(userPrincipalName=johndoe)))\" for [\"userPrincipalName\",\"sAMAccountName\",\"mail\",\"lockoutTime\",\"whenCreated\",\"pwdLastSet\",\"userAccountControl\",\"employeeID\",\"sn\",\"givenName\",\"initials\",\"cn\",\"displayName\",\"comment\",\"description\"]","time":"2015-05-19T14:00:08.164Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":7224,"level":20,"msg":"Querying active directory (DC=ABC,DC=LOCAL) with filter \"(&(objectCategory=User)(|(sAMAccountName=johndoe)(userPrincipalName=johndoe)))\" for [\"userPrincipalName\",\"sAMAccountName\",\"mail\",\"lockoutTime\",\"whenCreated\",\"pwdLastSet\",\"userAccountControl\",\"employeeID\",\"sn\",\"givenName\",\"initials\",\"cn\",\"displayName\",\"comment\",\"description\"]","time":"2015-05-19T14:00:08.165Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":7224,"level":30,"msg":"Active directory search (DC=ABC,DC=LOCAL) for \"(&(objectCategory=User)(|(sAMAccountName=johndoe)(userPrincipalName=johndoe)))\" returned 1 entries.","time":"2015-05-19T14:00:08.190Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":7224,"level":30,"msg":"1 user(s) found for query \"(&(objectCategory=User)(|(sAMAccountName=johndoe)(userPrincipalName=johndoe)))\". Returning first user: {\"dn\":\"CN=John Doe,OU=Domain Users,OU=Company,DC=abc,DC=local\",\"cn\":\"John Doe\",\"sn\":\"Doe\",\"description\":\"Software Engineer\",\"givenName\":\"John\",\"whenCreated\":\"20060821142146.0Z\",\"displayName\":\"John Doe\",\"userAccountControl\":\"512\",\"pwdLastSet\":\"130696373214064123\",\"sAMAccountName\":\"JohnDoe\",\"userPrincipalName\":\"JohnDoe@abc.local\",\"lockoutTime\":\"0\",\"mail\":\"JohnDoe@company.com\"}","time":"2015-05-19T14:00:08.190Z","v":0}

@roysjosh
Copy link

I see this also on 0.6.5. Going back to 0.6.4 results in a working app. I switched from ldaps:// to ldap:// while on 0.6.5 and did a packet capture and saw that there was no longer a bind on the connection before searching. All my code does is call .authenticate and then .findUser.

@gheeres
Copy link
Owner

gheeres commented May 19, 2015

Hmm... I can't replicate this. Are you also running on Windows?

@roysjosh
Copy link

No, Linux.

@kevinleedrum
Copy link
Author

I'm a total noob, but if it matters, Opts is empty in the 0.6.5 bunyan log when creating the ldapjs client for authentication (and not empty in the 0.6.4 log).

@gheeres
Copy link
Owner

gheeres commented May 19, 2015

Yeah. That is what I'm looking at right now. However, in my tests where I pass in a custom opts object as well as the default opts, I am seeing the same opts output.

@gheeres
Copy link
Owner

gheeres commented May 19, 2015

What version of node are you using?

@roysjosh
Copy link

0.10.36

@gheeres
Copy link
Owner

gheeres commented May 19, 2015

OK. Same here.

@kevinleedrum
Copy link
Author

0.12.2

@gheeres
Copy link
Owner

gheeres commented May 19, 2015

I pushed some updated code to the git repository. Adding a console.log statement to see what is happening with the opts parsing.

Please clone the latest GIT repository.
Please post the results.

createClient("ldap://domain.com")->{"url":"ldap://domain.com"}
[2015-05-19T15:07:17.106Z] DEBUG: ActiveDirectory/943 on devel1: Creating ldapjs client for ldap://domain.com. Opts: {}
[2015-05-19T15:07:17.125Z]  INFO: ActiveDirectory/943 on devel1: Authentication succeeded for "ldap://domain.com" as "user@domain.com" (password: "********")
Authenticated...
createClient("ldap://domain.com")->{"url":"ldap://domain.com","bindDN":"username@domain.com","bindCredentials":"password"}

In particular, I'm looking for the createClient() output line.

@gheeres
Copy link
Owner

gheeres commented May 19, 2015

Here is the test code that I am using. Perhaps I'm doing something different and not seeing the subtle difference? This would be so much easier to fix if I could replicate the problem...

var _ = require('../node_modules/underscore');
var config = require('./config').config;
var activeDirectory = new (require('../index'))(config);
var ad = activeDirectory;

var username = 'user@domain.com';
var password = 'password';

ad.authenticate(username, password, function(err, auth) {
  if (err) {
    console.log('ERROR: '+JSON.stringify(err));
    return;
  }

  if (auth) {
    console.log('Authenticated...');
    ad.findUser(username, function(err, user) {
      if (err) {
        console.log('ERROR: ' +JSON.stringify(err));
        return;
      }

      if (! user) console.log('User: ' + username + ' not found.');
      else console.log(JSON.stringify(user));
    });
  }
  else {
    console.log('Authentication failed!');
  }
});

Where the config.js file contains:

var url = 'ldap://domain.com';
var baseDN = 'dc=domain,dc=com';
var username = 'auth@domain.com';
var password = 'authpassword';

module.exports = {
  url: url,
  baseDN: baseDN,
  username: username,
  password: password,

  config: {
    url: url,
    baseDN: baseDN,
    username: username,
    password: password,
    logging: {
      name: 'ActiveDirectory',
      streams: [
        { level: 'debug',
          stream: process.stdout }
      ]
    }
  }
};

I also have a secondary test that was in response to issue #77, which is nearly identical. The primary difference being that I clear our the preconfigured username/password and then pass in secondary authentication via the opts.

var _ = require('../node_modules/underscore');
var config = require('./config').config;
// Here we exclude the preconfigured username/password
var activeDirectory = new (require('../index'))(_.omit(config, 'username', 'password'));
var ad = activeDirectory;

var username = 'user@domain.com';
var password = 'password';

ad.authenticate(username, password, function(err, auth) {
  if (err) {
    console.log('ERROR: '+JSON.stringify(err));
    return;
  }

  if (auth) {
    console.log('Authenticated...');

    var opts = {
      bindDN: username,
      bindCredentials: password
    };
    ad.findUser(opts, username, function(err, user) {
      if (err) {
        console.log('ERROR: ' +JSON.stringify(err));
        return;
      }

      if (! user) console.log('User: ' + username + ' not found.');
      else console.log(JSON.stringify(user));
    });
  }
  else {
    console.log('Authentication failed!');
  }
});

Both of these test cases work.

@roysjosh
Copy link

I think our AD at my work does not allow anonymous binds. Basically, you have to bind before searching for anything. That may be an option you can enable on your AD in order to replicate this?

@gheeres
Copy link
Owner

gheeres commented May 19, 2015

My AD doesn't allow anonymous searches either. You MUST bind before doing a search.

In my example output, you can see the bindDN and bindCredentials being passed:

createClient("ldap://domain.com")->{"url":"ldap://domain.com","bindDN":"username@domain.com","bindCredentials":"password"}

The first call to createClient is empty because we want to bind manually on an authenticate method call binding instead with the username/password that was provided.

For all operations in node-activedirectory, except authenticate() and getRootDSE(), the username/password that are specified when you configure and create your AD object are used for the binding operations.

Issue #77 added support to allow for alternate binding to be specified for all method calls via the opts object.

@gheeres
Copy link
Owner

gheeres commented May 19, 2015

Did you do a test run with the updated version on the GIT repository?
Have you tried using the code that I provided for testing?

@roysjosh
Copy link

createClient("ldap://XXX")->{"url":"ldap://XXX","bindDN":"XXX","bindCredentials":"XXX"}
Authenticated...
createClient("ldap://XXX")->{"url":"ldap://XXX","bindDN":"XXX","bindCredentials":"XXX"}
ERROR: {"dn":"","code":1,"name":"OperationsError","message":"000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1\u0000"}
ERROR: {}
ERROR: {}
ERROR: {}
ERROR: {}
[... lots more of these ...]
ERROR: {"code":"ECONNRESET","errno":"ECONNRESET","syscall":"read"}```

@roysjosh
Copy link

A packet dump again shows an immediate search without a bind. Modifying the example to add tlsOptions { ca: ... } and switching to ldaps:// show the same results (although there are the tlsOptions in the printed debug).

@kevinleedrum
Copy link
Author

Here are the stack and debug log using the latest build. I got the same results when I tried passing the bindDN and bindCredentials into findUser() via opts.

createClient("ldap://server")->{"url":"ldap://server","bindDN":"ldapuser@abc","bindCredentials":"ldappass"}
createClient("ldap://server")->{"url":"ldap://server","bindDN":"ldapuser@abc","bindCredentials":"ldappass"}
OperationsError: 000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1
    at messageCallback (C:\fgsapps\node_modules\activedirectory\node_modules\ldapjs\lib\client\client.js:867:40)
    at Parser.onMessage (C:\fgsapps\node_modules\activedirectory\node_modules\ldapjs\lib\client\client.js:199:12)
    at Parser.emit (events.js:107:17)
    at Parser.write (C:\fgsapps\node_modules\activedirectory\node_modules\ldapjs\lib\messages\parser.js:105:8)
    at Socket.onData (C:\fgsapps\node_modules\activedirectory\node_modules\ldapjs\lib\client\client.js:155:24)
    at Socket.emit (events.js:107:17)
    at readableAddChunk (_stream_readable.js:163:16)
    at Socket.Readable.push (_stream_readable.js:126:10)
    at TCP.onread (net.js:538:20)

{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":4160,"level":30,"msg":"Using username/password (ldapuser@abc/********) to bind to ActiveDirectory (ldap://server).","time":"2015-05-19T16:39:24.633Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":4160,"level":30,"msg":"Referrals are disabled","time":"2015-05-19T16:39:24.638Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":4160,"level":30,"msg":"Default user attributes: [\"userPrincipalName\",\"sAMAccountName\",\"mail\",\"lockoutTime\",\"whenCreated\",\"pwdLastSet\",\"userAccountControl\",\"employeeID\",\"sn\",\"givenName\",\"initials\",\"cn\",\"displayName\",\"comment\",\"description\"]","time":"2015-05-19T16:39:24.639Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":4160,"level":30,"msg":"Default group attributes: [\"objectCategory\",\"distinguishedName\",\"cn\",\"description\",\"member\"]","time":"2015-05-19T16:39:24.639Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":4160,"level":20,"msg":"Creating ldapjs client for ldap://server. Opts: {}","time":"2015-05-19T16:39:24.641Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":4160,"level":30,"msg":"Authentication succeeded for \"ldap://server\" as \"johndoe@abc\" (password: \"********\")","time":"2015-05-19T16:39:24.673Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":4160,"level":20,"msg":"Creating ldapjs client for ldap://server. Opts: {}","time":"2015-05-19T16:39:24.673Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":4160,"level":20,"msg":"Adding PagedResultControl to search (DC=abc,DC=LOCAL) with filter \"(&(objectCategory=User)(|(sAMAccountName=johndoe)(userPrincipalName=johndoe)))\" for [\"userPrincipalName\",\"sAMAccountName\",\"mail\",\"lockoutTime\",\"whenCreated\",\"pwdLastSet\",\"userAccountControl\",\"employeeID\",\"sn\",\"givenName\",\"initials\",\"cn\",\"displayName\",\"comment\",\"description\"]","time":"2015-05-19T16:39:24.673Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":4160,"level":20,"msg":"Querying active directory (DC=abc,DC=LOCAL) with filter \"(&(objectCategory=User)(|(sAMAccountName=johndoe)(userPrincipalName=johndoe)))\" for [\"userPrincipalName\",\"sAMAccountName\",\"mail\",\"lockoutTime\",\"whenCreated\",\"pwdLastSet\",\"userAccountControl\",\"employeeID\",\"sn\",\"givenName\",\"initials\",\"cn\",\"displayName\",\"comment\",\"description\"]","time":"2015-05-19T16:39:24.673Z","v":0}
{"name":"ActiveDirectory","hostname":"MYLAPTOP","pid":4160,"level":50,"err":{"message":"000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1\u0000","name":"OperationsError","stack":"OperationsError: 000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1\u0000\n    at messageCallback (C:\\fgsapps\\node_modules\\activedirectory\\node_modules\\ldapjs\\lib\\client\\client.js:867:40)\n    at Parser.onMessage (C:\\fgsapps\\node_modules\\activedirectory\\node_modules\\ldapjs\\lib\\client\\client.js:199:12)\n    at Parser.emit (events.js:107:17)\n    at Parser.write (C:\\fgsapps\\node_modules\\activedirectory\\node_modules\\ldapjs\\lib\\messages\\parser.js:105:8)\n    at Socket.onData (C:\\fgsapps\\node_modules\\activedirectory\\node_modules\\ldapjs\\lib\\client\\client.js:155:24)\n    at Socket.emit (events.js:107:17)\n    at readableAddChunk (_stream_readable.js:163:16)\n    at Socket.Readable.push (_stream_readable.js:126:10)\n    at TCP.onread (net.js:538:20)","code":1},"msg":"[UNKNOWN] An error occurred performing the requested LDAP search on DC=abc,DC=LOCAL ({\"filter\":\"(&(objectCategory=User)(|(sAMAccountName=johndoe)(userPrincipalName=johndoe)))\",\"scope\":\"sub\",\"attributes\":[\"userPrincipalName\",\"sAMAccountName\",\"mail\",\"lockoutTime\",\"whenCreated\",\"pwdLastSet\",\"userAccountControl\",\"employeeID\",\"sn\",\"givenName\",\"initials\",\"cn\",\"displayName\",\"comment\",\"description\"],\"controls\":[{\"_value\":{\"size\":1000},\"type\":\"1.2.840.113556.1.4.319\",\"criticality\":false,\"value\":{\"size\":1000},\"json\":{\"controlType\":\"1.2.840.113556.1.4.319\",\"criticality\":false,\"controlValue\":{\"size\":1000}}}]})","time":"2015-05-19T16:39:24.704Z","v":0}

@roysjosh
Copy link

A quick grep through ldapjs/lib/client/ for bindDN only hits in pool.js... some quick debugs show that with 0.6.5/6 the code path in ldapjs/lib/client/index.js returns the new Client(options) while 0.6.4 selects the ClientPool.

@roysjosh
Copy link

Adding more debug in ldapjs/lib/client/index.js shows that 0.6.5/6 omit the maxConnections parameter (where 0.6.4 included it and many others) to createClient causing the selection of the non-pool Client.

@gheeres
Copy link
Owner

gheeres commented May 19, 2015

Checking my client libraries, I'm actually using the v0.7.1 ldapjs client....
What version are you using?

@roysjosh
Copy link

adtest@0.0.1 /dev/shm/2
└─┬ activedirectory@0.6.5
  ├── async@0.9.2
  ├─┬ bunyan@1.3.5
  │ ├─┬ dtrace-provider@0.4.0
  │ │ └── nan@1.5.3
  │ ├─┬ mv@2.0.3
  │ │ ├─┬ mkdirp@0.5.1
  │ │ │ └── minimist@0.0.8
  │ │ ├── ncp@0.6.0
  │ │ └── rimraf@2.2.8
  │ └── safe-json-stringify@1.0.3
  ├─┬ ldapjs@0.7.1
  │ ├── asn1@0.2.1
  │ ├── assert-plus@0.1.5
  │ ├─┬ bunyan@0.22.1
  │ │ └── mv@0.0.5
  │ ├─┬ nopt@2.1.1
  │ │ └── abbrev@1.0.5
  │ └─┬ pooling@0.4.6
  │   ├── once@1.3.0
  │   └─┬ vasync@1.4.0
  │     ├─┬ jsprim@0.3.0
  │     │ ├── extsprintf@1.0.0
  │     │ ├── json-schema@0.2.2
  │     │ └── verror@1.3.3
  │     └─┬ verror@1.1.0
  │       └── extsprintf@1.0.0
  └── underscore@1.8.3

@gheeres
Copy link
Owner

gheeres commented May 19, 2015

I'm going to assuming applying the following diff:

diff --git a/lib/activedirectory.js b/lib/activedirectory.js
index 6715e98..c074c3d 100755
--- a/lib/activedirectory.js
+++ b/lib/activedirectory.js
@@ -288,7 +288,7 @@ function createClient(url, opts) {
   log.trace('createClient(%s)', url);

 console.log('createClient('+JSON.stringify(url) + ')->'+JSON.stringify(getLdapClientOpts(_.defaults({}, { url: url }, opts, this.opts))));
-  var opts = getLdapClientOpts(_.defaults({}, { url: url }, opts, this.opts));
+  var opts = getLdapClientOpts(_.defaults({}, { url: url }, this.opts));
   log.debug('Creating ldapjs client for %s. Opts: %j', opts.url, _.omit(opts, 'url', 'bindDN', 'bindCredentials'));
   var client = ldap.createClient(opts);
   return(client);

Resolves the problem? It should ignore the extra opts parsing that was recently added.

But doing that removes the new features that were added. Grr... this is frustrating why I can't replicate the problem locally.

@roysjosh
Copy link

Nope, non-pool Client is still selected.

$ sed -ne '/var opts = get/ p' node_modules/activedirectory/lib/activedirectory.js 
  var opts = getLdapClientOpts(_.defaults({}, { url: url }, this.opts));

@roysjosh
Copy link

It looks like, as you mention in a comment in your code, that the pooled client will be removed with the next ldapjs release... at which point, the same createClient() instance will need to be saved in your code so that a bind (authenticate) can be called followed by a search (e.g. findUser) through your API. Otherwise it will not be possible to perform a search on a bound client :(

@roysjosh
Copy link

@gheeres
Copy link
Owner

gheeres commented May 19, 2015

re: Nope, non-pool Client is still selected.

So with the patch I provided, you're still getting the client bind error?

@roysjosh
Copy link

Correct. I applied that diff on top of 0.6.6. If I also delete the getLdapClientOpts() on that same line, it works.

@gheeres
Copy link
Owner

gheeres commented May 19, 2015

What was the output from the console.log for "createClient"? I'm trying to figure out what opts are getting dropped, etc.

@roysjosh
Copy link

This issue seems to be caused by the dropping of maxConnections from the opts which is still valid in ldapjs 0.7.1. Your code sets maxConnections to 20 if it isn't supplied by the caller. Currently that parameter (when > 1) causes createClient to use a ldapjs pooled client which automatically binds to the bindDN. The non-pooled client does not do that in ldapjs 0.7.1. In ldapjs master, maxConnections is removed but the non-pooled client will bind to the bindDN automatically.

@roysjosh
Copy link

But here is the output. Non-working:

createClient("ldaps://XXX")->{"url":"ldaps://XXX","tlsOptions":{"ca":[...]},"bindDN":"XXX","bindCredentials":"XXX"}
createClient options
{ url: 'ldaps://XXX
  tlsOptions: { ca: <Buffer ...> },
  bindDN: 'XXX',
  bindCredentials: '' }
REGULAR CLIENT
Authenticated...
createClient("ldaps://XXX")->{"url":"ldaps://XXX","tlsOptions":{"ca":[...]},"bindDN":"XXX","bindCredentials":"XXX"}
createClient options
{ url: 'ldaps://XXX
  tlsOptions: { ca: <Buffer ...> },
  bindDN: 'XXX',
  bindCredentials: '' }
REGULAR CLIENT
ERROR: {"dn":"","code":1,"name":"OperationsError","message":"000004DC:
LdapErr: DSID-0C0906E8, comment: In order to perform this operation a
successful bind must be completed on the connection., data 0, v1db1\u0000"}
ERROR: {"code":"ECONNRESET","errno":"ECONNRESET","syscall":"read"}

Working:

createClient("ldaps://XXX")->{"url":"ldaps://XXX","tlsOptions":{"ca":[]},"bindDN":"XXX","bindCredentials":"XXX"}
createClient options
{ url: 'ldaps://XXX
  baseDN: 'XXX',
  username: 'XXX',
  password: 'XXX',
  tlsOptions: { ca: <Buffer ...> },
  bindDN: 'XXX',
  bindCredentials: 'XXX',
  maxConnections: 20 }
CLIENT POOL
Authenticated...
createClient("ldaps://XXX")->{"url":"ldaps://XXX","tlsOptions":{"ca":[]},"bindDN":"XXX","bindCredentials":"XXX"}
createClient options
{ url: 'ldaps://XXX
  baseDN: 'XXX',
  username: 'XXX',
  password: 'XXX',
  tlsOptions: { ca: <Buffer ...> },
  bindDN: 'XXX',
  bindCredentials: 'XXX',
  maxConnections: 20 }
CLIENT POOL
{"dn":"CN=Roys\\, Joshua ..."}

I added in the REGULAR CLIENT and CLIENT POOL debug lines in the ldapjs code at lib/client/index.js around the if (options.maxConnections > 1).

@roysjosh
Copy link

Oh, I also added the "createClient options" \n options debug splats in the same file in order to see what was actually being passed. You can see the addition of a ton of parameters.

@gheeres
Copy link
Owner

gheeres commented May 19, 2015

This issue seems to be caused by the dropping of maxConnections from the opts which is still valid in ldapjs 0.7.1.

Yes. I think you are right. Before reading your previous message I was looking at the output and noticed that immediately and it makes sense.

Can you apply the following patch:

index 6715e98..ed2315f 100755
--- a/lib/activedirectory.js
+++ b/lib/activedirectory.js
@@ -287,8 +287,11 @@ function createClient(url, opts) {
   }
   log.trace('createClient(%s)', url);

-console.log('createClient('+JSON.stringify(url) + ')->'+JSON.stringify(getLdapClientOpts(_.defaults({}, { url: url }, opts, this.opts))));
+console.log('createClient BEFORE('+JSON.stringify(url) + ')->'+ JSON.stringify(opts || this.opts));
   var opts = getLdapClientOpts(_.defaults({}, { url: url }, opts, this.opts));
+//  var opts = _.defaults({}, { url: url }, this.opts);
+//console.log('createClient AFTER('+JSON.stringify(url) + ')->'+JSON.stringify(getLdapClientOpts(_.defaults({}, { url: url }, opts, this.opts))));
+console.log('createClient AFTER('+JSON.stringify(url) + ')->'+JSON.stringify(opts));
   log.debug('Creating ldapjs client for %s. Opts: %j', opts.url, _.omit(opts, 'url', 'bindDN', 'bindCredentials'));
   var client = ldap.createClient(opts);
   return(client);
@@ -333,7 +336,8 @@ function getLdapClientOpts(opts) {
     'host', 'port', 'secure', 'tlsOptions',
     'socketPath', 'log', 'timeout', 'idleTimeout',
     'reconnect', 'queue', 'queueSize', 'queueTimeout',
-    'queueDisable', 'bindDN', 'bindCredentials'
+    'queueDisable', 'bindDN', 'bindCredentials',
+    'maxConnections'
   ));
 }

I added the 'maxConnections' to the list of supported ldapjs values.

@gheeres
Copy link
Owner

gheeres commented May 20, 2015

Commit: 420c6cf

@gheeres gheeres closed this as completed May 20, 2015
@kevinleedrum
Copy link
Author

Thanks!!!

@Earl-Brown
Copy link

I am having this same problem ... WIndows 10, Node 6.5.0; I have verified my version of activeDirectory has the content of commit 420c6cf

One thing that was a stumbling block is that I don't see anywhere in the documentation that says "findUser must run inside the authenticate() callback", which is implied by the working tests from the comment "gheeres commented on May 19, 2015"

my "npm ls" says this about my activeDirectory installation:

+-- activedirectory@0.7.2
| +-- async@2.0.1
| | `-- lodash@4.16.2
| +-- bunyan@1.8.1
| | +-- dtrace-provider@0.6.0
| | | `-- nan@2.4.0
| | +-- moment@2.15.1
| | +-- mv@2.1.1
| | | +-- mkdirp@0.5.1
| | | | `-- minimist@0.0.8
| | | +-- ncp@2.0.0
| | | `-- rimraf@2.4.5
| | |   `-- glob@6.0.4
| | |     +-- inflight@1.0.5
| | |     +-- minimatch@3.0.3
| | |     | `-- brace-expansion@1.1.6
| | |     |   +-- balanced-match@0.4.2
| | |     |   `-- concat-map@0.0.1
| | |     +-- once@1.4.0
| | |     `-- path-is-absolute@1.0.0
| | `-- safe-json-stringify@1.0.3
| +-- ldapjs@1.0.0
| | +-- asn1@0.2.3
| | +-- assert-plus@0.1.5
| | +-- backoff@2.4.1
| | | `-- precond@0.2.3
| | +-- bunyan@1.5.1
| | +-- dashdash@1.10.1
| | +-- ldap-filter@0.2.2
| | | `-- assert-plus@0.1.5
| | +-- once@1.3.2
| | | `-- wrappy@1.0.2
| | +-- vasync@1.6.3
| | | `-- verror@1.6.0
| | |   `-- extsprintf@1.2.0
| | `-- verror@1.6.0
| |   `-- extsprintf@1.2.0
| `-- underscore@1.8.3

I'll keep trying to figure out what I'm doing wrong, but I am hopeful someone will be able to help he mere!

@gheeres
Copy link
Owner

gheeres commented Sep 28, 2016

"findUser must run inside the authenticate() callback"

The findUser() does not need to be run inside of the authenticate() method. findUser() will use the credentials that were passed in when the ActiveDirectory object was created.

There have been instances where users have wanted to avoid having a special lookup account where they wanted the findUser() to run in the context of the person that had just logged on. In that case, you would need to have it inside of the authenticate() method. This is an advanced scenario.

The problem is likely that you are not initializing your ActiveDirectory object correctly. You must specify a valid username/password. This is an account that has permissions to view / search the entire active directory domain. It is typically NOT the user that is logged in, etc.

var ad = activeDirectory({
        url: 'ldap://server',
        baseDN: 'DC=ABC,DC=LOCAL',
        username: 'ldapuser@abc',
        password: 'ldappass'
    });

@Earl-Brown
Copy link

Earl-Brown commented Sep 28, 2016

Thanks - I'll try some more :)

ETA: Thanks - that helped my understanding a lot. With that and the SysInternals "Active Directory Explorer" tool, I was able to figure out the proper configuration to get this working.

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

No branches or pull requests

4 participants