[Gpg4win-users-en] pinentry asks the same password three times (Psi 0.13, three accounts with the same private key)

[???????? ????????]

Ok, I turned loggin on ....

According to this log pinentry was started three times with the same cash id
(BD155B4CBDB7925F3CEAB9A298983C5E484A4B17) A have made screenshots in
process viewer. Psi starts gpg for every Psi account in spite of the same
key id. 

2009-08-20 12:30:06 gpg-agent[2932] listening on socket
`C:\Users\akir\AppData\Roaming\gnupg\S.gpg-agent'
2009-08-20 12:30:06 gpg-agent[2932] gpg-agent (GnuPG) 2.0.12 started
2009-08-20 12:30:06 gpg-agent[2932] DBG: returning notify handle 000000E0
2009-08-20 12:30:06 gpg-agent[2932] handler 0xb60 for fd 240 started
2009-08-20 12:30:06 gpg-agent[1240] a gpg-agent is already running - not
starting a new one
2009-08-20 12:30:06 gpg-agent[1240] secmem usage: 0/32768 bytes in 0 blocks
gpg-agent[2932.240] DBG: -> OK Pleased to meet you
gpg-agent[2932.240] DBG: <- BYE
gpg-agent[2932.240] DBG: -> OK closing connection
2009-08-20 12:30:06 gpg-agent[2932] handler 0xb60 for fd 240 terminated
2009-08-20 12:30:07 gpg-agent[2932] handler 0x504 for fd 248 started
gpg-agent[2932.248] DBG: -> OK Pleased to meet you
gpg-agent[2932.248] DBG: <- RESET
gpg-agent[2932.248] DBG: -> OK
gpg-agent[2932.248] DBG: <- OPTION allow-pinentry-notify
gpg-agent[2932.248] DBG: -> OK
gpg-agent[2932.248] DBG: <- GETINFO cmd_has_option GET_PASSPHRASE repeat
gpg-agent[2932.248] DBG: -> OK
gpg-agent[2932.248] DBG: <- GET_PASSPHRASE --data --repeat=0 --
BD155B4CBDB7925F3CEAB9A298983C5E484A4B17 X X
Please+enter+the+passphrase+to+unlock+the+secret+key+for+the+OpenPGP+certifi
cate:%0A%22Anatoly+Kirsanov+<kiav1976 at mail.ru>%22%0A2048-bit+RSA+key,+ID+484
A4B17,%0Acreated+2009-08-03+(main+key+ID+CAF7EC4E).%0A
2009-08-20 12:30:07 gpg-agent[2932] starting a new PIN Entry
2009-08-20 12:30:08 gpg-agent[2932] handler 0x654 for fd 236 started
gpg-agent[2932.236] DBG: -> OK Pleased to meet you
gpg-agent[2932.236] DBG: <- RESET
gpg-agent[2932.236] DBG: -> OK
gpg-agent[2932.236] DBG: <- OPTION allow-pinentry-notify
gpg-agent[2932.236] DBG: -> OK
gpg-agent[2932.236] DBG: <- GETINFO cmd_has_option GET_PASSPHRASE repeat
gpg-agent[2932.236] DBG: -> OK
gpg-agent[2932.236] DBG: <- GET_PASSPHRASE --data --repeat=0 --
BD155B4CBDB7925F3CEAB9A298983C5E484A4B17 X X
Please+enter+the+passphrase+to+unlock+the+secret+key+for+the+OpenPGP+certifi
cate:%0A%22Anatoly+Kirsanov+<kiav1976 at mail.ru>%22%0A2048-bit+RSA+key,+ID+484
A4B17,%0Acreated+2009-08-03+(main+key+ID+CAF7EC4E).%0A
2009-08-20 12:30:09 gpg-agent[2932] handler 0x5ec for fd 268 started
gpg-agent[2932.268] DBG: -> OK Pleased to meet you
gpg-agent[2932.268] DBG: <- RESET
gpg-agent[2932.268] DBG: -> OK
gpg-agent[2932.268] DBG: <- OPTION allow-pinentry-notify
gpg-agent[2932.268] DBG: -> OK
gpg-agent[2932.268] DBG: <- GETINFO cmd_has_option GET_PASSPHRASE repeat
gpg-agent[2932.268] DBG: -> OK
gpg-agent[2932.268] DBG: <- GET_PASSPHRASE --data --repeat=0 --
BD155B4CBDB7925F3CEAB9A298983C5E484A4B17 X X
Please+enter+the+passphrase+to+unlock+the+secret+key+for+the+OpenPGP+certifi
cate:%0A%22Anatoly+Kirsanov+<kiav1976 at mail.ru>%22%0A2048-bit+RSA+key,+ID+484
A4B17,%0Acreated+2009-08-03+(main+key+ID+CAF7EC4E).%0A
2009-08-20 12:30:11 gpg-agent[2932] DBG: connection to PIN entry established
gpg-agent[2932.248] DBG: -> INQUIRE PINENTRY_LAUNCHED 316
gpg-agent[2932.248] DBG: <- END
2009-08-20 12:31:09 gpg-agent[2932] starting a new PIN Entry
gpg-agent[2932.248] DBG: -> [Confidential data not shown]
gpg-agent[2932.248] DBG: -> [Confidential data not shown]
2009-08-20 12:31:09 gpg-agent[2932] DBG: connection to PIN entry established
gpg-agent[2932.236] DBG: -> INQUIRE PINENTRY_LAUNCHED 2204
gpg-agent[2932.236] DBG: <- END
gpg-agent[2932.248] DBG: <- [Error: Input/output error]
2009-08-20 12:31:09 gpg-agent[2932] Assuan processing failed: IPC read error
2009-08-20 12:31:09 gpg-agent[2932] handler 0x504 for fd 248 terminated
2009-08-20 12:31:10 gpg-agent[2932] handler 0xd80 for fd 320 started
gpg-agent[2932.320] DBG: -> OK Pleased to meet you
gpg-agent[2932.320] DBG: <- RESET
gpg-agent[2932.320] DBG: -> OK
gpg-agent[2932.320] DBG: <- OPTION allow-pinentry-notify
gpg-agent[2932.320] DBG: -> OK
gpg-agent[2932.320] DBG: <- GETINFO cmd_has_option GET_PASSPHRASE repeat
gpg-agent[2932.320] DBG: -> OK
gpg-agent[2932.320] DBG: <- GET_PASSPHRASE --data --repeat=0 --
BD155B4CBDB7925F3CEAB9A298983C5E484A4B17 X X
Please+enter+the+passphrase+to+unlock+the+secret+key+for+the+OpenPGP+certifi
cate:%0A%22Anatoly+Kirsanov+<kiav1976 at mail.ru>%22%0A2048-bit+RSA+key,+ID+484
A4B17,%0Acreated+2009-08-03+(main+key+ID+CAF7EC4E).%0A
gpg-agent[2932.320] DBG: -> [Confidential data not shown]
gpg-agent[2932.320] DBG: -> [Confidential data not shown]
gpg-agent[2932.320] DBG: <- [Error: Input/output error]
2009-08-20 12:31:10 gpg-agent[2932] Assuan processing failed: IPC read error
2009-08-20 12:31:10 gpg-agent[2932] handler 0xd80 for fd 320 terminated
2009-08-20 12:31:14 gpg-agent[2932] handler 0x2e0 for fd 248 started
gpg-agent[2932.248] DBG: -> OK Pleased to meet you
gpg-agent[2932.248] DBG: <- GETINFO pid
gpg-agent[2932.248] DBG: -> D 2932
gpg-agent[2932.248] DBG: -> OK
gpg-agent[2932.248] DBG: <- BYE
gpg-agent[2932.248] DBG: -> OK closing connection
2009-08-20 12:31:14 gpg-agent[2932] handler 0x2e0 for fd 248 terminated
2009-08-20 12:31:53 gpg-agent[2932] starting a new PIN Entry
gpg-agent[2932.236] DBG: -> [Confidential data not shown]
gpg-agent[2932.236] DBG: -> [Confidential data not shown]
2009-08-20 12:31:54 gpg-agent[2932] DBG: connection to PIN entry established
gpg-agent[2932.268] DBG: -> INQUIRE PINENTRY_LAUNCHED 700
gpg-agent[2932.268] DBG: <- END
gpg-agent[2932.236] DBG: <- [Error: Input/output error]
2009-08-20 12:31:54 gpg-agent[2932] Assuan processing failed: IPC read error
2009-08-20 12:31:54 gpg-agent[2932] handler 0x654 for fd 236 terminated
2009-08-20 12:31:54 gpg-agent[2932] handler 0xd68 for fd 272 started
gpg-agent[2932.272] DBG: -> OK Pleased to meet you
gpg-agent[2932.272] DBG: <- RESET
gpg-agent[2932.272] DBG: -> OK
gpg-agent[2932.272] DBG: <- OPTION allow-pinentry-notify
gpg-agent[2932.272] DBG: -> OK
gpg-agent[2932.272] DBG: <- GETINFO cmd_has_option GET_PASSPHRASE repeat
gpg-agent[2932.272] DBG: -> OK
gpg-agent[2932.272] DBG: <- GET_PASSPHRASE --data --repeat=0 --
BD155B4CBDB7925F3CEAB9A298983C5E484A4B17 X X
Please+enter+the+passphrase+to+unlock+the+secret+key+for+the+OpenPGP+certifi
cate:%0A%22Anatoly+Kirsanov+<kiav1976 at mail.ru>%22%0A2048-bit+RSA+key,+ID+484
A4B17,%0Acreated+2009-08-03+(main+key+ID+CAF7EC4E).%0A
gpg-agent[2932.272] DBG: -> [Confidential data not shown]
gpg-agent[2932.272] DBG: -> [Confidential data not shown]
gpg-agent[2932.272] DBG: <- [Error: Input/output error]
2009-08-20 12:31:54 gpg-agent[2932] Assuan processing failed: IPC read error
2009-08-20 12:31:54 gpg-agent[2932] handler 0xd68 for fd 272 terminated
2009-08-20 12:32:14 gpg-agent[2932] handler 0xd58 for fd 236 started
gpg-agent[2932.236] DBG: -> OK Pleased to meet you
gpg-agent[2932.236] DBG: <- GETINFO pid
gpg-agent[2932.236] DBG: -> D 2932
gpg-agent[2932.236] DBG: -> OK
gpg-agent[2932.236] DBG: <- BYE
gpg-agent[2932.236] DBG: -> OK closing connection
2009-08-20 12:32:14 gpg-agent[2932] handler 0xd58 for fd 236 terminated
gpg-agent[2932.268] DBG: -> [Confidential data not shown]
gpg-agent[2932.268] DBG: -> [Confidential data not shown]
gpg-agent[2932.268] DBG: <- [Error: Input/output error]
2009-08-20 12:32:41 gpg-agent[2932] Assuan processing failed: IPC read error
2009-08-20 12:32:41 gpg-agent[2932] handler 0x5ec for fd 268 terminated
2009-08-20 12:32:42 gpg-agent[2932] handler 0x52c for fd 304 started
gpg-agent[2932.304] DBG: -> OK Pleased to meet you
gpg-agent[2932.304] DBG: <- RESET
gpg-agent[2932.304] DBG: -> OK
gpg-agent[2932.304] DBG: <- OPTION allow-pinentry-notify
gpg-agent[2932.304] DBG: -> OK
gpg-agent[2932.304] DBG: <- GETINFO cmd_has_option GET_PASSPHRASE repeat
gpg-agent[2932.304] DBG: -> OK
gpg-agent[2932.304] DBG: <- GET_PASSPHRASE --data --repeat=0 --
BD155B4CBDB7925F3CEAB9A298983C5E484A4B17 X X
Please+enter+the+passphrase+to+unlock+the+secret+key+for+the+OpenPGP+certifi
cate:%0A%22Anatoly+Kirsanov+<kiav1976 at mail.ru>%22%0A2048-bit+RSA+key,+ID+484
A4B17,%0Acreated+2009-08-03+(main+key+ID+CAF7EC4E).%0A
gpg-agent[2932.304] DBG: -> [Confidential data not shown]
gpg-agent[2932.304] DBG: -> [Confidential data not shown]
gpg-agent[2932.304] DBG: <- [Error: Input/output error]
2009-08-20 12:32:42 gpg-agent[2932] Assuan processing failed: IPC read error
2009-08-20 12:32:42 gpg-agent[2932] handler 0x52c for fd 304 terminated 


Anatoly

-----Original Message-----
From: Werner Koch [mailto:wk at gnupg.org] 
Sent: Wednesday, August 19, 2009 7:56 PM
To: kiav1976 at mail.ru
Cc: gpg4win-users-en at wald.intevation.org
Subject: Re: [Gpg4win-users-en] pinentry asks the same password three times
(Psi 0.13, three accounts with the same private key)

On Wed, 19 Aug 2009 15:36, kiav1976 at mail.ru said:

> Werner, I have ONE key, and tree accounts in Psi using this key. 
> pinentry asks the same password three times.

You can enable debugging for gpg-agent and look at the logfile (--debug
1024 shouldbe sufficient).  Here is an example with stripped timestamps:

  gpg-agent[10780.9] DBG: <- GET_PASSPHRASE --data --repeat=0 --
    1DFED28E885CE98C170CEE80907B5D1640619DD0
    Invalid+passphrase;+please+try+again X
    Please+enter+the+passphrase+to+unlock+the+secret+key+for+
    the+OpenPGP+certificate:%0A%22Joe+Random+Hacker+(test
    +key+with+passphrase+%22x%22)+<joe at setq.org>%22%0A1024
 
-bit+RSA+key,+ID+40619DD0,%0Acreated+2004-09-23+(main+key+ID+9CD9FD55).%0A
  gpg-agent[10780]: starting a new PIN Entry
  gpg-agent[10780]: DBG: connection to PIN entry established
  gpg-agent[10780.9] DBG: -> INQUIRE PINENTRY_LAUNCHED 3966
  gpg-agent[10780.9] DBG: <- END
  gpg-agent[10780.9] DBG: -> [Confidential data not shown]
  gpg-agent[10780.9] DBG: -> [Confidential data not shown]

GET_PASSPHRASE is the command gpg send to the gpg-agent.  In this case
gpg-agent figures that it has no cached passphrase with the cache-id
1DFED28E885CE98C170CEE80907B5D1640619DD0 and pops up the pinentry nd ask for
the passphrase.  In the above example I entered a bad passphrase first, thus
you see the "Invalid passphrase, try again" prompt.

  gpg-agent[10780.9] DBG: <- GET_PASSPHRASE --data --repeat=0 --
    1DFED28E885CE98C170CEE80907B5D1640619DD0 X X
    Please+enter+the+passphrase+to+unlock+the+secret+key+for+
    the+OpenPGP+certificate:%0A%22Joe+Random+Hacker+(test
    +key+with+passphrase+%22x%22)+<joe at setq.org>%22%0A1024-bit+
    RSA+key,+ID+40619DD0,%0Acreated+2004-09-23+(main+key+ID+9CD9FD55).%0A
  gpg-agent[10780.9] DBG: -> [Confidential data not shown]
  gpg-agent[10780.9] DBG: -> [Confidential data not shown]
  gpg-agent[10780.9] DBG: <- [EOF]
  
Here GET_PASSPHRASE is called again with the same cache-id and because the
passphrase is still in the cache the passphrase is retruned immediately.



Salam-Shalom,

   Werner



--
Die Gedanken sind frei.  Auschnahme regelt ein Bundeschgesetz.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: 2pin.jpg
Type: image/jpeg
Size: 233471 bytes
Desc: not available
URL: <http://lists.wald.intevation.org/pipermail/gpg4win-users-en/attachments/20090820/cc2134b7/attachment.jpg>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: 3pin.jpg
Type: image/jpeg
Size: 252718 bytes
Desc: not available
URL: <http://lists.wald.intevation.org/pipermail/gpg4win-users-en/attachments/20090820/cc2134b7/attachment-0001.jpg>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: 4agent.jpg
Type: image/jpeg
Size: 258859 bytes
Desc: not available
URL: <http://lists.wald.intevation.org/pipermail/gpg4win-users-en/attachments/20090820/cc2134b7/attachment-0002.jpg>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: 1pin.jpg
Type: image/jpeg
Size: 369992 bytes
Desc: not available
URL: <http://lists.wald.intevation.org/pipermail/gpg4win-users-en/attachments/20090820/cc2134b7/attachment-0003.jpg>