[Pdns-users] Manual notify problem with LDAP backend

[Fabian Fagerholm]

On Thu, 2005-08-18 at 11:44 +0200, Norbert Sendetzky wrote:
> Not at this point of time.
> Could you try to post more details? Please set loglevel to 9, query-logging to 
> yes and (if possible) recompile with -DVERBOSELOG to see what's going on.

Ok, I raised the loglevel, turned on query-logging and ran with a
version recompiled with -DVERBOSELOG.

Here's what pdns is saying right after "pdns_control notify paniq.net":

pdns[25133]: Notification request for domain 'paniq.net' received from operator
pdns[25133]: [LdapBackend] LDAP servers = 127.0.0.1:389
pdns[25133]: [LdapBackend] Ldap connection succeeded
pdns[25133]: No such domain 'paniq.net' in our database
pdns[25133]: PacketHandler destructor called - 5 left
pdns[25133]: UeberBackend destructor called, removing ourselves from instances, and deleting our backends
pdns[25133]: [LdapBackend] Ldap connection closed

And here is what slapd is logging:

slapd[24226]: daemon: activity on 1 descriptors
slapd[24226]: daemon: new connection on 15
slapd[24226]: conn=5 fd=15 ACCEPT from IP=127.0.0.1:34737 (IP=0.0.0.0:389)
slapd[24226]: daemon: added 15r
slapd[24226]: daemon: activity on:
slapd[24226]:
slapd[24226]: daemon: select: listen=6 active_threads=0 tvp=NULL
slapd[24226]: daemon: select: listen=7 active_threads=0 tvp=NULL
slapd[24226]: daemon: activity on 1 descriptors
slapd[24226]: daemon: activity on:
slapd[24226]:  15r
slapd[24226]:
slapd[24226]: daemon: read activity on 15
slapd[24226]: connection_get(15)
slapd[24226]: connection_get(15): got connid=5
slapd[24226]: connection_read(15): checking for input on id=5
slapd[24226]: ber_get_next on fd 15 failed errno=11 (Resource temporarily unavailable)
slapd[24226]: daemon: select: listen=6 active_threads=0 tvp=NULL
slapd[24226]: daemon: select: listen=7 active_threads=0 tvp=NULL
slapd[24226]: do_bind
slapd[24226]: >>> dnPrettyNormal: <cn=ldap,dc=local>
slapd[24226]: <<< dnPrettyNormal: <cn=ldap,dc=local>, <cn=ldap,dc=local>
slapd[24226]: do_bind: version=3 dn="cn=ldap,dc=local" method=128
slapd[24226]: conn=5 op=0 BIND dn="cn=ldap,dc=local" method=128
slapd[24226]: ==> bdb_bind: dn: cn=ldap,dc=local
slapd[24226]: bdb_dn2entry("cn=ldap,dc=local")
slapd[24226]: => access_allowed: auth access to "cn=ldap,dc=local" "userPassword" requested
slapd[24226]: => acl_get: [1] attr userPassword
slapd[24226]: => acl_mask: access to entry "cn=ldap,dc=local", attr "userPassword" requested
slapd[24226]: => acl_mask: to all values by "", (=n)
slapd[24226]: <= check a_dn_pat: cn=admin,dc=local
slapd[24226]: <= check a_dn_pat: anonymous
slapd[24226]: <= acl_mask: [2] applying auth(=x) (stop)
slapd[24226]: <= acl_mask: [2] mask: auth(=x)
slapd[24226]: => access_allowed: auth access granted by auth(=x)
slapd[24226]: conn=5 op=0 BIND dn="cn=ldap,dc=local" mech=SIMPLE ssf=0
slapd[24226]: do_bind: v3 bind: "cn=ldap,dc=local" to "cn=ldap,dc=local"
slapd[24226]: send_ldap_result: conn=5 op=0 p=3
slapd[24226]: send_ldap_result: err=0 matched="" text=""
slapd[24226]: send_ldap_response: msgid=1 tag=97 err=0

Here is where I suppose the LDAP backend should be making a query -- but
it isn't.

slapd[24226]: conn=5 op=0 RESULT tag=97 err=0 text=
slapd[24226]: daemon: activity on 1 descriptors
slapd[24226]: daemon: activity on:
slapd[24226]:  15r
slapd[24226]:
slapd[24226]: daemon: read activity on 15
slapd[24226]: connection_get(15)
slapd[24226]: connection_get(15): got connid=5
slapd[24226]: connection_read(15): checking for input on id=5
slapd[24226]: ber_get_next on fd 15 failed errno=0 (Success)
slapd[24226]: connection_read(15): input error=-2 id=5, closing.
slapd[24226]: connection_closing: readying conn=5 sd=15 for close
slapd[24226]: connection_close: deferring conn=5 sd=15
slapd[24226]: daemon: select: listen=6 active_threads=0 tvp=NULL
slapd[24226]: daemon: select: listen=7 active_threads=0 tvp=NULL
slapd[24226]: daemon: activity on 1 descriptors
slapd[24226]: daemon: select: listen=6 active_threads=0 tvp=NULL
slapd[24226]: daemon: select: listen=7 active_threads=0 tvp=NULL
slapd[24226]: do_unbind
slapd[24226]: conn=5 op=1 UNBIND
slapd[24226]: connection_resched: attempting closing conn=5 sd=15
slapd[24226]: connection_close: conn=5 sd=15
slapd[24226]: daemon: removing 15
slapd[24226]: conn=5 fd=15 closed

It looks to me like the LDAP backend is not even bothering to check the
existence of the domain in the directory. Or maybe I don't understand
what it's trying to do. At least it doesn't make any queries...

Was any of this useful in figuring out what is happening?

-- 
Fabian Fagerholm <fabbe at paniq.net>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 189 bytes
Desc: This is a digitally signed message part
URL: <http://mailman.powerdns.com/pipermail/pdns-users/attachments/20050818/b86839cb/attachment-0001.sig>