[Kolab-devel] [issue4212] Kleopatra hangs because pinentry-qt4 comes not up
Emanuel Schuetze
issues at kolab.org
Mon Mar 15 14:16:40 CET 2010
New submission from Emanuel Schuetze <emanuel at intevation.de>:
Tested with gpg4win-svn1359 + kdepim-r1102305 (kleo 2.0.14):
- Start Kleopatra
- Import openpgp secret key and set owner trust
- Start Outlook/gpgol
- Send an signed openpgp message with gpgol
=> Outlook and Kleopatra hangs because pinentry-qt4 doesn't comes up. A pinentry
procress was started but no dialog is opened! So Kleopatra couln't finish the
sign operation. The Outlook composer window freezed.
See attached kleo-log.
It's a critical issue!
----------
assignedto: marc
files: kleo-log.txt
keyword: gpg4win2, kleo
messages: 24180
nosy: emanuel, marc, werner
priority: critical
status: unread
title: Kleopatra hangs because pinentry-qt4 comes not up
______________________________________
Kolab issue tracker <issues at kolab.org>
<https://issues.kolab.org/issue4212>
______________________________________
-------------- next part --------------
Startup timing: 516 ms elapsed: Application created
Startup timing: 578 ms elapsed: UiServer created
Startup timing: 594 ms elapsed: UiServer started
UiServer: client connect on fd 1396
[3952.1396] DBG: -> OK GPG UI server (Kleopatra/2.0.14) ready to serve
UiServer: client connection 014CD868 established successfully
[3952.1396] DBG: <- GETINFO pid
[3952.1396] DBG: -> D 3952
[3952.1396] DBG: -> OK
Server PID = 3952
[3952.1396] DBG: <- [Error: Resource temporarily unavailable]
AllowSetForegroundWindow( 3952 ) failed: 5
[3952.1396] DBG: <- BYE
[3952.1396] DBG: -> OK closing connection
UiServer: connection 014CD868 closed
ArchiveDefinition[ "tar" ] ("tar", "cf", "-")
Fehler in der Archiv-Definition tar: Befehl leer oder nicht gefunden
ArchiveDefinition[ "zip" ] ("zip", "-r", "-", "%f")
Fehler in der Archiv-Definition zip: Befehl leer oder nicht gefunden
ArchiveDefinition[ "bzip2" ] ("tar", "cfj", "-")
Fehler in der Archiv-Definition bzip2: Befehl leer oder nicht gefunden
Startup timing: 4312 ms elapsed: SelfCheck completed
ReaderStatusThread[2nd]: new iteration command= "__update__" ; nullSlot= true
<update_cardinfo>
get_card_status( "C:/Dokumente und Einstellungen/admin/Anwendungsdaten/gnupg/reader_0.status" , 0 , 0x14e8770 )
gpgagent_transact( SCD SERIALNO )
gpgagent_transact( SCD GETATTR APPTYPE )
scd_getattr_status( APPTYPE ): got ( status( "APPTYPE" ) = "NKS"
)
parse_app_type( NKS )
static_cast<ReaderStatus::AppType>( it - begin( app_types ) ) 2
gpgagent_transact( SCD GETATTR NKS-VERSION )
scd_getattr_status( NKS-VERSION ): got ( status( "NKS-VERSION" ) = "3"
)
gpgagent_transact( SCD GETATTR CHV-STATUS )
Startup timing: 5547 ms elapsed: KeyCache loaded
KeyFilterManager::reload: final filter count is 12
Startup timing: 5719 ms elapsed: new instance created
scd_getattr_status( CHV-STATUS ): got ( status( "CHV-STATUS" ) = "3 3 3 0"
)
gpgagent_transact( SCD LEARN --keypairinfo )
parse_keypairinfo_and_lookup_key: pattern= &5873571FF1FC25D56F5884889EA7C3819A9428A6
parse_keypairinfo_and_lookup_key: e= 0 ; key.isNull() false
parse_keypairinfo_and_lookup_key: pattern= &096AA67BD7ACB1AEB9E12DBBD49E7BC7B32F9D22
parse_keypairinfo_and_lookup_key: e= 0 ; key.isNull() false
parse_keypairinfo_and_lookup_key: pattern= &1407AFEF9AB4783A717D984ADE74BC9638A13998
parse_keypairinfo_and_lookup_key: e= 0 ; key.isNull() false
parse_keypairinfo_and_lookup_key: pattern= &9C0FA63B05FAC1E913DB640D8B5419915BBE18C1
parse_keypairinfo_and_lookup_key: e= 0 ; key.isNull() false
get_card_status: ci.status CardUsable
</update_cardinfo>
ReaderStatusThread[2nd]: slot 0 : NoCard -> CardUsable
gpgagent_transact( GETEVENTCOUNTER )
get_event_counter(): got ( status( "EVENTCOUNTER" ) = "101 0 101"
)
eventCounter: 101
ReaderStatusThread[2nd]: .zZZ
ReaderStatusThread[2nd]: .oOO
ReaderStatusThread[2nd]: new iteration command= "__check__" ; nullSlot= true
gpgagent_transact( GETEVENTCOUNTER )
get_event_counter(): got ( status( "EVENTCOUNTER" ) = "101 0 101"
)
ReaderStatusThread[2nd]: .zZZ
ReaderStatusThread[2nd]: .oOO
ReaderStatusThread[2nd]: new iteration command= "__check__" ; nullSlot= true
gpgagent_transact( GETEVENTCOUNTER )
get_event_counter(): got ( status( "EVENTCOUNTER" ) = "101 0 101"
)
ReaderStatusThread[2nd]: .zZZ
UiServer: client connect on fd 1516
[3952.1516] DBG: -> OK GPG UI server (Kleopatra/2.0.14) ready to serve
UiServer: client connection 01563C18 established successfully
[3952.1516] DBG: <- GETINFO pid
[3952.1516] DBG: -> D 3952
[3952.1516] DBG: -> OK
[3952.1516] DBG: <- [Error: Resource temporarily unavailable]
[3952.1516] DBG: <- OPTION window-id=30154
[3952.1516] DBG: -> OK
[3952.1516] DBG: <- RESET
[3952.1516] DBG: -> OK
[3952.1516] DBG: <- SESSION 2 test sig
session_handler: id=2, title=test sig
[3952.1516] DBG: -> OK
[3952.1516] DBG: <- SENDER -- gpg4winusera at test.hq
[3952.1516] DBG: -> # ok, parsed as "gpg4winusera at test.hq"
[3952.1516] DBG: -> # matching OpenPGP key B726CB6BD1BB45392621CD598B59AB93C6BF6664
[3952.1516] DBG: -> S PROTOCOL OpenPGP
[3952.1516] DBG: -> OK
[3952.1516] DBG: <- INPUT FD=1148
KDPipeIODevice::doOpen (01581E28): created reader (015835B0) for fd -1
AssuanServerConnection: added "Nachricht #1"
[3952.1516] DBG: -> OK
[3952.1516] DBG: <- OUTPUT FD=1028
KDPipeIODevice::doOpen (015884A0): created writer (015A90E0) for fd -1
AssuanServerConnection: added ""
[3952.1516] DBG: -> OK
[3952.1516] DBG: <- SIGN --protocol=OpenPGP --detached
015832E8: KDPipeIODevice::readData: data=0158E588, maxSize=512
KDPipeIODevice::Private::startReaderThread(): locking reader (CONSUMER THREAD)
KDPipeIODevice::Private::startReaderThread(): locked reader (CONSUMER THREAD)
KDPipeIODevice::Private::startReaderThread(): waiting for hasStarted (CONSUMER THREAD)
015835B0: Reader::run: started
015835B0: Reader::run: rptr=0, wptr=0 -> numBytes=4096
015835B0: Reader::run: trying to read 4096 bytes from fd -1
015835B0 (fd=-1): Reader::run: read 100 bytes
015835B0 (fd=-1): Reader::run: Content-Type: text/plain;
charset="us-ascii"
Content-Transfer-Encoding: 7bit
test
23456z7u8
015835B0: Reader::run: buffer before: rptr= 0, wptr= 0
015835B0: Reader::run: buffer after: rptr= 0, wptr= 100
015835B0: Reader::run: buffer no longer empty, waking everyone
notifyReadyRead: 100 bytes available
notifyReadyRead: emit signal
KDPipeIODevice::Private::startReaderThread(): returned from hasStarted (CONSUMER THREAD)
015832E8: KDPipeIODevice::readData: try to lock reader (CONSUMER THREAD)
015832E8: KDPipeIODevice::readData: locked reader (CONSUMER THREAD)
015832E8: KDPipeIODevice::readData: got bufferNotEmptyCondition, trying to read 100 bytes
015835B0: KDPipeIODevice::readData: data=0158E588, maxSize=100; rptr=0, wptr=0 (bytesInBuffer=100); -> numRead=100
015835B0: KDPipeIODevice::readData: signal bufferNotFullCondition
015832E8: KDPipeIODevice::readData: read 100 bytes
015832E8 (fd=-1): KDPipeIODevice::readData: Content-Type: text/plain;
charset="us-ascii"
Content-Transfer-Encoding: 7bit
test
23456z7u8
notifyReadyRead: returning from waiting, leave
015835B0: Reader::run: rptr=0, wptr=0 -> numBytes=4096
015835B0: Reader::run: trying to read 4096 bytes from fd -1
015835B0: Reader::run: got eof (broken pipe)
015835B0 (fd=-1): Reader::run: read 0 bytes
015835B0 (fd=-1): Reader::run: Content-Type: text/plain;
charset="us-ascii"
Content-Transfer-Encoding: 7bit
test
23456z7u8
015835B0: Reader::run: received eof(1) or error(0), waking everyone
notifyReadyRead: 0 bytes available
notifyReadyRead: emit signal
KDPipeIODevice::Private::emitReadyRead 01581E28
KDPipeIODevice::Private::emitReadyRead 01581E28: locking reader (CONSUMER THREAD)
KDPipeIODevice::Private::emitReadyRead 01581E28: locked reader (CONSUMER THREAD)
KDPipeIODevice::Private::emitReadyRead 01581E28: buffer empty: 1 reader in ReadFile: 0
notifyReadyRead: returning from waiting, leave
KDPipeIODevice::Private::emitReadyRead 01581E28 leaving
KDPipeIODevice::Private::emitReadyRead 01581E28
KDPipeIODevice::Private::emitReadyRead 01581E28: locking reader (CONSUMER THREAD)
KDPipeIODevice::Private::emitReadyRead 01581E28: locked reader (CONSUMER THREAD)
KDPipeIODevice::Private::emitReadyRead 01581E28: buffer empty: 1 reader in ReadFile: 0
KDPipeIODevice::Private::emitReadyRead 01581E28 leaving
015832E8: KDPipeIODevice::readData: data=0158E588, maxSize=512
015832E8: KDPipeIODevice::readData: try to lock reader (CONSUMER THREAD)
015832E8: KDPipeIODevice::readData: locked reader (CONSUMER THREAD)
015832E8: KDPipeIODevice::readData: got empty buffer, signal eof
ReaderStatusThread[2nd]: .oOO
ReaderStatusThread[2nd]: new iteration command= "__check__" ; nullSlot= true
gpgagent_transact( GETEVENTCOUNTER )
get_event_counter(): got ( status( "EVENTCOUNTER" ) = "101 0 101"
)
ReaderStatusThread[2nd]: .zZZ
ReaderStatusThread[2nd]: .oOO
ReaderStatusThread[2nd]: new iteration command= "__check__" ; nullSlot= true
gpgagent_transact( GETEVENTCOUNTER )
get_event_counter(): got ( status( "EVENTCOUNTER" ) = "101 0 101"
)
ReaderStatusThread[2nd]: .zZZ
ReaderStatusThread[2nd]: .oOO
ReaderStatusThread[2nd]: new iteration command= "__check__" ; nullSlot= true
gpgagent_transact( GETEVENTCOUNTER )
get_event_counter(): got ( status( "EVENTCOUNTER" ) = "101 0 101"
)
ReaderStatusThread[2nd]: .zZZ
ReaderStatusThread[2nd]: .oOO
ReaderStatusThread[2nd]: new iteration command= "__check__" ; nullSlot= true
gpgagent_transact( GETEVENTCOUNTER )
get_event_counter(): got ( status( "EVENTCOUNTER" ) = "101 0 101"
)
ReaderStatusThread[2nd]: .zZZ
ReaderStatusThread[2nd]: .oOO
ReaderStatusThread[2nd]: new iteration command= "__check__" ; nullSlot= true
gpgagent_transact( GETEVENTCOUNTER )
get_event_counter(): got ( status( "EVENTCOUNTER" ) = "101 0 101"
)
ReaderStatusThread[2nd]: .zZZ
ReaderStatusThread[2nd]: .oOO
ReaderStatusThread[2nd]: new iteration command= "__check__" ; nullSlot= true
gpgagent_transact( GETEVENTCOUNTER )
get_event_counter(): got ( status( "EVENTCOUNTER" ) = "101 0 101"
)
ReaderStatusThread[2nd]: .zZZ
ReaderStatusThread[2nd]: .oOO
ReaderStatusThread[2nd]: new iteration command= "__check__" ; nullSlot= true
gpgagent_transact( GETEVENTCOUNTER )
get_event_counter(): got ( status( "EVENTCOUNTER" ) = "101 0 101"
)
ReaderStatusThread[2nd]: .zZZ
ReaderStatusThread[2nd]: .oOO
ReaderStatusThread[2nd]: new iteration command= "__check__" ; nullSlot= true
gpgagent_transact( GETEVENTCOUNTER )
get_event_counter(): got ( status( "EVENTCOUNTER" ) = "101 0 101"
)
ReaderStatusThread[2nd]: .zZZ
ReaderStatusThread[2nd]: .oOO
ReaderStatusThread[2nd]: new iteration command= "__check__" ; nullSlot= true
gpgagent_transact( GETEVENTCOUNTER )
get_event_counter(): got ( status( "EVENTCOUNTER" ) = "101 0 101"
)
ReaderStatusThread[2nd]: .zZZ
ReaderStatusThread[2nd]: .oOO
ReaderStatusThread[2nd]: new iteration command= "__check__" ; nullSlot= true
gpgagent_transact( GETEVENTCOUNTER )
get_event_counter(): got ( status( "EVENTCOUNTER" ) = "101 0 101"
)
ReaderStatusThread[2nd]: .zZZ
More information about the devel
mailing list