bug#21028: Performance regression in revision af1a69f4d17a482c359d98c00ef86fac835b5fac (Apr 2014).

["Clément Pit--Claudel" <clement.pitclaudel@live.com>]

[-- Attachment #1: Type: text/plain, Size: 9233 bytes --]

On 07/18/2015 04:26 AM, Eli Zaretskii wrote:
>> Date: Sat, 18 Jul 2015 04:16:16 -0700
>> From: Clément Pit--Claudel
>>  <clement.pitclaudel@live.com>
>> CC: Eli Zaretskii <eliz@gnu.org>, 21028@debbugs.gnu.org
>>
>> I've spent a bit more time looking into this. The problem is due to the following three lines being conditioned on `!NILP(val)`: (that's around line 2780 of src/font.c)
>>
>>     Lisp_Object copy = copy_font_spec (scratch_font_spec);
>>     ASET (copy, FONT_TYPE_INDEX, driver_list->driver->type);
>>     XSETCDR (cache, Fcons (Fcons (copy, val), XCDR (cache)));
>>
>> Before af1a69f, these lines were always run. In af1a69f, they only run if `val` is non nil, causing the regression: on master, moving them back out of the if statement fixes the problem.
> 
> Thanks.  Do you understand how doing something only sometimes could be
> slower than doing it always?

My guess would be that these lines themselves aren't slow, but omitting them makes things slow. In addition to the two perf traces that I sent, here are the two most common stack traces that I get when I interrupt the text insertion loop using [(gdb) run -Q --eval "(progn (dotimes (_ 10) (set-fontset-font t 'unicode (font-spec :name \"Arial\") nil 'append)) (redisplay t) (dotimes (_ 500) (insert \"日本国\n\")))"]

* 3/4 of the time I get this one:
(gdb) backtrace
#0  0x00007ffff164912d in poll () at ../sysdeps/unix/syscall-template.S:81
#1  0x00007fffee12db72 in ?? () from /usr/lib/x86_64-linux-gnu/libxcb.so.1
#2  0x00007fffee12f3ff in ?? () from /usr/lib/x86_64-linux-gnu/libxcb.so.1
#3  0x00007fffee12f512 in xcb_wait_for_reply () from /usr/lib/x86_64-linux-gnu/libxcb.so.1
#4  0x00007ffff4c9948f in _XReply () from /usr/lib/x86_64-linux-gnu/libX11.so.6
#5  0x00007ffff4c950cd in XSync () from /usr/lib/x86_64-linux-gnu/libX11.so.6
#6  0x00000000004bdfb5 in x_catch_errors (dpy=dpy@entry=0xbe58d0) at xterm.c:7471
#7  0x00000000005b06f9 in xfont_list_pattern (display=display@entry=0xbe58d0, 
    pattern=pattern@entry=0x7fffffff6f20 "Arial", registry=registry@entry=12339538, script=script@entry=12108082)
    at xfont.c:367
#8  0x00000000005b10ae in xfont_list (f=<optimized out>, spec=12261565) at xfont.c:560
#9  0x000000000056a879 in font_list_entities (f=f@entry=0x112a4b8, spec=spec@entry=18635693) at font.c:2756
#10 0x000000000056b242 in font_find_for_lface (f=f@entry=0x112a4b8, attrs=attrs@entry=0x1807320, 
    spec=<optimized out>, c=c@entry=22269) at font.c:3232
#11 0x00000000005b9481 in fontset_find_font (fontset=19770717, c=c@entry=22269, face=face@entry=0x1807320, 
    id=id@entry=-1, fallback=fallback@entry=false) at fontset.c:681
#12 0x00000000005b9940 in fontset_font (fontset=fontset@entry=18249853, c=c@entry=22269, face=face@entry=0x1807320, 
    id=-1) at fontset.c:754
#13 0x00000000005ba3ea in face_for_char (f=0x112a4b8, face=face@entry=0x1807320, c=22269, pos=<optimized out>, 
    object=<optimized out>) at fontset.c:956
#14 0x000000000043ff68 in get_next_display_element (it=it@entry=0x7fffffff8ff0) at xdisp.c:7064
#15 0x00000000004456e0 in display_line (it=it@entry=0x7fffffff8ff0) at xdisp.c:19867
#16 0x000000000044962a in try_window (window=window@entry=18003149, pos=..., flags=flags@entry=0) at xdisp.c:16685
#17 0x000000000045d312 in redisplay_window (window=18003149, just_this_one_p=just_this_one_p@entry=false)
    at xdisp.c:16367
#18 0x0000000000461193 in redisplay_window_0 (window=window@entry=18003149) at xdisp.c:14157
#19 0x00000000005545a6 in internal_condition_case_1 (bfun=bfun@entry=0x461160 <redisplay_window_0>, arg=18003149, 
    handlers=<optimized out>, hfun=hfun@entry=0x42b360 <redisplay_window_error>) at eval.c:1378
#20 0x000000000042fbfe in redisplay_windows (window=18003149) at xdisp.c:14137
#21 0x000000000044dfb1 in redisplay_internal () at xdisp.c:13736
#22 0x000000000044fdd5 in redisplay () at xdisp.c:13022
#23 0x00000000004ef9e1 in read_char (commandflag=1, map=map@entry=19387718, prev_event=12108082, 
    used_mouse_menu=used_mouse_menu@entry=0x7fffffffd71b, end_time=end_time@entry=0x0) at keyboard.c:2569
#24 0x00000000004f1353 in read_key_sequence (keybuf=keybuf@entry=0x7fffffffd7f0, prompt=12108082, 
    dont_downcase_last=dont_downcase_last@entry=false, can_return_switch_frame=can_return_switch_frame@entry=true, 
    fix_current_buffer=fix_current_buffer@entry=true, prevent_redisplay=prevent_redisplay@entry=false, bufsize=30)
    at keyboard.c:9081
#25 0x00000000004f2f70 in command_loop_1 () at keyboard.c:1449
#26 0x000000000055447e in internal_condition_case (bfun=bfun@entry=0x4f2d80 <command_loop_1>, 
    handlers=<optimized out>, hfun=hfun@entry=0x4e9d40 <cmd_error>) at eval.c:1354
#27 0x00000000004e546e in command_loop_2 (ignore=ignore@entry=12108082) at keyboard.c:1174
#28 0x000000000055438b in internal_catch (tag=12155586, func=func@entry=0x4e5450 <command_loop_2>, arg=12108082)
    at eval.c:1118
#29 0x00000000004e9967 in command_loop () at keyboard.c:1153
#30 recursive_edit_1 () at keyboard.c:777
#31 0x00000000004e9c52 in Frecursive_edit () at keyboard.c:845
#32 0x0000000000417f75 in main (argc=<optimized out>, argv=0x7fffffffdb48) at emacs.c:1654

* 1/4 of the time I get that one:
(gdb) backtrace
#0  0x00007ffff2453900 in ?? () from /usr/lib/x86_64-linux-gnu/libfontconfig.so.1
#1  0x00007ffff24543b6 in ?? () from /usr/lib/x86_64-linux-gnu/libfontconfig.so.1
#2  0x00007ffff246185d in ?? () from /usr/lib/x86_64-linux-gnu/libfontconfig.so.1
#3  0x00007ffff24619b0 in FcFontSetList () from /usr/lib/x86_64-linux-gnu/libfontconfig.so.1
#4  0x00007ffff24621ff in FcFontList () from /usr/lib/x86_64-linux-gnu/libfontconfig.so.1
#5  0x00000000005b3792 in ftfont_list (f=<optimized out>, spec=12261565) at ftfont.c:955
#6  0x00000000005b61fa in xftfont_list (f=<optimized out>, spec=<optimized out>) at xftfont.c:141
#7  0x000000000056a879 in font_list_entities (f=f@entry=0x112a4b8, spec=spec@entry=18192877) at font.c:2756
#8  0x000000000056b242 in font_find_for_lface (f=f@entry=0x112a4b8, attrs=attrs@entry=0x1807320, 
    spec=<optimized out>, c=c@entry=22269) at font.c:3232
#9  0x00000000005b9481 in fontset_find_font (fontset=19770717, c=c@entry=22269, face=face@entry=0x1807320, 
    id=id@entry=-1, fallback=fallback@entry=false) at fontset.c:681
#10 0x00000000005b9940 in fontset_font (fontset=fontset@entry=18249853, c=c@entry=22269, face=face@entry=0x1807320, 
    id=-1) at fontset.c:754
#11 0x00000000005ba3ea in face_for_char (f=0x112a4b8, face=face@entry=0x1807320, c=22269, pos=<optimized out>, 
    object=<optimized out>) at fontset.c:956
#12 0x000000000043ff68 in get_next_display_element (it=it@entry=0x7fffffff82f0) at xdisp.c:7064
#13 0x000000000043d8d1 in move_it_in_display_line_to (it=it@entry=0x7fffffff82f0, to_charpos=to_charpos@entry=2001, 
    to_x=to_x@entry=-1, op=op@entry=MOVE_TO_POS) at xdisp.c:8504
#14 0x00000000004450ec in move_it_to (it=it@entry=0x7fffffff82f0, to_charpos=to_charpos@entry=2001, 
    to_x=to_x@entry=-1, to_y=to_y@entry=-1, to_vpos=to_vpos@entry=-1, op=op@entry=8) at xdisp.c:9145
#15 0x000000000044999d in move_it_vertically_backward (it=it@entry=0x7fffffff9e60, dy=dy@entry=280) at xdisp.c:9318
#16 0x000000000045d26b in redisplay_window (window=18003149, just_this_one_p=just_this_one_p@entry=false)
    at xdisp.c:16330
#17 0x0000000000461193 in redisplay_window_0 (window=window@entry=18003149) at xdisp.c:14157
#18 0x00000000005545a6 in internal_condition_case_1 (bfun=bfun@entry=0x461160 <redisplay_window_0>, arg=18003149, 
    handlers=<optimized out>, hfun=hfun@entry=0x42b360 <redisplay_window_error>) at eval.c:1378
#19 0x000000000042fbfe in redisplay_windows (window=18003149) at xdisp.c:14137
#20 0x000000000044dfb1 in redisplay_internal () at xdisp.c:13736
#21 0x000000000044fdd5 in redisplay () at xdisp.c:13022
#22 0x00000000004ef9e1 in read_char (commandflag=1, map=map@entry=19387718, prev_event=12108082, 
    used_mouse_menu=used_mouse_menu@entry=0x7fffffffd71b, end_time=end_time@entry=0x0) at keyboard.c:2569
#23 0x00000000004f1353 in read_key_sequence (keybuf=keybuf@entry=0x7fffffffd7f0, prompt=12108082, 
    dont_downcase_last=dont_downcase_last@entry=false, can_return_switch_frame=can_return_switch_frame@entry=true, 
    fix_current_buffer=fix_current_buffer@entry=true, prevent_redisplay=prevent_redisplay@entry=false, bufsize=30)
    at keyboard.c:9081
#24 0x00000000004f2f70 in command_loop_1 () at keyboard.c:1449
#25 0x000000000055447e in internal_condition_case (bfun=bfun@entry=0x4f2d80 <command_loop_1>, 
    handlers=<optimized out>, hfun=hfun@entry=0x4e9d40 <cmd_error>) at eval.c:1354
#26 0x00000000004e546e in command_loop_2 (ignore=ignore@entry=12108082) at keyboard.c:1174
#27 0x000000000055438b in internal_catch (tag=12155586, func=func@entry=0x4e5450 <command_loop_2>, arg=12108082)
    at eval.c:1118
#28 0x00000000004e9967 in command_loop () at keyboard.c:1153
#29 recursive_edit_1 () at keyboard.c:777
#30 0x00000000004e9c52 in Frecursive_edit () at keyboard.c:845
#31 0x0000000000417f75 in main (argc=<optimized out>, argv=0x7fffffffdb48) at emacs.c:1654

Hopefully someone can make sense of this.



[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 836 bytes --]