Bug 1414896 - Rare "double free or corruption" crash when calling ssh many times in parallel
Summary: Rare "double free or corruption" crash when calling ssh many times in parallel
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: keyutils
Version: 26
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: David Howells
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-01-19 16:55 UTC by Jason Tibbitts
Modified: 2018-05-29 11:24 UTC (History)
6 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2018-05-29 11:24:02 UTC
Type: Bug


Attachments (Terms of Use)

Description Jason Tibbitts 2017-01-19 16:55:07 UTC
This is kind of a weird one; it's quite rare and tough to reproduce and google turns up nothing similar.  I don't really have much information but I figured I'd go ahead and get something filed so there's some record.

The issue is that under some circumstances, if I call ssh in a tight loop to a large number of different machines, I will very occasionally get a failure like this:

*** Error in `ssh': double free or corruption (!prev): 0x0000564ed3506fb0 ***

Which would maybe be an ssh issue, but the backtrace has kerberos libs all over it and it does seem to be very kerberos related.

It seems that I have to have a relatively empty ccache, so that this will cause a big pile of host principals to be fetched.  I'm using the kernel keyring, which I believe is the Fedora default:

Ticket cache: KEYRING:persistent:7225:krb_ccache_ZmI2S2H

The number of hosts to which I'm connecting will cause a keyring large enough to exhaust the allowed number of pinned pages and so some of those principals will be evicted from the ccache.  I'm not entirely sure that's related, but I think it is.

I usually have multiple ccaches in my collection, but I don't think that's related.

So far this has hit me when doing an ansible run with forks = 100 (so 100 ssh calls in parallel) and I also often do things like this:

for i in ld{00..130}; do echo $i; ssh root@$i whatever < /dev/null& done

(The actual command that gets run on the remote hosts is immaterial.)  It doesn't happen every time but at least this morning I can pretty reliably reproduce this by making sure I do kinit -R before running that loop.  It doesn't happen at all if I kestroy.  (ssh is actually authenticating via host keys anyway.)

And for fun, if I double the value of /proc/sys/kernel/keys/maxbytes (to 40000) then running that loop will often result in the complete removal of my primary ccache.  I was trying to see if it was some race relating to evicting keys to make space....

Here's some error output from the most recent occurrence.

*** Error in `ssh': free(): invalid next size (normal): 0x000055d2847f8790 ***
======= Backtrace: =========
/lib64/libc.so.6(+0x8288a)[0x7f1fd7f2c88a]
/lib64/libc.so.6(cfree+0x4c)[0x7f1fd7f302bc]
/lib64/libkeyutils.so.1(keyctl_read_alloc+0x4e)[0x7f1fd61d5a9e]
/lib64/libkrb5.so.3(+0x38328)[0x7f1fd86dd328]
/lib64/libkrb5.so.3(+0x387ea)[0x7f1fd86dd7ea]
/lib64/libkrb5.so.3(krb5_cc_store_cred+0x50)[0x7f1fd86df2a0]
/lib64/libkrb5.so.3(+0x4b1a3)[0x7f1fd86f01a3]
/lib64/libkrb5.so.3(krb5_tkt_creds_step+0xe9)[0x7f1fd86f0fe9]
/lib64/libkrb5.so.3(krb5_tkt_creds_get+0x128)[0x7f1fd86f1aa8]
/lib64/libkrb5.so.3(krb5_get_credentials+0xbc)[0x7f1fd86f1bcc]
/lib64/libgssapi_krb5.so.2(+0x2ada1)[0x7f1fd89b5da1]
/lib64/libgssapi_krb5.so.2(+0x2b5fb)[0x7f1fd89b65fb]
/lib64/libgssapi_krb5.so.2(gss_init_sec_context+0x1f3)[0x7f1fd899fdf3]
ssh(+0x516cf)[0x55d2835066cf]
ssh(+0x519a5)[0x55d2835069a5]
ssh(+0x50e43)[0x55d283505e43]
ssh(+0x51164)[0x55d283506164]
ssh(+0x1fd44)[0x55d2834d4d44]
ssh(+0x1cbcb)[0x55d2834d1bcb]
ssh(+0xbd30)[0x55d2834c0d30]
/lib64/libc.so.6(__libc_start_main+0xf1)[0x7f1fd7eca401]
ssh(+0xd68a)[0x55d2834c268a]
======= Memory map: ========
55d2834b5000-55d283568000 r-xp 00000000 fd:00 101484370                  /usr/bin/ssh
55d283768000-55d28376b000 r--p 000b3000 fd:00 101484370                  /usr/bin/ssh
55d28376b000-55d28376c000 rw-p 000b6000 fd:00 101484370                  /usr/bin/ssh
55d28376c000-55d283770000 rw-p 00000000 00:00 0 
55d2847d0000-55d284821000 rw-p 00000000 00:00 0                          [heap]
7f1fc8000000-7f1fc8021000 rw-p 00000000 00:00 0 
7f1fc8021000-7f1fcc000000 ---p 00000000 00:00 0 
7f1fcdbb4000-7f1fcdbca000 r-xp 00000000 fd:00 2682                       /usr/lib64/libgcc_s-6.3.1-20161221.so.1
7f1fcdbca000-7f1fcddc9000 ---p 00016000 fd:00 2682                       /usr/lib64/libgcc_s-6.3.1-20161221.so.1
7f1fcddc9000-7f1fcddca000 r--p 00015000 fd:00 2682                       /usr/lib64/libgcc_s-6.3.1-20161221.so.1
7f1fcddca000-7f1fcddcb000 rw-p 00016000 fd:00 2682                       /usr/lib64/libgcc_s-6.3.1-20161221.so.1
7f1fcddcb000-7f1fcddce000 r-xp 00000000 fd:00 35541043                   /usr/lib64/krb5/plugins/libkrb5/sssd_krb5_locator_plugin.so
7f1fcddce000-7f1fcdfcd000 ---p 00003000 fd:00 35541043                   /usr/lib64/krb5/plugins/libkrb5/sssd_krb5_locator_plugin.so
7f1fcdfcd000-7f1fcdfce000 r--p 00002000 fd:00 35541043                   /usr/lib64/krb5/plugins/libkrb5/sssd_krb5_locator_plugin.so
7f1fcdfce000-7f1fcdfcf000 rw-p 00000000 00:00 0 
7f1fcdfcf000-7f1fcdfed000 r-xp 00000000 fd:00 2452719                    /usr/lib64/libgssrpc.so.4.2
7f1fcdfed000-7f1fce1ed000 ---p 0001e000 fd:00 2452719                    /usr/lib64/libgssrpc.so.4.2
7f1fce1ed000-7f1fce1ee000 r--p 0001e000 fd:00 2452719                    /usr/lib64/libgssrpc.so.4.2
7f1fce1ee000-7f1fce1ef000 rw-p 0001f000 fd:00 2452719                    /usr/lib64/libgssrpc.so.4.2
7f1fce1ef000-7f1fce207000 r-xp 00000000 fd:00 34919165                   /usr/lib64/gssproxy/proxymech.so
7f1fce207000-7f1fce407000 ---p 00018000 fd:00 34919165                   /usr/lib64/gssproxy/proxymech.so
7f1fce407000-7f1fce408000 r--p 00018000 fd:00 34919165                   /usr/lib64/gssproxy/proxymech.so
7f1fce408000-7f1fce409000 rw-p 00019000 fd:00 34919165                   /usr/lib64/gssproxy/proxymech.so
7f1fce409000-7f1fce40e000 r-xp 00000000 fd:00 627881                     /usr/lib64/libnss_dns-2.24.so
7f1fce40e000-7f1fce60e000 ---p 00005000 fd:00 627881                     /usr/lib64/libnss_dns-2.24.so
7f1fce60e000-7f1fce60f000 r--p 00005000 fd:00 627881                     /usr/lib64/libnss_dns-2.24.so
7f1fce60f000-7f1fce610000 rw-p 00006000 fd:00 627881                     /usr/lib64/libnss_dns-2.24.so
7f1fce610000-7f1fce612000 r-xp 00000000 fd:00 698522                     /usr/lib64/libnss_mdns4_minimal.so.2
7f1fce612000-7f1fce811000 ---p 00002000 fd:00 698522                     /usr/lib64/libnss_mdns4_minimal.so.2
7f1fce811000-7f1fce812000 r--p 00001000 fd:00 698522                     /usr/lib64/libnss_mdns4_minimal.so.2
7f1fce812000-7f1fce813000 rw-p 00000000 00:00 0 
7f1fce813000-7f1fd53ac000 r--p 00000000 fd:00 35297073                   /usr/lib/locale/locale-archive
7f1fd53ac000-7f1fd5bb1000 r--s 00000000 fd:01 12583059                   /var/lib/sss/mc/passwd
7f1fd5bb1000-7f1fd5bb9000 r-xp 00000000 fd:00 164463                     /usr/lib64/libnss_sss.so.2
7f1fd5bb9000-7f1fd5db8000 ---p 00008000 fd:00 164463                     /usr/lib64/libnss_sss.so.2
7f1fd5db8000-7f1fd5db9000 r--p 00007000 fd:00 164463                     /usr/lib64/libnss_sss.so.2
7f1fd5db9000-7f1fd5dba000 rw-p 00008000 fd:00 164463                     /usr/lib64/libnss_sss.so.2
7f1fd5dba000-7f1fd5dc4000 r-xp 00000000 fd:00 627883                     /usr/lib64/libnss_files-2.24.so
7f1fd5dc4000-7f1fd5fc4000 ---p 0000a000 fd:00 627883                     /usr/lib64/libnss_files-2.24.so
7f1fd5fc4000-7f1fd5fc5000 r--p 0000a000 fd:00 627883                     /usr/lib64/libnss_files-2.24.so
7f1fd5fc5000-7f1fd5fc6000 rw-p 0000b000 fd:00 627883                     /usr/lib64/libnss_files-2.24.so
7f1fd5fc6000-7f1fd5fcc000 rw-p 00000000 00:00 0 
7f1fd5fcc000-7f1fd5fd3000 r-xp 00000000 fd:00 627889                     /usr/lib64/librt-2.24.so
7f1fd5fd3000-7f1fd61d2000 ---p 00007000 fd:00 627889                     /usr/lib64/librt-2.24.so
7f1fd61d2000-7f1fd61d3000 r--p 00006000 fd:00 627889                     /usr/lib64/librt-2.24.so
7f1fd61d3000-7f1fd61d4000 rw-p 00007000 fd:00 627889                     /usr/lib64/librt-2.24.so
7f1fd61d4000-7f1fd61d7000 r-xp 00000000 fd:00 3138                       /usr/lib64/libkeyutils.so.1.5
7f1fd61d7000-7f1fd63d6000 ---p 00003000 fd:00 3138                       /usr/lib64/libkeyutils.so.1.5
7f1fd63d6000-7f1fd63d7000 r--p 00002000 fd:00 3138                       /usr/lib64/libkeyutils.so.1.5
7f1fd63d7000-7f1fd63d8000 rw-p 00000000 00:00 0 
7f1fd63d8000-7f1fd63e5000 r-xp 00000000 fd:00 4852583                    /usr/lib64/libkrb5support.so.0.1
7f1fd63e5000-7f1fd65e5000 ---p 0000d000 fd:00 4852583                    /usr/lib64/libkrb5support.so.0.1
7f1fd65e5000-7f1fd65e6000 r--p 0000d000 fd:00 4852583                    /usr/lib64/libkrb5support.so.0.1
7f1fd65e6000-7f1fd65e7000 rw-p 0000e000 fd:00 4852583                    /usr/lib64/libkrb5support.so.0.1
7f1fd65e7000-7f1fd65e9000 r-xp 00000000 fd:00 909641                     /usr/lib64/libfreebl3.so
7f1fd65e9000-7f1fd67e8000 ---p 00002000 fd:00 909641                     /usr/lib64/libfreebl3.so
7f1fd67e8000-7f1fd67e9000 r--p 00001000 fd:00 909641                     /usr/lib64/libfreebl3.so
7f1fd67e9000-7f1fd67ea000 rw-p 00002000 fd:00 909641                     /usr/lib64/libfreebl3.so
7f1fd67ea000-7f1fd6802000 r-xp 00000000 fd:00 627885                     /usr/lib64/libpthread-2.24.so
7f1fd6802000-7f1fd6a02000 ---p 00018000 fd:00 627885                     /usr/lib64/libpthread-2.24.so
7f1fd6a02000-7f1fd6a03000 r--p 00018000 fd:00 627885                     /usr/lib64/libpthread-2.24.so
7f1fd6a03000-7f1fd6a04000 rw-p 00019000 fd:00 627885                     /usr/lib64/libpthread-2.24.so
7f1fd6a04000-7f1fd6a08000 rw-p 00000000 00:00 0 
7f1fd6a08000-7f1fd6a43000 r-xp 00000000 fd:00 2658467                    /usr/lib64/libnspr4.so
7f1fd6a43000-7f1fd6c42000 ---p 0003b000 fd:00 2658467                    /usr/lib64/libnspr4.so
7f1fd6c42000-7f1fd6c43000 r--p 0003a000 fd:00 2658467                    /usr/lib64/libnspr4.so
7f1fd6c43000-7f1fd6c45000 rw-p 0003b000 fd:00 2658467                    /usr/lib64/libnspr4.so
7f1fd6c45000-7f1fd6c47000 rw-p 00000000 00:00 0 
7f1fd6c47000-7f1fd6c4b000 r-xp 00000000 fd:00 6295679                    /usr/lib64/libplc4.so
7f1fd6c4b000-7f1fd6e4a000 ---p 00004000 fd:00 6295679                    /usr/lib64/libplc4.so
7f1fd6e4a000-7f1fd6e4b000 r--p 00003000 fd:00 6295679                    /usr/lib64/libplc4.so
7f1fd6e4b000-7f1fd6e4c000 rw-p 00004000 fd:00 6295679                    /usr/lib64/libplc4.so
7f1fd6e4c000-7f1fd6e4f000 r-xp 00000000 fd:00 6295680                    /usr/lib64/libplds4.so
7f1fd6e4f000-7f1fd704e000 ---p 00003000 fd:00 6295680                    /usr/lib64/libplds4.so
7f1fd704e000-7f1fd704f000 r--p 00002000 fd:00 6295680                    /usr/lib64/libplds4.so
7f1fd704f000-7f1fd7050000 rw-p 00003000 fd:00 6295680                    /usr/lib64/libplds4.so
7f1fd7050000-7f1fd7077000 r-xp 00000000 fd:00 6847480                    /usr/lib64/libnssutil3.so
7f1fd7077000-7f1fd7276000 ---p 00027000 fd:00 6847480                    /usr/lib64/libnssutil3.so
7f1fd7276000-7f1fd727d000 r--p 00026000 fd:00 6847480                    /usr/lib64/libnssutil3.so
7f1fd727d000-7f1fd727e000 rw-p 0002d000 fd:00 6847480                    /usr/lib64/libnssutil3.so
7f1fd727e000-7f1fd739f000 r-xp 00000000 fd:00 1906015                    /usr/lib64/libnss3.so
7f1fd739f000-7f1fd759e000 ---p 00121000 fd:00 1906015                    /usr/lib64/libnss3.so
7f1fd759e000-7f1fd75a3000 r--p 00120000 fd:00 1906015                    /usr/lib64/libnss3.so
7f1fd75a3000-7f1fd75a5000 rw-p 00125000 fd:00 1906015                    /usr/lib64/libnss3.so
7f1fd75a5000-7f1fd75a7000 rw-p 00000000 00:00 0 
7f1fd75a7000-7f1fd75cb000 r-xp 00000000 fd:00 34137328                   /usr/lib64/libsmime3.so
7f1fd75cb000-7f1fd77ca000 ---p 00024000 fd:00 34137328                   /usr/lib64/libsmime3.so
7f1fd77ca000-7f1fd77cd000 r--p 00023000 fd:00 34137328                   /usr/lib64/libsmime3.so
7f1fd77cd000-7f1fd77ce000 rw-p 00026000 fd:00 34137328                   /usr/lib64/libsmime3.so
7f1fd77ce000-7f1fd7814000 r-xp 00000000 fd:00 35493440                   /usr/lib64/libssl3.so
7f1fd7814000-7f1fd7a14000 ---p 00046000 fd:00 35493440                   /usr/lib64/libssl3.so
7f1fd7a14000-7f1fd7a18000 r--p 00046000 fd:00 35493440                   /usr/lib64/libssl3.so
7f1fd7a18000-7f1fd7a19000 rw-p 0004a000 fd:00 35493440                   /usr/lib64/libssl3.so
7f1fd7a19000-7f1fd7a1a000 rw-p 00000000 00:00 0 
7f1fd7a1a000-7f1fd7a36000 r-xp 00000000 fd:00 3048                       /usr/lib64/libsasl2.so.3.0.0
7f1fd7a36000-7f1fd7c35000 ---p 0001c000 fd:00 3048                       /usr/lib64/libsasl2.so.3.0.0
7f1fd7c35000-7f1fd7c36000 r--p 0001b000 fd:00 3048                       /usr/lib64/libsasl2.so.3.0.0
7f1fd7c36000-7f1fd7c37000 rw-p 0001c000 fd:00 3048                       /usr/lib64/libsasl2.so.3.0.0
7f1fd7c37000-7f1fd7ca9000 r-xp 00000000 fd:00 2618                       /usr/lib64/libpcre.so.1.2.8
7f1fd7ca9000-7f1fd7ea8000 ---p 00072000 fd:00 2618                       /usr/lib64/libpcre.so.1.2.8
7f1fd7ea8000-7f1fd7ea9000 r--p 00071000 fd:00 2618                       /usr/lib64/libpcre.so.1.2.8
7f1fd7ea9000-7f1fd7eaa000 rw-p 00072000 fd:00 2618                       /usr/lib64/libpcre.so.1.2.8
7f1fd7eaa000-7f1fd8067000 r-xp 00000000 fd:00 505889                     /usr/lib64/libc-2.24.so
7f1fd8067000-7f1fd8266000 ---p 001bd000 fd:00 505889                     /usr/lib64/libc-2.24.so
7f1fd8266000-7f1fd826a000 r--p 001bc000 fd:00 505889                     /usr/lib64/libc-2.24.so
7f1fd826a000-7f1fd826c000 rw-p 001c0000 fd:00 505889                     /usr/lib64/libc-2.24.so
7f1fd826c000-7f1fd8270000 rw-p 00000000 00:00 0 
7f1fd8270000-7f1fd8273000 r-xp 00000000 fd:00 2812                       /usr/lib64/libcom_err.so.2.1
7f1fd8273000-7f1fd8472000 ---p 00003000 fd:00 2812                       /usr/lib64/libcom_err.so.2.1
7f1fd8472000-7f1fd8473000 r--p 00002000 fd:00 2812                       /usr/lib64/libcom_err.so.2.1
7f1fd8473000-7f1fd8474000 rw-p 00003000 fd:00 2812                       /usr/lib64/libcom_err.so.2.1
7f1fd8474000-7f1fd84a2000 r-xp 00000000 fd:00 4806314                    /usr/lib64/libk5crypto.so.3.1
7f1fd84a2000-7f1fd86a2000 ---p 0002e000 fd:00 4806314                    /usr/lib64/libk5crypto.so.3.1
7f1fd86a2000-7f1fd86a4000 r--p 0002e000 fd:00 4806314                    /usr/lib64/libk5crypto.so.3.1
7f1fd86a4000-7f1fd86a5000 rw-p 00030000 fd:00 4806314                    /usr/lib64/libk5crypto.so.3.1
7f1fd86a5000-7f1fd877a000 r-xp 00000000 fd:00 160597                     /usr/lib64/libkrb5.so.3.3
7f1fd877a000-7f1fd897a000 ---p 000d5000 fd:00 160597                     /usr/lib64/libkrb5.so.3.3
7f1fd897a000-7f1fd8989000 r--p 000d5000 fd:00 160597                     /usr/lib64/libkrb5.so.3.3
7f1fd8989000-7f1fd898b000 rw-p 000e4000 fd:00 160597                     /usr/lib64/libkrb5.so.3.3
7f1fd898b000-7f1fd89d5000 r-xp 00000000 fd:00 239620                     /usr/lib64/libgssapi_krb5.so.2.2
7f1fd89d5000-7f1fd8bd5000 ---p 0004a000 fd:00 239620                     /usr/lib64/libgssapi_krb5.so.2.2
7f1fd8bd5000-7f1fd8bd7000 r--p 0004a000 fd:00 239620                     /usr/lib64/libgssapi_krb5.so.2.2
7f1fd8bd7000-7f1fd8bd8000 rw-p 0004c000 fd:00 239620                     /usr/lib64/libgssapi_krb5.so.2.2
7f1fd8bd8000-7f1fd8bef000 r-xp 00000000 fd:00 627887                     /usr/lib64/libresolv-2.24.so
7f1fd8bef000-7f1fd8def000 ---p 00017000 fd:00 627887                     /usr/lib64/libresolv-2.24.so
7f1fd8def000-7f1fd8df0000 r--p 00017000 fd:00 627887                     /usr/lib64/libresolv-2.24.so
7f1fd8df0000-7f1fd8df1000 rw-p 00018000 fd:00 627887                     /usr/lib64/libresolv-2.24.so
7f1fd8df1000-7f1fd8df3000 rw-p 00000000 00:00 0 
7f1fd8df3000-7f1fd8dfa000 r-xp 00000000 fd:00 160631                     /usr/lib64/libcrypt-nss-2.24.so
7f1fd8dfa000-7f1fd8ff9000 ---p 00007000 fd:00 160631                     /usr/lib64/libcrypt-nss-2.24.so
7f1fd8ff9000-7f1fd8ffa000 r--p 00006000 fd:00 160631                     /usr/lib64/libcrypt-nss-2.24.so
7f1fd8ffa000-7f1fd8ffb000 rw-p 00007000 fd:00 160631                     /usr/lib64/libcrypt-nss-2.24.so
7f1fd8ffb000-7f1fd9029000 rw-p 00000000 00:00 0 
7f1fd9029000-7f1fd903e000 r-xp 00000000 fd:00 2742                       /usr/lib64/libz.so.1.2.8
7f1fd903e000-7f1fd923d000 ---p 00015000 fd:00 2742                       /usr/lib64/libz.so.1.2.8
7f1fd923d000-7f1fd923e000 r--p 00014000 fd:00 2742                       /usr/lib64/libz.so.1.2.8
7f1fd923e000-7f1fd923f000 rw-p 00015000 fd:00 2742                       /usr/lib64/libz.so.1.2.8
7f1fd923f000-7f1fd9241000 r-xp 00000000 fd:00 2678                       /usr/lib64/libutil-2.24.so
7f1fd9241000-7f1fd9440000 ---p 00002000 fd:00 2678                       /usr/lib64/libutil-2.24.so
7f1fd9440000-7f1fd9441000 r--p 00001000 fd:00 2678                       /usr/lib64/libutil-2.24.so
7f1fd9441000-7f1fd9442000 rw-p 00002000 fd:00 2678                       /usr/lib64/libutil-2.24.so
7f1fd9442000-7f1fd9450000 r-xp 00000000 fd:00 778157                     /usr/lib64/liblber-2.4.so.2.10.7
7f1fd9450000-7f1fd964f000 ---p 0000e000 fd:00 778157                     /usr/lib64/liblber-2.4.so.2.10.7
7f1fd964f000-7f1fd9650000 r--p 0000d000 fd:00 778157                     /usr/lib64/liblber-2.4.so.2.10.7
7f1fd9650000-7f1fd9651000 rw-p 0000e000 fd:00 778157                     /usr/lib64/liblber-2.4.so.2.10.7
7f1fd9651000-7f1fd969f000 r-xp 00000000 fd:00 778159                     /usr/lib64/libldap-2.4.so.2.10.7
7f1fd969f000-7f1fd989e000 ---p 0004e000 fd:00 778159                     /usr/lib64/libldap-2.4.so.2.10.7
7f1fd989e000-7f1fd98a1000 r--p 0004d000 fd:00 778159                     /usr/lib64/libldap-2.4.so.2.10.7
7f1fd98a1000-7f1fd98a2000 rw-p 00050000 fd:00 778159                     /usr/lib64/libldap-2.4.so.2.10.7
7f1fd98a2000-7f1fd98a5000 r-xp 00000000 fd:00 505893                     /usr/lib64/libdl-2.24.so
7f1fd98a5000-7f1fd9aa4000 ---p 00003000 fd:00 505893                     /usr/lib64/libdl-2.24.so
7f1fd9aa4000-7f1fd9aa5000 r--p 00002000 fd:00 505893                     /usr/lib64/libdl-2.24.so
7f1fd9aa5000-7f1fd9aa6000 rw-p 00003000 fd:00 505893                     /usr/lib64/libdl-2.24.so
7f1fd9aa6000-7f1fd9cda000 r-xp 00000000 fd:00 160582                     /usr/lib64/libcrypto.so.1.0.2j
7f1fd9cda000-7f1fd9ed9000 ---p 00234000 fd:00 160582                     /usr/lib64/libcrypto.so.1.0.2j
7f1fd9ed9000-7f1fd9ef5000 r--p 00233000 fd:00 160582                     /usr/lib64/libcrypto.so.1.0.2j
7f1fd9ef5000-7f1fd9f02000 rw-p 0024f000 fd:00 160582                     /usr/lib64/libcrypto.so.1.0.2j
7f1fd9f02000-7f1fd9f06000 rw-p 00000000 00:00 0 
7f1fd9f06000-7f1fd9f29000 r-xp 00000000 fd:00 2737                       /usr/lib64/libselinux.so.1
7f1fd9f29000-7f1fda129000 ---p 00023000 fd:00 2737                       /usr/lib64/libselinux.so.1
7f1fda129000-7f1fda12a000 r--p 00023000 fd:00 2737                       /usr/lib64/libselinux.so.1
7f1fda12a000-7f1fda12b000 rw-p 00024000 fd:00 2737                       /usr/lib64/libselinux.so.1
7f1fda12b000-7f1fda12d000 rw-p 00000000 00:00 0 
7f1fda12d000-7f1fda12f000 r-xp 00000000 fd:00 819486                     /usr/lib64/libfipscheck.so.1.2.1
7f1fda12f000-7f1fda32e000 ---p 00002000 fd:00 819486                     /usr/lib64/libfipscheck.so.1.2.1
7f1fda32e000-7f1fda32f000 r--p 00001000 fd:00 819486                     /usr/lib64/libfipscheck.so.1.2.1
7f1fda32f000-7f1fda330000 rw-p 00000000 00:00 0 
7f1fda330000-7f1fda355000 r-xp 00000000 fd:00 2625                       /usr/lib64/ld-2.24.so
7f1fda50f000-7f1fda51e000 rw-p 00000000 00:00 0 
7f1fda54b000-7f1fda54c000 rw-p 00000000 00:00 0 
7f1fda54c000-7f1fda553000 r--s 00000000 fd:00 34137110                   /usr/lib64/gconv/gconv-modules.cache
7f1fda553000-7f1fda555000 rw-p 00000000 00:00 0 
7f1fda555000-7f1fda556000 r--p 00025000 fd:00 2625                       /usr/lib64/ld-2.24.so
7f1fda556000-7f1fda557000 rw-p 00026000 fd:00 2625                       /usr/lib64/ld-2.24.so
7f1fda557000-7f1fda558000 rw-p 00000000 00:00 0 
7ffd4e7d4000-7ffd4e7f6000 rw-p 00000000 00:00 0                          [stack]
7ffd4e7fc000-7ffd4e7fe000 r--p 00000000 00:00 0                          [vvar][112] 11902

And here's what gdb says with full debuginfo installed:

Thread 1 (Thread 0x7f1fda50f800 (LWP 11869)):
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:58
#1  0x00007f1fd7ee151a in __GI_abort () at abort.c:89
#2  0x00007f1fd7f23200 in __libc_message (do_abort=do_abort@entry=2,
    fmt=fmt@entry=0x7f1fd8037cd8 "*** Error in `%s': %s: 0x%s ***\n") at ../sysdeps/posix/libc_fatal.c:175
#3  0x00007f1fd7f2c88a in malloc_printerr (ar_ptr=<optimized out>, ptr=<optimized out>,
    str=0x7f1fd8037e30 "free(): invalid next size (normal)", action=3) at malloc.c:5046
#4  _int_free (av=<optimized out>, p=<optimized out>, have_lock=<optimized out>) at malloc.c:3902
#5  0x00007f1fd7f302bc in __GI___libc_free (mem=mem@entry=0x55d2847f8790) at malloc.c:2982
#6  0x00007f1fd61d5a9e in keyctl_read_alloc (id=40875571, _buffer=_buffer@entry=0x7ffd4e7f0220) at keyutils.c:302
#7  0x00007f1fd86dd328 in krcc_start_seq_get (context=context@entry=0x55d2847f5aa0, id=id@entry=0x55d284800900,
    cursor=cursor@entry=0x7ffd4e7f02b8) at cc_keyring.c:998
#8  0x00007f1fd86dd7ea in update_keyring_expiration (id=0x55d284800900, context=0x55d2847f5aa0) at cc_keyring.c:749
#9  krcc_store (context=0x55d2847f5aa0, id=0x55d284800900, creds=0x55d2847f9360) at cc_keyring.c:1322
#10 0x00007f1fd86df2a0 in krb5_cc_store_cred (context=context@entry=0x55d2847f5aa0, cache=0x55d284800900,
    creds=0x55d2847f9360) at ccfns.c:88
#11 0x00007f1fd86f01a3 in complete (context=context@entry=0x55d2847f5aa0, ctx=ctx@entry=0x55d2847f8040)
    at get_creds.c:443
#12 0x00007f1fd86f0fe9 in step_referrals (ctx=<optimized out>, context=<optimized out>) at get_creds.c:560
#13 krb5_tkt_creds_step (context=0x55d2847f5aa0, ctx=0x55d2847f8040, in=<optimized out>, out=<optimized out>,
    realm=<optimized out>, flags=<optimized out>) at get_creds.c:1252
#14 0x00007f1fd86f1aa8 in krb5_tkt_creds_get (context=context@entry=0x55d2847f5aa0, ctx=0x55d2847f8040)
    at get_creds.c:1190
#15 0x00007f1fd86f1bcc in krb5_get_credentials (context=context@entry=0x55d2847f5aa0, options=options@entry=0,
    ccache=<optimized out>, in_creds=in_creds@entry=0x7ffd4e7f0690, out_creds=out_creds@entry=0x7ffd4e7f0688)
    at get_creds.c:1279
#16 0x00007f1fd89b5da1 in get_credentials (server=<optimized out>, out_creds=<synthetic pointer>,
    endtime=<optimized out>, now=<optimized out>, cred=0x55d284801440, context=<optimized out>) at init_sec_context.c:195
#17 kg_new_connection (exts=0x7ffd4e7f0920, context=<optimized out>, time_rec=0x0, ret_flags=0x0,
    output_token=0x7ffd4e7f0ab0, actual_mech_type=0x0, input_token=<optimized out>, input_chan_bindings=0x0, time_req=0,
    req_flags=34, mech_type=0x7f1fd8bd5d00 <krb5_gss_oid_array>, target_name=<optimized out>,
    context_handle=0x55d2847f5c80, cred=0x55d284801440, minor_status=0x55d2847f5814) at init_sec_context.c:585
#18 krb5_gss_init_sec_context_ext (minor_status=minor_status@entry=0x55d2847f5814, claimant_cred_handle=0x55d284801440,
    claimant_cred_handle@entry=0x0, context_handle=context_handle@entry=0x55d2847f5c80, target_name=<optimized out>,
    mech_type=0x7f1fd8bd5d00 <krb5_gss_oid_array>, req_flags=req_flags@entry=34, time_req=0, input_chan_bindings=0x0,
    input_token=0x0, actual_mech_type=0x0, output_token=0x7ffd4e7f0ab0, ret_flags=0x0, time_rec=0x0, exts=0x7ffd4e7f0920)
    at init_sec_context.c:985
#19 0x00007f1fd89b65fb in krb5_gss_init_sec_context (minor_status=minor_status@entry=0x55d2847f5814,
    claimant_cred_handle=claimant_cred_handle@entry=0x0, context_handle=context_handle@entry=0x55d2847f5c80,
    target_name=<optimized out>, mech_type=<optimized out>, req_flags=req_flags@entry=34, time_req=0,
    input_chan_bindings=0x0, input_token=0x0, actual_mech_type=0x0, output_token=0x7ffd4e7f0ab0, ret_flags=0x0,
    time_rec=0x0) at init_sec_context.c:1087
#20 0x00007f1fd899fdf3 in gss_init_sec_context (minor_status=minor_status@entry=0x55d2847f5814,
    claimant_cred_handle=<optimized out>, context_handle=context_handle@entry=0x55d2847f5818,
    target_name=0x55d2847f5920, req_mech_type=<optimized out>, req_flags=34, time_req=0, input_chan_bindings=0x0,
    input_token=0x0, actual_mech_type=0x0, output_token=0x7ffd4e7f0ab0, ret_flags=0x0, time_rec=0x0)
    at g_init_sec_context.c:210
#21 0x000055d2835066cf in ssh_gssapi_init_ctx (ctx=0x55d2847f5810, deleg_creds=deleg_creds@entry=0,
    recv_tok=recv_tok@entry=0x0, send_tok=send_tok@entry=0x7ffd4e7f0ab0, flags=flags@entry=0x0) at gss-genr.c:357
#22 0x000055d2835069a5 in ssh_gssapi_check_mechanism (ctx=0x7ffd4e7f0aa8, ctx@entry=0x0, oid=<optimized out>,
    host=host@entry=0x55d2847f45e0 "ld77.e.math.uh.edu", client=client@entry=0x0) at gss-genr.c:481
#23 0x000055d283505e43 in ssh_gssapi_kex_mechs (gss_supported=0x55d2847f5500,
    check=check@entry=0x55d2835068c0 <ssh_gssapi_check_mechanism>, host=host@entry=0x55d2847f45e0 "ld77.e.math.uh.edu",
    client=client@entry=0x0, kex=kex@entry=0x55d2847e4d30 "gss-gex-sha1-,gss-group14-sha1-") at gss-genr.c:121
#24 0x000055d283506164 in ssh_gssapi_client_mechanisms (host=host@entry=0x55d2847f45e0 "ld77.e.math.uh.edu", client=0x0,
    kex=0x55d2847e4d30 "gss-gex-sha1-,gss-group14-sha1-") at gss-genr.c:88
#25 0x000055d2834d4d44 in ssh_kex2 (host=host@entry=0x55d2847e4e30 "ld77",
    hostaddr=hostaddr@entry=0x55d28376c4c0 <hostaddr>, port=port@entry=22) at sshconnect2.c:190
#26 0x000055d2834d1bcb in ssh_login (sensitive=0x55d28376c4a0 <sensitive_data>, orighost=<optimized out>,
    hostaddr=0x55d28376c4c0 <hostaddr>, port=<optimized out>, pw=<optimized out>, timeout_ms=-1000) at sshconnect.c:1389
#27 0x000055d2834c0d30 in main (ac=<optimized out>, av=<optimized out>) at ssh.c:1444

Comment 1 Jason Tibbitts 2017-01-19 16:58:46 UTC
Oops, this machine is currently running kernel-4.8.15-300.fc25.x86_64, openssh-7.4p1-1.fc25.x86_64 and krb5-libs-1.14.4-4.fc25.x86_64, glibc-2.24-4.fc25.x86_64.  Will try the 4.9 kernel series as soon as I have a chance to reboot.

Comment 2 Robbie Harwood 2017-01-19 17:24:07 UTC
Please let me know when you've tested the latest versions of things from fc25.  If you can reproduce it against rawhide's krb5 that would also be good to know; I can make a copr if needed.

Comment 3 Jason Tibbitts 2017-01-19 18:09:38 UTC
Besides the kernel, aren't those all the latest versions of everything?  I run with updates-testing enabled and see no updates to openssh*, krb5* or glibc*.

I can build the rawhide krb5 package, no problem.

Also note that I've been seeing this for quite some time; it's only now that I've found a few free minutes to try and figure out what's going on.

Comment 4 Robbie Harwood 2017-01-19 18:38:40 UTC
(In reply to Jason Tibbitts from comment #3)
> Besides the kernel, aren't those all the latest versions of everything?  I
> run with updates-testing enabled and see no updates to openssh*, krb5* or
> glibc*.

Think so; I misread and assumed you were waiting updates.

> Also note that I've been seeing this for quite some time; it's only now that
> I've found a few free minutes to try and figure out what's going on.

Good to know, thanks.

Comment 5 Jason Tibbitts 2017-01-19 19:26:43 UTC
Just rebooted into kernel-4.9.4-201.fc25.x86_64; no change in behavior.  (Hit it the first time I ran the ssh loop over 131 machines.)

I built the rawhide krb5 package, got rid of wine and its 32-bit lib requirements, and updated.  Not really much change, but if anything it's more prevalent now, so much so that I can't actually get a clean set of the glibc abort info to paste.  Sometimes over 10% of the ssh invocations fail (16 out of 131 calls in one example).

So here's a gdb backtrace of a random core.  If you do need the updated glibc abort output, let me know and I'll try to tweak the number of calls until I can catch a run with a failure that I can extract more easily.

Also, for some reason gdb wanted me to install more debuginfo packages this time.  Not sure why.

ἐπιθυμία:~❯ coredumpctl gdb 23438
           PID: 23438 (ssh)
           UID: 7225 (tibbs)
           GID: 7225 (tibbs)
        Signal: 6 (ABRT)
     Timestamp: Thu 2017-01-19 13:19:45 CST (5min ago)
  Command Line: ssh root@ld27 /bin/true
    Executable: /usr/bin/ssh
 Control Group: /user.slice/user-7225.slice/session-1.scope
          Unit: session-1.scope
         Slice: user-7225.slice
       Session: 1
     Owner UID: 7225 (tibbs)
       Boot ID: a465d9472c26400fb9b9f868f3e4d7d6
    Machine ID: 66adb4e0cc334c5f882963d6b0077b93
      Hostname: epithumia.math.uh.edu
      Coredump: /var/lib/systemd/coredump/core.ssh.7225.a465d9472c26400fb9b9f868f3e4d7d6.23438.1484853585000000000000.lz4
       Message: Process 23438 (ssh) of user 7225 dumped core.
                
                Stack trace of thread 23438:
                #0  0x00007f0145b0191f __GI_raise (libc.so.6)
                #1  0x00007f0145b0351a __GI_abort (libc.so.6)
                #2  0x00007f0145b45200 __libc_message (libc.so.6)
                #3  0x00007f0145b4e88a malloc_printerr (libc.so.6)
                #4  0x00007f0145b522bc __GI___libc_free (libc.so.6)
                #5  0x00007f0143df6a9e keyctl_read_alloc (libkeyutils.so.1)
                #6  0x00007f0146302438 krcc_start_seq_get (libkrb5.so.3)
                #7  0x00007f01463028fa update_keyring_expiration (libkrb5.so.3)
                #8  0x00007f01463043a0 krb5_cc_store_cred (libkrb5.so.3)
                #9  0x00007f0146315d03 complete (libkrb5.so.3)
                #10 0x00007f0146316b49 step_referrals (libkrb5.so.3)
                #11 0x00007f0146317608 krb5_tkt_creds_get (libkrb5.so.3)
                #12 0x00007f014631772c krb5_get_credentials (libkrb5.so.3)
                #13 0x00007f01465db9ac get_credentials (libgssapi_krb5.so.2)
                #14 0x00007f01465dc28b krb5_gss_init_sec_context (libgssapi_krb5.so.2)
                #15 0x00007f01465c5d13 gss_init_sec_context (libgssapi_krb5.so.2)
                #16 0x000055f39e8ec6cf ssh_gssapi_init_ctx (ssh)
                #17 0x000055f39e8ec9a5 ssh_gssapi_check_mechanism (ssh)
                #18 0x000055f39e8ebe43 ssh_gssapi_kex_mechs (ssh)
                #19 0x000055f39e8ec164 ssh_gssapi_client_mechanisms (ssh)
                #20 0x000055f39e8bad44 ssh_kex2 (ssh)
                #21 0x000055f39e8b7bcb ssh_login (ssh)
                #22 0x000055f39e8a6d30 main (ssh)
                #23 0x00007f0145aec401 __libc_start_main (libc.so.6)
                #24 0x000055f39e8a868a _start (ssh)

GNU gdb (GDB) Fedora 7.12-36.fc25
Copyright (C) 2017 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/bin/ssh...Reading symbols from /usr/lib/debug/usr/bin/ssh.debug...done.
done.
[New LWP 23438]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `ssh root@ld27 /bin/true'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:58
58      }
(gdb) thread apply all bt

Thread 1 (Thread 0x7f0148136800 (LWP 23438)):
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:58
#1  0x00007f0145b0351a in __GI_abort () at abort.c:89
#2  0x00007f0145b45200 in __libc_message (do_abort=do_abort@entry=2,
    fmt=fmt@entry=0x7f0145c59cd8 "*** Error in `%s': %s: 0x%s ***\n") at ../sysdeps/posix/libc_fatal.c:175
#3  0x00007f0145b4e88a in malloc_printerr (ar_ptr=<optimized out>, ptr=<optimized out>,
    str=0x7f0145c59d50 "free(): invalid next size (fast)", action=3) at malloc.c:5046
#4  _int_free (av=<optimized out>, p=<optimized out>, have_lock=<optimized out>) at malloc.c:3902
#5  0x00007f0145b522bc in __GI___libc_free (mem=mem@entry=0x55f39eb9b690) at malloc.c:2982
#6  0x00007f0143df6a9e in keyctl_read_alloc (id=572843864, _buffer=_buffer@entry=0x7fff2aefa380) at keyutils.c:302
#7  0x00007f0146302438 in krcc_start_seq_get (context=context@entry=0x55f39eb989e0, id=id@entry=0x55f39eb9b540,
    cursor=cursor@entry=0x7fff2aefa418) at cc_keyring.c:998
#8  0x00007f01463028fa in update_keyring_expiration (id=0x55f39eb9b540, context=0x55f39eb989e0) at cc_keyring.c:749
#9  krcc_store (context=0x55f39eb989e0, id=0x55f39eb9b540, creds=0x55f39eb9bf90) at cc_keyring.c:1322
#10 0x00007f01463043a0 in krb5_cc_store_cred (context=context@entry=0x55f39eb989e0, cache=0x55f39eb9b540,
    creds=0x55f39eb9bf90) at ccfns.c:88
#11 0x00007f0146315d03 in complete (context=context@entry=0x55f39eb989e0, ctx=ctx@entry=0x55f39eb9b2e0)
    at get_creds.c:443
#12 0x00007f0146316b49 in step_referrals (ctx=<optimized out>, context=<optimized out>) at get_creds.c:560
#13 krb5_tkt_creds_step (context=0x55f39eb989e0, ctx=0x55f39eb9b2e0, in=<optimized out>, out=<optimized out>,
    realm=<optimized out>, flags=<optimized out>) at get_creds.c:1252
#14 0x00007f0146317608 in krb5_tkt_creds_get (context=context@entry=0x55f39eb989e0, ctx=0x55f39eb9b2e0)
    at get_creds.c:1190
#15 0x00007f014631772c in krb5_get_credentials (context=context@entry=0x55f39eb989e0, options=0, ccache=<optimized out>,
    in_creds=in_creds@entry=0x7fff2aefa7f0, out_creds=out_creds@entry=0x7fff2aefa7e8) at get_creds.c:1279
#16 0x00007f01465db9ac in get_credentials (server=<optimized out>, out_creds=<synthetic pointer>,
    endtime=<optimized out>, now=<optimized out>, cred=0x55f39eba4380, context=<optimized out>) at init_sec_context.c:170
#17 kg_new_connection (exts=0x7fff2aefaa80, context=<optimized out>, time_rec=0x0, ret_flags=0x0,
    output_token=0x7fff2aefac10, actual_mech_type=0x0, input_token=<optimized out>, input_chan_bindings=0x0, time_req=0,
    req_flags=34, mech_type=0x7f01467fad00 <krb5_gss_oid_array>, target_name=<optimized out>,
    context_handle=0x55f39eb98bc0, cred=0x55f39eba4380, minor_status=0x55f39eb987d4) at init_sec_context.c:588
#18 krb5_gss_init_sec_context_ext (minor_status=minor_status@entry=0x55f39eb987d4, claimant_cred_handle=0x55f39eba4380,
    claimant_cred_handle@entry=0x0, context_handle=context_handle@entry=0x55f39eb98bc0, target_name=<optimized out>,
    mech_type=0x7f01467fad00 <krb5_gss_oid_array>, req_flags=req_flags@entry=34, time_req=0, input_chan_bindings=0x0,
    input_token=0x0, actual_mech_type=0x0, output_token=0x7fff2aefac10, ret_flags=0x0, time_rec=0x0, exts=0x7fff2aefaa80)
    at init_sec_context.c:988
#19 0x00007f01465dc28b in krb5_gss_init_sec_context (minor_status=minor_status@entry=0x55f39eb987d4,
    claimant_cred_handle=claimant_cred_handle@entry=0x0, context_handle=context_handle@entry=0x55f39eb98bc0,
    target_name=<optimized out>, mech_type=<optimized out>, req_flags=req_flags@entry=34, time_req=0,
    input_chan_bindings=0x0, input_token=0x0, actual_mech_type=0x0, output_token=0x7fff2aefac10, ret_flags=0x0,
    time_rec=0x0) at init_sec_context.c:1090
#20 0x00007f01465c5d13 in gss_init_sec_context (minor_status=minor_status@entry=0x55f39eb987d4,
    claimant_cred_handle=<optimized out>, context_handle=context_handle@entry=0x55f39eb987d8,
    target_name=0x55f39eb98880, req_mech_type=<optimized out>, req_flags=34, time_req=0, input_chan_bindings=0x0,
    input_token=0x0, actual_mech_type=0x0, output_token=0x7fff2aefac10, ret_flags=0x0, time_rec=0x0)
    at g_init_sec_context.c:210
#21 0x000055f39e8ec6cf in ssh_gssapi_init_ctx (ctx=0x55f39eb987d0, deleg_creds=deleg_creds@entry=0,
    recv_tok=recv_tok@entry=0x0, send_tok=send_tok@entry=0x7fff2aefac10, flags=flags@entry=0x0) at gss-genr.c:357
#22 0x000055f39e8ec9a5 in ssh_gssapi_check_mechanism (ctx=0x7fff2aefac08, ctx@entry=0x0, oid=<optimized out>,
    host=host@entry=0x55f39eb97580 "ld27.e.math.uh.edu", client=client@entry=0x0) at gss-genr.c:481
#23 0x000055f39e8ebe43 in ssh_gssapi_kex_mechs (gss_supported=0x55f39eb984a0,
    check=check@entry=0x55f39e8ec8c0 <ssh_gssapi_check_mechanism>, host=host@entry=0x55f39eb97580 "ld27.e.math.uh.edu",
    client=client@entry=0x0, kex=kex@entry=0x55f39eb87cd0 "gss-gex-sha1-,gss-group14-sha1-") at gss-genr.c:121
#24 0x000055f39e8ec164 in ssh_gssapi_client_mechanisms (host=host@entry=0x55f39eb97580 "ld27.e.math.uh.edu", client=0x0,
    kex=0x55f39eb87cd0 "gss-gex-sha1-,gss-group14-sha1-") at gss-genr.c:88
#25 0x000055f39e8bad44 in ssh_kex2 (host=host@entry=0x55f39eb87dd0 "ld27",
    hostaddr=hostaddr@entry=0x55f39eb524c0 <hostaddr>, port=port@entry=22) at sshconnect2.c:190
#26 0x000055f39e8b7bcb in ssh_login (sensitive=0x55f39eb524a0 <sensitive_data>, orighost=<optimized out>,
    hostaddr=0x55f39eb524c0 <hostaddr>, port=<optimized out>, pw=<optimized out>, timeout_ms=-1000) at sshconnect.c:1389
#27 0x000055f39e8a6d30 in main (ac=<optimized out>, av=<optimized out>) at ssh.c:1444
(gdb)

Comment 6 Jason Tibbitts 2017-01-19 19:35:03 UTC
Just looking at coredumpctl info output, I see that the backtraces aren't always consistent.  In case it helps to see multiple paths to the problematic code, here are a few (all from one run):

                Stack trace of thread 23469:
                #0  0x00007fd39a42491f __GI_raise (libc.so.6)
                #1  0x00007fd39a42651a __GI_abort (libc.so.6)
                #2  0x00007fd39a468200 __libc_message (libc.so.6)
                #3  0x00007fd39a47188a malloc_printerr (libc.so.6)
                #4  0x00007fd39a4752bc __GI___libc_free (libc.so.6)
                #5  0x00007fd398719a9e keyctl_read_alloc (libkeyutils.so.1)
                #6  0x00007fd39ac25438 krcc_start_seq_get (libkrb5.so.3)
                #7  0x00007fd39ac1c422 krb5_cccol_have_content (libkrb5.so.3)
                #8  0x00007fd39aef620f acquire_init_cred (libgssapi_krb5.so.2)
                #9  0x00007fd39aef6348 acquire_cred (libgssapi_krb5.so.2)
                #10 0x00007fd39aef645c krb5_gss_acquire_cred (libgssapi_krb5.so.2)
                #11 0x00007fd39aef9503 kg_get_defcred (libgssapi_krb5.so.2)
                #12 0x00007fd39aefe1b4 krb5_gss_init_sec_context_ext (libgssapi_krb5.so.2)
                #13 0x00007fd39aeff28b krb5_gss_init_sec_context (libgssapi_krb5.so.2)
                #14 0x00007fd39aee8d13 gss_init_sec_context (libgssapi_krb5.so.2)
                #15 0x00005571c6ea26cf ssh_gssapi_init_ctx (ssh)
                #16 0x00005571c6ea29a5 ssh_gssapi_check_mechanism (ssh)
                #17 0x00005571c6e6e635 userauth_gssapi (ssh)
                #18 0x00005571c6e71d18 userauth (ssh)
                #19 0x00005571c6e71e51 input_userauth_failure (ssh)
                #20 0x00005571c6e9b789 ssh_dispatch_run (ssh)
                #21 0x00005571c6e71726 ssh_userauth2 (ssh)
                #22 0x00005571c6e6dbdc ssh_login (ssh)
                #23 0x00005571c6e5cd30 main (ssh)
                #24 0x00007fd39a40f401 __libc_start_main (libc.so.6)
                #25 0x00005571c6e5e68a _start (ssh)


                Stack trace of thread 23509:
                #0  0x00007fcab943491f __GI_raise (libc.so.6)
                #1  0x00007fcab943651a __GI_abort (libc.so.6)
                #2  0x00007fcab9478200 __libc_message (libc.so.6)
                #3  0x00007fcab948188a malloc_printerr (libc.so.6)
                #4  0x00007fcab94852bc __GI___libc_free (libc.so.6)
                #5  0x00007fcab7729a9e keyctl_read_alloc (libkeyutils.so.1)
                #6  0x00007fcab9c35438 krcc_start_seq_get (libkrb5.so.3)
                #7  0x00007fcab9c2c422 krb5_cccol_have_content (libkrb5.so.3)
                #8  0x00007fcab9f0620f acquire_init_cred (libgssapi_krb5.so.2)
                #9  0x00007fcab9f06348 acquire_cred (libgssapi_krb5.so.2)
                #10 0x00007fcab9f0645c krb5_gss_acquire_cred (libgssapi_krb5.so.2)
                #11 0x00007fcab9f09503 kg_get_defcred (libgssapi_krb5.so.2)
                #12 0x00007fcab9f0e1b4 krb5_gss_init_sec_context_ext (libgssapi_krb5.so.2)
                #13 0x00007fcab9f0f28b krb5_gss_init_sec_context (libgssapi_krb5.so.2)
                #14 0x00007fcab9ef8d13 gss_init_sec_context (libgssapi_krb5.so.2)
                #15 0x000055e0718336cf ssh_gssapi_init_ctx (ssh)
                #16 0x000055e0718339a5 ssh_gssapi_check_mechanism (ssh)
                #17 0x000055e071832e43 ssh_gssapi_kex_mechs (ssh)
                #18 0x000055e071833164 ssh_gssapi_client_mechanisms (ssh)
                #19 0x000055e071801d44 ssh_kex2 (ssh)
                #20 0x000055e0717febcb ssh_login (ssh)
                #21 0x000055e0717edd30 main (ssh)
                #22 0x00007fcab941f401 __libc_start_main (libc.so.6)
                #23 0x000055e0717ef68a _start (ssh)


                Stack trace of thread 23507:
                #0  0x00007ff01697c91f __GI_raise (libc.so.6)
                #1  0x00007ff01697e51a __GI_abort (libc.so.6)
                #2  0x00007ff0169c0200 __libc_message (libc.so.6)
                #3  0x00007ff0169c988a malloc_printerr (libc.so.6)
                #4  0x00007ff0169cd2bc __GI___libc_free (libc.so.6)
                #5  0x00007ff014c71a9e keyctl_read_alloc (libkeyutils.so.1)
                #6  0x00007ff01717d438 krcc_start_seq_get (libkrb5.so.3)
                #7  0x00007ff017177dc0 krb5_cc_retrieve_cred_seq (libkrb5.so.3)
                #8  0x00007ff017178212 k5_cc_retrieve_cred_default (libkrb5.so.3)
                #9  0x00007ff01717f0d4 krb5_cc_retrieve_cred (libkrb5.so.3)
                #10 0x00007ff0171908ff cache_get (libkrb5.so.3)
                #11 0x00007ff017191e59 check_cache (libkrb5.so.3)
                #12 0x00007ff017192608 krb5_tkt_creds_get (libkrb5.so.3)
                #13 0x00007ff01719272c krb5_get_credentials (libkrb5.so.3)
                #14 0x00007ff01745305d iakerb_get_initial_state (libgssapi_krb5.so.2)
                #15 0x00007ff017440d13 gss_init_sec_context (libgssapi_krb5.so.2)
                #16 0x0000558d823e66cf ssh_gssapi_init_ctx (ssh)
                #17 0x0000558d823e69a5 ssh_gssapi_check_mechanism (ssh)
                #18 0x0000558d823e5e43 ssh_gssapi_kex_mechs (ssh)
                #19 0x0000558d823e6164 ssh_gssapi_client_mechanisms (ssh)
                #20 0x0000558d823b4d44 ssh_kex2 (ssh)
                #21 0x0000558d823b1bcb ssh_login (ssh)
                #22 0x0000558d823a0d30 main (ssh)
                #23 0x00007ff016967401 __libc_start_main (libc.so.6)
                #24 0x0000558d823a268a _start (ssh)


                Stack trace of thread 23511:
                #0  0x00007f7dd728891f __GI_raise (libc.so.6)
                #1  0x00007f7dd728a51a __GI_abort (libc.so.6)
                #2  0x00007f7dd72cc200 __libc_message (libc.so.6)
                #3  0x00007f7dd72d588a malloc_printerr (libc.so.6)
                #4  0x00007f7dd72d92bc __GI___libc_free (libc.so.6)
                #5  0x00007f7dd557da9e keyctl_read_alloc (libkeyutils.so.1)
                #6  0x00007f7dd7a89438 krcc_start_seq_get (libkrb5.so.3)
                #7  0x00007f7dd7a83dc0 krb5_cc_retrieve_cred_seq (libkrb5.so.3)
                #8  0x00007f7dd7a84212 k5_cc_retrieve_cred_default (libkrb5.so.3)
                #9  0x00007f7dd7a8b0d4 krb5_cc_retrieve_cred (libkrb5.so.3)
                #10 0x00007f7dd7a9c8ff cache_get (libkrb5.so.3)
                #11 0x00007f7dd7a9d268 get_cached_local_tgt (libkrb5.so.3)
                #12 0x00007f7dd7a9dd7c begin (libkrb5.so.3)
                #13 0x00007f7dd7a9e608 krb5_tkt_creds_get (libkrb5.so.3)
                #14 0x00007f7dd7a9e72c krb5_get_credentials (libkrb5.so.3)
                #15 0x00007f7dd7d629ac get_credentials (libgssapi_krb5.so.2)
                #16 0x00007f7dd7d6328b krb5_gss_init_sec_context (libgssapi_krb5.so.2)
                #17 0x00007f7dd7d4cd13 gss_init_sec_context (libgssapi_krb5.so.2)
                #18 0x000055b4dc7b66cf ssh_gssapi_init_ctx (ssh)
                #19 0x000055b4dc7b69a5 ssh_gssapi_check_mechanism (ssh)
                #20 0x000055b4dc7b5e43 ssh_gssapi_kex_mechs (ssh)
                #21 0x000055b4dc7b6164 ssh_gssapi_client_mechanisms (ssh)
                #22 0x000055b4dc784d44 ssh_kex2 (ssh)
                #23 0x000055b4dc781bcb ssh_login (ssh)
                #24 0x000055b4dc770d30 main (ssh)
                #25 0x00007f7dd7273401 __libc_start_main (libc.so.6)
                #26 0x000055b4dc77268a _start (ssh)

Comment 7 Robbie Harwood 2017-01-23 21:04:33 UTC
The free in question is internal to keyutils (keyctl_read_alloc) and looks to be triggered on the retry path.  We enter it here, if it helps: https://github.com/krb5/krb5/blob/krb5-1.15-final/src/lib/krb5/ccache/cc_keyring.c#L998

krb5 isn't passing anything in that would be expected to be `free()`d here, so I don't think this is something we can fix.  I don't have a reproducer, but please let me know if there's anything I can do to help.

Comment 8 Jason Tibbitts 2017-01-24 00:38:35 UTC
Yeah, sorry, it wasn't until just this morning that I realized that keyutils.so is something separate from krb5.

I'd think you'd need a whole lot of hosts in order to be be able to reproduce this, and there are possibly issues related to timing as well.  But it's trivial for me to test, so I'm happy to try out any patches or even just "try changing this line in foo.c to..." kind of suggestions.  I have no problem patching and building my own stuff.

Comment 9 Jason Tibbitts 2017-08-23 21:37:30 UTC
For what it's worth, this is still present in F26.

Comment 10 Fedora End Of Life 2018-05-03 08:09:55 UTC
This message is a reminder that Fedora 26 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 26. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as EOL if it remains open with a Fedora  'version'
of '26'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version'
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not
able to fix it before Fedora 26 is end of life. If you would still like
to see this bug fixed and are able to reproduce it against a later version
of Fedora, you are encouraged  change the 'version' to a later Fedora
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's
lifetime, sometimes those efforts are overtaken by events. Often a
more recent Fedora release includes newer upstream software that fixes
bugs or makes them obsolete.

Comment 11 Fedora End Of Life 2018-05-29 11:24:02 UTC
Fedora 26 changed to end-of-life (EOL) status on 2018-05-29. Fedora 26
is no longer maintained, which means that it will not receive any
further security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.


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