Page MenuHome GnuPG

ssh-import.scm fails during "make check" with gnupg 2.1.19
Closed, ResolvedPublic

Description

2.1.18 did not have this problem, and the tests completed successfully within
the sandboxed Homebrew build environment.

With 2.1.19, ssh-import.scm fails unless I build with --no-sandbox. If this
cannot be resolved, I will have to disable "make check" since all builds must be
sandboxed in homebrew/core.

I believe the failure is

Executing: '/usr/bin/ssh-add' '-l' '-E' 'md5'
error fetching identities for protocol 1: agent refused operation
error fetching identities for protocol 2: agent refused operation

Full log is here: https://gist.github.com/ilovezfs/b10da795bc4a7315233b23cfafabdcd9

Also attached.

(Note that I have run "make install" before "make check" in order to avoid the
failure in T2979.)

Details

Version
2.1.19

Event Timeline

This seems indeed a different problem than 2979.

SSH_AUTH_SOCK seems not to be set. I would suggest to try

mkdir /run/user/YOURUID
chown YOURUID /run/user/YOURUID

and try again.

justus added a subscriber: justus.

2.1.18 did not have this problem, and the tests completed successfully within
the sandboxed Homebrew build environment.

Your T2947 says otherwise. So does T2847. Can you please clarify that?

This is the interesting part of the log:

Importing ssh keys...

> dsa Executing: '/usr/bin/ssh-add' '-'

Identity added: (stdin) ((stdin))
Executing: '/usr/bin/ssh-add' '-l' '-E' 'md5'
rsa Executing: '/usr/bin/ssh-add' '-'
Identity added: (stdin) ((stdin))
Executing: '/usr/bin/ssh-add' '-l' '-E' 'md5'
ecdsa Executing: '/usr/bin/ssh-add' '-'
Identity added: (stdin) ((stdin))
Executing: '/usr/bin/ssh-add' '-l' '-E' 'md5'
error fetching identities for protocol 1: agent refused operation
error fetching identities for protocol 2: agent refused operation

So, what happens for 'dsa', 'rsa', 'ecdsa' is that first the key is added, then
with ssh-add -l we check that it is in fact added. This works for dsa and rsa,
but fails for ecdsa.

Can you please give us ssh -V, and describe the sandbox environment? Does it
affect which ssh version is used?

Your T2947 says otherwise. So does T2847. Can you please clarify that?

Sure. I'm referring to 2.1.18 with your subsequent fixes. See
https://github.com/Homebrew/homebrew-versions/commit/8243792932da5b7746bf229d4b63abd7592b21b3
which has the relevant patches (thank you) on the left side of the diff.

Oh cool, so that patch was effective :)

Yup! And remember, that was only a <= 10.10 issue, whereas the new "fun" is
across the board, 10.10, 10.11, and 10.12 (probably <= 10.9 too but we don't
test those).

mkdir /run/user/YOURUID

/run is not a thing on macOS. /var/run is but requires root access. The default
socket location on macOS is

iMac-TMP:~ joe$ ls -al /tmp/com.apple.launchd.OWt2QNcw7V
total 0
drwx------   2 joe   wheel   102 Mar  1 21:13 .
drwxrwxrwt  76 root  wheel  2686 Mar  2 00:44 ..
srw-rw-rw-   1 joe   admin     0 Mar  1 21:13 Listeners

One such directory and socket are created for each user when using ssh.

Note that I had tried hacking in /usr/local/var/run in place of your /run, and
creating the directory, etc., which the test did proceed to use but it didn't
resolve the problem. (I had done that before reporting here.)

This is not about socket directories, and SSH_AUTH_SOCK is set properly (as
demonstrated by the fact that dsa and rsa works).

Can you please give us ssh -V, and describe the sandbox environment? Does it
affect which ssh version is used?

(I'm mildly annoyed that I have to ask again. You are not forthcoming with
information about your environment. macOS is somewhat alien for us, and if you
want help with tracking down the issue, you need to give us more information.
Note that we really do make an effort, and we have a macOS build slave that does
not see these issues:

https://jenkins.gnupg.org/job/gnupg/XTARGET=native,label=macos/

(though we get our build dependencies from pkgsrc, and you get it from your
packages I guess, so there are bound to be differences).)

From your latest log I see that the version of ssh used supports ed25519, so
this must be version newer than 6.5.

I just committed a patch that dumps the ssh version and the path to the binary
when executing the test:

https://git.gnupg.org/cgi-bin/gitweb.cgi?p=gnupg.git;a=commitdiff;h=74cb3b230c1f99afc5fd09bccc24186a63b154b0

Can you please give us ssh -V, and describe the sandbox environment? Does it
affect which ssh version is used?

It's the system default. There's no other version of ssh that gets installed.
Our own ssh formula is homebrew/dupes/openssh and is explicitly barred from
being used as a dependency by anything else, as is anything else in homebrew/dupes.

10.12.3
robotunicorn ~ # ssh -V
OpenSSH_7.3p1, LibreSSL 2.4.1

10.11.6
iMac-TMP:~ joe$ ssh -V
OpenSSH_6.9p1, LibreSSL 2.1.8

yosemitevm ~ # ssh -V
OpenSSH_6.2p2, OSSLShim 0.9.8r 8 Dec 2011

Regarding the sandbox, here's where it's implemented:
https://github.com/Homebrew/brew/blob/master/Library/Homebrew/sandbox.rb

It's invoked as

/usr/bin/sandbox-exec -f /tmp/homebrew20170302-24230-1xmlw7l.sb nice
/System/Library/Frameworks/Ruby.framework/Versions/2.0/usr/bin/ruby -W0 -I
/usr/local/Homebrew/Library/Homebrew --
/usr/local/Homebrew/Library/Homebrew/build.rb
/usr/local/Homebrew/Library/Taps/homebrew/homebrew-versions/gnupg21.rb

The contents of the .sb file are as follows:

iMac-TMP:~ joe$ cat /tmp/homebrew20170302-24230-1xmlw7l.sb
(version 1)
(debug deny) ; log all denied operations to /var/log/system.log
(allow file-write* (subpath "/private/tmp"))
(allow file-write* (subpath "/private/var/tmp"))
(allow file-write* (regex #"^/private/var/folders/[^/]+/[^/]+/[C,T]/"))
(allow file-write* (subpath "/private/tmp"))
(allow file-write* (subpath "/Users/joe/Library/Caches/Homebrew"))
(allow file-write* (subpath "/Users/joe/Library/Logs/Homebrew/gnupg21"))
(allow file-write* (subpath "/Users/joe/Library/Developer"))
(allow file-write* (subpath "/usr/local/Cellar/gnupg21"))
(allow file-write* (subpath "/usr/local/etc"))
(allow file-write* (subpath "/usr/local/var"))
(allow file-write*
    (literal "/dev/ptmx")
    (literal "/dev/dtracehelper")
    (literal "/dev/null")
    (literal "/dev/zero")
    (regex #"^/dev/fd/[0-9]+$")
    (regex #"^/dev/ttys?[0-9]*$")
    )
(deny file-write*) ; deny non-whitelist file write operations
(allow process-exec
    (literal "/bin/ps")
    (with no-sandbox)
    ) ; allow certain processes running without sandbox
(allow default) ; allow everything else

The environment variables themselves are not different between sandboxed and
non-sandboxed builds.

Here's what's happening in the system log when the failed test runs:

Mar  2 03:06:53 iMac-TMP com.apple.xpc.launchd[1] (com.apple.auditd[39537])
<Warning>: Endpoint has been activated through legacy launch(3) APIs. Please
switch to XPC or bootstrap_check_in(): com.apple.auditd
Mar  2 03:06:53 iMac-TMP com.apple.ctkpcscd[39536] <Notice>:
SecTaskLoadEntitlements failed error=22
Mar  2 03:06:53 iMac-TMP com.apple.ctkpcscd[39536] <Warning>: Refusing sandboxed
PCSC.framework client without com.apple.security.smartcard entitlement
Mar  2 03:06:53 iMac-TMP joe[39540] <Warning>: audit warning: soft /var/audit
Mar  2 03:06:53 iMac-TMP joe[39541] <Warning>: audit warning: allsoft 
Mar  2 03:06:54 iMac-TMP joe[39544] <Warning>: audit warning: closefile
/var/audit/20170302110453.20170302110653
Mar  2 03:06:54 iMac-TMP com.apple.ctkpcscd[39536] <Notice>:
SecTaskLoadEntitlements failed error=22
Mar  2 03:06:54 iMac-TMP com.apple.ctkpcscd[39536] <Warning>: Refusing sandboxed
PCSC.framework client without com.apple.security.smartcard entitlement
Mar  2 03:06:54 iMac-TMP com.apple.xpc.launchd[1] (com.apple.ReportCrash[39548])
<Warning>: Endpoint has been activated through legacy launch(3) APIs. Please
switch to XPC or bootstrap_check_in(): com.apple.ReportCrash
Mar  2 03:06:54 iMac-TMP ReportCrash[39548] <Notice>: Saved crash report for
scdaemon[39535] version 0 to
/Users/joe/Library/Logs/DiagnosticReports/scdaemon_2017-03-02-030654_iMac-TMP.crash

This is interesting indeed. Might be related to a recent change to support
multiple smart cards.

A possible workaround for you is to disable the use of scdaemon in the tests.
Currently, it is not needed anyway. I'll attach a patch to do that.

Glad to hear that. Niibe will have a closer look at the issue tomorrow.

Thanks to you and thanks to Niibe in advance :)

I think that scdaemon in 2.1.18 would also crash in sandbox environment.
In 2.1.19, I modified ssh-agent emulation code to support multiple tokens.
This change assumes scdaemon returns ENODEV return code and behaves badly, if
scdaemon crashes.
In 2.1.18, the code was somewhat robust and scdaemon crash didn't cause failure.
I am currently looking into the reason why scdaemon crashes.

Sorry, I couldn't find any possible bug for PC/SC access in scdaemon. It looks
like scdaemon crashes when it tries to access card by PC/SC, and it seems that
it crashes there (I mean, in PC/SC).
I believe that this scdaemon's crash is something which is difficult to avoid in
an application.

Anyway, I fixed the issue itself by handling errors of gpg-agent for scdaemon:
https://git.gnupg.org/cgi-bin/gitweb.cgi?p=gnupg.git;a=commit;h=4ce4f2f683a17be3ddb93729f3f25014a97934ad

4ce4f2f683a17be3ddb93729f3f25014a97934ad allows make check to complete without
the other workaround. So it works as advertised! Thanks, Niibe and Justus.

Unsure whether to bump this or report it as a fresh bug, but the testing-scdaemon-inside-a-sandbox-on-macos issue has returned in GnuPG 2.1.21.

Ongoing discussion here on GitHub, including the output from make check. Depending on how you set it up the error is consistently either No SmartCard daemon or Broken pipe. After applying this patch from today the error is consistently simply Broken Pipe.

Essentially the same sandbox profile as Joe detailed in an earlier post:

(version 1)
(debug deny) ; log all denied operations to /var/log/system.log
(allow file-write* (subpath "/private/tmp"))
(allow file-write* (subpath "/private/var/tmp"))
(allow file-write* (regex #"^/private/var/folders/[^/]+/[^/]+/[C,T]/"))
(allow file-write* (subpath "/private/tmp"))
(allow file-write* (subpath "/usr/local/var/homebrewcache"))
(allow file-write* (subpath "/usr/local/var/homebrewcache/logs/gnupg"))
(allow file-write* (subpath "/Users/xyz/Library/Developer"))
(allow file-write* (subpath "/usr/local/Cellar/gnupg"))
(allow file-write* (subpath "/usr/local/etc"))
(allow file-write* (subpath "/usr/local/var"))
(allow file-write*
    (literal "/dev/ptmx")
    (literal "/dev/dtracehelper")
    (literal "/dev/null")
    (literal "/dev/zero")
    (regex #"^/dev/fd/[0-9]+$")
    (regex #"^/dev/ttys?[0-9]*$")
    )
(deny file-write*) ; deny non-whitelist file write operations
(allow process-exec
    (literal "/bin/ps")
    (with no-sandbox)
    ) ; allow certain processes running without sandbox
(allow default) ; allow everything else

Can confirm here too. Applying that on top of 2.1.21 works perfectly.