[Date Prev][Date Next] [Chronological] [Thread] [Top]

Re: smbk5pwd: ldappassword hangs



Hi -

On Mon, 7 Jun 2010 11:56:48 +0200, Frank Van Damme
<frank.vandamme@gmail.com> wrote:
> 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?
Not really ...

> 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...

Same problem as i figured out: in the last two weeks i am testing the
combination Heimdal+OpenLdap+Samba and
the smbk5pwd overlay. I compiled the stable OpenLdap and Heimdal release
successfully and combined it with Samba.
The error is nearly the same as described above. Only when i am changing
the password over Kerberos (via pam or kpasswd)
the password changes will done to the samba password (for userPassword i
use the {K5KEY} entry as described in smbk5pwd).

Try the ldappasswd with verbose output, you may see that the command tries
over and over to change the password...

Regards,
Marco

> 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.