Subject: bug#22790: 24.5; Infinite loop involving malloc called from signal handler

From: Andreas Gustafsson <[email-masked]>
Date: Mon, 29 Feb 2016 16:44:30 +0200

The lockup happened again.  There's still a SIGINT handler involved,
but at least there is only one of this time and not two recursive
ones.

The full backtrace and some additional gdb output are included below,
but I would think this two-line excerpt should be sufficient to
identify the bug (or at least _a_ bug, if there is more than one):

  #9  0x00007f7ff60cc266 in printf () from /usr/lib/libc.so.12
  #10 0x00000000004db715 in handle_interrupt (in_signal_handler=true) at keyboard.c:10364

That is, printf() is not a signal safe function, so emacs is invoking
undefined behavior by calling it from a signal handler.

> In any case, when this happens next, please use the procedure
> described in etc/DEBUG for locating the place where Emacs loops, and
> post that information.

As you can see from the gdb transcript below, the "step" function
didn't work, but "stepi" shows it looping within libpthread.

> Backtraces generated from an infloop
> interrupted in a random place tend to be random and don't provide
> enough information for finding out the reasons for the loop.

Even if you consider the backtrace to be suspect, code inspection
should suffice to show that the line

          printf ("Auto-save? (y or n) ");

in src/keyboard.c can be executed from a signal handler.
-- 
Andreas Gustafsson, [email-masked]

(gdb) where
#0  0x00007f7ff6c083e2 in ?? () from /usr/lib/libpthread.so.1
#1  0x00007f7ff6c08445 in ?? () from /usr/lib/libpthread.so.1
#2  0x00007f7ff6c08848 in ?? () from /usr/lib/libpthread.so.1
#3  0x00000000005c5486 in _malloc_internal (size=65536) at gmalloc.c:929
#4  0x00000000005c54fc in malloc (size=65536) at gmalloc.c:953
#5  0x00007f7ff60ed28c in __smakebuf () from /usr/lib/libc.so.12
#6  0x00007f7ff60ed125 in __swsetup () from /usr/lib/libc.so.12
#7  0x00007f7ff60cde92 in __vfprintf_unlocked () from /usr/lib/libc.so.12
#8  0x00007f7ff60d1258 in vfprintf () from /usr/lib/libc.so.12
#9  0x00007f7ff60cc266 in printf () from /usr/lib/libc.so.12
#10 0x00000000004db715 in handle_interrupt (in_signal_handler=true) at keyboard.c:10364
#11 0x00000000004db63e in handle_interrupt_signal (sig=2) at keyboard.c:10288
#12 0x00000000004e8b63 in deliver_process_signal (sig=2, handler=0x4db5f1 <handle_interrupt_signal>) at sysdep.c:1570
#13 0x00000000004db65a in deliver_interrupt_signal (sig=2) at keyboard.c:10295
#14 <signal handler called>
#15 0x00007f7ff6c083e2 in ?? () from /usr/lib/libpthread.so.1
#16 0x00007f7ff6c08445 in ?? () from /usr/lib/libpthread.so.1
#17 0x00007f7ff6c08848 in ?? () from /usr/lib/libpthread.so.1
#18 0x00000000005c5486 in _malloc_internal (size=1000) at gmalloc.c:929
#19 0x00000000005c54fc in malloc (size=1000) at gmalloc.c:953
#20 0x0000000000534f0d in xmalloc (size=1000) at alloc.c:677
#21 0x000000000057968f in Fprinc (object=8564569, printcharfun=11946034) at print.c:656
#22 0x000000000057a544 in print_error_message (data=41076294, stream=11944965, context=0x0, caller=11946034) at print.c:919
#23 0x000000000057a238 in Ferror_message_string (obj=41076294) at print.c:844
#24 0x000000000050e40e in auto_save_error (error_val=41076294) at fileio.c:5425
#25 0x000000000055787a in internal_condition_case (bfun=0x50e477 <auto_save_1>, handlers=11946082, hfun=0x50e3bf <auto_save_error>) at eval.c:1345
#26 0x000000000050eb76 in Fdo_auto_save (no_message=11946082, current_only=11946034) at fileio.c:5672
#27 0x00000000004cde3c in read_char (commandflag=1, map=41075894, prev_event=11946034, used_mouse_menu=0x7f7fffff9c0f, end_time=0x0) at keyboard.c:2751
#28 0x00000000004d932a in read_key_sequence (keybuf=0x7f7fffff9df0, bufsize=30, prompt=11946034, dont_downcase_last=false, can_return_switch_frame=true, fix_current_buffer=true, prevent_redisplay=false) at keyboard.c:9089
#29 0x00000000004cb5b0 in command_loop_1 () at keyboard.c:1453
#30 0x0000000000557882 in internal_condition_case (bfun=0x4cb1f1 <command_loop_1>, handlers=12016002, hfun=0x4cab3b <cmd_error>) at eval.c:1348
#31 0x00000000004caf5d in command_loop_2 (ignore=11946034) at keyboard.c:1178
#32 0x00000000005570b5 in internal_catch (tag=12108690, func=0x4caf37 <command_loop_2>, arg=11946034) at eval.c:1112
#33 0x00000000004caec0 in command_loop () at keyboard.c:1149
#34 0x00000000004ca737 in recursive_edit_1 () at keyboard.c:778
#35 0x00000000005017dd in read_minibuf (map=40555366, initial=37407873, prompt=18302785, expflag=false, histvar=12034962, histpos=0, defalt=11946034, allow_props=false, inherit_input_method=false) at minibuf.c:674
#36 0x0000000000501ffd in Fread_from_minibuffer (prompt=18302785, initial_contents=37407873, keymap=40555366, read=11946034, hist=12034962, default_value=11946034, inherit_input_method=11946034) at minibuf.c:957
#37 0x000000000055ab18 in Ffuncall (nargs=8, args=0x7f7fffffa398) at eval.c:2837
#38 0x0000000000599506 in exec_byte_code (bytestr=9425233, vector=9425269, maxdepth=72, args_template=8200, nargs=8, args=0x7f7fffffa918) at bytecode.c:916
#39 0x000000000055b0c7 in funcall_lambda (fun=9425189, nargs=8, arg_vector=0x7f7fffffa8d8) at eval.c:2978
#40 0x000000000055abb1 in Ffuncall (nargs=9, args=0x7f7fffffa8d0) at eval.c:2860
#41 0x0000000000503624 in Fcompleting_read (prompt=18302785, collection=12147074, predicate=12031842, require_match=11946034, initial_input=37407873, hist=12034962, def=11946034, inherit_input_method=11946034) at minibuf.c:1674
#42 0x000000000055ab77 in Ffuncall (nargs=8, args=0x7f7fffffaa70) at eval.c:2844
#43 0x0000000000599506 in exec_byte_code (bytestr=9416857, vector=9416893, maxdepth=92, args_template=6148, nargs=6, args=0x7f7fffffaff0) at bytecode.c:916
#44 0x000000000055b0c7 in funcall_lambda (fun=9416813, nargs=6, arg_vector=0x7f7fffffafc0) at eval.c:2978
#45 0x000000000055abb1 in Ffuncall (nargs=7, args=0x7f7fffffafb8) at eval.c:2860
#46 0x0000000000599506 in exec_byte_code (bytestr=9416657, vector=9416693, maxdepth=52, args_template=6148, nargs=6, args=0x7f7fffffb4f0) at bytecode.c:916
#47 0x000000000055b0c7 in funcall_lambda (fun=9416613, nargs=6, arg_vector=0x7f7fffffb4c0) at eval.c:2978
#48 0x000000000055abb1 in Ffuncall (nargs=7, args=0x7f7fffffb4b8) at eval.c:2860
#49 0x0000000000599506 in exec_byte_code (bytestr=13771137, vector=15498901, maxdepth=28, args_template=11946034, nargs=0, args=0x0) at bytecode.c:916
#50 0x000000000059899d in Fbyte_code (bytestr=13771137, vector=15498901, maxdepth=28) at bytecode.c:482
#51 0x00000000005595a6 in eval_sub (form=13294870) at eval.c:2187
#52 0x000000000055771f in internal_lisp_condition_case (var=11946034, bodyform=13294870, handlers=13294294) at eval.c:1317
#53 0x000000000059a671 in exec_byte_code (bytestr=13770785, vector=15499053, maxdepth=12, args_template=11946034, nargs=0, args=0x0) at bytecode.c:1162
#54 0x000000000055b3c0 in funcall_lambda (fun=15499117, nargs=6, arg_vector=0xec7f2d) at eval.c:3044
#55 0x000000000055abb1 in Ffuncall (nargs=7, args=0x7f7fffffbff8) at eval.c:2860
#56 0x0000000000599506 in exec_byte_code (bytestr=13774209, vector=15563853, maxdepth=28, args_template=11946034, nargs=0, args=0x0) at bytecode.c:916
#57 0x000000000055b3c0 in funcall_lambda (fun=15499165, nargs=3, arg_vector=0xed7c4d) at eval.c:3044
#58 0x000000000055aea5 in apply_lambda (fun=15499165, args=19767910, count=13) at eval.c:2919
#59 0x0000000000559777 in eval_sub (form=19767894) at eval.c:2226
#60 0x0000000000555e28 in Fprogn (body=19767958) at eval.c:462
#61 0x0000000000555dcd in Fcond (args=19767974) at eval.c:440
#62 0x0000000000559273 in eval_sub (form=19767382) at eval.c:2131
#63 0x0000000000555e28 in Fprogn (body=19767990) at eval.c:462
#64 0x0000000000556d09 in Flet (args=19767366) at eval.c:970
#65 0x0000000000559273 in eval_sub (form=19770054) at eval.c:2131
#66 0x0000000000555e28 in Fprogn (body=19768006) at eval.c:462
#67 0x0000000000556d09 in Flet (args=19770006) at eval.c:970
#68 0x0000000000559273 in eval_sub (form=19769894) at eval.c:2131
#69 0x000000000055939f in eval_sub (form=19769878) at eval.c:2147
#70 0x0000000000558dac in Feval (form=19769878, lexical=11946034) at eval.c:1996
#71 0x0000000000553732 in Fcall_interactively (function=18304242, record_flag=11946034, keys=11998845) at callint.c:345
#72 0x000000000055aa05 in Ffuncall (nargs=4, args=0x7f7fffffd248) at eval.c:2818
#73 0x0000000000599506 in exec_byte_code (bytestr=9460233, vector=9460269, maxdepth=52, args_template=4100, nargs=1, args=0x7f7fffffd760) at bytecode.c:916
#74 0x000000000055b0c7 in funcall_lambda (fun=9460189, nargs=1, arg_vector=0x7f7fffffd758) at eval.c:2978
#75 0x000000000055abb1 in Ffuncall (nargs=2, args=0x7f7fffffd750) at eval.c:2860
#76 0x000000000055a35f in call1 (fn=12009122, arg1=18304242) at eval.c:2610
#77 0x00000000004cb8a9 in command_loop_1 () at keyboard.c:1560
#78 0x0000000000557882 in internal_condition_case (bfun=0x4cb1f1 <command_loop_1>, handlers=12016002, hfun=0x4cab3b <cmd_error>) at eval.c:1348
#79 0x00000000004caf5d in command_loop_2 (ignore=11946034) at keyboard.c:1178
#80 0x00000000005570b5 in internal_catch (tag=12008098, func=0x4caf37 <command_loop_2>, arg=11946034) at eval.c:1112
#81 0x00000000004caf0f in command_loop () at keyboard.c:1157
#82 0x00000000004ca737 in recursive_edit_1 () at keyboard.c:778
#83 0x00000000004ca8a4 in Frecursive_edit () at keyboard.c:849
#84 0x00000000004c8aa4 in main (argc=4, argv=0x7f7fffffdb90) at emacs.c:1642
(gdb) step
Cannot find bounds of current function
(gdb) define s
Type commands for definition of "s".
End with a line saying just "end".
>stepi
>x/i $pc
>end
(gdb) s
0x00007f7ff6c08445 in ?? () from /usr/lib/libpthread.so.1
=> 0x7f7ff6c08445:      sub    $0x1,%ebp
(gdb) 
0x00007f7ff6c08448 in ?? () from /usr/lib/libpthread.so.1
=> 0x7f7ff6c08448:      jne    0x7f7ff6c08440
(gdb) 
0x00007f7ff6c08440 in ?? () from /usr/lib/libpthread.so.1
=> 0x7f7ff6c08440:      callq  0x7f7ff6c083e0
(gdb) 
0x00007f7ff6c083e0 in ?? () from /usr/lib/libpthread.so.1
=> 0x7f7ff6c083e0:      pause  
(gdb) 
0x00007f7ff6c083e2 in ?? () from /usr/lib/libpthread.so.1
=> 0x7f7ff6c083e2:      retq   
(gdb) 
0x00007f7ff6c08445 in ?? () from /usr/lib/libpthread.so.1
=> 0x7f7ff6c08445:      sub    $0x1,%ebp
(gdb) 
0x00007f7ff6c08448 in ?? () from /usr/lib/libpthread.so.1
=> 0x7f7ff6c08448:      jne    0x7f7ff6c08440
(gdb) 
0x00007f7ff6c08440 in ?? () from /usr/lib/libpthread.so.1
=> 0x7f7ff6c08440:      callq  0x7f7ff6c083e0
(gdb) 
0x00007f7ff6c083e0 in ?? () from /usr/lib/libpthread.so.1
=> 0x7f7ff6c083e0:      pause  
(gdb) 
0x00007f7ff6c083e2 in ?? () from /usr/lib/libpthread.so.1
=> 0x7f7ff6c083e2:      retq   
(gdb) 
0x00007f7ff6c08445 in ?? () from /usr/lib/libpthread.so.1
=> 0x7f7ff6c08445:      sub    $0x1,%ebp
(gdb) info threads
  Id   Target Id         Frame 
* 1    LWP 1             0x00007f7ff6c08445 in ?? () from /usr/lib/libpthread.so.1