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 708009 - "renew_all_tgts" and "renew_handlers" messages are being logged multiple times when the provider comes back online.
Summary: "renew_all_tgts" and "renew_handlers" messages are being logged multiple time...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: sssd
Version: 6.2
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: rc
: ---
Assignee: Stephen Gallagher
QA Contact: Chandrasekar Kannan
URL:
Whiteboard:
Depends On:
Blocks: 708104
TreeView+ depends on / blocked
 
Reported: 2011-05-26 14:33 UTC by Kaushik Banerjee
Modified: 2020-05-02 16:20 UTC (History)
6 users (show)

Fixed In Version: sssd-1.5.1-39.el6
Doc Type: Bug Fix
Doc Text:
Cause: The Kerberos ticket renewal timer tasks were issued every time a back end detected it was online Consequence: Bigger load on KDC servers and potentially confusing log messages Fix: The code that starts the renewal tasks was fixed to only issue them as configured Result: The ticket renewal tasks are only issued as per the krb5_renew_interval parameter
Clone Of:
: 708104 (view as bug list)
Environment:
Last Closed: 2011-12-06 16:38:37 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github SSSD sssd issues 1924 0 None None None 2020-05-02 16:20:10 UTC
Red Hat Product Errata RHBA-2011:1529 0 normal SHIPPED_LIVE sssd bug fix and enhancement update 2011-12-06 00:50:20 UTC

Description Kaushik Banerjee 2011-05-26 14:33:41 UTC 
Description of problem:
Multiple "renew_all_tgts" and "renew_handlers" are being called as seen from sssd_DOMAIN.log.

Version-Release number of selected component (if applicable):
sssd-1.5.1-34.el6

How reproducible:
Occasionally

Steps to Reproduce:
1. Configure sssd as shown in the Additional Info section.
2. Auth as puser1:
# ssh -l puser1 localhost
puser1@localhost's password: 
Last login: Thu May 26 10:31:13 2011 from localhost
Could not chdir to home directory /export/puser1: No such file or directory
-sh-4.1$ 

3. TGT renewals happen appropriately as per /var/log/sssd/sssd_default.log
4. Now, stop KDC.
5. Wait till the backend goes offline.
6. Run the command "gentent -s sss passwd kau1" (kau1 user doesn't exist in cache)
7. Start the KDC.
8. Run the command "gentent -s sss passwd kau1" or Auth as puser1.
9. The line "[renew_all_tgts] (9): Checking [FILE:/tmp/krb5_cache/krb5cc_puser1] for renewal at" keeps coming multiple times at the same instance of time.

<snip>
(Thu May 26 12:09:16 2011) [sssd[be[default]]] [safe_remove_old_ccache_file] (7): New and old ccache file are the same, no one will be deleted.
(Thu May 26 12:09:16 2011) [sssd[be[default]]] [krb5_save_ccname] (9): Save ccname [FILE:/tmp/krb5_cache/krb5cc_puser1] for user [puser1].
(Thu May 26 12:09:16 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Thu May 26 12:09:16 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 1)
(Thu May 26 12:09:16 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x8bd8340

(Thu May 26 12:09:16 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x8be3b10

(Thu May 26 12:09:16 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x8be3b10 "ltdb_timeout"

(Thu May 26 12:09:16 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x8bd8340 "ltdb_callback"

(Thu May 26 12:09:16 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 1)
(Thu May 26 12:09:16 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Thu May 26 12:09:16 2011) [sssd[be[default]]] [krb5_child_done] (7): Adding [FILE:/tmp/krb5_cache/krb5cc_puser1] for automatic renewal.
(Thu May 26 12:09:16 2011) [sssd[be[default]]] [add_tgt_to_renew_table] (7): Added [FILE:/tmp/krb5_cache/krb5cc_puser1] for renewal at [Thu May 26 12:11:13 2011].
(Thu May 26 12:09:16 2011) [sssd[be[default]]] [renew_tgt_done] (4): Successfully renewed TGT for user [puser1].
(Thu May 26 12:09:16 2011) [sssd[be[default]]] [child_sig_handler] (7): Waiting for child [22518].
(Thu May 26 12:09:16 2011) [sssd[be[default]]] [child_sig_handler] (4): child [22518] finished successfully.
(Thu May 26 12:09:25 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 8BCC550
(Thu May 26 12:09:25 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Thu May 26 12:09:25 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [ping]
(Thu May 26 12:09:26 2011) [sssd[be[default]]] [renew_all_tgts] (9): Checking [FILE:/tmp/krb5_cache/krb5cc_puser1] for renewal at [Thu May 26 12:11:13 2011].
(Thu May 26 12:09:26 2011) [sssd[be[default]]] [renew_handler] (7): Adding new renew timer.
(Thu May 26 12:09:26 2011) [sssd[be[default]]] [renew_all_tgts] (9): Checking [FILE:/tmp/krb5_cache/krb5cc_puser1] for renewal at [Thu May 26 12:11:13 2011].
(Thu May 26 12:09:26 2011) [sssd[be[default]]] [renew_handler] (7): Adding new renew timer.
(Thu May 26 12:09:35 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 8BCC550
(Thu May 26 12:09:35 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Thu May 26 12:09:35 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [ping]
(Thu May 26 12:09:37 2011) [sssd[be[default]]] [renew_all_tgts] (9): Checking [FILE:/tmp/krb5_cache/krb5cc_puser1] for renewal at [Thu May 26 12:11:13 2011].
(Thu May 26 12:09:37 2011) [sssd[be[default]]] [renew_handler] (7): Adding new renew timer.
(Thu May 26 12:09:37 2011) [sssd[be[default]]] [renew_all_tgts] (9): Checking [FILE:/tmp/krb5_cache/krb5cc_puser1] for renewal at [Thu May 26 12:11:13 2011].
(Thu May 26 12:09:37 2011) [sssd[be[default]]] [renew_handler] (7): Adding new renew timer.
(Thu May 26 12:09:45 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 8BCC550
(Thu May 26 12:09:45 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Thu May 26 12:09:45 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [ping]
(Thu May 26 12:09:48 2011) [sssd[be[default]]] [renew_all_tgts] (9): Checking [FILE:/tmp/krb5_cache/krb5cc_puser1] for renewal at [Thu May 26 12:11:13 2011].
(Thu May 26 12:09:48 2011) [sssd[be[default]]] [renew_handler] (7): Adding new renew timer.
(Thu May 26 12:09:48 2011) [sssd[be[default]]] [renew_all_tgts] (9): Checking [FILE:/tmp/krb5_cache/krb5cc_puser1] for renewal at [Thu May 26 12:11:13 2011].
(Thu May 26 12:09:48 2011) [sssd[be[default]]] [renew_handler] (7): Adding new renew timer.
(Thu May 26 12:09:55 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 8BCC550
(Thu May 26 12:09:55 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Thu May 26 12:09:55 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [ping]
(Thu May 26 12:09:59 2011) [sssd[be[default]]] [renew_all_tgts] (9): Checking [FILE:/tmp/krb5_cache/krb5cc_puser1] for renewal at [Thu May 26 12:11:13 2011].
(Thu May 26 12:09:59 2011) [sssd[be[default]]] [renew_handler] (7): Adding new renew timer.
(Thu May 26 12:09:59 2011) [sssd[be[default]]] [renew_all_tgts] (9): Checking [FILE:/tmp/krb5_cache/krb5cc_puser1] for renewal at [Thu May 26 12:11:13 2011].
(Thu May 26 12:09:59 2011) [sssd[be[default]]] [renew_handler] (7): Adding new renew timer.
</snip>

Actual results:
Multiple "renew_handler" & "renew_all_tgts" are being called at the same instance of time as seen in the logs.

Expected results:
Multiple "renew_handler" & "renew_all_tgts" shouldn't be called.

Additional info:
1. # cat /etc/sssd/sssd.conf
[sssd]
config_file_version = 2
reconnection_retries = 3
sbus_timeout = 30
services = nss, pam
domains = default

[nss]
filter_groups = root
filter_users = root
reconnection_retries = 3
debug_level = 9

[pam]
reconnection_retries = 3

[domain/default]
debug_level = 9
id_provider = ldap
ldap_uri = ldap://<LDAP SERVER>
ldap_search_base = dc=example,dc=com
auth_provider = krb5
krb5_server = <KDC>
krb5_realm = EXAMPLE.COM
krb5_lifetime = 120
krb5_renew_interval = 10
krb5_renewable_lifetime = 150m
krb5_ccname_template = FILE:%d/krb5cc_%u
krb5_ccachedir = /tmp/krb5_cache
Comment 5 Kaushik Banerjee 2011-09-27 16:53:16 UTC 
Steps to verify:

1. Configure sssd for auto renewal and start sssd.
2. Login as a user to get a renewable ticket.
3. Stop KDC.
4. Wait for provider to go offline.
5. Start KDC.
6. Check log for "[renew_all_tgts] (9): Checking [FILE:/tmp/krb5cc_XXXX_XXXXX] for renewal at [Tue Sep 27 22:18:40 2011]" messages.

Repeat steps 2-6 for about 3 cycles.

"renew_all_tgts" and "renew_handler" messages no longer appear multiple times.

Verified in version:
# rpm -qi sssd | head
Name        : sssd                         Relocations: (not relocatable)
Version     : 1.5.1                             Vendor: Red Hat, Inc.
Release     : 52.el6                        Build Date: Tue 20 Sep 2011 09:11:03 PM IST
Install Date: Mon 26 Sep 2011 05:56:30 PM IST      Build Host: x86-010.build.bos.redhat.com
Group       : Applications/System           Source RPM: sssd-1.5.1-52.el6.src.rpm
Size        : 3550647                          License: GPLv3+
Signature   : (none)
Packager    : Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>
URL         : http://fedorahosted.org/sssd/
Summary     : System Security Services Daemon
Comment 6 Jakub Hrozek 2011-10-26 16:48:29 UTC 
    Technical note added. If any revisions are required, please edit the "Technical Notes" field
    accordingly. All revisions will be proofread by the Engineering Content Services team.
    
    New Contents:
Cause: The Kerberos ticket renewal timer tasks were issued every time a back end detected it was online
Consequence: Bigger load on KDC servers and potentially confusing log messages
Fix: The code that starts the renewal tasks was fixed to only issue them as configured
Result: The ticket renewal tasks are only issued as per the krb5_renew_interval parameter
Comment 7 errata-xmlrpc 2011-12-06 16:38:37 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.

http://rhn.redhat.com/errata/RHBA-2011-1529.html
Note You need to log in before you can comment on or make changes to this bug.