From mboxrd@z Thu Jan 1 00:00:00 1970 Path: news.gmane.org!not-for-mail From: Dov Grobgeld Newsgroups: gmane.emacs.bugs Subject: bug#10580: 24.0.92; gdb initialization takes more than one minute at 100% CPU Date: Tue, 8 May 2012 10:56:21 +0300 Message-ID: References: <20253.9861.848886.122482@fencepost.gnu.org> <87aa1mj69x.fsf@gnu.org> <87havtvpeb.fsf@gnu.org> <874nrsem67.fsf@gnu.org> <874nrswme9.fsf@gnu.org> <87zk9kv75l.fsf@gnu.org> NNTP-Posting-Host: plane.gmane.org Mime-Version: 1.0 Content-Type: multipart/alternative; boundary=14dae9399bd9fcd52004bf81b86d X-Trace: dough.gmane.org 1336463828 19498 80.91.229.3 (8 May 2012 07:57:08 GMT) X-Complaints-To: usenet@dough.gmane.org NNTP-Posting-Date: Tue, 8 May 2012 07:57:08 +0000 (UTC) Cc: 10580@debbugs.gnu.org To: Chong Yidong Original-X-From: bug-gnu-emacs-bounces+geb-bug-gnu-emacs=m.gmane.org@gnu.org Tue May 08 09:57:06 2012 Return-path: Envelope-to: geb-bug-gnu-emacs@m.gmane.org Original-Received: from lists.gnu.org ([208.118.235.17]) by plane.gmane.org with esmtp (Exim 4.69) (envelope-from ) id 1SRfI8-0001G8-Qa for geb-bug-gnu-emacs@m.gmane.org; Tue, 08 May 2012 09:57:05 +0200 Original-Received: from localhost ([::1]:58786 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1SRfI8-0000za-8g for geb-bug-gnu-emacs@m.gmane.org; Tue, 08 May 2012 03:57:04 -0400 Original-Received: from eggs.gnu.org ([208.118.235.92]:46763) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1SRfI4-0000yj-BM for bug-gnu-emacs@gnu.org; Tue, 08 May 2012 03:57:02 -0400 Original-Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1SRfI2-0005VS-EJ for bug-gnu-emacs@gnu.org; Tue, 08 May 2012 03:56:59 -0400 Original-Received: from debbugs.gnu.org ([140.186.70.43]:39353) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1SRfI2-0005VJ-84 for bug-gnu-emacs@gnu.org; Tue, 08 May 2012 03:56:58 -0400 Original-Received: from Debian-debbugs by debbugs.gnu.org with local (Exim 4.72) (envelope-from ) id 1SRfK2-0004ho-F7 for bug-gnu-emacs@gnu.org; Tue, 08 May 2012 03:59:02 -0400 X-Loop: help-debbugs@gnu.org Resent-From: Dov Grobgeld Original-Sender: debbugs-submit-bounces@debbugs.gnu.org Resent-CC: bug-gnu-emacs@gnu.org Resent-Date: Tue, 08 May 2012 07:59:02 +0000 Resent-Message-ID: Resent-Sender: help-debbugs@gnu.org X-GNU-PR-Message: followup 10580 X-GNU-PR-Package: emacs X-GNU-PR-Keywords: Original-Received: via spool by 10580-submit@debbugs.gnu.org id=B10580.133646391818058 (code B ref 10580); Tue, 08 May 2012 07:59:02 +0000 Original-Received: (at 10580) by debbugs.gnu.org; 8 May 2012 07:58:38 +0000 Original-Received: from localhost ([127.0.0.1]:40387 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.72) (envelope-from ) id 1SRfJc-0004hC-GV for submit@debbugs.gnu.org; Tue, 08 May 2012 03:58:37 -0400 Original-Received: from mail-ob0-f172.google.com ([209.85.214.172]:49589) by debbugs.gnu.org with esmtp (Exim 4.72) (envelope-from ) id 1SRfJZ-0004gy-2J for 10580@debbugs.gnu.org; Tue, 08 May 2012 03:58:34 -0400 Original-Received: by obbeh20 with SMTP id eh20so9352449obb.3 for <10580@debbugs.gnu.org>; Tue, 08 May 2012 00:56:22 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :cc:content-type; bh=q1TKw5VTdr+07Ai9jsb2/BbKHUN+2i/3MUsewmRmOUk=; b=PpNgBdwcLeZCfdNIrHw0OnHTfHwuJRjBLyfHvYSblaLOIh86ToqySoU8Jk8Ttx0vg/ sUymzvXn4T6wIiZXO1irvTnxOxBkDJ0C2/5i2drkmliWU/yuL0AD+x/tZdPmzCb4AzvE UmyYrEttgpsXmmiqM29i5MEiGcbBgnqQnNFzEhGGYTyp1JK33drWGiivRER01QN6Rp26 /Lgn2kviYeZgfFX8LwmFVmLsrZALy9zu4VSqNu9zldElS8kBngK53a0DvXfrH9X5AZoZ XAbrcPMl8UbUnATn/ZKMGZQrDLY+7/un6H6WJrQ94izgCd0s38aypZzs+8cipAxahwYX z0cQ== Original-Received: by 10.182.159.5 with SMTP id wy5mr1513462obb.24.1336463782106; Tue, 08 May 2012 00:56:22 -0700 (PDT) Original-Received: by 10.182.60.137 with HTTP; Tue, 8 May 2012 00:56:21 -0700 (PDT) In-Reply-To: X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.13 Precedence: list X-detected-operating-system: by eggs.gnu.org: GNU/Linux 2.6 (newer, 2) X-Received-From: 140.186.70.43 X-BeenThere: bug-gnu-emacs@gnu.org List-Id: "Bug reports for GNU Emacs, the Swiss army knife of text editors" List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: bug-gnu-emacs-bounces+geb-bug-gnu-emacs=m.gmane.org@gnu.org Original-Sender: bug-gnu-emacs-bounces+geb-bug-gnu-emacs=m.gmane.org@gnu.org Xref: news.gmane.org gmane.emacs.bugs:59857 Archived-At: --14dae9399bd9fcd52004bf81b86d Content-Type: text/plain; charset=UTF-8 Some more info that I found through strace that might help. Alltogether read_process_output() is called 214 times and thus a total of 870k of text is read through /dev/ptmx to read_process_output() . Could the amount of data possibly explain the slowness? Regards, Dov On Tue, May 8, 2012 at 8:33 AM, Dov Grobgeld wrote: > I added the above patch and the result is as follows: > > After the following two lines: > > > nread = read_process_output (proc, channel); > > pp = XPROCESS(proc); > > nread==4095, pp->pid=1234 repeatedly. (Actually 1234 seems to be an > arbitrary, but constant number between 1000 and 2000). > > This seems strange, as obviously the sub-process does not produce 4095 > characters repeatedly. > > Thanks, > Dov > > On Mon, May 7, 2012 at 9:26 AM, Chong Yidong wrote: > >> Actually, try the following patch instead (apparently gdb has some >> issues with printing errno). Apply the patch, then when Emacs is taking >> 100% CPU do an interrupt and set the breakpoint at process.c:4855, then >> when the breakpoint triggers do >> >> n >> p nread >> p errno >> >> and step through the subsequent if/else blocks. Thanks. >> >> Basically, the 100% CPU appears to be because Emacs' select() call keeps >> getting worken up by the pty attached to your program. But, for some >> reason, no actual output being read from that pty. These debugging >> steps are trying to figure out if some uncaught errno is being reported >> by the pty read. >> >> >> === modified file 'src/process.c' >> *** src/process.c 2012-04-20 06:39:29 +0000 >> --- src/process.c 2012-05-07 06:21:39 +0000 >> *************** >> *** 4822,4827 **** >> --- 4822,4829 ---- >> && !FD_ISSET (channel, &non_process_wait_mask)) >> { >> int nread; >> + int saved_errno = 0; >> + struct Lisp_Process *pp; >> >> /* If waiting for this channel, arrange to return as >> soon as no more input to be processed. No more >> *************** >> *** 4847,4852 **** >> --- 4849,4859 ---- >> buffered-ahead character if we have one. */ >> >> nread = read_process_output (proc, channel); >> + >> + pp = XPROCESS (proc); >> + if (pp->pid == -2) >> + saved_errno = errno; >> + >> if (nread > 0) >> { >> /* Since read_process_output can run a filter, >> >> > --14dae9399bd9fcd52004bf81b86d Content-Type: text/html; charset=UTF-8 Content-Transfer-Encoding: quoted-printable
Some more info t= hat I found through strace that might help. Alltogether read_process_output= () is called 214 times and thus a total of 870k of text is read through /de= v/ptmx to read_process_output() . Could the amount of data possibly explain= the slowness?

Regards,
Dov

On Tue, May 8,= 2012 at 8:33 AM, Dov Grobgeld <dov.grobgeld@gmail.com>= wrote:
I added the above patch and the result is as follows:
After the following two lines:


=C2=A0=C2=A0=C2=A0 nread =3D read_process_output (proc, channel);
=C2=A0=C2=A0=C2=A0 pp =3D XPROCESS(proc);

nread=3D=3D4095, pp->pid=3D1234 repeatedly. (Actually 1234 seems to = be an arbitrary, but constant number between 1000 and 2000).

This s= eems strange, as obviously the sub-process does not produce 4095 characters= repeatedly.

Thanks,
Dov

On Mon, May 7, 2012 at 9:26 AM, Chong Yidong <= cyd@gnu.org>= wrote:
Actually, try the following patch instead (apparently gdb has some
issues with printing errno). =C2=A0Apply the patch, then when Emacs is taki= ng
100% CPU do an interrupt and set the breakpoint at process.c:4855, then
when the breakpoint triggers do

n
p nread
p errno

and step through the subsequent if/else blocks. =C2=A0Thanks.

Basically, the 100% CPU appears to be because Emacs' select() call keep= s
getting worken up by the pty attached to your program. =C2=A0But, for some<= br> reason, no actual output being read from that pty. =C2=A0These debugging steps are trying to figure out if some uncaught errno is being reported
by the pty read.


=3D=3D=3D modified file 'src/process.c'
*** src/process.c =C2=A0 =C2=A0 =C2=A0 2012-04-20 06:39:29 +0000
--- src/process.c =C2=A0 =C2=A0 =C2=A0 2012-05-07 06:21:39 +0000
***************
*** 4822,4827 ****
--- 4822,4829 ----
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0&& !FD_ISSE= T (channel, &non_process_wait_mask))
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0{
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0int nread;
+ =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 int saved_errno =3D 0;
+ =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 struct Lisp_Process *pp;

=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0/* If waiting for this cha= nnel, arrange to return as
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 soon as no more in= put to be processed. =C2=A0No more
***************
*** 4847,4852 ****
--- 4849,4859 ----
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 buffered-ahea= d character if we have one. =C2=A0*/

=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0nread =3D read_process_out= put (proc, channel);
+
+ =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 pp =3D XPROCESS (pro= c);
+ =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 if (pp->pid =3D=3D -2)=
+ =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 saved_errno =3D errno;
+
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0if (nread > 0)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0{
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0/* Since rea= d_process_output can run a filter,



--14dae9399bd9fcd52004bf81b86d--