Hi,
this patch is a hotfix for pam-srv-failing tests.
Increasing the timeout to 30 seconds seems to be enough. I do not want to make it too big because the timeout is currently not configurable.
I'd like to talk to Sumit about what he thinks the proper solution should be. I am not sure if it times out because we do something unnecessary in p11 child.
See the simple patch.
Michal
On 08/14/2015 02:40 PM, Michal Židek wrote:
Hi,
this patch is a hotfix for pam-srv-failing tests.
Increasing the timeout to 30 seconds seems to be enough. I do not want to make it too big because the timeout is currently not configurable.
I'd like to talk to Sumit about what he thinks the proper solution should be. I am not sure
When he returns from PTO that is.
if it times out because we do something unnecessary in p11 child.
See the simple patch.
Michal
sssd-devel mailing list sssd-devel@lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/sssd-devel
On 14 August 2015 at 14:40, Michal Židek mzidek@redhat.com wrote:
Hi,
this patch is a hotfix for pam-srv-failing tests.
Increasing the timeout to 30 seconds seems to be enough. I do not want to make it too big because the timeout is currently not configurable.
I'd like to talk to Sumit about what he thinks the proper solution should be. I am not sure if it times out because we do something unnecessary in p11 child.
One "simple" fix for this kind of failures is to use dbx/gdb/pstack to wait for a specific "checkpoint" in the code. For example http://svn.nrubsig.org/svn/people/gisburn/code/kdctest/test3.sh demonstrates this by waiting for the krb5kdc to enter the poll event loop: -- snip -- function run_kdc { typeset -x KRB5_KDC_PROFILE="${_.krb5_kdc_profile}" typeset -x KRB5_CONFIG='/dev/null'
(( _.kdc_pid != -1 )) && return 1
krb5kdc -n -r "${_.realmname}" & (( _.kdc_pid=$! ))
# Wait until the KDC becomes ready # (we probe the KDC process itself because a simple # $ sleep 10 # is not reliable when the system # is paging/swapping or simply too slow (e.g. # embedded system)) typeset pout integer i pres for (( i=100; i > 0 ; i-- )) ; do sleep 0.25
pout="${ /usr/bin/pstack ${_.kdc_pid} 2>'/dev/null' ; (( pres=$? )) ; }" if (( pres != 0 )) || \ [[ "${pout}" == ~(E)[[:space:]]+_*(epoll|poll) ]] ; then break fi done
# KDC process still running ? kill -0 ${_.kdc_pid} 2>'/dev/null' || \ { print -u2 -f $"KDC failed.\n" ; return 1 ; }
return 0 } -- snip --
----
Bye, Roland
On (14/08/15 14:40), Michal Židek wrote:
Hi,
this patch is a hotfix for pam-srv-failing tests.
Increasing the timeout to 30 seconds seems to be enough. I do not want to make it too big because the timeout is currently not configurable.
The observation seems to be correct; at least according to log file http://sssd-ci.duckdns.org/logs/job/23/21/rhel7/ci-build-debug/pam-srv-tests...
There is a 3.5 seconds delays between creating child handler and 1st message in child. (Mon Aug 17 10:50:35:304490 2015) [sssd] [child_handler_setup] (0x2000): Setting up signal handler up for pid [30764] (Mon Aug 17 10:50:35:305471 2015) [sssd] [child_handler_setup] (0x2000): Signal handler set up for pid [30764] (Mon Aug 17 10:50:35:306615 2015) [sssd] [pam_initgr_cache_remove] (0x2000): [pamuser] removed from PAM initgroup cache (Mon Aug 17 10:50:35:307109 2015) [sssd] [pam_initgr_cache_remove] (0x2000): [wronguser] removed from PAM initgroup cache (Mon Aug 17 10:50:38:972629 2015) [[sssd[p11_child[30764]]]] [main] (0x0400): p11_child started.
And another 5 seconds between starting real work in the child (Mon Aug 17 10:50:39:091652 2015) [[sssd[p11_child[30764]]]] [main] (0x0020): setuid failed: 1, p11_child might not work! (Mon Aug 17 10:50:39:093917 2015) [[sssd[p11_child[30764]]]] [main] (0x0020): setgid failed: 1, p11_child might not work! (Mon Aug 17 10:50:39:094746 2015) [[sssd[p11_child[30764]]]] [main] (0x2000): Running with real IDs [499][499]. (Mon Aug 17 10:50:44:375594 2015) [[sssd[p11_child[30764]]]] [do_work] (0x4000): Default Module List:
It might be caused either by valgrind or by high load on machine. IMHO changing default from 10 seconds to 30 is too much.
We can use the same trick in dyndns_test dyndns_tests_CFLAGS = \ $(AM_CFLAGS) \ -DDYNDNS_TIMEOUT=2
and in pamsrv_cmd.c use conditional default value. #ifndef SSS_P11_CHILD_TIMEOUT # define SSS_P11_CHILD_TIMEOUT 30 #endif
I'd like to talk to Sumit about what he thinks the proper solution should be. I am not sure if it times out because we do something unnecessary in p11 child.
See the simple patch.
LS
On 08/17/2015 01:22 PM, Lukas Slebodnik wrote:
On (14/08/15 14:40), Michal Židek wrote:
Hi,
this patch is a hotfix for pam-srv-failing tests.
Increasing the timeout to 30 seconds seems to be enough. I do not want to make it too big because the timeout is currently not configurable.
The observation seems to be correct; at least according to log file http://sssd-ci.duckdns.org/logs/job/23/21/rhel7/ci-build-debug/pam-srv-tests...
There is a 3.5 seconds delays between creating child handler and 1st message in child. (Mon Aug 17 10:50:35:304490 2015) [sssd] [child_handler_setup] (0x2000): Setting up signal handler up for pid [30764] (Mon Aug 17 10:50:35:305471 2015) [sssd] [child_handler_setup] (0x2000): Signal handler set up for pid [30764] (Mon Aug 17 10:50:35:306615 2015) [sssd] [pam_initgr_cache_remove] (0x2000): [pamuser] removed from PAM initgroup cache (Mon Aug 17 10:50:35:307109 2015) [sssd] [pam_initgr_cache_remove] (0x2000): [wronguser] removed from PAM initgroup cache (Mon Aug 17 10:50:38:972629 2015) [[sssd[p11_child[30764]]]] [main] (0x0400): p11_child started.
And another 5 seconds between starting real work in the child (Mon Aug 17 10:50:39:091652 2015) [[sssd[p11_child[30764]]]] [main] (0x0020): setuid failed: 1, p11_child might not work! (Mon Aug 17 10:50:39:093917 2015) [[sssd[p11_child[30764]]]] [main] (0x0020): setgid failed: 1, p11_child might not work! (Mon Aug 17 10:50:39:094746 2015) [[sssd[p11_child[30764]]]] [main] (0x2000): Running with real IDs [499][499]. (Mon Aug 17 10:50:44:375594 2015) [[sssd[p11_child[30764]]]] [do_work] (0x4000): Default Module List:
It might be caused either by valgrind or by high load on machine. IMHO changing default from 10 seconds to 30 is too much.
We can use the same trick in dyndns_test dyndns_tests_CFLAGS = \ $(AM_CFLAGS) \ -DDYNDNS_TIMEOUT=2
and in pamsrv_cmd.c use conditional default value. #ifndef SSS_P11_CHILD_TIMEOUT # define SSS_P11_CHILD_TIMEOUT 30 #endif
I'd like to talk to Sumit about what he thinks the proper solution should be. I am not sure if it times out because we do something unnecessary in p11 child.
See the simple patch.
LS
Thank you for comments. I pushed the newly attached patch to CI (5 times, essential tests only, with disabled be_req tests). To see if it fails. I am waiting for the results now.
Michal
On (17/08/15 14:45), Michal Židek wrote:
On 08/17/2015 01:22 PM, Lukas Slebodnik wrote:
On (14/08/15 14:40), Michal Židek wrote:
Hi,
this patch is a hotfix for pam-srv-failing tests.
Increasing the timeout to 30 seconds seems to be enough. I do not want to make it too big because the timeout is currently not configurable.
The observation seems to be correct; at least according to log file http://sssd-ci.duckdns.org/logs/job/23/21/rhel7/ci-build-debug/pam-srv-tests...
There is a 3.5 seconds delays between creating child handler and 1st message in child. (Mon Aug 17 10:50:35:304490 2015) [sssd] [child_handler_setup] (0x2000): Setting up signal handler up for pid [30764] (Mon Aug 17 10:50:35:305471 2015) [sssd] [child_handler_setup] (0x2000): Signal handler set up for pid [30764] (Mon Aug 17 10:50:35:306615 2015) [sssd] [pam_initgr_cache_remove] (0x2000): [pamuser] removed from PAM initgroup cache (Mon Aug 17 10:50:35:307109 2015) [sssd] [pam_initgr_cache_remove] (0x2000): [wronguser] removed from PAM initgroup cache (Mon Aug 17 10:50:38:972629 2015) [[sssd[p11_child[30764]]]] [main] (0x0400): p11_child started.
And another 5 seconds between starting real work in the child (Mon Aug 17 10:50:39:091652 2015) [[sssd[p11_child[30764]]]] [main] (0x0020): setuid failed: 1, p11_child might not work! (Mon Aug 17 10:50:39:093917 2015) [[sssd[p11_child[30764]]]] [main] (0x0020): setgid failed: 1, p11_child might not work! (Mon Aug 17 10:50:39:094746 2015) [[sssd[p11_child[30764]]]] [main] (0x2000): Running with real IDs [499][499]. (Mon Aug 17 10:50:44:375594 2015) [[sssd[p11_child[30764]]]] [do_work] (0x4000): Default Module List:
It might be caused either by valgrind or by high load on machine. IMHO changing default from 10 seconds to 30 is too much.
We can use the same trick in dyndns_test dyndns_tests_CFLAGS = \ $(AM_CFLAGS) \ -DDYNDNS_TIMEOUT=2
and in pamsrv_cmd.c use conditional default value. #ifndef SSS_P11_CHILD_TIMEOUT # define SSS_P11_CHILD_TIMEOUT 30 #endif
I'd like to talk to Sumit about what he thinks the proper solution should be. I am not sure if it times out because we do something unnecessary in p11 child.
See the simple patch.
LS
Thank you for comments. I pushed the newly attached patch to CI (5 times, essential tests only, with disabled be_req tests). To see if it fails. I am waiting for the results now.
I'm definitelly sure it will work. I tested first version with hardcoded 30 seconds and it passed more then 25 runs :-)
BTW it would be good to find out what is a reason so big (3-5 seconds) timeouts.
From 9b218d50bcfb31bbb8167ea9b02711de9a6de14b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Michal=20=C5=BDidek?= mzidek@redhat.com Date: Thu, 13 Aug 2015 14:03:24 +0200 Subject: [PATCH] pam: Incerease p11 child timeout
Ticket: https://fedorahosted.org/sssd/ticket/2746
It was timeouting often in CI machines.
ACK
LS
On Mon, Aug 17, 2015 at 03:03:35PM +0200, Lukas Slebodnik wrote:
On (17/08/15 14:45), Michal Židek wrote:
On 08/17/2015 01:22 PM, Lukas Slebodnik wrote:
On (14/08/15 14:40), Michal Židek wrote:
Hi,
this patch is a hotfix for pam-srv-failing tests.
Increasing the timeout to 30 seconds seems to be enough. I do not want to make it too big because the timeout is currently not configurable.
The observation seems to be correct; at least according to log file http://sssd-ci.duckdns.org/logs/job/23/21/rhel7/ci-build-debug/pam-srv-tests...
There is a 3.5 seconds delays between creating child handler and 1st message in child. (Mon Aug 17 10:50:35:304490 2015) [sssd] [child_handler_setup] (0x2000): Setting up signal handler up for pid [30764] (Mon Aug 17 10:50:35:305471 2015) [sssd] [child_handler_setup] (0x2000): Signal handler set up for pid [30764] (Mon Aug 17 10:50:35:306615 2015) [sssd] [pam_initgr_cache_remove] (0x2000): [pamuser] removed from PAM initgroup cache (Mon Aug 17 10:50:35:307109 2015) [sssd] [pam_initgr_cache_remove] (0x2000): [wronguser] removed from PAM initgroup cache (Mon Aug 17 10:50:38:972629 2015) [[sssd[p11_child[30764]]]] [main] (0x0400): p11_child started.
And another 5 seconds between starting real work in the child (Mon Aug 17 10:50:39:091652 2015) [[sssd[p11_child[30764]]]] [main] (0x0020): setuid failed: 1, p11_child might not work! (Mon Aug 17 10:50:39:093917 2015) [[sssd[p11_child[30764]]]] [main] (0x0020): setgid failed: 1, p11_child might not work! (Mon Aug 17 10:50:39:094746 2015) [[sssd[p11_child[30764]]]] [main] (0x2000): Running with real IDs [499][499]. (Mon Aug 17 10:50:44:375594 2015) [[sssd[p11_child[30764]]]] [do_work] (0x4000): Default Module List:
It might be caused either by valgrind or by high load on machine. IMHO changing default from 10 seconds to 30 is too much.
We can use the same trick in dyndns_test dyndns_tests_CFLAGS = \ $(AM_CFLAGS) \ -DDYNDNS_TIMEOUT=2
and in pamsrv_cmd.c use conditional default value. #ifndef SSS_P11_CHILD_TIMEOUT # define SSS_P11_CHILD_TIMEOUT 30 #endif
I'd like to talk to Sumit about what he thinks the proper solution should be. I am not sure if it times out because we do something unnecessary in p11 child.
See the simple patch.
LS
Thank you for comments. I pushed the newly attached patch to CI (5 times, essential tests only, with disabled be_req tests). To see if it fails. I am waiting for the results now.
I'm definitelly sure it will work. I tested first version with hardcoded 30 seconds and it passed more then 25 runs :-)
BTW it would be good to find out what is a reason so big (3-5 seconds) timeouts.
From 9b218d50bcfb31bbb8167ea9b02711de9a6de14b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Michal=20=C5=BDidek?= mzidek@redhat.com Date: Thu, 13 Aug 2015 14:03:24 +0200 Subject: [PATCH] pam: Incerease p11 child timeout
Ticket: https://fedorahosted.org/sssd/ticket/2746
It was timeouting often in CI machines.
ACK
* master: 9da121c08b785b56733a11fa46e14c708dda62e9
On Fri, Aug 14, 2015 at 02:40:45PM +0200, Michal Židek wrote:
Hi,
this patch is a hotfix for pam-srv-failing tests.
Increasing the timeout to 30 seconds seems to be enough. I do not want to make it too big because the timeout is currently not configurable.
I'd like to talk to Sumit about what he thinks the proper solution should be. I am not sure if it times out because we do something unnecessary in p11 child.
Hi Michal,
thank you for taking care of it. I think it would be best to make the timeout configurable. The NSS smart card operations are slow in general even when using certificates on the disk and not talking to hardware readers.
Would you like to create a trac ticket for this or shall I?
bye, Sumit
See the simple patch.
Michal
On 08/28/2015 10:29 AM, Sumit Bose wrote:
On Fri, Aug 14, 2015 at 02:40:45PM +0200, Michal Židek wrote:
Hi,
this patch is a hotfix for pam-srv-failing tests.
Increasing the timeout to 30 seconds seems to be enough. I do not want to make it too big because the timeout is currently not configurable.
I'd like to talk to Sumit about what he thinks the proper solution should be. I am not sure if it times out because we do something unnecessary in p11 child.
Hi Michal,
thank you for taking care of it. I think it would be best to make the timeout configurable. The NSS smart card operations are slow in general even when using certificates on the disk and not talking to hardware readers.
Would you like to create a trac ticket for this or shall I?
I will create it. Thanks for your opinion.
Michal
bye, Sumit
See the simple patch.
Michal
sssd-devel mailing list sssd-devel@lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/sssd-devel
sssd-devel@lists.fedorahosted.org