Bug 1381936

Summary: automount killed by SIGABRT (double free or corruption (fasttop) in ldap_int_tls_destroy())
Product: Red Hat Enterprise Linux 7 Reporter: Karsten Weiss <knweiss>
Component: autofsAssignee: Ian Kent <ikent>
Status: CLOSED CURRENTRELEASE QA Contact: Filesystem QE <fs-qe>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 7.2CC: denx87, xifeng
Target Milestone: rc   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2017-02-07 01:50:44 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:

Description Karsten Weiss 2016-10-05 11:49:53 UTC 
Description of problem:

There's a "double free or corruption (fasttop)" malloc corruption in ldap_int_tls_destroy().
It happens if the connection to the LDAP server fails.

# abrt-cli  list
id 1dd8c8f3e4c79345234fcfb304f0c0d388ab1d74
reason:         automount killed by SIGABRT
time:           Sat 16 Jul 2016 06:23:18 AM CEST
cmdline:        /usr/sbin/automount --pid-file /run/autofs.pid
package:        autofs-5.0.7-54.el7
uid:            0 (root)
count:          2
Directory:      /var/spool/abrt/ccpp-2016-07-16-06:23:18-3263
Reported:       http://retrace/faf/reports/bthash/fb1f2cdcc1975270606cf03b64a97ec3d5da03be
root@cmtcbc3u180 ccpp-2016-07-16-06:23:18-3263 #

/var/log/messages:

Jul 16 06:22:55 cmtcbc3u180 automount[3263]: key "session.zip" not found in map source(s).
Jul 16 06:23:18 cmtcbc3u180 automount[3263]: bind_ldap_simple: lookup(ldap): Unable to bind to the LDAP server: (default), error Can't contact LDAP server
Jul 16 06:23:19 cmtcbc3u180 automount[3058]: key "session.zip" not found in map source(s).

(Please ignore the strange keys...)

root@cmtcbc3u180 ccpp-2016-07-16-06:23:18-3263 # gdb /usr/sbin/automount --core=coredump
[...]
Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/sbin/automount --pid-file /run/autofs.pid'.
Program terminated with signal 6, Aborted.
#0  0x00007fd1e7bfb5f7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
56        return INLINE_SYSCALL (tgkill, 3, pid, selftid, sig);
Missing separate debuginfos, use: debuginfo-install cyrus-sasl-gssapi-2.1.26-20.el7_2.x86_64 cyrus-sasl-lib-2.1.26-20.el7_2.x86_64 cyrus-sasl-plain-2.1.26-20.el7_2.x86_64 keyutils-libs-1.5.8-3.el7.x86_64 krb5-libs-1.13.2-12.el7_2.x86_64 libcom_err-1.42.9-7.el7.x86_64 libdb-5.3.21-19.el7.x86_64 libgcc-4.8.5-4.el7.x86_64 libselinux-2.2.2-6.el7.x86_64 libtirpc-0.2.4-0.6.el7.x86_64 libxml2-2.9.1-6.el7_2.3.x86_64 nss-3.21.0-9.el7_2.x86_64 nss-softokn-freebl-3.16.2.3-14.2.el7_2.x86_64 nss-util-3.21.0-2.2.el7_2.x86_64 pcre-8.32-15.el7_2.1.x86_64 sssd-client-1.13.0-40.el7_2.12.x86_64 xz-libs-5.1.2-12alpha.el7.x86_64 zlib-1.2.7-15.el7.x86_64
(gdb) bt
#0  0x00007fd1e7bfb5f7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#1  0x00007fd1e7bfcce8 in __GI_abort () at abort.c:90
#2  0x00007fd1e7c3b327 in __libc_message (do_abort=do_abort@entry=2, fmt=fmt@entry=0x7fd1e7d45488 "*** Error in `%s': %s: 0x%s ***\n") at ../sysdeps/unix/sysv/linux/libc_fatal.c:196
#3  0x00007fd1e7c43053 in malloc_printerr (ar_ptr=0x7fd19c000020, ptr=<optimized out>, str=0x7fd1e7d45520 "double free or corruption (fasttop)", action=3) at malloc.c:5022
#4  _int_free (av=0x7fd19c000020, p=<optimized out>, have_lock=0) at malloc.c:3842
#5  0x00007fd1e57136f5 in ldap_int_tls_destroy (lo=0x7fd1980244f0) at tls2.c:105
#6  0x00007fd1e56f8277 in ldap_ld_free (ld=0x7fd19801fe00, close=<optimized out>, sctrls=<optimized out>, cctrls=<optimized out>) at unbind.c:209
#7  0x00007fd1e593d0b8 in __unbind_ldap_connection (logopt=logopt@entry=0, ldap=ldap@entry=0x7fd19801fe00, ctxt=ctxt@entry=0x7fd194027270) at lookup_ldap.c:227
#8  0x00007fd1e593d11e in unbind_ldap_connection (logopt=logopt@entry=0, ldap=ldap@entry=0x7fd19801fe00, ctxt=ctxt@entry=0x7fd194027270) at lookup_ldap.c:239
#9  0x00007fd1e593d520 in do_connect (logopt=logopt@entry=0, ldap=ldap@entry=0x7fd1aa392a20, uri=<optimized out>, ctxt=ctxt@entry=0x7fd194027270) at lookup_ldap.c:662
#10 0x00007fd1e593dd97 in do_reconnect (logopt=0, ldap=0x7fd1aa392a20, ctxt=0x7fd194027270) at lookup_ldap.c:972
#11 0x00007fd1e5941618 in lookup_one (ap=<optimized out>, ap=<optimized out>, ctxt=0x7fd194027270, qKey_len=10, qKey=0x7fd198020a10 "broker.zip", source=0x7fd1bc000950) at lookup_ldap.c:2932
#12 match_key (ctxt=0x7fd194027270, key_len=10, key=0x7fd198020a10 "broker.zip", source=0x7fd1bc000950, ap=0x7fd1eaef08e0) at lookup_ldap.c:3427
#13 check_map_indirect (ctxt=0x7fd194027270, key_len=10, key=0x7fd198020a10 "broker.zip", source=0x7fd1bc000950, ap=0x7fd1eaef08e0) at lookup_ldap.c:3514
#14 lookup_mount (ap=0x7fd1eaef08e0, name=<optimized out>, name_len=<optimized out>, context=0x7fd194027270) at lookup_ldap.c:3667
#15 0x00007fd1e92a4d2b in lookup_name_source_instance (name_len=10, name=0x7fd1aa396dc0 "broker.zip", type=0x7fd19801fc50 "ldap", map=0x7fd1eaef09d0, ap=0x7fd1eaef08e0) at lookup.c:936
#16 lookup_map_name (this=0x7fd198023960, name_len=10, name=0x7fd1aa396dc0 "broker.zip", map=0x7fd1eaef09d0, ap=0x7fd1eaef08e0) at lookup.c:991
#17 lookup_nss_mount (ap=ap@entry=0x7fd1eaef08e0, source=source@entry=0x0, name=name@entry=0x7fd1aa396dc0 "broker.zip", name_len=10) at lookup.c:1185
#18 0x00007fd1e929bcb5 in do_mount_indirect (arg=<optimized out>) at indirect.c:772
#19 0x00007fd1e8e54dc5 in start_thread (arg=0x7fd1aa399700) at pthread_create.c:308
#20 0x00007fd1e7cbcced in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113
(gdb) info threads
  Id   Target Id         Frame 
  17   Thread 0x7fd1c9ffb700 (LWP 4205) 0x00007fd1e7cb269d in poll () at ../sysdeps/unix/syscall-template.S:81
  16   Thread 0x7fd1caffd700 (LWP 3985) 0x00007fd1e7cb269d in poll () at ../sysdeps/unix/syscall-template.S:81
  15   Thread 0x7fd1c8ff9700 (LWP 4316) 0x00007fd1e7cb269d in poll () at ../sysdeps/unix/syscall-template.S:81
  14   Thread 0x7fd1e9288700 (LWP 3280) pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:238
  13   Thread 0x7fd1c97fa700 (LWP 4271) 0x00007fd1e7cb269d in poll () at ../sysdeps/unix/syscall-template.S:81
  12   Thread 0x7fd1e0a43700 (LWP 3729) 0x00007fd1e7cb269d in poll () at ../sysdeps/unix/syscall-template.S:81
  11   Thread 0x7fd1e636d700 (LWP 3426) 0x00007fd1e7cb269d in poll () at ../sysdeps/unix/syscall-template.S:81
  10   Thread 0x7fd1cbfff700 (LWP 3766) 0x00007fd1e7cb269d in poll () at ../sysdeps/unix/syscall-template.S:81
  9    Thread 0x7fd1ca7fc700 (LWP 4192) 0x00007fd1e7cb269d in poll () at ../sysdeps/unix/syscall-template.S:81
  8    Thread 0x7fd1e2246700 (LWP 3506) 0x00007fd1e7cb269d in poll () at ../sysdeps/unix/syscall-template.S:81
  7    Thread 0x7fd1e9268840 (LWP 3263) 0x00007fd1e8e5be91 in do_sigwait (sig=0x7ffeb29dd738, set=<optimized out>) at ../sysdeps/unix/sysv/linux/sigwait.c:61
  6    Thread 0x7fd1e1a45700 (LWP 3559) 0x00007fd1e7cb269d in poll () at ../sysdeps/unix/syscall-template.S:81
  5    Thread 0x7fd1abfff700 (LWP 4355) 0x00007fd1e7cb269d in poll () at ../sysdeps/unix/syscall-template.S:81
  4    Thread 0x7fd1e1244700 (LWP 3652) 0x00007fd1e7cb269d in poll () at ../sysdeps/unix/syscall-template.S:81
  3    Thread 0x7fd1cb7fe700 (LWP 3907) 0x00007fd1e7cb269d in poll () at ../sysdeps/unix/syscall-template.S:81
  2    Thread 0x7fd1e9267700 (LWP 3281) pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
* 1    Thread 0x7fd1aa399700 (LWP 3036) 0x00007fd1e7bfb5f7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
(gdb) bt full
#0  0x00007fd1e7bfb5f7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
        resultvar = 0
        pid = 3263
        selftid = 3036
#1  0x00007fd1e7bfcce8 in __GI_abort () at abort.c:90
        save_stage = 2
        act = {__sigaction_handler = {sa_handler = 0x7fd1e7bd83fc, sa_sigaction = 0x7fd1e7bd83fc}, sa_mask = {__val = {5, 140539514334516, 3, 140538480762174, 2, 140539514330887, 1, 140539514339571, 3, 140538480762148, 12, 
              140539514339575, 2, 140538480762960, 140538480762960, 140538480764720}}, sa_flags = 13, sa_restorer = 0x7fd1aa392250}
        sigs = {__val = {32, 0 <repeats 15 times>}}
#2  0x00007fd1e7c3b327 in __libc_message (do_abort=do_abort@entry=2, fmt=fmt@entry=0x7fd1e7d45488 "*** Error in `%s': %s: 0x%s ***\n") at ../sysdeps/unix/sysv/linux/libc_fatal.c:196
        ap = {{gp_offset = 40, fp_offset = 48, overflow_arg_area = 0x7fd1aa392740, reg_save_area = 0x7fd1aa392650}}
        ap_copy = {{gp_offset = 16, fp_offset = 48, overflow_arg_area = 0x7fd1aa392740, reg_save_area = 0x7fd1aa392650}}
        fd = 2
        on_2 = <optimized out>
        list = <optimized out>
        nlist = <optimized out>
        cp = <optimized out>
        written = <optimized out>
#3  0x00007fd1e7c43053 in malloc_printerr (ar_ptr=0x7fd19c000020, ptr=<optimized out>, str=0x7fd1e7d45520 "double free or corruption (fasttop)", action=3) at malloc.c:5022
        buf = "00007fd19c00c340"
        cp = <optimized out>
        ar_ptr = 0x7fd19c000020
        ptr = <optimized out>
        str = 0x7fd1e7d45520 "double free or corruption (fasttop)"
        action = 3
#4  _int_free (av=0x7fd19c000020, p=<optimized out>, have_lock=0) at malloc.c:3842
        size = <optimized out>
        fb = <optimized out>
        nextchunk = <optimized out>
        nextsize = <optimized out>
        nextinuse = <optimized out>
        prevsize = <optimized out>
        bck = <optimized out>
        fwd = <optimized out>
        errstr = 0x7fd1e7d45520 "double free or corruption (fasttop)"
        locked = <optimized out>
#5  0x00007fd1e57136f5 in ldap_int_tls_destroy (lo=0x7fd1980244f0) at tls2.c:105
No locals.
#6  0x00007fd1e56f8277 in ldap_ld_free (ld=0x7fd19801fe00, close=<optimized out>, sctrls=<optimized out>, cctrls=<optimized out>) at unbind.c:209
        lm = <optimized out>
        next = <optimized out>
#7  0x00007fd1e593d0b8 in __unbind_ldap_connection (logopt=logopt@entry=0, ldap=ldap@entry=0x7fd19801fe00, ctxt=ctxt@entry=0x7fd194027270) at lookup_ldap.c:227
        rv = <optimized out>
        __FUNCTION__ = "__unbind_ldap_connection"
#8  0x00007fd1e593d11e in unbind_ldap_connection (logopt=logopt@entry=0, ldap=ldap@entry=0x7fd19801fe00, ctxt=ctxt@entry=0x7fd194027270) at lookup_ldap.c:239
        rv = <optimized out>
#9  0x00007fd1e593d520 in do_connect (logopt=logopt@entry=0, ldap=ldap@entry=0x7fd1aa392a20, uri=<optimized out>, ctxt=ctxt@entry=0x7fd194027270) at lookup_ldap.c:662
        cur_host = 0x0
        handle = 0x7fd19801fe00
        ret = 0
        __FUNCTION__ = "do_connect"
#10 0x00007fd1e593dd97 in do_reconnect (logopt=0, ldap=0x7fd1aa392a20, ctxt=0x7fd194027270) at lookup_ldap.c:972
        ret = 2
#11 0x00007fd1e5941618 in lookup_one (ap=<optimized out>, ap=<optimized out>, ctxt=0x7fd194027270, qKey_len=10, qKey=0x7fd198020a10 "broker.zip", source=0x7fd1bc000950) at lookup_ldap.c:2932
        rv = <optimized out>
        buf = '\000' <repeats 127 times>
        enc_len2 = 0
        we = <optimized out>
        query = <optimized out>
        entry = <optimized out>
        i = <optimized out>
        age = 1468642998
        bvKey = <optimized out>
        class = <optimized out>
        enc_key1 = 0x0
        attrs = {0x0, 0x0, 0x0}
        scope = 2
        mc = 0x7fd1eaef0af0
        count = <optimized out>
        e = <optimized out>
        info = <optimized out>
        enc_key2 = 0x0
        bvValues = <optimized out>
        wild = 0
        ret = 8
        l = <optimized out>
        ql = <optimized out>
        result = 0x0
        enc_len1 = 0
        ldap = 0x0
#12 match_key (ctxt=0x7fd194027270, key_len=10, key=0x7fd198020a10 "broker.zip", source=0x7fd1bc000950, ap=0x7fd1eaef08e0) at lookup_ldap.c:3427
        is_amd_format = <optimized out>
        buf = '\000' <repeats 127 times>
        lkp_key = <optimized out>
        prefix = <optimized out>
        ret = <optimized out>
#13 check_map_indirect (ctxt=0x7fd194027270, key_len=10, key=0x7fd198020a10 "broker.zip", source=0x7fd1bc000950, ap=0x7fd1eaef08e0) at lookup_ldap.c:3514
        is_amd_format = 0
        mc = 0x7fd1eaef0af0
        me = <optimized out>
        ret = <optimized out>
        status = <optimized out>
        now = 1468642998
        t_last_read = <optimized out>
        cur_state = 0
#14 lookup_mount (ap=0x7fd1eaef08e0, name=<optimized out>, name_len=<optimized out>, context=0x7fd194027270) at lookup_ldap.c:3667
        ctxt = <optimized out>
        source = 0x7fd1bc000950
        mc = 0x7fd1eaef0af0
        me = <optimized out>
        key = "broker.zip", '\000' <repeats 245 times>
        key_len = 10
        lkp_key = 0x7fd198020a10 "broker.zip"
        mapent = 0x0
        mapent_buf = '\000' <repeats 5320 times>...
        buf = '\000' <repeats 127 times>
        status = 0
        ret = 1
        __FUNCTION__ = "lookup_mount"
#15 0x00007fd1e92a4d2b in lookup_name_source_instance (name_len=10, name=0x7fd1aa396dc0 "broker.zip", type=0x7fd19801fc50 "ldap", map=0x7fd1eaef09d0, ap=0x7fd1eaef08e0) at lookup.c:936
        instance = <optimized out>
        format = 0x0
        age = 1468642998
#16 lookup_map_name (this=0x7fd198023960, name_len=10, name=0x7fd1aa396dc0 "broker.zip", map=0x7fd1eaef09d0, ap=0x7fd1eaef08e0) at lookup.c:991
        result = <optimized out>
        tmap = {flags = 0, type = 0x7fd198023af0 "file", format = 0x0, name = 0x7fd1eaef0ad0 "auto.bulkdata", exp_timeout = 300, age = 140538175188040, master_line = 50161, mc = 0x7fd1eaef0af0, stale = 2550268096, recurse = 0, 
          depth = 0, lookup = 0xc3f100006688, argc = 0, argv = 0x0, instance = 0x7fd1bc000950, next = 0x7fd1eaeeedf8}
        path = <optimized out>
#17 lookup_nss_mount (ap=ap@entry=0x7fd1eaef08e0, source=source@entry=0x0, name=name@entry=0x7fd1aa396dc0 "broker.zip", name_len=10) at lookup.c:1185
        __clframe = {__cancel_routine = <optimized out>, __cancel_arg = 0x7fd1eaef07f0, __do_it = 1, __cancel_type = <optimized out>}
        entry = 0x7fd1eaef07f0
        nsslist = {next = 0x7fd198025e18, prev = 0x7fd198023988}
        head = 0x7fd1aa396bd0
        p = 0x7fd198023988
        this = 0x7fd198023960
        map = 0x7fd1eaef09d0
        status = <optimized out>
        result = <optimized out>
        __FUNCTION__ = "lookup_nss_mount"
#18 0x00007fd1e929bcb5 in do_mount_indirect (arg=<optimized out>) at indirect.c:772
        __clframe = {__cancel_routine = <optimized out>, __cancel_arg = 0x7fd1aa396d40, __do_it = 1, __cancel_type = <optimized out>}
        ops = 0x7fd1e94d37e0 <dev_ioctl_ops>
        args = <optimized out>
        mt = {mutex = {__data = {__lock = 1, __count = 0, __owner = 3036, __nusers = 2, __kind = 0, __spins = 0, __list = {__prev = 0x0, __next = 0x0}}, 
            __size = "\001\000\000\000\000\000\000\000\334\v\000\000\002", '\000' <repeats 26 times>, __align = 1}, cond = {__data = {__lock = 0, __futex = 1, __total_seq = 1, __wakeup_seq = 0, __woken_seq = 0, 
              __mutex = 0x7fd1bc001c90, __nwaiters = 2, __broadcast_seq = 0}, __size = "\000\000\000\000\001\000\000\000\001", '\000' <repeats 23 times>, "\220\034\000\274\321\177\000\000\002\000\000\000\000\000\000", 
            __align = 4294967296}, signaled = 0, ap = 0x7fd1eaef08e0, status = 0, type = 0, ioctlfd = 0, mc = 0x0, name = "broker.zip", '\000' <repeats 4085 times>, dev = 45, len = 10, uid = 26248, gid = 50161, 
          wait_queue_token = 4227674}
        ap = 0x7fd1eaef08e0
        buf = "/bulkdata/broker.zip", '\000' <repeats 1773 times>...
        st = {st_dev = 0, st_ino = 140539566419408, st_nlink = 140538480782576, st_mode = 3941526752, st_uid = 32721, st_gid = 3914151904, __pad0 = 32721, st_rdev = 140539536816922, st_size = 140539566419408, 
          st_blksize = 140539536714833, st_blocks = 8245298605459466287, st_atim = {tv_sec = 3832563748384172405, tv_nsec = 32489904834574592}, st_mtim = {tv_sec = 0, tv_nsec = 0}, st_ctim = {tv_sec = 0, tv_nsec = 0}, __unused = {
            0, 0, 0}}
        len = <optimized out>
        status = <optimized out>
        state = 0
        __FUNCTION__ = "do_mount_indirect"
#19 0x00007fd1e8e54dc5 in start_thread (arg=0x7fd1aa399700) at pthread_create.c:308
        __res = <optimized out>
        pd = 0x7fd1aa399700
        now = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140538480793344, -3012529110417862157, 0, 140538480794048, 140538480793344, 35, 2995470786128843251, 2995607844891333107}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 
              0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
        not_first_call = <optimized out>
        pagesize_m1 = <optimized out>
        sp = <optimized out>
        freesize = <optimized out>
#20 0x00007fd1e7cbcced in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113
No locals.


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

autofs-5.0.7-54.el7 (CentOS)

How reproducible:

It happens when there are connection problems to the LDAP server.

Steps to Reproduce:
1. -
2. -
3. -

Actual results:
autofs abort.

Expected results:
No autofs abort.

Additional info:
See https://bugzilla.redhat.com/show_bug.cgi?id=1381924 which is similar.

I've also added an external bug reference to a bug report for CentOS 6.5(!) that has a very similar backtrace.