647816 – Login screen freezes for more than 2mins when configured SSSD for proxy auth.

RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.

Bug 647816 - Login screen freezes for more than 2mins when configured SSSD for proxy auth.

Summary: Login screen freezes for more than 2mins when configured SSSD for proxy auth.

Keywords:
Status:	CLOSED ERRATA
Alias:	None
Product:	Red Hat Enterprise Linux 6
Classification:	Red Hat
Component:	sssd
Sub Component:
Version:	6.0
Hardware:	Unspecified
OS:	Unspecified
Priority:	low
Severity:	medium
Target Milestone:	rc
Target Release:	---
Assignee:	Stephen Gallagher
QA Contact:	Chandrasekar Kannan
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:	579778
TreeView+	depends on / blocked

Reported:	2010-10-29 15:13 UTC by Gowrishankar Rajaiyan
Modified:	2020-05-02 16:16 UTC (History)
CC List:	4 users (show)
Fixed In Version:	sssd-1.5.0-1.el6
Doc Type:	Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:	2011-05-19 11:41:51 UTC
Target Upstream Version:
Embargoed:

Attachments	(Terms of Use)
sssd_PROXYLDAP.log.tgz (190.51 KB, application/x-gzip) 2010-10-29 20:04 UTC, Gowrishankar Rajaiyan	no flags	Details
View All

Links
System	ID	Private	Priority	Status	Summary	Last Updated
Github	SSSD sssd issues 1702	0	None	closed	Login screen freezes for more than 2mins when configured SSSD for proxy auth	2020-12-16 01:10:47 UTC
Red Hat Product Errata	RHSA-2011:0560	0	normal	SHIPPED_LIVE	Low: sssd security, bug fix, and enhancement update	2011-05-19 11:38:17 UTC

Description Gowrishankar Rajaiyan 2010-10-29 15:13:14 UTC

Description of problem:
The gnome-screensaver freezes for more than 2 minutes when configured SSSD for proxy id and auth.

Version-Release number of selected component (if applicable):
sssd-1.2.1-28.el6_0.1.x86_64

How reproducible:


Steps to Reproduce:
1. Configure SSSD for proxy provider and auth.
2. Login to the system using GDM.
3. Go to System | Preferences | About me
4. Change your password.
5. Lock screen.
6. Try incorrect or blank passwords for multiple times.
7. Wait for few minutes (~5 mins)
8. Now try to unlock the screen with correct/incorrect password.
  
Actual results:
gnome-screensaver-dialog freezes at 'checking...' for more than 2 mins.

Work-around: restart SSSD service.

Expected results:
Should not freeze and return "Incorrect password" immediately after the password validation.

Additional info:

Relevant sssd.conf:
[domain/PROXYLDAP]
id_provider = proxy
proxy_lib_name = ldap
proxy_pam_target = sssdproxyldap
debug_level = 9
debug_to_files = true
auth_provider = proxy
cache_credentials = True
enumerate = true

/var/log/sssd/sssd_PROXYLDAP:
(Fri Oct 29 20:29:28 2010) [sssd[be[PROXYLDAP]]] [sbus_dispatch] (9): dbus conn: 2129590
(Fri Oct 29 20:29:28 2010) [sssd[be[PROXYLDAP]]] [sbus_dispatch] (9): Dispatching.
(Fri Oct 29 20:29:28 2010) [sssd[be[PROXYLDAP]]] [sbus_message_handler] (9): Received SBUS method [ping]
(Fri Oct 29 20:29:35 2010) [sssd[be[PROXYLDAP]]] [sbus_dispatch] (9): dbus conn: 212C500
(Fri Oct 29 20:29:35 2010) [sssd[be[PROXYLDAP]]] [sbus_dispatch] (9): Dispatching.
(Fri Oct 29 20:29:35 2010) [sssd[be[PROXYLDAP]]] [sbus_message_handler] (9): Received SBUS method [getAccountInfo]
(Fri Oct 29 20:29:35 2010) [sssd[be[PROXYLDAP]]] [be_get_account_info] (4): Got request for [3][1][name=puser1]
(Fri Oct 29 20:29:35 2010) [sssd[be[PROXYLDAP]]] [ldb] (9): start ldb transaction (nesting: 0)
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [get_initgr_groups_process] (2): proxy -> initgroups_dyn failed (0)[Success]
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [ldb] (9): cancel ldb transaction (nesting: 0)
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [acctinfo_callback] (4): Request processed. Returned 3,5,Internal Error (Input/output error)
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [sbus_dispatch] (9): dbus conn: 212C500
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [sbus_dispatch] (9): Dispatching.
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [sbus_message_handler] (9): Received SBUS method [pamHandler]
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [be_pam_handler] (4): Got request with the following data
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [pam_print_data] (4): command: PAM_AUTHENTICATE
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [pam_print_data] (4): domain: PROXYLDAP
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [pam_print_data] (4): user: puser1
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [pam_print_data] (4): service: gnome-screensaver
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [pam_print_data] (4): tty: :0.0
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [pam_print_data] (4): ruser: 
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [pam_print_data] (4): rhost: 
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [pam_print_data] (4): authtok type: 1
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [pam_print_data] (4): authtok size: 10
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [pam_print_data] (4): newauthtok type: 0
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [pam_print_data] (4): newauthtok size: 0
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [pam_print_data] (4): priv: 0
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [pam_print_data] (4): cli_pid: 4274
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [proxy_child_send] (8): Queueing request [14]
(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [proxy_child_send] (8): All available child slots are full, queuing request
(Fri Oct 29 20:29:38 2010) [sssd[be[PROXYLDAP]]] [sbus_dispatch] (9): dbus conn: 2129590
(Fri Oct 29 20:29:38 2010) [sssd[be[PROXYLDAP]]] [sbus_dispatch] (9): Dispatching.
(Fri Oct 29 20:29:38 2010) [sssd[be[PROXYLDAP]]] [sbus_message_handler] (9): Received SBUS method [ping]

Comment 2 Stephen Gallagher 2010-10-29 15:33:40 UTC

Please gzip and attach the complete log for this domain.

(Fri Oct 29 20:29:36 2010) [sssd[be[PROXYLDAP]]] [proxy_child_send] (8): All
available child slots are full, queuing request

This shouldn't happen unless you have a lot of other auth requests waiting to be processed (or stuck somehow). I need to see a longer history to figure out why that happened.

Comment 3 Gowrishankar Rajaiyan 2010-10-29 20:04:33 UTC

Created attachment 456551 [details]
sssd_PROXYLDAP.log.tgz

Comment 4 Dmitri Pal 2010-10-29 22:31:43 UTC

https://fedorahosted.org/sssd/ticket/660

Comment 6 Gowrishankar Rajaiyan 2011-03-22 07:39:38 UTC

Method:
1. Set up proxy auth 
2. Perform more than 12 auth attempts (successful or not doesn't matter)

Result: No more timeouts seen, as expected.


relevant sssd.conf:
[domain/default]
id_provider = proxy
auth_provider = proxy
proxy_lib_name = ldap
proxy_pam_target = sssdproxyldap
debug_level = 9
cache_credentials = true
enumerate = true


/var/log/sssd/sssd_domain.log:
(Tue Mar 22 13:04:12 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: F95F10
(Tue Mar 22 13:04:12 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue Mar 22 13:04:12 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [getAccountInfo]
(Tue Mar 22 13:04:12 2011) [sssd[be[default]]] [be_get_account_info] (4): Got request for [3][1][name=puser1]
(Tue Mar 22 13:04:12 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue Mar 22 13:04:12 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 1)
(Tue Mar 22 13:04:12 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0xfdfc90

(Tue Mar 22 13:04:12 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x100acc0

(Tue Mar 22 13:04:12 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x100acc0 "ltdb_timeout"

(Tue Mar 22 13:04:12 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0xfdfc90 "ltdb_callback"

(Tue Mar 22 13:04:12 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 2)
(Tue Mar 22 13:04:12 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x1012770

(Tue Mar 22 13:04:12 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x1012890

(Tue Mar 22 13:04:12 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x1012890 "ltdb_timeout"

(Tue Mar 22 13:04:12 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x1012770 "ltdb_callback"

(Tue Mar 22 13:04:12 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 2)
(Tue Mar 22 13:04:12 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 1)
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [get_initgr_groups_process] (2): proxy -> initgroups_dyn failed (5)[Input/output error]
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 0)
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [acctinfo_callback] (4): Request processed. Returned 3,5,Internal Error (Memory buffer error)
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: F95F10
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [pamHandler]
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [be_pam_handler] (4): Got request with the following data
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): command: PAM_AUTHENTICATE
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): domain: default
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): user: puser1
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): service: gnome-screensaver
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): tty: :0.0
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): ruser: 
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): rhost: 
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): authtok type: 1
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): authtok size: 6
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok type: 0
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok size: 0
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): priv: 0
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): cli_pid: 1673
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [proxy_child_send] (8): Queueing request [37]
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [proxy_child_init_send] (7): Starting proxy child with args [/usr/libexec/sssd/proxy_child -d 9 --debug-to-files --domain default --id 37]
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [sbus_server_init_new_connection] (5): Entering.
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [sbus_server_init_new_connection] (5): Adding connection 0x100ac00.
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [sbus_init_connection] (5): Adding connection 100AC00
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [sbus_add_watch] (8): 0x100b0d0/0xff9f90 (26), -/W (disabled)
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [sbus_toggle_watch] (8): 0x100b0d0/0xfbe4c0 (26), R/- (enabled)
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [sbus_server_init_new_connection] (5): Got a connection
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [proxy_client_init] (4): Set-up proxy client ID timeout [0x10113b0]
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 100AC00
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [sbus_toggle_watch] (8): 0x100b0d0/0xfbe4c0 (26), R/- (disabled)
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [sbus_toggle_watch] (8): 0x100b0d0/0xff9f90 (26), -/W (enabled)
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [sbus_toggle_watch] (8): 0x100b0d0/0xfbe4c0 (26), R/- (enabled)
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [sbus_toggle_watch] (8): 0x100b0d0/0xff9f90 (26), -/W (disabled)
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 100AC00
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [RegisterService]
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [client_registration] (4): Cancel proxy client ID timeout [0x10113b0]
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [client_registration] (4): Proxy client [37] connected
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [proxy_pam_conv_send] (4): Sending request with the following data:
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): command: PAM_AUTHENTICATE
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): domain: default
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): user: puser1
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): service: gnome-screensaver
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): tty: :0.0
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): ruser: 
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): rhost: 
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): authtok type: 1
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): authtok size: 6
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok type: 0
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok size: 0
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): priv: 0
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [pam_print_data] (4): cli_pid: 1673
(Tue Mar 22 13:04:13 2011) [sssd[be[default]]] [sbus_add_timeout] (8): 0x100fa80
(Tue Mar 22 13:04:14 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: F92EF0
(Tue Mar 22 13:04:14 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue Mar 22 13:04:14 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [ping]
(Tue Mar 22 13:04:15 2011) [sssd[be[default]]] [sbus_remove_timeout] (8): 0x100fa80
(Tue Mar 22 13:04:15 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 100AC00
(Tue Mar 22 13:04:15 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue Mar 22 13:04:15 2011) [sssd[be[default]]] [proxy_pam_conv_reply] (8): Handling pam conversation reply
(Tue Mar 22 13:04:15 2011) [sssd[be[default]]] [proxy_pam_conv_reply] (4): received: [7][default]
(Tue Mar 22 13:04:15 2011) [sssd[be[default]]] [proxy_child_destructor] (8): Removing proxy child id [37]
(Tue Mar 22 13:04:15 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Backend returned: (0, 0, <NULL>) [Success]
(Tue Mar 22 13:04:15 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sending result [7][default]
(Tue Mar 22 13:04:15 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sent result [7][default]
(Tue Mar 22 13:04:15 2011) [sssd[be[default]]] [sbus_remove_watch] (8): 0x100b0d0/0xfbe4c0
(Tue Mar 22 13:04:15 2011) [sssd[be[default]]] [sbus_remove_watch] (8): 0x100b0d0/0xff9f90
(Tue Mar 22 13:04:15 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 100AC00
(Tue Mar 22 13:04:15 2011) [sssd[be[default]]] [sbus_dispatch] (3): Connection is not open for dispatching.
(Tue Mar 22 13:04:15 2011) [sssd[be[default]]] [proxy_child_sig_handler] (7): Waiting for child [1687].
(Tue Mar 22 13:04:15 2011) [sssd[be[default]]] [proxy_child_sig_handler] (4): child [1687] was terminated by signal [9].
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: F95F10
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [getAccountInfo]
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [be_get_account_info] (4): Got request for [3][1][name=puser1]
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 1)
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x100b170

(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x100b220

(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x100b220 "ltdb_timeout"

(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x100b170 "ltdb_callback"

(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 2)
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x10149c0

(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x1014ae0

(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x1014ae0 "ltdb_timeout"

(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x10149c0 "ltdb_callback"

(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 2)
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 1)
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [get_initgr_groups_process] (2): proxy -> initgroups_dyn failed (5)[Input/output error]
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 0)
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [acctinfo_callback] (4): Request processed. Returned 3,5,Internal Error (Memory buffer error)
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: F95F10
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [pamHandler]
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [be_pam_handler] (4): Got request with the following data
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): command: PAM_AUTHENTICATE
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): domain: default
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): user: puser1
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): service: gnome-screensaver
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): tty: :0.0
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): ruser: 
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): rhost: 
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): authtok type: 1
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): authtok size: 11
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok type: 0
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok size: 0
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): priv: 0
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): cli_pid: 1673
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [proxy_child_send] (8): Queueing request [38]
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [proxy_child_init_send] (7): Starting proxy child with args [/usr/libexec/sssd/proxy_child -d 9 --debug-to-files --domain default --id 38]
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_server_init_new_connection] (5): Entering.
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_server_init_new_connection] (5): Adding connection 0x10161e0.
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_init_connection] (5): Adding connection 10161E0
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_add_watch] (8): 0x1011810/0x100fa30 (26), -/W (disabled)
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_toggle_watch] (8): 0x1011810/0xff3340 (26), R/- (enabled)
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_server_init_new_connection] (5): Got a connection
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [proxy_client_init] (4): Set-up proxy client ID timeout [0x1011a80]
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 10161E0
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_toggle_watch] (8): 0x1011810/0xff3340 (26), R/- (disabled)
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_toggle_watch] (8): 0x1011810/0x100fa30 (26), -/W (enabled)
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_toggle_watch] (8): 0x1011810/0xff3340 (26), R/- (enabled)
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_toggle_watch] (8): 0x1011810/0x100fa30 (26), -/W (disabled)
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 10161E0
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [RegisterService]
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [client_registration] (4): Cancel proxy client ID timeout [0x1011a80]
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [client_registration] (4): Proxy client [38] connected
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [proxy_pam_conv_send] (4): Sending request with the following data:
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): command: PAM_AUTHENTICATE
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): domain: default
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): user: puser1
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): service: gnome-screensaver
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): tty: :0.0
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): ruser: 
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): rhost: 
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): authtok type: 1
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): authtok size: 11
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok type: 0
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok size: 0
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): priv: 0
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [pam_print_data] (4): cli_pid: 1673
(Tue Mar 22 13:04:22 2011) [sssd[be[default]]] [sbus_add_timeout] (8): 0xff21e0
(Tue Mar 22 13:04:24 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: F92EF0
(Tue Mar 22 13:04:24 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue Mar 22 13:04:24 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [ping]
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [sbus_remove_timeout] (8): 0xff21e0
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 10161E0
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [proxy_pam_conv_reply] (8): Handling pam conversation reply
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [proxy_pam_conv_reply] (4): received: [0][default]
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [proxy_child_destructor] (8): Removing proxy child id [38]
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x1008450

(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x1008570

(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x1008570 "ltdb_timeout"

(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x1008450 "ltdb_callback"

(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Backend returned: (0, 0, <NULL>) [Success]
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sending result [0][default]
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sent result [0][default]
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [proxy_child_sig_handler] (7): Waiting for child [1690].
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [proxy_child_sig_handler] (4): child [1690] was terminated by signal [9].
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [sbus_remove_watch] (8): 0x1011810/0xff3340
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [sbus_remove_watch] (8): 0x1011810/0x100fa30
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 10161E0
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [sbus_dispatch] (3): Connection is not open for dispatching.
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: F95F10
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [pamHandler]
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [be_pam_handler] (4): Got request with the following data
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): command: PAM_ACCT_MGMT
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): domain: default
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): user: puser1
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): service: gnome-screensaver
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): tty: :0.0
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): ruser: 
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): rhost: 
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): authtok type: 0
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): authtok size: 0
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok type: 0
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok size: 0
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): priv: 0
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): cli_pid: 1673
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [be_target_access_permit] (9): be_target_access_permit called, returning PAM_SUCCESS.
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Backend returned: (0, 0, <NULL>) [Success]
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sending result [0][default]
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sent result [0][default]
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: F95F10
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [pamHandler]
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [be_pam_handler] (4): Got request with the following data
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): command: PAM_SETCRED
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): domain: default
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): user: puser1
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): service: gnome-screensaver
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): tty: :0.0
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): ruser: 
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): rhost: 
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): authtok type: 0
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): authtok size: 0
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok type: 0
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok size: 0
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): priv: 0
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [pam_print_data] (4): cli_pid: 1673
(Tue Mar 22 13:04:25 2011) [sssd[be[default]]] [be_pam_handler] (4): Sending result [0][default]

Comment 7 Gowrishankar Rajaiyan 2011-03-22 07:40:21 UTC

# rpm -qi sssd | head
Name        : sssd                         Relocations: (not relocatable)
Version     : 1.5.1                             Vendor: Red Hat, Inc.
Release     : 14.el6                        Build Date: Thu 10 Mar 2011 01:00:12 AM IST
Install Date: Tue 22 Mar 2011 11:38:48 AM IST      Build Host: x86-009.build.bos.redhat.com
Group       : Applications/System           Source RPM: sssd-1.5.1-14.el6.src.rpm
Size        : 3418526                          License: GPLv3+
Signature   : (none)
Packager    : Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>
URL         : http://fedorahosted.org/sssd/
Summary     : System Security Services Daemon


Verified.

Comment 8 errata-xmlrpc 2011-05-19 11:41:51 UTC

An advisory has been issued which should help the problem
described in this bug report. This report is therefore being
closed with a resolution of ERRATA. For more information
on therefore solution and/or where to find the updated files,
please follow the link below. You may reopen this bug report
if the solution does not work for you.

http://rhn.redhat.com/errata/RHSA-2011-0560.html

Comment 9 errata-xmlrpc 2011-05-19 13:08:51 UTC

An advisory has been issued which should help the problem
described in this bug report. This report is therefore being
closed with a resolution of ERRATA. For more information
on therefore solution and/or where to find the updated files,
please follow the link below. You may reopen this bug report
if the solution does not work for you.

http://rhn.redhat.com/errata/RHSA-2011-0560.html

Note You need to log in before you can comment on or make changes to this bug.