Bug 1369079

Summary: sssd runs out of available child slots and starts queuing requests in proxy mode
Product: Red Hat Enterprise Linux 6 Reporter: Thorsten Scherf <tscherf>
Component: sssdAssignee: Petr Čech <pcech>
Status: CLOSED ERRATA QA Contact: Steeve Goveas <sgoveas>
Severity: high Docs Contact:
Priority: high    
Version: 6.8CC: apeetham, grajaiya, jhrozek, lslebodn, mkosek, mzidek, pbrezina, pcech, sgoveas
Target Milestone: rc   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: sssd-1.13.3-30.el6 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: 1368467 Environment:
Last Closed: 2017-03-21 09:57:36 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Bug Depends On: 1368467    
Bug Blocks:    

Description Thorsten Scherf 2016-08-22 12:48:13 UTC 
+++ This bug was initially created as a clone of Bug #1368467 +++

Description of problem:

Authentication in proxy mode fails under heavy load 

(Thu Aug 18 11:09:25 2016) [sssd[be[indis]]] [be_pam_handler] (4): Got request with the following data
(Thu Aug 18 11:09:25 2016) [sssd[be[indis]]] [pam_print_data] (4): command: PAM_AUTHENTICATE
(Thu Aug 18 11:09:25 2016) [sssd[be[indis]]] [pam_print_data] (4): domain: indis
(Thu Aug 18 11:09:25 2016) [sssd[be[indis]]] [pam_print_data] (4): user: APPUSER
(Thu Aug 18 11:09:25 2016) [sssd[be[indis]]] [pam_print_data] (4): service: vsftpd_nas
(Thu Aug 18 11:09:25 2016) [sssd[be[indis]]] [pam_print_data] (4): tty: ftp
(Thu Aug 18 11:09:25 2016) [sssd[be[indis]]] [pam_print_data] (4): ruser: APPUSER
(Thu Aug 18 11:09:25 2016) [sssd[be[indis]]] [pam_print_data] (4): rhost: nastf2.testfactory.copergmps
(Thu Aug 18 11:09:25 2016) [sssd[be[indis]]] [pam_print_data] (4): authtok type: 1
(Thu Aug 18 11:09:25 2016) [sssd[be[indis]]] [pam_print_data] (4): authtok size: 7
(Thu Aug 18 11:09:25 2016) [sssd[be[indis]]] [pam_print_data] (4): newauthtok type: 0
(Thu Aug 18 11:09:25 2016) [sssd[be[indis]]] [pam_print_data] (4): newauthtok size: 0
(Thu Aug 18 11:09:25 2016) [sssd[be[indis]]] [pam_print_data] (4): priv: 0
(Thu Aug 18 11:09:25 2016) [sssd[be[indis]]] [pam_print_data] (4): cli_pid: 27026
(Thu Aug 18 11:09:25 2016) [sssd[be[indis]]] [proxy_child_send] (8): Queueing request [19]
(Thu Aug 18 11:09:25 2016) [sssd[be[indis]]] [proxy_child_send] (8): All available child slots are full, queuing request

The request is turn the hardcoded number of preforked childs into a config option.

$ grep -B1  max_children src/providers/proxy/proxy_init.c
    /* Set up request hash table */
    /* FIXME: get max_children from configuration file */
    auth_ctx->max_children = 10;

Version-Release number of selected component (if applicable):

verified on RHEL-5.11, but some code also exists in master.


How reproducible:

for I in $(seq 1 350); do 
	lftp -e 'ls; quit' ftp://FTP-SERVER -u LDAP-USER,LDAP-USER-KRB5-PASS 1>/dev/null & 
done

while pidof lftp >/dev/null; do
	echo -n '.'
	sleep 1
done
echo 


Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:


Additional info:
Comment 1 Jakub Hrozek 2016-08-22 14:39:41 UTC 
Upstream ticket:
https://fedorahosted.org/sssd/ticket/3153
Comment 3 Lukas Slebodnik 2016-09-14 10:50:05 UTC 
sssd-1-13:
* 90c62a1b4bac450712bc5a194b793761329a1d3a
Comment 5 Amith 2016-12-19 19:32:00 UTC 
Verified the bug on SSSD Version : sssd-1.13.3-54.el6.i686

Steps followed during verification:

1. Setup a server with over 350 ldap users.

2. Setup SSSD client as proxy provider.

3. Set proxy_max_children to a lower value to reproduce the issue. Start with proxy_max_children = 1

4. Execute user authentication in a loop, to simulate high load.

for ((i=1 ; i<=350 ; i++))
do
export USER=testuser$i
expect -f  - <<<'
    spawn ssh -o StrictHostKeyChecking=no -l $env(USER) localhost
    set timeout -1
    expect "*assword:"
    send -- "Secret123\r"
    expect "*$ "
    send -- "ls\r"
    expect "*$ "
    send -- "logout\r"
    expect eof
'
done

5. Execute the above from different terminals at the same time.

6. Monitor /var/log/sssd/sssd_PROXY.log file for error:

[sssd[be[PROXY]]] [proxy_child_send] (0x2000): All available child slots are full, queuing request

7. Increment the value of proxy_max_children and repeat the tests.


I reproduced the issue when proxy_max_children set from 1 to 6:

# grep slot sssd_PROXY.log
(Mon Dec 19 13:42:35 2016) [sssd[be[PROXY]]] [proxy_child_send] (0x2000): All available child slots are full, queuing request
(Mon Dec 19 13:42:40 2016) [sssd[be[PROXY]]] [proxy_child_send] (0x2000): All available child slots are full, queuing request
(Mon Dec 19 13:43:05 2016) [sssd[be[PROXY]]] [proxy_child_send] (0x2000): All available child slots are full, queuing request
(Mon Dec 19 13:43:10 2016) [sssd[be[PROXY]]] [proxy_child_send] (0x2000): All available child slots are full, queuing request
(Mon Dec 19 13:43:10 2016) [sssd[be[PROXY]]] [proxy_child_send] (0x2000): All available child slots are full, queuing request
(Mon Dec 19 13:43:15 2016) [sssd[be[PROXY]]] [proxy_child_send] (0x2000): All available child slots are full, queuing request
(Mon Dec 19 13:43:15 2016) [sssd[be[PROXY]]] [proxy_child_send] (0x2000): All available child slots are full, queuing request
(Mon Dec 19 13:43:20 2016) [sssd[be[PROXY]]] [proxy_child_send] (0x2000): All available child slots are full, queuing request
(Mon Dec 19 13:43:20 2016) [sssd[be[PROXY]]] [proxy_child_send] (0x2000): All available child slots are full, queuing request
(Mon Dec 19 13:43:25 2016) [sssd[be[PROXY]]] [proxy_child_send] (0x2000): All available child slots are full, queuing request
(Mon Dec 19 13:43:25 2016) [sssd[be[PROXY]]] [proxy_child_send] (0x2000): All available child slots are full, queuing request
(Mon Dec 19 13:43:29 2016) [sssd[be[PROXY]]] [proxy_child_send] (0x2000): All available child slots are full, queuing request

But the errors disappeared when proxy_max_children set to 10.
Comment 7 errata-xmlrpc 2017-03-21 09:57:36 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHBA-2017-0632.html