I suggest you try stats logging (256) as was previously suggested.
--Quanah
On Jan 23, 2011, at 7:55 AM, "mike@grounded.net" mike@grounded.net wrote:
Sent my reply too quickly, the web server IS making a connection to openldap, it wasn't showing up at log level 128. Raising it to 254 now shows it in the slapd logging. Raising it has also given me information I wasn't seeing before, such as the missing connection which is there after all.
This is when the user should be created into the ou=users,dc=mydomain,dc=com but doesn't. I only see one error but am not sure if this is enough to know what is preventing the user from being created.
Jan 23 06:35:46 ldap slapd[16330]: daemon: activity on 1 descriptor Jan 23 06:35:46 ldap slapd[16330]: daemon: activity on: Jan 23 06:35:46 ldap slapd[16330]: Jan 23 06:35:46 ldap slapd[16330]: daemon: epoll: listen=7 active_threads=0 tvp=NULL Jan 23 06:35:46 ldap slapd[16330]: daemon: epoll: listen=8 busy Jan 23 06:35:46 ldap slapd[16330]: daemon: listen=8, new connection on 12 Jan 23 06:35:46 ldap slapd[16330]: daemon: added 12r (active) listener=(nil) Jan 23 06:35:46 ldap slapd[16330]: daemon: activity on 2 descriptors Jan 23 06:35:46 ldap slapd[16330]: daemon: activity on: Jan 23 06:35:46 ldap slapd[16330]: 12r Jan 23 06:35:46 ldap slapd[16330]: Jan 23 06:35:46 ldap slapd[16330]: daemon: read active on 12 Jan 23 06:35:46 ldap slapd[16330]: daemon: epoll: listen=7 active_threads=0 tvp=NULL Jan 23 06:35:46 ldap slapd[16330]: daemon: epoll: listen=8 active_threads=0 tvp=NULL Jan 23 06:35:46 ldap slapd[16330]: connection_get(12) Jan 23 06:35:46 ldap slapd[16330]: send_ldap_result: err=0 matched="" text="" Jan 23 06:35:46 ldap slapd[16330]: daemon: activity on 1 descriptor Jan 23 06:35:46 ldap slapd[16330]: daemon: activity on: Jan 23 06:35:46 ldap slapd[16330]: Jan 23 06:35:46 ldap slapd[16330]: daemon: epoll: listen=7 active_threads=0 tvp=NULL Jan 23 06:35:46 ldap slapd[16330]: daemon: epoll: listen=8 active_threads=0 tvp=NULL Jan 23 06:35:46 ldap slapd[16330]: daemon: activity on 1 descriptor Jan 23 06:35:46 ldap slapd[16330]: daemon: activity on: Jan 23 06:35:46 ldap slapd[16330]: 12r Jan 23 06:35:46 ldap slapd[16330]: Jan 23 06:35:46 ldap slapd[16330]: daemon: read active on 12 Jan 23 06:35:46 ldap slapd[16330]: daemon: epoll: listen=7 active_threads=0 tvp=NULL Jan 23 06:35:47 ldap slapd[16330]: daemon: epoll: listen=8 active_threads=0 tvp=NULL Jan 23 06:35:46 ldap slapd[16330]: connection_get(12) Jan 23 06:35:47 ldap slapd[16330]: SRCH "dc=mydomain,dc=com" 2 0 Jan 23 06:35:47 ldap slapd[16330]: 0 0 0 Jan 23 06:35:47 ldap slapd[16330]: begin get_filter Jan 23 06:35:47 ldap slapd[16330]: EQUALITY Jan 23 06:35:47 ldap slapd[16330]: end get_filter 0 Jan 23 06:35:47 ldap slapd[16330]: filter: (uid=projects) Jan 23 06:35:47 ldap slapd[16330]: attrs: Jan 23 06:35:47 ldap slapd[16330]: Jan 23 06:35:47 ldap slapd[16330]: => bdb_filter_candidates Jan 23 06:35:47 ldap slapd[16330]: AND Jan 23 06:35:47 ldap slapd[16330]: => bdb_list_candidates 0xa0 Jan 23 06:35:47 ldap slapd[16330]: => bdb_filter_candidates Jan 23 06:35:47 ldap slapd[16330]: OR Jan 23 06:35:47 ldap slapd[16330]: => bdb_list_candidates 0xa1 Jan 23 06:35:47 ldap slapd[16330]: => bdb_filter_candidates Jan 23 06:35:47 ldap slapd[16330]: EQUALITY Jan 23 06:35:47 ldap slapd[16330]: bdb_idl_fetch_key: [b49d1940] Jan 23 06:35:47 ldap slapd[16330]: <= bdb_filter_candidates: id=0 first=0 last=0 Jan 23 06:35:47 ldap slapd[16330]: => bdb_filter_candidates Jan 23 06:35:47 ldap slapd[16330]: EQUALITY Jan 23 06:35:47 ldap slapd[16330]: bdb_idl_fetch_key: [63fc7386] Jan 23 06:35:47 ldap slapd[16330]: <= bdb_filter_candidates: id=0 first=0 last=0 Jan 23 06:35:47 ldap slapd[16330]: <= bdb_list_candidates: id=0 first=0 last=0 Jan 23 06:35:47 ldap slapd[16330]: <= bdb_filter_candidates: id=0 first=0 last=0 Jan 23 06:35:47 ldap slapd[16330]: <= bdb_list_candidates: id=0 first=1 last=0 Jan 23 06:35:47 ldap slapd[16330]: <= bdb_filter_candidates: id=0 first=1 last=0 Jan 23 06:35:47 ldap slapd[16330]: send_ldap_result: err=0 matched="" text="" Jan 23 06:35:47 ldap slapd[16330]: daemon: activity on 1 descriptor Jan 23 06:35:47 ldap slapd[16330]: daemon: activity on: Jan 23 06:35:47 ldap slapd[16330]: Jan 23 06:35:47 ldap slapd[16330]: daemon: epoll: listen=7 active_threads=0 tvp=NULL Jan 23 06:35:47 ldap slapd[16330]: daemon: epoll: listen=8 active_threads=0 tvp=NULL Jan 23 06:35:47 ldap slapd[16330]: daemon: activity on 1 descriptor Jan 23 06:35:47 ldap slapd[16330]: daemon: activity on: Jan 23 06:35:47 ldap slapd[16330]: 12r Jan 23 06:35:47 ldap slapd[16330]: Jan 23 06:35:47 ldap slapd[16330]: daemon: read active on 12 Jan 23 06:35:47 ldap slapd[16330]: daemon: epoll: listen=7 active_threads=0 tvp=NULL Jan 23 06:35:47 ldap slapd[16330]: daemon: epoll: listen=8 active_threads=0 tvp=NULL Jan 23 06:35:47 ldap slapd[16330]: connection_get(12) Jan 23 06:35:47 ldap slapd[16330]: connection_read(12): input error=-2 id=2, closing. <<<ERROR<<< Jan 23 06:35:47 ldap slapd[16330]: daemon: removing 12 Jan 23 06:35:47 ldap slapd[16330]: daemon: activity on 1 descriptor Jan 23 06:35:47 ldap slapd[16330]: daemon: activity on: Jan 23 06:35:47 ldap slapd[16330]: Jan 23 06:35:47 ldap slapd[16330]: daemon: epoll: listen=7 active_threads=0 tvp=NULL Jan 23 06:35:47 ldap slapd[16330]: daemon: epoll: listen=8 active_threads=0 tvp=NULL