Page MenuHome GnuPG

Kleopatra: Encoding problems with GnuPG output on Windows
Testing, HighPublic

Description

Notices with refresh-keys but I also had this on other places where Gpg Output was used in Kleopatra.

I think that stringFromGpgOutput (I think that is what is called) might be wrong now that GnuPG trys to always output UTF-8

Reproducable with German l10n and refresh-keys. Both the output window and the error message (if there is an error) have broken umlauts.

Event Timeline

There are a very large number of changes, so older changes are hidden. Show Older Changes
ikloecker moved this task from Restricted Project Column to Restricted Project Column on the Restricted Project board.
ikloecker moved this task from Restricted Project Column to Restricted Project Column on the Restricted Project board.

The texts for GnuPG error codes should now be displayed correctly.

Found this one in Gpg4win-4.2.0-beta384:

ebo moved this task from Restricted Project Column to Restricted Project Column on the Restricted Project board.Sep 5 2023, 11:59 AM

Found in GnuPG-VS-Desktop-3.2.0-beta178, broken ü and no linebreaks:

Setting this to high after consultation with @werner, these issues should be fixed in next release.

ebo raised the priority of this task from Normal to High.Sep 5 2023, 12:00 PM
In T5960#175302, @ebo wrote:

Found in GnuPG-VS-Desktop-3.2.0-beta178, broken ü and no linebreaks:

Setting this to high after consultation with @werner, these issues should be fixed in next release.

This is export to server. This one seems to come from a direct call to gpg instead of using gpgme. Very bad.

Please provide the debug output, so that I can see which encoding was used to decode the error message.

Debugview:

[1400] org.kde.pim.kleopatra: "C:\\Program Files (x86)\\GnuPG VS-Desktop\\GnuPG\\bin\\gpg.exe --send-keys 3A12118AD7F4CBB6FF38C6B8F615AD82F702FA1F gestartet ..."
[1400] org.kde.pim.kleopatra: "gpg: NOTE: THIS IS A DEVELOPMENT VERSION!\r\ngpg: It is only intended for test purposes and should NOT be\r\ngpg: used in a production environment or with production keys!\r\ngpg: enabled debug flags: memstat trust extprog\r\ngpg: enabled compatibility flags:"
[1400] org.kde.pim.kleopatra: "gpg: sende Schlüssel F615AD82F702FA1F auf ldap://"
[1400] org.kde.pim.kleopatra: "gpg: Senden an Schlüsselserver fehlgeschlagen: Ungültige LDAP Credentials\r\ngpg: Senden an Schlüsselserver fehlgeschlagen: Ungültige LDAP Credentials\r\ngpg: keydb: handles=1 locks=0 parse=1 get=1\r\ngpg:        build=0 update=0 insert=0 delete=0\r\ngpg:        reset=0 found=1 not=0 cache=0 not=0\r\ngpg: kid_not_found_cache: count=0 peak=0 flushes=0\r\ngpg: sig_cache: total=2 cached=2 good=2 bad=0\r\ngpg: random usage: poolsize=600 mixed=0 polls=0/0 added=0/0\r\n              outmix=0 getlvl1=0/0 getlvl2=0/0\r\ngpg: rndjent stat: collector=0x00000000 calls=0 bytes=0\r\ngpg: secmem usage: 0/32768 bytes in 0 blocks"

Do you need this for the ü-error in the error message on keytocard, too?

The debug output of libkleo is missing. Please add org.kde.pim.libkleo.debug=true to your qtlogging.ini.

[2188] org.kde.pim.libkleo: gpgConfGetConsoleOutputCodePage starting "C:\\Program Files x86)\\GnuPG VS-Desktop\\bin\\..\\GnuPG\\bin\\gpgconf.exe" --show-codepages
[2188] org.kde.pim.libkleo: gpgConfGetConsoleOutputCodePage returns 0

With regard to the ü-error in the error message on keytocard somebody else has to check what's going wrong because I'm convinced that we are doing everything right.

In gpgme (src/version.c) we call

gettext_use_utf8 (1);

which is supposed to force libgpg-error's gettext to return UTF-8 encoded messages.

And in libkleo Formatting::errorAsString which is used for the error message on keytocard we do

#if defined(Q_OS_WIN) && GPGMEPP_ERROR_ASSTRING_RETURNS_UTF8_ON_WINDOWS
    return QString::fromUtf8(error.asString());
#else
    return QString::fromLocal8Bit(error.asString());
#endif

I'm blind to seeing where this goes wrong.

Edit: The above changes have landed in the code in April 2023. It should be double-checked that Gpg4win-4.2.0-beta384 didn't use older code. Best check again with the latest build.

The previous two changes will hopefully fix the error output of export to server. I'm not entirely sure about the missing line breaks.

ikloecker moved this task from Restricted Project Column to Restricted Project Column on the Restricted Project board.

Also, please retest T5960#172860 with the latest build.

/home/aheinecke/dev/main/src/gpg4win/src/playground/build/libkleo-202309061056/src/utils/gnupg.cpp: In function 'QString Kleo::stringFromGpgOutput(const QByteArray&)':
/home/aheinecke/dev/main/src/gpg4win/src/playground/build/libkleo-202309061056/src/utils/gnupg.cpp:573:53: error: passing 'const QByteArray' as 'this' argument discards qualifiers [-fpermissive]
  573 |         const auto s = fromEncoding(cpno, ba.replace("\r\n", "\n").constData());
      |                                           ~~~~~~~~~~^~~~~~~~~~~~~~
In file included from /home/aheinecke/dev/main/src/gpg4win/src/playground/install/include/QtCore/qstring.h:50,
                 from /home/aheinecke/dev/main/src/gpg4win/src/playground/install/include/QtCore/qhashfunctions.h:44,
                 from /home/aheinecke/dev/main/src/gpg4win/src/playground/install/include/QtCore/qlist.h:47,
                 from /home/aheinecke/dev/main/src/gpg4win/src/playground/install/include/QtCore/qstringlist.h:41,
                 from /home/aheinecke/dev/main/src/gpg4win/src/playground/install/include/QtCore/QStringList:1,
                 from /home/aheinecke/dev/main/src/gpg4win/src/playground/build/libkleo-202309061056/src/utils/gnupg.h:16,
                 from /home/aheinecke/dev/main/src/gpg4win/src/playground/build/libkleo-202309061056/src/utils/gnupg.cpp:18:
/home/aheinecke/dev/main/src/gpg4win/src/playground/install/include/QtCore/qbytearray.h:738:20: note:   in call to 'QByteArray& QByteArray::replace(const char*, const char*)'
  738 | inline QByteArray &QByteArray::replace(const char *before, const char *after)

Hopefully, we will soon have a Windows CI to catch such errors.

Also, please retest T5960#172860 with the latest build.

The ü there is still broken in Gpg4win-4.2.1-beta31 build today with up to date libkleo (but 3 days old gpgme)

[6064] org.kde.pim.kleopatra: KeyToCardCommand::doStart()
[6064] org.kde.pim.kleopatra: KeyToCardCommand::Private::start()
[6064] org.kde.pim.kleopatra: ReaderStatus::getCard() - Found card with serial number "D2760001240100000006154932980000" and app "openpgp"
[6064] org.kde.pim.kleopatra: KeyToCardCommand::Private::startKeyToOpenPGPCard()
[6064] org.kde.pim.kleopatra: ReaderStatus::getCard() - Found card with serial number "D2760001240100000006154932980000" and app "openpgp"
[6064] org.kde.pim.kleopatra: ReaderStatusThread[2nd]: new iteration command= "KEYTOCARD --force 8B8713E028E9DC05A4FEA1B70A21B293C2081819 D2760001240100000006154932980000 OPENPGP.2 20230308T111545"  ; nullSlot= false
[6064] org.kde.pim.libkleo: sendCommand "SCD SWITCHCARD D2760001240100000006154932980000"
[6064] org.kde.pim.libkleo: sendStatusLinesCommand "SCD SWITCHCARD D2760001240100000006154932980000" : got ( status( "SERIALNO" ) = "D2760001240100000006154932980000" 
[6064]  )
[6064] org.kde.pim.libkleo: sendCommand "SCD SWITCHAPP openpgp"
[6064] org.kde.pim.libkleo: sendStatusLinesCommand "SCD SWITCHAPP openpgp" : got ( status( "SERIALNO" ) = "D2760001240100000006154932980000 openpgp piv" 
[6064]  )
[6064] org.kde.pim.libkleo: sendCommand "KEYTOCARD --force 8B8713E028E9DC05A4FEA1B70A21B293C2081819 D2760001240100000006154932980000 OPENPGP.2 20230308T111545"
[6064] org.kde.pim.libkleo: sendCommand "KEYTOCARD --force 8B8713E028E9DC05A4FEA1B70A21B293C2081819 D2760001240100000006154932980000 OPENPGP.2 20230308T111545" failed: Ung?ltiger Wert (code: 55, source: SCD)

Then gettext_use_utf8 doesn't seem to be working as intended.

The previous two changes will hopefully fix the error output of export to server. I'm not entirely sure about the missing line breaks.

The result of your changes is a bit unexpected for me, maybe something is missing in the testversion Gpg4win-4.2.1-beta31?

[6064] org.kde.pim.kleopatra: Kleo::Commands::RevokeCertificationCommand(0x8a9c7d8) ~RevokeCertificationCommand
[6064] org.kde.pim.kleopatra: Kleo::Command(0x8a9c7d8) ~Command
[6064] org.kde.pim.kleopatra: Kleo::Command(0x8a9c7d8) ~Private
[6064] org.kde.pim.libkleo: gpgConfGetConsoleOutputCodePage starting "C:\\Program Files (x86)\\GnuPG\\bin\\gpgconf.exe" --show-codepages
[6064] org.kde.pim.libkleo: gpgConfGetConsoleOutputCodePage returns 65001
[6064] org.kde.pim.libkleo: stringFromGpgOutput trying to decode "" using codepage 65001
[6064] kf.i18n.kuit: "Markup error in message {<__kuit_internal_top__><para>Beim Export der OpenPGP-Zertifikate ist ein Fehler ...}: Unerwartet ''.. Last tag parsed: message. Complete message follows:\n<__kuit_internal_top__><para>Beim Export der OpenPGP-Zertifikate ist ein Fehler aufgetreten.</para> <para>Die Ausgabe von <command>C:\\Program Files (x86)\\GnuPG\\bin\\gpg.exe</command> lautet: <message>\u0000</message></para></__kuit_internal_top__>"
[6064] org.kde.pim.libkleo: stringFromGpgOutput trying to decode "" using codepage 65001
[6064] kf.i18n.kuit: "Markup error in message {<__kuit_internal_top__><para>Beim Export der OpenPGP-Zertifikate ist ein Fehler ...}: Unerwartet ''.. Last tag parsed: message. Complete message follows:\n<__kuit_internal_top__><para>Beim Export der OpenPGP-Zertifikate ist ein Fehler aufgetreten.</para> <para>Die Ausgabe von <command>C:\\Program Files (x86)\\GnuPG\\bin\\gpg.exe</command> lautet: <message>\u0000</message></para></__kuit_internal_top__>"
In T5960#175407, @ebo wrote:

The result of your changes is a bit unexpected for me, maybe something is missing in the testversion Gpg4win-4.2.1-beta31?

[6064] org.kde.pim.libkleo: gpgConfGetConsoleOutputCodePage returns 65001
[6064] org.kde.pim.libkleo: stringFromGpgOutput trying to decode "" using codepage 65001

Looks like the output of the command is empty. Maybe a timing problem?

[6064] kf.i18n.kuit: "Markup error in message {<__kuit_internal_top__><para>Beim Export der OpenPGP-Zertifikate ist ein Fehler ...}: Unerwartet ''.. Last tag parsed: message. Complete message follows:\n<__kuit_internal_top__><para>Beim Export der OpenPGP-Zertifikate ist ein Fehler aufgetreten.</para> <para>Die Ausgabe von <command>C:\\Program Files (x86)\\GnuPG\\bin\\gpg.exe</command> lautet: <message>\u0000</message></para></__kuit_internal_top__>"

Looks like we decode the string including the terminating null character.

This looks to me like the typical thing where you also do not get the "Diagnostics" button viewed. Because log-file is set in the various .conf files and the stderr does not get back to GPGME / Kleopatra so we have nothing to show there because the actual error ended up in a log file.

ok, with the new testversion VS-Desktop-3.2.0.0-beta214 and without Debug redirection (mea culpa), the info window looks like this:


And Debugview shows:

[3376] org.kde.pim.libkleo: gpgConfGetConsoleOutputCodePage starting "C:\\Program Files (x86)\\GnuPG VS-Desktop\\bin\\..\\GnuPG\\bin\\gpgconf.exe" --show-codepages
[3376] org.kde.pim.libkleo: gpgConfGetConsoleOutputCodePage ConsoleOutputCP is 0 - use ACP
[3376] org.kde.pim.libkleo: gpgConfGetConsoleOutputCodePage returns 0

I tried to reproduce this with a locally built gpg4win-4.2.1-beta56. Using localhost as keyserver I got (after a looooooong timeout)

with debug output

[6472] org.kde.pim.libkleo: gpgConfGetConsoleOutputCodePage starting "C:\\Program Files (x86)\\GnuPG\\bin\\gpgconf.exe" --show-codepages
[6472] org.kde.pim.libkleo: gpgConfGetConsoleOutputCodePage returns 65001
[...]
[6472] org.kde.pim.kleopatra: "C:\\Program Files (x86)\\GnuPG\\bin\\gpg.exe --send-keys 40C8670A86AC2B2C35AC6E1B25579E2EBB089E1B gestartet ..."
[...]
[6472] org.kde.pim.libkleo: stringFromGpgOutput trying to decode "gpg: sende Schl\xC3\xBCssel 25579E2EBB089E1B auf hkps://localhost" using codepage 65001
[6472] org.kde.pim.kleopatra: "gpg: sende Schlüssel 25579E2EBB089E1B auf hkps://localhost"
[6472] org.kde.pim.libkleo: stringFromGpgOutput trying to decode "gpg: Senden an Schl\xC3\xBCsselserver fehlgeschlagen: Unknown error\r\ngpg: Senden an Schl\xC3\xBCsselserver fehlgeschlagen: Unknown error" using codepage 65001
[6472] org.kde.pim.kleopatra: "gpg: Senden an Schlüsselserver fehlgeschlagen: Unknown error\ngpg: Senden an Schlüsselserver fehlgeschlagen: Unknown error"
[6472] org.kde.pim.libkleo: stringFromGpgOutput trying to decode "gpg: sende Schl\xC3\xBCssel 25579E2EBB089E1B auf hkps://localhost\r\ngpg: Senden an Schl\xC3\xBCsselserver fehlgeschlagen: Unknown error\r\ngpg: Senden an Schl\xC3\xBCsselserver fehlgeschlagen: Unknown error\r\n" using codepage 65001
[6472] org.kde.pim.libkleo: stringFromGpgOutput trying to decode "gpg: sende Schl\xC3\xBCssel 25579E2EBB089E1B auf hkps://localhost\r\ngpg: Senden an Schl\xC3\xBCsselserver fehlgeschlagen: Unknown error\r\ngpg: Senden an Schl\xC3\xBCsselserver fehlgeschlagen: Unknown error\r\n" using codepage 65001

The remaining problem with output that's read directly from a GnuPG process seems to be that sometimes gpgconf --show-codepages prints 0 as ConsoleOutputCodePage or even as ACP (as in T5960#175580).

If a valid ConsoleOutputCodePage is printed by gpgconf as in my previous comment, then the decoding works as intended.

I have no idea why gpgconf sometimes fails to print valid code pages. Maybe it depends on the way Kleopatra is started. I started it by double clicking the application icon on the desktop and by typing kleopatra in the Search field.

With regard to invalid characters in error messages as in T5960#172860:
We are using the identical function everywhere to convert the error codes to text. If an invalid character is displayed if copying a key to a smart card failed, then invalid characters should also be displayed for example if one tries to decrypt something in the notepad without having the necessary secret key. I get "Kein geheimer Schlüssel" in this case, i.e. no invalid character.

As far as I can tell and see with my limited tests, everything works (for me). There's nothing else I can do and I don't have the slightest clue why it seems to fail sometimes. Somebody else needs to take over.

In the VSD Testversion:

C:\Users\g10code.WIN-TEST3>gpgconf --show-codepages
Ungültige Option "--show-codepages"

So this seems to be an issue of the gpg version in VSD

gpgconf --show-codepages ist just a debugging aid. We use the code pages only for output to the console. The problem we see here is about log messages and they are always send as utf8 to stderr or the pipe used instead - without any translation.

From our always used init_common_subsystems:

#ifdef HAVE_W32_SYSTEM
  /* We want gettext to always output UTF-8 and we put the console in
   * utf-8 mode.  */
  gettext_use_utf8 (1);
  if (!SetConsoleCP (CP_UTF8) || !SetConsoleOutputCP (CP_UTF8))

With the latest change the output read directly from gpg should now be displayed correctly.

Error messages were already displayed correctly for me on Windows (T5960#175623).

ebo moved this task from Restricted Project Column to Restricted Project Column on the Restricted Project board.Sep 29 2023, 4:03 PM

This looks nice! One down...

But "Zeitüberschreitung" is still broken. (See pictures above.)
For retest of "ungültiger Wert" I would need a newer gpg4win Testversion.

ebo moved this task from Restricted Project Column to Restricted Project Column on the Restricted Project board.Oct 31 2023, 2:07 PM
ebo moved this task from Restricted Project Column to Restricted Project Column on the Restricted Project board.EditedNov 3 2023, 11:20 AM

with VS-Desktop-3.1.90.258-Beta the ü is still broken for "Zeitüberschreitung" in the error window which occurs in the context of keytocard:

[5780] org.kde.pim.libkleo: sendCommand "KEYTOCARD --force 1A63F7F35AB5F31A7BE34555DE616C0A2E48F32E D276000124010304000500009D400000 OPENPGP.1 20230308T111343" failed: Zeit?berschreitung (code: 62, source: Pinentry)

In the context of e.g. signing there is another kind of window, where the "ü" is displayed correctly.

For comparison, this is the debugview output if I don't give the passwort on import of a X.509 certificate, were the ü is displayed correctly:

[5780] org.kde.pim.kleopatra: Kleo::ImportCertificateFromFileCommand(0x9cc8ef0) addImportResult "Z:/neue_testzertifikate/ted.tester@demo.gnupg.com-sign.p12" Result: "Zeitüberschreitung"

From the "Prüfprotokoll":
gpgsm: DBG: chan_0x00000258 -> END
gpgsm: DBG: chan_0x00000258 <- ERR 83886142 Zeit�berschreitung <Pinentry>
gpgsm: gesamte verarbeitete Anzahl: 0
gpgsm: DBG: chan_0x00000158 -> S IMPORT_RES 0 0 0 0 0 0 0 0 0 0 0 0 0 0
gpgsm: Fehler beim Importieren des Zertifikats: Zeitüberschreitung

ikloecker changed the task status from Testing to Open.Nov 8 2023, 11:35 AM

I tried to reproduce this but I didn't succeed. I used "Create New OpenPGP Cert" for my attempts.

First try with unpatched error dialog. Note the slashes surrouding the error text.

Next try with added translation context "@info" which makes xi18nc output HTML. Note: Now the error text is printed italic. But the error message is not translated (because of the added translation context).

Next try with patched translations adding the message with context. Done to rule out (encoding of) translation playing a role in the issue.

Next try with the exact error message the encoding issue occurred with (but still with OpenPGP certificate creation).

Final try with the exact same code for the message box.

I have no idea why it should make a difference whether the error message is shown after OpenPGP certificate creation or after copying a key to a smart card. Everything should run in the main thread. I'll add some more debug output for further investigation.

ikloecker changed the task status from Open to Testing.Nov 10 2023, 8:28 AM

Setting back to Testing to get some more debug logs with a build that includes the latest commits.

I have no idea why it should make a difference whether the error message is shown after OpenPGP certificate creation or after copying a key to a smart card. Everything should run in the main thread. I'll add some more debug output for further investigation.

The one goes through GPGME and the other is talking directly to the agent so there is a big difference.

Sure. But in both cases they get back an error code and then, back in safe Kleopatra territory, they convert this error code into a string. I don't see how this error code to string conversion should have anything to do with the way the commands triggered the operation. Both conversions should happen in the main thread, so that the state of libgpg-error should be identical. The logging will show if in the still failing case libgpg-error is not switched to UTF-8 for localized texts.

Some logs after entering a wrong reset code (PUK) for an OpenPGP smart card.

404.228467	2024/05/27 15:56:17.987	8056	kleopatra.exe	org.kde.pim.libkleo: sendCommand "SCD PASSWD --reset OPENPGP.2" failed: "Falscher R?ckstellcode" (code: 322, source: SCD)
404.230320	2024/05/27 15:56:17.987	8056	kleopatra.exe	org.kde.pim.libkleo: errorAsString gettext_use_utf8(-1) returns 1
404.230596	2024/05/27 15:56:17.987	8056	kleopatra.exe	org.kde.pim.libkleo: errorAsString error: Falscher R?ckstellcode
404.231068	2024/05/27 15:56:17.987	8056	kleopatra.exe	org.kde.pim.libkleo: errorAsString error (percent-encoded): "Falscher%20R%FCckstellcode"
404.231182	2024/05/27 15:56:17.987	8056	kleopatra.exe	org.kde.pim.kleopatra: ChangePinCommand::slotResult(): "Falscher R?ckstellcode" ( 322 )
404.231315	2024/05/27 15:56:17.987	8056	kleopatra.exe	org.kde.pim.libkleo: errorAsString gettext_use_utf8(-1) returns 1
404.231428	2024/05/27 15:56:17.987	8056	kleopatra.exe	org.kde.pim.libkleo: errorAsString error: Falscher R?ckstellcode
404.231850	2024/05/27 15:56:17.987	8056	kleopatra.exe	org.kde.pim.libkleo: errorAsString error (percent-encoded): "Falscher%20R%FCckstellcode"

I think I have identified the root cause of the remaining issue with wrongly encoded error texts. The good thing is that the problem shouldn't occur if one does not enable debug logging for libkleo/kleopatra.

Analysis (Windows only):

  • GpgME's Error::asString is called from the ReaderStatus thread to output the log message [...] sendCommand [...] failed: [...] shown above.
  • On the first call Error::asString calls gpgme_strerror_r and stores the result in a member variable.
  • gpgme_strerror_r indirectly calls get_string (libgpg-error/src/w32-gettext.c).
  • get_string checks tls->gt_use_utf8 to determine whether the translation needs to be converted from UTF-8 to native encoding.
  • tls stands for "thread-local storage".
  • For each thread a tls instance is created (DllMain in libgpg-error/src/init.c). tls->gt_use_utf8 is initialized as 0.
  • On initialization, gpgme calls gettext_use_utf8(1) which sets tls->gt_use_utf8 to 1. But only for the main thread!

Conclusion: If Error::asString is called from a secondary thread then it caches a wrongly encoded error message. This cached error message is then returned on subsequent calls of Error::asString from the main thread.

I will submit a bug for libgpg-error because I think for secondary threads tls->gt_use_utf8 should be initialized to the value of the main thread. And I will add an alternative to Error::asString which doesn't cache the result of gpgme_strerror_r. Unfortunately, Error::asString is unfixable because it returns a const char * which wouldn't be thread-safe if the pointer didn't point to the cached member variable. It's ironic that a fix for making Error::asString more thread-safe introduced a bug if it's called from different threads.

Update: The bug for libgpg-error is T7185: Calling gettext_use_utf8(1) for the main thread should enable UTF-8 for all later created secondary threads.

Mark for backport to VSD 3.3

ikloecker changed the task status from Testing to Open.Jul 5 2024, 9:26 AM
ikloecker changed the task status from Open to Testing.Jul 5 2024, 5:34 PM
ikloecker moved this task from Backlog to WiP on the vsd33 board.

The final (known) encoding problem with broken umlauts in German error descriptions should be fixed.

Now even the error descriptions that are logged by background threads should have readable umlauts (see T7188).

ebo moved this task from Restricted Project Column to Restricted Project Column on the Restricted Project board.Thu, Sep 26, 4:40 PM

with gpg4win-Beta-50: "Rückstellcode" is shown correctly with an ü