hanging when typing fast

[shaunhaskey]

Hi,

First of all, thank you very much for creating elpy - I find it extremely useful.

Unfortunately, I am running into some problems, that seem to be related to auto-complete, and typing speed. If I type the following as fast as I can (~80wpm):
for i in range(10):
emacs gets about half way through what I typed and hangs for ~20s, and eventually gives the following output in messages

error in process filter: turn-on-font-lock-if-desired: Lisp nesting exceeds max-lisp-eval-depth' error in process filter: Lisp nesting exceedsmax-lisp-eval-depth'

If I type slower, I don't seem to see this problem. Also, this problem only seems to occur when I am editing a file belonging to a larger module as opposed to a 'standalone' .py file.

I have ac-auto-start set to 3, it was worse with a lower number. ac-auto-show-menu is set to 0.4, and ac-quick-help-delay to 0.5 in elpy.el.

Here is the elpy related entry in init.el
(package-initialize)
(elpy-enable)
(elpy-use-ipython)
(setq python-shell-interpreter-args "--pylab --colors Linux")
(setq elpy-rpc-backend "jedi")

Here are the versions I'm using:
emacs 24.3.1, ubuntu 12.04, elpy 1.4.1

Thanks,
Shaun

[jorgenschaefer]

Thank you for the report!

I'm afraid I can not reproduce this behavior, so I'll have to make you jump through some shotgun-debugging stunts.

• What's the value of M-: (length (elpy-rpc-get-completions)) at the beginning of a line in this buffer?
• Could you M-x toggle-debug-on-error and reproduce the error, and if that produces a backtrace, post that?
• Could you M-x toggle-debug-on-quite and hit C-g when Emacs hangs, and post the backtrace that produces, if any?
• If neither of these produce a backtrace, could you M-x profiler-start RET cpu RET, reproduce this, and post the data from M-x profiler-report?

Thank you!

[shaunhaskey]

Hi,

Here are the results of the debugging:

(length (elpy-rpc-get-completions)) gives the following:

193

Without toggle-debug-on-error I get the following in messages:
error in process filter: turn-on-font-lock-if-desired: Lisp nesting exceeds
max-lisp-eval-depth' error in process filter: Lisp nesting exceedsmax-lisp-eval-depth'

with toggle-debug-on-error I get the following in messages:

Debug on Error enabled globally
auto-complete error: (error Lisp nesting exceeds `max-lisp-eval-depth')
auto-complete-mode is not enabled [2 times]

auto-complete mode switches off, and is no backtrace produced

toggle-debug-on-quit produces a backtrace, and emacs becomes very sluggish
and is using 100% CPU even 10 mins after I C-g.

I have attached a print screen of what the backtrace looks like. I also
saved it, but it is 6.2MB. Let me know if you would like me to send it?

I have also attached the result of the profiler-report.

Let me know what else I can do.

Thanks,
Shaun

On Sun, May 25, 2014 at 5:31 PM, Jorgen Schäfer [email protected]:

Thank you for the report!

I'm afraid I can not reproduce this behavior, so I'll have to make you
jump through some shotgun-debugging stunts.

• What's the value of M-: (length (elpy-rpc-get-completions)) at the
  beginning of a line in this buffer?
• Could you M-x toggle-debug-on-error and reproduce the error, and if
  that produces a backtrace, post that?
• Could you M-x toggle-debug-on-quite and hit C-g when Emacs hangs,
  and post the backtrace that produces, if any?
• If neither of these produce a backtrace, could you M-x
  profiler-start RET cpu RET, reproduce this, and post the data from M-x
  profiler-report?

Thank you!

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/234#issuecomment-44120994
.

[jorgenschaefer]

It seems that github does not include attachments sent via mail. Could you please compress the backtrace and send it (together with the profiling info) to contact (at) jorgenschaefer.de? Thank you!

[jorgenschaefer]

The backtrace picture I got looks really weird. Elpy sends a completion request. process-send-string apparently immediately reads data back, gets the response of an earlier request, and processes that with the same stack (it should wait until this call finishes). Which in turn re-starts auto-complete, which does an RPC call, which reads data back …

While that smells definitely fishy, I'm not convinced that's the cause of the problem. The last call in the backtrace I see there is the 25th RPC call, and there are 12 calls per cycle, which is 300 frames deep. The default value for `max-lisp-eval-depth' is 600, so there has to be something before that (bottom of the trace). And this wouldn't explain the 20s hang, either.

You can try as a workaround to increase max-lisp-eval-depth to something like 6000.

Elpy 1.5 will be using Company for the in-line completion, not auto-complete, so regardless of whether we figure out what is causing this, the problem should be fixed when that gets released. But the next major release is not due until August, so I'd be quite interested in fixing this even with auto-complete. :-)

[jorgenschaefer]

Ok, I was wrong, the bug is exactly that: Auto-complete starts, asks elpy to initialize, elpy sends a get_completions call. So far, so good and normal. Now, this call should finish, but instead, Emacs immediately (from the process-send-string) reads data from the subprocess, which is a response to the auto-complete call one earlier. As Elpy now has a response, it asks auto-complete to pop up the info window. Instead, auto-complete re-initializes Elpy, which asks for completions, which reads the previous response, and we're in a loop that consumes stack frames.

So this is two bugs.

First, process-send-string reads data from a subprocess and handles it immediately (process.c:5580 in the current trunk). This is what causes this code to exceed the eval depth, but also enables the following.

Second, because the call to initialize elpy never returns, auto-complete does not know that the call to init succeeded, so happily re-executes it (auto-complete.el:1569).

Which results in an endless loop.

Nice example of a race condition in concurrent programming! :-)

Could you evaluate the following two statements and see if that fixes this problem for you?

(defvar elpy--ac-init-lock nil)
(defun elpy--ac-init ()
  "Initialize a completion.                                                     

This will call Python in the background and initialize                          
`elpy--ac-cache' when it returns."
  (when (and (not elpy--ac-init-lock)
             (not (eq (python-syntax-context-type)
                      'comment)))
    (let ((elpy--ac-init-lock t))
      (elpy-rpc-get-completions
       (lambda (result)
         (setq elpy--ac-cache nil)
         (dolist (completion result)
           (let ((name (car completion))
                 (doc (cadr completion)))
             (when (not (string-prefix-p "_" name))
               (push (cons (concat ac-prefix name)
                           doc)
                     elpy--ac-cache))))
         (ac-start))
       (lambda (err)
         (message "Can't get completions: %s" err))))))

[shaunhaskey]

Hi,

Those statements appear to fix the problem, thanks! I'll put them in my
init.el for now, and keep and eye on things to see if it shows up at all.
It is a little bit jerky and unresponsive when editing that file that was
part of a module, but always catches up (i.e no lost keystrokes). It is not
jerky when editing a standalone file. I assume this is to do with all the
extra auto-completion options it is constantly thinking about?

Thanks again,
Shaun

On Tue, May 27, 2014 at 6:51 PM, Jorgen Schäfer [email protected]:

Ok, I was wrong, the bug is exactly that: Auto-complete starts, asks elpy
to initialize, elpy sends a get_completions call. So far, so good and
normal. Now, this call should finish, but instead, Emacs immediately (from
the process-send-string) reads data from the subprocess, which is a
response to the auto-complete call one earlier. As Elpy now has a response,
it asks auto-complete to pop up the info window. Instead, auto-complete
re-initializes Elpy, which asks for completions, which reads the previous
response, and we're in a loop that consumes stack frames.

So this is two bugs.

First, process-send-string reads data from a subprocess and handles it
immediately (process.c:5580 in the current trunk). This is what causes this
code to exceed the eval depth, but also enables the following.

Second, because the call to initialize elpy never returns, auto-complete
does not know that the call to init succeeded, so happily re-executes it
(auto-complete.el:1569).

Which results in an endless loop.

Nice example of a race condition in concurrent programming! :-)

Could you evaluate the following two statements and see if that fixes this
problem for you?

(defvar elpy--ac-init-lock nil)(defun elpy--ac-init ()
"Initialize a completion.
This will call Python in the background and initialize `elpy--ac-cache' when it returns."
(when (and (not elpy--ac-init-lock)
(not (eq (python-syntax-context-type)
'comment)))
(let ((elpy--ac-init-lock t))
(elpy-rpc-get-completions
(lambda (result)
(setq elpy--ac-cache nil)
(dolist (completion result)
(let ((name (car completion))
(doc (cadr completion)))
(when (not (string-prefix-p "_" name))
(push (cons (concat ac-prefix name)
doc)
elpy--ac-cache))))
(ac-start))
(lambda (err)
(message "Can't get completions: %s" err))))))

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/234#issuecomment-44249993
.

[jorgenschaefer]

Elpy should not be jerky even for large files because it runs most stuff asynchronously. The one thing it can't do asynchronously is serializing/deserializing large buffers, so if you are editing a large file, it can slow things down considerably (Elpy 1.5 will fix this). Then again, I have noticed that auto-complete can behave in very strange ways in certain Emacs configurations. It might be that this is hitting you.

If you feel adventurous, you could try the current development version of Elpy (git clone the repo and add it to your load-path) and see if that works better for you. But be aware that I take the term "development version" seriously, it is by no means stable :-D

[shaunhaskey]

The file is quite large - 3136 lines, 164k characters. I should probably
clean it up or organise things a bit better. I'll see how things go with
these changes, and think about giving the development version a try!

On Wed, May 28, 2014 at 9:47 PM, Jorgen Schäfer [email protected]:

Elpy should not be jerky even for large files because it runs most
stuff asynchronously. The one thing it can't do asynchronously is
serializing/deserializing large buffers, so if you are editing a large
file, it can slow things down considerably (Elpy 1.5 will fix this). Then
again, I have noticed that auto-complete can behave in very strange ways in
certain Emacs configurations. It might be that this is hitting you.

If you feel adventurous, you could try the current development version of
Elpy (git clone the repo and add it to your load-path) and see if that
works better for you. But be aware that I take the term "development
version" seriously, it is by no means stable :-D

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/234#issuecomment-44396203
.

[jorgenschaefer]

As there were no further updates, I assume this fixed the problem for you. I'll close this issue. If you experience any further problems, please do not hesitate to open a new one, though!