Subject: Re: bug#25172: 26.0.50; Concurrency feature, sit-for doesn't work (crashing and unexpected behaviour)

From: Elias Mårtenson <[email-masked]>
Date: Wed, 14 Dec 2016 11:02:43 +0800

This is the second test case. In this case, Emacs didn't crash when I ran
the test case and everything seemed to be working properly. I then ran the
test case several times in quick succession to get a lot more threads and
eventually, after I had tried to create 100 more threads and running out of
resources (I got an error suggesting that was the case) and I was about to
exit Emacs, it crashed.

Here is the backtrace from that session:

           PID: 30950 (emacs)
          UID: 50067 (emartenson)
          GID: 50067 (emartenson)
       Signal: 6 (ABRT)
    Timestamp: Wed 2016-12-14 10:56:06 SGT (6min ago)
 Command Line: dist/bin/emacs -Q
   Executable: /home/emartenson/src/emacs/dist/bin/emacs-26.0.50
Control Group: /system.slice/system-getty.slice/[email-masked]
         Unit: [email-masked]
        Slice: system-getty.slice
      Boot ID: 45a62f2ad9804a0b81fed25ad8faffab
   Machine ID: 50467f3a69eb4dbea19c8a2972949839
     Hostname: em-desktop
      Storage:
/var/lib/systemd/coredump/core.emacs.50067.45a62f2ad9804a0b81fed25ad
8faffab.30950.1481684166000000000000.lz4
      Message: Process 30950 (emacs) of user 50067 dumped core.

               Stack trace of thread 30950:
               #0  0x00007fef6f9ddf5f raise (libpthread.so.0)
               #1  0x0000000000553ac0 terminate_due_to_signal
(emacs-26.0.50)
               #2  0x0000000000578227 handle_fatal_signal (emacs-26.0.50)
               #3  0x00000000005781f8 deliver_thread_signal (emacs-26.0.50)
               #4  0x000000000057825e deliver_fatal_thread_signal
(emacs-26.0.50)
               #5  0x00007fef6f9de080 __restore_rt (libpthread.so.0)
               #6  0x00007fef6f23004f raise (libc.so.6)
               #7  0x00007fef6f23147a abort (libc.so.6)
               #8  0x00007fef6f228ea7 __assert_fail_base (libc.so.6)
               #9  0x00007fef6f228f52 __assert_fail (libc.so.6)
               #10 0x00007fef74262c4a n/a (libX11.so.6)
               #11 0x00007fef74262cfb n/a (libX11.so.6)
               #12 0x00007fef74262fed _XEventsQueued (libX11.so.6)
               #13 0x00007fef74254cb7 XPending (libX11.so.6)
               #14 0x00007fef760c2cde n/a (libgdk-3.so.0)
               #15 0x00007fef749cec89 g_main_context_prepare
(libglib-2.0.so.0)
               #16 0x00007fef749cf6ab n/a (libglib-2.0.so.0)
               #17 0x00007fef749cf847 g_main_context_pending
(libglib-2.0.so.0)
               #18 0x00007fef7657ecad gtk_events_pending (libgtk-3.so.0)
               #19 0x000000000051fc12 XTread_socket (emacs-26.0.50)
               #20 0x0000000000563d58 gobble_input (emacs-26.0.50)
               #21 0x00000000005641f1 handle_async_input (emacs-26.0.50)
               #22 0x0000000000564210 process_pending_signals
(emacs-26.0.50)
               #23 0x00000000005d1812 Fmake_list (emacs-26.0.50)
               #24 0x00000000005fefa5 concat (emacs-26.0.50)
               #25 0x00000000005fe9a6 Fcopy_sequence (emacs-26.0.50)
               #26 0x000000000055f400 timer_check (emacs-26.0.50)
               #27 0x000000000055d258 readable_events (emacs-26.0.50)
               #28 0x0000000000563ba1 get_input_pending (emacs-26.0.50)
               #29 0x0000000000569d9b detect_input_pending_run_timers
(emacs-26.0.5
0)
               #30 0x000000000064dde6 wait_reading_process_output
(emacs-26.0.50)
               #31 0x000000000042516e sit_for (emacs-26.0.50)
               #32 0x000000000055baae read_char (emacs-26.0.50)
               #33 0x000000000056857a read_key_sequence (emacs-26.0.50)
               #34 0x000000000055879f command_loop_1 (emacs-26.0.50)
               #35 0x00000000005f628a internal_condition_case
(emacs-26.0.50)
               #36 0x0000000000558098 command_loop_2 (emacs-26.0.50)
               #37 0x00000000005f5b57 internal_catch (emacs-26.0.50)
               #38 0x000000000055803a command_loop (emacs-26.0.50)
               #39 0x0000000000557756 recursive_edit_1 (emacs-26.0.50)
               #40 0x00000000005578d2 Frecursive_edit (emacs-26.0.50)
               #41 0x00000000005556cd main (emacs-26.0.50)
               #42 0x00007fef6f21d291 __libc_start_main (libc.so.6)
               #43 0x000000000041846a _start (emacs-26.0.50)

               Stack trace of thread 30952:
               #0  0x00007fef6f2dc48d poll (libc.so.6)
               #1  0x00007fef749cf786 n/a (libglib-2.0.so.0)
               #2  0x00007fef749cfb12 g_main_loop_run (libglib-2.0.so.0)
               #3  0x00007fef74fb5316 n/a (libgio-2.0.so.0)
               #4  0x00007fef749f70d5 n/a (libglib-2.0.so.0)
               #5  0x00007fef6f9d4454 start_thread (libpthread.so.0)
               #6  0x00007fef6f2e57df __clone (libc.so.6)

               Stack trace of thread 30951:
               #0  0x00007fef6f2dc48d poll (libc.so.6)
               #1  0x00007fef749cf786 n/a (libglib-2.0.so.0)
               #2  0x00007fef749cf89c g_main_context_iteration
(libglib-2.0.so.0)
               #3  0x00007fef749cf8e1 n/a (libglib-2.0.so.0)
               #4  0x00007fef749f70d5 n/a (libglib-2.0.so.0)
               #5  0x00007fef6f9d4454 start_thread (libpthread.so.0)
               #6  0x00007fef6f2e57df __clone (libc.so.6)

               Stack trace of thread 30953:
               #0  0x00007fef6f2dc48d poll (libc.so.6)
               #1  0x00007fef749cf786 n/a (libglib-2.0.so.0)
               #2  0x00007fef749cf89c g_main_context_iteration
(libglib-2.0.so.0)
               #3  0x00007fef65f434bd n/a (libdconfsettings.so)
               #4  0x00007fef749f70d5 n/a (libglib-2.0.so.0)
               #5  0x00007fef6f9d4454 start_thread (libpthread.so.0)
               #6  0x00007fef6f2e57df __clone (libc.so.6)

GNU gdb (GDB) 7.12
Copyright (C) 2016 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-pc-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from
/home/emartenson/src/emacs/dist/bin/emacs-26.0.50...done.

warning: core file may not match specified executable file.
[New LWP 30950]
[New LWP 30952]
[New LWP 30951]
[New LWP 30953]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/usr/lib/libthread_db.so.1".
Core was generated by `dist/bin/emacs -Q'.
Program terminated with signal SIGABRT, Aborted.
#0  0x00007fef6f9ddf5f in raise () from /usr/lib/libpthread.so.0
[Current thread is 1 (Thread 0x7fef778cba00 (LWP 30950))]
(gdb) bt full
#0  0x00007fef6f9ddf5f in raise () at /usr/lib/libpthread.so.0
#1  0x0000000000553ac0 in terminate_due_to_signal (sig=6,
backtrace_limit=40)
   at emacs.c:396
#2  0x0000000000578227 in handle_fatal_signal (sig=6) at sysdep.c:1685
#3  0x00000000005781f8 in deliver_thread_signal (sig=6, handler=0x57820d
<handle_fat
al_signal>) at sysdep.c:1659
       old_errno = 11
#4  0x000000000057825e in deliver_fatal_thread_signal (sig=6) at
sysdep.c:1697
#5  0x00007fef6f9de080 in <signal handler called> () at
/usr/lib/libpthread.so.0
#6  0x00007fef6f23004f in raise () at /usr/lib/libc.so.6
#7  0x00007fef6f23147a in abort () at /usr/lib/libc.so.6
#8  0x00007fef6f228ea7 in __assert_fail_base () at /usr/lib/libc.so.6
#9  0x00007fef6f228f52 in  () at /usr/lib/libc.so.6
#10 0x00007fef74262c4a in  () at /usr/lib/libX11.so.6
#11 0x00007fef74262cfb in  () at /usr/lib/libX11.so.6
#12 0x00007fef74262fed in _XEventsQueued () at /usr/lib/libX11.so.6
#13 0x00007fef74254cb7 in XPending () at /usr/lib/libX11.so.6
#14 0x00007fef760c2cde in  () at /usr/lib/libgdk-3.so.0
#15 0x00007fef749cec89 in g_main_context_prepare () at
/usr/lib/libglib-2.0.so.0
#16 0x00007fef749cf6ab in  () at /usr/lib/libglib-2.0.so.0
#17 0x00007fef749cf847 in g_main_context_pending () at
/usr/lib/libglib-2.0.so.0
#18 0x00007fef7657ecad in gtk_events_pending () at /usr/lib/libgtk-3.so.0
#19 0x000000000051fc12 in XTread_socket (terminal=0x123de40
<bss_sbrk_buffer+5752160
>, hold_quit=0x7ffe6b540fc0) at xterm.c:8897
       count = 0
       event_found = false
       dpyinfo = 0x471cd50
#20 0x0000000000563d58 in gobble_input () at keyboard.c:6880
       nr = 0
       hold_quit =
         {kind = NO_EVENT, part = scroll_bar_nowhere, code = 0, modifiers =
0, x =
0, y = 0, timestamp = 0, frame_or_window = 0, arg = 0}
       next = 0x0
       nread = 0
       err = false
       t = 0x123de40 <bss_sbrk_buffer+5752160>
#21 0x00000000005641f1 in handle_async_input () at keyboard.c:7135
       nread = 32766
#22 0x0000000000564210 in process_pending_signals () at keyboard.c:7149
#23 0x00000000005d1812 in Fmake_list (length=0, init=0) at alloc.c:2913
       val = 75342771
       size = 0
#24 0x00000000005fefa5 in concat (nargs=1, args=0x7ffe6b541208,
target_type=
   Lisp_Cons, last_special=false) at fns.c:680
       val = 13375328
       tail = 0
       this = 22175315
       toindex = 1481684167
       toindex_byte = 0
       result_len = 1
       result_len_byte = 1
       argnum = 1
       last_tail = 0
       prev = 5568549
       some_multibyte = false
       textprops = 0x0
       num_textprops = 0
       sa_avail = 16384
       sa_count = 4
       sa_must_free = false
#25 0x00000000005fe9a6 in Fcopy_sequence (arg=22175315) at fns.c:548
#26 0x000000000055f400 in timer_check () at keyboard.c:4514
       nexttime = {tv_sec = 140730699092560, tv_nsec = 13375328}
       timers = 0
       idle_timers = 140730699096416
       tem = 0
#27 0x000000000055d258 in readable_events (flags=1) at keyboard.c:3345
#28 0x0000000000563ba1 in get_input_pending (flags=1) at keyboard.c:6795
#29 0x0000000000569d9b in detect_input_pending_run_timers (do_display=true)
---Type <return> to continue, or q <return> to quit---
   at keyboard.c:9935
       old_timers_run = 104
#30 0x000000000064dde6 in wait_reading_process_output (time_limit=30,
nsecs=0, read_
kbd=-1, do_display=true, wait_for_cell=0, wait_proc=0x0, just_wait_proc=0)
   at process.c:5476
       old_timers_run = 104
       old_buffer = 0x48b2800
       old_window = 19844149
       leave = false
       process_skipped = false
       channel = 1024
       nfds = 1
       Available = {fds_bits = {64, 0 <repeats 15 times>}}
       Writeok = {fds_bits = {0 <repeats 16 times>}}
       check_write = true
       check_delay = 0
       no_avail = false
       xerrno = 11
       proc = 140730699093664
       timeout = {tv_sec = 0, tv_nsec = 0}
       end_time = {tv_sec = 1481684190, tv_nsec = 754967307}
       timer_delay = {tv_sec = 0, tv_nsec = 499151921}
       got_output_end_time = {tv_sec = 1481684190, tv_nsec = 754967307}
       wait = TIMEOUT
       got_some_output = -1
       retry_for_async = false
       count = 3
       now = {tv_sec = 0, tv_nsec = -1}
#31 0x000000000042516e in sit_for (timeout=122, reading=true,
display_option=1)
   at dispnew.c:5763
       sec = 30
       nsec = 0
       do_display = true
#32 0x000000000055baae in read_char (commandflag=1, map=21961475,
prev_event=0, used
_mouse_menu=0x7ffe6b541aff, end_time=0x0) at keyboard.c:2722
       tem0 = 5568549
       timeout = 30
       delay_level = 4
       buffer_size = 3
       c = 0
       jmpcount = 3
       local_getcjmp =
               {{__jmpbuf = {0, 1990301376317110879, 4293696,
140730699096416, 0, 0
, 1990301376688306783, -1989976898492548513}, __mask_was_saved = 0,
__saved_mask = {
__val = {13648768, 13233360, 6139553, 0, 140730699094336, 5568549,
18271280, 1323336
0, 5703494, 0, 140730699094384, 5568549, 19964883, 140730699094480,
6272103, 0}}}}
       save_jump =
               {{__jmpbuf = {0, 1999463896344836703, 0, 30, 0,
140666480590848, 199
9463894568548959, -1989976898492548513}, __mask_was_saved = 0, __saved_mask
= {__val
= {80, 0, 4098007, 0, 500000000, 0, 9223372036854775807, 0, 495901993, 0,
91783517,
140663768982032, 5632523, 21931219, 15478450176544054016, 0}}}}
       tem = 21961475
       save = 0
       previous_echo_area_message = 0
       also_record = 0
       reread = false
       recorded = false
       polling_stopped_here = false
       orig_kboard = 0x46f9900
#33 0x000000000056857a in read_key_sequence (keybuf=0x7ffe6b541cb0,
bufsize=30, prom
pt=0, dont_downcase_last=false, can_return_switch_frame=true,
fix_current_buffer=tru
e, prevent_redisplay=false) at keyboard.c:9136
       interrupted_kboard = 0x46f9900
       interrupted_frame = 0x12ebc30 <bss_sbrk_buffer+6464336>
       key = 4544753
       used_mouse_menu = false
       echo_local_start = 0
       last_real_key_start = 0
       keys_local_start = 0
---Type <return> to continue, or q <return> to quit---
       new_binding = 5
       count = 3
       t = 0
       echo_start = 0
       keys_start = 0
       current_binding = 21961475
       first_event = 0
       first_unbound = 31
       mock_input = 0
       fkey = {parent = 17969043, map = 17969043, start = 0, end = 0}
       keytran = {parent = 13711939, map = 13711939, start = 0, end = 0}
       indec = {parent = 17969059, map = 17969059, start = 0, end = 0}
       shift_translated = false
       delayed_switch_frame = 0
       original_uppercase = 0
       original_uppercase_position = -1
       dummyflag = false
       starting_buffer = 0x48b2800
       fake_prefixed_keys = 0
#34 0x000000000055879f in command_loop_1 () at keyboard.c:1373
       cmd = 140730699095552
       keybuf =
         {140730699095312, 6264856, 140730699095360, 4, 140730699095296,
515936, 3,
3, 0, 9555221, 140730699095360, 0, 140730699095392, 6263156, 0, 9567684,
13233360,
515936, 0, 140730699095392, 5568549, 0, 13233360, 5602788, 13233360,
140730699095440
, 0, 140730699095456, 5568549, 5602591}
       i = 1
       prev_modiff = 0
       prev_buffer = 0x0
       already_adjusted = false
#35 0x00000000005f628a in internal_condition_case (bfun=0x55838e
<command_loop_1>, h
andlers=19680, hfun=0x557b7b <cmd_error>) at eval.c:1336
       val = 5568549
       c = 0x45c0290
#36 0x0000000000558098 in command_loop_2 (ignore=0) at keyboard.c:1115
       val = 2
#37 0x00000000005f5b57 in internal_catch (tag=47088, func=0x55806f
<command_loop_2>,
arg=0) at eval.c:1101
       val = 5568549
       c = 0x45c0160
#38 0x000000000055803a in command_loop () at keyboard.c:1094
#39 0x0000000000557756 in recursive_edit_1 () at keyboard.c:700
       count = 1
       val = 140730699095856
#40 0x00000000005578d2 in Frecursive_edit () at keyboard.c:771
       count = 0
       buffer = 0
#41 0x00000000005556cd in main (argc=2, argv=0x7ffe6b542168) at
emacs.c:1691
       stack_bottom_variable = 0 '\000'
       do_initial_setlocale = true
       dumping = false
       skip_args = 0
       no_loadup = false
       junk = 0x0
       dname_arg = 0x0
       ch_to_dir = 0x0
       original_pwd = 0x0
       disable_aslr = false
       rlim = {rlim_cur = 8720384, rlim_max = 18446744073709551615}
       sockfd = -1

On 14 December 2016 at 10:58, Elias Mårtenson <[email-masked]> wrote:

> On 14 December 2016 at 00:26, Eli Zaretskii <[email-masked]> wrote:
>
>> > From: Elias Mårtenson <[email-masked]>
>> > Date: Tue, 13 Dec 2016 12:16:41 +0800
>> > Cc: Clément Pit--Claudel <[email-masked]>,
>> >       [email-masked]
>> >
>> > This is the output from the SIGABRT case. Again, there is a lot of
>> information before the actual "bt full" output:
>>
>> This shows exactly the situation which I imagined could happen: 3
>> threads, including the main thread, all running the code in xg_select
>> which calls unblock_input, and aborting due to the block level being
>> negative.
>>
>> Can you try removing the calls to block_input/unblock_input from
>> xgselect.c, and see if these crashes then stop?
>>
>
> I have tried this now, and it's much more stable now. It doesn't
> immediately crash, and sometimes it doesn't crash at all.
>
> When it crashes, it does so after several seconds, and I have captured two
> of these crashes.
>
> I will post these backtraces in the following two emails.
>
> Regards,
> Elias
>