Page MenuHome GnuPG
Create Task
Maniphest T4456

gpgme repeatedly segfaults claws-mail after update to 1.13.0
Closed, ResolvedPublic
Actions

Description

I'm on ArchLinux and use claws-mail, which depends on the gpgme library for signed mails. Recently claws mail started crashing "randomly" very often.
I reported this problem to the claws-mail developers first and provided them with backtraces of a debug build of claws-mail. Based on the traces they decided, that this is not a problem in claws-mail, but in gpgme.

I then checked and noticed that the gpgme package on ArchLinux was updated fairly recently as well. Downgrading the package from 1.13.0-1 to 1.12.0-2 fixed the issue for me.

So i have to assume that there is some bug or backwards compatibility issue in gpgme 1.13.0 that leads to segmentation faults.

Extract from the traces:

Thread 1 "claws-mail" received signal SIGSEGV, Segmentation fault.
0x0000555556cd8200 in ?? ()
[...]
Thread 1 (Thread 0x7ffff1f1fd00 (LWP 1573)):
#0  0x0000555556cd8200 in  ()
#1  0x00007fffeb32da92 in  () at /usr/lib/libgpgme.so.11
#2  0x00007fffeb336142 in  () at /usr/lib/libgpgme.so.11
#3  0x00007fffeb33c626 in  () at /usr/lib/libgpgme.so.11
#4  0x00007fffeb3266c3 in  () at /usr/lib/libgpgme.so.11
#5  0x00007fffeb33b804 in gpgme_ctx_set_engine_info () at /usr/lib/libgpgme.so.11
#6  0x00007fffeb31e0c5 in gpgme_get_key () at /usr/lib/libgpgme.so.11
#7  0x00007ffff013c556 in sgpgme_sigstat_info_short () at /usr/lib/claws-mail/plugins/pgpcore.so
#8  0x00007ffff0abce16 in  () at /usr/lib/claws-mail/plugins/smime.so
#9  0x00005555557ecc94 in privacy_mimeinfo_sig_info_short ()
#10 0x000055555575c5aa in  ()
#11 0x000055555575cad4 in  ()
#12 0x00007ffff68f3e53 in  () at /usr/lib/libglib-2.0.so.0
#13 0x00007ffff68f4661 in g_main_context_dispatch () at /usr/lib/libglib-2.0.so.0
#14 0x00007ffff68f6739 in  () at /usr/lib/libglib-2.0.so.0
#15 0x00007ffff68f76d2 in g_main_loop_run () at /usr/lib/libglib-2.0.so.0
#16 0x00007ffff7a75df3 in gtk_main () at /usr/lib/libgtk-x11-2.0.so.0
#17 0x000055555571ea5e in main ()

You can find the full backtraces in the claws-mail bug report in the "External Link".

Details

External Link
https://www.thewildbeast.co.uk/claws-mail/bugzilla/show_bug.cgi?id=4196
Version
1.13.0

Revisions and Commits

rM GPGME
rM7673ef795348 core: Fix duplication of close_notify_handler for gpgsm.

Event Timeline

Blubberbub created this task.Apr 11 2019, 10:53 AM
• werner triaged this task as High priority.Apr 11 2019, 11:23 AM
• werner added a subscriber: • werner.Apr 11 2019, 11:29 AM

Can you please run claws like this:

GPGME_DEBUG=9:/tmp/gpgme.log claws-mail

The first and last lines from that log file should be helpful for us. Take care if you need to use production keys and data and not test keys.

Blubberbub added a comment.Apr 11 2019, 12:54 PM

I did that. It felt like it took longer for the error to appear with debug output enabled, but that is probably subjective/random noise.

First lines:

GPGME 2019-04-11 11:32:05 <0x660e>  gpgme_debug: level=9
GPGME 2019-04-11 11:32:05 <0x660e>  gpgme_check_version: call: 0=(nil) req_version=1.0.0, VERSION=1.13.0
GPGME 2019-04-11 11:32:05 <0x660e>  gpgme_check_version_internal: call: 0=(nil) req_version=1.0.0, offset_sig_validity=60
GPGME 2019-04-11 11:32:05 <0x660e>  gpgme_set_locale: enter: ctx=(nil) category=0, value=de_DE.UTF-8
GPGME 2019-04-11 11:32:05 <0x660e>  gpgme_set_locale: leave: 
GPGME 2019-04-11 11:32:05 <0x660e>  gpgme_set_locale: enter: ctx=(nil) category=5, value=en_US.UTF-8
GPGME 2019-04-11 11:32:05 <0x660e>  gpgme_set_locale: leave: 
GPGME 2019-04-11 11:32:05 <0x660e>  gpgme-dinfo: gpgconf='/usr/bin/gpgconf'
GPGME 2019-04-11 11:32:05 <0x660e>  _gpgme_io_pipe: enter: filedes=0x7ffc1ce20098 inherit_idx=1 (GPGME uses it for reading)
GPGME 2019-04-11 11:32:05 <0x660e>  _gpgme_io_pipe: leave: read=0x16, write=0x17
GPGME 2019-04-11 11:32:05 <0x660e>  _gpgme_io_spawn: enter: path=0x560d87b5dc40 path=/usr/bin/gpgconf
GPGME 2019-04-11 11:32:05 <0x660e>  _gpgme_io_spawn: check: path=0x560d87b5dc40 argv[ 0] = /usr/bin/gpgconf
GPGME 2019-04-11 11:32:05 <0x660e>  _gpgme_io_spawn: check: path=0x560d87b5dc40 argv[ 1] = --list-dirs
GPGME 2019-04-11 11:32:05 <0x660e>  _gpgme_io_spawn: check: path=0x560d87b5dc40 fd[0] = 0x17 -> 0x1
GPGME 2019-04-11 11:32:05 <0x660e>  _gpgme_io_spawn: check: path=0x560d87b5dc40 waiting for child process pid=26130
GPGME 2019-04-11 11:32:05 <0x6613>    gpgme:max_fds: call: 0=(nil) max fds=24 (/proc)
GPGME 2019-04-11 11:32:05 <0x660e>    _gpgme_io_close: enter: fd=0x17 
GPGME 2019-04-11 11:32:05 <0x660e>    _gpgme_io_close: leave: result=0
GPGME 2019-04-11 11:32:05 <0x660e>  _gpgme_io_spawn: leave: result=0

Last lines of the log.

GPGME 2019-04-11 12:24:58 <0x6b90>  gpgme_data_release: call: dh=[redacted] 
GPGME 2019-04-11 12:24:58 <0x6b90>  gpgme_data_release: call: dh=[redacted]
GPGME 2019-04-11 12:24:58 <0x660e>  gpgme_get_key: enter: ctx=0x560d8833c0c0 fpr=[redacted], secret=0
GPGME 2019-04-11 12:24:58 <0x660e>    gpgme_new: enter: r_ctx=0x7ffc1ce22520 
GPGME 2019-04-11 12:24:58 <0x660e>    gpgme_new: leave: ctx=0x560d87f6b6e0
GPGME 2019-04-11 12:24:58 <0x660e>    gpgme_get_protocol: call: ctx=0x560d8833c0c0 ctx->protocol=1 (CMS)
GPGME 2019-04-11 12:24:58 <0x660e>    gpgme_set_protocol: enter: ctx=0x560d87f6b6e0 protocol=1 (CMS)
GPGME 2019-04-11 12:24:58 <0x660e>    gpgme_set_protocol: leave: 
GPGME 2019-04-11 12:24:58 <0x660e>    gpgme_get_keylist_mode: call: ctx=0x560d8833c0c0 ctx->keylist_mode=0x1
GPGME 2019-04-11 12:24:58 <0x660e>    gpgme_set_keylist_mode: call: ctx=0x560d87f6b6e0 keylist_mode=0x1
GPGME 2019-04-11 12:24:58 <0x660e>    gpgme_ctx_get_engine_info: call: ctx=0x560d8833c0c0 ctx->engine_info=0x560d87687cf0
GPGME 2019-04-11 12:24:58 <0x660e>    gpgme_ctx_set_engine_info: enter: ctx=0x560d87f6b6e0 protocol=1 (CMS), file_name=/usr/bin/gpgsm, home_dir=(default)
GPGME 2019-04-11 12:24:58 <0x660e>      _gpgme_io_pipe: enter: filedes=0x7ffc1ce223c8 inherit_idx=1 (GPGME uses it for reading)
GPGME 2019-04-11 12:24:58 <0x660e>      _gpgme_io_pipe: leave: read=0x21, write=0x22
GPGME 2019-04-11 12:24:58 <0x660e>      _gpgme_io_spawn: enter: path=0x560d8830df90 path=/usr/bin/gpgsm
GPGME 2019-04-11 12:24:58 <0x660e>      _gpgme_io_spawn: check: path=0x560d8830df90 argv[ 0] = /usr/bin/gpgsm
GPGME 2019-04-11 12:24:58 <0x660e>      _gpgme_io_spawn: check: path=0x560d8830df90 argv[ 1] = --version
GPGME 2019-04-11 12:24:58 <0x660e>      _gpgme_io_spawn: check: path=0x560d8830df90 fd[0] = 0x22 -> 0x1
GPGME 2019-04-11 12:24:58 <0x660e>      _gpgme_io_spawn: check: path=0x560d8830df90 waiting for child process pid=27541
GPGME 2019-04-11 12:24:58 <0x6b96>        gpgme:max_fds: call: 0=(nil) max fds=46 (/proc)
GPGME 2019-04-11 12:24:58 <0x660e>        _gpgme_io_close: enter: fd=0x22 
GPGME 2019-04-11 12:24:58 <0x660e>        _gpgme_io_close: check: fd=0x22 invoking close handler 0x7f341d8b8960/0x7f33f0003930
GPGME 2019-04-11 12:24:58 <0x660e>        _gpgme_io_close: leave: result=0
GPGME 2019-04-11 12:24:58 <0x660e>      _gpgme_io_spawn: leave: result=0
GPGME 2019-04-11 12:24:58 <0x660e>      _gpgme_io_read: enter: fd=0x21 buffer=0x7ffc1ce22410, count=79
GPGME 2019-04-11 12:24:58 <0x660e>      _gpgme_io_read: check: 677067736d202847 6e7550472920322e gpgsm (GnuPG) 2.
GPGME 2019-04-11 12:24:58 <0x660e>      _gpgme_io_read: check: 322e31350a6c6962 6763727970742031 2.15.libgcrypt 1
GPGME 2019-04-11 12:24:58 <0x660e>      _gpgme_io_read: check: 2e382e340a6c6962 6b73626120312e33 .8.4.libksba 1.3
GPGME 2019-04-11 12:24:58 <0x660e>      _gpgme_io_read: check: 2e350a436f707972 6967687420284329 .5.Copyright (C)
GPGME 2019-04-11 12:24:58 <0x660e>      _gpgme_io_read: check: 2032303139204672 656520536f6674    2019 Free Soft
GPGME 2019-04-11 12:24:58 <0x660e>      _gpgme_io_read: leave: result=79
GPGME 2019-04-11 12:24:58 <0x660e>      _gpgme_io_close: enter: fd=0x21 
GPGME 2019-04-11 12:24:58 <0x660e>      _gpgme_io_close: check: fd=0x21 invoking close handler 0x7f341d8b8960/0x560d87f6b000

I hope i redacted all the private information from the log, because i don't have test-data to reproduce it.

I hope you can get some information from these logs, because i cannot. The only thing i noticed is, that gpgsm gets added into the mix and that max fds changes between the beginning and the end of the log.

Blubberbub added a comment.Apr 16 2019, 2:47 PM

Can you see the problem and fix it with the given information?

I want to inform you, that I will be on vacation after this friday, so i will not be able to gather any more information about the problem on my system for two weeks.

If you need anything from me in order to find/fix/reproduce the problem it would be great if you could tell me as soon as possible, so i can provide you the information before i'm gone.

• gniibe added a subscriber: • gniibe.Apr 18 2019, 5:14 AM

Apparently, it SEGV-ted itself by assert at line 468 in gpgme/src/engine.c.
For GpgSM, info->file_name is not assigned (while it is done by gpg and gpgconf).
The code hasn't been changed for a while, I don't know the exact reason why it becomes occur.

• gniibe added a comment.Apr 19 2019, 6:05 AM

Sorry, I overlooked. I think it is inside _gpgme_io_close calling the handler, and the handler segfaults.

• gniibe added a comment.Apr 19 2019, 7:23 AM

Before the SEGV, calling a handler in _gpgme_io_close is strange:

GPGME 2019-04-11 12:24:58 <0x660e>        _gpgme_io_close: check: fd=0x22 invoking close handler 0x7f341d8b8960/0x7f33f0003930

Because the file descriptor 0x21 and 0x22 is allocated by _gpgme_io_pipe, and there should be no handler(s) for those fds.
Either, the notify_table is screwed up, or there is a leak of fds.
I'd like to see the logs of all calls of _gpgme_io_set_close_notify and _gpgme_io_close.

• gniibe changed the task status from Open to Testing.Apr 19 2019, 8:02 AM

I think I identified the bug. A fix is pushed.

• gniibe claimed this task.Apr 19 2019, 8:02 AM
• gniibe added a commit: rM7673ef795348: core: Fix duplication of close_notify_handler for gpgsm..Apr 19 2019, 8:04 AM
Blubberbub added a comment.May 15 2019, 4:19 PM

I patched version 1.13.0 with that commit and installed the patched version on Monday. It appears to have fixed the problem.

• werner moved this task from Backlog to QA for next release on the gpgme board.Jun 4 2019, 10:15 AM
• werner closed this task as Resolved.Jun 4 2019, 11:06 AM
• werner moved this task from QA for next release to gpgme 1.23.x on the gpgme board.Oct 25 2023, 10:42 AM
• werner edited projects, added gpgme (gpgme 1.23.x); removed gpgme.