Bug 1496467

Summary: Regression: SSH AuthorizedKeysCommand hangs when output is too large
Product: Red Hat Enterprise Linux 7 Reporter: Konrad Mosoń <mosonkonrad>
Component: opensshAssignee: Jakub Jelen <jjelen>
Status: CLOSED ERRATA QA Contact: Stefan Dordevic <sdordevi>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 7.4CC: dennis.schridde, nmavrogi, sdordevi
Target Milestone: rc   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: openssh-7.4p1-15.el7 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-04-10 18:19:11 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:
Embargoed:
Bug Depends On:    
Bug Blocks: 1476743    
Attachments:
Description Flags
Patch for specfile none

Description Konrad Mosoń 2017-09-27 13:29:01 UTC
Description of problem:

We use GitLab which has a lot of entries in it's authorized_keys. We also use AuthorizedKeysCommand which parses authorized_keys along with other files. Unfortunately it stopped working after upgrade to RHEL 7.4 cause pipe hungs.

I trimmed GitLab's authorized_keys only for testing to my entry and then login worked.


Version-Release number of selected component (if applicable):
openssh-7.4p1-12.el7_4.x86_64


How reproducible:
Always when authorized_keys is big (not sure how big it must be, mine is 119K big)


Steps to Reproduce:
1. Install RHEL 7.4

2. Create authorized_keys large enough.

3. Reconfigure sshd_config adding:
-------
AuthorizedKeysCommand /usr/libexec/openssh/ssh-pubkey-helper
AuthorizedKeysCommandUser root
--------

4. Create helper script:
--------
#!/bin/bash

USER=$1
HOME=`getent passwd $USER | cut -d: -f6`

if [ -f $HOME/.ssh/authorized_keys ]; then
	cat $HOME/.ssh/authorized_keys*
fi
--------

5. Try to login.


Actual results:
SSH connection hungs, and later fails with "Authentication failed" message.

This is strace from broken SSH:

--------
[pid 32328] <... read resumed> "", 128) = 0
[pid 32328] --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=32329, si_uid=0, si_status=0, si_utime=0, si_stime=0} ---
[pid 32328] wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WNOHANG, NULL) = 32329
[pid 32328] wait4(-1, 0x7ffecd2a9d90, WNOHANG, NULL) = -1 ECHILD (No child processes)
[pid 32328] rt_sigreturn({mask=[]})     = 0
[pid 32328] close(3)                    = 0
[pid 32328] rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 32328] rt_sigaction(SIGINT, {0x43e780, [], SA_RESTORER, 0x7fe385314270}, {SIG_DFL, [], SA_RESTORER, 0x7fe385314270}, 8) = 0
[pid 32328] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 32328] rt_sigaction(SIGINT, {SIG_DFL, [], SA_RESTORER, 0x7fe385314270}, {0x43e780, [], SA_RESTORER, 0x7fe385314270}, 8) = 0
[pid 32328] rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
[pid 32328] read(255, "\nif [ -f $HOME/.ssh/authorized_keys ]; then\n\tcat $HOME/.ssh/authorized_keys*\nfi\n", 142) = 80
[pid 32328] rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
[pid 32328] rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
[pid 32328] stat("/var/opt/gitlab/.ssh/authorized_keys", {st_mode=S_IFREG|0644, st_size=121632, ...}) = 0
[pid 32328] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 32328] openat(AT_FDCWD, "/var/opt/gitlab/.ssh/", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 3
[pid 32328] getdents(3, /* 4 entries */, 32768) = 128
[pid 32328] getdents(3, /* 0 entries */, 32768) = 0
[pid 32328] close(3)                    = 0
[pid 32328] stat(".", {st_mode=S_IFDIR|0555, st_size=4096, ...}) = 0
[pid 32328] stat("/usr/local/bin/cat", 0x7ffecd2aa470) = -1 ENOENT (No such file or directory)
[pid 32328] stat("/usr/bin/cat", {st_mode=S_IFREG|0755, st_size=54080, ...}) = 0
[pid 32328] stat("/usr/bin/cat", {st_mode=S_IFREG|0755, st_size=54080, ...}) = 0
[pid 32328] geteuid()                   = 0
[pid 32328] getegid()                   = 0
[pid 32328] getuid()                    = 0
[pid 32328] getgid()                    = 0
[pid 32328] access("/usr/bin/cat", X_OK) = 0
[pid 32328] stat("/usr/bin/cat", {st_mode=S_IFREG|0755, st_size=54080, ...}) = 0
[pid 32328] geteuid()                   = 0
[pid 32328] getegid()                   = 0
[pid 32328] getuid()                    = 0
[pid 32328] getgid()                    = 0
[pid 32328] access("/usr/bin/cat", R_OK) = 0
[pid 32328] stat("/usr/bin/cat", {st_mode=S_IFREG|0755, st_size=54080, ...}) = 0
[pid 32328] stat("/usr/bin/cat", {st_mode=S_IFREG|0755, st_size=54080, ...}) = 0
[pid 32328] geteuid()                   = 0
[pid 32328] getegid()                   = 0
[pid 32328] getuid()                    = 0
[pid 32328] getgid()                    = 0
[pid 32328] access("/usr/bin/cat", X_OK) = 0
[pid 32328] stat("/usr/bin/cat", {st_mode=S_IFREG|0755, st_size=54080, ...}) = 0
[pid 32328] geteuid()                   = 0
[pid 32328] getegid()                   = 0
[pid 32328] getuid()                    = 0
[pid 32328] getgid()                    = 0
[pid 32328] access("/usr/bin/cat", R_OK) = 0
[pid 32328] rt_sigprocmask(SIG_BLOCK, [INT CHLD], [], 8) = 0
[pid 32328] rt_sigprocmask(SIG_BLOCK, [CHLD], [INT CHLD], 8) = 0
[pid 32328] rt_sigprocmask(SIG_SETMASK, [INT CHLD], NULL, 8) = 0
[pid 32328] clone(strace: Process 32332 attached
child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7fe385ce4a10) = 32332
[pid 32332] close(255 <unfinished ...>
[pid 32328] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 32328] rt_sigprocmask(SIG_BLOCK, [CHLD],  <unfinished ...>
[pid 32332] <... close resumed> )       = 0
[pid 32328] <... rt_sigprocmask resumed> [], 8) = 0
[pid 32328] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 32328] rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 32328] rt_sigaction(SIGINT, {0x43e780, [], SA_RESTORER, 0x7fe385314270},  <unfinished ...>
[pid 32332] rt_sigprocmask(SIG_SETMASK, [],  <unfinished ...>
[pid 32328] <... rt_sigaction resumed> {SIG_DFL, [], SA_RESTORER, 0x7fe385314270}, 8) = 0
[pid 32332] <... rt_sigprocmask resumed> NULL, 8) = 0
[pid 32328] wait4(-1,  <unfinished ...>
[pid 32332] rt_sigaction(SIGTSTP, {SIG_DFL, [], SA_RESTORER, 0x7fe385314270}, {SIG_DFL, [], 0}, 8) = 0
[pid 32332] rt_sigaction(SIGTTIN, {SIG_DFL, [], SA_RESTORER, 0x7fe385314270}, {SIG_DFL, [], 0}, 8) = 0
[pid 32332] rt_sigaction(SIGTTOU, {SIG_DFL, [], SA_RESTORER, 0x7fe385314270}, {SIG_DFL, [], 0}, 8) = 0
[pid 32332] rt_sigaction(SIGINT, {SIG_DFL, [], SA_RESTORER, 0x7fe385314270}, {SIG_DFL, [], SA_RESTORER, 0x7fe385314270}, 8) = 0
[pid 32332] rt_sigaction(SIGQUIT, {SIG_DFL, [], SA_RESTORER, 0x7fe385314270}, {SIG_IGN, [], SA_RESTORER, 0x7fe385314270}, 8) = 0
[pid 32332] rt_sigaction(SIGCHLD, {SIG_DFL, [], SA_RESTORER|SA_RESTART, 0x7fe385314270}, {0x441310, [], SA_RESTORER|SA_RESTART, 0x7fe385314270}, 8) = 0
[pid 32332] execve("/usr/bin/cat", ["cat", "/var/opt/gitlab/.ssh/authorized_keys"], [/* 8 vars */]) = 0
[pid 32332] brk(NULL)                   = 0x2395000
[pid 32332] mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f7e2df83000
[pid 32332] access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
[pid 32332] open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
[pid 32332] fstat(3, {st_mode=S_IFREG|0644, st_size=34276, ...}) = 0
[pid 32332] mmap(NULL, 34276, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f7e2df7a000
[pid 32332] close(3)                    = 0
[pid 32332] open("/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
[pid 32332] read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\20\35\2\0\0\0\0\0@\0\0\0\0\0\0\0(c \0\0\0\0\0\0\0\0\0@\0008\0\n\0@\0K\0J\0\6\0\0\0\5\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0000\2\0\0\0\0\0\0000\2\0\0\0\0\0\0\10\0\0\0\0\0\0\0\3\0\0\0\4\0\0\0\240I\30\0\0\0\0\0\240I\30\0\0\0\0\0\240I\30\0\0\0\0\0\34\0\0\0\0\0\0\0\34\0\0\0\0\0\0\0\20\0\0\0\0\0\0\0\1\0\0\0\5\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\224}\33\0\0\0\0\0\224}\33\0\0\0\0\0\0\0 \0\0\0\0\0\1\0\0\0\6\0\0\0000\207\33\0\0\0\0\0000\207;\0\0\0\0\0000\207;\0\0\0\0\0pQ\0\0\0\0\0\0\220\232\0\0\0\0\0\0\0\0 \0\0\0\0\0\2\0\0\0\6\0\0\0\200\273\33\0\0\0\0\0\200\273;\0\0\0\0\0\200\273;\0\0\0\0\0\360\1\0\0\0\0\0\0\360\1\0\0\0\0\0\0\10\0\0\0\0\0\0\0\4\0\0\0\4\0\0\0p\2\0\0\0\0\0\0p\2\0\0\0\0\0\0p\2\0\0\0\0\0\0D\0\0\0\0\0\0\0D\0\0\0\0\0\0\0\4\0\0\0\0\0\0\0\7\0\0\0\4\0\0\0000\207\33\0\0\0\0\0000\207;\0\0\0\0\0000\207;\0\0\0\0\0\20\0\0\0\0\0\0\0\220\0\0\0\0\0\0\0\20\0\0\0\0\0\0\0P\345td\4\0\0\0\274I\30\0\0\0\0\0\274I\30\0\0\0\0\0\274I\30\0\0\0\0\0004i\0\0\0\0\0\0004i\0\0\0\0\0\0\4\0\0\0\0\0\0\0Q\345td\6\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\20\0\0\0\0\0\0\0R\345td\4\0\0\0000\207\33\0\0\0\0\0000\207;\0\0\0\0\0000\207;\0\0\0\0\0\3208\0\0\0\0\0\0\3208\0\0\0\0\0\0\1\0\0\0\0\0\0\0\4\0\0\0\24\0\0\0\3\0\0\0GNU\0\303\362\210\0021J\364\356\206k\370\322\341\265\6\267\273\363L\366\4\0\0\0\20\0"..., 832) = 832
[pid 32332] fstat(3, {st_mode=S_IFREG|0755, st_size=2127336, ...}) = 0
[pid 32332] mmap(NULL, 3940800, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f7e2d9a0000
[pid 32332] mprotect(0x7f7e2db58000, 2097152, PROT_NONE) = 0
[pid 32332] mmap(0x7f7e2dd58000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1b8000) = 0x7f7e2dd58000
[pid 32332] mmap(0x7f7e2dd5e000, 16832, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f7e2dd5e000
[pid 32332] close(3)                    = 0
[pid 32332] mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f7e2df79000
[pid 32332] mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f7e2df77000
[pid 32332] arch_prctl(ARCH_SET_FS, 0x7f7e2df77740) = 0
[pid 32332] mprotect(0x7f7e2dd58000, 16384, PROT_READ) = 0
[pid 32332] mprotect(0x60b000, 4096, PROT_READ) = 0
[pid 32332] mprotect(0x7f7e2df84000, 4096, PROT_READ) = 0
[pid 32332] munmap(0x7f7e2df7a000, 34276) = 0
[pid 32332] brk(NULL)                   = 0x2395000
[pid 32332] brk(0x23b6000)              = 0x23b6000
[pid 32332] brk(NULL)                   = 0x23b6000
[pid 32332] open("/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
[pid 32332] fstat(3, {st_mode=S_IFREG|0644, st_size=106070960, ...}) = 0
[pid 32332] mmap(NULL, 106070960, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f7e27477000
[pid 32332] close(3)                    = 0
[pid 32332] fstat(1, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0
[pid 32332] open("/var/opt/gitlab/.ssh/authorized_keys", O_RDONLY) = 3
[pid 32332] fstat(3, {st_mode=S_IFREG|0644, st_size=121632, ...}) = 0
[pid 32332] fadvise64(3, 0, 0, POSIX_FADV_SEQUENTIAL) = 0
[pid 32332] read(3, "# Managed by gitlab-shell\ncommand=\"/opt/gitlab/embedded/service/gitlab-shell/bin/gitlab-shell key-5\",no-port-forwarding,no-X11-forwarding,no-agent-forwarding,no-pty ssh-rsa <CENSORED>\ncommand=\"/opt/gitlab/embedded/service/gitlab-shell/bin/gitlab-shell key-11\",no-port-forwarding,no-X11-forwarding,no-agen"..., 65536) = 65536
[pid 32332] write(1, "# Managed by gitlab-shell\ncommand=\"/opt/gitlab/embedded/service/gitlab-shell/bin/gitlab-shell key-5\",no-port-forwarding,no-X11-forwarding,no-agent-forwarding,no-pty ssh-rsa <CENSORED>\ncommand=\"/opt/gitlab/embedded/service/gitlab-shell/bin/gitlab-shell key-11\",no-port-forwarding,no-X11-forwarding,no-agen"..., 65536) = 65536
[pid 32327] <... read resumed> "# Managed by gitlab-shell\ncommand=\"/opt/gitlab/embedded/service/gitlab-shell/bin/gitlab-shell key-5\",no-port-forwarding,no-X11-forwarding,no-agent-forwarding,no-pty ssh-rsa <CENSORED>\ncommand=\"/opt/gitlab/embedded/service/gitlab-shell/bin/gitlab-shell key-11\",no-port-forwarding,no-X11-forwarding,no-agen"..., 4096) = 4096
[pid 32327] read(4, "itlab-shell key-20\",no-port-forwarding,no-X11-forwarding,no-agent-forwarding,no-pty ssh-rsa <CENSORED>\ncommand=\"/opt/gitlab/embedded/service/gitlab-shell/bin/gitlab-shell key-21\",no-port-forwarding,no-X11-forwarding,no-agent-forwarding,no-pty ssh-rsa <CENSORED>"..., 4096) = 4096
[pid 32327] read(4, "<CENSORED>\ncommand=\"/opt/gitlab/embedded/service/gitlab-shell/bin/gitlab-shell key-35\",no-port-forwarding,no-X11-forwarding,no-agent-forwarding,no-pty ssh-dss <CENSORED>"..., 4096) = 4096
[pid 32327] read(4, "<CENSORED>\ncommand=\"/opt/gitlab/embedded/service/gitlab-shell/bin/gitlab-shell key-55\",no-port-forwarding,no-X11-forwarding,no-agent-forwarding,no-pty ssh-rsa <CENSORED>\ncommand=\"/opt/gitlab/"..., 4096) = 4096
[pid 32327] wait4(32328,  <unfinished ...>
[pid 32332] read(3, "<CENSORED>\ncommand=\"/opt/gitlab/embedded/service/gitlab-shell/bin/gitlab-shell key-213\",no-port-forwarding,no-X11-forwarding,no-agent-forwarding,no-pty ssh-rsa <CENSORED>\ncommand=\"/opt/gitlab/embedded/service/gitlab-shell/bin/gitlab-shell key-214\",no-port-forwarding,no-X11-forwarding,no-agent-for"..., 65536) = 56096
[pid 32332] write(1, "<CENSORED>\ncommand=\"/opt/gitlab/embedded/service/gitlab-shell/bin/gitlab-shell key-213\",no-port-forwarding,no-X11-forwarding,no-agent-forwarding,no-pty ssh-rsa <CENSORED>\ncommand=\"/opt/gitlab/embedded/service/gitlab-shell/bin/gitlab-shell key-214\",no-port-forwarding,no-X11-forwarding,no-agent-for"..., 56096

!! >>---- HERE IT HANGS ----<< !!

^Cstrace: Process 32305 detached
strace: Process 32327 detached
strace: Process 32328 detached
strace: Process 32332 detached
 <detached ...>
--------



Expected results:
Login should working like it works in openssh-6.6.1p1-35.el7_3.x86_64


Additional info:

Downgrading to openssh-6.6.1p1-35.el7_3.x86_64 from RHEL 7.3 workaround this problem at the moment.

Comment 2 Jakub Jelen 2017-09-27 13:56:58 UTC
Looking through the upstream bug [1], it looks like it was not completely fixed in 7.4 to which we rebased and there is single change needed to make it working again [2].

Can you verify that this this patch will fix the problem for you? If you wish a testing package or you would like to prioritize this effort, please contact you Red Hat Support.

[1] https://bugzilla.mindrot.org/show_bug.cgi?id=2496
[2] https://github.com/openssh/openssh-portable/commit/ddd3d34e

Comment 3 Konrad Mosoń 2017-10-03 12:14:09 UTC
Just tested this patch, and OpenSSH with our script works correctly with it. I can login now to Git account via SSH.

I'm attaching patch for specfile I used to test this (openssh-7.4p1-fix-authkeys-script-pipe.patch is directly downloaded commit from GitHub [2]).

Comment 4 Konrad Mosoń 2017-10-03 12:14:41 UTC
Created attachment 1333620 [details]
Patch for specfile

Comment 11 errata-xmlrpc 2018-04-10 18:19:11 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.

https://access.redhat.com/errata/RHSA-2018:0980