Hi all,

I came back to ticket #3222 "sssd still showing ipa user after removed from last group" [1]. And I have new knowledge. But I still do not see the light at the end of the tunnel.

[1] https://fedorahosted.org/sssd/ticket/3222

I attached patch which enables some basic debug on using of memcache. And two reproducers (with and without memcache) which are based on reproducer written in ticket.

If we use memcache, the issue occurs only sometimes.

The difference between both cases is mixed state of switch after sss_nss_mc_getgrnam() call in _nss_sss_getgrnam_r() function.

Note: code says (for default case):
/* if using the mmaped cache failed,
 * fall back to socket based comms */


Could anyone help, please?


The report is:

#--- WRONG

[root@mirach sssd]# date && getent group testgroup
Wed Nov  9 16:01:05 CET 2016
>>> [A] record not found (time[1478703665])
>>> [B] record not found (time[1478703665])
testgroup:*:1703800674:

Number of members added 1

[root@mirach sssd]# sss_cache -UG && date && getent group testgroup
Wed Nov  9 16:01:07 CET 2016
>>> [A] record not found (time[1478703667])
>>> [B] default (time[1478703667])
testgroup:*:1703800674:testuser

Number of members removed 1

[root@mirach sssd]# sss_cache -UG && date && getent group testgroup
Wed Nov  9 16:01:09 CET 2016
>>> mc record expires at [1478703967] | now [1478703669]
>>> [A] MC used (time[1478703669])
testgroup:*:1703800674:testuser

[root@mirach sssd]# grep '>>>' *.log
sssd_nss.log:(Wed Nov 9 16:01:06 2016) [sssd[nss]] [sss_mmap_set_rec_header] (0x0010): >>> MC STORE expiration [1478703966] | now [1478703666] | delta [300] sssd_nss.log:(Wed Nov 9 16:01:06 2016) [sssd[nss]] [sss_mmap_cache_gr_store] (0x0010): >>> MC STORE [testgroup] [300] members [0] sssd_nss.log:(Wed Nov 9 16:01:07 2016) [sssd[nss]] [sss_mmap_set_rec_header] (0x0010): >>> MC STORE expiration [1478703967] | now [1478703667] | delta [300] sssd_nss.log:(Wed Nov 9 16:01:07 2016) [sssd[nss]] [sss_mmap_cache_gr_store] (0x0010): >>> MC STORE [testgroup] [300] members [1]



#--- RIGHT

[root@mirach sssd]# date && getent group testgroup
Wed Nov  9 15:56:54 CET 2016
>>> [A] record not found (time[1478703414])
>>> [B] record not found (time[1478703414])
testgroup:*:1703800674:

Number of members added 1

[root@mirach sssd]# sss_cache -UG && date && getent group testgroup
Wed Nov  9 15:56:56 CET 2016
>>> [A] default (time[1478703416])
>>> [B] default (time[1478703416])
testgroup:*:1703800674:testuser

Number of members removed 1

[root@mirach sssd]# sss_cache -UG && date && getent group testgroup
Wed Nov  9 15:56:58 CET 2016
>>> [A] record not found (time[1478703418])
>>> [B] record not found (time[1478703418])
testgroup:*:1703800674:

[root@mirach sssd]# grep '>>>' *.log
sssd_nss.log:(Wed Nov 9 15:56:54 2016) [sssd[nss]] [sss_mmap_set_rec_header] (0x0010): >>> MC STORE expiration [1478703714] | now [1478703414] | delta [300] sssd_nss.log:(Wed Nov 9 15:56:54 2016) [sssd[nss]] [sss_mmap_cache_gr_store] (0x0010): >>> MC STORE [testgroup] [300] members [0] sssd_nss.log:(Wed Nov 9 15:56:56 2016) [sssd[nss]] [sss_mmap_set_rec_header] (0x0010): >>> MC STORE expiration [1478703716] | now [1478703416] | delta [300] sssd_nss.log:(Wed Nov 9 15:56:56 2016) [sssd[nss]] [sss_mmap_cache_gr_store] (0x0010): >>> MC STORE [testgroup] [300] members [1] sssd_nss.log:(Wed Nov 9 15:56:58 2016) [sssd[nss]] [sss_mmap_set_rec_header] (0x0010): >>> MC STORE expiration [1478703718] | now [1478703418] | delta [300] sssd_nss.log:(Wed Nov 9 15:56:58 2016) [sssd[nss]] [sss_mmap_cache_gr_store] (0x0010): >>> MC STORE [testgroup] [300] members [0]


Regards

--
Petr^4 Čech
>From 08ec8bbaaab760396747420e46f8190c3a2dfead Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Petr=20=C4=8Cech?= <pc...@redhat.com>
Date: Mon, 24 Oct 2016 15:16:34 +0200
Subject: [PATCH] WIP: debug for t3222

This patch enables debug messages needed for investigation of memory
cache.
---
 src/responder/nss/nsssrv_mmap_cache.c |  8 ++++++++
 src/sss_client/nss_group.c            | 10 ++++++++++
 src/sss_client/nss_mc_group.c         |  3 +++
 3 files changed, 21 insertions(+)

diff --git a/src/responder/nss/nsssrv_mmap_cache.c b/src/responder/nss/nsssrv_mmap_cache.c
index f7f62733941cd3ae3b071d6d54c801f9be1ce800..f25357712bf06da49e3a96f0ff7a4812c4f63dca 100644
--- a/src/responder/nss/nsssrv_mmap_cache.c
+++ b/src/responder/nss/nsssrv_mmap_cache.c
@@ -643,6 +643,8 @@ static inline void sss_mmap_set_rec_header(struct sss_mc_ctx *mcc,
     rec->expire = time(NULL) + ttl;
     rec->hash1 = sss_mc_hash(mcc, key1, key1_len);
     rec->hash2 = sss_mc_hash(mcc, key2, key2_len);
+
+    DEBUG(SSSDBG_FATAL_FAILURE, ">>> MC STORE expiration [%lu] | now [%lu] | delta [%li]\n", rec->expire, time(NULL), rec->expire - time(NULL));
 }
 
 static inline void sss_mmap_chain_in_rec(struct sss_mc_ctx *mcc,
@@ -846,11 +848,13 @@ int sss_mmap_cache_gr_store(struct sss_mc_ctx **_mcc,
 
     if (mcc == NULL) {
         /* cache not initialized ? */
+        DEBUG(SSSDBG_FATAL_FAILURE, ">>> MC STORE err 1\n");
         return EINVAL;
     }
 
     ret = snprintf(gidstr, 11, "%ld", (long)gid);
     if (ret > 10) {
+        DEBUG(SSSDBG_FATAL_FAILURE, ">>> MC STORE err 2\n");
         return EINVAL;
     }
     to_sized_string(&gidkey, gidstr);
@@ -860,11 +864,13 @@ int sss_mmap_cache_gr_store(struct sss_mc_ctx **_mcc,
               sizeof(struct sss_mc_grp_data) +
               data_len;
     if (rec_len > mcc->dt_size) {
+        DEBUG(SSSDBG_FATAL_FAILURE, ">>> MC STORE err 3\n");
         return ENOMEM;
     }
 
     ret = sss_mc_get_record(_mcc, rec_len, name, &rec);
     if (ret != EOK) {
+        DEBUG(SSSDBG_FATAL_FAILURE, ">>> MC STORE err 4\n");
         return ret;
     }
 
@@ -889,6 +895,8 @@ int sss_mmap_cache_gr_store(struct sss_mc_ctx **_mcc,
     memcpy(&data->strs[pos], membuf, memsize);
     pos += memsize;
 
+    DEBUG(SSSDBG_FATAL_FAILURE, ">>> MC STORE [%s] [%li] members [%i]\n", name->str, mcc->valid_time_slot, data->members);
+
     MC_LOWER_BARRIER(rec);
 
     /* finally chain the rec in the hash table */
diff --git a/src/sss_client/nss_group.c b/src/sss_client/nss_group.c
index 0e686af43aeb84a5938315e3922e9fcf2fef4e83..38cffe0fa518c923d1a29e83e0f0df365e91bbf7 100644
--- a/src/sss_client/nss_group.c
+++ b/src/sss_client/nss_group.c
@@ -24,9 +24,11 @@
 #include <sys/types.h>
 #include <unistd.h>
 #include <stdlib.h>
+#include <stdio.h>
 #include <stdint.h>
 #include <string.h>
 #include <stdbool.h>
+#include <time.h>
 #include "sss_cli.h"
 #include "nss_mc.h"
 
@@ -421,17 +423,21 @@ enum nss_status _nss_sss_getgrnam_r(const char *name, struct group *result,
     switch (ret) {
     case 0:
         *errnop = 0;
+        printf(">>> [A] MC used (time[%lu])\n", time(NULL));
         return NSS_STATUS_SUCCESS;
     case ERANGE:
         *errnop = ERANGE;
+        printf(">>> [A] MC expired (time[%lu])\n", time(NULL));
         return NSS_STATUS_TRYAGAIN;
     case ENOENT:
         /* fall through, we need to actively ask the parent
          * if no entry is found */
+        printf(">>> [A] record not found (time[%lu])\n", time(NULL));
         break;
     default:
         /* if using the mmaped cache failed,
          * fall back to socket based comms */
+        printf(">>> [A] default (time[%lu])\n", time(NULL));
         break;
     }
 
@@ -446,18 +452,22 @@ enum nss_status _nss_sss_getgrnam_r(const char *name, struct group *result,
     case 0:
         *errnop = 0;
         nret = NSS_STATUS_SUCCESS;
+        printf(">>> [B] MC used (time[%lu])\n", time(NULL));
         goto out;
     case ERANGE:
         *errnop = ERANGE;
         nret = NSS_STATUS_TRYAGAIN;
+        printf(">>> [B] MC expired (time[%lu])\n", time(NULL));
         goto out;
     case ENOENT:
         /* fall through, we need to actively ask the parent
          * if no entry is found */
+        printf(">>> [B] record not found (time[%lu])\n", time(NULL));
         break;
     default:
         /* if using the mmaped cache failed,
          * fall back to socket based comms */
+        printf(">>> [B] default (time[%lu])\n", time(NULL));
         break;
     }
 
diff --git a/src/sss_client/nss_mc_group.c b/src/sss_client/nss_mc_group.c
index aacf59d9fd8b81ea895f4660de08f3e44f0ce645..1b5632d5debf5c0cb6bd948df913ba5fed773aad 100644
--- a/src/sss_client/nss_mc_group.c
+++ b/src/sss_client/nss_mc_group.c
@@ -23,6 +23,7 @@
 #include <stdio.h>
 #include <string.h>
 #include <stdlib.h>
+#include <stdio.h>
 #include <stddef.h>
 #include <sys/mman.h>
 #include <time.h>
@@ -48,8 +49,10 @@ static errno_t sss_nss_mc_parse_result(struct sss_mc_rec *rec,
     expire = rec->expire;
     if (expire < time(NULL)) {
         /* entry is now invalid */
+        printf(">>> mc record expired [%lu] | now [%lu]\n", rec->expire, time(NULL));
         return EINVAL;
     }
+    printf(">>> mc record expires at [%lu] | now [%lu]\n", rec->expire, time(NULL));
 
     data = (struct sss_mc_grp_data *)rec->data;
 
-- 
2.7.4

Attachment: group_member_with_memcache.sh
Description: application/shellscript

Attachment: group_member_without_memcache.sh
Description: application/shellscript

_______________________________________________
sssd-devel mailing list -- sssd-devel@lists.fedorahosted.org
To unsubscribe send an email to sssd-devel-le...@lists.fedorahosted.org

Reply via email to