bug#16526: 24.3.50; scroll-conservatively & c-mode regression

[Eli Zaretskii <eliz@gnu.org>]

> Date: Sun, 26 Jan 2014 12:20:01 +0100
> From: martin rudalics <rudalics@gmx.at>
> CC: acm@muc.de, 16526@debbugs.gnu.org
> 
>  > More accurately, end-of-buffer calls recenter, which needs to compute
>  > where to put window-start, which requires Emacs to examine the text
>  > before point.  As part of this examination, we invoke functions that
>  > simulate display, and those trigger JIT Lock, whose fontification
>  > function starts the madness.
> 
> This doesn't match my observations.  With my shortened scenario
> 
> (progn
>    (setq scroll-conservatively 101)
>    (find-file (concat source-directory "src/xdisp.c"))
>    (end-of-buffer)
>    (sit-for 3))
> 
> there is no such problem.

You are right, sorry.  (I wasn't wrong, either: recenter does call the
same find_defun_start around EOB, which is what I saw.  But those
calls are very few and aren't responsible for the slowdown.  I also
wasn't wrong about point being at EOB, see below.  But I described
what happens incorrectly.)

Here's what I see in the debugger:

After beginning-of-buffer jumps to point-min, redisplay kicks in.
Since scroll-conservatively is set to a large value, redisplay first
tries to see whether it can bring point into view by scrolling the
window as little as possible.  It calls try_scrolling, which at some
point (around line 15000) tries to see whether the new location of
point is close enough to the current window start.  It does so by
calling move_it_to, which simulates the display.  While doing so,
move_it_to hits a portion of text with font-lock properties, and calls
JIT Lock to fontify them.

And here's where things go awry: For some reason, the CC Mode
fontification code decides it needs to scan the buffer backwards,
starting from EOB.  So it goes temporarily to EOB (this is why I saw
point being there), and scans all the way back, I think in this loop
from c-append-lower-brace-pair-to-state-cache, which is called with
its first argument FROM set to EOB:

	  ;; In the next pair of nested loops, the inner one moves back past a
	  ;; pair of (mis-)matching parens or brackets; the outer one moves
	  ;; back over a sequence of unmatched close brace/paren/bracket each
	  ;; time round.
	  (while
	      (progn
		(c-safe
		  (while
		      (and (setq ce (scan-lists bra -1 -1)) ; back past )/]/}; might signal
			   (setq bra (scan-lists ce -1 1)) ; back past (/[/{; might signal
			   (or (> bra here) ;(> ce here)
			       (and
				(< ce here)
				(or (not (eq (char-after bra) ?\{))
				    (and (goto-char bra)
					 (c-beginning-of-macro)
					 (< (point) macro-start-or-from))))))))
		(and ce (< ce bra)))
	    (setq bra ce))	; If we just backed over an unbalanced closing
					; brace, ignore it.

This loop takes a lot of time, of course, and is a waste of time,
since eventually try_scrolling comes to the correct conclusion that
scrolling is impossible, and instead recenters at BOB.

Why does CC Mode decide to go from EOB backwards, I don't know;
presumably, this is decided by c-parse-state-get-strategy as part of
c-parse-state-1.

For the record, below is the full C and Lisp backtrace I obtained when
c-append-lower-brace-pair-to-state-cache jumps to the EOB, which in
Lisp happens here:

  (save-excursion
    (save-restriction
      (let* (new-cons
	     (cache-pos (c-state-cache-top-lparen)) ; might be nil.
	     (macro-start-or-from
	      (progn (goto-char from)  <<<<<<<<<<<<<<<<<<<<<<<<<<<
		     (c-beginning-of-macro)
		     (point)))
	     (bra			; Position of "{".
	      ;; Don't start scanning in the middle of a CPP construct unless
	      ;; it contains HERE - these constructs, in Emacs, are "commented
	      ;; out" with category properties.
	      (if (eq (c-get-char-property macro-start-or-from 'category)
			'c-cpp-delimiter)
		    macro-start-or-from
		  from))
	     ce)			; Position of "}"

I hope this information will allow Alan to find the culprit and solve
the problem.

=============================================================================
Hardware watchpoint 4: -location current_buffer->pt

Old value = 1617
New value = 947778
0x011df59f in temp_set_point_both (
    buffer=0x380be00 <__register_frame_info+58768896>, charpos=947778,
    bytepos=947778) at intervals.c:1789
1789      SET_BUF_PT_BOTH (buffer, charpos, bytepos);
(gdb) bt
#0  0x011df59f in temp_set_point_both (
    buffer=0x380be00 <__register_frame_info+58768896>, charpos=947778,
    bytepos=947778) at intervals.c:1789
#1  0x011dfd99 in set_point_both (charpos=947778, bytepos=947778)
    at intervals.c:2045
#2  0x011df60a in set_point (charpos=947778) at intervals.c:1807
#3  0x011700fd in Fgoto_char (position=...) at editfns.c:239
#4  0x011820e2 in eval_sub (form=...) at eval.c:2176
#5  0x0117dc49 in Fprogn (body=...) at eval.c:459
#6  0x01181e50 in eval_sub (form=...) at eval.c:2124
#7  0x0117edea in FletX (args=...) at eval.c:872
#8  0x01181e50 in eval_sub (form=...) at eval.c:2124
#9  0x0117dc49 in Fprogn (body=...) at eval.c:459
#10 0x01176cc2 in Fsave_restriction (body=...) at editfns.c:3415
#11 0x01181e50 in eval_sub (form=...) at eval.c:2124
#12 0x0117dc49 in Fprogn (body=...) at eval.c:459
#13 0x0117161e in Fsave_excursion (args=...) at editfns.c:941
#14 0x01181e50 in eval_sub (form=...) at eval.c:2124
#15 0x0117dc49 in Fprogn (body=...) at eval.c:459
#16 0x01183f33 in funcall_lambda (fun=..., nargs=2, arg_vector=0x886db0)
    at eval.c:3033
#17 0x01183911 in apply_lambda (fun=..., args=...) at eval.c:2915
#18 0x0118244d in eval_sub (form=...) at eval.c:2251
#19 0x0117d9d4 in Fif (args=...) at eval.c:410
#20 0x01181e50 in eval_sub (form=...) at eval.c:2124
#21 0x0117dc49 in Fprogn (body=...) at eval.c:459
#22 0x0117db99 in Fcond (args=...) at eval.c:437
#23 0x01181e50 in eval_sub (form=...) at eval.c:2124
#24 0x0117dc49 in Fprogn (body=...) at eval.c:459
#25 0x0117ef6b in FletX (args=...) at eval.c:897
#26 0x01181e50 in eval_sub (form=...) at eval.c:2124
#27 0x0117dc49 in Fprogn (body=...) at eval.c:459
#28 0x01183f33 in funcall_lambda (fun=..., nargs=0, arg_vector=0x887310)
    at eval.c:3033
#29 0x01183911 in apply_lambda (fun=..., args=...) at eval.c:2915
#30 0x0118244d in eval_sub (form=...) at eval.c:2251
#31 0x0117dc49 in Fprogn (body=...) at eval.c:459
#32 0x01181e50 in eval_sub (form=...) at eval.c:2124
#33 0x0117fb6a in Funwind_protect (args=...) at eval.c:1206
#34 0x01181e50 in eval_sub (form=...) at eval.c:2124
#35 0x0117dc49 in Fprogn (body=...) at eval.c:459
#36 0x0117ef6b in FletX (args=...) at eval.c:897
#37 0x01181e50 in eval_sub (form=...) at eval.c:2124
#38 0x0117fb6a in Funwind_protect (args=...) at eval.c:1206
#39 0x01181e50 in eval_sub (form=...) at eval.c:2124
#40 0x0117dc49 in Fprogn (body=...) at eval.c:459
#41 0x0117da92 in Fif (args=...) at eval.c:411
#42 0x01181e50 in eval_sub (form=...) at eval.c:2124
#43 0x0117dc49 in Fprogn (body=...) at eval.c:459
#44 0x01181e50 in eval_sub (form=...) at eval.c:2124
#45 0x0117fb6a in Funwind_protect (args=...) at eval.c:1206
#46 0x01181e50 in eval_sub (form=...) at eval.c:2124
#47 0x0117dd09 in Fprog1 (args=...) at eval.c:491
#48 0x01181e50 in eval_sub (form=...) at eval.c:2124
#49 0x0117dc49 in Fprogn (body=...) at eval.c:459
#50 0x0117f401 in Flet (args=...) at eval.c:967
#51 0x01181e50 in eval_sub (form=...) at eval.c:2124
#52 0x0117dc49 in Fprogn (body=...) at eval.c:459
#53 0x01183f33 in funcall_lambda (fun=..., nargs=0, arg_vector=0x887f28)
    at eval.c:3033
#54 0x0118371d in Ffuncall (nargs=1, args=0x887f24) at eval.c:2867
#55 0x011c4bc3 in exec_byte_code (bytestr=..., vector=..., maxdepth=...,
    args_template=..., nargs=0, args=0x0) at bytecode.c:919
#56 0x01183fc8 in funcall_lambda (fun=..., nargs=1,
    arg_vector=0x3936595 <__register_frame_info+59991445>) at eval.c:3040
#57 0x01183644 in Ffuncall (nargs=2, args=0x888264) at eval.c:2855
#58 0x011c4bc3 in exec_byte_code (bytestr=..., vector=..., maxdepth=...,
    args_template=..., nargs=0, args=0x0) at bytecode.c:919
#59 0x01183fc8 in funcall_lambda (fun=..., nargs=3,
    arg_vector=0x1317efd <pure+652573>) at eval.c:3040
#60 0x01183644 in Ffuncall (nargs=4, args=0x8885b4) at eval.c:2855
#61 0x011c4bc3 in exec_byte_code (bytestr=..., vector=..., maxdepth=...,
    args_template=..., nargs=0, args=0x0) at bytecode.c:919
#62 0x01183fc8 in funcall_lambda (fun=..., nargs=3,
    arg_vector=0x1317555 <pure+650101>) at eval.c:3040
#63 0x01183644 in Ffuncall (nargs=4, args=0x8888f4) at eval.c:2855
#64 0x011c4bc3 in exec_byte_code (bytestr=..., vector=..., maxdepth=...,
    args_template=..., nargs=0, args=0x0) at bytecode.c:919
#65 0x01183fc8 in funcall_lambda (fun=..., nargs=3, arg_vector=0x51d1bfd)
    at eval.c:3040
#66 0x01183644 in Ffuncall (nargs=4, args=0x888c34) at eval.c:2855
#67 0x011c4bc3 in exec_byte_code (bytestr=..., vector=..., maxdepth=...,
    args_template=..., nargs=0, args=0x0) at bytecode.c:919
#68 0x01183fc8 in funcall_lambda (fun=..., nargs=2,
    arg_vector=0x1317155 <pure+649077>) at eval.c:3040
#69 0x01183644 in Ffuncall (nargs=3, args=0x889098) at eval.c:2855
#70 0x011829aa in funcall_nil (nargs=3, args=0x889098) at eval.c:2357
#71 0x01182dbf in run_hook_with_args (nargs=3, args=0x889098,
    funcall=0x1182992 <funcall_nil>) at eval.c:2542
#72 0x01182a21 in Frun_hook_with_args (nargs=3, args=0x889098) at eval.c:2403
#73 0x0118330a in Ffuncall (nargs=4, args=0x889094) at eval.c:2787
#74 0x011c4bc3 in exec_byte_code (bytestr=..., vector=..., maxdepth=...,
    args_template=..., nargs=0, args=0x8893e4) at bytecode.c:919
#75 0x01183bf2 in funcall_lambda (fun=..., nargs=0, arg_vector=0x8893e4)
    at eval.c:2974
#76 0x01183644 in Ffuncall (nargs=1, args=0x8893e0) at eval.c:2855
#77 0x01181fe4 in eval_sub (form=...) at eval.c:2148
#78 0x0118025e in internal_lisp_condition_case (var=..., bodyform=...,
    handlers=...) at eval.c:1314
#79 0x011c5af4 in exec_byte_code (bytestr=..., vector=..., maxdepth=...,
    args_template=..., nargs=2, args=0x8898c4) at bytecode.c:1169
#80 0x01183bf2 in funcall_lambda (fun=..., nargs=2, arg_vector=0x8898bc)
    at eval.c:2974
#81 0x01183644 in Ffuncall (nargs=3, args=0x8898b8) at eval.c:2855
#82 0x011c4bc3 in exec_byte_code (bytestr=..., vector=..., maxdepth=...,
    args_template=..., nargs=1, args=0x889c58) at bytecode.c:919
#83 0x01183bf2 in funcall_lambda (fun=..., nargs=1, arg_vector=0x889c54)
    at eval.c:2974
#84 0x01183644 in Ffuncall (nargs=2, args=0x889c50) at eval.c:2855
#85 0x011806bb in internal_condition_case_n (bfun=0x11830e4 <Ffuncall>,
    nargs=2, args=0x889c50, handlers=..., hfun=0x1026dfa <safe_eval_handler>)
    at eval.c:1427
#86 0x01026f19 in safe_call (nargs=2, func=...) at xdisp.c:2563
#87 0x01026f56 in safe_call1 (fn=..., arg=...) at xdisp.c:2579
#88 0x0102a1d5 in handle_fontified_prop (it=0x88d2fc) at xdisp.c:3756
#89 0x010293a3 in handle_stop (it=0x88d2fc) at xdisp.c:3320
#90 0x010359e6 in next_element_from_buffer (it=0x88d2fc) at xdisp.c:8077
#91 0x010325b4 in get_next_display_element (it=0x88d2fc) at xdisp.c:6732
#92 0x010364d4 in move_it_in_display_line_to (it=0x88d2fc, to_charpos=949978,
    to_x=0, op=(MOVE_TO_X | MOVE_TO_POS)) at xdisp.c:8412
#93 0x01038443 in move_it_to (it=0x88d2fc, to_charpos=949978, to_x=0,
    to_y=1600, to_vpos=-1, op=11) at xdisp.c:8936
#94 0x0104798f in try_scrolling (window=..., just_this_one_p=0,
    arg_scroll_conservatively=101, scroll_step=0, temp_scroll_step=0,
    last_line_misfit=0) at xdisp.c:15016
#95 0x0104bb7b in redisplay_window (window=..., just_this_one_p=false)
    at xdisp.c:16119
#96 0x01044bf1 in redisplay_window_0 (window=...) at xdisp.c:14056
#97 0x01180479 in internal_condition_case_1 (
    bfun=0x1044bbb <redisplay_window_0>, arg=..., handlers=...,
    hfun=0x1044b97 <redisplay_window_error>) at eval.c:1369
#98 0x01044b7c in redisplay_windows (window=...) at xdisp.c:14036
#99 0x01043b49 in redisplay_internal () at xdisp.c:13635
#100 0x0103ca92 in resize_echo_area_exactly () at xdisp.c:10559
#101 0x010f622b in command_loop_1 () at keyboard.c:1571
#102 0x01180366 in internal_condition_case (bfun=0x10f5b5b <command_loop_1>,
    handlers=..., hfun=0x10f53c7 <cmd_error>) at eval.c:1345
#103 0x010f5811 in command_loop_2 (ignore=...) at keyboard.c:1170
#104 0x0117f913 in internal_catch (tag=..., func=0x10f57ed <command_loop_2>,
    arg=...) at eval.c:1109
#105 0x010f57c9 in command_loop () at keyboard.c:1149
#106 0x010f4f63 in recursive_edit_1 () at keyboard.c:777
#107 0x010f5120 in Frecursive_edit () at keyboard.c:841
#108 0x010f32ff in main (argc=2, argv=0xe51ff8) at emacs.c:1643

Lisp Backtrace:
"goto-char" (0x886820)
"progn" (0x88696c)
"let*" (0x886a8c)
"save-restriction" (0x886bac)
"save-excursion" (0x886ccc)
"c-append-lower-brace-pair-to-state-cache" (0x886db0)
"if" (0x886fac)
"cond" (0x8870dc)
"let*" (0x88722c)
"c-parse-state-1" (0x887310)
"progn" (0x8874fc)
"unwind-protect" (0x8875ec)
"let*" (0x88773c)
"unwind-protect" (0x88782c)
"if" (0x88794c)
"progn" (0x887a3c)
"unwind-protect" (0x887b2c)
"prog1" (0x887c2c)
"let" (0x887dbc)
"c-parse-state" (0x887f28)
"c-font-lock-complex-decl-prepare" (0x888268)
"font-lock-fontify-keywords-region" (0x8885b8)
"font-lock-default-fontify-region" (0x8888f8)
"c-font-lock-fontify-region" (0x888c38)
"font-lock-fontify-region" (0x88909c)
"run-hook-with-args" (0x889098)
0x37cc9b0 PVEC_COMPILED
"funcall" (0x8893e0)
"jit-lock-fontify-now" (0x8898bc)
"jit-lock-function" (0x889c54)
"redisplay_internal (C function)" (0x153de1c)