Bug 318116

Summary: Interface with gpgsm hangs after any S/MIME operation, requires killing gpgsm
Product: [Applications] kmail2 Reporter: Matt Whitlock <kde>
Component: cryptoAssignee: kdepim bugs <kdepim-bugs>
Status: RESOLVED UPSTREAM    
Severity: normal CC: arthur, duncant, igor.donev, lty1993, mail, meyerm, Nicky726, scarpino, smartins, tschenturs, vmatare+kdebug, Wolfgang_Mader
Priority: NOR    
Version: 4.10.2   
Target Milestone: ---   
Platform: Gentoo Packages   
OS: Linux   
Latest Commit: Version Fixed In:
Sentry Crash Report:

Description Matt Whitlock 2013-04-10 04:50:03 UTC 
When performing any S/MIME operation (encrypting, decrypting, signing, verifying), KMail's background task hangs indefinitely, until the spawned gpgsm process is killed. Once the gpgsm is killed, KMail resumes normal behavior (and even sees the correct result of the gpgsm operation).

Reproducible: Always

Steps to Reproduce:
1. Try to view a signed and/or encrypted S/MIME message.
2. KMail never gets past "Please wait while the signature is being verified" or "Please wait while the message is being decrypted".
3. killall gpgsm
4. KMail completes verification or decryption.
Actual Results:  
KMail's S/MIME operations hang until the spawned gpgsm process is killed.

Expected Results:  
KMail should be able to perform S/MIME operations without the gpgsm process needing to be manually killed.

Here is the GnuPG log resulting from opening an encrypted email (with several recipients) in KMail:

[client at fd 5 connected]
  5 - 2013-04-10 00:32:37 gpgsm[8120]: enabled debug flags: assuan
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 -> # Home: ~/.gnupg
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 -> # Config: /home/mattw/.gnupg/gpgsm.conf
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 -> # AgentInfo: /tmp/gpg-SIR2s2/S.gpg-agent:5289:1
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 -> # DirmngrInfo: [not set]
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 -> OK GNU Privacy Guard's S/M server 2.0.19 ready
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 <- OPTION display=:0
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 -> OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 <- OPTION enable-audit-log=1
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 -> OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 <- # descriptor 26 is in flight
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 <- INPUT FD
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 -> OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 <- # descriptor 28 is in flight
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 <- OUTPUT FD
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 -> OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 <- DECRYPT
  5 - 2013-04-10 00:32:37 gpgsm[8120]: DBG: recp 0 - issuer: #####REDACTED#####
  5 - 2013-04-10 00:32:37 gpgsm[8120]: DBG: recp 0 - serial: 52
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 -> S ENC_TO 69F4C6A64E8F54FB 0 0
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- OK Pleased to meet you, process 8120
  5 - 2013-04-10 00:32:37 gpgsm[8120]: DBG: connection to agent established
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> RESET
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> OPTION display=:0
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> OPTION putenv=GTK_IM_MODULE=xim
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> OPTION allow-pinentry-notify
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> RESET
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> SETKEY 2B3FCDED2104E11ACB32DDD23E0252D92E255266
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> SETKEYDESC Please+enter+the+passphrase+to+unlock+the+secret+key+for+the+X.509+certificate:#####REDACTED#####
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> PKDECRYPT
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- INQUIRE CIPHERTEXT
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> [ 44 20 28 37 3a 65 6e 63 2d 76 61 6c 28 33 3a 72 ...(273 byte(s) skipped) ]
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> END
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- ERR 67108881 No secret key <GPG Agent>
  5 - 2013-04-10 00:32:37 gpgsm[8120]: error decrypting session key: No secret key
  5 - 2013-04-10 00:32:37 gpgsm[8120]: decrypting session key failed: No secret key
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 -> S NO_SECKEY 69F4C6A64E8F54FB
  5 - 2013-04-10 00:32:37 gpgsm[8120]: DBG: recp 1 - issuer: #####REDACTED#####
  5 - 2013-04-10 00:32:37 gpgsm[8120]: DBG: recp 1 - serial: 53
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 -> S ENC_TO FFFFFFFFEF76C775 0 0
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> RESET
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> SETKEY 89945F0CB0E8CCD558C78D935B6F735E88B40641
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> SETKEYDESC Please+enter+the+passphrase+to+unlock+the+secret+key+for+the+X.509+certificate:#####REDACTED#####
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> PKDECRYPT
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- INQUIRE CIPHERTEXT
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> [ 44 20 28 37 3a 65 6e 63 2d 76 61 6c 28 33 3a 72 ...(273 byte(s) skipped) ]
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> END
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- ERR 67108881 No secret key <GPG Agent>
  5 - 2013-04-10 00:32:37 gpgsm[8120]: error decrypting session key: No secret key
  5 - 2013-04-10 00:32:37 gpgsm[8120]: decrypting session key failed: No secret key
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 -> S NO_SECKEY FFFFFFFFEF76C775
  5 - 2013-04-10 00:32:37 gpgsm[8120]: DBG: recp 2 - issuer: #####REDACTED#####
  5 - 2013-04-10 00:32:37 gpgsm[8120]: DBG: recp 2 - serial: 55
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 -> S ENC_TO 39D7924FFFFFFFFF 0 0
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> RESET
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> SETKEY E498D68EC75CA8AD94E024BA78BC6C1D07C610C7
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> SETKEYDESC Please+enter+the+passphrase+to+unlock+the+secret+key+for+the+X.509+certificate:#####REDACTED#####
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> PKDECRYPT
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- INQUIRE CIPHERTEXT
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> [ 44 20 28 37 3a 65 6e 63 2d 76 61 6c 28 33 3a 72 ...(279 byte(s) skipped) ]
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> END
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- ERR 67108881 No secret key <GPG Agent>
  5 - 2013-04-10 00:32:37 gpgsm[8120]: error decrypting session key: No secret key
  5 - 2013-04-10 00:32:37 gpgsm[8120]: decrypting session key failed: No secret key
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 -> S NO_SECKEY 39D7924FFFFFFFFF
  5 - 2013-04-10 00:32:37 gpgsm[8120]: DBG: recp 3 - issuer: #####REDACTED#####
  5 - 2013-04-10 00:32:37 gpgsm[8120]: DBG: recp 3 - serial: 5B
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_26 -> S ENC_TO FFFFFFFFDA2FCFC4 0 0
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> RESET
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> SETKEY 015C1A86EEB02C504E8E6765F42F7522E9A41C33
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> SETKEYDESC Please+enter+the+passphrase+to+unlock+the+secret+key+for+the+X.509+certificate:#####REDACTED#####
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- OK
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> PKDECRYPT
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- INQUIRE CIPHERTEXT
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> [ 44 20 28 37 3a 65 6e 63 2d 76 61 6c 28 33 3a 72 ...(273 byte(s) skipped) ]
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> END
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 <- INQUIRE PINENTRY_LAUNCHED 8121
  5 - 2013-04-10 00:32:37 gpgsm[8120]: chan_11 -> END
  5 - 2013-04-10 00:32:42 gpgsm[8120]: chan_11 <- [ 44 20 28 35 3a 76 61 6c 75 65 32 35 35 3a 02 bd ...(259 byte(s) skipped) ]
  5 - 2013-04-10 00:32:42 gpgsm[8120]: chan_11 <- OK
  5 - 2013-04-10 00:32:42 gpgsm[8120]: chan_26 -> S DECRYPTION_OKAY
  5 - 2013-04-10 00:32:42 gpgsm[8120]: chan_26 -> OK
  5 - 2013-04-10 00:32:42 gpgsm[8120]: chan_26 <- # descriptor 27 is in flight
  5 - 2013-04-10 00:32:42 gpgsm[8120]: chan_26 <- OUTPUT FD
  5 - 2013-04-10 00:32:42 gpgsm[8120]: chan_26 -> OK
  5 - 2013-04-10 00:32:42 gpgsm[8120]: chan_26 <- GETAUDITLOG --html
  5 - 2013-04-10 00:32:42 gpgsm[8120]: chan_26 -> OK
(( I had to kill the gpgsm process at this point to get KMail to display the decrypted message. ))
[client at fd 5 disconnected]


Here is the GnuPG log resulting from opening a signed email in KMail:

[client at fd 5 connected]
  5 - 2013-04-10 00:33:12 gpgsm[8188]: enabled debug flags: assuan
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 -> # Home: ~/.gnupg
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 -> # Config: /home/mattw/.gnupg/gpgsm.conf
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 -> # AgentInfo: /tmp/gpg-SIR2s2/S.gpg-agent:5289:1
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 -> # DirmngrInfo: [not set]
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 -> OK GNU Privacy Guard's S/M server 2.0.19 ready
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 <- OPTION display=:0
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 -> OK
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 <- OPTION enable-audit-log=1
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 -> OK
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 <- # descriptor 24 is in flight
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 <- INPUT FD
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 -> OK
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 <- # descriptor 24 is in flight
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 <- MESSAGE FD
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 -> OK
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 <- VERIFY
  5 - 2013-04-10 00:33:12 gpgsm[8188]: detached signature
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 -> S NEWSIG
  5 - 2013-04-10 00:33:12 gpgsm[8188]: Signature made 2013-04-09 15:39:38 using certificate ID 0x7180637D
  5 - 2013-04-10 00:33:12 gpgsm[8188]: certificate is good
  5 - 2013-04-10 00:33:12 gpgsm[8188]: root certificate is good
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_10 <- OK Pleased to meet you, process 8188
  5 - 2013-04-10 00:33:12 gpgsm[8188]: DBG: connection to agent established
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_10 -> RESET
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_10 <- OK
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_10 -> OPTION display=:0
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_10 <- OK
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_10 -> OPTION putenv=GTK_IM_MODULE=xim
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_10 <- OK
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_10 -> OPTION allow-pinentry-notify
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_10 <- OK
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_10 -> ISTRUSTED 957E9EB15ABBC3F2837A081CDB788DD12128C753
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_10 <- OK
  5 - 2013-04-10 00:33:12 gpgsm[8188]: CRLs not checked due to --disable-crl-checks option
  5 - 2013-04-10 00:33:12 gpgsm[8188]: validation model used: shell
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 -> S GOODSIG 06E6A5B44044C53F0C8C72086DEDCD4B7180637D #####REDACTED#####
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 -> S VALIDSIG 06E6A5B44044C53F0C8C72086DEDCD4B7180637D 2013-04-09 20130409T153938 20131221T184552 0 0 1 2 00
  5 - 2013-04-10 00:33:12 gpgsm[8188]: Good signature from #####REDACTED#####
  5 - 2013-04-10 00:33:12 gpgsm[8188]:                 aka #####REDACTED#####
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 -> S TRUST_FULLY 0 shell
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 -> OK
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 <- # descriptor 25 is in flight
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 <- OUTPUT FD
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 -> OK
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 <- GETAUDITLOG --html
  5 - 2013-04-10 00:33:12 gpgsm[8188]: chan_24 -> OK
(( I had to kill the gpgsm process at this point to get KMail to show that the signature is valid. ))
[client at fd 5 disconnected]
Comment 1 Wolfgang Mader 2013-04-23 08:05:22 UTC 
I can confirm this an Arch Liunx, KDE platform 4.10.2, KMail 4.10.2.
Comment 2 igor.donev 2013-04-30 15:06:22 UTC 
I confirm the same on Arch Linux KDE platform 4.10.2, KMail 4.10.2.
Comment 3 mail 2013-05-03 15:50:29 UTC 
I can confirm this Issue. Also on Arch

KDE-PIM Version 4.10.2
gpgsm (GnuPG) 2.0.19
libgcrypt 1.5.2
libksba 1.3.0
gpgme  1.4.0-1 

see forum thread: https://forum.kde.org/viewtopic.php?f=215&t=111020&p=264227#p264227
Comment 4 Nicky726 2013-05-06 17:10:50 UTC 
I can also confirm this on Arch Linux (KDE 4.10.2, gpgme 1.4.0) 
Link to Arch bugzilla: https://bugs.archlinux.org/task/35112
Comment 5 mail 2013-05-10 15:08:06 UTC 
Updated KDE-PIM to 4.10.3 -- no change
Comment 6 mail 2013-05-10 15:28:48 UTC 
As supposed by Nicky726 downgrading to 1.3.2-1 solves the issue:
If you didn't clean your pacman cache recently:

# pacman -U /var/cache/pacman/pkg/gpgme-1.3.2-1-x86_64.pkg.tar.xz 

restart kontact / kmail
Comment 7 mail 2013-05-11 09:22:25 UTC 
Can somebody with detailed debug information file a bug here:

https://bugs.g10code.com/gnupg/
Comment 8 Nicky726 2013-05-11 13:15:01 UTC 
With gpgme 1.4.1 the issue still persists.
Comment 9 lty1993 2013-05-24 06:08:05 UTC 
*** This bug has been confirmed by popular vote. ***
Comment 10 meyerm 2013-07-22 08:33:44 UTC 
Still valid vor 4.10.5(-1) and gnupg 2.0.20(-2) (Archlinux packages).
Comment 11 meyerm 2013-07-29 13:48:37 UTC 
https://bugs.g10code.com/gnupg/issue1502
Comment 12 Sergio Martins 2013-08-04 17:47:34 UTC 
This is https://bugs.g10code.com/gnupg/issue1502.

You can configure gpgme with --disable-fd-passing as a workaround