GNU bug report logs - #15794
Core dump after SIGTERM during GC marking

Previous Next

To add a comment to this bug, you must first unarchive it, by sending
a message to control AT debbugs.gnu.org, with unarchive 15794 in the body.
You can then email your comments to 15794 AT debbugs.gnu.org in the normal way.

Toggle the display of automated, internal messages from the tracker.

Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Barry OReilly <gundaetiapo <at> gmail.com>
To: bug-gnu-emacs <at> gnu.org
Subject: Core dump after SIGTERM during GC marking
Date: Sun, 3 Nov 2013 00:28:09 -0400

[Message part 1 (text/plain, inline)]

I noticed a core dump file in my file system that was almost a week old.
I'm not certain what was doing, but I think I was developing Elisp code
around the time which may have inf looped and led to me issuing the SIGTERM
indicated in the backtrace.

I have attached the output of 'bt full'.

In GNU Emacs 24.3.50.1 (x86_64-unknown-linux-gnu, GTK+ Version 3.4.2)
 of 2013-08-24 on epich-vb
Windowing system distributor `The X.Org Foundation', version 11.0.11103000
System Description:    Linux Mint 13 Maya

Configured using:
 `configure --prefix=/home/epich/s/sw/emacs/../emacs-install'

[Message part 2 (text/html, inline)]

[bt-full.txt (text/plain, attachment)]

Message #8 received at 15794 <at> debbugs.gnu.org (full text, mbox):

From: Andreas Schwab <schwab <at> linux-m68k.org>
To: Barry OReilly <gundaetiapo <at> gmail.com>
Cc: 15794 <at> debbugs.gnu.org
Subject: Re: bug#15794: Core dump after SIGTERM during GC marking
Date: Sun, 03 Nov 2013 07:37:04 +0100

Barry OReilly <gundaetiapo <at> gmail.com> writes:

> #60 0x00000000004ecaa5 in deliver_process_signal (sig=15, handler=0x4ebc30 <handle_fatal_signal>) at sysdep.c:1597
>         old_errno = 11
>         on_main_thread = true
> #61 <signal handler called>
> No symbol table info available.
> #62 string_intervals (s=57280353) at lisp.h:3129
> No locals.
> #63 mark_object (arg=<optimized out>) at alloc.c:5957
>         ptr = <optimized out>
>         ptrx = <optimized out>
>         obj = 59121106
>         cdr_count = 0

The signal was received during GC.  Shouldn't its handling be postponed
then?

Andreas.

-- 
Andreas Schwab, schwab <at> linux-m68k.org
GPG Key fingerprint = 58CA 54C7 6D53 942B 1756  01D3 44D5 214B 8276 4ED5
"And now for something completely different."

Message #11 received at 15794 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Barry OReilly <gundaetiapo <at> gmail.com>
Cc: 15794 <at> debbugs.gnu.org
Subject: Re: bug#15794: Core dump after SIGTERM during GC marking
Date: Sun, 03 Nov 2013 19:39:24 +0200

> Date: Sun, 3 Nov 2013 00:28:09 -0400
> From: Barry OReilly <gundaetiapo <at> gmail.com>
> 
> I noticed a core dump file in my file system that was almost a week old.
> I'm not certain what was doing

You can find the equivalent of "C-h l" in the variable recent_keys.

> but I think I was developing Elisp code
> around the time which may have inf looped and led to me issuing the SIGTERM
> indicated in the backtrace.
> 
> I have attached the output of 'bt full'.

Executive summary:

 . Emacs was in GC

 . You killed it with SIGTERM

 . Emacs started emergency shutdown, and as part of that invoked the
   hooks in kill-emacs-hook

 . One of those hooks hit a bad regexp, and tried to signal an error

 . 'signal' aborted because it noticed that Emacs is in GC

Since kill-emacs-hook is nil by default, it is hard to know what
exactly happened.  Please try to find out whoch function was run by
the hook at the point of the crash.  The easiest way of doing that is
to call "xbacktrace" (which is always recommended when reporting
bugs, btw).

In any case, running Lisp in the middle of GC is intrinsically
dangerous, so perhaps the error in regexp is due to that; hard to know
without seeing the pattern that was passed to compile_pattern_1.

Message #14 received at 15794 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Andreas Schwab <schwab <at> linux-m68k.org>
Cc: 15794 <at> debbugs.gnu.org, gundaetiapo <at> gmail.com
Subject: Re: bug#15794: Core dump after SIGTERM during GC marking
Date: Sun, 03 Nov 2013 19:41:09 +0200

> From: Andreas Schwab <schwab <at> linux-m68k.org>
> Date: Sun, 03 Nov 2013 07:37:04 +0100
> Cc: 15794 <at> debbugs.gnu.org
> 
> Barry OReilly <gundaetiapo <at> gmail.com> writes:
> 
> > #60 0x00000000004ecaa5 in deliver_process_signal (sig=15, handler=0x4ebc30 <handle_fatal_signal>) at sysdep.c:1597
> >         old_errno = 11
> >         on_main_thread = true
> > #61 <signal handler called>
> > No symbol table info available.
> > #62 string_intervals (s=57280353) at lisp.h:3129
> > No locals.
> > #63 mark_object (arg=<optimized out>) at alloc.c:5957
> >         ptr = <optimized out>
> >         ptrx = <optimized out>
> >         obj = 59121106
> >         cdr_count = 0
> 
> The signal was received during GC.  Shouldn't its handling be postponed
> then?

Maybe.  But then it would be impossible to kill Emacs during a runaway
GC in a way that would cause Emacs to auto-save, wouldn't it?

Perhaps a better alternative would be to avoid running kill-emacs-hook
in this case?

Message #17 received at 15794 <at> debbugs.gnu.org (full text, mbox):

From: Andreas Schwab <schwab <at> linux-m68k.org>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: 15794 <at> debbugs.gnu.org, gundaetiapo <at> gmail.com
Subject: Re: bug#15794: Core dump after SIGTERM during GC marking
Date: Sun, 03 Nov 2013 19:03:00 +0100

Eli Zaretskii <eliz <at> gnu.org> writes:

>> From: Andreas Schwab <schwab <at> linux-m68k.org>
>> Date: Sun, 03 Nov 2013 07:37:04 +0100
>> Cc: 15794 <at> debbugs.gnu.org
>> 
>> Barry OReilly <gundaetiapo <at> gmail.com> writes:
>> 
>> > #60 0x00000000004ecaa5 in deliver_process_signal (sig=15, handler=0x4ebc30 <handle_fatal_signal>) at sysdep.c:1597
>> >         old_errno = 11
>> >         on_main_thread = true
>> > #61 <signal handler called>
>> > No symbol table info available.
>> > #62 string_intervals (s=57280353) at lisp.h:3129
>> > No locals.
>> > #63 mark_object (arg=<optimized out>) at alloc.c:5957
>> >         ptr = <optimized out>
>> >         ptrx = <optimized out>
>> >         obj = 59121106
>> >         cdr_count = 0
>> 
>> The signal was received during GC.  Shouldn't its handling be postponed
>> then?
>
> Maybe.  But then it would be impossible to kill Emacs during a runaway
> GC in a way that would cause Emacs to auto-save, wouldn't it?

Even auto-save is a no-no in a signal handler.

Andreas.

-- 
Andreas Schwab, schwab <at> linux-m68k.org
GPG Key fingerprint = 58CA 54C7 6D53 942B 1756  01D3 44D5 214B 8276 4ED5
"And now for something completely different."

Message #20 received at 15794 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Andreas Schwab <schwab <at> linux-m68k.org>
Cc: 15794 <at> debbugs.gnu.org, gundaetiapo <at> gmail.com
Subject: Re: bug#15794: Core dump after SIGTERM during GC marking
Date: Sun, 03 Nov 2013 21:52:25 +0200

> From: Andreas Schwab <schwab <at> linux-m68k.org>
> Cc: 15794 <at> debbugs.gnu.org,  gundaetiapo <at> gmail.com
> Date: Sun, 03 Nov 2013 19:03:00 +0100
> 
> >> The signal was received during GC.  Shouldn't its handling be postponed
> >> then?
> >
> > Maybe.  But then it would be impossible to kill Emacs during a runaway
> > GC in a way that would cause Emacs to auto-save, wouldn't it?
> 
> Even auto-save is a no-no in a signal handler.

I don't see why.  Auto-save takes care to do only predictable things.
Not to mention that Emacs has been doing this for many years, and that
it's a valuable feature that it does.

Message #23 received at 15794 <at> debbugs.gnu.org (full text, mbox):

From: Barry OReilly <gundaetiapo <at> gmail.com>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: 15794 <at> debbugs.gnu.org, Andreas Schwab <schwab <at> linux-m68k.org>
Subject: Re: bug#15794: Core dump after SIGTERM during GC marking
Date: Sun, 3 Nov 2013 15:29:55 -0500

[Message part 1 (text/plain, inline)]

> Since kill-emacs-hook is nil by default, it is hard to know what
> exactly happened. Please try to find out whoch function was run by
> the hook at the point of the crash. The easiest way of doing that is
> to call "xbacktrace" (which is always recommended when reporting
> bugs, btw).

etc/DEBUG says to run GDB in the src directory. When I do that:

$ gdb emacs core
GNU gdb (Ubuntu/Linaro 7.4-2012.04-0ubuntu2) 7.4-2012.04
Copyright (C) 2012 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html
>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
For bug reporting instructions, please see:
<http://bugs.launchpad.net/gdb-linaro/>...
Reading symbols from /media/sda3/sw/emacs/src/emacs...done.
[New LWP 22588]
[New LWP 22589]
[New LWP 22590]
[New LWP 22591]

warning: Error reading shared library list entry at 0x2493ba3824548b44

warning: Error reading shared library list entry at 0x45c889440000017e
Core was generated by `emacs --reverse-video'.
Program terminated with signal 6, Aborted.
#0  0x00007f14dc5c5b7b in ?? ()
SIGINT is used by the debugger.
Are you sure you want to change it? (y or n) [answered Y; input not from
terminal]
DISPLAY = :0.0
TERM = xterm
Breakpoint 1 at 0x4d6250: file emacs.c, line 348.
Temporary breakpoint 2 at 0x4ef720: file sysdep.c, line 846.
(gdb) xbacktrace
You can't do that without a process to debug.
(gdb) quit

Probably has to do with emacs being an install of Emacs trunk as of
about August while the source tree is up to date. How do I get a
xbacktrace from an install?

My kill-emacs-hook is:

  (ede-save-cache semanticdb-kill-emacs-hook)

[Message part 2 (text/html, inline)]

Message #26 received at 15794 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Barry OReilly <gundaetiapo <at> gmail.com>
Cc: 15794 <at> debbugs.gnu.org, schwab <at> linux-m68k.org
Subject: Re: bug#15794: Core dump after SIGTERM during GC marking
Date: Sun, 03 Nov 2013 22:39:59 +0200

> Date: Sun, 3 Nov 2013 15:29:55 -0500
> From: Barry OReilly <gundaetiapo <at> gmail.com>
> Cc: Andreas Schwab <schwab <at> linux-m68k.org>, 15794 <at> debbugs.gnu.org
> 
> (gdb) xbacktrace
> You can't do that without a process to debug.

Sorry, I failed to mention that xbacktrace won't work on a core dump.

Message #29 received at 15794 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Barry OReilly <gundaetiapo <at> gmail.com>
Cc: 15794 <at> debbugs.gnu.org, schwab <at> linux-m68k.org
Subject: Re: bug#15794: Core dump after SIGTERM during GC marking
Date: Sun, 03 Nov 2013 22:42:15 +0200

> Date: Sun, 3 Nov 2013 15:29:55 -0500
> From: Barry OReilly <gundaetiapo <at> gmail.com>
> Cc: Andreas Schwab <schwab <at> linux-m68k.org>, 15794 <at> debbugs.gnu.org
> 
> (gdb) xbacktrace
> You can't do that without a process to debug.

Sorry, I failed to mention that xbacktrace won't work on a core dump.

But you should be able to display the value of kill-emacs-hook, by
walking its car and cdr links.

Message #32 received at 15794 <at> debbugs.gnu.org (full text, mbox):

From: Andreas Schwab <schwab <at> linux-m68k.org>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: 15794 <at> debbugs.gnu.org, gundaetiapo <at> gmail.com
Subject: Re: bug#15794: Core dump after SIGTERM during GC marking
Date: Sun, 03 Nov 2013 23:22:31 +0100

Eli Zaretskii <eliz <at> gnu.org> writes:

>> From: Andreas Schwab <schwab <at> linux-m68k.org>
>> Cc: 15794 <at> debbugs.gnu.org,  gundaetiapo <at> gmail.com
>> Date: Sun, 03 Nov 2013 19:03:00 +0100
>> 
>> >> The signal was received during GC.  Shouldn't its handling be postponed
>> >> then?
>> >
>> > Maybe.  But then it would be impossible to kill Emacs during a runaway
>> > GC in a way that would cause Emacs to auto-save, wouldn't it?
>> 
>> Even auto-save is a no-no in a signal handler.
>
> I don't see why.  Auto-save takes care to do only predictable things.

A lot of things that are a no-no in a signal handler, like calling
auto-save-hook.

> Not to mention that Emacs has been doing this for many years, and that
> it's a valuable feature that it does.

That's the nice thing about undefined behaviour, it can take a long time
until you see its ugly head.

Andreas.

-- 
Andreas Schwab, schwab <at> linux-m68k.org
GPG Key fingerprint = 58CA 54C7 6D53 942B 1756  01D3 44D5 214B 8276 4ED5
"And now for something completely different."

Message #35 received at 15794 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Andreas Schwab <schwab <at> linux-m68k.org>
Cc: 15794 <at> debbugs.gnu.org, gundaetiapo <at> gmail.com
Subject: Re: bug#15794: Core dump after SIGTERM during GC marking
Date: Mon, 04 Nov 2013 05:38:04 +0200

> From: Andreas Schwab <schwab <at> linux-m68k.org>
> Cc: 15794 <at> debbugs.gnu.org,  gundaetiapo <at> gmail.com
> Date: Sun, 03 Nov 2013 23:22:31 +0100
> 
> >> Even auto-save is a no-no in a signal handler.
> >
> > I don't see why.  Auto-save takes care to do only predictable things.
> 
> A lot of things that are a no-no in a signal handler, like calling
> auto-save-hook.

We could disable that (and the other things) as well.

Message #38 received at 15794 <at> debbugs.gnu.org (full text, mbox):

From: Andreas Schwab <schwab <at> suse.de>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: 15794 <at> debbugs.gnu.org, gundaetiapo <at> gmail.com
Subject: Re: bug#15794: Core dump after SIGTERM during GC marking
Date: Mon, 04 Nov 2013 09:56:44 +0100

Eli Zaretskii <eliz <at> gnu.org> writes:

>> From: Andreas Schwab <schwab <at> linux-m68k.org>
>> Cc: 15794 <at> debbugs.gnu.org,  gundaetiapo <at> gmail.com
>> Date: Sun, 03 Nov 2013 23:22:31 +0100
>> 
>> >> Even auto-save is a no-no in a signal handler.
>> >
>> > I don't see why.  Auto-save takes care to do only predictable things.
>> 
>> A lot of things that are a no-no in a signal handler, like calling
>> auto-save-hook.
>
> We could disable that (and the other things) as well.

You would have to disable opening files, too.

Andreas.

-- 
Andreas Schwab, SUSE Labs, schwab <at> suse.de
GPG Key fingerprint = 0196 BAD8 1CE9 1970 F4BE  1748 E4D4 88E3 0EEA B9D7
"And now for something completely different."

Message #41 received at 15794 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Andreas Schwab <schwab <at> suse.de>
Cc: 15794 <at> debbugs.gnu.org, gundaetiapo <at> gmail.com
Subject: Re: bug#15794: Core dump after SIGTERM during GC marking
Date: Mon, 04 Nov 2013 18:02:38 +0200

> From: Andreas Schwab <schwab <at> suse.de>
> Cc: 15794 <at> debbugs.gnu.org, gundaetiapo <at> gmail.com
> Date: Mon, 04 Nov 2013 09:56:44 +0100
> 
> Eli Zaretskii <eliz <at> gnu.org> writes:
> 
> >> From: Andreas Schwab <schwab <at> linux-m68k.org>
> >> Cc: 15794 <at> debbugs.gnu.org,  gundaetiapo <at> gmail.com
> >> Date: Sun, 03 Nov 2013 23:22:31 +0100
> >> 
> >> >> Even auto-save is a no-no in a signal handler.
> >> >
> >> > I don't see why.  Auto-save takes care to do only predictable things.
> >> 
> >> A lot of things that are a no-no in a signal handler, like calling
> >> auto-save-hook.
> >
> > We could disable that (and the other things) as well.
> 
> You would have to disable opening files, too.

What's wrong with opening files from a signal handler?  I always
thought that open(2) (and also write(2) and close(2)) are async-signal
safe on Posix systems, and this page

  http://pubs.opengroup.org/onlinepubs/9699919799/functions/V2_chap02.html

seems to agree.

Message #44 received at 15794 <at> debbugs.gnu.org (full text, mbox):

From: Andreas Schwab <schwab <at> suse.de>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: 15794 <at> debbugs.gnu.org, gundaetiapo <at> gmail.com
Subject: Re: bug#15794: Core dump after SIGTERM during GC marking
Date: Mon, 04 Nov 2013 17:18:41 +0100

Eli Zaretskii <eliz <at> gnu.org> writes:

>> From: Andreas Schwab <schwab <at> suse.de>
>> Cc: 15794 <at> debbugs.gnu.org, gundaetiapo <at> gmail.com
>> Date: Mon, 04 Nov 2013 09:56:44 +0100
>> 
>> Eli Zaretskii <eliz <at> gnu.org> writes:
>> 
>> >> From: Andreas Schwab <schwab <at> linux-m68k.org>
>> >> Cc: 15794 <at> debbugs.gnu.org,  gundaetiapo <at> gmail.com
>> >> Date: Sun, 03 Nov 2013 23:22:31 +0100
>> >> 
>> >> >> Even auto-save is a no-no in a signal handler.
>> >> >
>> >> > I don't see why.  Auto-save takes care to do only predictable things.
>> >> 
>> >> A lot of things that are a no-no in a signal handler, like calling
>> >> auto-save-hook.
>> >
>> > We could disable that (and the other things) as well.
>> 
>> You would have to disable opening files, too.
>
> What's wrong with opening files from a signal handler?  I always
> thought that open(2) (and also write(2) and close(2)) are async-signal
> safe on Posix systems, and this page

But fdopen isn't.

Andreas.

-- 
Andreas Schwab, SUSE Labs, schwab <at> suse.de
GPG Key fingerprint = 0196 BAD8 1CE9 1970 F4BE  1748 E4D4 88E3 0EEA B9D7
"And now for something completely different."

Message #47 received at 15794 <at> debbugs.gnu.org (full text, mbox):

From: Barry OReilly <gundaetiapo <at> gmail.com>
To: Andreas Schwab <schwab <at> suse.de>
Cc: 15794 <15794 <at> debbugs.gnu.org>, Eli Zaretskii <eliz <at> gnu.org>
Subject: Re: bug#15794: Core dump after SIGTERM during GC marking
Date: Tue, 5 Nov 2013 10:27:32 -0500

[Message part 1 (text/plain, inline)]

The bug is not easy to reproduce. In order to facilitate doing so, I
put a sleep in so as it is easier to issue the SIGTERM within GC. I
found GC marking normally takes about 10ms. I applied the following
patch to the Emacs sources:

diff --git a/src/alloc.c b/src/alloc.c
index b35f7c4..1d75e56 100644
--- a/src/alloc.c
+++ b/src/alloc.c
@@ -5487,6 +5487,10 @@ See Info node `(elisp)Garbage Collection'.  */)
   gc_in_progress = 1;

   /* Mark all the special slots that serve as the roots of accessibility.
*/
+  { struct timespec debug_ts; char debug_dateStr[20]; {
clock_gettime(CLOCK_REALTIME, &debug_ts); struct tm mytm;
localtime_r(&debug_ts.tv_sec, &mytm); strftime(debug_dateStr, 20,
"%Y-%m-%dT%H:%M:%S", &mytm); }
+       printf( "%s.%09ld|pid:%d|tid:%ld|%s|%d| DEBUG: GC: Start mark\n",
// TODO: debugging
+                         debug_dateStr, debug_ts.tv_nsec, getpid(),
pthread_self(), __FILE__, __LINE__ ); fflush(stdout); }
+  sleep(1);

   mark_buffer (&buffer_defaults);
   mark_buffer (&buffer_local_symbols);
@@ -5545,6 +5549,10 @@ See Info node `(elisp)Garbage Collection'.  */)
       mark_object (BVAR (nextb, undo_list));
     }

+  { struct timespec debug_ts; char debug_dateStr[20]; {
clock_gettime(CLOCK_REALTIME, &debug_ts); struct tm mytm;
localtime_r(&debug_ts.tv_sec, &mytm); strftime(debug_dateStr, 20,
"%Y-%m-%dT%H:%M:%S", &mytm); }
+       printf( "%s.%09ld|pid:%d|tid:%ld|%s|%d| DEBUG: GC: Start sweep\n",
// TODO: debugging
+                         debug_dateStr, debug_ts.tv_nsec, getpid(),
pthread_self(), __FILE__, __LINE__ ); fflush(stdout); }
+
   gc_sweep ();

   /* Clear the mark bits that we set in certain root slots.  */

I then started Emacs via GDB and issued a SIGTERM during the sleep. As
before, I witnessed an abort in a kill hook. The C and Lisp
backtraces:

#0  terminate_due_to_signal (sig=6, backtrace_limit=40) at emacs.c:349
#1  0x0000000000522303 in emacs_abort () at sysdep.c:2123
#2  0x000000000058a2d8 in Fsignal (error_symbol=12904418, data=29814278) at
eval.c:1465
#3  0x000000000058a5b9 in xsignal (error_symbol=6, data=40) at eval.c:1562
#4  0x000000000058aaea in xsignal2 (error_symbol=12904418, arg1=<value
optimized out>, arg2=<value optimized out>) at eval.c:1583
#5  0x00000000005700d6 in wrong_type_argument (predicate=40, value=1) at
data.c:205
#6  0x000000000058e43d in CHECK_TYPE (symbol=40, propname=<value optimized
out>) at lisp.h:953
#7  CHECK_SYMBOL (symbol=40, propname=<value optimized out>) at lisp.h:2402
#8  Fget (symbol=40, propname=<value optimized out>) at fns.c:1861
#9  0x00000000005c7709 in exec_byte_code (bytestr=6, vector=40, maxdepth=1,
args_template=12844642, nargs=0, args=0x4e) at bytecode.c:1332
#10 0x00000000005889e9 in eval_sub (form=<value optimized out>) at
eval.c:2165
#11 0x000000000058bf57 in internal_lisp_condition_case (var=12844642,
bodyform=26306566, handlers=<value optimized out>) at eval.c:1300
#12 0x00000000005c6f66 in exec_byte_code (bytestr=6, vector=40, maxdepth=1,
args_template=12844642, nargs=0, args=0x8f) at bytecode.c:1169
#13 0x000000000058909c in funcall_lambda (fun=25511693, nargs=2,
arg_vector=0x7fffffff82a0) at eval.c:3023
#14 0x000000000058935c in Ffuncall (nargs=3, args=<value optimized out>) at
eval.c:2850
#15 0x00000000005c5450 in exec_byte_code (bytestr=6, vector=40, maxdepth=1,
args_template=12844642, nargs=0, args=0x22) at bytecode.c:919
#16 0x000000000058909c in funcall_lambda (fun=21562829, nargs=2,
arg_vector=0x7fffffff8440) at eval.c:3023
#17 0x000000000058935c in Ffuncall (nargs=3, args=<value optimized out>) at
eval.c:2850
#18 0x00000000005c5450 in exec_byte_code (bytestr=6, vector=40, maxdepth=1,
args_template=12844642, nargs=0, args=0x22) at bytecode.c:919
#19 0x000000000058909c in funcall_lambda (fun=29060741, nargs=2,
arg_vector=0x7fffffff85d8) at eval.c:3023
#20 0x000000000058935c in Ffuncall (nargs=3, args=<value optimized out>) at
eval.c:2850
#21 0x0000000000589bdf in Fapply (nargs=2, args=0x7fffffff86c0) at
eval.c:2328
#22 0x00000000005895dc in Ffuncall (nargs=3, args=<value optimized out>) at
eval.c:2770
#23 0x00000000005c5450 in exec_byte_code (bytestr=6, vector=40, maxdepth=1,
args_template=12844642, nargs=0, args=0x22) at bytecode.c:919
#24 0x000000000058909c in funcall_lambda (fun=21522045, nargs=2,
arg_vector=0x7fffffff8820) at eval.c:3023
#25 0x000000000058a8f1 in apply_lambda (fun=21522045, args=26334146) at
eval.c:2898
#26 0x0000000000588336 in eval_sub (form=4611686018628714496) at eval.c:2234
#27 0x0000000000588d4f in Fprogn (body=<value optimized out>) at eval.c:447
#28 0x0000000000589032 in funcall_lambda (fun=29225190, nargs=2,
arg_vector=0x7fffffff8a30) at eval.c:3016
#29 0x000000000058935c in Ffuncall (nargs=3, args=<value optimized out>) at
eval.c:2850
#30 0x00000000005c5450 in exec_byte_code (bytestr=6, vector=40, maxdepth=1,
args_template=12844642, nargs=0, args=0x22) at bytecode.c:919
#31 0x000000000058909c in funcall_lambda (fun=29060941, nargs=2,
arg_vector=0x7fffffff8bc8) at eval.c:3023
#32 0x000000000058935c in Ffuncall (nargs=3, args=<value optimized out>) at
eval.c:2850
#33 0x0000000000589bdf in Fapply (nargs=2, args=0x7fffffff8cb0) at
eval.c:2328
#34 0x00000000005895dc in Ffuncall (nargs=3, args=<value optimized out>) at
eval.c:2770
#35 0x00000000005c5450 in exec_byte_code (bytestr=6, vector=40, maxdepth=1,
args_template=12844642, nargs=0, args=0x22) at bytecode.c:919
#36 0x000000000058909c in funcall_lambda (fun=28959853, nargs=2,
arg_vector=0x7fffffff8e50) at eval.c:3023
#37 0x000000000058935c in Ffuncall (nargs=3, args=<value optimized out>) at
eval.c:2850
#38 0x00000000005c5450 in exec_byte_code (bytestr=6, vector=40, maxdepth=1,
args_template=12844642, nargs=0, args=0x22) at bytecode.c:919
#39 0x000000000058909c in funcall_lambda (fun=29369645, nargs=2,
arg_vector=0x7fffffff8ff0) at eval.c:3023
#40 0x000000000058935c in Ffuncall (nargs=3, args=<value optimized out>) at
eval.c:2850
#41 0x00000000005c5450 in exec_byte_code (bytestr=6, vector=40, maxdepth=1,
args_template=12844642, nargs=0, args=0x22) at bytecode.c:919
#42 0x000000000058909c in funcall_lambda (fun=28595629, nargs=0,
arg_vector=0x7fffffff9180) at eval.c:3023
#43 0x000000000058935c in Ffuncall (nargs=1, args=<value optimized out>) at
eval.c:2850
#44 0x00000000005c5450 in exec_byte_code (bytestr=6, vector=40, maxdepth=1,
args_template=12844642, nargs=0, args=0x20) at bytecode.c:919
#45 0x000000000058909c in funcall_lambda (fun=28892277, nargs=1,
arg_vector=0x7fffffff9310) at eval.c:3023
#46 0x000000000058935c in Ffuncall (nargs=2, args=<value optimized out>) at
eval.c:2850
#47 0x00000000005c5450 in exec_byte_code (bytestr=6, vector=40, maxdepth=1,
args_template=12844642, nargs=0, args=0x21) at bytecode.c:919
#48 0x000000000058909c in funcall_lambda (fun=28595133, nargs=0,
arg_vector=0x7fffffff94e8) at eval.c:3023
#49 0x000000000058935c in Ffuncall (nargs=1, args=<value optimized out>) at
eval.c:2850
#50 0x0000000000589a69 in funcall_nil (nargs=6, args=0x28) at eval.c:2340
#51 0x0000000000586be0 in run_hook_with_args (nargs=1, args=0x7fffffff94e0,
funcall=0x589a60 <funcall_nil>) at eval.c:2525
#52 0x0000000000586c85 in Frun_hooks (nargs=1, args=0x7fffffff95a8) at
eval.c:2367
#53 0x00000000005895dc in Ffuncall (nargs=2, args=<value optimized out>) at
eval.c:2770
#54 0x00000000005c5450 in exec_byte_code (bytestr=6, vector=40, maxdepth=1,
args_template=5120, nargs=2, args=0x21) at bytecode.c:919
#55 0x000000000058935c in Ffuncall (nargs=3, args=<value optimized out>) at
eval.c:2850
#56 0x00000000005c5450 in exec_byte_code (bytestr=6, vector=40, maxdepth=1,
args_template=6168, nargs=6, args=0x22) at bytecode.c:919
#57 0x000000000058935c in Ffuncall (nargs=7, args=<value optimized out>) at
eval.c:2850
#58 0x00000000005c5450 in exec_byte_code (bytestr=6, vector=40, maxdepth=1,
args_template=4100, nargs=2, args=0x26) at bytecode.c:919
#59 0x000000000058935c in Ffuncall (nargs=3, args=<value optimized out>) at
eval.c:2850
#60 0x00000000005c5450 in exec_byte_code (bytestr=6, vector=40, maxdepth=1,
args_template=12844642, nargs=0, args=0x22) at bytecode.c:919
#61 0x00000000005889e9 in eval_sub (form=<value optimized out>) at
eval.c:2165
#62 0x000000000058bf57 in internal_lisp_condition_case (var=12844642,
bodyform=27909238, handlers=<value optimized out>) at eval.c:1300
#63 0x00000000005c6f66 in exec_byte_code (bytestr=6, vector=40, maxdepth=1,
args_template=12844642, nargs=0, args=0x8f) at bytecode.c:1169
#64 0x000000000058909c in funcall_lambda (fun=28480253, nargs=0,
arg_vector=0x7fffffff9e68) at eval.c:3023
#65 0x000000000058935c in Ffuncall (nargs=1, args=<value optimized out>) at
eval.c:2850
#66 0x0000000000589a69 in funcall_nil (nargs=6, args=0x28) at eval.c:2340
#67 0x0000000000586be0 in run_hook_with_args (nargs=1, args=0x7fffffff9e60,
funcall=0x589a60 <funcall_nil>) at eval.c:2525
#68 0x0000000000586c85 in Frun_hooks (nargs=1, args=0xbd2200) at eval.c:2367
#69 0x00000000005031d5 in Fkill_emacs (arg=60) at emacs.c:1891
#70 0x0000000000503300 in terminate_due_to_signal (sig=15,
backtrace_limit=40) at emacs.c:359
#71 0x000000000052238e in handle_fatal_signal (sig=6) at sysdep.c:1624
#72 0x0000000000522895 in deliver_process_signal (sig=15, handler=0x522380
<handle_fatal_signal>) at sysdep.c:1564
#73 <signal handler called>
#74 0x00000031cf09a080 in __nanosleep_nocancel () from /lib64/libc.so.6
#75 0x00000031cf099ed4 in sleep () from /lib64/libc.so.6
#76 0x000000000056ea7e in Fgarbage_collect () at alloc.c:5493
#77 0x000000000058810a in maybe_gc (form=29416886) at lisp.h:4387
#78 eval_sub (form=29416886) at eval.c:2058
#79 0x00000000005b063f in readevalloop (readcharfun=12973922,
stream=0x1b34e70, sourcename=17010609, printflag=false, unibyte=<value
optimized out>, readfun=12844642, start=12844642, end=12844642) at
lread.c:1876
#80 0x00000000005b45db in Fload (file=27104785, noerror=<value optimized
out>, nomessage=12844690, nosuffix=<value optimized out>,
must_suffix=<value optimized out>) at lread.c:1352
#81 0x0000000000593f46 in Frequire (feature=28527506, filename=27104785,
noerror=12844642) at fns.c:2658
#82 0x00000000005897bb in Ffuncall (nargs=2, args=<value optimized out>) at
eval.c:2796
#83 0x00000000005c5450 in exec_byte_code (bytestr=140737488332304,
vector=140737488332304, maxdepth=0, args_template=12844642, nargs=0,
args=0x21) at bytecode.c:919
#84 0x00000000005889e9 in eval_sub (form=<value optimized out>) at
eval.c:2165
#85 0x00000000005b063f in readevalloop (readcharfun=12973922,
stream=0x1b94f90, sourcename=15942977, printflag=false, unibyte=<value
optimized out>, readfun=12844642, start=12844642, end=12844642) at
lread.c:1876
#86 0x00000000005b45db in Fload (file=27125345, noerror=<value optimized
out>, nomessage=12844690, nosuffix=<value optimized out>,
must_suffix=<value optimized out>) at lread.c:1352
#87 0x0000000000593f46 in Frequire (feature=28526530, filename=27125345,
noerror=12844642) at fns.c:2658
#88 0x00000000005897bb in Ffuncall (nargs=2, args=<value optimized out>) at
eval.c:2796
#89 0x00000000005c5450 in exec_byte_code (bytestr=140737488332304,
vector=140737488332304, maxdepth=0, args_template=12844642, nargs=0,
args=0x21) at bytecode.c:919
#90 0x00000000005889e9 in eval_sub (form=<value optimized out>) at
eval.c:2165
#91 0x00000000005b063f in readevalloop (readcharfun=12973922,
stream=0x1b373d0, sourcename=27422081, printflag=false, unibyte=<value
optimized out>, readfun=12844642, start=12844642, end=12844642) at
lread.c:1876
#92 0x00000000005b45db in Fload (file=27463873, noerror=<value optimized
out>, nomessage=12844690, nosuffix=<value optimized out>,
must_suffix=<value optimized out>) at lread.c:1352
#93 0x0000000000593f46 in Frequire (feature=29444146, filename=27463873,
noerror=12844642) at fns.c:2658
#94 0x00000000005889e9 in eval_sub (form=<value optimized out>) at
eval.c:2165
#95 0x0000000000588d4f in Fprogn (body=<value optimized out>) at eval.c:447
#96 0x000000000058860a in eval_sub (form=<value optimized out>) at
eval.c:2107
#97 0x000000000058860a in eval_sub (form=<value optimized out>) at
eval.c:2107
#98 0x00000000005b063f in readevalloop (readcharfun=16137829, stream=0x0,
sourcename=15822161, printflag=false, unibyte=<value optimized out>,
readfun=12844642, start=12844642, end=12844642) at lread.c:1876
#99 0x00000000005b1eab in Feval_buffer (buffer=<value optimized out>,
printflag=12844642, filename=16137681, unibyte=12844642,
do_allow_print=12844690) at lread.c:1937
#100 0x000000000058983f in Ffuncall (nargs=6, args=<value optimized out>)
at eval.c:2805
#101 0x00000000005c5450 in exec_byte_code (bytestr=140737488332304,
vector=140737488332304, maxdepth=0, args_template=12844642, nargs=0,
args=0x25) at bytecode.c:919
#102 0x000000000058909c in funcall_lambda (fun=9040965, nargs=4,
arg_vector=0x7fffffffbc38) at eval.c:3023
#103 0x000000000058935c in Ffuncall (nargs=5, args=<value optimized out>)
at eval.c:2850
#104 0x0000000000589949 in call4 (fn=<value optimized out>, arg1=<value
optimized out>, arg2=0, arg3=-1, arg4=0) at eval.c:2637
#105 0x00000000005b447c in Fload (file=16139217, noerror=12844690,
nomessage=12844690, nosuffix=<value optimized out>, must_suffix=12844642)
at lread.c:1294
#106 0x000000000058983f in Ffuncall (nargs=4, args=<value optimized out>)
at eval.c:2805
#107 0x00000000005c5450 in exec_byte_code (bytestr=140737488332304,
vector=140737488332304, maxdepth=0, args_template=0, nargs=0, args=0x23) at
bytecode.c:919
#108 0x000000000058935c in Ffuncall (nargs=1, args=<value optimized out>)
at eval.c:2850
#109 0x00000000005c5450 in exec_byte_code (bytestr=140737488332304,
vector=140737488332304, maxdepth=0, args_template=0, nargs=0, args=0x20) at
bytecode.c:919
#110 0x000000000058935c in Ffuncall (nargs=1, args=<value optimized out>)
at eval.c:2850
#111 0x000000000058871f in eval_sub (form=<value optimized out>) at
eval.c:2131
#112 0x000000000058bf57 in internal_lisp_condition_case (var=16899698,
bodyform=12817510, handlers=<value optimized out>) at eval.c:1300
#113 0x00000000005c6f66 in exec_byte_code (bytestr=140737488332304,
vector=140737488332304, maxdepth=0, args_template=0, nargs=0, args=0x8f) at
bytecode.c:1169
#114 0x000000000058935c in Ffuncall (nargs=1, args=<value optimized out>)
at eval.c:2850
#115 0x00000000005c5450 in exec_byte_code (bytestr=140737488332304,
vector=140737488332304, maxdepth=0, args_template=0, nargs=0, args=0x20) at
bytecode.c:919
#116 0x000000000058a8f1 in apply_lambda (fun=9398557, args=12844642) at
eval.c:2898
#117 0x0000000000588336 in eval_sub (form=4611686018628714496) at
eval.c:2234
#118 0x000000000058b212 in Feval (form=16182630, lexical=<value optimized
out>) at eval.c:1977
#119 0x00000000005871c4 in internal_condition_case (bfun=0x509f30
<top_level_2>, handlers=12904226, hfun=0x50f0e0 <cmd_error>) at eval.c:1331
#120 0x000000000050d5f6 in top_level_1 (ignore=<value optimized out>) at
keyboard.c:1175
#121 0x0000000000587088 in internal_catch (tag=12900162, func=0x50d590
<top_level_1>, arg=12844642) at eval.c:1097
#122 0x000000000050d468 in command_loop () at keyboard.c:1136
#123 recursive_edit_1 () at keyboard.c:776
#124 0x000000000050e5a7 in Frecursive_edit () at keyboard.c:840
#125 0x0000000000504a2d in main (argc=<value optimized out>,
argv=0x7fffffffc8e8) at emacs.c:1592

Lisp Backtrace:
"byte-code" (0xffff7fc0)
"eieio-oref" (0xffff82a0)
"slot-boundp" (0xffff8440)
"ede-project-autoload" (0xffff85d8)
"apply" (0xffff86c0)
"eieio-generic-call-primary-only" (0xffff8820)
"ede-project-root-directory" (0xffff8a30)
0x1bb6f48 PVEC_COMPILED
"apply" (0xffff8cb0)
"ede-dir-to-projectfile" (0xffff8e50)
"ede-directory-project-p" (0xffff8ff0)
"ede-initialize-state-current-buffer" (0xffff9180)
"ede-minor-mode" (0xffff9310)
"ede-turn-on-hook" (0xffff94e8)
"run-hooks" (0xffff95a8)
"after-find-file" (0xffff9728)
"find-file-noselect-1" (0xffff98f0)
"find-file-noselect" (0xffff9a50)
"byte-code" (0xffff9b60)
"ede-save-cache" (0xffff9e68)
"Automatic GC" (0xc33108)
"require" (0xffffad50)
"byte-code" (0xffffae50)
"require" (0xffffb250)
"byte-code" (0xffffb350)
"require" (0xffffb6f0)
"progn" (0xffffb808)
"if" (0xffffb8c8)
"eval-buffer" (0xffffba90)
"load-with-code-conversion" (0xffffbc38)
"load" (0xffffbee8)
0x8f8610 PVEC_COMPILED
0xf72a28 PVEC_COMPILED
"funcall" (0xffffc160)
"command-line" (0xffffc478)
"normal-top-level" (0xffffc570)

[Message part 2 (text/html, inline)]

Message #50 received at 15794 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Barry OReilly <gundaetiapo <at> gmail.com>
Cc: schwab <at> suse.de, 15794 <at> debbugs.gnu.org
Subject: Re: bug#15794: Core dump after SIGTERM during GC marking
Date: Tue, 05 Nov 2013 17:53:17 +0200

> Date: Tue, 5 Nov 2013 10:27:32 -0500
> From: Barry OReilly <gundaetiapo <at> gmail.com>
> Cc: Eli Zaretskii <eliz <at> gnu.org>, 15794 <15794 <at> debbugs.gnu.org>
> 
> I then started Emacs via GDB and issued a SIGTERM during the sleep. As
> before, I witnessed an abort in a kill hook. The C and Lisp
> backtraces:

Thanks.  But the Lisp backtrace doesn't tell which function of the
kill-emacs-hook was running, and the C backtrace is different (no
trace of regexp functions) anyway, and GC didn't really start doing
its job, so it's not exactly the same crash.

To try and see which function from those that are in kill-emacs-hook,
go to frame #68:

> #68 0x0000000000586c85 in Frun_hooks (nargs=1, args=0xbd2200) at eval.c:2367
> #69 0x00000000005031d5 in Fkill_emacs (arg=60) at emacs.c:1891
> #70 0x0000000000503300 in terminate_due_to_signal (sig=15,
> backtrace_limit=40) at emacs.c:359

And look at the variable 'args', which should be a list.  Since this
session crashed in GC, it is not safe to print Lisp objects with "pp"
and its likes.  Instead, you will have to walk the list using "xcar"
and "xcdr", display the type of each object in the list using "xtype",
and then display the object itself with the appropriate x* command,
normally "xsymbol", since the list is constructed from function
symbols.

If you cannot do this in frame 68 for some reason (yours is an
optimized build, so variables might not reflect the true state of
affairs), try the frame above it:

> #67 0x0000000000586be0 in run_hook_with_args (nargs=1, args=0x7fffffff9e60,
> funcall=0x589a60 <funcall_nil>) at eval.c:2525

Again, look at 'args'.

Btw, I'm not sure what we are trying to establish here.  Shutting down
Emacs in the middle of GC is inherently dangerous.

Message #53 received at 15794 <at> debbugs.gnu.org (full text, mbox):

From: Barry OReilly <gundaetiapo <at> gmail.com>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: Andreas Schwab <schwab <at> suse.de>, 15794 <15794 <at> debbugs.gnu.org>
Subject: Re: bug#15794: Core dump after SIGTERM during GC marking
Date: Tue, 5 Nov 2013 11:52:09 -0500

[Message part 1 (text/plain, inline)]

Since I can't reproduce the original crash, I am trying other means of
gathering evidence. A SIGTERM could be handled at any time right?
Including as in this artificial reproduction.

> But the Lisp backtrace doesn't tell which function of the
> kill-emacs-hook was running,

Yes it does. The hook is ede-save-cache. It is one of the two hooks my
configuration sets up, as I indicated earlier.

> and GC didn't really start doing its job, so it's not exactly the
> same crash.

It is after gc_in_progress = 1. Are you trying to argue Emacs cannot
possibly enter the SIGTERM handler between that and when GC "really
starts doing its job" (whenever that is)?

> And look at the variable 'args', which should be a list. Since this
> session crashed in GC, it is not safe to print Lisp objects with
> "pp" and its likes. Instead, you will have to walk the list using
> "xcar" and "xcdr", display the type of each object in the list using
> "xtype", and then display the object itself with the appropriate x*
> command, normally "xsymbol", since the list is constructed from
> function symbols.

Can this be done for core dump files?

[Message part 2 (text/html, inline)]

Message #56 received at 15794 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Barry OReilly <gundaetiapo <at> gmail.com>
Cc: schwab <at> suse.de, 15794 <at> debbugs.gnu.org
Subject: Re: bug#15794: Core dump after SIGTERM during GC marking
Date: Tue, 05 Nov 2013 19:16:51 +0200

> Date: Tue, 5 Nov 2013 11:52:09 -0500
> From: Barry OReilly <gundaetiapo <at> gmail.com>
> Cc: Andreas Schwab <schwab <at> suse.de>, 15794 <15794 <at> debbugs.gnu.org>
> 
> Since I can't reproduce the original crash, I am trying other means of
> gathering evidence.

I understand.  I'm just saying that you don't necessarily see the same
problem.

> A SIGTERM could be handled at any time right?
> Including as in this artificial reproduction.

Yes, but the effect and the results could be different.

> > But the Lisp backtrace doesn't tell which function of the
> > kill-emacs-hook was running,
> 
> Yes it does. The hook is ede-save-cache. It is one of the two hooks my
> configuration sets up, as I indicated earlier.

Maybe, but I will believe that when I see it explicitly.  Backtraces
from optimized builds are not to be trusted too much.

> > and GC didn't really start doing its job, so it's not exactly the
> > same crash.
> 
> It is after gc_in_progress = 1.

Yes, but the flag is not the issue here.  The issue here is that while
GC runs, it marks Lisp objects, which might make them look invalid to
Lisp code.  In addition, GC can compact strings and other objects, and
if the signal hits at that moment, Lisp code could start working on an
invalid string, or string whose data was moved elsewhere.  But all
this happens when mark_object and its subroutines have really done
some non-trivial job; when you stop GC before they start, all those
problems did not yet materialize.

> Are you trying to argue Emacs cannot possibly enter the SIGTERM
> handler between that and when GC "really starts doing its job"
> (whenever that is)?

No, of course not.

> > And look at the variable 'args', which should be a list. Since this
> > session crashed in GC, it is not safe to print Lisp objects with
> > "pp" and its likes. Instead, you will have to walk the list using
> > "xcar" and "xcdr", display the type of each object in the list using
> > "xtype", and then display the object itself with the appropriate x*
> > command, normally "xsymbol", since the list is constructed from
> > function symbols.
> 
> Can this be done for core dump files?

Yes, the commands I mentioned work for core dumps as well.  They just
manipulate bit masks.

Btw, if you want to see a better backtrace, both in C and in Lisp,
remove or rename the *.elc files of the involved packages.  then Emacs
will run the *.el files in the interpreter, and you will see much more
detail, instead of all those unhelpful exec_byte_code calls that tell
nothing about what is being invoked.

Message #59 received at 15794 <at> debbugs.gnu.org (full text, mbox):

From: Lars Ingebrigtsen <larsi <at> gnus.org>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: schwab <at> suse.de, Barry OReilly <gundaetiapo <at> gmail.com>,
 15794 <at> debbugs.gnu.org
Subject: Re: bug#15794: Core dump after SIGTERM during GC marking
Date: Sun, 29 Sep 2019 16:00:50 +0200

Eli Zaretskii <eliz <at> gnu.org> writes:

> Btw, if you want to see a better backtrace, both in C and in Lisp,
> remove or rename the *.elc files of the involved packages.  then Emacs
> will run the *.el files in the interpreter, and you will see much more
> detail, instead of all those unhelpful exec_byte_code calls that tell
> nothing about what is being invoked.

This was five years ago, and much has changed in this area since that
time, so I doubt that we'll be able to make further progress with this
bug report, and I'm closing it.  Please reopen if this problem is still
an issue.

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.