bug#895: slow processing of process output

bug#895: slow processing of process output

[Dan Nicolaescu]

emacs -Q -nw
M-x rgrep RET emacs RET *.el RET PATH_TO_EMACS_SOURCE_TREE/lisp RET

takes a few minutes.  The output is about 9000 lines.

Running the correspondind command:

find . \( -path \*/SCCS -o -path \*/RCS -o -path \*/CVS -o -path \*/MCVS -o -path \*/.svn -o -path \*/.git -o -path \*/.hg -o -path \*/.bzr -o -path \*/_MTN -o -path \*/_darcs -o -path \*/\{arch\} \) -prune -o -type f \( -name *.el \) -print0 | xargs -0 -e grep -i -nH -e emacs

from a shell (and redirecting the output to a file) takes less than one second.

bug#895: slow processing of process output

[Dan Nicolaescu]

Dan Nicolaescu <dann@ics.uci.edu> writes:

  > emacs -Q -nw
  > M-x rgrep RET emacs RET *.el RET PATH_TO_EMACS_SOURCE_TREE/lisp RET
  > 
  > takes a few minutes.  The output is about 9000 lines.
  > 
  > Running the correspondind command:
  > 
  > find . \( -path \*/SCCS -o -path \*/RCS -o -path \*/CVS -o -path \*/MCVS -o -path \*/.svn -o -path \*/.git -o -path \*/.hg -o -path \*/.bzr -o -path \*/_MTN -o -path \*/_darcs -o -path \*/\{arch\} \) -prune -o -type f \( -name *.el \) -print0 | xargs -0 -e grep -i -nH -e emacs
  > 
  > from a shell (and redirecting the output to a file) takes less than one second.

One more data point:

emacs -Q -nw

M-x lgrep RET emacs RET *.el RET PATH_TO_EMACS_SOURCE_TREE/lisp RET

takes 33 seconds.  It runs the command:  grep -i -nH -e emacs *.el

M-x shell RET time grep -i -nH -e emacs *.el
0.087u 0.020s 0:01.60 6.2%      0+0k 0+0io 0pf+0w
              ^^^^^^^
              A lot less than 33 seconds.

bug#895: slow processing of process output on Mac

[mh origin]

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

I see this with matlab-shell, when trying to tab-complete, in Emacs 23 and
emacs 24 on the Mac, both on Lion and on Snow Leopard.  I fired this up in
the debugger and it looks like it gets stuck on a system call but I'm
afraid I couldn't figure out any more than that.

At first start, Matlab returns completions just fine, but after about an
hour it starts hanging when tab is pressed.

The function called on completion is here:
https://github.com/ruediger/matlab-emacs/blob/master/matlab.el#L4831

And the accept-process-output call that hangs is here:
https://github.com/ruediger/matlab-emacs/blob/master/matlab.el#L5304

I'm using Emacs 24.0.93 from here:
http://emacsformacosx.com/emacs-builds/Emacs-pretest-24.0.93-universal-10.6.8.dmg

Can I do anything else to help people track this down?

[-- Attachment #2: Type: text/html, Size: 1168 bytes --]

bug#895: slow processing of process output

[Richard Copley]

I tested in current master with mingw-w64 on Windows. The rgrep
command given in the OP takes 29 s in Emacs, but the corresponding
shell command[1] takes over a minute in Windows cmd.exe (at a guess,
that's because cmd.exe scrolls line-by-line so has to push a lot of
pixels).

Likewise, building Emacs is faster with "M-x compile" than it is on
the shell (from a clean checkout on my configuration it takes 7 min 43
seconds in Emacs and 9 minutes 15 seconds in cmd.exe).

I'm tempted to conclude that this bug has been fixed.

[1] G:\usr\bin\find.exe . -type d "(" -path "*/SCCS" -o -path "*/RCS"
-o -path "*/CVS" -o -path "*/MCVS" -o -path "*/.src" -o -path "*/.svn"
-o -path "*/.git" -o -path "*/.hg" -o -path "*/.bzr" -o -path "*/_MTN"
-o -path "*/_darcs" -o -path "*/{arch}" ")" -prune -o ^"^!^" -type d
"(" -name ".#*" -o -name "*.o" -o -name "*~" -o -name "*.bin" -o -name
"*.bak" -o -name "*.obj" -o -name "*.map" -o -name "*.ico" -o -name
"*.pif" -o -name "*.lnk" -o -name "*.a" -o -name "*.ln" -o -name
"*.blg" -o -name "*.bbl" -o -name "*.dll" -o -name "*.drv" -o -name
"*.vxd" -o -name "*.386" -o -name "*.elc" -o -name "*.lof" -o -name
"*.glo" -o -name "*.idx" -o -name "*.lot" -o -name "*.fmt" -o -name
"*.tfm" -o -name "*.class" -o -name "*.fas" -o -name "*.lib" -o -name
"*.mem" -o -name "*.x86f" -o -name "*.sparcf" -o -name "*.dfsl" -o
-name "*.pfsl" -o -name "*.d64fsl" -o -name "*.p64fsl" -o -name
"*.lx64fsl" -o -name "*.lx32fsl" -o -name "*.dx64fsl" -o -name
"*.dx32fsl" -o -name "*.fx64fsl" -o -name "*.fx32fsl" -o -name
"*.sx64fsl" -o -name "*.sx32fsl" -o -name "*.wx64fsl" -o -name
"*.wx32fsl" -o -name "*.fasl" -o -name "*.ufsl" -o -name "*.fsl" -o
-name "*.dxl" -o -name "*.lo" -o -name "*.la" -o -name "*.gmo" -o
-name "*.mo" -o -name "*.toc" -o -name "*.aux" -o -name "*.cp" -o
-name "*.fn" -o -name "*.ky" -o -name "*.pg" -o -name "*.tp" -o -name
"*.vr" -o -name "*.cps" -o -name "*.fns" -o -name "*.kys" -o -name
"*.pgs" -o -name "*.tps" -o -name "*.vrs" -o -name "*.pyc" -o -name
"*.pyo" ")" -prune -o  -type f "(" -iname "*.el" ")" -exec
G:\usr\bin\grep.exe --color=always -i -nH -e "emacs" {} +


In GNU Emacs 25.0.50.1 (x86_64-w64-mingw32)
 of 2016-01-02 built on MACHINE
Repository revision: 372d00a981942a5da868a33372eb29d5806f2ab3
Windowing system distributor 'Microsoft Corp.', version 10.0.10586
Configured using:
 'configure --prefix /c/emacs/emacs-20160101-122333
 --without-imagemagick --disable-dependency-tracking
 --enable-locallisppath=%emacs_dir%/../site-lisp 'CFLAGS=-Og -g -ggdb''

Configured features:
XPM JPEG TIFF GIF PNG RSVG SOUND DBUS NOTIFY ACL GNUTLS LIBXML2 ZLIB
TOOLKIT_SCROLL_BARS

Important settings:
  value of $LANG: ENG
  locale-coding-system: cp1252

Major mode: Lisp Interaction

Minor modes in effect:
  tooltip-mode: t
  global-eldoc-mode: t
  electric-indent-mode: t
  mouse-wheel-mode: t
  tool-bar-mode: t
  menu-bar-mode: t
  file-name-shadow-mode: t
  global-font-lock-mode: t
  font-lock-mode: t
  blink-cursor-mode: t
  auto-composition-mode: t
  auto-encryption-mode: t
  auto-compression-mode: t
  line-number-mode: t
  transient-mark-mode: t

Recent messages:
For information about GNU Emacs and the GNU system, type C-h C-a.

Load-path shadows:
None found.

Features:
(shadow sort gnus-util mail-extr emacsbug message dired format-spec
rfc822 mml mml-sec mm-decode mm-bodies mm-encode mail-parse rfc2231
mailabbrev gmm-utils mailheader sendmail rfc2047 rfc2045 ietf-drums
mm-util help-fns help-mode easymenu cl-loaddefs pcase cl-lib mail-prsvr
mail-utils time-date mule-util tooltip eldoc electric uniquify
ediff-hook vc-hooks lisp-float-type mwheel dos-w32 ls-lisp disp-table
w32-win w32-vars term/common-win tool-bar dnd fontset image regexp-opt
fringe tabulated-list newcomment elisp-mode lisp-mode prog-mode register
page menu-bar rfn-eshadow timer select scroll-bar mouse jit-lock
font-lock syntax facemenu font-core frame cl-generic cham georgian
utf-8-lang misc-lang vietnamese tibetan thai tai-viet lao korean
japanese eucjp-ms cp51932 hebrew greek romanian slovak czech european
ethiopic indian cyrillic chinese charscript case-table epa-hook
jka-cmpr-hook help simple abbrev minibuffer cl-preloaded nadvice
loaddefs button faces cus-face macroexp files text-properties overlay
sha1 md5 base64 format env code-pages mule custom widget
hashtable-print-readable backquote w32notify dbusbind w32 multi-tty
make-network-process emacs)

Memory information:
((conses 16 83465 5112)
 (symbols 56 19008 0)
 (miscs 48 36 86)
 (strings 32 14081 5015)
 (string-bytes 1 386417)
 (vectors 16 11288)
 (vector-slots 8 408630 5027)
 (floats 8 139 4)
 (intervals 56 239 22)
 (buffers 976 11))

bug#895: slow processing of process output

[Eli Zaretskii]

> From: Richard Copley <rcopley@gmail.com>
> Date: Fri, 8 Jan 2016 01:24:08 +0000
> 
> I tested in current master with mingw-w64 on Windows. The rgrep
> command given in the OP takes 29 s in Emacs, but the corresponding
> shell command[1] takes over a minute in Windows cmd.exe (at a guess,
> that's because cmd.exe scrolls line-by-line so has to push a lot of
> pixels).
> 
> Likewise, building Emacs is faster with "M-x compile" than it is on
> the shell (from a clean checkout on my configuration it takes 7 min 43
> seconds in Emacs and 9 minutes 15 seconds in cmd.exe).
> 
> I'm tempted to conclude that this bug has been fixed.

Thanks.

I think we need to try reproducing this on a Posix host before we can
conclude the bug is fixed.  The original problem was reported on
GNU/Linux, AFAICT, and the machinery used on Windows for communicating
with subprocesses is very different from that used on Unix.

Would someone please try reproducing this on GNU or Unix system?

TIA

bug#895: slow processing of process output

[Alexis]

Eli Zaretskii <eliz@gnu.org> writes:

> I think we need to try reproducing this on a Posix host before 
> we can conclude the bug is fixed.  The original problem was 
> reported on GNU/Linux, AFAICT, and the machinery used on Windows 
> for communicating with subprocesses is very different from that 
> used on Unix.
>
> Would someone please try reproducing this on GNU or Unix system?

Compiled from current master, running the rgrep command as per the 
OP successfully returns a buffer of ~17000 lines almost instantly 
on my Debian Jessie system.

bug#895: slow processing of process output

[Eli Zaretskii]

> From: Alexis <flexibeast@gmail.com>
> Cc: Richard Copley <rcopley@gmail.com>, 895@debbugs.gnu.org
> Date: Fri, 08 Jan 2016 20:53:59 +1100
> 
> Eli Zaretskii <eliz@gnu.org> writes:
> 
> > I think we need to try reproducing this on a Posix host before 
> > we can conclude the bug is fixed.  The original problem was 
> > reported on GNU/Linux, AFAICT, and the machinery used on Windows 
> > for communicating with subprocesses is very different from that 
> > used on Unix.
> >
> > Would someone please try reproducing this on GNU or Unix system?
> 
> Compiled from current master, running the rgrep command as per the 
> OP successfully returns a buffer of ~17000 lines almost instantly 
> on my Debian Jessie system.

Thanks, I guess this does mean we fixed it somehow.

bug#895: slow processing of process output

[Dmitry Gutov]

On 01/08/2016 12:30 PM, Eli Zaretskii wrote:

> Would someone please try reproducing this on GNU or Unix system?

Looks fixed:

With warm cache, the original commands takes 4 seconds in Emacs, also 4 
seconds in my shell (fish inside terminator), and produces the output of 
17000 lines.

It's still <1 second when redirected to a file, but that's to be 
expected, I think.

bug#895: slow processing of process output

[Eli Zaretskii]

> Cc: 895@debbugs.gnu.org
> From: Dmitry Gutov <dgutov@yandex.ru>
> Date: Fri, 8 Jan 2016 13:07:22 +0300
> 
> On 01/08/2016 12:30 PM, Eli Zaretskii wrote:
> 
> > Would someone please try reproducing this on GNU or Unix system?
> 
> Looks fixed:
> 
> With warm cache, the original commands takes 4 seconds in Emacs, also 4 
> seconds in my shell (fish inside terminator), and produces the output of 
> 17000 lines.
> 
> It's still <1 second when redirected to a file, but that's to be 
> expected, I think.

Thanks.

bug#895: slow processing of process output

[Richard Copley]

tags 685872 unreproducible

bug#895: slow processing of process output

[Noam Postavsky]

Dmitry Gutov <dgutov <at> yandex.ru> wrote:
>
> Looks fixed:
>
> With warm cache, the original commands takes 4 seconds in Emacs, also 4
> seconds in my shell (fish inside terminator), and produces the output of
> 17000 lines.
>
> It's still <1 second when redirected to a file, but that's to be
> expected, I think.

Closing.