From: Gary Williams Date: Wed, 17 Jan 2001 17:01:19 +0000 (+0000) Subject: fix format for new logging X-Git-Tag: LDBM_PRE_GIANT_RWLOCK~1582 X-Git-Url: https://git.sur5r.net/?a=commitdiff_plain;h=3281138bcfae5aea0e42cf5aa9c368753a56bf46;p=openldap fix format for new logging --- diff --git a/servers/slapd/back-ldbm/add.c b/servers/slapd/back-ldbm/add.c index 1b36200c88..b7fdb1c816 100644 --- a/servers/slapd/back-ldbm/add.c +++ b/servers/slapd/back-ldbm/add.c @@ -33,7 +33,13 @@ ldbm_back_add( AttributeDescription *children = slap_schema.si_ad_children; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY,"ldbm_back_add: %s\n", + e->e_dn )); +#else Debug(LDAP_DEBUG_ARGS, "==> ldbm_back_add: %s\n", e->e_dn, 0, 0); +#endif + /* nobody else can add until we lock our parent */ ldap_pvt_thread_mutex_lock(&li->li_add_mutex); @@ -50,8 +56,15 @@ ldbm_back_add( if ( rc != LDAP_SUCCESS ) { ldap_pvt_thread_mutex_unlock(&li->li_add_mutex); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_back_add: entry (%s) failed schema check.\n", + e->e_dn )); +#else Debug( LDAP_DEBUG_TRACE, "entry failed schema check: %s\n", text, 0, 0 ); +#endif + send_ldap_result( conn, op, rc, NULL, text, NULL, NULL ); @@ -90,8 +103,15 @@ ldbm_back_add( refs = default_referral; } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_back_add: Parent of (%s) does not exist.\n", + e->e_dn )); +#else Debug( LDAP_DEBUG_TRACE, "parent does not exist\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_REFERRAL, matched_dn, NULL, refs, NULL ); @@ -116,8 +136,15 @@ ldbm_back_add( /* free parent and writer lock */ cache_return_entry_w( &li->li_cache, p ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_back_add: No write access to parent (%s).\n", + e->e_dn )); +#else Debug( LDAP_DEBUG_TRACE, "no write access to parent\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_INSUFFICIENT_ACCESS, NULL, "no write access to parent", NULL, NULL ); @@ -131,8 +158,14 @@ ldbm_back_add( /* free parent and writer lock */ cache_return_entry_w( &li->li_cache, p ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_back_add: Parent is an alias.\n")); +#else Debug( LDAP_DEBUG_TRACE, "parent is alias\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_ALIAS_PROBLEM, NULL, "parent is an alias", NULL, NULL ); @@ -150,8 +183,14 @@ ldbm_back_add( /* free parent and writer lock */ cache_return_entry_w( &li->li_cache, p ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_back_add: Parent is referral.\n" )); +#else Debug( LDAP_DEBUG_TRACE, "parent is referral\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_REFERRAL, matched_dn, NULL, refs, NULL ); @@ -170,9 +209,16 @@ ldbm_back_add( if ( !be_isroot( be, op->o_ndn ) && !be_issuffix( be, "" ) ) { ldap_pvt_thread_mutex_unlock(&li->li_add_mutex); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_back_add: %s add denied.\n", + pdn == NULL ? "suffix" : "entry at root" )); +#else Debug( LDAP_DEBUG_TRACE, "%s add denied\n", pdn == NULL ? "suffix" : "entry at root", 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_INSUFFICIENT_ACCESS, NULL, NULL, NULL, NULL ); @@ -202,8 +248,14 @@ ldbm_back_add( ldap_pvt_thread_mutex_unlock(&li->li_root_mutex); } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_back_add: next_id failed.\n" )); +#else Debug( LDAP_DEBUG_ANY, "ldbm_add: next_id failed\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_OTHER, NULL, "next_id add failed", NULL, NULL ); @@ -227,8 +279,14 @@ ldbm_back_add( ldap_pvt_thread_mutex_unlock(&li->li_root_mutex); } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_back_add: cache_add_entry_lock failed.\n" )); +#else Debug( LDAP_DEBUG_ANY, "cache_add_entry_lock failed\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, rc > 0 ? LDAP_ALREADY_EXISTS : LDAP_OTHER, @@ -241,8 +299,14 @@ ldbm_back_add( /* attribute indexes */ if ( index_entry_add( be, e, e->e_attrs ) != LDAP_SUCCESS ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_back_add: index_entry_add failed.\n" )); +#else Debug( LDAP_DEBUG_TRACE, "index_entry_add failed\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_OTHER, NULL, "index generation failed", NULL, NULL ); @@ -251,8 +315,14 @@ ldbm_back_add( /* dn2id index */ if ( dn2id_add( be, e->e_ndn, e->e_id ) != 0 ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_back_add: dn2id_add failed.\n" )); +#else Debug( LDAP_DEBUG_TRACE, "dn2id_add failed\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_OTHER, NULL, "DN index generation failed", NULL, NULL ); @@ -261,8 +331,14 @@ ldbm_back_add( /* id2entry index */ if ( id2entry_add( be, e ) != 0 ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_back_add: id2entry_add failed.\n" )); +#else Debug( LDAP_DEBUG_TRACE, "id2entry_add failed\n", 0, 0, 0 ); +#endif + (void) dn2id_delete( be, e->e_ndn, e->e_id ); send_ldap_result( conn, op, LDAP_OTHER, NULL, "entry store failed", NULL, NULL ); diff --git a/servers/slapd/back-ldbm/attr.c b/servers/slapd/back-ldbm/attr.c index fbd8e0d04e..f642aedec9 100644 --- a/servers/slapd/back-ldbm/attr.c +++ b/servers/slapd/back-ldbm/attr.c @@ -201,8 +201,15 @@ attr_index_config( return LDAP_INAPPROPRIATE_MATCHING; } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "attr_index_config: index %s 0x%04x\n", + ad->ad_cname->bv_val, mask )); +#else Debug( LDAP_DEBUG_CONFIG, "index %s 0x%04x\n", ad->ad_cname->bv_val, mask, 0 ); +#endif + #ifdef SLAPD_USE_AD a->ai_desc = ad; diff --git a/servers/slapd/back-ldbm/attribute.c b/servers/slapd/back-ldbm/attribute.c index eebada043e..bad3eed2e2 100644 --- a/servers/slapd/back-ldbm/attribute.c +++ b/servers/slapd/back-ldbm/attribute.c @@ -31,12 +31,21 @@ ldbm_back_attribute( struct berval ***vals ) { struct ldbminfo *li = (struct ldbminfo *) be->be_private; - Entry *e; - int i, j, rc; + Entry *e; + int i, j, rc; Attribute *attr; struct berval **v; const char *entry_at_name = entry_at->ad_cname->bv_val; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ARGS, + "ldbm_back_attribute: gr dn: \"%s\"\n", e_ndn )); + LDAP_LOG(( "backend", LDAP_LEVEL_ARGS, + "ldbm_back_attribute: at: \"%s\"\n", entry_at_name)); + LDAP_LOG(( "backend", LDAP_LEVEL_ARGS, + "ldbm_back_attribute: tr dn: \"%s\"\n", + target ? target->e_ndn : "" )); +#else Debug( LDAP_DEBUG_ARGS, "=> ldbm_back_attribute: gr dn: \"%s\"\n", e_ndn, 0, 0 ); @@ -47,40 +56,73 @@ ldbm_back_attribute( Debug( LDAP_DEBUG_ARGS, "=> ldbm_back_attribute: tr dn: \"%s\"\n", target ? target->e_ndn : "", 0, 0 ); +#endif if (target != NULL && strcmp(target->e_ndn, e_ndn) == 0) { /* we already have a LOCKED copy of the entry */ e = target; - Debug( LDAP_DEBUG_ARGS, +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_back_attribute: target is LOCKED (%s)\n", + e_ndn )); +#else + Debug( LDAP_DEBUG_ARGS, "=> ldbm_back_attribute: target is entry: \"%s\"\n", e_ndn, 0, 0 ); +#endif + } else { /* can we find entry with reader lock */ if ((e = dn2entry_r(be, e_ndn, NULL )) == NULL) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_attribute: cannot find entry (%s)\n", + e_ndn )); +#else Debug( LDAP_DEBUG_ACL, "=> ldbm_back_attribute: cannot find entry: \"%s\"\n", e_ndn, 0, 0 ); +#endif + return LDAP_NO_SUCH_OBJECT; } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_back_attribute: found entry (%s)\n", e_ndn )); +#else Debug( LDAP_DEBUG_ACL, "=> ldbm_back_attribute: found entry: \"%s\"\n", e_ndn, 0, 0 ); +#endif + } /* find attribute values */ - + if( is_entry_alias( e ) ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_attribute: entry (%s) is an alias\n", e->e_dn )); +#else Debug( LDAP_DEBUG_ACL, "<= ldbm_back_attribute: entry is an alias\n", 0, 0, 0 ); +#endif + rc = LDAP_ALIAS_PROBLEM; goto return_results; } if( is_entry_referral( e ) ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_attribute: entry (%s) is a referral.\n", e->e_dn )); +#else Debug( LDAP_DEBUG_ACL, "<= ldbm_back_attribute: entry is an referral\n", 0, 0, 0 ); +#endif + rc = LDAP_REFERRAL; goto return_results; } @@ -94,9 +136,15 @@ ldbm_back_attribute( } if ((attr = attr_find(e->e_attrs, entry_at)) == NULL) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_attribute: failed to find %s.\n", entry_at_name )); +#else Debug( LDAP_DEBUG_ACL, "<= ldbm_back_attribute: failed to find %s\n", entry_at_name, 0, 0 ); +#endif + rc = LDAP_NO_SUCH_ATTRIBUTE; goto return_results; } @@ -140,12 +188,19 @@ ldbm_back_attribute( return_results: if( target != e ) { /* free entry and reader lock */ - cache_return_entry_r( &li->li_cache, e ); + cache_return_entry_r( &li->li_cache, e ); } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "ldbm_back_attribute: rc=%d nvals=%d.\n", + rc, j )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_attribute: rc=%d nvals=%d\n", rc, j, 0 ); +#endif + return(rc); } diff --git a/servers/slapd/back-ldbm/bind.c b/servers/slapd/back-ldbm/bind.c index 08c0d64baa..d33ea5fd30 100644 --- a/servers/slapd/back-ldbm/bind.c +++ b/servers/slapd/back-ldbm/bind.c @@ -43,7 +43,13 @@ ldbm_back_bind( AttributeDescription *password = slap_schema.si_ad_userPassword; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "ldbm_back_bind: dn: %s.\n", dn )); +#else Debug(LDAP_DEBUG_ARGS, "==> ldbm_back_bind: dn: %s\n", dn, 0, 0); +#endif + *edn = NULL; dn = ndn; @@ -103,8 +109,14 @@ ldbm_back_bind( if ( is_entry_alias( e ) ) { /* entry is an alias, don't allow bind */ +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_bind: entry (%s) is an alias.\n", e->e_dn )); +#else Debug( LDAP_DEBUG_TRACE, "entry is alias\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_ALIAS_PROBLEM, NULL, "entry is alias", NULL, NULL ); @@ -118,8 +130,14 @@ ldbm_back_bind( struct berval **refs = get_entry_referrals( be, conn, op, e ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_bind: entry(%s) is a referral.\n", e->e_dn )); +#else Debug( LDAP_DEBUG_TRACE, "entry is referral\n", 0, 0, 0 ); +#endif + if( refs != NULL ) { send_ldap_result( conn, op, LDAP_REFERRAL, diff --git a/servers/slapd/back-ldbm/cache.c b/servers/slapd/back-ldbm/cache.c index c1ad171020..ecd8de2ac9 100644 --- a/servers/slapd/back-ldbm/cache.c +++ b/servers/slapd/back-ldbm/cache.c @@ -47,8 +47,15 @@ static void lru_print(Cache *cache); static int cache_entry_rdwr_lock(Entry *e, int rw) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_ENTRY, + "cache_entry_rdwr_lock: %s lock on ID %ld\n", + rw ? "w" : "r", e->e_id )); +#else Debug( LDAP_DEBUG_ARGS, "entry_rdwr_%slock: ID: %ld\n", rw ? "w" : "r", e->e_id, 0); +#endif + if (rw) return ldap_pvt_thread_rdwr_wlock(&LEI(e)->lei_rdwr); @@ -59,8 +66,15 @@ cache_entry_rdwr_lock(Entry *e, int rw) static int cache_entry_rdwr_trylock(Entry *e, int rw) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_ENTRY, + "cache_entry_rdwr_trylock: try %s lock on ID: %ld.\n", + rw ? "w" : "r", e->e_id )); +#else Debug( LDAP_DEBUG_ARGS, "entry_rdwr_%strylock: ID: %ld\n", rw ? "w" : "r", e->e_id, 0); +#endif + if (rw) return ldap_pvt_thread_rdwr_wtrylock(&LEI(e)->lei_rdwr); @@ -71,8 +85,15 @@ cache_entry_rdwr_trylock(Entry *e, int rw) static int cache_entry_rdwr_unlock(Entry *e, int rw) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_ENTRY, + "cache_entry_rdwr_unlock: remove %s lock on ID %ld.\n", + rw ? "w" : "r", e->e_id )); +#else Debug( LDAP_DEBUG_ARGS, "entry_rdwr_%sunlock: ID: %ld\n", rw ? "w" : "r", e->e_id, 0); +#endif + if (rw) return ldap_pvt_thread_rdwr_wunlock(&LEI(e)->lei_rdwr); @@ -147,18 +168,32 @@ cache_return_entry_rw( Cache *cache, Entry *e, int rw ) /* free cache mutex */ ldap_pvt_thread_mutex_unlock( &cache->c_mutex ); +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_DETAIL1, + "cache_return_entry_rw: return (%ld):%s, refcnt=%d\n", + id, rw ? "w" : "r", refcnt )); +#else Debug( LDAP_DEBUG_TRACE, "====> cache_return_entry_%s( %ld ): created (%d)\n", rw ? "w" : "r", id, refcnt ); +#endif + } else if ( LEI(e)->lei_state == CACHE_ENTRY_DELETED ) { if( refcnt > 0 ) { /* free cache mutex */ ldap_pvt_thread_mutex_unlock( &cache->c_mutex ); +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_DETAIL1, + "cache_return_entry_rw: %ld, delete pending (%d).\n", + id, refcnt )); +#else Debug( LDAP_DEBUG_TRACE, "====> cache_return_entry_%s( %ld ): delete pending (%d)\n", rw ? "w" : "r", id, refcnt ); +#endif + } else { cache_entry_private_destroy( e ); @@ -167,18 +202,32 @@ cache_return_entry_rw( Cache *cache, Entry *e, int rw ) /* free cache mutex */ ldap_pvt_thread_mutex_unlock( &cache->c_mutex ); +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_DETAIL1, + "cache_return_entry_rw: (%ld): deleted (%d)\n", + id, refcnt )); +#else Debug( LDAP_DEBUG_TRACE, "====> cache_return_entry_%s( %ld ): deleted (%d)\n", rw ? "w" : "r", id, refcnt ); +#endif + } } else { /* free cache mutex */ ldap_pvt_thread_mutex_unlock( &cache->c_mutex ); +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_DETAIL1, + "cache_return_entry_rw: ID %ld:%s returned (%d)\n", + id, rw ? "w": "r", refcnt )); +#else Debug( LDAP_DEBUG_TRACE, "====> cache_return_entry_%s( %ld ): returned (%d)\n", rw ? "w" : "r", id, refcnt); +#endif + } } @@ -223,6 +272,11 @@ cache_add_entry_rw( int i, rc; Entry *ee; +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_ENTRY, + "cache_add_entry_rw: add (%s):%s to cache\n", + e->e_dn, rw ? "w" : "r" )); +#endif /* set cache mutex */ ldap_pvt_thread_mutex_lock( &cache->c_mutex ); @@ -232,9 +286,16 @@ cache_add_entry_rw( /* free cache mutex */ ldap_pvt_thread_mutex_unlock( &cache->c_mutex ); +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_ERR, + "cache_add_entry_rw: add (%s):%ld private init failed!\n", + e->e_dn, e->e_id )); +#else Debug( LDAP_DEBUG_ANY, "====> cache_add_entry( %ld ): \"%s\": private init failed!\n", e->e_id, e->e_dn, 0 ); +#endif + return( -1 ); } @@ -245,9 +306,16 @@ cache_add_entry_rw( /* free cache mutex */ ldap_pvt_thread_mutex_unlock( &cache->c_mutex ); +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_DETAIL1, + "cache_add_entry: (%s):%ld already in cache.\n", + e->e_dn, e->e_id )); +#else Debug( LDAP_DEBUG_TRACE, "====> cache_add_entry( %ld ): \"%s\": already in dn cache\n", e->e_id, e->e_dn, 0 ); +#endif + cache_entry_private_destroy(e); @@ -258,17 +326,31 @@ cache_add_entry_rw( if ( avl_insert( &cache->c_idtree, (caddr_t) e, (AVL_CMP) entry_id_cmp, avl_dup_error ) != 0 ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_DETAIL1, + "cache_add_entry: (%s):%ls already in cache.\n", + e->e_dn, e->e_id )); +#else Debug( LDAP_DEBUG_ANY, "====> cache_add_entry( %ld ): \"%s\": already in id cache\n", e->e_id, e->e_dn, 0 ); +#endif + /* delete from dn tree inserted above */ if ( avl_delete( &cache->c_dntree, (caddr_t) e, (AVL_CMP) entry_dn_cmp ) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_INFO, + "cache_add_entry: can't delete (%s) from cache.\n", + e->e_dn )); +#else Debug( LDAP_DEBUG_ANY, "====> can't delete from dn cache\n", 0, 0, 0 ); +#endif + } cache_entry_private_destroy(e); @@ -351,9 +433,16 @@ cache_update_entry( if ( avl_insert( &cache->c_dntree, (caddr_t) e, (AVL_CMP) entry_dn_cmp, avl_dup_error ) != 0 ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_DETAIL1, + "cache_update_entry: (%s):%ld already in dn cache\n", + e->e_dn, e->e_id )); +#else Debug( LDAP_DEBUG_TRACE, "====> cache_update_entry( %ld ): \"%s\": already in dn cache\n", e->e_id, e->e_dn, 0 ); +#endif + /* free cache mutex */ ldap_pvt_thread_mutex_unlock( &cache->c_mutex ); @@ -364,16 +453,30 @@ cache_update_entry( if ( avl_insert( &cache->c_idtree, (caddr_t) e, (AVL_CMP) entry_id_cmp, avl_dup_error ) != 0 ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_DETAIL1, + "cache_update_entry: (%s)%ld already in id cache\n", + e->e_dn, e->e_id )); +#else Debug( LDAP_DEBUG_ANY, "====> cache_update_entry( %ld ): \"%s\": already in id cache\n", e->e_id, e->e_dn, 0 ); +#endif + /* delete from dn tree inserted above */ if ( avl_delete( &cache->c_dntree, (caddr_t) e, (AVL_CMP) entry_dn_cmp ) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_INFO, + "cache_update_entry: can't delete (%s)%ld from dn cache.\n", + e->e_dn, e->e_id )); +#else Debug( LDAP_DEBUG_ANY, "====> can't delete from dn cache\n", 0, 0, 0 ); +#endif + } /* free cache mutex */ @@ -479,9 +582,16 @@ try_again: /* free cache mutex */ ldap_pvt_thread_mutex_unlock( &cache->c_mutex ); +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_INFO, + "cache_find_entry_dn2id: (%s)%ld not ready: %d\n", + dn, id, state )); +#else Debug(LDAP_DEBUG_TRACE, "====> cache_find_entry_dn2id(\"%s\"): %ld (not ready) %d\n", dn, id, state); +#endif + ldap_pvt_thread_yield(); goto try_again; @@ -490,13 +600,20 @@ try_again: /* lru */ LRU_DELETE( cache, ep ); LRU_ADD( cache, ep ); - + /* free cache mutex */ ldap_pvt_thread_mutex_unlock( &cache->c_mutex ); +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_DETAIL1, + "cache_find_entry_dn2id: (%s)%ld %d tries\n", + dn, id, count )); +#else Debug(LDAP_DEBUG_TRACE, "====> cache_find_entry_dn2id(\"%s\"): %ld (%d tries)\n", dn, id, count); +#endif + } else { /* free cache mutex */ @@ -554,9 +671,17 @@ try_again: /* free cache mutex */ ldap_pvt_thread_mutex_unlock( &cache->c_mutex ); +#ifdef NEW_LOGGING + LDAP_LOG(( "caceh", LDAP_LEVEL_INFO, + "cache_find_entry_id: (%ld)->%ld not ready (%d).\n", + id, ep_id, state )); + +#else Debug(LDAP_DEBUG_TRACE, "====> cache_find_entry_id( %ld ): %ld (not ready) %d\n", id, ep_id, state); +#endif + ldap_pvt_thread_yield(); goto try_again; @@ -572,9 +697,16 @@ try_again: /* free cache mutex */ ldap_pvt_thread_mutex_unlock( &cache->c_mutex ); +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_INFO, + "cache_find_entry_id: %ld -> %ld (busy) %d.\n", + id, ep_id, state )); +#else Debug(LDAP_DEBUG_TRACE, "====> cache_find_entry_id( %ld ): %ld (busy) %d\n", id, ep_id, state); +#endif + ldap_pvt_thread_yield(); goto try_again; @@ -583,15 +715,22 @@ try_again: /* lru */ LRU_DELETE( cache, ep ); LRU_ADD( cache, ep ); - + LEI(ep)->lei_refcnt++; /* free cache mutex */ ldap_pvt_thread_mutex_unlock( &cache->c_mutex ); +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_DETAIL1, + "cache_find_entry_id: %ld -> %s found %d tries.\n", + ep_id, ep->e_dn, count )); +#else Debug(LDAP_DEBUG_TRACE, "====> cache_find_entry_id( %ld ) \"%s\" (found) (%d tries)\n", ep_id, ep->e_dn, count); +#endif + return( ep ); } @@ -626,8 +765,14 @@ cache_delete_entry( assert( e->e_private ); +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_ENTRY, + "cache_delete_entry: delete %ld.\n", e->e_id )); +#else Debug( LDAP_DEBUG_TRACE, "====> cache_delete_entry( %ld )\n", e->e_id, 0, 0 ); +#endif + rc = cache_delete_entry_internal( cache, e ); @@ -642,7 +787,7 @@ cache_delete_entry_internal( Entry *e ) { - int rc = 0; /* return code */ + int rc = 0; /* return code */ /* dn tree */ if ( avl_delete( &cache->c_dntree, (caddr_t) e, (AVL_CMP) entry_dn_cmp ) @@ -683,7 +828,13 @@ cache_release_all( Cache *cache ) /* set cache mutex */ ldap_pvt_thread_mutex_lock( &cache->c_mutex ); +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_ENTRY, + "cache_release_all: enter\n" )); +#else Debug( LDAP_DEBUG_TRACE, "====> cache_release_all\n", 0, 0, 0 ); +#endif + while ( (e = cache->c_lrutail) != NULL && LEI(e)->lei_refcnt == 0 ) { #ifdef LDAP_RDWR_DEBUG @@ -698,7 +849,13 @@ cache_release_all( Cache *cache ) } if ( cache->c_cursize ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_INFO, + "cache_release_all: Entry cache could not be emptied.\n" )); +#else Debug( LDAP_DEBUG_TRACE, "Entry-cache could not be emptied\n", 0, 0, 0 ); +#endif + } /* free cache mutex */ diff --git a/servers/slapd/back-ldbm/close.c b/servers/slapd/back-ldbm/close.c index 5ba0c64503..452d38f222 100644 --- a/servers/slapd/back-ldbm/close.c +++ b/servers/slapd/back-ldbm/close.c @@ -17,9 +17,21 @@ int ldbm_back_db_close( Backend *be ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_CRIT, + "ldbm_back_db_close: ldbm backend syncing\n" )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm backend syncing\n", 0, 0, 0 ); +#endif + ldbm_cache_flush_all( be ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_CRIT, + "ldbm_back_db_close: ldbm backend synch'ed\n" )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm backend done syncing\n", 0, 0, 0 ); +#endif + cache_release_all( &((struct ldbminfo *) be->be_private)->li_cache ); diff --git a/servers/slapd/back-ldbm/compare.c b/servers/slapd/back-ldbm/compare.c index d17c1f4cbb..ba1ee41e70 100644 --- a/servers/slapd/back-ldbm/compare.c +++ b/servers/slapd/back-ldbm/compare.c @@ -64,8 +64,14 @@ ldbm_back_compare( struct berval **refs = get_entry_referrals( be, conn, op, e ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_compare: entry (%s) is a referral.\n", e->e_dn )); +#else Debug( LDAP_DEBUG_TRACE, "entry is referral\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_REFERRAL, e->e_dn, NULL, refs, NULL ); diff --git a/servers/slapd/back-ldbm/dbcache.c b/servers/slapd/back-ldbm/dbcache.c index 97b5a5e04b..2a57127a3e 100644 --- a/servers/slapd/back-ldbm/dbcache.c +++ b/servers/slapd/back-ldbm/dbcache.c @@ -49,8 +49,14 @@ ldbm_cache_open( flags |= LDBM_NOSYNC; } +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_ENTRY, + "ldbm_cache_open: \"%s\", %d, %o\n", buf, flags, li->li_mode )); +#else Debug( LDAP_DEBUG_TRACE, "=> ldbm_cache_open( \"%s\", %d, %o )\n", buf, flags, li->li_mode ); +#endif + curtime = slap_get_time(); empty = MAXDBCACHE; @@ -74,7 +80,7 @@ ldbm_cache_open( { /* we don't want to use an open cache with different * permissions (esp. if we need write but the open - * cache is read-only). So close this one if + * cache is read-only). So close this one if * possible, and re-open below. * * FIXME: what about the case where the refcount @@ -91,8 +97,14 @@ ldbm_cache_open( break; } li->li_dbcache[i].dbc_refcnt++; +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_DETAIL1, + "ldbm_cache_open: cache %d\n", i )); +#else Debug( LDAP_DEBUG_TRACE, "<= ldbm_cache_open (cache %d)\n", i, 0, 0 ); +#endif + ldap_pvt_thread_mutex_unlock( &li->li_dbcache_mutex ); return( &li->li_dbcache[i] ); } @@ -115,9 +127,15 @@ ldbm_cache_open( free( li->li_dbcache[i].dbc_name ); li->li_dbcache[i].dbc_name = NULL; } else { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_INFO, + "ldbm_cache_open: no unused db to close - waiting\n" )); +#else Debug( LDAP_DEBUG_ANY, "ldbm_cache_open no unused db to close - waiting\n", 0, 0, 0 ); +#endif + ldap_pvt_thread_cond_wait( &li->li_dbcache_cv, &li->li_dbcache_mutex ); /* after waiting for a free slot, go back to square @@ -132,10 +150,18 @@ ldbm_cache_open( li->li_dbcachesize )) == NULL ) { int err = errno; +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_ERR, + "ldbm_cache_open: \"%s\" failed, errono=%d, reason=%s\n", + buf, err, err > -1 && err < sys_nerr ? sys_errlist[err] : + "unknown" )); +#else Debug( LDAP_DEBUG_TRACE, "<= ldbm_cache_open NULL \"%s\" errno=%d reason=\"%s\")\n", buf, err, err > -1 && err < sys_nerr ? sys_errlist[err] : "unknown" ); +#endif + ldap_pvt_thread_mutex_unlock( &li->li_dbcache_mutex ); return( NULL ); } @@ -159,11 +185,25 @@ ldbm_cache_open( assert( li->li_dbcache[i].dbc_maxindirect < 256 ); +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_ARGS, + "ldbm_cache_open: blksize:%ld maxids:%d maxindirect:%d\n", + li->li_dbcache[i].dbc_blksize, li->li_dbcache[i].dbc_maxids, + li->li_dbcache[i].dbc_maxindirect )); +#else Debug( LDAP_DEBUG_ARGS, "ldbm_cache_open (blksize %ld) (maxids %d) (maxindirect %d)\n", li->li_dbcache[i].dbc_blksize, li->li_dbcache[i].dbc_maxids, li->li_dbcache[i].dbc_maxindirect ); +#endif + +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_DETAIL1, + "ldbm_cache_open: opened %d\n", i )); +#else Debug( LDAP_DEBUG_TRACE, "<= ldbm_cache_open (opened %d)\n", i, 0, 0 ); +#endif + ldap_pvt_thread_mutex_unlock( &li->li_dbcache_mutex ); return( &li->li_dbcache[i] ); } @@ -211,19 +251,40 @@ ldbm_cache_flush_all( Backend *be ) ldap_pvt_thread_mutex_lock( &li->li_dbcache_mutex ); for ( i = 0; i < MAXDBCACHE; i++ ) { if ( li->li_dbcache[i].dbc_name != NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_DETAIL1, + "ldbm_cache_flush_all: flushing db (%s)\n", + li->li_dbcache[i].dbc_name )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm flushing db (%s)\n", li->li_dbcache[i].dbc_name, 0, 0 ); +#endif + ldbm_sync( li->li_dbcache[i].dbc_db ); li->li_dbcache[i].dbc_dirty = 0; if ( li->li_dbcache[i].dbc_refcnt != 0 ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_INFO, + "ldbm_cache_flush_all: couldn't close db (%s), refcnt=%d\n", + li->li_dbcache[i].dbc_name, li->li_dbcache[i].dbc_refcnt )); +#else Debug( LDAP_DEBUG_TRACE, "refcnt = %d, couldn't close db (%s)\n", li->li_dbcache[i].dbc_refcnt, li->li_dbcache[i].dbc_name, 0 ); +#endif + } else { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_DETAIL1, + "ldbm_cache_flush_all: ldbm closing db (%s)\n", + li->li_dbcache[i].dbc_name )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm closing db (%s)\n", li->li_dbcache[i].dbc_name, 0, 0 ); +#endif + ldap_pvt_thread_cond_signal( &li->li_dbcache_cv ); ldbm_close( li->li_dbcache[i].dbc_db ); free( li->li_dbcache[i].dbc_name ); diff --git a/servers/slapd/back-ldbm/delete.c b/servers/slapd/back-ldbm/delete.c index dd0f7fc971..09b51cb7b9 100644 --- a/servers/slapd/back-ldbm/delete.c +++ b/servers/slapd/back-ldbm/delete.c @@ -34,15 +34,27 @@ ldbm_back_delete( int manageDSAit = get_manageDSAit( op ); AttributeDescription *children = slap_schema.si_ad_children; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "ldbm_back_delete: %s\n", dn )); +#else Debug(LDAP_DEBUG_ARGS, "==> ldbm_back_delete: %s\n", dn, 0, 0); +#endif + /* get entry with writer lock */ if ( (e = dn2entry_w( be, ndn, &matched )) == NULL ) { char *matched_dn = NULL; struct berval **refs = NULL; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_delete: no such object %s\n", dn )); +#else Debug(LDAP_DEBUG_ARGS, "<=- ldbm_back_delete: no such object %s\n", dn, 0, 0); +#endif + if ( matched != NULL ) { matched_dn = ch_strdup( matched->e_dn ); @@ -71,8 +83,15 @@ ldbm_back_delete( struct berval **refs = get_entry_referrals( be, conn, op, e ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_delete: entry (%s) is a referral.\n", + e->e_dn )); +#else Debug( LDAP_DEBUG_TRACE, "entry is referral\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_REFERRAL, e->e_dn, NULL, refs, NULL ); @@ -85,8 +104,14 @@ ldbm_back_delete( if ( has_children( be, e ) ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_back_delete: (%s) is a non-leaf node.\n", dn )); +#else Debug(LDAP_DEBUG_ARGS, "<=- ldbm_back_delete: non leaf %s\n", dn, 0, 0); +#endif + send_ldap_result( conn, op, LDAP_NOT_ALLOWED_ON_NONLEAF, NULL, "subtree delete not supported", NULL, NULL ); goto return_results; @@ -95,9 +120,15 @@ ldbm_back_delete( /* delete from parent's id2children entry */ if( (pdn = dn_parent( be, e->e_ndn )) != NULL ) { if( (p = dn2entry_w( be, pdn, NULL )) == NULL) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_back_delete: parent of (%s) does not exist\n", dn )); +#else Debug( LDAP_DEBUG_TRACE, "<=- ldbm_back_delete: parent does not exist\n", 0, 0, 0); +#endif + send_ldap_result( conn, op, LDAP_OTHER, NULL, "could not locate parent of entry", NULL, NULL ); goto return_results; @@ -107,9 +138,15 @@ ldbm_back_delete( if ( ! access_allowed( be, conn, op, p, children, NULL, ACL_WRITE ) ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_back_delete: no access to parent of (%s)\n", dn )); +#else Debug( LDAP_DEBUG_TRACE, "<=- ldbm_back_delete: no access to parent\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_INSUFFICIENT_ACCESS, NULL, NULL, NULL, NULL ); goto return_results; @@ -118,9 +155,16 @@ ldbm_back_delete( } else { /* no parent, must be root to delete */ if( ! be_isroot( be, op->o_ndn ) ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_back_delete: (%s) has no parent & not a root.\n", + dn )); +#else Debug( LDAP_DEBUG_TRACE, "<=- ldbm_back_delete: no parent & not root\n", 0, 0, 0); +#endif + send_ldap_result( conn, op, LDAP_INSUFFICIENT_ACCESS, NULL, NULL, NULL, NULL ); goto return_results; @@ -132,9 +176,15 @@ ldbm_back_delete( /* delete from dn2id mapping */ if ( dn2id_delete( be, e->e_ndn, e->e_id ) != 0 ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_back_delete: (%s) operations error\n", dn )); +#else Debug(LDAP_DEBUG_ARGS, "<=- ldbm_back_delete: operations error %s\n", dn, 0, 0); +#endif + send_ldap_result( conn, op, LDAP_OTHER, NULL, "DN index delete failed", NULL, NULL ); goto return_results; @@ -142,9 +192,16 @@ ldbm_back_delete( /* delete from disk and cache */ if ( id2entry_delete( be, e ) != 0 ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_back_delete: (%s) operations error\n", + dn )); +#else Debug(LDAP_DEBUG_ARGS, "<=- ldbm_back_delete: operations error %s\n", dn, 0, 0); +#endif + send_ldap_result( conn, op, LDAP_OTHER, NULL, "entry delete failed", NULL, NULL ); goto return_results; diff --git a/servers/slapd/back-ldbm/dn2id.c b/servers/slapd/back-ldbm/dn2id.c index 81f1154a85..8841ef1435 100644 --- a/servers/slapd/back-ldbm/dn2id.c +++ b/servers/slapd/back-ldbm/dn2id.c @@ -28,13 +28,25 @@ dn2id_add( Datum key, data; struct ldbminfo *li = (struct ldbminfo *) be->be_private; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "dn2id_add: (%s):%ld\n", dn, id )); +#else Debug( LDAP_DEBUG_TRACE, "=> dn2id_add( \"%s\", %ld )\n", dn, id, 0 ); +#endif + assert( id != NOID ); if ( (db = ldbm_cache_open( be, "dn2id", LDBM_SUFFIX, LDBM_WRCREAT )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "dn2id_add: couldn't open/create dn2id%s\n", LDBM_SUFFIX )); +#else Debug( LDAP_DEBUG_ANY, "Could not open/create dn2id%s\n", LDBM_SUFFIX, 0, 0 ); +#endif + return( -1 ); } @@ -91,7 +103,13 @@ dn2id_add( ldbm_cache_close( be, db ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "dn2id_add: return %d\n", rc )); +#else Debug( LDAP_DEBUG_TRACE, "<= dn2id_add %d\n", rc, 0, 0 ); +#endif + return( rc ); } @@ -106,19 +124,37 @@ dn2id( ID id; Datum key, data; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "dn2id: (%s)\n", dn )); +#else Debug( LDAP_DEBUG_TRACE, "=> dn2id( \"%s\" )\n", dn, 0, 0 ); +#endif + /* first check the cache */ if ( (id = cache_find_entry_dn2id( be, &li->li_cache, dn )) != NOID ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "dn2id: (%s)%ld in cache.\n", dn, id )); +#else Debug( LDAP_DEBUG_TRACE, "<= dn2id %ld (in cache)\n", id, 0, 0 ); +#endif + return( id ); } if ( (db = ldbm_cache_open( be, "dn2id", LDBM_SUFFIX, LDBM_WRCREAT )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "dn2id: couldn't open dn2id%s\n", LDBM_SUFFIX )); +#else Debug( LDAP_DEBUG_ANY, "<= dn2id could not open dn2id%s\n", LDBM_SUFFIX, 0, 0 ); +#endif + return( NOID ); } @@ -135,7 +171,13 @@ dn2id( free( key.dptr ); if ( data.dptr == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "dn2id: (%s) NOID\n", dn )); +#else Debug( LDAP_DEBUG_TRACE, "<= dn2id NOID\n", 0, 0, 0 ); +#endif + return( NOID ); } @@ -145,7 +187,13 @@ dn2id( ldbm_datum_free( db->dbc_db, data ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "dn2id: %ld\n", id )); +#else Debug( LDAP_DEBUG_TRACE, "<= dn2id %ld\n", id, 0, 0 ); +#endif + return( id ); } @@ -160,12 +208,24 @@ dn2idl( Datum key; ID_BLOCK *idl; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "dn2idl: \"%c%s\"\n", prefix, dn )); +#else Debug( LDAP_DEBUG_TRACE, "=> dn2idl( \"%c%s\" )\n", prefix, dn, 0 ); +#endif + if ( (db = ldbm_cache_open( be, "dn2id", LDBM_SUFFIX, LDBM_WRCREAT )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "dn2idl: could not open dn2id%s\n", LDBM_SUFFIX )); +#else Debug( LDAP_DEBUG_ANY, "<= dn2idl could not open dn2id%s\n", LDBM_SUFFIX, 0, 0 ); +#endif + return NULL; } @@ -196,15 +256,27 @@ dn2id_delete( Datum key; int rc; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "dn2id_delete: (%s)%ld\n", dn, id )); +#else Debug( LDAP_DEBUG_TRACE, "=> dn2id_delete( \"%s\", %ld )\n", dn, id, 0 ); +#endif + assert( id != NOID ); if ( (db = ldbm_cache_open( be, "dn2id", LDBM_SUFFIX, LDBM_WRCREAT )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "dn2id_delete: couldn't open db2id%s\n", LDBM_SUFFIX )); +#else Debug( LDAP_DEBUG_ANY, "<= dn2id_delete could not open dn2id%s\n", LDBM_SUFFIX, 0, 0 ); +#endif + return( -1 ); } @@ -258,7 +330,13 @@ dn2id_delete( ldbm_cache_close( be, db ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "dn2id_delete: return %d\n", rc )); +#else Debug( LDAP_DEBUG_TRACE, "<= dn2id_delete %d\n", rc, 0, 0 ); +#endif + return( rc ); } @@ -272,15 +350,22 @@ dn2entry_rw( Backend *be, const char *dn, Entry **matched, - int rw + int rw ) { ID id; Entry *e = NULL; char *pdn; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "dn2entry_rw: %s entry %s\n", rw ? "w" : "r", + dn )); +#else Debug(LDAP_DEBUG_TRACE, "dn2entry_%s: dn: \"%s\"\n", rw ? "w" : "r", dn, 0); +#endif + if( matched != NULL ) { /* caller cares about match */ @@ -294,9 +379,16 @@ dn2entry_rw( } if ( id != NOID ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "dn2entry_rw: no entry for valid id (%ld), dn (%s)\n", + id, dn )); +#else Debug(LDAP_DEBUG_ANY, "dn2entry_%s: no entry for valid id (%ld), dn \"%s\"\n", rw ? "w" : "r", id, dn); +#endif + /* must have been deleted from underneath us */ /* treat as if NOID was found */ } diff --git a/servers/slapd/back-ldbm/filterindex.c b/servers/slapd/back-ldbm/filterindex.c index 5fa63bdc22..1d74d15bec 100644 --- a/servers/slapd/back-ldbm/filterindex.c +++ b/servers/slapd/back-ldbm/filterindex.c @@ -38,62 +38,137 @@ filter_candidates( { ID_BLOCK *result, *tmp1, *tmp2; +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ENTRY, "filter_candidates: enter\n")); +#else Debug( LDAP_DEBUG_TRACE, "=> filter_candidates\n", 0, 0, 0 ); +#endif + result = NULL; switch ( f->f_choice ) { case SLAPD_FILTER_DN_ONE: +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_DETAIL1, + "filter_candidates: DN ONE (%s)\n", f->f_dn )); +#else Debug( LDAP_DEBUG_FILTER, "\tDN ONE\n", 0, 0, 0 ); +#endif + result = dn2idl( be, f->f_dn, DN_ONE_PREFIX ); break; case SLAPD_FILTER_DN_SUBTREE: +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_DETAIL1, + "filter_candidates: DN SUBTREE (%s)\n", f->f_dn )); +#else Debug( LDAP_DEBUG_FILTER, "\tDN SUBTREE\n", 0, 0, 0 ); +#endif + result = dn2idl( be, f->f_dn, DN_SUBTREE_PREFIX ); break; case LDAP_FILTER_PRESENT: +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_DETAIL1, + "filter_candidates: Present (%s)\n", f->f_desc->ad_cname->bv_val )); +#else Debug( LDAP_DEBUG_FILTER, "\tPRESENT\n", 0, 0, 0 ); +#endif + result = presence_candidates( be, f->f_desc ); break; case LDAP_FILTER_EQUALITY: +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_DETAIL1, + "filter_candidates: EQUALITY (%s),(%s)\n", + f->f_ava->aa_desc->ad_cname->bv_val, + f->f_ava->aa_value->bv_val )); +#else Debug( LDAP_DEBUG_FILTER, "\tEQUALITY\n", 0, 0, 0 ); +#endif + result = equality_candidates( be, f->f_ava ); break; case LDAP_FILTER_APPROX: +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_DETAIL1, + "filter_candidates: APPROX (%s), (%s)\n", + f->f_ava->aa_desc->ad_cname->bv_val, + f->f_ava->aa_value->bv_val )); +#else Debug( LDAP_DEBUG_FILTER, "\tAPPROX\n", 0, 0, 0 ); +#endif + result = approx_candidates( be, f->f_ava ); break; case LDAP_FILTER_SUBSTRINGS: +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_DETAIL1, + "filter_candidates: SUBSTRINGS\n")); +#else Debug( LDAP_DEBUG_FILTER, "\tSUBSTRINGS\n", 0, 0, 0 ); +#endif + result = substring_candidates( be, f->f_sub ); break; case LDAP_FILTER_GE: +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_DETAIL1, + "filter_candidates: GE\n")); +#else Debug( LDAP_DEBUG_FILTER, "\tGE\n", 0, 0, 0 ); +#endif + result = idl_allids( be ); break; case LDAP_FILTER_LE: +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_DETAIL1, + "filter_candidates: LE\n" )); +#else Debug( LDAP_DEBUG_FILTER, "\tLE\n", 0, 0, 0 ); +#endif + result = idl_allids( be ); break; case LDAP_FILTER_AND: +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_DETAIL1, + "filter_candidates: AND\n" )); +#else Debug( LDAP_DEBUG_FILTER, "\tAND\n", 0, 0, 0 ); +#endif + result = list_candidates( be, f->f_and, LDAP_FILTER_AND ); break; case LDAP_FILTER_OR: +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_DETAIL1, + "filter_candidates: OR\n" )); +#else Debug( LDAP_DEBUG_FILTER, "\tOR\n", 0, 0, 0 ); +#endif + result = list_candidates( be, f->f_or, LDAP_FILTER_OR ); break; case LDAP_FILTER_NOT: +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_DETAIL1, + "filter_candidates: NOT\n" )); +#else Debug( LDAP_DEBUG_FILTER, "\tNOT\n", 0, 0, 0 ); +#endif + tmp1 = idl_allids( be ); tmp2 = filter_candidates( be, f->f_not ); result = idl_notin( be, tmp1, tmp2 ); @@ -102,8 +177,15 @@ filter_candidates( break; } +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ENTRY, + "filter_candidates: return %ld\n", + result ? ID_BLOCK_NIDS(result) : 0 )); +#else Debug( LDAP_DEBUG_TRACE, "<= filter_candidates %ld\n", result ? ID_BLOCK_NIDS(result) : 0, 0, 0 ); +#endif + return( result ); } @@ -120,7 +202,13 @@ presence_candidates( slap_mask_t mask; struct berval *prefix; +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ENTRY, + "presence_candidates: enter\n" )); +#else Debug( LDAP_DEBUG_TRACE, "=> presence_candidates\n", 0, 0, 0 ); +#endif + idl = idl_allids( be ); @@ -128,17 +216,30 @@ presence_candidates( &dbname, &mask, &prefix ); if( rc != LDAP_SUCCESS ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_INFO, + "presence_candidates: index_param returned %d\n", + rc )); +#else Debug( LDAP_DEBUG_TRACE, "<= presence_candidates: index_param returned=%d\n", rc, 0, 0 ); +#endif + return idl; } if( dbname == NULL ) { /* not indexed */ +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_INFO, + "presence_candidates: not indexed\n" )); +#else Debug( LDAP_DEBUG_TRACE, "<= presense_candidates: not indexed\n", 0, 0, 0 ); +#endif + ber_bvfree( prefix ); return idl; } @@ -146,9 +247,16 @@ presence_candidates( db = ldbm_cache_open( be, dbname, LDBM_SUFFIX, LDBM_READER ); if ( db == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_INFO, + "presence_candidates: db open failed (%s%s)\n", + dbname, LDBM_SUFFIX )); +#else Debug( LDAP_DEBUG_ANY, "<= presense_candidates db open failed (%s%s)\n", dbname, LDBM_SUFFIX, 0 ); +#endif + ber_bvfree( prefix ); return idl; } @@ -160,22 +268,41 @@ presence_candidates( rc = key_read( be, db, prefix, &idl ); if( rc != LDAP_SUCCESS ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ERR, + "presence_candidates: key read failed (%d)\n", rc )); +#else Debug( LDAP_DEBUG_TRACE, "<= presense_candidates key read failed (%d)\n", rc, 0, 0 ); +#endif + } else if( idl == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_DETAIL1, + "presence_candidates: NULL\n" )); +#else Debug( LDAP_DEBUG_TRACE, "<= presense_candidates NULL\n", 0, 0, 0 ); +#endif + } } ldbm_cache_close( be, db ); ber_bvfree( prefix ); +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ENTRY, + "presence_candidates: return %ld\n", + idl ? ID_BLOCK_NIDS(idl) : 0 )); +#else Debug( LDAP_DEBUG_TRACE, "<= presence_candidates %ld\n", idl ? ID_BLOCK_NIDS(idl) : 0, 0, 0 ); +#endif + return( idl ); } @@ -195,7 +322,13 @@ equality_candidates( struct berval **keys = NULL; MatchingRule *mr; +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ENTRY, + "equality_candidates: enter\n" )); +#else Debug( LDAP_DEBUG_TRACE, "=> equality_candidates\n", 0, 0, 0 ); +#endif + idl = idl_allids( be ); @@ -203,17 +336,29 @@ equality_candidates( &dbname, &mask, &prefix ); if( rc != LDAP_SUCCESS ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ERR, + "equality_candidates: index_param returned %d\n", rc )); +#else Debug( LDAP_DEBUG_TRACE, "<= equality_candidates: index_param returned=%d\n", rc, 0, 0 ); +#endif + return idl; } if( dbname == NULL ) { /* not indexed */ +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ERR, + "equality_candidates: not indexed\n" )); +#else Debug( LDAP_DEBUG_TRACE, "<= equality_candidates: not indexed\n", 0, 0, 0 ); +#endif + ber_bvfree( prefix ); return idl; } @@ -241,25 +386,46 @@ equality_candidates( ber_bvfree( prefix ); if( rc != LDAP_SUCCESS ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ERR, + "equality_candidates: (%s%s) MR filter failed (%d\n", + dbname, LDBM_SUFFIX, rc )); +#else Debug( LDAP_DEBUG_TRACE, "<= equality_candidates: (%s%s) MR filter failed (%d)\n", dbname, LDBM_SUFFIX, rc ); +#endif + return idl; } if( keys == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ERR, + "equality_candidates: no keys (%s%s)\n", + dbname, LDBM_SUFFIX )); +#else Debug( LDAP_DEBUG_TRACE, "<= equality_candidates: no keys (%s%s)\n", dbname, LDBM_SUFFIX, 0 ); +#endif + return idl; } db = ldbm_cache_open( be, dbname, LDBM_SUFFIX, LDBM_READER ); if ( db == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ERR, + "equality_candidates: db open failed (%s%s)\n", + dbname, LDBM_SUFFIX )); +#else Debug( LDAP_DEBUG_ANY, "<= equality_candidates db open failed (%s%s)\n", dbname, LDBM_SUFFIX, 0 ); +#endif + return idl; } @@ -272,18 +438,30 @@ equality_candidates( if( rc != LDAP_SUCCESS ) { idl_free( idl ); idl = NULL; +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ERR, + "equality_candidates: key read failed (%d)\n", rc )); +#else Debug( LDAP_DEBUG_TRACE, "<= equality_candidates key read failed (%d)\n", rc, 0, 0 ); +#endif + break; } if( tmp == NULL ) { idl_free( idl ); idl = NULL; +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_INFO, + "equality_candidates NULL\n" )); +#else Debug( LDAP_DEBUG_TRACE, "<= equality_candidates NULL\n", 0, 0, 0 ); +#endif + break; } @@ -300,8 +478,15 @@ equality_candidates( ldbm_cache_close( be, db ); +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ENTRY, + "equality_candidates: return %ld\n", + idl ? ID_BLOCK_NIDS(idl) : 0 )); +#else Debug( LDAP_DEBUG_TRACE, "<= equality_candidates %ld\n", idl ? ID_BLOCK_NIDS(idl) : 0, 0, 0 ); +#endif + return( idl ); } @@ -321,7 +506,13 @@ approx_candidates( struct berval **keys = NULL; MatchingRule *mr; +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ENTRY, + "approx_candidates: enter\n" )); +#else Debug( LDAP_DEBUG_TRACE, "=> approx_candidates\n", 0, 0, 0 ); +#endif + idl = idl_allids( be ); @@ -329,17 +520,29 @@ approx_candidates( &dbname, &mask, &prefix ); if( rc != LDAP_SUCCESS ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ERR, + "approx_candidates: index_param returned %d\n", rc )); +#else Debug( LDAP_DEBUG_TRACE, "<= approx_candidates: index_param returned=%d\n", rc, 0, 0 ); +#endif + return idl; } if( dbname == NULL ) { /* not indexed */ +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ERR, + "approx_candidates: not indexed\n" )); +#else Debug( LDAP_DEBUG_ANY, "<= approx_candidates: not indexed\n", 0, 0, 0 ); +#endif + ber_bvfree( prefix ); return idl; } @@ -372,25 +575,46 @@ approx_candidates( ber_bvfree( prefix ); if( rc != LDAP_SUCCESS ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ERR, + "approx_candidates: (%s%s) MR filter failed (%d)\n", + dbname, LDBM_SUFFIX, rc )); +#else Debug( LDAP_DEBUG_TRACE, "<= approx_candidates: (%s%s) MR filter failed (%d)\n", dbname, LDBM_SUFFIX, rc ); +#endif + return idl; } if( keys == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_INFO, + "approx_candidates: no keys (%s%s)\n", + dbname, LDBM_SUFFIX )); +#else Debug( LDAP_DEBUG_TRACE, "<= approx_candidates: no keys (%s%s)\n", dbname, LDBM_SUFFIX, 0 ); +#endif + return idl; } db = ldbm_cache_open( be, dbname, LDBM_SUFFIX, LDBM_READER ); if ( db == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ERR, + "approx_candidates db open failed (%s%s)\n", + dbname, LDBM_SUFFIX )); +#else Debug( LDAP_DEBUG_ANY, "<= approx_candidates db open failed (%s%s)\n", dbname, LDBM_SUFFIX, 0 ); +#endif + return idl; } @@ -403,16 +627,28 @@ approx_candidates( if( rc != LDAP_SUCCESS ) { idl_free( idl ); idl = NULL; +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ERR, + "approx_candidates: key read failed (%d)\n", rc )); +#else Debug( LDAP_DEBUG_TRACE, "<= approx_candidates key read failed (%d)\n", rc, 0, 0 ); +#endif + break; } if( tmp == NULL ) { idl_free( idl ); idl = NULL; +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_INFO, + "approx_candidates: NULL\n" )); +#else Debug( LDAP_DEBUG_TRACE, "<= approx_candidates NULL\n", 0, 0, 0 ); +#endif + break; } @@ -427,8 +663,15 @@ approx_candidates( ldbm_cache_close( be, db ); +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ENTRY, + "approx_candidates: return %ld\n", + idl ? ID_BLOCK_NIDS(idl) : 0 )); +#else Debug( LDAP_DEBUG_TRACE, "<= approx_candidates %ld\n", idl ? ID_BLOCK_NIDS(idl) : 0, 0, 0 ); +#endif + return( idl ); } @@ -442,16 +685,28 @@ list_candidates( ID_BLOCK *idl, *tmp, *tmp2; Filter *f; +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ENTRY, + "list_candidates: 0x%x\n", ftype )); +#else Debug( LDAP_DEBUG_TRACE, "=> list_candidates 0x%x\n", ftype, 0, 0 ); +#endif + idl = NULL; for ( f = flist; f != NULL; f = f->f_next ) { if ( (tmp = filter_candidates( be, f )) == NULL && ftype == LDAP_FILTER_AND ) { - Debug( LDAP_DEBUG_TRACE, - "<= list_candidates NULL\n", 0, 0, 0 ); - idl_free( idl ); - return( NULL ); +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_INFO, + "list_candidates: NULL\n" )); +#else + Debug( LDAP_DEBUG_TRACE, + "<= list_candidates NULL\n", 0, 0, 0 ); +#endif + + idl_free( idl ); + return( NULL ); } tmp2 = idl; @@ -468,8 +723,15 @@ list_candidates( } } +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ENTRY, + "list_candidates: return %ld\n", + idl ? ID_BLOCK_NIDS(idl) : 0 )); +#else Debug( LDAP_DEBUG_TRACE, "<= list_candidates %ld\n", idl ? ID_BLOCK_NIDS(idl) : 0, 0, 0 ); +#endif + return( idl ); } @@ -489,7 +751,13 @@ substring_candidates( struct berval **keys = NULL; MatchingRule *mr; +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ENTRY, + "substrings_candidates: enter\n" )); +#else Debug( LDAP_DEBUG_TRACE, "=> substrings_candidates\n", 0, 0, 0 ); +#endif + idl = idl_allids( be ); @@ -497,17 +765,29 @@ substring_candidates( &dbname, &mask, &prefix ); if( rc != LDAP_SUCCESS ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ERR, + "substrings_candidates: index_param returned %d\n", rc )); +#else Debug( LDAP_DEBUG_TRACE, "<= substrings_candidates: index_param returned=%d\n", rc, 0, 0 ); +#endif + return idl; } if( dbname == NULL ) { /* not indexed */ +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ERR, + "substrings_candidates: not indexed\n" )); +#else Debug( LDAP_DEBUG_ANY, "<= substrings_candidates: not indexed\n", 0, 0, 0 ); +#endif + ber_bvfree( prefix ); return idl; } @@ -536,25 +816,46 @@ substring_candidates( ber_bvfree( prefix ); if( rc != LDAP_SUCCESS ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ERR, + "substrings_candidates: (%s%s) MR filter failed (%d)\n", + dbname, LDBM_SUFFIX, rc )); +#else Debug( LDAP_DEBUG_TRACE, "<= substrings_candidates: (%s%s) MR filter failed (%d)\n", dbname, LDBM_SUFFIX, rc ); +#endif + return idl; } if( keys == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ERR, + "substrings_candidates: (0x%04lx) no keys (%s%s)\n", + mask, dbname, LDBM_SUFFIX )); +#else Debug( LDAP_DEBUG_TRACE, "<= substrings_candidates: (0x%04lx) no keys (%s%s)\n", mask, dbname, LDBM_SUFFIX ); +#endif + return idl; } db = ldbm_cache_open( be, dbname, LDBM_SUFFIX, LDBM_READER ); if ( db == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ERR, + "substrings_candidates: db open failed (%s%s)\n", + dbname, LDBM_SUFFIX )); +#else Debug( LDAP_DEBUG_ANY, "<= substrings_candidates db open failed (%s%s)\n", dbname, LDBM_SUFFIX, 0 ); +#endif + return idl; } @@ -567,16 +868,29 @@ substring_candidates( if( rc != LDAP_SUCCESS ) { idl_free( idl ); idl = NULL; +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ERR, + "substrings_candidates: key read failed (%d)\n", + rc )); +#else Debug( LDAP_DEBUG_TRACE, "<= substrings_candidates key read failed (%d)\n", rc, 0, 0 ); +#endif + break; } if( tmp == NULL ) { idl_free( idl ); idl = NULL; +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_INFO, + "substrings_candidates: NULL\n" )); +#else Debug( LDAP_DEBUG_TRACE, "<= substrings_candidates NULL\n", 0, 0, 0 ); +#endif + break; } @@ -591,7 +905,14 @@ substring_candidates( ldbm_cache_close( be, db ); +#ifdef NEW_LOGGING + LDAP_LOG(( "filter", LDAP_LEVEL_ENTRY, + "substrings_candidates: return %ld\n", + idl ? ID_BLOCK_NIDS(idl) : 0 )); +#else Debug( LDAP_DEBUG_TRACE, "<= substrings_candidates %ld\n", idl ? ID_BLOCK_NIDS(idl) : 0, 0, 0 ); +#endif + return( idl ); } diff --git a/servers/slapd/back-ldbm/group.c b/servers/slapd/back-ldbm/group.c index decb193072..ff597f41f9 100644 --- a/servers/slapd/back-ldbm/group.c +++ b/servers/slapd/back-ldbm/group.c @@ -34,8 +34,8 @@ ldbm_back_group( ) { struct ldbminfo *li = (struct ldbminfo *) be->be_private; - Entry *e; - int rc = 1; + Entry *e; + int rc = 1; Attribute *attr; struct berval bv; @@ -49,9 +49,15 @@ ldbm_back_group( group_oc_name = group_oc->soc_oid; } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "ldbm_back_group: check (%s) member of (%s), oc %s\n", + op_ndn, gr_ndn, group_oc_name )); +#else Debug( LDAP_DEBUG_ARGS, "=> ldbm_back_group: gr dn: \"%s\"\n", gr_ndn, 0, 0 ); + Debug( LDAP_DEBUG_ARGS, "=> ldbm_back_group: op dn: \"%s\"\n", op_ndn, 0, 0 ); @@ -62,91 +68,163 @@ ldbm_back_group( Debug( LDAP_DEBUG_ARGS, "=> ldbm_back_group: tr dn: \"%s\"\n", target->e_ndn, 0, 0 ); +#endif if (strcmp(target->e_ndn, gr_ndn) == 0) { /* we already have a LOCKED copy of the entry */ e = target; - Debug( LDAP_DEBUG_ARGS, +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_back_group: target is group (%s)\n", gr_ndn )); +#else + Debug( LDAP_DEBUG_ARGS, "=> ldbm_back_group: target is group: \"%s\"\n", gr_ndn, 0, 0 ); +#endif + } else { /* can we find group entry with reader lock */ if ((e = dn2entry_r(be, gr_ndn, NULL )) == NULL) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_back_group: cannot find group (%s)\n", + gr_ndn )); +#else Debug( LDAP_DEBUG_ACL, "=> ldbm_back_group: cannot find group: \"%s\"\n", gr_ndn, 0, 0 ); +#endif + return( 1 ); } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_back_group: found group (%s)\n", gr_ndn )); +#else Debug( LDAP_DEBUG_ACL, "=> ldbm_back_group: found group: \"%s\"\n", gr_ndn, 0, 0 ); +#endif + } /* find it's objectClass and member attribute values * make sure this is a group entry * finally test if we can find op_dn in the member attribute value list * */ - + rc = 1; - + if( is_entry_alias( e ) ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_group: group (%s) is an alias\n", gr_ndn )); +#else Debug( LDAP_DEBUG_ACL, "<= ldbm_back_group: group is an alias\n", 0, 0, 0 ); +#endif + goto return_results; } if( is_entry_referral( e ) ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_group: group (%s) is a referral.\n", gr_ndn )); +#else Debug( LDAP_DEBUG_ACL, "<= ldbm_back_group: group is an referral\n", 0, 0, 0 ); +#endif + goto return_results; } if( !is_entry_objectclass( e, group_oc ) ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_back_group: failed to find %s in objectClass.\n", + group_oc_name )); +#else Debug( LDAP_DEBUG_ACL, "<= ldbm_back_group: failed to find %s in objectClass\n", group_oc_name, 0, 0 ); +#endif + goto return_results; } if ((attr = attr_find(e->e_attrs, group_at)) == NULL) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_group: failed to find %s\n", group_at_name )); +#else Debug( LDAP_DEBUG_ACL, "<= ldbm_back_group: failed to find %s\n", group_at_name, 0, 0 ); +#endif + goto return_results; } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "ldbm_back_group: found objectClass %s and %s\n", + group_oc_name, group_at_name )); +#else Debug( LDAP_DEBUG_ACL, "<= ldbm_back_group: found objectClass %s and %s\n", group_oc_name, group_at_name, 0 ); +#endif + bv.bv_val = (char *) op_ndn; - bv.bv_len = strlen( op_ndn ); + bv.bv_len = strlen( op_ndn ); if( value_find( group_at, attr->a_vals, &bv ) != LDAP_SUCCESS ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_back_group: \"%s\" not in \"%s\": %s\n", + op_ndn, gr_ndn, group_at_name )); +#else Debug( LDAP_DEBUG_ACL, "<= ldbm_back_group: \"%s\" not in \"%s\": %s\n", op_ndn, gr_ndn, group_at_name ); +#endif + goto return_results; } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_back_group: %s is in %s: %s\n", + op_ndn, gr_ndn, group_at_name )); +#else Debug( LDAP_DEBUG_ACL, "<= ldbm_back_group: \"%s\" is in \"%s\": %s\n", op_ndn, gr_ndn, group_at_name ); +#endif + rc = 0; return_results: if( target != e ) { /* free entry and reader lock */ - cache_return_entry_r( &li->li_cache, e ); + cache_return_entry_r( &li->li_cache, e ); } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "ldbm_back_group: rc=%d\n", rc )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_group: rc=%d\n", rc, 0, 0 ); +#endif + return(rc); } diff --git a/servers/slapd/back-ldbm/id2children.c b/servers/slapd/back-ldbm/id2children.c index 983f4e05cb..27f3b625c8 100644 --- a/servers/slapd/back-ldbm/id2children.c +++ b/servers/slapd/back-ldbm/id2children.c @@ -29,13 +29,26 @@ has_children( ldbm_datum_init( key ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "has_children: enter %ld\n", p->e_id )); +#else Debug( LDAP_DEBUG_TRACE, "=> has_children( %ld )\n", p->e_id , 0, 0 ); +#endif + if ( (db = ldbm_cache_open( be, "dn2id", LDBM_SUFFIX, LDBM_WRCREAT )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "has_children: could not open \"dn2id%s\"\n", + LDBM_SUFFIX )); +#else Debug( LDAP_DEBUG_ANY, "<= has_children -1 could not open \"dn2id%s\"\n", LDBM_SUFFIX, 0, 0 ); +#endif + return( 0 ); } @@ -54,7 +67,14 @@ has_children( rc = 1; } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "has_children: id (%ld) %s children.\n", + p->e_id, rc ? "has" : "doesn't have" )); +#else Debug( LDAP_DEBUG_TRACE, "<= has_children( %ld ): %s\n", p->e_id, rc ? "yes" : "no", 0 ); +#endif + return( rc ); } diff --git a/servers/slapd/back-ldbm/id2entry.c b/servers/slapd/back-ldbm/id2entry.c index f38802126d..a0e11c8073 100644 --- a/servers/slapd/back-ldbm/id2entry.c +++ b/servers/slapd/back-ldbm/id2entry.c @@ -30,13 +30,26 @@ id2entry_add( Backend *be, Entry *e ) ldbm_datum_init( key ); ldbm_datum_init( data ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "id2entry_add: (%s)%ld\n", e->e_dn, e->e_id )); +#else Debug( LDAP_DEBUG_TRACE, "=> id2entry_add( %ld, \"%s\" )\n", e->e_id, e->e_dn, 0 ); +#endif + if ( (db = ldbm_cache_open( be, "id2entry", LDBM_SUFFIX, LDBM_WRCREAT )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "id2entry_add: could not open/create id2entry%s\n", + LDBM_SUFFIX )); +#else Debug( LDAP_DEBUG_ANY, "Could not open/create id2entry%s\n", LDBM_SUFFIX, 0, 0 ); +#endif + return( -1 ); } @@ -55,7 +68,13 @@ id2entry_add( Backend *be, Entry *e ) ldbm_cache_close( be, db ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "id2entry_add: return %d\n", rc )); +#else Debug( LDAP_DEBUG_TRACE, "<= id2entry_add %d\n", rc, 0, 0 ); +#endif + return( rc ); } @@ -68,8 +87,14 @@ id2entry_delete( Backend *be, Entry *e ) Datum key; int rc; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "id2entry_delete: (%s)%ld\n", e->e_dn, e->e_id )); +#else Debug(LDAP_DEBUG_TRACE, "=> id2entry_delete( %ld, \"%s\" )\n", e->e_id, e->e_dn, 0 ); +#endif + #ifdef notdef #ifdef LDAP_RDWR_DEBUG @@ -82,14 +107,28 @@ id2entry_delete( Backend *be, Entry *e ) if ( (db = ldbm_cache_open( be, "id2entry", LDBM_SUFFIX, LDBM_WRCREAT )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "id2entry_delete: could not open/create id2entry%s\n", + LDBM_SUFFIX )); +#else Debug( LDAP_DEBUG_ANY, "Could not open/create id2entry%s\n", LDBM_SUFFIX, 0, 0 ); +#endif + return( -1 ); } if ( cache_delete_entry( &li->li_cache, e ) != 0 ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "id2entry_delete: Could not delete (%s)%ld from cache\n", + e->e_dn, e->e_id )); +#else Debug(LDAP_DEBUG_ANY, "could not delete %ld (%s) from cache\n", e->e_id, e->e_dn, 0 ); +#endif + } key.dptr = (char *) &e->e_id; @@ -99,7 +138,13 @@ id2entry_delete( Backend *be, Entry *e ) ldbm_cache_close( be, db ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "id2entry_delete: return %d\n", rc )); +#else Debug( LDAP_DEBUG_TRACE, "<= id2entry_delete %d\n", rc, 0, 0 ); +#endif + return( rc ); } @@ -115,19 +160,39 @@ id2entry_rw( Backend *be, ID id, int rw ) ldbm_datum_init( key ); ldbm_datum_init( data ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "id2entry_rw: %s (%ld)\n", + rw ? "write" : "read", id )); +#else Debug( LDAP_DEBUG_TRACE, "=> id2entry_%s( %ld )\n", rw ? "w" : "r", id, 0 ); +#endif + if ( (e = cache_find_entry_id( &li->li_cache, id, rw )) != NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "id2entry_rw: %s (%ld) 0x%lx (cache).\n", + rw ? "write" : "read", id, (unsigned long)e )); +#else Debug( LDAP_DEBUG_TRACE, "<= id2entry_%s( %ld ) 0x%lx (cache)\n", rw ? "w" : "r", id, (unsigned long) e ); +#endif + return( e ); } if ( (db = ldbm_cache_open( be, "id2entry", LDBM_SUFFIX, LDBM_WRCREAT )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "id2entry_rw: could not open id2entry%s\n", LDBM_SUFFIX )); +#else Debug( LDAP_DEBUG_ANY, "Could not open id2entry%s\n", LDBM_SUFFIX, 0, 0 ); +#endif + return( NULL ); } @@ -137,8 +202,14 @@ id2entry_rw( Backend *be, ID id, int rw ) data = ldbm_cache_fetch( db, key ); if ( data.dptr == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "id2entry_rw: (%ld) not found\n", id )); +#else Debug( LDAP_DEBUG_TRACE, "<= id2entry_%s( %ld ) not found\n", rw ? "w" : "r", id, 0 ); +#endif + ldbm_cache_close( be, db ); return( NULL ); } @@ -148,8 +219,15 @@ id2entry_rw( Backend *be, ID id, int rw ) ldbm_cache_close( be, db ); if ( e == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "id2entry_rw: %s of %ld failed\n", + rw ? "write" : "read", id )); +#else Debug( LDAP_DEBUG_TRACE, "<= id2entry_%s( %ld ) (failed)\n", rw ? "w" : "r", id, 0 ); +#endif + return( NULL ); } @@ -163,18 +241,39 @@ id2entry_rw( Backend *be, ID id, int rw ) * There are many underlying race condtions in the cache/disk code. */ if ( (e = cache_find_entry_id( &li->li_cache, id, rw )) != NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "id2entry_rw: %s of %ld 0x%lx (cache)\n", + rw ? "write" : "read", id, (unsigned long)e )); +#else Debug( LDAP_DEBUG_TRACE, "<= id2entry_%s( %ld ) 0x%lx (cache)\n", rw ? "w" : "r", id, (unsigned long) e ); +#endif + return( e ); } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "id2entry_rw: %s of %ld (cache add failed)\n", + rw ? "write" : "read", id )); +#else Debug( LDAP_DEBUG_TRACE, "<= id2entry_%s( %ld ) (cache add failed)\n", rw ? "w" : "r", id, 0 ); +#endif + return NULL; } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "id2entry_rw: %s of %ld 0x%lx (disk)\n", + rw ? "write" : "read", id, (unsigned long)e )); +#else Debug( LDAP_DEBUG_TRACE, "<= id2entry_%s( %ld ) 0x%lx (disk)\n", rw ? "w" : "r", id, (unsigned long) e ); +#endif + return( e ); } diff --git a/servers/slapd/back-ldbm/idl.c b/servers/slapd/back-ldbm/idl.c index e189a5bd6b..9603cd4b79 100644 --- a/servers/slapd/back-ldbm/idl.c +++ b/servers/slapd/back-ldbm/idl.c @@ -78,9 +78,15 @@ void idl_free( ID_BLOCK *idl ) { if ( idl == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_INFO, + "idl_freee: called with NULL pointer\n" )); +#else Debug( LDAP_DEBUG_TRACE, "idl_free: called with NULL pointer\n", 0, 0, 0 ); +#endif + return; } @@ -117,9 +123,9 @@ idl_fetch_one( /* Fetch a set of ID_BLOCKs from the cache * if not INDIRECT - * if block return is an ALLIDS block, + * if block return is an ALLIDS block, * return an new ALLIDS block - * otherwise + * otherwise * return block * construct super block from all blocks referenced by INDIRECT block * return super block @@ -174,8 +180,14 @@ idl_fetch( cont_id( &data, ID_BLOCK_ID(idl, i) ); if ( (tmp[i] = idl_fetch_one( be, db, data )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_INFO, + "idl_fetch: idl_fetch_one returned NULL\n" )); +#else Debug( LDAP_DEBUG_ANY, "idl_fetch: one returned NULL\n", 0, 0, 0 ); +#endif + continue; } @@ -206,8 +218,15 @@ idl_fetch( } free( (char *) tmp ); +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_ENTRY, + "idl_fetch: %ld ids (%ld max)\n", + ID_BLOCK_NIDS(idl), ID_BLOCK_NMAX(idl) )); +#else Debug( LDAP_DEBUG_TRACE, "<= idl_fetch %ld ids (%ld max)\n", ID_BLOCK_NIDS(idl), ID_BLOCK_NMAX(idl), 0 ); +#endif + return( idl ); } @@ -302,10 +321,10 @@ idl_change_first( Backend *be, DBCache *db, Datum hkey, /* header block key */ - ID_BLOCK *h, /* header block */ + ID_BLOCK *h, /* header block */ int pos, /* pos in h to update */ Datum bkey, /* data block key */ - ID_BLOCK *b /* data block */ + ID_BLOCK *b /* data block */ ) { int rc; @@ -314,9 +333,15 @@ idl_change_first( /* delete old key block */ if ( (rc = ldbm_cache_delete( db, bkey )) != 0 ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_INFO, + "idl_change_first: ldbm_cache_delete returned %d\n", rc )); +#else Debug( LDAP_DEBUG_ANY, "idl_change_first: ldbm_cache_delete returned %d\n", rc, 0, 0 ); +#endif + return( rc ); } @@ -324,16 +349,28 @@ idl_change_first( cont_id( &bkey, ID_BLOCK_ID(b, 0) ); if ( (rc = idl_store( be, db, bkey, b )) != 0 ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_INFO, + "idl_change_first: idl_store returned %d\n", rc )); +#else Debug( LDAP_DEBUG_ANY, "idl_change_first: idl_store returned %d\n", rc, 0, 0 ); +#endif + return( rc ); } /* update + write indirect header block */ ID_BLOCK_ID(h, pos) = ID_BLOCK_ID(b, 0); if ( (rc = idl_store( be, db, hkey, h )) != 0 ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_INFO, + "idl_change_first: idl_store returned %s\n", rc )); +#else Debug( LDAP_DEBUG_ANY, "idl_change_first: idl_store returned %d\n", rc, 0, 0 ); +#endif + return( rc ); } @@ -446,8 +483,14 @@ idl_insert_key( cont_id( &k2, ID_BLOCK_ID(idl, i) ); if ( (tmp = idl_fetch_one( be, db, k2 )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_ERR, + "idl_insert_key: nonexistent continuation block\n" )); +#else Debug( LDAP_DEBUG_ANY, "idl_insert_key: nonexistent continuation block\n", 0, 0, 0 ); +#endif + cont_free( &k2 ); idl_free( idl ); return( -1 ); @@ -457,8 +500,14 @@ idl_insert_key( switch ( idl_insert( &tmp, id, db->dbc_maxids ) ) { case 0: /* id inserted ok */ if ( (rc = idl_store( be, db, k2, tmp )) != 0 ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_ERR, + "ids_insert_key: idl_store returned %d\n", rc )); +#else Debug( LDAP_DEBUG_ANY, "idl_insert_key: idl_store returned %d\n", rc, 0, 0 ); +#endif + } break; @@ -490,9 +539,15 @@ idl_insert_key( cont_alloc( &k2, &key ); cont_id( &k2, ID_BLOCK_ID(idl, i) ); if ( (tmp2 = idl_fetch_one( be, db, k2 )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_ERR, + "idl_insert_key: idl_fetch_one returned NULL\n")); +#else Debug( LDAP_DEBUG_ANY, "idl_insert_key: idl_fetch_one returned NULL\n", 0, 0, 0 ); +#endif + /* split the original block */ cont_free( &k2 ); goto split; @@ -519,8 +574,14 @@ idl_insert_key( k3.dsize = k2.dsize; AC_MEMCPY(k3.dptr, k2.dptr, k3.dsize); if ( (rc = idl_store( be, db, k3, tmp )) != 0 ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_ERR, + "idl_insert_key: idl_store returned %d\n", rc )); +#else Debug( LDAP_DEBUG_ANY, "idl_insert_key: idl_store returned %d\n", rc, 0, 0 ); +#endif + } free( k3.dptr ); @@ -546,9 +607,16 @@ idl_insert_key( * will always be called. */ if ( rc == 2 ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_INFO, + "idl_insert_key: id %ld is already in next block\n", + id )); +#else Debug( LDAP_DEBUG_ANY, "idl_insert_key: id %ld already in next block\n", id, 0, 0 ); +#endif + } idl_free( tmp ); @@ -581,7 +649,7 @@ split: /* * we've passed the all-id threshold, meaning * that this set of blocks should be replaced - * by a single "all-id" block. our job: delete + * by a single "all-id" block. our job: delete * all the indirect blocks, and replace the header * block by an all-id block. */ @@ -651,7 +719,7 @@ split: * idl_insert - insert an id into an id list. * * returns - * 0 id inserted + * 0 id inserted * 1 id inserted, first id in block has changed * 2 id not inserted, already there * 3 id not inserted, block must be split @@ -690,7 +758,7 @@ idl_insert( ID_BLOCK **idl, ID id, unsigned int maxids ) /* make a slot for the new id */ AC_MEMCPY( &ID_BLOCK_ID(*idl, i+1), &ID_BLOCK_ID(*idl, i), - (ID_BLOCK_NIDS(*idl) - i) * sizeof(ID) ); + (ID_BLOCK_NIDS(*idl) - i) * sizeof(ID) ); ID_BLOCK_ID(*idl, i) = id; ID_BLOCK_NIDS(*idl)++; @@ -705,10 +773,10 @@ idl_insert( ID_BLOCK **idl, ID id, unsigned int maxids ) int idl_delete_key ( - Backend *be, - DBCache *db, - Datum key, - ID id + Backend *be, + DBCache *db, + Datum key, + ID id ) { Datum data; @@ -767,8 +835,14 @@ idl_delete_key ( cont_id( &data, ID_BLOCK_ID(idl, j) ); if ( (tmp = idl_fetch_one( be, db, data )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "cache", LDAP_LEVEL_INFO, + "idl_delete_key: idl_fetch_one returned NULL\n" )); +#else Debug( LDAP_DEBUG_ANY, "idl_delete_key: idl_fetch of returned NULL\n", 0, 0, 0 ); +#endif + continue; } /* @@ -962,8 +1036,8 @@ idl_union( ID_BLOCK * idl_notin( Backend *be, - ID_BLOCK *a, - ID_BLOCK *b + ID_BLOCK *a, + ID_BLOCK *b ) { unsigned int ni, ai, bi; @@ -1039,7 +1113,7 @@ idl_notin( * otherwise return first ID * * cursor is set to 1 - */ + */ ID idl_firstid( ID_BLOCK *idl, ID *cursor ) { diff --git a/servers/slapd/back-ldbm/index.c b/servers/slapd/back-ldbm/index.c index 54b437be86..f24903003d 100644 --- a/servers/slapd/back-ldbm/index.c +++ b/servers/slapd/back-ldbm/index.c @@ -156,9 +156,16 @@ static int indexer( db = ldbm_cache_open( be, dbname, LDBM_SUFFIX, LDBM_WRCREAT ); if ( db == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "index", LDAP_LEVEL_ERR, + "index_read: Could not open db %s%s\n", + dbname, LDBM_SUFFIX )); +#else Debug( LDAP_DEBUG_ANY, "<= index_read NULL (could not open %s%s)\n", dbname, LDBM_SUFFIX, 0 ); +#endif + ad_free( ad, 1 ); return LDAP_OTHER; } @@ -178,7 +185,7 @@ static int indexer( if( rc == LDAP_SUCCESS && keys != NULL ) { for( i=0; keys[i] != NULL; i++ ) { key_change( be, db, keys[i], id, op ); - } + } ber_bvecfree( keys ); } } @@ -194,7 +201,7 @@ static int indexer( if( rc == LDAP_SUCCESS && keys != NULL ) { for( i=0; keys[i] != NULL; i++ ) { key_change( be, db, keys[i], id, op ); - } + } ber_bvecfree( keys ); } } @@ -210,7 +217,7 @@ static int indexer( if( rc == LDAP_SUCCESS && keys != NULL ) { for( i=0; keys[i] != NULL; i++ ) { key_change( be, db, keys[i], id, op ); - } + } ber_bvecfree( keys ); } } @@ -318,18 +325,32 @@ index_entry( Attribute *ap ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "index", LDAP_LEVEL_ENTRY, + "index_entry: %s (%s)%ld\n", + op == SLAP_INDEX_ADD_OP ? "add" : "del", + e->e_dn, e->e_id )); +#else Debug( LDAP_DEBUG_TRACE, "=> index_entry_%s( %ld, \"%s\" )\n", op == SLAP_INDEX_ADD_OP ? "add" : "del", e->e_id, e->e_dn ); +#endif + /* add each attribute to the indexes */ for ( ; ap != NULL; ap = ap->a_next ) { index_values( be, ap->a_desc, ap->a_vals, e->e_id, op ); } +#ifdef NEW_LOGGING + LDAP_LOG(( "index", LDAP_LEVEL_ENTRY, + "index_entry: success\n" )); +#else Debug( LDAP_DEBUG_TRACE, "<= index_entry_%s( %ld, \"%s\" ) success\n", op == SLAP_INDEX_ADD_OP ? "add" : "del", e->e_id, e->e_dn ); +#endif + return LDAP_SUCCESS; } diff --git a/servers/slapd/back-ldbm/key.c b/servers/slapd/back-ldbm/key.c index c8dc26e690..de8b90565e 100644 --- a/servers/slapd/back-ldbm/key.c +++ b/servers/slapd/back-ldbm/key.c @@ -24,10 +24,16 @@ key_read( ID_BLOCK **idout ) { - Datum key; + Datum key; ID_BLOCK *idl; +#ifdef NEW_LOGGING + LDAP_LOG(( "index", LDAP_LEVEL_ENTRY, + "key_read: enter\n" )); +#else Debug( LDAP_DEBUG_TRACE, "=> key_read\n", 0, 0, 0 ); +#endif + ldbm_datum_init( key ); key.dptr = k->bv_val; @@ -35,8 +41,15 @@ key_read( idl = idl_fetch( be, db, key ); +#ifdef NEW_LOGGING + LDAP_LOG(( "index", LDAP_LEVEL_ENTRY, + "key_read: %ld candidates\n", + idl ? ID_BLOCK_NIDS(idl) : 0 )); +#else Debug( LDAP_DEBUG_TRACE, "<= index_read %ld candidates\n", idl ? ID_BLOCK_NIDS(idl) : 0, 0, 0 ); +#endif + *idout = idl; return LDAP_SUCCESS; @@ -53,10 +66,17 @@ key_change( ) { int rc; - Datum key; + Datum key; +#ifdef NEW_LOGGING + LDAP_LOG(( "index", LDAP_LEVEL_ENTRY, + "key_change: %s ID %lx\n", + op == SLAP_INDEX_ADD_OP ? "Add" : "Delete", (long)id )); +#else Debug( LDAP_DEBUG_TRACE, "=> key_change(%s,%lx)\n", op == SLAP_INDEX_ADD_OP ? "ADD":"DELETE", (long) id, 0 ); +#endif + ldbm_datum_init( key ); key.dptr = k->bv_val; @@ -72,7 +92,13 @@ key_change( } +#ifdef NEW_LOGGING + LDAP_LOG(( "index", LDAP_LEVEL_ENTRY, + "key_change: return %d\n", rc )); +#else Debug( LDAP_DEBUG_TRACE, "<= key_change %d\n", rc, 0, 0 ); +#endif + ldap_pvt_thread_yield(); diff --git a/servers/slapd/back-ldbm/modify.c b/servers/slapd/back-ldbm/modify.c index 07a5747b61..9bda7df81c 100644 --- a/servers/slapd/back-ldbm/modify.c +++ b/servers/slapd/back-ldbm/modify.c @@ -42,7 +42,13 @@ int ldbm_modify_internal( Modifications *ml; Attribute *save_attrs; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "ldbm_modify_internal: %s\n", dn )); +#else Debug(LDAP_DEBUG_TRACE, "ldbm_modify_internal:\n", 0, 0, 0); +#endif + if ( !acl_check_modlist( be, conn, op, e, modlist )) { return LDAP_INSUFFICIENT_ACCESS; @@ -56,64 +62,123 @@ int ldbm_modify_internal( switch ( mod->sm_op ) { case LDAP_MOD_ADD: +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_modify_internal: add\n" )); +#else Debug(LDAP_DEBUG_ARGS, "ldbm_modify_internal: add\n", 0, 0, 0); +#endif + err = add_values( e, mod, op->o_ndn ); if( err != LDAP_SUCCESS ) { + *text = "modify: add values failed"; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_modify_internal: failed %d (%s)\n", + err, *text )); +#else Debug(LDAP_DEBUG_ARGS, "ldbm_modify_internal: %d %s\n", err, *text, 0); - *text = "modify: add values failed"; +#endif } break; case LDAP_MOD_DELETE: +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_modify_internal: delete\n" )); +#else Debug(LDAP_DEBUG_ARGS, "ldbm_modify_internal: delete\n", 0, 0, 0); +#endif + err = delete_values( e, mod, op->o_ndn ); assert( err != LDAP_TYPE_OR_VALUE_EXISTS ); if( err != LDAP_SUCCESS ) { + *text = "modify: delete values failed"; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_modify_internal: failed %d (%s)\n", err, *text )); +#else Debug(LDAP_DEBUG_ARGS, "ldbm_modify_internal: %d %s\n", err, *text, 0); - *text = "modify: delete values failed"; +#endif } break; case LDAP_MOD_REPLACE: +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_modify_internal: replace\n" )); +#else Debug(LDAP_DEBUG_ARGS, "ldbm_modify_internal: replace\n", 0, 0, 0); +#endif + err = replace_values( e, mod, op->o_ndn ); assert( err != LDAP_TYPE_OR_VALUE_EXISTS ); if( err != LDAP_SUCCESS ) { + *text = "modify: replace values failed"; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_modify_internal: failed %d (%s)\n", err, *text )); +#else Debug(LDAP_DEBUG_ARGS, "ldbm_modify_internal: %d %s\n", err, *text, 0); - *text = "modify: replace values failed"; +#endif + } break; case SLAP_MOD_SOFTADD: +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_modify_internal: softadd\n" )); +#else Debug(LDAP_DEBUG_ARGS, "ldbm_modify_internal: softadd\n", 0, 0, 0); - /* Avoid problems in index_add_mods() - * We need to add index if necessary. - */ - mod->sm_op = LDAP_MOD_ADD; +#endif + + /* Avoid problems in index_add_mods() + * We need to add index if necessary. + */ + mod->sm_op = LDAP_MOD_ADD; err = add_values( e, mod, op->o_ndn ); - if ( err == LDAP_TYPE_OR_VALUE_EXISTS ) { - err = LDAP_SUCCESS; - } + if ( err == LDAP_TYPE_OR_VALUE_EXISTS ) { + err = LDAP_SUCCESS; + } if( err != LDAP_SUCCESS ) { + *text = "modify: (soft)add values failed"; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_modify_internal: failed %d (%s)\n", err, *text )); +#else Debug(LDAP_DEBUG_ARGS, "ldbm_modify_internal: %d %s\n", err, *text, 0); - *text = "modify: (soft)add values failed"; +#endif + } - break; + break; default: +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_modify_internal: invalid op %d\n", mod->sm_op )); +#else Debug(LDAP_DEBUG_ANY, "ldbm_modify_internal: invalid op %d\n", mod->sm_op, 0, 0); - *text = "Invalid modify operation"; +#endif + err = LDAP_OTHER; + *text = "Invalid modify operation"; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_modify_internal: %d (%s)\n", err, *text )); +#else Debug(LDAP_DEBUG_ARGS, "ldbm_modify_internal: %d %s\n", err, *text, 0); +#endif + } if ( err != LDAP_SUCCESS ) { @@ -139,8 +204,15 @@ int ldbm_modify_internal( if ( rc != LDAP_SUCCESS ) { attrs_free( e->e_attrs ); e->e_attrs = save_attrs; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_modify_internal: entry failed schema check: %s\n", + *text )); +#else Debug( LDAP_DEBUG_ANY, "entry failed schema check: %s\n", *text, 0, 0 ); +#endif + return rc; } @@ -183,7 +255,13 @@ ldbm_back_modify( int manageDSAit = get_manageDSAit( op ); const char *text = NULL; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "ldbm_back_modify: enter\n" )); +#else Debug(LDAP_DEBUG_ARGS, "ldbm_back_modify:\n", 0, 0, 0); +#endif + /* acquire and lock entry */ if ( (e = dn2entry_w( be, ndn, &matched )) == NULL ) { @@ -217,8 +295,14 @@ ldbm_back_modify( struct berval **refs = get_entry_referrals( be, conn, op, e ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_modify: entry (%s) is referral\n", ndn )); +#else Debug( LDAP_DEBUG_TRACE, "entry is referral\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_REFERRAL, e->e_dn, NULL, refs, NULL ); @@ -234,7 +318,7 @@ ldbm_back_modify( if( rc != LDAP_SUCCESS ) { if( rc != SLAPD_ABANDON ) { send_ldap_result( conn, op, rc, - NULL, text, NULL, NULL ); + NULL, text, NULL, NULL ); } goto error_return; @@ -334,8 +418,14 @@ delete_values( /* delete the entire attribute */ if ( mod->sm_bvalues == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "delete_values: removing entire attribute %s\n", desc )); +#else Debug( LDAP_DEBUG_ARGS, "removing entire attribute %s\n", desc, 0, 0 ); +#endif + return( attr_delete( &e->e_attrs, mod->sm_desc ) ? LDAP_NO_SUCH_ATTRIBUTE : LDAP_SUCCESS ); } @@ -348,9 +438,15 @@ delete_values( /* delete specific values - find the attribute first */ if ( (a = attr_find( e->e_attrs, mod->sm_desc )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldap_modify_delete: Could not find attribute %s\n", desc )); +#else Debug( LDAP_DEBUG_ARGS, "ldap_modify_delete: " "could not find attribute %s\n", desc, 0, 0 ); +#endif + return( LDAP_NO_SUCH_ATTRIBUTE ); } @@ -397,18 +493,30 @@ delete_values( /* looked through them all w/o finding it */ if ( ! found ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ARGS, + "delete_values: could not find value for attr %s\n", desc )); +#else Debug( LDAP_DEBUG_ARGS, "ldbm_modify_delete: could not find value for attr %s\n", desc, 0, 0 ); +#endif + return LDAP_NO_SUCH_ATTRIBUTE; } } /* if no values remain, delete the entire attribute */ if ( a->a_vals[0] == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "delete_values: removing entire attribute %s\n", desc )); +#else Debug( LDAP_DEBUG_ARGS, "removing entire attribute %s\n", desc, 0, 0 ); +#endif + if ( attr_delete( &e->e_attrs, mod->sm_desc ) ) { return LDAP_NO_SUCH_ATTRIBUTE; } diff --git a/servers/slapd/back-ldbm/modrdn.c b/servers/slapd/back-ldbm/modrdn.c index 38572293a9..2d8b4b0157 100644 --- a/servers/slapd/back-ldbm/modrdn.c +++ b/servers/slapd/back-ldbm/modrdn.c @@ -56,12 +56,12 @@ ldbm_back_modrdn( /* Added to support LDAP v2 correctly (deleteoldrdn thing) */ char *new_rdn_val = NULL; /* Val of new rdn */ char *new_rdn_type = NULL; /* Type of new rdn */ - char *old_rdn = NULL; /* Old rdn's attr type & val */ + char *old_rdn = NULL; /* Old rdn's attr type & val */ char *old_rdn_type = NULL; /* Type of old rdn attr. */ char *old_rdn_val = NULL; /* Old rdn attribute value */ /* Added to support newSuperior */ Entry *np = NULL; /* newSuperior Entry */ - char *np_dn = NULL; /* newSuperior dn */ + char *np_dn = NULL; /* newSuperior dn */ char *np_ndn = NULL; /* newSuperior ndn */ char *new_parent_dn = NULL; /* np_dn, p_dn, or NULL */ /* Used to interface with ldbm_modify_internal() */ @@ -72,9 +72,16 @@ ldbm_back_modrdn( Modifications mod[2]; /* Used to delete old rdn */ int manageDSAit = get_manageDSAit( op ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "ldbm_back_modrdn: dn: %s newSuperior=%s\n", + dn ? dn : "NULL", newSuperior ? newSuperior : "NULL" )); +#else Debug( LDAP_DEBUG_TRACE, "==>ldbm_back_modrdn(newSuperior=%s)\n", (newSuperior ? newSuperior : "NULL"), 0, 0 ); +#endif + /* get entry with writer lock */ if ( (e = dn2entry_w( be, ndn, &matched )) == NULL ) { @@ -108,8 +115,14 @@ ldbm_back_modrdn( struct berval **refs = get_entry_referrals( be, conn, op, e ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_modrdn: entry %s is a referral\n", e->e_dn )); +#else Debug( LDAP_DEBUG_TRACE, "entry is referral\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_REFERRAL, e->e_dn, NULL, refs, NULL ); @@ -126,8 +139,14 @@ ldbm_back_modrdn( */ if( (p = dn2entry_w( be, p_ndn, NULL )) == NULL) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_modrdn: parent of %s does not exist\n", e->e_ndn )); +#else Debug( LDAP_DEBUG_TRACE, "parent does not exist\n", 0, 0, 0); +#endif + send_ldap_result( conn, op, LDAP_OTHER, NULL, NULL, NULL, NULL ); goto return_results; @@ -137,28 +156,54 @@ ldbm_back_modrdn( if ( ! access_allowed( be, conn, op, p, children, NULL, ACL_WRITE ) ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_modrdn: no access to parent of (%s)\n", e->e_dn )); +#else Debug( LDAP_DEBUG_TRACE, "no access to parent\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_INSUFFICIENT_ACCESS, NULL, NULL, NULL, NULL ); goto return_results; } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_back_modrdn: wr to children of entry %s OK\n", + p_ndn )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: wr to children of entry %s OK\n", p_ndn, 0, 0 ); +#endif + p_dn = dn_parent( be, e->e_dn ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_back_modrdn: parent dn=%s\n", p_dn )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: parent dn=%s\n", p_dn, 0, 0 ); +#endif + } else { /* no parent, modrdn entry directly under root */ if( ! be_isroot( be, op->o_ndn ) ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_modrdn: (%s) no parent & not a root.\n", + e->e_dn )); +#else Debug( LDAP_DEBUG_TRACE, "no parent & not root\n", 0, 0, 0); +#endif + send_ldap_result( conn, op, LDAP_INSUFFICIENT_ACCESS, NULL, NULL, NULL, NULL ); goto return_results; @@ -167,18 +212,30 @@ ldbm_back_modrdn( ldap_pvt_thread_mutex_lock(&li->li_root_mutex); rootlock = 1; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_modrdn: (%s) no parent, locked root.\n", e->e_dn )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: no parent, locked root\n", 0, 0, 0 ); +#endif + } new_parent_dn = p_dn; /* New Parent unless newSuperior given */ if ( newSuperior != NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_back_modrdn: new parent \"%s\" requested\n", newSuperior )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: new parent \"%s\" requested...\n", newSuperior, 0, 0 ); +#endif + np_dn = ch_strdup( newSuperior ); np_ndn = ch_strdup( np_dn ); @@ -186,9 +243,16 @@ ldbm_back_modrdn( /* newSuperior == oldParent? */ if ( strcmp( p_ndn, np_ndn ) == 0 ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_modrdn: new parent\"%s\" seems to be the same as the old parent \"%s\"\n", + newSuperior, p_dn )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: new parent \"%s\" seems to be the same as old parent \"%s\"...\n", newSuperior, p_dn, 0 ); +#endif + newSuperior = NULL; /* ignore newSuperior */ } } @@ -199,25 +263,44 @@ ldbm_back_modrdn( /* Get Entry with dn=newSuperior. Does newSuperior exist? */ if( (np = dn2entry_w( be, np_ndn, NULL )) == NULL) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ERR, + "ldbm_back_modrdn: newSup(ndn=%s) not found.\n", np_ndn )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: newSup(ndn=%s) not here!\n", np_ndn, 0, 0); +#endif + send_ldap_result( conn, op, LDAP_OTHER, NULL, NULL, NULL, NULL ); goto return_results; } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_back_modrdn: wr to new parent OK np=%p, id=%ld\n", + np, np->e_id )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: wr to new parent OK np=%p, id=%ld\n", np, np->e_id, 0 ); +#endif + /* check newSuperior for "children" acl */ if ( !access_allowed( be, conn, op, np, children, NULL, ACL_WRITE ) ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_modrdn: no wr to newSup children.\n" )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: no wr to newSup children\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_INSUFFICIENT_ACCESS, NULL, NULL, NULL, NULL ); goto return_results; @@ -225,8 +308,14 @@ ldbm_back_modrdn( if ( is_entry_alias( np ) ) { /* entry is an alias, don't allow bind */ +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_modrdn: entry (%s) is an alias.\n", np->e_dn )); +#else Debug( LDAP_DEBUG_TRACE, "entry is alias\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_ALIAS_PROBLEM, NULL, NULL, NULL, NULL ); @@ -237,8 +326,15 @@ ldbm_back_modrdn( if ( is_entry_referral( np ) ) { /* parent is a referral, don't allow add */ /* parent is an alias, don't allow add */ +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_modrdn: entry (%s) is a referral\n", + np->e_dn )); +#else Debug( LDAP_DEBUG_TRACE, "entry is referral\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_OPERATIONS_ERROR, NULL, NULL, NULL, NULL ); @@ -246,9 +342,15 @@ ldbm_back_modrdn( goto return_results; } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_back_modrdn: wr to new parent's children OK.\n" )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: wr to new parent's children OK\n", 0, 0 , 0 ); +#endif + new_parent_dn = np_dn; } @@ -261,8 +363,14 @@ ldbm_back_modrdn( new_ndn = ch_strdup(new_dn); (void) dn_normalize( new_ndn ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_back_modrdn: new ndn=%s\n", new_ndn )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: new ndn=%s\n", new_ndn, 0, 0 ); +#endif + /* check for abandon */ ldap_pvt_thread_mutex_lock( &op->o_abandonmutex ); @@ -278,9 +386,15 @@ ldbm_back_modrdn( goto return_results; } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_modrdn: new ndn (%s) does not exist\n", new_ndn )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: new ndn=%s does not exist\n", new_ndn, 0, 0 ); +#endif + /* Get attribute type and attribute value of our new rdn, we will * need to add that to our new entry @@ -288,9 +402,15 @@ ldbm_back_modrdn( if ( (new_rdn_type = rdn_attr_type( newrdn )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_modrdn: can't figure out type of newrdn\n" )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: can't figure out type of newrdn\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_OPERATIONS_ERROR, NULL, "unknown type used in RDN", NULL, NULL ); goto return_results; @@ -299,34 +419,60 @@ ldbm_back_modrdn( if ( (new_rdn_val = rdn_attr_value( newrdn )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_modrdn: can't figure out val of newrdn\n")); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: can't figure out val of newrdn\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_OPERATIONS_ERROR, NULL, "could not parse RDN value", NULL, NULL ); goto return_results; } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_back_modrdn: new_rdn_val=\"%s\", new_rdn_type=\"%s\"\n", + new_rdn_val, new_rdn_type )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: new_rdn_val=\"%s\", new_rdn_type=\"%s\"\n", new_rdn_val, new_rdn_type, 0 ); +#endif + /* Retrieve the old rdn from the entry's dn */ if ( (old_rdn = dn_rdn( be, dn )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_modrdn: can't figure out old_rdn from dn (%s)\n", + dn )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: can't figure out old_rdn from dn\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_OTHER, NULL, "could not parse old DN", NULL, NULL ); goto return_results; } if ( (old_rdn_type = rdn_attr_type( old_rdn )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_modrdn: can't figure out the old_rdn type.\n" )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: can't figure out the old_rdn type\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_OTHER, NULL, "count parse RDN from old DN", NULL, NULL ); goto return_results; @@ -334,13 +480,26 @@ ldbm_back_modrdn( if ( strcasecmp( old_rdn_type, new_rdn_type ) != 0 ) { /* Not a big deal but we may say something */ +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_modrdn: old_rdn_type=%s new_rdn_type-%s\n", + old_rdn_type, new_rdn_type )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: old_rdn_type=%s, new_rdn_type=%s!\n", old_rdn_type, new_rdn_type, 0 ); +#endif + } +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_back_modrdn: DN_X500\n" )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: DN_X500\n", 0, 0, 0 ); +#endif + /* Add new attribute value to the entry. */ @@ -358,9 +517,16 @@ ldbm_back_modrdn( rc = slap_str2ad( new_rdn_type, &mod[0].sml_desc, &text ); if( rc != LDAP_SUCCESS ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_modrdn: slap_str2ad error: %s (%s)\n", + text, new_rdn_type )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: %s: %s (new)\n", text, new_rdn_type, 0 ); +#endif + send_ldap_result( conn, op, rc, NULL, text, NULL, NULL ); goto return_results; @@ -378,9 +544,15 @@ ldbm_back_modrdn( if ((old_rdn_val = rdn_attr_value( old_rdn )) == NULL) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_modrdn: can't figure out old_rdn_val from old_rdn\n" )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: can't figure out old_rdn_val from old_rdn\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_OTHER, NULL, "could not parse value from old RDN", NULL, NULL ); goto return_results; @@ -401,9 +573,16 @@ ldbm_back_modrdn( rc = slap_str2ad( old_rdn_type, &mod[1].sml_desc, &text ); if( rc != LDAP_SUCCESS ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_back_modrdn: %s: %s (old)\n", + text, old_rdn_type )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: %s: %s (old)\n", text, old_rdn_type, 0 ); +#endif + send_ldap_result( conn, op, rc, NULL, text, NULL, NULL ); goto return_results; @@ -414,9 +593,15 @@ ldbm_back_modrdn( mod[1].sml_op = LDAP_MOD_DELETE; mod[1].sml_next = NULL; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_back_modrdn: removing old_rdn_val=%s\n", old_rdn_val )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_back_modrdn: removing old_rdn_val=%s\n", old_rdn_val, 0, 0 ); +#endif + } /* check for abandon */ diff --git a/servers/slapd/back-ldbm/nextid.c b/servers/slapd/back-ldbm/nextid.c index 2ea984a852..8ac43d944a 100644 --- a/servers/slapd/back-ldbm/nextid.c +++ b/servers/slapd/back-ldbm/nextid.c @@ -28,8 +28,14 @@ next_id_read( Backend *be ) if ( (db = ldbm_cache_open( be, "nextid", LDBM_SUFFIX, LDBM_WRCREAT )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_CRIT, + "next_id_read: could not open/create nextid%s\n", LDBM_SUFFIX )); +#else Debug( LDAP_DEBUG_ANY, "Could not open/create nextid" LDBM_SUFFIX "\n", 0, 0, 0 ); +#endif + return( NOID ); } @@ -62,8 +68,14 @@ next_id_write( Backend *be, ID id ) if ( (db = ldbm_cache_open( be, "nextid", LDBM_SUFFIX, LDBM_WRCREAT )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_CRIT, + "next_id_write: Could not open/create nextid%s\n", LDBM_SUFFIX )); +#else Debug( LDAP_DEBUG_ANY, "Could not open/create nextid" LDBM_SUFFIX "\n", 0, 0, 0 ); +#endif + return( NOID ); } diff --git a/servers/slapd/back-ldbm/passwd.c b/servers/slapd/back-ldbm/passwd.c index 2acb3d8532..eb339f0149 100644 --- a/servers/slapd/back-ldbm/passwd.c +++ b/servers/slapd/back-ldbm/passwd.c @@ -46,8 +46,15 @@ ldbm_back_exop_passwd( rc = slap_passwd_parse( reqdata, &id, NULL, &new, text ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "ldbm_back_exop_passwd: \"%s\"\n", + id ? id->bv_val : "" )); +#else Debug( LDAP_DEBUG_ARGS, "==> ldbm_back_exop_passwd: \"%s\"\n", id ? id->bv_val : "", 0, 0 ); +#endif + if( rc != LDAP_SUCCESS ) { goto done; @@ -75,8 +82,15 @@ ldbm_back_exop_passwd( dn = id ? id->bv_val : op->o_dn; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_back_exop_passwd: \"%s\"%s\n", + dn, id ? " (proxy)" : "" )); +#else Debug( LDAP_DEBUG_TRACE, "passwd: \"%s\"%s\n", dn, id ? " (proxy)" : "", 0 ); +#endif + if( dn == NULL || dn[0] == '\0' ) { *text = "No password is associated with the Root DSE"; diff --git a/servers/slapd/back-ldbm/referral.c b/servers/slapd/back-ldbm/referral.c index 805a03c4d6..678393aa46 100644 --- a/servers/slapd/back-ldbm/referral.c +++ b/servers/slapd/back-ldbm/referral.c @@ -47,9 +47,16 @@ ldbm_back_referrals( if ( matched != NULL ) { matched_dn = ch_strdup( matched->e_dn ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_back_referrals: op=%ld target=\"%s\" matched=\"%s\"\n", + op->o_tag, dn, matched_dn )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_referrals: op=%ld target=\"%s\" matched=\"%s\"\n", op->o_tag, dn, matched_dn ); +#endif + refs = is_entry_referral( matched ) ? get_entry_referrals( be, conn, op, matched ) @@ -77,13 +84,20 @@ ldbm_back_referrals( struct berval **refs = get_entry_referrals( be, conn, op, e ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_referrals: op=%ld target=\"%s\" matched=\"%s\"\n", + op->o_tag, dn, e->e_dn )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_referrals: op=%ld target=\"%s\" matched=\"%s\"\n", op->o_tag, dn, e->e_dn ); +#endif + if( refs != NULL ) { send_ldap_result( conn, op, rc = LDAP_REFERRAL, - e->e_dn, NULL, refs, NULL ); + e->e_dn, NULL, refs, NULL ); } ber_bvecfree( refs ); diff --git a/servers/slapd/back-ldbm/search.c b/servers/slapd/back-ldbm/search.c index 26ea7bf9e9..18c89e8384 100644 --- a/servers/slapd/back-ldbm/search.c +++ b/servers/slapd/back-ldbm/search.c @@ -53,7 +53,13 @@ ldbm_back_search( int nentries = 0; int manageDSAit = get_manageDSAit( op ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "ldbm_back_search: enter\n" )); +#else Debug(LDAP_DEBUG_TRACE, "=> ldbm_back_search\n", 0, 0, 0); +#endif + if ( *nbase == '\0' ) { /* DIT root special case */ @@ -114,9 +120,16 @@ ldbm_back_search( cache_return_entry_r( &li->li_cache, e ); +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_search: entry (%s) is a referral.\n", + e->e_dn )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_search: entry is referral\n", 0, 0, 0 ); +#endif + send_ldap_result( conn, op, LDAP_REFERRAL, matched_dn, NULL, refs, NULL ); @@ -148,8 +161,14 @@ ldbm_back_search( searchit: if ( candidates == NULL ) { /* no candidates */ +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_search: no candidates\n" )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_search: no candidates\n", 0, 0, 0 ); +#endif + send_search_result( conn, op, LDAP_SUCCESS, @@ -202,9 +221,15 @@ searchit: e = id2entry_r( be, id ); if ( e == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_search: candidate %ld not found.\n", id )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_search: candidate %ld not found\n", id, 0, 0 ); +#endif + goto loop_continue; } @@ -239,9 +264,15 @@ searchit: } else if ( dn_issuffix( e->e_ndn, realbase ) ) { /* alias is within scope */ +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "ldbm_search: \"%s\" in subtree\n", e->e_dn )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_search: \"%s\" in subtree\n", e->e_dn, 0, 0 ); +#endif + goto loop_continue; } @@ -321,14 +352,26 @@ searchit: } } } else { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL2, + "ldbm_search: candidate %ld scope not okay\n", id )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_search: candidate %ld scope not okay\n", id, 0, 0 ); +#endif + } } else { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL2, + "ldbm_search: candidate %ld does not match filter\n", id )); +#else Debug( LDAP_DEBUG_TRACE, "ldbm_search: candidate %ld does not match filter\n", id, 0, 0 ); +#endif + } loop_continue: @@ -362,8 +405,14 @@ base_candidate( { ID_BLOCK *idl; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "base_candidate: base (%s)\n", e->e_dn )); +#else Debug(LDAP_DEBUG_TRACE, "base_candidates: base: \"%s\"\n", e->e_dn, 0, 0); +#endif + idl = idl_alloc( 1 ); idl_insert( &idl, e->e_id, 1 ); @@ -386,9 +435,16 @@ search_candidates( static struct berval bv_ref = { sizeof("REFERRAL")-1, "REFERRAL" }; static struct berval bv_alias = { sizeof("ALIAS")-1, "ALIAS" }; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_DETAIL1, + "search_candidates: base (%s) scope %d deref %d\n", + e->e_ndn, scope, deref )); +#else Debug(LDAP_DEBUG_TRACE, "search_candidates: base=\"%s\" s=%d d=%d\n", e->e_ndn, scope, deref ); +#endif + xf.f_or = filter; xf.f_choice = LDAP_FILTER_OR; diff --git a/servers/slapd/back-ldbm/tools.c b/servers/slapd/back-ldbm/tools.c index 68d2a28969..4bae7a4c9c 100644 --- a/servers/slapd/back-ldbm/tools.c +++ b/servers/slapd/back-ldbm/tools.c @@ -46,8 +46,14 @@ int ldbm_tool_entry_open( if ( (id2entry = ldbm_cache_open( be, "id2entry", LDBM_SUFFIX, flags )) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_CRIT, + "Could not open/create id2entry%s\n", LDBM_SUFFIX )); +#else Debug( LDAP_DEBUG_ANY, "Could not open/create id2entry" LDBM_SUFFIX "\n", 0, 0, 0 ); +#endif + return( -1 ); } @@ -161,8 +167,14 @@ ID ldbm_tool_entry_put( e->e_id = li->li_nextid++; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "ldbm_tool_entry_put: (%s)%ld\n", e->e_dn, e->e_id )); +#else Debug( LDAP_DEBUG_TRACE, "=> ldbm_tool_entry_put( %ld, \"%s\" )\n", e->e_id, e->e_dn, 0 ); +#endif + rc = index_entry_add( be, e, e->e_attrs ); @@ -203,15 +215,28 @@ int ldbm_tool_entry_reindex( int rc; Entry *e; +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "ldbm_tool_entry_reindex: ID=%ld\n", (long)id )); +#else Debug( LDAP_DEBUG_ARGS, "=> ldbm_tool_entry_reindex( %ld )\n", (long) id, 0, 0 ); +#endif + e = ldbm_tool_entry_get( be, id ); if( e == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_INFO, + "ldbm_tool_entry_reindex: could not locate id %ld\n", + (long)id )); +#else Debug( LDAP_DEBUG_ANY, "ldbm_tool_entry_reindex:: could not locate id=%ld\n", (long) id, 0, 0 ); +#endif + return -1; } @@ -222,8 +247,14 @@ int ldbm_tool_entry_reindex( * */ +#ifdef NEW_LOGGING + LDAP_LOG(( "backend", LDAP_LEVEL_ENTRY, + "ldbm_tool_entry_reindex: (%s) %ld\n", e->e_dn, id )); +#else Debug( LDAP_DEBUG_TRACE, "=> ldbm_tool_entry_reindex( %ld, \"%s\" )\n", id, e->e_dn, 0 ); +#endif + rc = index_entry_add( be, e, e->e_attrs );