[Date Prev][Date Next] [Chronological] [Thread] [Top]
Re: Normal User Binding Problem?

To: "Aaron M. Hirsch" <Aaron.Hirsch@atosorigin.com>
Subject: Re: Normal User Binding Problem?
From: "Chris St. Pierre" <cas1650@NebrWesleyan.edu>
Date: Mon, 09 Feb 2004 15:51:36 -0600 (CST)
Cc: Openldap list <openldap-software@OpenLDAP.org>
In-reply-to: <4027D47D.7010101@atosorigin.com>
References: <4024FFDD.8010208@atosorigin.com> <4027D47D.7010101@atosorigin.com>
I'm having a very similar -- possibly identical -- problem.  I, too, can bind
as anonymous or as manager, but not as a real user.  Interestingly, I can
actually *login* to the server as a regular user, and it Does The Right Thing,
validating against LDAP, and I can finger, ls -l works, etc.  But if I try to
do an ldapsearch, I get the same output as Aaron (right down to the same debug
information).  I've also enclosed the output to my logfile (with -d 385) in
hopes that it might help get this figured out.  Thanks

Chris

***********slapd logfile*************

ldap_pvt_gethostbyname_a: host=students.NebrWesleyan.edu, r=0
put_filter: "(objectclass=*)"
put_filter: simple
put_simple_filter: "objectclass=*"
ber_scanf fmt (m) ber:
conn=0 fd=9 ACCEPT from IP=10.12.1.6:48969 (IP=0.0.0.0:389)
connection_get(9): got connid=0
connection_read(9): checking for input on id=0
ber_get_next
ber_get_next: tag 0x30 len 76 contents:
do_bind
ber_get_next
ber_get_next on fd 9 failed errno=11 (Resource temporarily unavailable)
ber_scanf fmt ({imt) ber:
ber_scanf fmt (m}) ber:
>>> dnPrettyNormal: <uid=cas1650,ou=People,dc=students,dc=NebrWesleyan,dc=edu>
=> ldap_bv2dn(uid=cas1650,ou=People,dc=students,dc=NebrWesleyan,dc=edu,0)
<= ldap_bv2dn(uid=cas1650,ou=People,dc=students,dc=NebrWesleyan,dc=edu,0)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(uid=cas1650,ou=People,dc=students,dc=NebrWesleyan,dc=edu,272)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(uid=cas1650,ou=people,dc=students,dc=nebrwesleyan,dc=edu,272)=0
<<< dnPrettyNormal:
<uid=cas1650,ou=People,dc=students,dc=NebrWesleyan,dc=edu>,
<uid=cas1650,ou=people,dc=students,dc=nebrwesleyan,dc=edu>
do_bind: version=3
dn="uid=cas1650,ou=People,dc=students,dc=NebrWesleyan,dc=edu" method=128
conn=0 op=0 BIND dn="uid=cas1650,ou=People,dc=students,dc=NebrWesleyan,dc=edu"
method=128
dn2entry_r: dn: "uid=cas1650,ou=people,dc=students,dc=nebrwesleyan,dc=edu"
=> dn2id( "uid=cas1650,ou=people,dc=students,dc=nebrwesleyan,dc=edu" )
=> ldbm_cache_open( "dn2id.dbb", 73, 600 )
<= ldbm_cache_open (opened 0)
<= dn2id 93
=> id2entry_r( 93 )
=> ldbm_cache_open( "id2entry.dbb", 73, 600 )
<= ldbm_cache_open (opened 1)
=> str2entry
>>> dnPrettyNormal: <uid=cas1650,ou=People,dc=students,dc=NebrWesleyan,dc=edu>
=> ldap_bv2dn(uid=cas1650,ou=People,dc=students,dc=NebrWesleyan,dc=edu,0)
<= ldap_bv2dn(uid=cas1650,ou=People,dc=students,dc=NebrWesleyan,dc=edu,0)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(uid=cas1650,ou=People,dc=students,dc=NebrWesleyan,dc=edu,272)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(uid=cas1650,ou=people,dc=students,dc=nebrwesleyan,dc=edu,272)=0
<<< dnPrettyNormal:
<uid=cas1650,ou=People,dc=students,dc=NebrWesleyan,dc=edu>,
<uid=cas1650,ou=people,dc=students,dc=nebrwesleyan,dc=edu>
<= str2entry(uid=cas1650,ou=People,dc=students,dc=NebrWesleyan,dc=edu) ->
0x1011c130
<= id2entry_r( 93 ) 0x1011c130 (disk)
=> access_allowed: auth access to
"uid=cas1650,ou=People,dc=students,dc=NebrWesleyan,dc=edu" "userPassword"
requested
=> acl_get: [1] check attr userPassword
<= acl_get: [1] acl uid=cas1650,ou=People,dc=students,dc=NebrWesleyan,dc=edu
attr: userPassword
=> acl_mask: access to entry
"uid=cas1650,ou=People,dc=students,dc=NebrWesleyan,dc=edu", attr
"userPassword" requested
=> acl_mask: to all values by "", (=n)
<= check a_dn_pat: self
<= check a_dn_pat: uid=root,ou=People,dc=students,dc=NebrWesleyan,dc=edu
=> string_expand: pattern:
uid=root,ou=People,dc=students,dc=NebrWesleyan,dc=edu
=> string_expand: expanded:
uid=root,ou=People,dc=students,dc=NebrWesleyan,dc=edu
=> regex_matches: string:
=> regex_matches: rc: 1 no matches
<= check a_dn_pat: *
<= acl_mask: [3] applying auth(=x) (stop)
<= acl_mask: [3] mask: auth(=x)
=> access_allowed: auth access granted by auth(=x)
send_ldap_result: conn=0 op=0 p=3
send_ldap_response: msgid=1 tag=97 err=49
ber_flush: 14 bytes to sd 9
connection_get(9): got connid=0
connection_read(9): checking for input on id=0
ber_get_next
ber_get_next on fd 9 failed errno=0 (Success)
connection_read(9): input error=-2 id=0, closing.
connection_closing: readying conn=0 sd=9 for close
connection_close: deferring conn=0 sd=9
conn=0 op=0 RESULT tag=97 err=49 text=
====> cache_return_entry_r( 93 ): created (0)
connection_resched: attempting closing conn=0 sd=9
connection_close: conn=0 sd=9
conn=0 fd=9 closed



On Mon, 9 Feb 2004, Aaron M. Hirsch wrote:

>-----BEGIN PGP SIGNED MESSAGE-----
>Hash: SHA1
>
>
>| I have an RedHat ES 3.0 server running OpenSSL 0.9.7c, DB-4.2.52,
>| Cyrus-SASL-2.1.17, and OpenLDAP-2.2.4. I have the server running
>| and am able to bind as "manager" and "anonymous", however when I
>| try to bind to the server as an actual "user", i.e. myself ahirsch,
>| I get a connection refused with the following information:
>|
>| slapd starting daemon: added 6r daemon: added 7r daemon: select:
>| listen=6 active_threads=0 tvp=NULL daemon: select: listen=7
>| active_threads=0 tvp=NULL daemon: activity on 1 descriptors daemon:
>| new connection on 10 ldap_pvt_gethostbyname_a: host=konldap1, r=0
>| conn=0 fd=10 ACCEPT from IP=148.80.180.89:33755 (IP=0.0.0.0:389)
>| daemon: added 10r daemon: activity on: daemon: select: listen=6
>| active_threads=0 tvp=NULL daemon: select: listen=7 active_threads=0
>| tvp=NULL daemon: activity on 1 descriptors daemon: activity on: 10r
>| daemon: read activity on 10 connection_get(10) connection_get(10):
>| got connid=0 connection_read(10): checking for input on id=0
>| ber_get_next ldap_read: want=8, got=8 ~ 0000: 30 31 02 01 01 60
>| 2c 02 01...`,. ldap_read: want=43,
>| got=43 ~ 0000: 01 03 04 1d 63 6e 3d 61 68 69 72 73 63 68 2c 20
>| ....cn=ahirsch, ~ 0010: 64 63 3d 63 65 6c 6c 6e 65 74 2c 64 63
>| 3d 63 6f dc=cellnet,dc=co ~ 0020: 6d 80 08 31 52 44 54 63 24 64
>| 62 m..password ber_get_next: tag 0x30 len 49 contents: ber_dump:
>| buf=0x081ed2c8 ptr=0x081ed2c8 end=0x081ed2f9 len=49 ~ 0000: 02 01
>| 01 60 2c 02 01 03 04 1d 63 6e 3d 61 68 69 ...`,.....cn=ahi ~
>| 0010: 72 73 63 68 2c 20 64 63 3d 63 65 6c 6c 6e 65 74 rsch,
>| dc=cellnet ~ 0020: 2c 64 63 3d 63 6f 6d 80 08 31 52 44 54 63 24
>| 64 ,dc=com..password ~ 0030: 62
>| b ber_get_next ldap_read: want=8 error=Resource temporarily
>| unavailable ber_get_next on fd 10 failed errno=11 (Resource
>| temporarily unavailable) do_bind ber_scanf fmt ({imt) ber:
>| ber_dump: buf=0x081ed2c8 ptr=0x081ed2cb end=0x081ed2f9 len=46 ~
>| 0000: 60 2c 02 01 03 04 1d 63 6e 3d 61 68 69 72 73 63
>| `,.....cn=ahirsc ~ 0010: 68 2c 20 64 63 3d 63 65 6c 6c 6e 65 74
>| 2c 64 63 h, dc=cellnet,dc ~ 0020: 3d 63 6f 6d 80 08 31 52 44
>| 54 63 24 64 62 =com..password ber_scanf fmt (m}) ber: ber_dump:
>| buf=0x081ed2c8 ptr=0x081ed2ef end=0x081ed2f9 len=10 ~ 0000: 00 08
>| 31 52 44 54 63 24 64 62 ..password |>>
>| dnPrettyNormal: <cn=ahirsch, dc=cellnet,dc=com> =>
>| ldap_bv2dn(cn=ahirsch, dc=cellnet,dc=com,0) <=
>| ldap_bv2dn(cn=ahirsch, dc=cellnet,dc=com,0)=0 => ldap_dn2bv(272) <=
>| ldap_dn2bv(cn=ahirsch,dc=cellnet,dc=com,272)=0 => ldap_dn2bv(272)
>| <= ldap_dn2bv(cn=ahirsch,dc=cellnet,dc=com,272)=0 <<<
>| dnPrettyNormal: <cn=ahirsch,dc=cellnet,dc=com>,
>| <cn=ahirsch,dc=cellnet,dc=com> do_bind: version=3
>| dn="cn=ahirsch,dc=cellnet,dc=com" method=128 conn=0 op=0 BIND
>| dn="cn=ahirsch,dc=cellnet,dc=com" method=128 daemon: select:
>| listen=6 active_threads=0 tvp=NULL ==> bdb_bind: dn:
>| cn=ahirsch,dc=cellnet,dc=com
>| bdb_dn2entry("cn=ahirsch,dc=cellnet,dc=com") => bdb_dn2id(
>| "dc=cellnet,dc=com" ) <= bdb_dn2id: got id=0x00000001 => bdb_dn2id(
>| "cn=ahirsch,dc=cellnet,dc=com" ) <= bdb_dn2id: get failed:
>| DB_NOTFOUND: No matching key/data pair found (-30990) entry_decode:
>| "dc=cellnet,dc=com" <= entry_decode(dc=cellnet,dc=com)
>| send_ldap_result: conn=0 op=0 p=3 send_ldap_result: err=49
>| matched="" text="" send_ldap_response: msgid=1 tag=97 err=49
>| ber_flush: 14 bytes to sd 10 ~ 0000: 30 0c 02 01 01 61 07 0a 01
>| 31 04 00 04 00 0....a...1.... ldap_write: want=14, written=14 ~
>| 0000: 30 0c 02 01 01 61 07 0a 01 31 04 00 04 00 0....a...1....
>| conn=0 op=0 RESULT tag=97 err=49 text= daemon: select: listen=7
>| active_threads=0 tvp=NULL daemon: activity on 1 descriptors daemon:
>| activity on: 10r daemon: read activity on 10 connection_get(10)
>| connection_get(10): got connid=0 connection_read(10): checking for
>| input on id=0 ber_get_next ldap_read: want=8, got=0
>|
>| ber_get_next on fd 10 failed errno=0 (Success) connection_read(10):
>| input error=-2 id=0, closing. connection_closing: readying conn=0
>| sd=10 for close connection_close: conn=0 sd=10 daemon: removing 10
>| conn=0 fd=10 closed daemon: select: listen=6 active_threads=0
>| tvp=NULL daemon: select: listen=7 active_threads=0 tvp=NULL daemon:
>| activity on 1 descriptors daemon: select: listen=6 active_threads=0
>| tvp=NULL daemon: select: listen=7 active_threads=0 tvp=NULL
>|
>| I have verified that the password is correct and I have machines
>| that I authenticate against that allow me in fine, but am unable to
>| bind, say with ldapbrowser, as a real user.
>|
>| Here are my ACL's from my slapd.conf:
>|
>| access to attrs=userPassword ~ by self write ~ by anonymous
>| auth ~ by dn.base="cn=Manager" write ~ by * none
>|
>| access to * ~ by self write ~ by dn.base="cn=Manager" write
>| ~ by * read stop
>|
>| I have also tried it without the dn.base lines with the same
>| errors. I've been searching online but not finding any answers.
>| Does anyone have any idea where I should look next?
>|
>| TIA!
>
>When I try to perform an ldapsearch I get "ldap_bind: Invalid
>credentials (49)"
>
>Here is the debug output from the search:
>
>[ahirsch@kclnx13 ahirsch]$ ldapsearch -x -d -1 -D
>"cn=ahirsch,ou=office,ou=projects,dc=cellnet,dc=com" -h 148.80.180.253
>- -p 389 -W
>ldap_create
>Enter LDAP Password:
>ldap_bind_s
>ldap_simple_bind_s
>ldap_sasl_bind_s
>ldap_sasl_bind
>ldap_send_initial_request
>ldap_new_connection
>ldap_int_open_connection
>ldap_connect_to_host: TCP 148.80.180.253:389
>ldap_new_socket: 3
>ldap_prepare_socket: 3
>ldap_connect_to_host: Trying 148.80.180.253:389
>ldap_connect_timeout: fd: 3 tm: -1 async: 0
>ldap_ndelay_on: 3
>ldap_is_sock_ready: 3
>ldap_ndelay_off: 3
>ldap_int_sasl_open: host=konldap1.cellnet.com
>ldap_open_defconn: successful
>ldap_send_server_request
>ber_flush: 71 bytes to sd 3
>~ 0000: 30 45 02 01 01 60 40 02 01 03 04 32 63 6e 3d 61
>0E...`@....2cn=a
>~ 0010: 68 69 72 73 63 68 2c 6f 75 3d 6f 66 66 69 63 65
>hirsch,ou=office
>~ 0020: 2c 6f 75 3d 70 72 6f 6a 65 63 74 73 2c 64 63 3d
>,ou=projects,dc=
>~ 0030: 63 65 6c 6c 6e 65 74 2c 64 63 3d 63 6f 6d 80 07
>cellnet,dc=com..
>~ 0040: 63 33 31 31 6e 33 74 c311n3t
>ldap_write: want=71, written=71
>~ 0000: 30 45 02 01 01 60 40 02 01 03 04 32 63 6e 3d 61
>0E...`@....2cn=a
>~ 0010: 68 69 72 73 63 68 2c 6f 75 3d 6f 66 66 69 63 65
>hirsch,ou=office
>~ 0020: 2c 6f 75 3d 70 72 6f 6a 65 63 74 73 2c 64 63 3d
>,ou=projects,dc=
>~ 0030: 63 65 6c 6c 6e 65 74 2c 64 63 3d 63 6f 6d 80 07
>cellnet,dc=com..
>~ 0040: 63 33 31 31 6e 33 74 c311n3t
>ldap_result msgid 1
>ldap_chkResponseList for msgid=1, all=1
>ldap_chkResponseList returns NULL
>wait4msg (infinite timeout), msgid 1
>wait4msg continue, msgid 1, all 1
>** Connections:
>* host: 148.80.180.253 port: 389 (default)
>~ refcnt: 2 status: Connected
>~ last used: Mon Feb 9 12:38:30 2004
>
>** Outstanding Requests:
>~ * msgid 1, origid 1, status InProgress
>~ outstanding referrals 0, parent count 0
>** Response Queue:
>~ Empty
>ldap_chkResponseList for msgid=1, all=1
>ldap_chkResponseList returns NULL
>ldap_int_select
>read1msg: msgid 1, all 1
>ber_get_next
>ldap_read: want=8, got=8
>~ 0000: 30 0c 02 01 01 61 07 0a 0....a..
>ldap_read: want=6, got=6
>~ 0000: 01 31 04 00 04 00 .1....
>ber_get_next: tag 0x30 len 12 contents:
>ber_dump: buf=0x09cfcec0 ptr=0x09cfcec0 end=0x09cfcecc len=12
>~ 0000: 02 01 01 61 07 0a 01 31 04 00 04 00 ...a...1....
>ldap_read: message type bind msgid 1, original id 1
>ber_scanf fmt ({iaa) ber:
>ber_dump: buf=0x09cfcec0 ptr=0x09cfcec3 end=0x09cfcecc len=9
>~ 0000: 61 07 0a 01 31 04 00 04 00 a...1....
>read1msg: 0 new referrals
>read1msg: mark request completed, id = 1
>request 1 done
>res_errno: 0, res_error: <>, res_matched: <>
>ldap_free_request (origid 1, msgid 1)
>ldap_free_connection
>ldap_free_connection: refcnt 1
>ldap_parse_result
>ber_scanf fmt ({iaa) ber:
>ber_dump: buf=0x09cfcec0 ptr=0x09cfcec3 end=0x09cfcecc len=9
>~ 0000: 61 07 0a 01 31 04 00 04 00 a...1....
>ber_scanf fmt (}) ber:
>ber_dump: buf=0x09cfcec0 ptr=0x09cfcecc end=0x09cfcecc len=0
>
>ldap_msgfree
>ldap_perror
>ldap_bind: Invalid credentials (49)
>
>I know that the account ahirsch is popluated in
>ou=office,ou=projects,dc=cellnet,dc=com on host 148.80.180.253 and
>that the password used is correct.
>
>On my workstation, which authenticates me against the LDAP server in
>question, when I do an ldapwhoami -x I get anonymous. I would have
>thought that by logging in as myself it would have returned ahirsch.
>
>I'm at a complete loss and we have to cut over to this server very
>quickly as our access to the corporate LDAP server has been cut off.
>Any ideas would be greatly appericiated!
>
>- --
>Aaron M. Hirsch
>Atos Origin - Cellnet
>11146 Thompson Ave.
>Lenexa, KS 66219
>Work:(913) 312-4717
>Fax:(913) 312-4701
>Mobile:(913) 284-9094
>-----BEGIN PGP SIGNATURE-----
>Version: GnuPG v1.2.3 (GNU/Linux)
>Comment: Using GnuPG with Thunderbird - http://enigmail.mozdev.org
>
>iD8DBQFAJ9R8gBD+XyMGAPwRAhC1AKCCLngNzGrWRqbumtfTgl2IYokmCwCfQQWH
>xykbLK1Otb+ecLiugHPT8Wk=
>=JtCq
>-----END PGP SIGNATURE-----
>
>

****************************************************************
"Listen: We are here on Earth to fart around. Don't let anybody
 tell you any different!"    --Kurt Vonnegut
References:
- Normal User Binding Problem?
  - From: "Aaron M. Hirsch" <Aaron.Hirsch@atosorigin.com>
- Re: Normal User Binding Problem?
  - From: "Aaron M. Hirsch" <Aaron.Hirsch@atosorigin.com>
Prev by Date: Re: Slapd stops working after a NOT graceful shutdown
Next by Date: Re: Log sequence error on db_recover
Index(es):
- Chronological
- Thread