Re: smbk5pwd: ldappassword hangs

[Frank Van Damme <frank.vandamme@gmail.com>]

2010/5/31 Frank Van Damme <frank.vandamme@gmail.com>:
> Hi list,
>
> I installed and configured the smbk5pwd overlay as described on
> http://student.physik.uni-mainz.de/~reiffert/smbk5pwd.html#smbk5pwd.
> This succeeded, the module is loaded etc. But an unwelcome side effect
> is that password changes don't function anymore. With the
> overlay/module disabled, there is no problem; if I enable it, the
> "ldappasswd" command hangs. I marked where I hit Ctrl-C on the hanging
> ldappasswd command.
>
> This is the slapd log...


Does no one have an idea, please?

I'm also adding the log in a situation where the module is not used
and the ldappasswd operation is requested (which succeeds). At a
certain point, the log says "do_extended", that's where the previous
log stops...

do_bind: v3 bind: "uid=tryout,ou=People,dc=otec,dc=vub,dc=ac,dc=be" to
"uid=tryout,ou=People,dc=otec,dc=vub,dc=ac,dc=be"
send_ldap_result: conn=0 op=0 p=3
send_ldap_result: err=0 matched="" text=""
send_ldap_response: msgid=1 tag=97 err=0
ber_flush2: 14 bytes to sd 15
  0000:  30 0c 02 01 01 61 07 0a  01 00 04 00 04 00         0....a........
ldap_write: want=14, written=14
  0000:  30 0c 02 01 01 61 07 0a  01 00 04 00 04 00         0....a........
conn=0 op=0 RESULT tag=97 err=0 text=

daemon: epoll: listen=7 active_threads=0 tvp=zero
daemon: epoll: listen=8 active_threads=0 tvp=zero
daemon: epoll: listen=9 active_threads=0 tvp=zero
daemon: epoll: listen=10 active_threads=0 tvp=zero
daemon: activity on 1 descriptor
daemon: activity on: 15r
daemon: read active on 15
daemon: epoll: listen=7 active_threads=0 tvp=zero
daemon: epoll: listen=8 active_threads=0 tvp=zero
daemon: epoll: listen=9 active_threads=0 tvp=zero
daemon: epoll: listen=10 active_threads=0 tvp=zero
connection_get(15)
connection_get(15): got connid=0
connection_read(15): checking for input on id=0
ber_get_next
ldap_read: want=8, got=8
  0000:  30 32 02 01 02 77 2d 80                            02...w-.
ldap_read: want=44, got=44
  0000:  17 31 2e 33 2e 36 2e 31  2e 34 2e 31 2e 34 32 30   .1.3.6.1.4.1.420
  0010:  33 2e 31 2e 31 31 2e 31  81 12 30 10 81 06 74 72   3.1.11.1..0...tr
  0020:  79 74 72 79 82 06 74 72  79 74 72 79               ytry..trytry
ber_get_next: tag 0x30 len 50 contents:
ber_dump: buf=0x824a1a8 ptr=0x824a1a8 end=0x824a1da len=50
  0000:  02 01 02 77 2d 80 17 31  2e 33 2e 36 2e 31 2e 34   ...w-..1.3.6.1.4
  0010:  2e 31 2e 34 32 30 33 2e  31 2e 31 31 2e 31 81 12   .1.4203.1.11.1..
  0020:  30 10 81 06 74 72 79 74  72 79 82 06 74 72 79 74   0...trytry..tryt
  0030:  72 79                                              ry
ber_get_next
ldap_read: want=8 error=Resource temporarily unavailable
conn=0 op=1 do_extended
ber_scanf fmt ({m) ber:
ber_dump: buf=0x824a1a8 ptr=0x824a1ab end=0x824a1da len=47
  0000:  77 2d 80 17 31 2e 33 2e  36 2e 31 2e 34 2e 31 2e   w-..1.3.6.1.4.1.
  0010:  34 32 30 33 2e 31 2e 31  31 2e 31 81 12 30 10 81   4203.1.11.1..0..
  0020:  06 74 72 79 74 72 79 82  06 74 72 79 74 72 79      .trytry..trytry
ber_scanf fmt (m) ber:
ber_dump: buf=0x824a1a8 ptr=0x824a1c6 end=0x824a1da len=20
  0000:  00 12 30 10 81 06 74 72  79 74 72 79 82 06 74 72   ..0...trytry..tr
  0010:  79 74 72 79                                        ytry
conn=0 op=1 EXT oid=1.3.6.1.4.1.4203.1.11.1
do_extended: oid=1.3.6.1.4.1.4203.1.11.1
conn=0 op=1 PASSMOD old new
bdb_dn2entry("uid=tryout,ou=people,dc=otec,dc=vub,dc=ac,dc=be")
=> bdb_entry_get: ndn: "uid=tryout,ou=people,dc=otec,dc=vub,dc=ac,dc=be"
=> bdb_entry_get: oc: "(null)", at: "userPassword"
bdb_dn2entry("uid=tryout,ou=people,dc=otec,dc=vub,dc=ac,dc=be")
=> bdb_entry_get: found entry: "uid=tryout,ou=people,dc=otec,dc=vub,dc=ac,dc=be"
bdb_entry_get: rc=0
=> access_allowed: auth access to
"uid=tryout,ou=People,dc=otec,dc=vub,dc=ac,dc=be" "userPassword"
requested
=> acl_get: [1] attr userPassword
=> slap_access_allowed: result not in cache (userPassword)
=> acl_mask: access to entry
"uid=tryout,ou=People,dc=otec,dc=vub,dc=ac,dc=be", attr "userPassword"
requested
=> acl_mask: to value by "uid=tryout,ou=people,dc=otec,dc=vub,dc=ac,dc=be", (=0)
<= check a_dn_pat: cn=admin,dc=otec,dc=vub,dc=ac,dc=be
<= check a_dn_pat: anonymous
<= check a_dn_pat: self
<= acl_mask: [3] applying write(=wrscxd) (stop)
<= acl_mask: [3] mask: write(=wrscxd)
=> slap_access_allowed: auth access granted by write(=wrscxd)
=> access_allowed: auth access granted by write(=wrscxd)
hdb_modify: uid=tryout,ou=People,dc=otec,dc=vub,dc=ac,dc=be
bdb_dn2entry("uid=tryout,ou=people,dc=otec,dc=vub,dc=ac,dc=be")
bdb_modify_internal: 0x00000022: uid=tryout,ou=People,dc=otec,dc=vub,dc=ac,dc=be
=> access_allowed: delete access to
"uid=tryout,ou=People,dc=otec,dc=vub,dc=ac,dc=be" "userPassword"
requested
=> acl_get: [1] attr userPassword
=> slap_access_allowed: result not in cache (userPassword)
=> acl_mask: access to entry
"uid=tryout,ou=People,dc=otec,dc=vub,dc=ac,dc=be", attr "userPassword"
requested
=> acl_mask: to all values by
"uid=tryout,ou=people,dc=otec,dc=vub,dc=ac,dc=be", (=0)
<= check a_dn_pat: cn=admin,dc=otec,dc=vub,dc=ac,dc=be
<= check a_dn_pat: anonymous
<= check a_dn_pat: self
<= acl_mask: [3] applying write(=wrscxd) (stop)
<= acl_mask: [3] mask: write(=wrscxd)
=> slap_access_allowed: delete access granted by write(=wrscxd)
=> access_allowed: delete access granted by write(=wrscxd)
=> access_allowed: add access to
"uid=tryout,ou=People,dc=otec,dc=vub,dc=ac,dc=be" "userPassword"
requested
=> acl_get: [1] attr userPassword
=> slap_access_allowed: result not in cache (userPassword)
=> acl_mask: access to entry
"uid=tryout,ou=People,dc=otec,dc=vub,dc=ac,dc=be", attr "userPassword"
requested
=> acl_mask: to value by "uid=tryout,ou=people,dc=otec,dc=vub,dc=ac,dc=be", (=0)
<= check a_dn_pat: cn=admin,dc=otec,dc=vub,dc=ac,dc=be
<= check a_dn_pat: anonymous
<= check a_dn_pat: self
<= acl_mask: [3] applying write(=wrscxd) (stop)
<= acl_mask: [3] mask: write(=wrscxd)
=> slap_access_allowed: add access granted by write(=wrscxd)
=> access_allowed: add access granted by write(=wrscxd)
acl: internal mod entryCSN: modify access granted
acl: internal mod modifiersName: modify access granted
acl: internal mod modifyTimestamp: modify access granted
daemon: activity on 1 descriptor
daemon: activity on:bdb_modify_internal: replace userPassword

daemon: epoll: listen=7 active_threads=0 tvp=zero
daemon: epoll: listen=8 active_threads=0 tvp=zero
daemon: epoll: listen=9 active_threads=0 tvp=zero
daemon: epoll: listen=10 active_threads=0 tvp=zero
bdb_modify_internal: replace entryCSN
bdb_modify_internal: replace modifiersName
bdb_modify_internal: replace modifyTimestamp
oc_check_required entry
(uid=tryout,ou=People,dc=otec,dc=vub,dc=ac,dc=be), objectClass
"shadowAccount"
oc_check_required entry
(uid=tryout,ou=People,dc=otec,dc=vub,dc=ac,dc=be), objectClass
"posixAccount"
oc_check_required entry
(uid=tryout,ou=People,dc=otec,dc=vub,dc=ac,dc=be), objectClass
"inetOrgPerson"
oc_check_required entry
(uid=tryout,ou=People,dc=otec,dc=vub,dc=ac,dc=be), objectClass
"sambaSamAccount"
oc_check_allowed type "objectClass"
oc_check_allowed type "shadowWarning"
oc_check_allowed type "homeDirectory"
oc_check_allowed type "loginShell"
oc_check_allowed type "uid"
oc_check_allowed type "uidNumber"
oc_check_allowed type "gidNumber"
oc_check_allowed type "sn"
oc_check_allowed type "givenName"
oc_check_allowed type "structuralObjectClass"
oc_check_allowed type "entryUUID"
oc_check_allowed type "creatorsName"
oc_check_allowed type "createTimestamp"
oc_check_allowed type "cn"
oc_check_allowed type "sambaDomainName"
oc_check_allowed type "displayName"
oc_check_allowed type "sambaSID"
oc_check_allowed type "shadowInactive"
oc_check_allowed type "sambaAcctFlags"
oc_check_allowed type "sambaLMPassword"
oc_check_allowed type "sambaNTPassword"
oc_check_allowed type "sambaPwdLastSet"
oc_check_allowed type "shadowExpire"
oc_check_allowed type "shadowMax"
oc_check_allowed type "shadowLastChange"
oc_check_allowed type "userPassword"
oc_check_allowed type "entryCSN"
oc_check_allowed type "modifiersName"
oc_check_allowed type "modifyTimestamp"
=> entry_encode(0x00000022):
hdb_modify: updated id=00000022
dn="uid=tryout,ou=People,dc=otec,dc=vub,dc=ac,dc=be"
send_ldap_result: conn=0 op=1 p=3
send_ldap_result: err=0 matched="" text=""
send_ldap_extended: err=0 oid= len=0
send_ldap_response: msgid=2 tag=120 err=0
ber_flush2: 14 bytes to sd 15
  0000:  30 0c 02 01 02 78 07 0a  01 00 04 00 04 00         0....x........
ldap_write: want=14, written=14
  0000:  30 0c 02 01 02 78 07 0a  01 00 04 00 04 00         0....x........
conn=0 op=1 RESULT oid= err=0 text=
daemon: activity on 1 descriptor
daemon: activity on: 15r
daemon: read active on 15
daemon: epoll: listen=7 active_threads=0 tvp=zero
daemon: epoll: listen=8 active_threads=0 tvp=zero
daemon: epoll: listen=9 active_threads=0 tvp=zero
daemon: epoll: listen=10 active_threads=0 tvp=zero
connection_get(15)
connection_get(15): got connid=0
connection_read(15): checking for input on id=0
ber_get_next
ldap_read: want=8, got=7
  0000:  30 05 02 01 03 42 00                               0....B.
ber_get_next: tag 0x30 len 5 contents:
ber_dump: buf=0xb61007e8 ptr=0xb61007e8 end=0xb61007ed len=5
  0000:  02 01 03 42 00                                     ...B.
ber_get_next
ldap_read: want=8, got=0

ber_get_next on fd 15 failed errno=0 (Success)
connection_read(15): input error=-2 id=0, closing.
connection_closing: readying conn=0 sd=15 for close
connection_close: deferring conn=0 sd=15
conn=0 op=2 do_unbind
conn=0 op=2 UNBIND
connection_resched: attempting closing conn=0 sd=15
connection_close: conn=0 sd=15
daemon: removing 15
conn=0 fd=15 closed
daemon: activity on 1 descriptor
daemon: activity on:
daemon: epoll: listen=7 active_threads=0 tvp=zero
daemon: epoll: listen=8 active_threads=0 tvp=zero
daemon: epoll: listen=9 active_threads=0 tvp=zero
daemon: epoll: listen=10 active_threads=0 tvp=zero
^Cdaemon: shutdown requested and initiated.
daemon: closing 7
daemon: closing 8
daemon: closing 9
daemon: closing 10
slapd shutdown: waiting for 0 threads to terminate
slapd shutdown: initiated
====> bdb_cache_release_all
slapd destroy: freeing system resources.
slapd stopped.



-- 
Frank Van Damme
A: Because it destroys the flow of the conversation.
Q: Why is it bad?
A: No, it's bad.
Q: Should I top post in replies to mailing lists or on Usenet?