]> git.sur5r.net Git - openldap/blobdiff - servers/slapd/overlays/pcache.c
More logging for ITS#4423
[openldap] / servers / slapd / overlays / pcache.c
index a1a5fdd7256e9c6e604ead1013fb0ddb3d891b9b..8c3829bb733ceb66ea1e44fdfb14cc52c7a2f44a 100644 (file)
@@ -70,7 +70,7 @@ typedef struct query_template_s {
        int             no_of_queries;  /* Total number of queries in the template */
        time_t          ttl;            /* TTL for the queries of this template */
        time_t          negttl;         /* TTL for negative results */
-        ldap_pvt_thread_rdwr_t t_rwlock; /* Rd/wr lock for accessing queries in the template */
+       ldap_pvt_thread_rdwr_t *t_rwlock; /* Rd/wr lock for accessing queries in the template */
 } QueryTemplate;
 
 /*
@@ -132,11 +132,12 @@ typedef struct cache_manager_s {
        void    *cc_arg;
 
        ldap_pvt_thread_mutex_t         cache_mutex;
-       ldap_pvt_thread_mutex_t         remove_mutex;
 
        query_manager*   qm;    /* query cache managed by the cache manager */
 } cache_manager;
 
+static int pcache_debug;
+
 static AttributeDescription *ad_queryid;
 static char *queryid_schema = "( 1.3.6.1.4.1.4203.666.1.12 NAME 'queryid' "
                        "DESC 'list of queries the entry belongs to' "
@@ -264,7 +265,7 @@ add_query_on_top (query_manager* qm, CachedQuery* qc)
 
        qc->lru_down = top;
        qc->lru_up = NULL;
-       Debug( LDAP_DEBUG_TRACE, "Base of added query = %s\n",
+       Debug( pcache_debug, "Base of added query = %s\n",
                        q->base.bv_val, 0, 0 );
 }
 
@@ -416,7 +417,6 @@ strings_containment(struct berval* stored, struct berval* incoming)
 static int
 substr_containment_substr(Operation *op, Filter* stored, Filter* incoming)
 {
-       int i;
        int rc = 0;
 
        struct berval init_incoming;
@@ -493,9 +493,9 @@ query_containment(Operation *op, query_manager *qm,
 
        MatchingRule* mrule = NULL;
        if (inputf != NULL) {
-               Debug( LDAP_DEBUG_TRACE, "Lock QC index = %d\n",
+               Debug( pcache_debug, "Lock QC index = %d\n",
                                template_index, 0, 0 );
-               ldap_pvt_thread_rdwr_rlock(&(templa[template_index].t_rwlock));
+               ldap_pvt_thread_rdwr_rlock(templa[template_index].t_rwlock);
                for(qc=templa[template_index].query; qc != NULL; qc= qc->next) {
                        q = (Query*)qc;
                        if(base_scope_compare(&(q->base), base, q->scope, scope)) {
@@ -523,8 +523,8 @@ query_containment(Operation *op, query_manager *qm,
                                                        &(fi->f_ava->aa_value),
                                                        &(fs->f_ava->aa_value), &text);
                                                if (rc != LDAP_SUCCESS) {
-                                                       ldap_pvt_thread_rdwr_runlock(&(templa[template_index].t_rwlock));
-                                                       Debug( LDAP_DEBUG_TRACE,
+                                                       ldap_pvt_thread_rdwr_runlock(templa[template_index].t_rwlock);
+                                                       Debug( pcache_debug,
                                                        "Unlock: Exiting QC index=%d\n",
                                                        template_index, 0, 0 );
                                                        return NULL;
@@ -565,13 +565,13 @@ query_containment(Operation *op, query_manager *qm,
                                                fi=fi->f_next;
                                                break;
                                        case LDAP_FILTER_GE:
-                                               if (ret >= 0)
+                                               if (mrule && ret >= 0)
                                                        res = 1;
                                                fs=fs->f_next;
                                                fi=fi->f_next;
                                                break;
                                        case LDAP_FILTER_LE:
-                                               if (ret <= 0)
+                                               if (mrule && ret <= 0)
                                                        res = 1;
                                                fs=fs->f_next;
                                                fi=fi->f_next;
@@ -595,10 +595,10 @@ query_containment(Operation *op, query_manager *qm,
                                }
                        }
                }
-               Debug( LDAP_DEBUG_TRACE,
+               Debug( pcache_debug,
                        "Not answerable: Unlock QC index=%d\n",
                        template_index, 0, 0 );
-               ldap_pvt_thread_rdwr_runlock(&(templa[template_index].t_rwlock));
+               ldap_pvt_thread_rdwr_runlock(templa[template_index].t_rwlock);
        }
        return NULL;
 }
@@ -607,7 +607,6 @@ static void
 free_query (CachedQuery* qc)
 {
        Query* q = (Query*)qc;
-       int i;
 
        free(qc->q_uuid.bv_val);
        filter_free(q->filter);
@@ -637,7 +636,7 @@ static void add_query(
        }
        new_cached_query->lru_up = NULL;
        new_cached_query->lru_down = NULL;
-       Debug( LDAP_DEBUG_TRACE, "Added query expires at %ld\n",
+       Debug( pcache_debug, "Added query expires at %ld\n",
                        (long) new_cached_query->expiry_time, 0, 0 );
        new_query = (Query*)new_cached_query;
 
@@ -647,9 +646,9 @@ static void add_query(
        new_query->attrs = query->attrs;
 
        /* Adding a query    */
-       Debug( LDAP_DEBUG_TRACE, "Lock AQ index = %d\n",
+       Debug( pcache_debug, "Lock AQ index = %d\n",
                        template_index, 0, 0 );
-       ldap_pvt_thread_rdwr_wlock(&templ->t_rwlock);
+       ldap_pvt_thread_rdwr_wlock(templ->t_rwlock);
        if (templ->query == NULL)
                templ->query_last = new_cached_query;
        else
@@ -658,12 +657,12 @@ static void add_query(
        new_cached_query->prev = NULL;
        templ->query = new_cached_query;
        templ->no_of_queries++;
-       Debug( LDAP_DEBUG_TRACE, "TEMPLATE %d QUERIES++ %d\n",
+       Debug( pcache_debug, "TEMPLATE %d QUERIES++ %d\n",
                        template_index, templ->no_of_queries, 0 );
 
-       Debug( LDAP_DEBUG_TRACE, "Unlock AQ index = %d \n",
+       Debug( pcache_debug, "Unlock AQ index = %d \n",
                        template_index, 0, 0 );
-       ldap_pvt_thread_rdwr_wunlock(&templ->t_rwlock);
+       ldap_pvt_thread_rdwr_wunlock(templ->t_rwlock);
 
        /* Adding on top of LRU list  */
        ldap_pvt_thread_mutex_lock(&qm->lru_mutex);
@@ -703,7 +702,7 @@ static void cache_replacement(query_manager* qm, struct berval *result)
        result->bv_len = 0;
 
        if (!bottom) {
-               Debug ( LDAP_DEBUG_TRACE,
+               Debug ( pcache_debug,
                        "Cache replacement invoked without "
                        "any query in LRU list\n", 0, 0, 0 );
                ldap_pvt_thread_mutex_unlock(&qm->lru_mutex);
@@ -717,13 +716,13 @@ static void cache_replacement(query_manager* qm, struct berval *result)
        *result = bottom->q_uuid;
        bottom->q_uuid.bv_val = NULL;
 
-       Debug( LDAP_DEBUG_TRACE, "Lock CR index = %d\n", temp_id, 0, 0 );
-       ldap_pvt_thread_rdwr_wlock(&(qm->templates[temp_id].t_rwlock));
+       Debug( pcache_debug, "Lock CR index = %d\n", temp_id, 0, 0 );
+       ldap_pvt_thread_rdwr_wlock(qm->templates[temp_id].t_rwlock);
        remove_from_template(bottom, (qm->templates+temp_id));
-       Debug( LDAP_DEBUG_TRACE, "TEMPLATE %d QUERIES-- %d\n",
+       Debug( pcache_debug, "TEMPLATE %d QUERIES-- %d\n",
                temp_id, qm->templates[temp_id].no_of_queries, 0 );
-       Debug( LDAP_DEBUG_TRACE, "Unlock CR index = %d\n", temp_id, 0, 0 );
-       ldap_pvt_thread_rdwr_wunlock(&(qm->templates[temp_id].t_rwlock));
+       Debug( pcache_debug, "Unlock CR index = %d\n", temp_id, 0, 0 );
+       ldap_pvt_thread_rdwr_wunlock(qm->templates[temp_id].t_rwlock);
        free_query(bottom);
 }
 
@@ -815,7 +814,7 @@ remove_query_data (
                op->o_req_ndn = qi->xdn;
 
                if ( qi->del) {
-                       Debug( LDAP_DEBUG_TRACE, "DELETING ENTRY TEMPLATE=%s\n",
+                       Debug( pcache_debug, "DELETING ENTRY TEMPLATE=%s\n",
                                query_uuid->bv_val, 0, 0 );
 
                        op->o_tag = LDAP_REQ_DELETE;
@@ -837,7 +836,7 @@ remove_query_data (
                        mod.sml_values = vals;
                        mod.sml_nvalues = NULL;
                        mod.sml_next = NULL;
-                       Debug( LDAP_DEBUG_TRACE,
+                       Debug( pcache_debug,
                                "REMOVING TEMP ATTR : TEMPLATE=%s\n",
                                query_uuid->bv_val, 0, 0 );
 
@@ -979,35 +978,32 @@ cache_entries(
        op_tmp.o_dn = cm->db.be_rootdn;
        op_tmp.o_ndn = cm->db.be_rootndn;
 
-       Debug( LDAP_DEBUG_TRACE, "UUID for query being added = %s\n",
+       Debug( pcache_debug, "UUID for query being added = %s\n",
                        uuidbuf, 0, 0 );
 
        for ( e=si->head; e; e=si->head ) {
                si->head = e->e_private;
                e->e_private = NULL;
-               Debug( LDAP_DEBUG_NONE, "LOCKING REMOVE MUTEX\n", 0, 0, 0 );
-               ldap_pvt_thread_mutex_lock(&cm->remove_mutex);
-               Debug( LDAP_DEBUG_NONE, "LOCKED REMOVE MUTEX\n", 0, 0, 0);
                while ( cm->cur_entries > (cm->max_entries) ) {
                                qm->crfunc(qm, &crp_uuid);
                                if (crp_uuid.bv_val) {
-                                       Debug( LDAP_DEBUG_TRACE,
+                                       Debug( pcache_debug,
                                                "Removing query UUID %s\n",
                                                crp_uuid.bv_val, 0, 0 );
                                        return_val = remove_query_data(&op_tmp, rs, &crp_uuid);
-                                       Debug( LDAP_DEBUG_TRACE,
+                                       Debug( pcache_debug,
                                                "QUERY REMOVED, SIZE=%d\n",
                                                return_val, 0, 0);
                                        ldap_pvt_thread_mutex_lock(
                                                        &cm->cache_mutex );
                                        cm->cur_entries -= return_val;
                                        cm->num_cached_queries--;
-                                       Debug( LDAP_DEBUG_TRACE,
+                                       Debug( pcache_debug,
                                                "STORED QUERIES = %lu\n",
                                                cm->num_cached_queries, 0, 0 );
                                        ldap_pvt_thread_mutex_unlock(
                                                        &cm->cache_mutex );
-                                       Debug( LDAP_DEBUG_TRACE,
+                                       Debug( pcache_debug,
                                                "QUERY REMOVED, CACHE ="
                                                "%d entries\n",
                                                cm->cur_entries, 0, 0 );
@@ -1015,10 +1011,9 @@ cache_entries(
                }
 
                return_val = merge_entry(&op_tmp, e, query_uuid);
-               ldap_pvt_thread_mutex_unlock(&cm->remove_mutex);
                ldap_pvt_thread_mutex_lock(&cm->cache_mutex);
                cm->cur_entries += return_val;
-               Debug( LDAP_DEBUG_TRACE,
+               Debug( pcache_debug,
                        "ENTRY ADDED/MERGED, CACHED ENTRIES=%d\n",
                        cm->cur_entries, 0, 0 );
                return_val = 0;
@@ -1073,13 +1068,14 @@ pcache_response(
        } else if ( rs->sr_type == REP_RESULT ) {
                QueryTemplate* templ = (qm->templates)+si->template_id;
                if (( si->count && cache_entries( op, rs, &uuid ) == 0 ) ||
-                       ( !si->count && templ->negttl )) {
+                       ( templ->negttl && !si->count && !si->over &&
+                               rs->sr_err == LDAP_SUCCESS )) {
                        qm->addfunc(qm, &si->query, si->template_id,
                                si->count ? &uuid : NULL);
 
                        ldap_pvt_thread_mutex_lock(&cm->cache_mutex);
                        cm->num_cached_queries++;
-                       Debug( LDAP_DEBUG_TRACE, "STORED QUERIES = %lu\n",
+                       Debug( pcache_debug, "STORED QUERIES = %lu\n",
                                        cm->num_cached_queries, 0, 0 );
                        ldap_pvt_thread_mutex_unlock(&cm->cache_mutex);
 
@@ -1182,7 +1178,7 @@ pcache_chk_controls(
                /* fallthru */
 
        case SLAP_CONTROL_CRITICAL:
-               Debug( LDAP_DEBUG_TRACE, "%s: "
+               Debug( pcache_debug, "%s: "
                        "%scritical pagedResults control "
                        "disabled with proxy cache%s.\n",
                        op->o_log_prefix, non, stripped );
@@ -1207,8 +1203,6 @@ pcache_op_search(
        cache_manager *cm = on->on_bi.bi_private;
        query_manager*          qm = cm->qm;
 
-       int count;
-
        int i = -1;
 
        AttributeName   *filter_attrs = NULL;
@@ -1221,7 +1215,6 @@ pcache_op_search(
        int             cacheable = 0;
        int             fattr_cnt=0;
        int             fattr_got_oc = 0;
-       int             oc_attr_absent = 1;
 
        struct berval tempstr;
 
@@ -1233,7 +1226,7 @@ pcache_op_search(
                return SLAP_CB_CONTINUE;
        }
 
-       Debug( LDAP_DEBUG_TRACE, "query template of incoming query = %s\n",
+       Debug( pcache_debug, "query template of incoming query = %s\n",
                                        tempstr.bv_val, 0, 0 );
 
        /* FIXME: cannot cache/answer requests with pagedResults control */
@@ -1278,9 +1271,9 @@ pcache_op_search(
                BackendDB       *save_bd = op->o_bd;
                slap_callback   *save_cb = op->o_callback;
 
-               Debug( LDAP_DEBUG_TRACE, "QUERY ANSWERABLE\n", 0, 0, 0 );
+               Debug( pcache_debug, "QUERY ANSWERABLE\n", 0, 0, 0 );
                op->o_tmpfree( filter_attrs, op->o_tmpmemctx );
-               ldap_pvt_thread_rdwr_runlock(&qm->templates[i].t_rwlock);
+               ldap_pvt_thread_rdwr_runlock(qm->templates[i].t_rwlock);
                if ( BER_BVISNULL( &answerable->q_uuid )) {
                        /* No entries cached, just an empty result set */
                        i = rs->sr_err = 0;
@@ -1295,7 +1288,7 @@ pcache_op_search(
                return i;
        }
 
-       Debug( LDAP_DEBUG_TRACE, "QUERY NOT ANSWERABLE\n", 0, 0, 0 );
+       Debug( pcache_debug, "QUERY NOT ANSWERABLE\n", 0, 0, 0 );
 
        ldap_pvt_thread_mutex_lock(&cm->cache_mutex);
        if (cm->num_cached_queries >= cm->max_queries) {
@@ -1303,11 +1296,14 @@ pcache_op_search(
        }
        ldap_pvt_thread_mutex_unlock(&cm->cache_mutex);
 
+       if (op->ors_attrsonly)
+               cacheable = 0;
+
        if (cacheable) {
                slap_callback           *cb;
                struct search_info      *si;
 
-               Debug( LDAP_DEBUG_TRACE, "QUERY CACHEABLE\n", 0, 0, 0 );
+               Debug( pcache_debug, "QUERY CACHEABLE\n", 0, 0, 0 );
                query.filter = filter_dup(op->ors_filter, NULL);
                add_filter_attrs(op, &query.attrs, &qm->attr_sets[attr_set],
                        filter_attrs, fattr_cnt, fattr_got_oc);
@@ -1344,7 +1340,7 @@ pcache_op_search(
                }
 
        } else {
-               Debug( LDAP_DEBUG_TRACE, "QUERY NOT CACHEABLE\n",
+               Debug( pcache_debug, "QUERY NOT CACHEABLE\n",
                                        0, 0, 0);
        }
 
@@ -1423,33 +1419,32 @@ consistency_check(
                query = templ->query_last;
                if ( query ) pause = 0;
                op->o_time = slap_get_time();
-               ldap_pvt_thread_mutex_lock(&cm->remove_mutex);
                while (query && (query->expiry_time < op->o_time)) {
-                       ldap_pvt_thread_mutex_lock(&qm->lru_mutex);
-                       remove_query(qm, query);
-                       ldap_pvt_thread_mutex_unlock(&qm->lru_mutex);
-                       Debug( LDAP_DEBUG_TRACE, "Lock CR index = %d\n",
+                       Debug( pcache_debug, "Lock CR index = %d\n",
                                        i, 0, 0 );
-                       ldap_pvt_thread_rdwr_wlock(&templ->t_rwlock);
+                       ldap_pvt_thread_rdwr_wlock(templ->t_rwlock);
                        remove_from_template(query, templ);
-                       Debug( LDAP_DEBUG_TRACE, "TEMPLATE %d QUERIES-- %d\n",
+                       Debug( pcache_debug, "TEMPLATE %d QUERIES-- %d\n",
                                        i, templ->no_of_queries, 0 );
-                       Debug( LDAP_DEBUG_TRACE, "Unlock CR index = %d\n",
+                       Debug( pcache_debug, "Unlock CR index = %d\n",
                                        i, 0, 0 );
-                       ldap_pvt_thread_rdwr_wunlock(&templ->t_rwlock);
+                       ldap_pvt_thread_rdwr_wunlock(templ->t_rwlock);
+                       ldap_pvt_thread_mutex_lock(&qm->lru_mutex);
+                       remove_query(qm, query);
+                       ldap_pvt_thread_mutex_unlock(&qm->lru_mutex);
                        if ( BER_BVISNULL( &query->q_uuid ))
                                return_val = 0;
                        else
                                return_val = remove_query_data(op, &rs, &query->q_uuid);
-                       Debug( LDAP_DEBUG_TRACE, "STALE QUERY REMOVED, SIZE=%d\n",
+                       Debug( pcache_debug, "STALE QUERY REMOVED, SIZE=%d\n",
                                                return_val, 0, 0 );
                        ldap_pvt_thread_mutex_lock(&cm->cache_mutex);
                        cm->cur_entries -= return_val;
                        cm->num_cached_queries--;
-                       Debug( LDAP_DEBUG_TRACE, "STORED QUERIES = %lu\n",
+                       Debug( pcache_debug, "STORED QUERIES = %lu\n",
                                        cm->num_cached_queries, 0, 0 );
                        ldap_pvt_thread_mutex_unlock(&cm->cache_mutex);
-                       Debug( LDAP_DEBUG_TRACE,
+                       Debug( pcache_debug,
                                "STALE QUERY REMOVED, CACHE ="
                                "%d entries\n",
                                cm->cur_entries, 0, 0 );
@@ -1457,7 +1452,6 @@ consistency_check(
                        query = query->prev;
                        free_query(query_prev);
                }
-               ldap_pvt_thread_mutex_unlock(&cm->remove_mutex);
        }
        ldap_pvt_thread_mutex_lock( &slapd_rq.rq_mutex );
        if ( ldap_pvt_runqueue_isrunning( &slapd_rq, rtask )) {
@@ -1732,7 +1726,7 @@ pc_cf_gen( ConfigArgs *c )
                        return( 1 );
                }
                cm->cc_period = (time_t)t;
-               Debug( LDAP_DEBUG_TRACE,
+               Debug( pcache_debug,
                                "Total # of attribute sets to be cached = %d.\n",
                                cm->numattrsets, 0, 0 );
                qm->attr_sets = ( struct attr_set * )ch_calloc( cm->numattrsets,
@@ -1808,7 +1802,8 @@ pc_cf_gen( ConfigArgs *c )
                qm->templates = ( QueryTemplate* )ch_realloc( qm->templates,
                                ( num + 2 ) * sizeof( QueryTemplate ));
                temp = qm->templates + num;
-               ldap_pvt_thread_rdwr_init( &temp->t_rwlock );
+               temp->t_rwlock = ch_malloc( sizeof( ldap_pvt_thread_rdwr_t ) );
+               ldap_pvt_thread_rdwr_init( temp->t_rwlock );
                temp->query = temp->query_last = NULL;
                if ( lutil_parse_time( c->argv[3], &t ) != 0 ) {
                        snprintf( c->msg, sizeof( c->msg ), "unable to parse template ttl=\"%s\"",
@@ -1833,15 +1828,15 @@ pc_cf_gen( ConfigArgs *c )
                temp->no_of_queries = 0;
 
                ber_str2bv( c->argv[1], 0, 1, &temp->querystr );
-               Debug( LDAP_DEBUG_TRACE, "Template:\n", 0, 0, 0 );
-               Debug( LDAP_DEBUG_TRACE, "  query template: %s\n",
+               Debug( pcache_debug, "Template:\n", 0, 0, 0 );
+               Debug( pcache_debug, "  query template: %s\n",
                                temp->querystr.bv_val, 0, 0 );
                temp->attr_set_index = i;
                qm->attr_sets[i].flags |= PC_REFERENCED;
-               Debug( LDAP_DEBUG_TRACE, "  attributes: \n", 0, 0, 0 );
+               Debug( pcache_debug, "  attributes: \n", 0, 0, 0 );
                if ( ( attrarray = qm->attr_sets[i].attrs ) != NULL ) {
                        for ( i=0; attrarray[i].an_name.bv_val; i++ )
-                               Debug( LDAP_DEBUG_TRACE, "\t%s\n",
+                               Debug( pcache_debug, "\t%s\n",
                                        attrarray[i].an_name.bv_val, 0, 0 );
                }
                temp++; 
@@ -1933,7 +1928,6 @@ pcache_db_init(
        ldap_pvt_thread_mutex_init(&qm->lru_mutex);
 
        ldap_pvt_thread_mutex_init(&cm->cache_mutex);
-       ldap_pvt_thread_mutex_init(&cm->remove_mutex);
        return 0;
 }
 
@@ -2016,7 +2010,7 @@ pcache_db_close(
        slap_overinst *on = (slap_overinst *)be->bd_info;
        cache_manager *cm = on->on_bi.bi_private;
        query_manager *qm = cm->qm;
-       int i, j, rc = 0;
+       int i, rc = 0;
 
        /* cleanup stuff inherited from the original database... */
        cm->db.be_limits = NULL;
@@ -2032,7 +2026,8 @@ pcache_db_close(
                        free_query( qc );
                }
                free( qm->templates[i].querystr.bv_val );
-               ldap_pvt_thread_rdwr_destroy( &qm->templates[i].t_rwlock );
+               ldap_pvt_thread_rdwr_destroy( qm->templates[i].t_rwlock );
+               ch_free( qm->templates[i].t_rwlock );
        }
        free( qm->templates );
        qm->templates = NULL;
@@ -2069,7 +2064,6 @@ pcache_db_destroy(
 
        ldap_pvt_thread_mutex_destroy( &qm->lru_mutex );
        ldap_pvt_thread_mutex_destroy( &cm->cache_mutex );
-       ldap_pvt_thread_mutex_destroy( &cm->remove_mutex );
        free( qm );
        free( cm );
 
@@ -2088,6 +2082,10 @@ int pcache_initialize()
        LDAPAttributeType *at;
        int code;
        const char *err;
+       struct berval debugbv = BER_BVC("pcache");
+
+       if (( code = slap_loglevel_get( &debugbv, &pcache_debug )))
+               return code;
 
        at = ldap_str2attributetype( queryid_schema, &code, &err,
                LDAP_SCHEMA_ALLOW_ALL );