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

From: Clément Pit--Claudel <[email-masked]>
Date: Sun, 11 Dec 2016 14:05:39 -0500

On 2016-12-11 12:52, Eli Zaretskii wrote:
>> From: Elias Mårtenson <[email-masked]>
>> Date: Mon, 12 Dec 2016 00:35:34 +0800
>>
>> #2  0x00000000005868ca in emacs_abort () at sysdep.c:2342
>> No locals.
>> #3  0x000000000057117a in unblock_input_to (level=-1) at keyboard.c:7170
>                                               ^^^^^^^^
> It aborts because level is negative.  Not sure how this happened.
> 
> Can you still see the problem with the current master?  I tried
> reproducing this on 2 different systems, and couldn't: it works as
> expected for me and doesn't crash.

I seem to have a similar problem with

    (make-thread (lambda () (sleep-for 5) (print 1)))

I sometimes need to run it a few times before it crashes.  I'm on the latest master.

(gdb) bt full
#0  0x00007ffff07b3428 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54
        resultvar = 0
        pid = 11760
        selftid = 11799
#1  0x00007ffff07b502a in __GI_abort () at abort.c:89
        save_stage = 2
        act = {__sigaction_handler = {sa_handler = 0x2020202020202020, sa_sigaction = 0x2020202020202020}, sa_mask = {
            __val = {3395749441387372576, 3414407380873671541, 7794943938178463864, 8461814194867891817, 
              3270285648122702895, 8299696943092622706, 734137523729608303, 3546132143273305655, 7378645706714656865, 
              3472384375719748966, 3467895374536122416, 2319406791620833328, 3904937764721408048, 2314907620205670965, 
              2314885530818453536, 2314885530818453536}}, sa_flags = 1937059616, sa_restorer = 0x61}
        sigs = {__val = {32, 0 <repeats 15 times>}}
#2  0x00007ffff07f57ea in __libc_message (do_abort=do_abort@entry=2, 
    fmt=fmt@entry=0x7ffff090e2e0 "*** Error in `%s': %s: 0x%s ***\n") at ../sysdeps/posix/libc_fatal.c:175
        ap = <error reading variable ap (Attempt to dereference a generic pointer.)>
        fd = 15
        on_2 = <optimized out>
        list = <optimized out>
        nlist = <optimized out>
        cp = <optimized out>
        written = <optimized out>
#3  0x00007ffff07fde0a in malloc_printerr (ar_ptr=<optimized out>, ptr=<optimized out>, 
    str=0x7ffff090e3a8 "double free or corruption (fasttop)", action=3) at malloc.c:5004
---Type <return> to continue, or q <return> to quit---
        buf = "000000000375bb10"
        cp = <optimized out>
        ar_ptr = <optimized out>
        str = 0x7ffff090e3a8 "double free or corruption (fasttop)"
        action = 3
#4  _int_free (av=<optimized out>, p=<optimized out>, have_lock=0) at malloc.c:3865
        size = <optimized out>
        fb = <optimized out>
        nextchunk = <optimized out>
        nextsize = <optimized out>
        nextinuse = <optimized out>
        prevsize = <optimized out>
        bck = <optimized out>
        fwd = <optimized out>
        errstr = <optimized out>
        locked = <optimized out>
#5  0x00007ffff080198c in __GI___libc_free (mem=<optimized out>) at malloc.c:2966
        ar_ptr = <optimized out>
        p = <optimized out>
        hook = <optimized out>
#6  0x00007ffff4f35555 in _XEventsQueued () from /usr/lib/x86_64-linux-gnu/libX11.so.6
No symbol table info available.
#7  0x00007ffff4f26f47 in XPending () from /usr/lib/x86_64-linux-gnu/libX11.so.6
---Type <return> to continue, or q <return> to quit---
No symbol table info available.
#8  0x00007ffff671cdae in ?? () from /usr/lib/x86_64-linux-gnu/libgdk-3.so.0
No symbol table info available.
#9  0x00007ffff569d92d in g_main_context_prepare () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
No symbol table info available.
#10 0x00007ffff569e2cb in ?? () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
No symbol table info available.
#11 0x00007ffff569e457 in g_main_context_pending () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
No symbol table info available.
#12 0x00000000005e36c0 in xg_select (fds_lim=<optimized out>, rfds=<optimized out>, wfds=<optimized out>, efds=0x0, 
    timeout=<optimized out>, sigmask=<optimized out>) at xgselect.c:160
        pselect_errno = 11
        all_rfds = {fds_bits = {64, 0 <repeats 15 times>}}
        all_wfds = {fds_bits = {0 <repeats 16 times>}}
        tmo = {tv_sec = 0, tv_nsec = 304000000}
        tmop = 0x7fffde709520
        context = 0x152b7a0
        have_wfds = <optimized out>
        gfds_buf = {{fd = 6, events = 1, revents = 0}, {fd = 7, events = 1, revents = 0}, {fd = 8, events = 1, 
            revents = 0}, {fd = 12, events = 1, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 24171632, 
            events = 0, revents = 0}, {fd = -563048304, events = 32767, revents = 0}, {fd = -563048312, 
            events = 32767, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 2147483647, events = 0, 
            revents = 0}, {fd = -357850320, events = 32767, revents = 0}, {fd = -217677327, events = 32767, 
---Type <return> to continue, or q <return> to quit---
            revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 1046005248, events = 18318, revents = 45690}, {
            fd = -563048448, events = 32767, revents = 0}, {fd = 24171632, events = 0, revents = 0}, {fd = -563048464, 
            events = 32767, revents = 0}, {fd = -134239019, events = 32767, revents = 0}, {fd = -563048416, 
            events = 32767, revents = 0}, {fd = 24180224, events = 1, revents = 0}, {fd = 1, events = 0, revents = 0}, 
          {fd = -563048304, events = 32767, revents = 0}, {fd = -563048312, events = 32767, revents = 0}, {fd = 0, 
            events = 0, revents = 0}, {fd = -563048416, events = 32767, revents = 0}, {fd = -259445626, 
            events = 32767, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 22198176, events = 0, revents = 0}, 
          {fd = 2147483647, events = 0, revents = 0}, {fd = -177614239, events = 32767, revents = 0}, {fd = 55474, 
            events = 0, revents = 0}, {fd = 914807005, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {
            fd = 1046005248, events = 18318, revents = 45690}, {fd = 22198176, events = 0, revents = 0}, {
            fd = -177608112, events = 32767, revents = 0}, {fd = -563048312, events = 32767, revents = 0}, {
            fd = -160314138, events = 32767, revents = 0}, {fd = 22198176, events = 0, revents = 0}, {fd = 2147483647, 
            events = 0, revents = 0}, {fd = -563048304, events = 32767, revents = 0}, {fd = -177611430, 
            events = 32767, revents = 0}, {fd = -563048240, events = 65535, revents = 65535}, {fd = 0, events = 0, 
            revents = 0}, {fd = 22198176, events = 0, revents = 0}, {fd = 1, events = 0, revents = 0}, {fd = 0, 
            events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 10217640, events = 0, revents = 0}, {
            fd = 1046005248, events = 18318, revents = 45690}, {fd = 11408464, events = 0, revents = 0}, {
            fd = 22198176, events = 0, revents = 0}, {fd = 4, events = 0, revents = 0}, {fd = -177613708, 
            events = 32767, revents = 0}, {fd = 22198176, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, 
          {fd = 22094688, events = 0, revents = 0}, {fd = -177609890, events = 32767, revents = 0}, {fd = 8, 
            events = 0, revents = 0}, {fd = -563047872, events = 0, revents = 0}, {fd = 2147483647, events = 0, 
            revents = 0}, {fd = 1046005248, events = 18318, revents = 45690}, {fd = 0, events = 0, revents = 0}, {
            fd = 22198176, events = 0, revents = 0}, {fd = -563048016, events = 32767, revents = 0}, {fd = 23799296, 
---Type <return> to continue, or q <return> to quit---
            events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, 
            events = 0, revents = 0}, {fd = -177609631, events = 32767, revents = 0}, {fd = 10264600, events = 0, 
            revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = -563048016, events = 32767, revents = 0}, {
            fd = -155524076, events = 32767, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 4987814, 
            events = 0, revents = 0}, {fd = 19092928, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {
            fd = -563048016, events = 32767, revents = 0}, {fd = 5214957, events = 0, revents = 0}, {fd = 0, 
            events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, 
            events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, 
            events = 0, revents = 0}, {fd = 1046005248, events = 18318, revents = 45690}, {fd = 1, events = 0, 
            revents = 0}, {fd = 1, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = -1, 
            events = 65535, revents = 8191}, {fd = 6, events = 0, revents = 0}, {fd = 1046005248, events = 18318, 
            revents = 45690}, {fd = 1, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, 
            events = 0, revents = 0}, {fd = 5563340, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {
            fd = 53718947, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 5, events = 0, 
            revents = 0}, {fd = -563047648, events = 32767, revents = 0}, {fd = 5695640, events = 0, revents = 0}, {
            fd = 57696608, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, 
            revents = 0}, {fd = 5563340, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, 
            events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 5, events = 0, revents = 0}, {
            fd = -563047568, events = 32767, revents = 0}, {fd = 5695640, events = 0, revents = 0}, {fd = 57696608, 
            events = 0, revents = 0}, {fd = 57696488, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {
            fd = 0, events = 0, revents = 0}, {fd = 12592064, events = 0, revents = 0}, {fd = 0, events = 0, 
            revents = 0}, {fd = -254450433, events = 32767, revents = 0}, {fd = 1, events = 0, revents = 0}, {
            fd = -563047504, events = 32767, revents = 0}, {fd = 1, events = 0, revents = 0}, {fd = -563047600, 
---Type <return> to continue, or q <return> to quit---
            events = 32767, revents = 0}, {fd = -134239004, events = 32767, revents = 0}, {fd = -563047424, 
            events = 32767, revents = 0}, {fd = 54403072, events = 1, revents = 0}}
        gfds = <optimized out>
        gfds_size = <optimized out>
        n_gfds = <optimized out>
        retval = 0
        our_fds = 1
        max_fds = <optimized out>
        context_acquired = true
        i = <optimized out>
        nfds = 1
        tmo_in_millisec = 304
        must_free = <optimized out>
        need_to_dispatch = true
#13 0x00000000005c5153 in really_call_select (arg=arg@entry=0x7fffde7093f0) at thread.c:494
        sa = 0x7fffde7093f0
        self = 0x3841340
#14 0x000000000054e77b in flush_stack_call_func (func=func@entry=0x5c5120 <really_call_select>, 
    arg=arg@entry=0x7fffde7093f0) at alloc.c:5137
        end = 0x7fffde7093a0
        self = <optimized out>
#15 0x00000000005c5887 in thread_select (func=<optimized out>, max_fds=<optimized out>, 
    rfds=rfds@entry=0x7fffde7096f0, wfds=wfds@entry=0x7fffde709770, efds=efds@entry=0x0, 
---Type <return> to continue, or q <return> to quit---
    timeout=timeout@entry=0x7fffde709520, sigmask=0x0) at thread.c:513
        sa = {func = 0x5e3320 <xg_select>, max_fds = 18, rfds = 0x7fffde7096f0, wfds = 0x7fffde709770, efds = 0x0, 
          timeout = 0x7fffde709520, sigmask = 0x0, result = 12930704}
#16 0x00000000005a9946 in wait_reading_process_output (time_limit=time_limit@entry=5, nsecs=nsecs@entry=0, 
    read_kbd=read_kbd@entry=0, do_display=do_display@entry=false, wait_for_cell=wait_for_cell@entry=0, 
    wait_proc=wait_proc@entry=0x0, just_wait_proc=0) at process.c:5345
        process_skipped = <optimized out>
        channel = <optimized out>
        nfds = <optimized out>
        Available = {fds_bits = {0 <repeats 16 times>}}
        Writeok = {fds_bits = {0 <repeats 16 times>}}
        check_write = <optimized out>
        check_delay = <optimized out>
        no_avail = <optimized out>
        xerrno = 4
        proc = <optimized out>
        timeout = {tv_sec = 0, tv_nsec = 227014373}
        end_time = {tv_sec = 1481482901, tv_nsec = 520691515}
        timer_delay = <optimized out>
        got_output_end_time = {tv_sec = 1481482901, tv_nsec = 520691515}
        wait = TIMEOUT
        got_some_output = -1
        retry_for_async = <optimized out>
---Type <return> to continue, or q <return> to quit---
        now = <optimized out>
#17 0x000000000041c9b3 in Fsleep_for (seconds=<optimized out>, milliseconds=<optimized out>) at dispnew.c:5695
        t = {tv_sec = 5, tv_nsec = 0}
        tend = {tv_sec = 1481482901, tv_nsec = 520691282}
        duration = <optimized out>
#18 0x0000000000567497 in eval_sub (form=<optimized out>) at eval.c:2214
        i = <optimized out>
        maxargs = 2
        args_left = 0
        numargs = <optimized out>
        fun = 8750293
        val = <optimized out>
        original_args = 51935619
        count = 1
        argvals = {22, 0, 19, 288, 140736925309536, 0, 19, 288}
#19 0x0000000000567c3d in Fprogn (body=51935411) at eval.c:450
        val = 0
#20 funcall_lambda (fun=51935379, nargs=nargs@entry=0, arg_vector=arg_vector@entry=0x3841368) at eval.c:3006
        val = <optimized out>
        syms_left = 0
        lexenv = 0
        i = <optimized out>
        optional = <optimized out>
---Type <return> to continue, or q <return> to quit---
        rest = <optimized out>
        previous_optional_or_rest = <optimized out>
#21 0x0000000000567eab in Ffuncall (nargs=nargs@entry=1, args=0x3841360) at eval.c:2749
        fun = <optimized out>
        original_fun = 51935379
        numargs = 0
        val = <optimized out>
        count = 0
#22 0x00000000005c55b3 in invoke_thread_function () at thread.c:603
        count = 0
#23 0x0000000000566302 in internal_condition_case (bfun=bfun@entry=0x5c5580 <invoke_thread_function>, 
    handlers=handlers@entry=45648, hfun=hfun@entry=0x5c4920 <do_nothing>) at eval.c:1336
        val = <optimized out>
        c = <optimized out>
#24 0x00000000005c5497 in run_thread (state=0x3841340) at thread.c:638
        stack_pos = 0 '\000'
        self = 0x3841340
        iter = <optimized out>
#25 0x00007ffff0d526ba in start_thread (arg=0x7fffde70a700) at pthread_create.c:333
        __res = <optimized out>
        pd = 0x7fffde70a700
        now = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140736925312768, 3652512205833442630, 0, 140737488342639, 
---Type <return> to continue, or q <return> to quit---
                140736925313472, 0, -3652445003701349050, -3652500843749370554}, mask_was_saved = 0}}, priv = {pad = {
              0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
        not_first_call = <optimized out>
        pagesize_m1 = <optimized out>
        sp = <optimized out>
        freesize = <optimized out>
        __PRETTY_FUNCTION__ = "start_thread"
#26 0x00007ffff088482d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109
No locals.