Bug 745966

Summary: sssd_pam segfaults on sssd restart
Product: Red Hat Enterprise Linux 6 Reporter: Kaushik Banerjee <kbanerje>
Component: sssdAssignee: Stephen Gallagher <sgallagh>
Status: CLOSED ERRATA QA Contact: IDM QE LIST <seceng-idm-qe-list>
Severity: unspecified Docs Contact:
Priority: high    
Version: 6.2CC: grajaiya, jgalipea, jzeleny, prc, syeghiay
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: sssd-1.5.1-57.el6 Doc Type: Bug Fix
Doc Text:
Cause: When internal communication between PAM responder and one of SSSD's backends timed out for some reason, a handling routine is invoked. That routine can cause a race condition which can result in accessing memory that has been freed. Consequence: PAM responder crashes Fix: Timeout handling routine doesn't free the context until all operations on this context are done. Result: In case the communication times out, PAM responder doesn't crash any more.
Story Points: ---
Clone Of:
: 748896 (view as bug list) Environment:
Last Closed: 2011-12-06 16:41:03 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 748554, 748896    

Description Kaushik Banerjee 2011-10-13 14:25:12 UTC
Description of problem:
sssd_pam segfaults on restarting sssd

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

How reproducible:
Intermittently

Steps to Reproduce:
1. Try to compile and run the reproducer from https://bugzilla.redhat.com/show_bug.cgi?id=725281

2. # ./check_user -n 2000 user1
Password:
Error in "pam_authenticate": Authentication failure
Authentication failure for user "user1" in loop 177

3. Restart sssd at this point.
  
Actual results:

Restarting sssd segfaults sssd_pam. syslog shows:
kernel: sssd_pam[3919]: segfault at 3032756193 ip 0000003c1ac0247d sp 00007ffff9b48528 error 4 in libtevent.so.0.9.8[3c1ac00000+9000]


Expected results:
sssd_pam should not segfault on restarting sssd.

Additional info:
Crash backtrace:

# gdb --core /var/spool/abrt/ccpp-2011-10-11-10\:28\:02-10783/coredump /usr/libexec/sssd/sssd_pam --quiet -ex "thread apply all bt full" -ex "quit"
Reading symbols from /usr/libexec/sssd/sssd_pam...Reading symbols from /usr/lib/debug/usr/libexec/sssd/sssd_pam.debug...done.
done.
[New Thread 10783]
Missing separate debuginfo for 
Try: yum --disablerepo='*' --enablerepo='*-debuginfo' install /usr/lib/debug/.build-id/a4/d2906aec2b8215b54d204db777231d708fb610
Reading symbols from /usr/lib64/libtevent.so.0.9.8...Reading symbols from /usr/lib/debug/usr/lib64/libtevent.so.0.9.8.debug...done.
done.
Loaded symbols for /usr/lib64/libtevent.so.0.9.8
Reading symbols from /usr/lib64/libtalloc.so.2.0.1...Reading symbols from /usr/lib/debug/usr/lib64/libtalloc.so.2.0.1.debug...done.
done.
Loaded symbols for /usr/lib64/libtalloc.so.2.0.1
Reading symbols from /lib64/libpopt.so.0.0.0...Reading symbols from /usr/lib/debug/lib64/libpopt.so.0.0.0.debug...done.
done.
Loaded symbols for /lib64/libpopt.so.0.0.0
Reading symbols from /usr/lib64/libldb.so.0.9.10...Reading symbols from /usr/lib/debug/usr/lib64/libldb.so.0.9.10.debug...done.
done.
Loaded symbols for /usr/lib64/libldb.so.0.9.10
Reading symbols from /lib64/libdbus-1.so.3.4.0...Reading symbols from /usr/lib/debug/lib64/libdbus-1.so.3.4.0.debug...done.
done.
Loaded symbols for /lib64/libdbus-1.so.3.4.0
Reading symbols from /lib64/librt-2.12.so...Reading symbols from /usr/lib/debug/lib64/librt-2.12.so.debug...done.
done.
Loaded symbols for /lib64/librt-2.12.so
Reading symbols from /lib64/libpcre.so.0.0.1...Reading symbols from /usr/lib/debug/lib64/libpcre.so.0.0.1.debug...done.
done.
Loaded symbols for /lib64/libpcre.so.0.0.1
Reading symbols from /usr/lib64/libini_config.so.2.0.0...Reading symbols from /usr/lib/debug/usr/lib64/libini_config.so.2.0.0.debug...done.
done.
Loaded symbols for /usr/lib64/libini_config.so.2.0.0
Reading symbols from /usr/lib64/libcollection.so.2.0.0...Reading symbols from /usr/lib/debug/usr/lib64/libcollection.so.2.0.0.debug...done.
done.
Loaded symbols for /usr/lib64/libcollection.so.2.0.0
Reading symbols from /usr/lib64/libdhash.so.1.0.0...Reading symbols from /usr/lib/debug/usr/lib64/libdhash.so.1.0.0.debug...done.
done.
Loaded symbols for /usr/lib64/libdhash.so.1.0.0
Reading symbols from /lib64/liblber-2.4.so.2.5.6...Reading symbols from /usr/lib/debug/lib64/liblber-2.4.so.2.5.6.debug...done.
done.
Loaded symbols for /lib64/liblber-2.4.so.2.5.6
Reading symbols from /lib64/libldap-2.4.so.2.5.6...Reading symbols from /usr/lib/debug/lib64/libldap-2.4.so.2.5.6.debug...done.
done.
Loaded symbols for /lib64/libldap-2.4.so.2.5.6
Reading symbols from /usr/lib64/libtdb.so.1.2.1...Reading symbols from /usr/lib/debug/usr/lib64/libtdb.so.1.2.1.debug...done.
done.
Loaded symbols for /usr/lib64/libtdb.so.1.2.1
Reading symbols from /usr/lib64/libssl3.so...Reading symbols from /usr/lib/debug/usr/lib64/libssl3.so.debug...done.
done.
Loaded symbols for /usr/lib64/libssl3.so
Reading symbols from /usr/lib64/libsmime3.so...Reading symbols from /usr/lib/debug/usr/lib64/libsmime3.so.debug...done.
done.
Loaded symbols for /usr/lib64/libsmime3.so
Reading symbols from /usr/lib64/libnss3.so...Reading symbols from /usr/lib/debug/usr/lib64/libnss3.so.debug...done.
done.
Loaded symbols for /usr/lib64/libnss3.so
Reading symbols from /usr/lib64/libnssutil3.so...Reading symbols from /usr/lib/debug/usr/lib64/libnssutil3.so.debug...done.
done.
Loaded symbols for /usr/lib64/libnssutil3.so
Reading symbols from /lib64/libplds4.so...Reading symbols from /usr/lib/debug/lib64/libplds4.so.debug...done.
done.
Loaded symbols for /lib64/libplds4.so
Reading symbols from /lib64/libplc4.so...Reading symbols from /usr/lib/debug/lib64/libplc4.so.debug...done.
done.
Loaded symbols for /lib64/libplc4.so
Reading symbols from /lib64/libnspr4.so...Reading symbols from /usr/lib/debug/lib64/libnspr4.so.debug...done.
done.
Loaded symbols for /lib64/libnspr4.so
Reading symbols from /lib64/libpthread-2.12.so...Reading symbols from /usr/lib/debug/lib64/libpthread-2.12.so.debug...done.
[Thread debugging using libthread_db enabled]
done.
Loaded symbols for /lib64/libpthread-2.12.so
Reading symbols from /lib64/libdl-2.12.so...Reading symbols from /usr/lib/debug/lib64/libdl-2.12.so.debug...done.
done.
Loaded symbols for /lib64/libdl-2.12.so
Reading symbols from /lib64/libc-2.12.so...Reading symbols from /usr/lib/debug/lib64/libc-2.12.so.debug...done.
done.
Loaded symbols for /lib64/libc-2.12.so
Reading symbols from /lib64/ld-2.12.so...Reading symbols from /usr/lib/debug/lib64/ld-2.12.so.debug...done.
done.
Loaded symbols for /lib64/ld-2.12.so
Reading symbols from /usr/lib64/libpath_utils.so.1.0.0...Reading symbols from /usr/lib/debug/usr/lib64/libpath_utils.so.1.0.0.debug...done.
done.
Loaded symbols for /usr/lib64/libpath_utils.so.1.0.0
Reading symbols from /usr/lib64/libref_array.so.1.0.0...Reading symbols from /usr/lib/debug/usr/lib64/libref_array.so.1.0.0.debug...done.
done.
Loaded symbols for /usr/lib64/libref_array.so.1.0.0
Reading symbols from /lib64/libresolv-2.12.so...Reading symbols from /usr/lib/debug/lib64/libresolv-2.12.so.debug...done.
done.
Loaded symbols for /lib64/libresolv-2.12.so
Reading symbols from /usr/lib64/libsasl2.so.2.0.23...Reading symbols from /usr/lib/debug/usr/lib64/libsasl2.so.2.0.23.debug...done.
done.
Loaded symbols for /usr/lib64/libsasl2.so.2.0.23
Reading symbols from /lib64/libz.so.1.2.3...Reading symbols from /usr/lib/debug/lib64/libz.so.1.2.3.debug...done.
done.
Loaded symbols for /lib64/libz.so.1.2.3
Reading symbols from /lib64/libcrypt-2.12.so...Reading symbols from /usr/lib/debug/lib64/libcrypt-2.12.so.debug...done.
done.
Loaded symbols for /lib64/libcrypt-2.12.so
Reading symbols from /lib64/libfreebl3.so...Reading symbols from /usr/lib/debug/lib64/libfreebl3.so.debug...done.
done.
Loaded symbols for /lib64/libfreebl3.so
Reading symbols from /usr/lib64/ldb/memberof.so...Reading symbols from /usr/lib/debug/usr/lib64/ldb/memberof.so.debug...done.
done.
Loaded symbols for /usr/lib64/ldb/memberof.so
Core was generated by `/usr/libexec/sssd/sssd_pam -d 9 --debug-to-files'.
Program terminated with signal 11, Segmentation fault.
#0  _tevent_add_timer (ev=0x1c47a80, mem_ctx=0x1c44760, next_event=..., handler=0x3d0001b790 <ltdb_callback>, 
    private_data=0x1c44760, handler_name=0x3d0002ae7e "ltdb_callback", 
    location=0x3d0002ae67 "ldb_tdb/ldb_tdb.c:1282") at tevent.c:358
358		return ev->ops->add_timer(ev, mem_ctx, next_event, handler, private_data,

Thread 1 (Thread 0x7f2083952700 (LWP 10783)):
#0  _tevent_add_timer (ev=0x1c47a80, mem_ctx=0x1c44760, next_event=..., handler=0x3d0001b790 <ltdb_callback>, 
    private_data=0x1c44760, handler_name=0x3d0002ae7e "ltdb_callback", 
    location=0x3d0002ae67 "ldb_tdb/ldb_tdb.c:1282") at tevent.c:358
No locals.
#1  0x0000003d0001a163 in ltdb_handle_request (module=0x1c441f0, req=0x1c457f0) at ldb_tdb/ldb_tdb.c:1282
        ldb = 0x1c47990
        ev = 0x1c47a80
        ac = 0x1c44760
        te = <value optimized out>
        tv = {tv_sec = 0, tv_usec = 0}
#2  0x0000003d0001196a in ldb_next_request (module=0x1c441f0, request=0x1c457f0) at common/ldb_modules.c:563
        ret = <value optimized out>
#3  0x0000003d0000808b in asq_search (module=0x1c429c0, req=0x1c457f0) at modules/asq.c:358
        ldb = 0x1c47990
        base_req = <value optimized out>
        control = 0x0
        ac = <value optimized out>
        ret = 4
#4  0x0000003d0000bc2f in ldb_search (ldb=0x1c47990, mem_ctx=0x1c49400, result=0x7fff75a39638, 
    base=<value optimized out>, scope=<value optimized out>, attrs=0x63e020, 
    exp_fmt=0x435300 "(&(objectclass=user)(name=%s))") at common/ldb.c:1349
        req = 0x1c457f0
        res = 0x1c41610
        expression = 0x1c45ba0 "(&(objectclass=user)(name=user1))"
        ap = {{gp_offset = 48, fp_offset = 48, overflow_arg_area = 0x7fff75a39618, 
            reg_save_area = 0x7fff75a39520}}
        ret = <value optimized out>
#5  0x000000000041d045 in sysdb_getpwnam (mem_ctx=0x1c42a40, ctx=0x1c44de0, domain=<value optimized out>, 
    name=0x1c43490 "user1", _res=0x1c42a60) at src/db/sysdb_search.c:64
        tmpctx = 0x1c49400
        attrs = {0x430cca "name", 0x433cc8 "uidNumber", 0x433c8f "gidNumber", 0x433cdb "gecos", 
          0x433ce1 "homeDirectory", 0x433cef "loginShell", 0x433c6c "lastUpdate", 
          0x4313e7 "dataExpireTimestamp", 0x435931 "initgrExpireTimestamp", 0x433c14 "objectClass", 0x0}
---Type <return> to continue, or q <return> to quit--- 
        base_dn = 0x1c4ffb0
        res = <value optimized out>
        sanitized_name = 0x1c434f0 "user1"
        ret = 0
#6  0x0000000000407cd1 in pam_check_user_search (preq=0x1c42a40) at src/responder/pam/pamsrv_cmd.c:844
        dom = 0x1c3ffd0
        cctx = 0x1c437e0
        name = 0x1c43490 "user1"
        sysdb = 0x1c44de0
        cacheExpire = <value optimized out>
        ret = <value optimized out>
        __FUNCTION__ = "pam_check_user_search"
#7  0x0000000000409c08 in pam_check_user_dp_callback (err_maj=<value optimized out>, err_min=5, 
    err_msg=0x4363a0 "Internal Error", ptr=<value optimized out>) at src/responder/pam/pamsrv_cmd.c:955
        preq = 0x1c42a40
        ret = <value optimized out>
        pctx = 0x1c400a0
        __FUNCTION__ = "pam_check_user_dp_callback"
#8  0x000000000042f386 in sss_dp_req_destructor (ptr=<value optimized out>)
    at src/responder/common/responder_dp.c:100
        sdp_req = 0x1c47390
        cb = <value optimized out>
        next = 0x0
        key = {type = HASH_KEY_STRING, {str = 0x1c439c0 "3user1@AD", ul = 29637056}}
        hret = <value optimized out>
        __FUNCTION__ = "sss_dp_req_destructor"
#9  0x0000003cfd002d9e in _talloc_free_internal (ptr=0x1c47390, location=0x3cfd007b1d "talloc.c:1893")
    at talloc.c:600
        d = 0x42f2b0 <sss_dp_req_destructor>
        tc = 0x42f2b0
#10 0x0000003cfd002c2b in _talloc_free_internal (ptr=0x1c40620, location=0x3cfd007b1d "talloc.c:1893")
    at talloc.c:631
        child = 0x1c47390
        new_parent = 0x0
        tc = 0x1c47390
#11 0x0000003cfd002c2b in _talloc_free_internal (ptr=0x1c400a0, location=0x3cfd007b1d "talloc.c:1893")
    at talloc.c:631
        child = 0x1c40620
        new_parent = 0x0
        tc = 0x1c40620
#12 0x0000003cfd002c2b in _talloc_free_internal (ptr=0x1c3f420, location=0x3cfd007b1d "talloc.c:1893")
---Type <return> to continue, or q <return> to quit---
    at talloc.c:631
        child = 0x1c400a0
        new_parent = 0x0
        tc = 0x1c400a0
#13 0x0000003cfd002c2b in _talloc_free_internal (ptr=0x1c3e320, location=0x3cfd007b1d "talloc.c:1893")
    at talloc.c:631
        child = 0x1c3f420
        new_parent = 0x0
        tc = 0x1c3f420
#14 0x0000003cfd001abb in _talloc_free_internal (ptr=0x1c3e140, location=0x3cfd007b1d "talloc.c:1893")
    at talloc.c:631
        child = 0x1c3e320
        new_parent = 0x0
#15 _talloc_free (ptr=0x1c3e140, location=0x3cfd007b1d "talloc.c:1893") at talloc.c:1133
        tc = 0x1c3e320
#16 0x0000003cfa435d92 in __run_exit_handlers (status=0) at exit.c:78
        atfct = <value optimized out>
        onfct = <value optimized out>
        cxafct = <value optimized out>
        f = <value optimized out>
#17 exit (status=0) at exit.c:100
No locals.
#18 0x0000000000425a37 in default_quit (ev=<value optimized out>, se=<value optimized out>, 
    signum=<value optimized out>, count=<value optimized out>, siginfo=<value optimized out>, 
    private_data=<value optimized out>) at src/util/server.c:251
        done_sigterm = 0
        __FUNCTION__ = "default_quit"
#19 0x0000003cfe003baa in tevent_common_check_signal (ev=0x1c3e320) at tevent_signal.c:353
        se = 0x1c3f1a0
        count = 1
        sl = <value optimized out>
        next = 0x0
        counter = {count = <value optimized out>, seen = 0}
        clear_processed_siginfo = <value optimized out>
        i = <value optimized out>
#20 0x0000003cfe0054fa in epoll_event_loop (ev=<value optimized out>, location=<value optimized out>)
    at tevent_standard.c:267
        ret = -1
        i = <value optimized out>
        events = {{events = 1, data = {ptr = 0x1c45560, fd = 29644128, u32 = 29644128, u64 = 29644128}}}
        timeout = <value optimized out>
---Type <return> to continue, or q <return> to quit---
#21 std_event_loop_once (ev=<value optimized out>, location=<value optimized out>) at tevent_standard.c:544
        std_ev = 0x1c3e3e0
        tval = {tv_sec = 0, tv_usec = 575408}
#22 0x0000003cfe0026d0 in _tevent_loop_once (ev=0x1c3e320, location=0x436e15 "src/util/server.c:526")
    at tevent.c:490
        ret = <value optimized out>
        nesting_stack_ptr = 0x0
#23 0x0000003cfe00273b in tevent_common_loop_wait (ev=0x1c3e320, location=0x436e15 "src/util/server.c:526")
    at tevent.c:591
        ret = <value optimized out>
#24 0x00000000004259f1 in server_loop (main_ctx=0x1c3f420) at src/util/server.c:526
No locals.
#25 0x00000000004079b0 in main (argc=<value optimized out>, argv=<value optimized out>)
    at src/responder/pam/pamsrv.c:230
        opt = <value optimized out>
        pc = <value optimized out>
        main_ctx = 0x1c3f420
        ret = <value optimized out>
        long_options = {{longName = 0x0, shortName = 0 '\000', argInfo = 4, arg = 0x63e0c0, val = 0, 
            descrip = 0x431062 "Help options:", argDescrip = 0x0}, {longName = 0x431070 "debug-level", 
            shortName = 100 'd', argInfo = 2, arg = 0x63e1b8, val = 0, descrip = 0x431041 "Debug level", 
            argDescrip = 0x0}, {longName = 0x43107c "debug-to-files", shortName = 102 'f', argInfo = 0, 
            arg = 0x63e1bc, val = 0, descrip = 0x4311a8 "Send the debug output to files instead of stderr", 
            argDescrip = 0x0}, {longName = 0x43108b "debug-timestamps", shortName = 0 '\000', argInfo = 2, 
            arg = 0x63e080, val = 0, descrip = 0x43104d "Add debug timestamps", argDescrip = 0x0}, {
            longName = 0x0, shortName = 0 '\000', argInfo = 0, arg = 0x0, val = 0, descrip = 0x0, 
            argDescrip = 0x0}}
        __FUNCTION__ = "main"

Comment 2 Stephen Gallagher 2011-10-13 14:33:53 UTC
Upstream ticket:
https://fedorahosted.org/sssd/ticket/1038

Comment 5 Kaushik Banerjee 2011-10-18 07:05:39 UTC
Verified that segfaults from sssd_pam are no longer seen after restarting sssd.


Verified in version:
# rpm -qi sssd | head
Name        : sssd                         Relocations: (not relocatable)
Version     : 1.5.1                             Vendor: Red Hat, Inc.
Release     : 59.el6                        Build Date: Tue 18 Oct 2011 02:29:48 AM IST
Install Date: Tue 18 Oct 2011 11:30:40 AM IST      Build Host: x86-003.build.bos.redhat.com
Group       : Applications/System           Source RPM: sssd-1.5.1-59.el6.src.rpm
Size        : 3615305                          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 Jan Zeleny 2011-10-27 11:45:40 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: When internal communication between PAM responder and one of SSSD's backends timed out for some reason, a handling routine is invoked. That routine can cause a race condition which can result in accessing memory that has been freed.
Consequence: PAM responder crashes
Fix: Timeout handling routine doesn't free the context until all operations on this context are done.
Result: In case the communication times out, PAM responder doesn't crash any more.

Comment 7 errata-xmlrpc 2011-12-06 16:41:03 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