bug#12326: 24.2.50; js2-mode freezes on current trunk

bug#12326: 24.2.50; js2-mode freezes on current trunk

[Dmitry Gutov]

js2-mode freezes during editing in some buffers.

This has been a long-standing complaint on Mac OS X port, but now it
affect Linux and Windows users too, see
https://github.com/mooz/js2-mode/issues/49

Bisecting the Bazaar history (on a Windows machine) points to the
month-old commit no 109470, which adds one line in `timer_check_2'.

Here's the timer-scheduling function from js2-mode:

(defun js2-mode-reset-timer ()
   "Cancel any existing parse timer and schedule a new one."
   (if js2-mode-parse-timer
       (cancel-timer js2-mode-parse-timer))
   (setq js2-mode-parsing nil)
   (setq js2-mode-parse-timer
         (run-with-idle-timer js2-idle-timer-delay nil
                              #'js2-mode-idle-reparse (current-buffer))))

It's only called from an after-change function and from a
`js2-mode-idle-reparse' callee, in case parsing has been interrupted.
To handle interruptions, the parser code periodically calls
(input-pending-p), and when it's true, aborts and reschedules.

Any ideas?

In GNU Emacs 24.2.50.1 (i386-mingw-nt6.1.7601)
  of 2012-09-01 on SOL
Bzr revision: 109843 rudalics@gmx.at-20120901164709-puy2rq2g4zsjwjee
Windowing system distributor `Microsoft Corp.', version 6.1.7601
Configured using:
  `configure --with-gcc (3.4) --cflags -IJ:/Apps/system/gnuwin32/include'

Important settings:
   value of $EMACSDATA: C:/Users/gutov/vc/emacs-bzr/trunk/etc
   value of $EMACSDOC: C:/Users/gutov/vc/emacs-bzr/trunk/etc
   value of $EMACSLOADPATH: 
C:/Users/gutov/vc/emacs-bzr/trunk/site-lisp;C:/Users/gutov/vc/emacs-bzr/trunk/../site-lisp;C:/Users/gutov/vc/emacs-bzr/trunk/lisp;C:/Users/gutov/vc/emacs-bzr/trunk/leim
   value of $EMACSPATH: C:/Users/gutov/vc/emacs-bzr/trunk/bin
   value of $LANG: RUS
   locale-coding-system: cp1251
   default enable-multibyte-characters: t

Major mode: Bzr-Log-View

Minor modes in effect:
   recentf-mode: t
   helm-dired-mode: Enable helm completion in Dired functions.
Bindings affected are C, R, S, H.
This is deprecated for Emacs24+ users, use `helm-mode' instead.
   shell-dirtrack-mode: t
   helm-match-plugin-mode: t
   global-undo-tree-mode: t
   undo-tree-mode: t
   global-diff-hl-mode: t
   diff-auto-refine-mode: t
   savehist-mode: t
   yas/global-mode: t
   yas/minor-mode: t
   global-auto-revert-mode: t
   cua-mode: t
   global-ethan-wspace-mode: t
   global-auto-complete-mode: t
   autopair-global-mode: t
   ido-ubiquitous-mode: t
   ido-everywhere: t
   show-paren-mode: t
   mouse-wheel-mode: t
   file-name-shadow-mode: t
   global-font-lock-mode: t
   font-lock-mode: t
   auto-composition-mode: t
   auto-encryption-mode: t
   auto-compression-mode: t
   buffer-read-only: t
   column-number-mode: t
   line-number-mode: t
   transient-mark-mode: t

Recent input:
<triple-wheel-down> <triple-wheel-down> <triple-wheel-down>
<triple-wheel-down> <triple-wheel-down> <triple-wheel-down>
<triple-wheel-down> <triple-wheel-down> <wheel-up>
<double-wheel-up> <triple-wheel-up> <triple-wheel-up>
<help-echo> <down-mouse-1> <mouse-1> <help-echo> <help-echo>
<down-mouse-1> <mouse-1> <wheel-down> <wheel-up> <double-wheel-up>
<wheel-up> <double-wheel-up> <triple-wheel-up> <triple-wheel-up>
<wheel-up> <double-wheel-up> <triple-wheel-up> <triple-wheel-up>
<triple-wheel-up> <wheel-up> <double-wheel-up> <triple-wheel-up>
<triple-wheel-up> <triple-wheel-up> <wheel-down> <double-wheel-down>
<triple-wheel-down> <triple-wheel-down> <triple-wheel-down>
<triple-wheel-down> <triple-wheel-down> <triple-wheel-down>
<triple-wheel-down> <triple-wheel-down> <triple-wheel-down>
<triple-wheel-down> <help-echo> <help-echo> <help-echo>
<help-echo> <down-mouse-1> <mouse-1> C-x 3 C-; \ .
e r b <return> <down> <down> <down> <end> SPC <backspace>
SPC <backspace> SPC <backspace> SPC <backspace> SPC
<backspace> <home> <delete> SPC <backspace> <delete>
SPC C-z SPC C-z <down> SPC <backspace> <up> <down>
<end> <up> <up> <up> <backspace> % <backspace> % <backspace>
% <backspace> % <backspace> ? % <backspace> <backspace>
% <backspace> % <backspace> % <backspace> % <down>
<down> <down> <down> C-x 0 <wheel-down> <double-wheel-down>
<triple-wheel-down> <triple-wheel-down> <triple-wheel-down>
<wheel-up> <double-wheel-up> <triple-wheel-up> <triple-wheel-up>
<triple-wheel-up> <wheel-up> <double-wheel-up> <triple-wheel-up>
<triple-wheel-up> <help-echo> <down-mouse-1> <mouse-1>
<wheel-down> <double-wheel-down> <triple-wheel-down>
<help-echo> <help-echo> <down-mouse-1> <mouse-1> <wheel-up>
<double-wheel-up> <triple-wheel-up> <triple-wheel-up>
<triple-wheel-up> <wheel-down> <double-wheel-down>
<triple-wheel-down> C-c <left> C-c <left> C-c <left>
C-c <left> <down> <down> <down> <down> <down> <down>
<down> <down> <down> <down> <down> <down> <down> <down>
<down> <down> <down> <down> <down> <down> <down> <up>
<up> <up> <up> <up> <up> <up> <up> <up> <up> <up> <up>
<up> <up> <up> <up> <up> <up> <up> <up> <up> <up> <up>
<up> <up> <up> <up> <up> <up> <up> <up> <up> <up> <up>
<up> <up> <up> <up> <up> <up> <up> <up> <up> <up> <up>
<up> <up> <prior> <next> <next> <down> <down> <down>
<down> <down> <down> <down> <down> <down> <down> <down>
<down> <down> <down> <down> <down> <down> <down> <down>
<down> <down> <down> <down> <down> <down> <down> <down>
<down> <up> <up> <up> <up> <up> <up> <up> <up> <up>
<up> <up> <up> <up> <up> <up> <up> <up> <up> <up> <down>
<down> <down> <left> C-x 3 M-x r e p o r t - e m a
c s <right> <return>

Recent messages:
Winner undo (1 / 8)
Finding changes in c:/Users/gutov/vc/emacs-bzr/trunk/src/keyboard.c...
byte-code: End of buffer [8 times]
byte-code: Beginning of buffer [7 times]

Undo branch point!
Winner undo (1 / 15)
Winner undo (2 / 15)
Winner undo (3 / 15)
Winner undo (4 / 14)

Load-path shadows:
c:/Users/gutov/.emacs.d/elpa/magit-20120616/.dir-locals hides 
c:/Users/gutov/.emacs.d/elpa/sunrise-commander-20120705/.dir-locals
c:/Users/gutov/.emacs.d/elpa/magit-20120616/.dir-locals hides 
c:/Users/gutov/vc/emacs-bzr/trunk/lisp/gnus/.dir-locals

Features:
(shadow sort mail-extr emacsbug message rfc822 mml mml-sec mm-decode
mm-bodies mm-encode mail-parse rfc2231 mailabbrev gmm-utils mailheader
sendmail rfc2047 rfc2045 ietf-drums mail-utils js json imenu css-mode
ruby-electric ruby-tools inf-ruby ruby-mode mmm-mode mmm-univ mmm-class
subword mmm-erb derived mmm-region mmm-utils sgml-mode whitespace
add-log log-view pcvs-util vc-bzr cc-langs cc-mode cc-fonts cc-guess
cc-menus cc-cmds cc-styles cc-align cc-engine cc-vars cc-defs unsafep
flyspell ispell recentf tree-widget wid-edit bow helm-files image-dired
tramp tramp-compat tramp-loaddefs shell pcomplete format-spec dired-x
dired-aux thingatpt helm-tags helm-locate helm-help helm-grep
helm-regexp grep helm-external helm-bookmark helm-buffers helm-elscreen
helm-utils compile comint ansi-color helm-match-plugin helm helm-config
elisp-slime-nav etags paredit saveplace undo-tree diff diff-hl
face-remap vc-hg vc-git vc ediff-merg ediff-diff ediff-wind ediff-help
ediff-util ediff-mult ediff-init ediff vc-dispatcher diff-mode savehist
yasnippet autorevert cua-base winner point-stack .emacs-loaddefs
cyril-util devenv ethan-wspace pos-tip ac-slime auto-complete-config
auto-complete popup eproject-extras ibuf-macs ibuf-ext ibuffer iswitchb
eproject esh-var esh-io esh-cmd esh-opt esh-ext esh-proc esh-arg eldoc
esh-groups eshell esh-module esh-mode esh-util progmodes dropdown-list
mmm mmm-auto mmm-vars mmm-compat autopair easy-mmode keys switch-window
quail help-mode easymenu hippie dired winring ring transpose-frame
iflipb misc prefs defuns birds-of-paradise-plus-theme-autoloads
coffee-mode-autoloads eldoc-eval-autoloads findr-autoloads
gist-autoloads gh-autoloads inf-ruby-autoloads inflections-autoloads
iy-go-to-char-autoloads logito-autoloads move-text-autoloads
pcache-autoloads finder-inf rainbow-mode-autoloads
ruby-electric-autoloads ruby-tools-autoloads
starter-kit-bindings-autoloads windmove starter-kit-lisp-autoloads
cl-macs gv elisp-slime-nav-autoloads starter-kit-autoloads edmacro
kmacro smex cl cl-lib starter-kit-misc warnings ffap url-parse
auth-source eieio byte-opt bytecomp byte-compile cconv macroexp
gnus-util mm-util mail-prsvr password-cache url-vars ido-ubiquitous ido
paren starter-kit-defuns uniquify advice help-fns advice-preload
magit-autoloads ido-ubiquitous-autoloads smex-autoloads
find-file-in-project-autoloads idle-highlight-mode-autoloads
paredit-autoloads sunrise-commander-autoloads switch-window-autoloads
tango-2-theme-autoloads twilight-bright-theme-autoloads typing-autoloads
undo-tree-autoloads volatile-highlights-autoloads wgrep-autoloads
yaml-mode-autoloads package time-date tooltip ediff-hook vc-hooks
lisp-float-type mwheel dos-w32 disp-table ls-lisp w32-win w32-vars
tool-bar dnd fontset image regexp-opt fringe tabulated-list newcomment
lisp-mode register page menu-bar rfn-eshadow timer select scroll-bar
mouse jit-lock font-lock syntax facemenu font-core frame cham georgian
utf-8-lang misc-lang vietnamese tibetan thai tai-viet lao korean
japanese hebrew greek romanian slovak czech european ethiopic indian
cyrillic chinese case-table epa-hook jka-cmpr-hook help simple abbrev
minibuffer button faces cus-face files text-properties overlay sha1 md5
base64 format env code-pages mule custom widget hashtable-print-readable
backquote make-network-process multi-tty emacs)

bug#12326: (24.2.50; js2-mode freezes on current trunk)

[Dmitry Gutov]

Some further analysis showed that the freeze is caused by the infinite 
mutual loop between `js2-do-parse' and `js2-mode-reset-timer'.
Looks like it goes like this:

1. I enter some input.
2. js2-mode-edit is called; it calls js2-mode-reset-timer
3. js2-mode-reset-timer schedules js2-mode-idle-reparse to run
4. js2-mode-idle-reparse calls js2-do-parse
5. If I manage to press a button while js2-do-parse is still running, 
and it reaches an (input-pending-p), it stops parsing and calls 
js2-mode-reset-timer.
6. Apparently, at this point the timer code still thinks we're idle, 
because it immediately calls js2-mode-idle-reparse. So goto 4. While 
(input-pending-p) still returns true.

If I manually inline `run-with-idle-timer' into `js2-mode-reset-timer' 
and change the DONT-WAIT `timer-activate-when-idle' argument to nil, it 
fixes the problem. Like this:

(defun js2-mode-reset-timer ()
   "Cancel any existing parse timer and schedule a new one."
   (if js2-mode-parse-timer
       (cancel-timer js2-mode-parse-timer))
   (setq js2-mode-parsing nil)
   (let ((timer (timer-create)))
     (setq js2-mode-parse-timer timer)
     (timer-set-function timer 'js2-mode-idle-reparse (list 
(current-buffer)))
     (timer-set-idle-time timer js2-idle-timer-delay)
     (timer-activate-when-idle timer)))

Is this a problem in Emacs or consumer code?

bug#12326: 24.2.50; js2-mode freezes on current trunk

[Jan Djärv]

Hello.

1 sep 2012 kl. 23:57 skrev Dmitry Gutov <dgutov@yandex.ru>:

> js2-mode freezes during editing in some buffers.
> 
> This has been a long-standing complaint on Mac OS X port, but now it
> affect Linux and Windows users too, see
> https://github.com/mooz/js2-mode/issues/49
> 
> Bisecting the Bazaar history (on a Windows machine) points to the
> month-old commit no 109470, which adds one line in `timer_check_2'.
> 

The reason for that line is to make timer_check return the time to the next timeout, not the time to some random timer.

When a dialog i shown, the time to the next time is checked with timer_check and when that time is reached, the timer is run.  If timer_check returns an out of order time, timers are not run when they should be.

I'm surprised that js2 functions with undefined behaviour and not with defined behaviour.

	Jan D.

bug#12326: 24.2.50; js2-mode freezes on current trunk

[Dmitry Gutov]

Hi Jan,

On 02.09.2012 12:35, Jan Djärv wrote:
> 1 sep 2012 kl. 23:57 skrev Dmitry Gutov <dgutov@yandex.ru>:
>
>> js2-mode freezes during editing in some buffers.
>>
>> This has been a long-standing complaint on Mac OS X port, but now it
>> affect Linux and Windows users too, see
>> https://github.com/mooz/js2-mode/issues/49
>>
>> Bisecting the Bazaar history (on a Windows machine) points to the
>> month-old commit no 109470, which adds one line in `timer_check_2'.
>>
>
> The reason for that line is to make timer_check return the time to the next timeout, not the time to some random timer.

How was it random? AFAICT, your line just breaks out of the "while" loop 
when a ripe timer is found, and so `timer_check_2' returns 0 time, and 
its caller (timer_check) calls it again.
And before that the while loop in `timer_check_2' just ran until it 
reached the end of timers lists, or found a non-ripe timer.

I think the main difference is, previously, `timer_check_2' was called 
only once, so `now' and `idleness_now' were calculated at that time, and 
all timers were checked for ripeness against those values.

Now `now' and `idleness_now' are recalculated after each time a ripe 
timer fires, which is arguably more correct (some time has passed, after 
all), but doesn't leave the room for the event loop to detect new 
keypresses and update `timer_idleness_start_time'.

> When a dialog i shown, the time to the next time is checked with timer_check and when that time is reached, the timer is run.  If timer_check returns an out of order time, timers are not run when they should be.

Didn't they they just run a little late, due to the time values, against 
which the difference was calculated, being slightly outdated?

> I'm surprised that js2 functions with undefined behaviour and not with defined behaviour.

Looks like the previous behavior was more conservative.

I think js2-mode is only unusual in that it may schedule a new timer 
from within a timer callback function.

--Dmitry

bug#12326: 24.2.50; js2-mode freezes on current trunk

[Jan Djärv]

Hello.

2 sep 2012 kl. 15:03 skrev Dmitry Gutov <dgutov@yandex.ru>:

> Hi Jan,
> 
> On 02.09.2012 12:35, Jan Djärv wrote:
>> 1 sep 2012 kl. 23:57 skrev Dmitry Gutov <dgutov@yandex.ru>:
>> 
>>> js2-mode freezes during editing in some buffers.
>>> 
>>> This has been a long-standing complaint on Mac OS X port, but now it
>>> affect Linux and Windows users too, see
>>> https://github.com/mooz/js2-mode/issues/49
>>> 
>>> Bisecting the Bazaar history (on a Windows machine) points to the
>>> month-old commit no 109470, which adds one line in `timer_check_2'.
>>> 
>> 
>> The reason for that line is to make timer_check return the time to the next timeout, not the time to some random timer.
> 
> How was it random? AFAICT, your line just breaks out of the "while" loop when a ripe timer is found, and so `timer_check_2' returns 0 time, and its caller (timer_check) calls it again.
> And before that the while loop in `timer_check_2' just ran until it reached the end of timers lists, or found a non-ripe timer.
> 
> I think the main difference is, previously, `timer_check_2' was called only once, so `now' and `idleness_now' were calculated at that time, and all timers were checked for ripeness against those values.
> 
> Now `now' and `idleness_now' are recalculated after each time a ripe timer fires, which is arguably more correct (some time has passed, after all), but doesn't leave the room for the event loop to detect new keypresses and update `timer_idleness_start_time'.

That is not the problem.
Previously timer_check_2 found a timer to run, ran that, and continued to search in the list.
If the timer callback added a timer, it may happen that that timer is inserted in the front of the list, and not checked by timer_check_2.

Now timer_check_2 finds a timer, runs that, and then returns so timer_check can call timer_check_2 again.  This makes timer_check_2 start over, checking from the beginning of the list.

> 
>> When a dialog i shown, the time to the next time is checked with timer_check and when that time is reached, the timer is run.  If timer_check returns an out of order time, timers are not run when they should be.
> 
> Didn't they they just run a little late, due to the time values, against which the difference was calculated, being slightly outdated?

The case I had was one repeating 20 second timer, and one repeating 2 second timer.
The 2 second timer would be run once, then timer_check_2 would return the difference to the 20 second timer, thus skipping some 10 invokations of the 2 second timer.

> 
>> I'm surprised that js2 functions with undefined behaviour and not with defined behaviour.
> 
> Looks like the previous behavior was more conservative.

And wrong.

> 
> I think js2-mode is only unusual in that it may schedule a new timer from within a timer callback function.

It may be that some timing issues in the handling of the timer lists still remain.

	Jan D.

bug#12326: 24.2.50; js2-mode freezes on current trunk

[Dmitry Gutov]

On 02.09.2012 20:06, Jan Djärv wrote:
> That is not the problem.
> Previously timer_check_2 found a timer to run, ran that, and continued to search in the list.
> If the timer callback added a timer, it may happen that that timer is inserted in the front of the list, and not checked by timer_check_2.

I see. That's probably the reason why it worked.

> Now timer_check_2 finds a timer, runs that, and then returns so timer_check can call timer_check_2 again.  This makes timer_check_2 start over, checking from the beginning of the list.
>
>>
>>> When a dialog i shown, the time to the next time is checked with timer_check and when that time is reached, the timer is run.  If timer_check returns an out of order time, timers are not run when they should be.
>>
>> Didn't they they just run a little late, due to the time values, against which the difference was calculated, being slightly outdated?
>
> The case I had was one repeating 20 second timer, and one repeating 2 second timer.
> The 2 second timer would be run once, then timer_check_2 would return the difference to the 20 second timer, thus skipping some 10 invokations of the 2 second timer.
>
>>
>>> I'm surprised that js2 functions with undefined behaviour and not with defined behaviour.
>>
>> Looks like the previous behavior was more conservative.
>
> And wrong.
>
>>
>> I think js2-mode is only unusual in that it may schedule a new timer from within a timer callback function.
>
> It may be that some timing issues in the handling of the timer lists still remain.

Indeed. I wonder if scheduling an idle timer from within its callback 
with `run-with-idle-timer' is supposed to work at all.