scd: a race condition between scd_command_handler and handle_tick

[NIIBE Yutaka]

On 2012-04-04 at 10:43 +0900, Niibe Yutaka wrote:
> This is a bug report for GnuPG 2.0.19 (or 2.0.18).  I have not yet
> checked if there is this bug in the development version or not.
> 
> This bug was found at "make check" of building scute 1.4.0 for Debian.
> I think that it is a bug of a race condition.
[...]
> It surely occured on other non-exotic architectures.  In fact, I
> encountered on my amd64 box too (sorry, I lost the log).

I minimize reproducible test case.  I tested on Debian sid amd64
environment.

Here is a session log:
------------------------------------
# Confirm that libpcsclite1
$ dpkg -l libpcsclite1
Desired=Unknown/Install/Remove/Purge/Hold
| Status=Not/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend
|/ Err?=(none)/Reinst-required (Status,Err: uppercase=bad)
||/ Name           Version        Description
+++-==============-==============-============================================
un  libpcsclite1   <none>         (no description available)

# Setup GnuPG's homedir for testing, and enable debugging of scdaemon 
$ mkdir -p $HOME/tmp/dot-gnupg
$ GNUPGHOME=$HOME/tmp/dot-gnupg
$ export GNUPGHOME
$ echo debug-level guru >tmp/dot-gnupg/scdaemon.conf
$ echo debug-all >>tmp/dot-gnupg/scdaemon.conf
$ echo log-file $HOME/tmp/dot-gnupg/scd.log >>tmp/dot-gnupg/scdaemon.conf

# Run GPG-AGENT
$ eval $(gpg-agent --daemon)

# Using GPG-CONNECT-AGENT, try to access smartcard
$ gpg-connect-agent learn /bye
ERR 100663404 Card error <SCD>				# This is normal
$ gpg-connect-agent learn /bye
ERR 100663356 Not supported <SCD>			# This is by a bug
$ gpg-connect-agent learn /bye
ERR 100663404 Card error <SCD>
------------------------------------

Here is a scdaemon debug output:
------------------------------------
2012-04-05 02:04:59 scdaemon[14197] listening on socket `/tmp/gpg-oBXWNe/S.scdaemon'
2012-04-05 02:04:59 scdaemon[14197] handler for fd -1 started
2012-04-05 02:05:00 scdaemon[14197] error sending PC/SC OPEN request: Broken pipe
scdaemon[14197]: chan_7 -> OK GNU Privacy Guard's Smartcard server ready
scdaemon[14197]: chan_7 <- GETINFO socket_name
scdaemon[14197]: chan_7 -> D /tmp/gpg-oBXWNe/S.scdaemon
scdaemon[14197]: chan_7 -> OK
scdaemon[14197]: chan_7 <- OPTION event-signal=12
scdaemon[14197]: chan_7 -> OK
scdaemon[14197]: chan_7 <- SERIALNO
scdaemon[14197]: chan_7 -> ERR 100663404 Card error <SCD>
scdaemon[14197]: chan_7 <- RESTART
scdaemon[14197]: chan_7 -> OK
2012-04-05 02:05:01 scdaemon[14197] error sending PC/SC OPEN request: Broken pipe
2012-04-05 02:05:01 scdaemon[14197] error sending PC/SC OPEN request: Broken pipe
scdaemon[14197]: chan_7 <- SERIALNO
2012-04-05 02:05:02 scdaemon[14197] DBG: send apdu: c=00 i=A4 p1=00 p2=0C lc=2 le=-1 em=0
2012-04-05 02:05:02 scdaemon[14197] apdu_send_simple(0) failed: not supported
2012-04-05 02:05:02 scdaemon[14197] DBG: send apdu: c=00 i=A4 p1=04 p2=00 lc=6 le=-1 em=0
2012-04-05 02:05:02 scdaemon[14197] apdu_send_simple(0) failed: not supported
2012-04-05 02:05:02 scdaemon[14197] DBG: send apdu: c=00 i=A4 p1=04 p2=0C lc=7 le=-1 em=0
2012-04-05 02:05:02 scdaemon[14197] apdu_send_simple(0) failed: not supported
2012-04-05 02:05:02 scdaemon[14197] DBG: send apdu: c=00 i=A4 p1=04 p2=0C lc=12 le=-1 em=0
2012-04-05 02:05:02 scdaemon[14197] apdu_send_simple(0) failed: not supported
2012-04-05 02:05:02 scdaemon[14197] DBG: send apdu: c=00 i=A4 p1=08 p2=0C lc=2 le=-1 em=0
2012-04-05 02:05:02 scdaemon[14197] apdu_send_simple(0) failed: not supported
2012-04-05 02:05:02 scdaemon[14197] DBG: send apdu: c=00 i=A4 p1=01 p2=0C lc=2 le=-1 em=0
2012-04-05 02:05:02 scdaemon[14197] apdu_send_simple(0) failed: not supported
2012-04-05 02:05:02 scdaemon[14197] DBG: send apdu: c=00 i=A4 p1=04 p2=0C lc=6 le=-1 em=0
2012-04-05 02:05:02 scdaemon[14197] apdu_send_simple(0) failed: not supported
2012-04-05 02:05:02 scdaemon[14197] DBG: send apdu: c=00 i=A4 p1=04 p2=0C lc=9 le=-1 em=0
2012-04-05 02:05:02 scdaemon[14197] apdu_send_simple(0) failed: not supported
2012-04-05 02:05:02 scdaemon[14197] no supported card application found: Not supported
scdaemon[14197]: chan_7 -> ERR 100663356 Not supported <SCD>
scdaemon[14197]: chan_7 <- RESTART
scdaemon[14197]: chan_7 -> OK
2012-04-05 02:05:02 scdaemon[14197] error sending PC/SC OPEN request: Broken pipe
2012-04-05 02:05:03 scdaemon[14197] error sending PC/SC OPEN request: Broken pipe
2012-04-05 02:05:04 scdaemon[14197] error sending PC/SC OPEN request: Broken pipe
2012-04-05 02:05:04 scdaemon[14197] error sending PC/SC OPEN request: Broken pipe
scdaemon[14197]: chan_7 <- SERIALNO
scdaemon[14197]: chan_7 -> ERR 100663404 Card error <SCD>
scdaemon[14197]: chan_7 <- RESTART
scdaemon[14197]: chan_7 -> OK
2012-04-05 02:05:05 scdaemon[14197] error sending PC/SC OPEN request: Broken pipe
2012-04-05 02:05:06 scdaemon[14197] error sending PC/SC OPEN request: Broken pipe
------------------------------------

Because of the race condition, we see apdu_send_simple in the log.
--