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

Petr Cech pcech at redhat.com
Wed Aug 12 15:57:06 UTC 2015


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
-------------- next part --------------
A non-text attachment was scrubbed...
Name: 0001-TEST-Observation-patch.patch
Type: text/x-patch
Size: 3106 bytes
Desc: not available
URL: <https://lists.fedorahosted.org/pipermail/sssd-devel/attachments/20150812/05f088c5/attachment.bin>
-------------- next part --------------
/*
 *   gcc cpu_braker.c -o cpu_braker.x
 */

#include <unistd.h>

int main(int argv, char *argc[]) {
    for (int i = 0; ; ++i) {
        i++;
        if (i / 10000 == 0) {
            usleep(100);
        }
    }
    return 0;
}


More information about the sssd-devel mailing list