On (10/06/16 09:54), Sumit Bose wrote: >On Fri, Jun 10, 2016 at 09:26:38AM +0200, Lukas Slebodnik wrote: >> ehlo, >> >> I took some time to find out why pam-srv-tests fails so often. >> https://fedorahosted.org/sssd/ticket/2994 >> >> It is caused by slow execution of function sysdb_cache_password_ex. >> >> (Thu Jun 9 22:13:36:771048 2016) [sssd] [sysdb_cache_password_ex] (0x0100): >> start. >> (Thu Jun 9 22:13:36:771317 2016) [sssd] [sysdb_cache_password_ex] (0x0100): >> Before s3crypt_gen_salt >> (Thu Jun 9 22:13:36:771678 2016) [sssd] [sysdb_cache_password_ex] (0x0100): >> Before s3crypt_sha512 >> (Thu Jun 9 22:13:38:022470 2016) [sssd] [sysdb_cache_password_ex] (0x0100): >> Before sysdb_new_attrs >> (Thu Jun 9 22:13:38:023115 2016) [sssd] [sysdb_cache_password_ex] (0x0100): >> Before sysdb_attrs_add_string >> (Thu Jun 9 22:13:38:023431 2016) [sssd] [sysdb_cache_password_ex] (0x0100): >> Before sysdb_attrs_add_long >> (Thu Jun 9 22:13:38:023829 2016) [sssd] [sysdb_cache_password_ex] (0x0100): >> Before sysdb_attrs_add_long v2 >> (Thu Jun 9 22:13:38:024156 2016) [sssd] [sysdb_cache_password_ex] (0x0100): >> Before sysdb_attrs_add_long v3 >> (Thu Jun 9 22:13:38:024482 2016) [sssd] [sysdb_cache_password_ex] (0x0100): >> Before sysdb_attrs_add_uint32 >> (Thu Jun 9 22:13:38:024816 2016) [sssd] [sysdb_cache_password_ex] (0x0100): >> Before sysdb_set_user_attr >> (Thu Jun 9 22:13:38:035319 2016) [sssd] [sysdb_cache_password_ex] (0x0100): >> return eok >> >> As you can see, the execution of function s3crypt_sha512 >> took almost two seconds. >> >> Is it caused by valgrind all low entropy? > >The random data for the salt is already collected in s3crypt_gen_salt(). >sha512_crypt_r() basically mingles and password and the salt and does >hash operations. > >From a short inspection I can see nothing obvious which might cause such >delay. Maybe nspr_nss_init() if we really have to init NSS at this >point. The main operations in sha512_crypt_r() are heavily CPU bound, so >maybe some scheduler decides that its time for a different process to get >some CPU time? > >On the other hand can you give some details why the test fails because >of this delay? It looks a bit like we depend on a specific execution >time either in the test or the main code. If this is the case I think we >would make the code more robust by removing this dependency. >
There are two possitive tests for pam authentication. test_pam_cached_auth_success and test_pam_cached_auth_success_combined_pw_with_cached_2fa The test case is: * simulate authenticate in pam responder -> common_test_pam_cached_auth * back-end should be contacted * store cached password (here is slow function sysdb_cache_password_ex) // we need to explicitely cache password because it is usually done in // back-end * simulate authenticate in pam responder -> common_test_pam_cached_auth * back-end should *NOT* be contacted However, the value of cached_auth_timeout is set to 2 seconds in tests. and therefore back-end is sometimes contected in second authentication. I tried to increase value of cached_auth_timeout 2 -> 4. It helped a little bit but after this change I can still see failures in pam-srv-tests but in differetn tests :-) [ FAILED ] test_pam_preauth_cert_nomatch [ FAILED ] test_pam_preauth_cert_match [ FAILED ] test_pam_preauth_cert_match_wrong_user [ FAILED ] test_pam_preauth_cert_no_logon_name and it does not make sense to me because it failes due to slow p11_child (30 seconds shoudl be enough for p11_child) http://sssd-ci.duckdns.org/logs-test/job/0/73/rhel6/ci-build-debug/pam-srv-tests.log I will try with disabled debuging. LS _______________________________________________ sssd-devel mailing list [email protected] https://lists.fedorahosted.org/admin/lists/[email protected]
