Add in rety loop for query_user_list (from APP_HEAD). Deals with a bug
[nivanova/samba-autobuild/.git] / source3 / nsswitch / winbindd_cache.c
index 5eabcfca208b14aefc7445e909983b7a6de75a09..e0860cd695bb76e6add6b2b1a7d7e92c268795e2 100644 (file)
@@ -26,7 +26,6 @@
 #define DBGC_CLASS DBGC_WINBIND
 
 struct winbind_cache {
-       struct winbindd_methods *backend;
        TDB_CONTEXT *tdb;
 };
 
@@ -46,12 +45,14 @@ void wcache_flush_cache(void)
 {
        extern BOOL opt_nocache;
 
-       if (!wcache) return;
+       if (!wcache)
+               return;
        if (wcache->tdb) {
                tdb_close(wcache->tdb);
                wcache->tdb = NULL;
        }
-       if (opt_nocache) return;
+       if (opt_nocache)
+               return;
 
        wcache->tdb = tdb_open_log(lock_path("winbindd_cache.tdb"), 5000, 
                                   TDB_CLEAR_IF_FIRST, O_RDWR|O_CREAT, 0600);
@@ -59,6 +60,7 @@ void wcache_flush_cache(void)
        if (!wcache->tdb) {
                DEBUG(0,("Failed to open winbindd_cache.tdb!\n"));
        }
+       DEBUG(10,("wcache_flush_cache success\n"));
 }
 
 void winbindd_check_cache_size(time_t t)
@@ -93,25 +95,29 @@ void winbindd_check_cache_size(time_t t)
 /* get the winbind_cache structure */
 static struct winbind_cache *get_cache(struct winbindd_domain *domain)
 {
-       extern struct winbindd_methods msrpc_methods;
        struct winbind_cache *ret = wcache;
 
-       if (ret) return ret;
-       
-       ret = smb_xmalloc(sizeof(*ret));
-       ZERO_STRUCTP(ret);
-       switch (lp_security()) {
+       if (!domain->backend) {
+               extern struct winbindd_methods msrpc_methods;
+               switch (lp_security()) {
 #ifdef HAVE_ADS
-       case SEC_ADS: {
-               extern struct winbindd_methods ads_methods;
-               ret->backend = &ads_methods;
-               break;
-       }
+               case SEC_ADS: {
+                       extern struct winbindd_methods ads_methods;
+                       domain->backend = &ads_methods;
+                       break;
+               }
 #endif
-       default:
-               ret->backend = &msrpc_methods;
+               default:
+                       domain->backend = &msrpc_methods;
+               }
        }
 
+       if (ret)
+               return ret;
+       
+       ret = smb_xmalloc(sizeof(*ret));
+       ZERO_STRUCTP(ret);
+
        wcache = ret;
        wcache_flush_cache();
 
@@ -123,12 +129,12 @@ static struct winbind_cache *get_cache(struct winbindd_domain *domain)
 */
 static void centry_free(struct cache_entry *centry)
 {
-       if (!centry) return;
+       if (!centry)
+               return;
        SAFE_FREE(centry->data);
        free(centry);
 }
 
-
 /*
   pull a uint32 from a cache entry 
 */
@@ -199,8 +205,10 @@ static DOM_SID *centry_sid(struct cache_entry *centry, TALLOC_CTX *mem_ctx)
 {
        DOM_SID *sid;
        char *sid_string;
+
        sid = talloc(mem_ctx, sizeof(*sid));
-       if (!sid) return NULL;
+       if (!sid)
+               return NULL;
        
        sid_string = centry_string(centry, mem_ctx);
        if (!string_to_sid(sid, sid_string)) {
@@ -212,19 +220,100 @@ static DOM_SID *centry_sid(struct cache_entry *centry, TALLOC_CTX *mem_ctx)
 /* the server is considered down if it can't give us a sequence number */
 static BOOL wcache_server_down(struct winbindd_domain *domain)
 {
-       if (!wcache->tdb) return False;
-       return (domain->sequence_number == DOM_SEQUENCE_NONE);
+       BOOL ret;
+
+       if (!wcache->tdb)
+               return False;
+
+       ret = (domain->sequence_number == DOM_SEQUENCE_NONE);
+
+       if (ret)
+               DEBUG(10,("wcache_server_down: server for Domain %s down\n", 
+                       domain->name ));
+       return ret;
 }
 
+static NTSTATUS fetch_cache_seqnum( struct winbindd_domain *domain, time_t now )
+{
+       TDB_DATA data;
+       fstring key;
+       uint32 time_diff;
+       
+       if (!wcache->tdb) {
+               DEBUG(10,("fetch_cache_seqnum: tdb == NULL\n"));
+               return NT_STATUS_UNSUCCESSFUL;
+       }
+               
+       snprintf( key, sizeof(key), "SEQNUM/%s", domain->name );
+       
+       data = tdb_fetch_by_string( wcache->tdb, key );
+       if ( !data.dptr || data.dsize!=8 ) {
+               DEBUG(10,("fetch_cache_seqnum: invalid data size key [%s]\n", key ));
+               return NT_STATUS_UNSUCCESSFUL;
+       }
+       
+       domain->sequence_number = IVAL(data.dptr, 0);
+       domain->last_seq_check  = IVAL(data.dptr, 4);
+       
+       /* have we expired? */
+       
+       time_diff = now - domain->last_seq_check;
+       if ( time_diff > lp_winbind_cache_time() ) {
+               DEBUG(10,("fetch_cache_seqnum: timeout [%s][%u @ %u]\n",
+                       domain->name, domain->sequence_number,
+                       (uint32)domain->last_seq_check));
+               return NT_STATUS_UNSUCCESSFUL;
+       }
+
+       DEBUG(10,("fetch_cache_seqnum: success [%s][%u @ %u]\n", 
+               domain->name, domain->sequence_number, 
+               (uint32)domain->last_seq_check));
+
+       return NT_STATUS_OK;
+}
+
+static NTSTATUS store_cache_seqnum( struct winbindd_domain *domain )
+{
+       TDB_DATA data, key;
+       fstring key_str;
+       char buf[8];
+       
+       if (!wcache->tdb) {
+               DEBUG(10,("store_cache_seqnum: tdb == NULL\n"));
+               return NT_STATUS_UNSUCCESSFUL;
+       }
+               
+       snprintf( key_str, sizeof(key_str), "SEQNUM/%s", domain->name );
+       key.dptr = key_str;
+       key.dsize = strlen(key_str)+1;
+       
+       SIVAL(buf, 0, domain->sequence_number);
+       SIVAL(buf, 4, domain->last_seq_check);
+       data.dptr = buf;
+       data.dsize = 8;
+       
+       if ( tdb_store( wcache->tdb, key, data, TDB_REPLACE) == -1 ) {
+               DEBUG(10,("store_cache_seqnum: tdb_store fail key [%s]\n", key_str ));
+               return NT_STATUS_UNSUCCESSFUL;
+       }
+
+       DEBUG(10,("store_cache_seqnum: success [%s][%u @ %u]\n", 
+               domain->name, domain->sequence_number, 
+               (uint32)domain->last_seq_check));
+       
+       return NT_STATUS_OK;
+}
 
 /*
   refresh the domain sequence number. If force is True
   then always refresh it, no matter how recently we fetched it
 */
+
 static void refresh_sequence_number(struct winbindd_domain *domain, BOOL force)
 {
        NTSTATUS status;
        unsigned time_diff;
+       time_t t = time(NULL);
        unsigned cache_time = lp_winbind_cache_time();
 
        /* trying to reconnect is expensive, don't do it too often */
@@ -232,31 +321,50 @@ static void refresh_sequence_number(struct winbindd_domain *domain, BOOL force)
                cache_time *= 8;
        }
 
-       time_diff = time(NULL) - domain->last_seq_check;
+       time_diff = t - domain->last_seq_check;
 
        /* see if we have to refetch the domain sequence number */
        if (!force && (time_diff < cache_time)) {
+               DEBUG(10, ("refresh_sequence_number: %s time ok\n", domain->name));
                return;
        }
+       
+       /* try to get the sequence number from the tdb cache first */
+       /* this will update the timestamp as well */
+       
+       status = fetch_cache_seqnum( domain, t );
+       if ( NT_STATUS_IS_OK(status) )
+               goto done;      
 
-       status = wcache->backend->sequence_number(domain, &domain->sequence_number);
+       status = domain->backend->sequence_number(domain, &domain->sequence_number);
 
        if (!NT_STATUS_IS_OK(status)) {
                domain->sequence_number = DOM_SEQUENCE_NONE;
        }
-
+       
        domain->last_seq_check = time(NULL);
+       
+       /* save the new sequence number ni the cache */
+       store_cache_seqnum( domain );
+
+done:
+       DEBUG(10, ("refresh_sequence_number: %s seq number is now %d\n", 
+                  domain->name, domain->sequence_number));
+
+       return;
 }
 
 /*
   decide if a cache entry has expired
 */
-static BOOL centry_expired(struct winbindd_domain *domain, struct cache_entry *centry)
+static BOOL centry_expired(struct winbindd_domain *domain, const char *keystr, struct cache_entry *centry)
 {
        /* if the server is OK and our cache entry came from when it was down then
           the entry is invalid */
        if (domain->sequence_number != DOM_SEQUENCE_NONE && 
            centry->sequence_number == DOM_SEQUENCE_NONE) {
+               DEBUG(10,("centry_expired: Key %s for domain %s invalid sequence.\n",
+                       keystr, domain->name ));
                return True;
        }
 
@@ -264,9 +372,14 @@ static BOOL centry_expired(struct winbindd_domain *domain, struct cache_entry *c
           current sequence number then it is OK */
        if (wcache_server_down(domain) || 
            centry->sequence_number == domain->sequence_number) {
+               DEBUG(10,("centry_expired: Key %s for domain %s is good.\n",
+                       keystr, domain->name ));
                return False;
        }
 
+       DEBUG(10,("centry_expired: Key %s for domain %s expired\n",
+               keystr, domain->name ));
+
        /* it's expired */
        return True;
 }
@@ -297,9 +410,9 @@ static struct cache_entry *wcache_fetch(struct winbind_cache *cache,
        key.dptr = kstr;
        key.dsize = strlen(kstr);
        data = tdb_fetch(wcache->tdb, key);
-       free(kstr);
        if (!data.dptr) {
                /* a cache miss */
+               free(kstr);
                return NULL;
        }
 
@@ -310,25 +423,38 @@ static struct cache_entry *wcache_fetch(struct winbind_cache *cache,
 
        if (centry->len < 8) {
                /* huh? corrupt cache? */
+               DEBUG(10,("wcache_fetch: Corrupt cache for key %s domain %s (len < 8) ?\n",
+                       kstr, domain->name ));
                centry_free(centry);
+               free(kstr);
                return NULL;
        }
        
        centry->status = NT_STATUS(centry_uint32(centry));
        centry->sequence_number = centry_uint32(centry);
 
-       if (centry_expired(domain, centry)) {
+       if (centry_expired(domain, kstr, centry)) {
                extern BOOL opt_dual_daemon;
 
+               DEBUG(10,("wcache_fetch: entry %s expired for domain %s\n",
+                        kstr, domain->name ));
+
                if (opt_dual_daemon) {
                        extern BOOL background_process;
                        background_process = True;
+                       DEBUG(10,("wcache_fetch: background processing expired entry %s for domain %s\n",
+                                kstr, domain->name ));
                } else {
                        centry_free(centry);
+                       free(kstr);
                        return NULL;
                }
        }
 
+       DEBUG(10,("wcache_fetch: returning entry %s for domain %s\n",
+                kstr, domain->name ));
+
+       free(kstr);
        return centry;
 }
 
@@ -338,7 +464,8 @@ static struct cache_entry *wcache_fetch(struct winbind_cache *cache,
 static void centry_expand(struct cache_entry *centry, uint32 len)
 {
        uint8 *p;
-       if (centry->len - centry->ofs >= len) return;
+       if (centry->len - centry->ofs >= len)
+               return;
        centry->len *= 2;
        p = realloc(centry->data, centry->len);
        if (!p) {
@@ -383,7 +510,8 @@ static void centry_put_string(struct cache_entry *centry, const char *s)
 
        len = strlen(s);
        /* can't handle more than 254 char strings. Truncating is probably best */
-       if (len > 254) len = 254;
+       if (len > 254)
+               len = 254;
        centry_put_uint8(centry, len);
        centry_expand(centry, len);
        memcpy(centry->data + centry->ofs, s, len);
@@ -403,7 +531,8 @@ struct cache_entry *centry_start(struct winbindd_domain *domain, NTSTATUS status
 {
        struct cache_entry *centry;
 
-       if (!wcache->tdb) return NULL;
+       if (!wcache->tdb)
+               return NULL;
 
        centry = smb_xmalloc(sizeof(*centry));
 
@@ -449,11 +578,13 @@ static void wcache_save_name_to_sid(struct winbindd_domain *domain,
        fstring sid_string;
 
        centry = centry_start(domain, status);
-       if (!centry) return;
+       if (!centry)
+               return;
        centry_put_sid(centry, sid);
        fstrcpy(uname, name);
        strupper(uname);
        centry_end(centry, "NS/%s", sid_to_string(sid_string, sid));
+       DEBUG(10,("wcache_save_name_to_sid: %s -> %s\n", uname, sid_string));
        centry_free(centry);
 }
 
@@ -464,12 +595,14 @@ static void wcache_save_sid_to_name(struct winbindd_domain *domain, NTSTATUS sta
        fstring sid_string;
 
        centry = centry_start(domain, status);
-       if (!centry) return;
+       if (!centry)
+               return;
        if (NT_STATUS_IS_OK(status)) {
                centry_put_uint32(centry, type);
                centry_put_string(centry, name);
        }
        centry_end(centry, "SN/%s", sid_to_string(sid_string, sid));
+       DEBUG(10,("wcache_save_sid_to_name: %s -> %s\n", sid_string, name));
        centry_free(centry);
 }
 
@@ -480,12 +613,14 @@ static void wcache_save_user(struct winbindd_domain *domain, NTSTATUS status, WI
        fstring sid_string;
 
        centry = centry_start(domain, status);
-       if (!centry) return;
+       if (!centry)
+               return;
        centry_put_string(centry, info->acct_name);
        centry_put_string(centry, info->full_name);
        centry_put_sid(centry, info->user_sid);
        centry_put_sid(centry, info->group_sid);
        centry_end(centry, "U/%s", sid_to_string(sid_string, info->user_sid));
+       DEBUG(10,("wcache_save_user: %s (acct_name %s)\n", sid_string, info->acct_name));
        centry_free(centry);
 }
 
@@ -499,19 +634,23 @@ static NTSTATUS query_user_list(struct winbindd_domain *domain,
        struct winbind_cache *cache = get_cache(domain);
        struct cache_entry *centry = NULL;
        NTSTATUS status;
-       unsigned int i;
+       unsigned int i, retry;
 
-       if (!cache->tdb) goto do_query;
+       if (!cache->tdb)
+               goto do_query;
 
        centry = wcache_fetch(cache, domain, "UL/%s", domain->name);
-       if (!centry) goto do_query;
+       if (!centry)
+               goto do_query;
 
        *num_entries = centry_uint32(centry);
        
-       if (*num_entries == 0) goto do_cached;
+       if (*num_entries == 0)
+               goto do_cached;
 
        (*info) = talloc(mem_ctx, sizeof(**info) * (*num_entries));
-       if (! (*info)) smb_panic("query_user_list out of memory");
+       if (! (*info))
+               smb_panic("query_user_list out of memory");
        for (i=0; i<(*num_entries); i++) {
                (*info)[i].acct_name = centry_string(centry, mem_ctx);
                (*info)[i].full_name = centry_string(centry, mem_ctx);
@@ -521,6 +660,10 @@ static NTSTATUS query_user_list(struct winbindd_domain *domain,
 
 do_cached:     
        status = centry->status;
+
+       DEBUG(10,("query_user_list: [Cached] - cached list for domain %s status %s\n",
+               domain->name, get_friendly_nt_error_msg(status) ));
+
        centry_free(centry);
        return status;
 
@@ -532,19 +675,42 @@ do_query:
                return NT_STATUS_SERVER_DISABLED;
        }
 
-       status = cache->backend->query_user_list(domain, mem_ctx, num_entries, info);
+       /* Put the query_user_list() in a retry loop.  There appears to be
+        * some bug either with Windows 2000 or Samba's handling of large
+        * rpc replies.  This manifests itself as sudden disconnection
+        * at a random point in the enumeration of a large (60k) user list.
+        * The retry loop simply tries the operation again. )-:  It's not
+        * pretty but an acceptable workaround until we work out what the
+        * real problem is. */
+
+       retry = 0;
+       do {
+
+               DEBUG(10,("query_user_list: [Cached] - doing backend query for list for domain %s\n",
+                       domain->name ));
+
+               status = domain->backend->query_user_list(domain, mem_ctx, num_entries, info);
+               if (!NT_STATUS_IS_OK(status))
+                       DEBUG(3, ("query_user_list: returned 0x%08x, retrying\n", NT_STATUS_V(status)));
+                       if (NT_STATUS_V(status) == NT_STATUS_V(NT_STATUS_UNSUCCESSFUL)) {
+                               DEBUG(3, ("query_user_list: flushing connection cache\n"));
+                               winbindd_cm_flush();
+                       }
+
+       } while (NT_STATUS_V(status) == NT_STATUS_V(NT_STATUS_UNSUCCESSFUL) && (retry++ < 5));
 
        /* and save it */
-       refresh_sequence_number(domain, True);
+       refresh_sequence_number(domain, False);
        centry = centry_start(domain, status);
-       if (!centry) goto skip_save;
+       if (!centry)
+               goto skip_save;
        centry_put_uint32(centry, *num_entries);
        for (i=0; i<(*num_entries); i++) {
                centry_put_string(centry, (*info)[i].acct_name);
                centry_put_string(centry, (*info)[i].full_name);
                centry_put_sid(centry, (*info)[i].user_sid);
                centry_put_sid(centry, (*info)[i].group_sid);
-               if (cache->backend->consistent) {
+               if (domain->backend->consistent) {
                        /* when the backend is consistent we can pre-prime some mappings */
                        wcache_save_name_to_sid(domain, NT_STATUS_OK, 
                                                (*info)[i].acct_name, 
@@ -575,17 +741,21 @@ static NTSTATUS enum_dom_groups(struct winbindd_domain *domain,
        NTSTATUS status;
        unsigned int i;
 
-       if (!cache->tdb) goto do_query;
+       if (!cache->tdb)
+               goto do_query;
 
        centry = wcache_fetch(cache, domain, "GL/%s/domain", domain->name);
-       if (!centry) goto do_query;
+       if (!centry)
+               goto do_query;
 
        *num_entries = centry_uint32(centry);
        
-       if (*num_entries == 0) goto do_cached;
+       if (*num_entries == 0)
+               goto do_cached;
 
        (*info) = talloc(mem_ctx, sizeof(**info) * (*num_entries));
-       if (! (*info)) smb_panic("enum_dom_groups out of memory");
+       if (! (*info))
+               smb_panic("enum_dom_groups out of memory");
        for (i=0; i<(*num_entries); i++) {
                fstrcpy((*info)[i].acct_name, centry_string(centry, mem_ctx));
                fstrcpy((*info)[i].acct_desc, centry_string(centry, mem_ctx));
@@ -594,6 +764,10 @@ static NTSTATUS enum_dom_groups(struct winbindd_domain *domain,
 
 do_cached:     
        status = centry->status;
+
+       DEBUG(10,("enum_dom_groups: [Cached] - cached list for domain %s status %s\n",
+               domain->name, get_friendly_nt_error_msg(status) ));
+
        centry_free(centry);
        return status;
 
@@ -605,12 +779,16 @@ do_query:
                return NT_STATUS_SERVER_DISABLED;
        }
 
-       status = cache->backend->enum_dom_groups(domain, mem_ctx, num_entries, info);
+       DEBUG(10,("enum_dom_groups: [Cached] - doing backend query for list for domain %s\n",
+               domain->name ));
+
+       status = domain->backend->enum_dom_groups(domain, mem_ctx, num_entries, info);
 
        /* and save it */
-       refresh_sequence_number(domain, True);
+       refresh_sequence_number(domain, False);
        centry = centry_start(domain, status);
-       if (!centry) goto skip_save;
+       if (!centry)
+               goto skip_save;
        centry_put_uint32(centry, *num_entries);
        for (i=0; i<(*num_entries); i++) {
                centry_put_string(centry, (*info)[i].acct_name);
@@ -635,17 +813,21 @@ static NTSTATUS enum_local_groups(struct winbindd_domain *domain,
        NTSTATUS status;
        unsigned int i;
 
-       if (!cache->tdb) goto do_query;
+       if (!cache->tdb)
+               goto do_query;
 
        centry = wcache_fetch(cache, domain, "GL/%s/local", domain->name);
-       if (!centry) goto do_query;
+       if (!centry)
+               goto do_query;
 
        *num_entries = centry_uint32(centry);
        
-       if (*num_entries == 0) goto do_cached;
+       if (*num_entries == 0)
+               goto do_cached;
 
        (*info) = talloc(mem_ctx, sizeof(**info) * (*num_entries));
-       if (! (*info)) smb_panic("enum_dom_groups out of memory");
+       if (! (*info))
+               smb_panic("enum_dom_groups out of memory");
        for (i=0; i<(*num_entries); i++) {
                fstrcpy((*info)[i].acct_name, centry_string(centry, mem_ctx));
                fstrcpy((*info)[i].acct_desc, centry_string(centry, mem_ctx));
@@ -660,11 +842,14 @@ do_cached:
           indicate this. */
 
        if (wcache_server_down(domain)) {
-               DEBUG(10, ("query_user_list: returning cached user list and server was down\n"));
+               DEBUG(10, ("enum_local_groups: returning cached user list and server was down\n"));
                status = NT_STATUS_MORE_PROCESSING_REQUIRED;
        } else
                status = centry->status;
 
+       DEBUG(10,("enum_local_groups: [Cached] - cached list for domain %s status %s\n",
+               domain->name, get_friendly_nt_error_msg(status) ));
+
        centry_free(centry);
        return status;
 
@@ -676,12 +861,16 @@ do_query:
                return NT_STATUS_SERVER_DISABLED;
        }
 
-       status = cache->backend->enum_local_groups(domain, mem_ctx, num_entries, info);
+       DEBUG(10,("enum_local_groups: [Cached] - doing backend query for list for domain %s\n",
+               domain->name ));
+
+       status = domain->backend->enum_local_groups(domain, mem_ctx, num_entries, info);
 
        /* and save it */
-       refresh_sequence_number(domain, True);
+       refresh_sequence_number(domain, False);
        centry = centry_start(domain, status);
-       if (!centry) goto skip_save;
+       if (!centry)
+               goto skip_save;
        centry_put_uint32(centry, *num_entries);
        for (i=0; i<(*num_entries); i++) {
                centry_put_string(centry, (*info)[i].acct_name);
@@ -708,12 +897,14 @@ static NTSTATUS name_to_sid(struct winbindd_domain *domain,
        fstring uname;
        DOM_SID *sid2;
 
-       if (!cache->tdb) goto do_query;
+       if (!cache->tdb)
+               goto do_query;
 
        fstrcpy(uname, name);
        strupper(uname);
        centry = wcache_fetch(cache, domain, "NS/%s/%s", domain->name, uname);
-       if (!centry) goto do_query;
+       if (!centry)
+               goto do_query;
        *type = centry_uint32(centry);
        sid2 = centry_sid(centry, mem_ctx);
        if (!sid2) {
@@ -723,6 +914,10 @@ static NTSTATUS name_to_sid(struct winbindd_domain *domain,
        }
 
        status = centry->status;
+
+       DEBUG(10,("name_to_sid: [Cached] - cached name for domain %s status %s\n",
+               domain->name, get_friendly_nt_error_msg(status) ));
+
        centry_free(centry);
        return status;
 
@@ -732,7 +927,11 @@ do_query:
        if (wcache_server_down(domain)) {
                return NT_STATUS_SERVER_DISABLED;
        }
-       status = cache->backend->name_to_sid(domain, mem_ctx, name, sid, type);
+
+       DEBUG(10,("name_to_sid: [Cached] - doing backend query for name for domain %s\n",
+               domain->name ));
+
+       status = domain->backend->name_to_sid(domain, mem_ctx, name, sid, type);
 
        /* and save it */
        wcache_save_name_to_sid(domain, status, name, sid, *type);
@@ -756,15 +955,21 @@ static NTSTATUS sid_to_name(struct winbindd_domain *domain,
        NTSTATUS status;
        fstring sid_string;
 
-       if (!cache->tdb) goto do_query;
+       if (!cache->tdb)
+               goto do_query;
 
        centry = wcache_fetch(cache, domain, "SN/%s", sid_to_string(sid_string, sid));
-       if (!centry) goto do_query;
+       if (!centry)
+               goto do_query;
        if (NT_STATUS_IS_OK(centry->status)) {
                *type = centry_uint32(centry);
                *name = centry_string(centry, mem_ctx);
        }
        status = centry->status;
+
+       DEBUG(10,("sid_to_name: [Cached] - cached name for domain %s status %s\n",
+               domain->name, get_friendly_nt_error_msg(status) ));
+
        centry_free(centry);
        return status;
 
@@ -774,10 +979,14 @@ do_query:
        if (wcache_server_down(domain)) {
                return NT_STATUS_SERVER_DISABLED;
        }
-       status = cache->backend->sid_to_name(domain, mem_ctx, sid, name, type);
+
+       DEBUG(10,("sid_to_name: [Cached] - doing backend query for name for domain %s\n",
+               domain->name ));
+
+       status = domain->backend->sid_to_name(domain, mem_ctx, sid, name, type);
 
        /* and save it */
-       refresh_sequence_number(domain, True);
+       refresh_sequence_number(domain, False);
        wcache_save_sid_to_name(domain, status, sid, *name, *type);
        wcache_save_name_to_sid(domain, status, *name, sid, *type);
 
@@ -796,16 +1005,22 @@ static NTSTATUS query_user(struct winbindd_domain *domain,
        NTSTATUS status;
        fstring sid_string;
 
-       if (!cache->tdb) goto do_query;
+       if (!cache->tdb)
+               goto do_query;
 
        centry = wcache_fetch(cache, domain, "U/%s", sid_to_string(sid_string, user_sid));
-       if (!centry) goto do_query;
+       if (!centry)
+               goto do_query;
 
        info->acct_name = centry_string(centry, mem_ctx);
        info->full_name = centry_string(centry, mem_ctx);
        info->user_sid = centry_sid(centry, mem_ctx);
        info->group_sid = centry_sid(centry, mem_ctx);
        status = centry->status;
+
+       DEBUG(10,("query_user: [Cached] - cached info for domain %s status %s\n",
+               domain->name, get_friendly_nt_error_msg(status) ));
+
        centry_free(centry);
        return status;
 
@@ -816,10 +1031,13 @@ do_query:
                return NT_STATUS_SERVER_DISABLED;
        }
        
-       status = cache->backend->query_user(domain, mem_ctx, user_sid, info);
+       DEBUG(10,("sid_to_name: [Cached] - doing backend query for info for domain %s\n",
+               domain->name ));
+
+       status = domain->backend->query_user(domain, mem_ctx, user_sid, info);
 
        /* and save it */
-       refresh_sequence_number(domain, True);
+       refresh_sequence_number(domain, False);
        wcache_save_user(domain, status, info);
 
        return status;
@@ -838,23 +1056,31 @@ static NTSTATUS lookup_usergroups(struct winbindd_domain *domain,
        unsigned int i;
        fstring sid_string;
 
-       if (!cache->tdb) goto do_query;
+       if (!cache->tdb)
+               goto do_query;
 
        centry = wcache_fetch(cache, domain, "UG/%s", sid_to_string(sid_string, user_sid));
-       if (!centry) goto do_query;
+       if (!centry)
+               goto do_query;
 
        *num_groups = centry_uint32(centry);
        
-       if (*num_groups == 0) goto do_cached;
+       if (*num_groups == 0)
+               goto do_cached;
 
        (*user_gids) = talloc(mem_ctx, sizeof(**user_gids) * (*num_groups));
-       if (! (*user_gids)) smb_panic("lookup_usergroups out of memory");
+       if (! (*user_gids))
+               smb_panic("lookup_usergroups out of memory");
        for (i=0; i<(*num_groups); i++) {
                (*user_gids)[i] = centry_sid(centry, mem_ctx);
        }
 
 do_cached:     
        status = centry->status;
+
+       DEBUG(10,("lookup_usergroups: [Cached] - cached info for domain %s status %s\n",
+               domain->name, get_friendly_nt_error_msg(status) ));
+
        centry_free(centry);
        return status;
 
@@ -865,12 +1091,17 @@ do_query:
        if (wcache_server_down(domain)) {
                return NT_STATUS_SERVER_DISABLED;
        }
-       status = cache->backend->lookup_usergroups(domain, mem_ctx, user_sid, num_groups, user_gids);
+
+       DEBUG(10,("lookup_usergroups: [Cached] - doing backend query for info for domain %s\n",
+               domain->name ));
+
+       status = domain->backend->lookup_usergroups(domain, mem_ctx, user_sid, num_groups, user_gids);
 
        /* and save it */
-       refresh_sequence_number(domain, True);
+       refresh_sequence_number(domain, False);
        centry = centry_start(domain, status);
-       if (!centry) goto skip_save;
+       if (!centry)
+               goto skip_save;
        centry_put_uint32(centry, *num_groups);
        for (i=0; i<(*num_groups); i++) {
                centry_put_sid(centry, (*user_gids)[i]);
@@ -895,14 +1126,17 @@ static NTSTATUS lookup_groupmem(struct winbindd_domain *domain,
        unsigned int i;
        fstring sid_string;
 
-       if (!cache->tdb) goto do_query;
+       if (!cache->tdb)
+               goto do_query;
 
        centry = wcache_fetch(cache, domain, "GM/%s", sid_to_string(sid_string, group_sid));
-       if (!centry) goto do_query;
+       if (!centry)
+               goto do_query;
 
        *num_names = centry_uint32(centry);
        
-       if (*num_names == 0) goto do_cached;
+       if (*num_names == 0)
+               goto do_cached;
 
        (*sid_mem) = talloc(mem_ctx, sizeof(**sid_mem) * (*num_names));
        (*names) = talloc(mem_ctx, sizeof(**names) * (*num_names));
@@ -920,6 +1154,10 @@ static NTSTATUS lookup_groupmem(struct winbindd_domain *domain,
 
 do_cached:     
        status = centry->status;
+
+       DEBUG(10,("lookup_groupmem: [Cached] - cached info for domain %s status %s\n",
+               domain->name, get_friendly_nt_error_msg(status) ));
+
        centry_free(centry);
        return status;
 
@@ -933,13 +1171,18 @@ do_query:
        if (wcache_server_down(domain)) {
                return NT_STATUS_SERVER_DISABLED;
        }
-       status = cache->backend->lookup_groupmem(domain, mem_ctx, group_sid, num_names, 
-                                                sid_mem, names, name_types);
+
+       DEBUG(10,("lookup_groupmem: [Cached] - doing backend query for info for domain %s\n",
+               domain->name ));
+
+       status = domain->backend->lookup_groupmem(domain, mem_ctx, group_sid, num_names, 
+                                                 sid_mem, names, name_types);
 
        /* and save it */
-       refresh_sequence_number(domain, True);
+       refresh_sequence_number(domain, False);
        centry = centry_start(domain, status);
-       if (!centry) goto skip_save;
+       if (!centry)
+               goto skip_save;
        centry_put_uint32(centry, *num_names);
        for (i=0; i<(*num_names); i++) {
                centry_put_sid(centry, (*sid_mem)[i]);
@@ -971,29 +1214,38 @@ static NTSTATUS trusted_domains(struct winbindd_domain *domain,
                                char ***alt_names,
                                DOM_SID **dom_sids)
 {
-       struct winbind_cache *cache = get_cache(domain);
+       get_cache(domain);
+
+       DEBUG(10,("trusted_domains: [Cached] - doing backend query for info for domain %s\n",
+               domain->name ));
 
        /* we don't cache this call */
-       return cache->backend->trusted_domains(domain, mem_ctx, num_domains, 
+       return domain->backend->trusted_domains(domain, mem_ctx, num_domains, 
                                               names, alt_names, dom_sids);
 }
 
 /* find the domain sid */
 static NTSTATUS domain_sid(struct winbindd_domain *domain, DOM_SID *sid)
 {
-       struct winbind_cache *cache = get_cache(domain);
+       get_cache(domain);
+
+       DEBUG(10,("domain_sid: [Cached] - doing backend query for info for domain %s\n",
+               domain->name ));
 
        /* we don't cache this call */
-       return cache->backend->domain_sid(domain, sid);
+       return domain->backend->domain_sid(domain, sid);
 }
 
 /* find the alternate names for the domain, if any */
 static NTSTATUS alternate_name(struct winbindd_domain *domain)
 {
-       struct winbind_cache *cache = get_cache(domain);
+       get_cache(domain);
+
+       DEBUG(10,("alternate_name: [Cached] - doing backend query for info for domain %s\n",
+               domain->name ));
 
        /* we don't cache this call */
-       return cache->backend->alternate_name(domain);
+       return domain->backend->alternate_name(domain);
 }
 
 /* the ADS backend methods are exposed via this structure */