[SSSD] [WIP] [TEST]: Observation patch

Lukas Slebodnik lslebodn at redhat.com
Thu Aug 13 05:49:01 UTC 2015


On (12/08/15 17:57), Petr Cech wrote:
>Hi,
>
>I have explored in detail why the test responder_cache_req-tests failed so
>often. I created a new VM with RHEL 6.7.
>
>
>OBSERVATION:
>
>How we know, CI machines are under pressure, so I wrote simple cpu_braker,
>see [1]. I ran the tests 50 times with cpu_braker (average load > 2.60, only
>1 CPU).
>Results:
>
>    [ RUN      ] test_users_by_filter_multiple_domains_valid
>    0x2 != 0
>    src/tests/cmocka/test_responder_cache_req.c:1875: error: Failure!
>
>    [ RUN      ] test_users_by_filter_multiple_domains_valid
>    0x1 != 0x2
>    src/tests/cmocka/test_responder_cache_req.c:1879: error: Failure!
>
>    [ RUN      ] test_groups_by_filter_valid
>    0x1 != 0x2
>    src/tests/cmocka/test_responder_cache_req.c:1972: error: Failure!
>
>    [ RUN      ] test_groups_by_filter_multiple_domains_valid
>    0x2 != 0
>    src/tests/cmocka/test_responder_cache_req.c:2051: error: Failure!
>
>    [ RUN      ] test_groups_by_filter_multiple_domains_valid
>    0x1 != 0x2
>    src/tests/cmocka/test_responder_cache_req.c:2055: error: Failure!
>
>These errors say they failed to retrieve data from the cache. Tests inserts
>two test values into the cache at the beginning of their run, and then tries
>to pull it back. And sometime if they are under pressure, they fail.
>
>For a more detailed explanation, I added some printf(). I ran the test 25
>times.
>The results:
>
>    [ RUN      ] test_users_by_filter_valid
>    >>> ... sysdb_store_user at [1439384336] (src/db/sysdb_ops.c:1882)
>    >>> ... cache_req_input_create at [1439384337]
>(src/responder/common/responder_cache_req.c:122)
>    >>> ... recent_filter = [(lastUpdate>=1439384337)]
>(src/responder/common/responder_cache_req.c:44)
>    >>> ... sysdb_store_user at [1439384337] (src/db/sysdb_ops.c:1882)
>    >>> ... recent_filter = [(lastUpdate>=1439384337)]
>(src/responder/common/responder_cache_req.c:44)
>    0x1 != 0x2
>    src/tests/cmocka/test_responder_cache_req.c:1748: error: Failure!
>
>    [ RUN      ] test_users_by_filter_multiple_domains_valid
>    >>> ... sysdb_store_user at [1439384174] (src/db/sysdb_ops.c:1882)
>    >>> ... sysdb_store_user at [1439384174] (src/db/sysdb_ops.c:1882)
>    >>> ... cache_req_input_create at [1439384175]
>(src/responder/common/responder_cache_req.c:122)
>    >>> ... recent_filter = [(lastUpdate>=1439384175)]
>(src/responder/common/responder_cache_req.c:44)
>    >>> ... recent_filter = [(lastUpdate>=1439384175)]
>(src/responder/common/responder_cache_req.c:44)
>    0x2 != 0
>    src/tests/cmocka/test_responder_cache_req.c:1874: error: Failure!
>
>    [ RUN      ] test_groups_by_filter_valid
>    >>> ... sysdb_store_group at [1439385276] (src/db/sysdb_ops.c:2042)
>    >>> ... cache_req_input_create at [1439385277]
>(src/responder/common/responder_cache_req.c:122)
>    >>> ... recent_filter = [(lastUpdate>=1439385277)]
>(src/responder/common/responder_cache_req.c:67)
>    >>> ... sysdb_store_group at [1439385277] (src/db/sysdb_ops.c:2042)
>    >>> ... recent_filter = [(lastUpdate>=1439385277)]
>(src/responder/common/responder_cache_req.c:67)
>    0x1 != 0x2
>    src/tests/cmocka/test_responder_cache_req.c:1971: error: Failure!
>
>    [ RUN      ] test_groups_by_filter_multiple_domains_valid
>    >>> ... sysdb_store_group at [1439385286] (src/db/sysdb_ops.c:2042)
>    >>> ... sysdb_store_group at [1439385287] (src/db/sysdb_ops.c:2042)
>    >>> ... cache_req_input_create at [1439385287]
>(src/responder/common/responder_cache_req.c:122)
>    >>> ... recent_filter = [(lastUpdate>=1439385287)]
>(src/responder/common/responder_cache_req.c:67)
>    >>> ... recent_filter = [(lastUpdate>=1439385287)]
>(src/responder/common/responder_cache_req.c:67)
>    0x1 != 0x2
>    src/tests/cmocka/test_responder_cache_req.c:2054: error: Failure!
>
>As we can see, we have discovered a new failing test
>test_users_by_filter_valid.
>
>REPRODUCER:
>
>Use cpu_braker [1] and observation patch [2] and try some iterations...
># for i in {1..50} ; do ./responder_cache_req-tests ; done
>
>
>SOLUTION?
>
>The problem is caused by trying to retrieve records from the cache, with the
>time filter set. A time filter we have set by the time of the request
>creation. However, we create the request in our tests after inserting records
>into the cache. Therefore, it may vary the data records time and the time
>filter.
>
>So, solution is create the request and then insert records or create request
>and set:
># req.req_start = req.req_start - 1.
>
>Please, can you help me? For example see function:
>test_users_by_filter_multiple_domains_valid()
>in src/tests/cmocka/test_responder_cache_req.c:1834
>
>Regards
>
>Petr
>
>
>ATTACHMENTS:
>
>[1] cpu_braker.c
>[2] 0001-TEST-Observation-patch.patch

>From b58608eaadca863b28b0cc80b0588fa536d508b8 Mon Sep 17 00:00:00 2001
>From: Petr Cech <pcech at redhat.com>
>Date: Wed, 12 Aug 2015 15:41:03 +0200
>Subject: [PATCH] [TEST]: Observation patch
>
>This patch is part of reproducer, nothing more.
>
>Resolves:
>https://fedorahosted.org/sssd/ticket/2730
>---
> src/db/sysdb_ops.c                         |    6 ++++++
> src/responder/common/responder_cache_req.c |   11 +++++++++++
> 2 files changed, 17 insertions(+), 0 deletions(-)
>
>diff --git a/src/db/sysdb_ops.c b/src/db/sysdb_ops.c
>index d1d43ebe6c71611f3371b2f4ccf5f7911909c9de..341380c2ed5d30ea1f63b25bdf2a860a1296a979 100644
>--- a/src/db/sysdb_ops.c
>+++ b/src/db/sysdb_ops.c
>@@ -1878,6 +1878,9 @@ int sysdb_store_user(struct sss_domain_info *domain,
>     errno_t sret = EOK;
>     bool in_transaction = false;
> 
>+    printf(">>> ... sysdb_store_user at [%lld] (%s:%i)\n",
>+           (long long) now, __FILE__, __LINE__);
>+
FYI:
You can use debug macros as well for trouble shooting issues.
Debugging in most of test can be enabled with command line argument
--debug-level=9 becasue test contais macro SSSD_DEBUG_OPTS in
struct poptOption array and dubuggin is initialized with another macro
"DEBUG_CLI_INIT(debug_level);"

I often use a trick to overrride default debug_level and to avoid
using command line arguments.
    debug_level = 0xFFF0;
    DEBUG_CLI_INIT(debug_level);

HTH

LS



More information about the sssd-devel mailing list