bug#15045: Point jumps inappropriately around time of Semantic lexing

[David Engster <deng@randomsample.de>]

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

[Adding Eric to CC]

David Engster writes:
> Stefan Monnier writes:
>>> The short of it is that I occasionally witness point jump to elsewhere
>>> in the buffer while I'm editing and then back again.
>>
>> So it's "displayed at A" then "displayed at B" then "displayed at
>> A again"?  what happens between each one of those 3 displays?
>>
>> If "nothing", then I suspect there's something like a `sit-for'
>> somewhere that causes a redisplay in the middle of the command (i.e. in
>> the middle of a save-excursion).
>
> I sometimes see this as well, and yes, "nothing" happens between those
> three displays. I also think there's a redisplay triggered by another
> background task while Semantic does its idle parsing stuff.

I think I tracked this down. I first instrumented `sit-for' to see which
background tasks trigger it. On my machine, this happens by two things:
`jit-lock-deferred-fontify', and `display-time-event-handler'.

The display-time handler is called twice per minute: I have
(display-time) in my .emacs, and every full minute the time gets updated
in the mode-line. Also, it is called in the
gnus-after-get-new-news-hook, and since I check for new mails in the
background, it gets called through this, too.

It's kinda hard to trigger this problem through jit-lock, since its idle
time is much smaller than the one from Semantic. So I disabled it and
tried to trigger the jump by stopping typing at roughly XX:XX:59. The
semantic idle function kicks in after 1 second, and lo and behold, I saw
a jump. It's still difficult to reproduce, but I managed to get two
backtraces in the past hour, which are attached.

As you can see, the display-time-event-handler does indeed interrupt the
lexing phase. It does a `sit-for', the display jumps. Not sure what
happens after that. Does the semantic-idle function resume? Anyway,
somehow point gets back to its original position, and through
`trace-redisplay', I saw the following on stderr:

0x7f35178 (test.cpp): same window start
0x7f35178 (test.cpp): 1
redisplay_preserve_echo_area (2)
redisplay_internal 0
0x7f35178 (test.cpp): try_scrolling
redisplay_preserve_echo_area (8)
redisplay_internal 0
0x7f35178 (test.cpp): same window start
0x7f35178 (test.cpp): 1
0x7f35178 (test.cpp): try_scrolling
redisplay_preserve_echo_area (8)

I guess this just says that redisplay made point visible by scrolling,
right?

You might wonder how the display-time-event-handler can interrupt the
Semantic lexer. In the two backtraces, you see that it calls
`accept-process-output' and `input-pending-p'. This is hidden inside the
macro `semantic-throw-on-input', which can be called in code wrapped
inside `semantic-exit-on-input'; it's our poor-man's 'yield'. It's used
extensively in the idle function code, and it's just there to do a
non-local exit in case the user does something. However, now I know that
it also allows other timers to run.

If you look in the `define-lex' macro, you see that it calls
`semantic-throw-on-input' after each identified token. The problem is
that it does not restore the cursor position before that, so I guess the
fix is simply to change this call to

	   (save-excursion
	     (goto-char starting-position)
	     (semantic-throw-on-input 'lex))

Obviously, we will have to check all other calls to
`semantic-throw-on-input' for this as well. However, I also wonder if
display-time-event-handler couldn't just call `force-mode-line-update';
or does this repaint the whole display as well?

-David


[-- Attachment #2: backtr1.txt --]
[-- Type: text/plain, Size: 991 bytes --]

  sit-for(0)
  display-time-event-handler()
  apply(display-time-event-handler nil)
  byte-code("[snipped]" [timer apply 5 6] 4)
  timer-event-handler([t 20995 27860 0 60 display-time-event-handler nil nil 0])
  accept-process-output()
  semantic-c-lexer(2886 7946 nil nil)
  semantic-lex(2886 7946 nil)
  semantic-parse-region-default(2886 7946 nil nil nil)
  semantic-parse-region-c-mode(2886 7946 nil nil nil)
  semantic-parse-region(2886 7946 nil)
  semantic-edits-incremental-parser-1()
  byte-code("[snipped]" [err message "incremental parser error: %S" error-message-string t] 4)))] 3)
  semantic-parse-changes-default()
  semantic-parse-changes()
  semantic-fetch-tags()
  byte-code("[snipped]" [semantic-fetch-tags nil] 1)
  semantic-idle-scheduler-refresh-tags()
  byte-code("[snipped]")
  semantic-idle-core-handler()
  semantic-idle-scheduler-function()
  apply(semantic-idle-scheduler-function nil)
  timer-event-handler([t 0 1 0 t semantic-idle-scheduler-function nil idle 0])

[-- Attachment #3: backtr2.txt --]
[-- Type: text/plain, Size: 1266 bytes --]

  sit-for(0)
  display-time-event-handler()
  apply(display-time-event-handler nil)
  byte-code("[snipped]" [timer apply 5 6] 4)
  timer-event-handler([t 20995 36800 0 60 display-time-event-handler nil nil 0])
  input-pending-p()
  semantic-c-lexer(2939 7944 nil nil)
  semantic-lex(2939 7944 nil)
  semantic-parse-region-default(2939 7944 bovine-inner-scope nil t)
  semantic-parse-region-c-mode(2939 7944 bovine-inner-scope nil t)
  semantic-parse-region(2939 7944 bovine-inner-scope nil t)
  semantic-get-local-variables-default()
  semantic-get-local-variables-c++-mode()
  semantic-get-local-variables()
  semantic-get-all-local-variables-default(nil)
  semantic-get-all-local-variables()
  byte-code("[snipped]" [scopecache eieio-oset localvar semantic-get-all-local-variables] 4)
  semantic-calculate-scope(7797)
  semantic-analyze-current-context-default(7797)
  semantic-analyze-current-context(7797)
  byte-code("[snipped]" [semantic-analyze-current-context] 2)
  semantic-idle-summary-current-symbol-info-context()
  semantic-idle-summary-current-symbol-info-default()
  semantic-idle-summary-current-symbol-info-c-mode()
  semantic-idle-summary-current-symbol-info()
  semantic-idle-summary-idle-function()
  funcall(semantic-idle-summary-idle-function)