From mboxrd@z Thu Jan 1 00:00:00 1970 Path: news.gmane.org!not-for-mail From: Stephen Berman Newsgroups: gmane.emacs.devel,gmane.emacs.pretest.bugs Subject: Re: 22.1.50; insert-file-contents is slow under tramp Date: Thu, 23 Aug 2007 22:39:03 +0200 Message-ID: <87k5rmkmu0.fsf@escher.local.home> References: <87veb6l9b0.fsf@escher.local.home> <46CD98DC.1050701@gmx.at> <87r6lul2fc.fsf@escher.local.home> <46CDC8B3.7000301@gmx.at> <46CDED2B.3080904@gmx.at> NNTP-Posting-Host: lo.gmane.org Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii X-Trace: sea.gmane.org 1187901591 517 80.91.229.12 (23 Aug 2007 20:39:51 GMT) X-Complaints-To: usenet@sea.gmane.org NNTP-Posting-Date: Thu, 23 Aug 2007 20:39:51 +0000 (UTC) Cc: emacs-pretest-bug@gnu.org To: emacs-devel@gnu.org Original-X-From: emacs-devel-bounces+ged-emacs-devel=m.gmane.org@gnu.org Thu Aug 23 22:39:49 2007 Return-path: Envelope-to: ged-emacs-devel@m.gmane.org Original-Received: from lists.gnu.org ([199.232.76.165]) by lo.gmane.org with esmtp (Exim 4.50) id 1IOJSz-0005HO-Ot for ged-emacs-devel@m.gmane.org; Thu, 23 Aug 2007 22:39:46 +0200 Original-Received: from localhost ([127.0.0.1] helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.43) id 1IOJSz-0001cW-2I for ged-emacs-devel@m.gmane.org; Thu, 23 Aug 2007 16:39:45 -0400 Original-Received: from mailman by lists.gnu.org with tmda-scanned (Exim 4.43) id 1IOJSv-0001bV-Jy for emacs-devel@gnu.org; Thu, 23 Aug 2007 16:39:41 -0400 Original-Received: from exim by lists.gnu.org with spam-scanned (Exim 4.43) id 1IOJSt-0001b7-1q for emacs-devel@gnu.org; Thu, 23 Aug 2007 16:39:41 -0400 Original-Received: from [199.232.76.173] (helo=monty-python.gnu.org) by lists.gnu.org with esmtp (Exim 4.43) id 1IOJSs-0001b4-TC for emacs-devel@gnu.org; Thu, 23 Aug 2007 16:39:38 -0400 Original-Received: from main.gmane.org ([80.91.229.2] helo=ciao.gmane.org) by monty-python.gnu.org with esmtps (TLS-1.0:RSA_AES_256_CBC_SHA1:32) (Exim 4.60) (envelope-from ) id 1IOJSr-00039W-Se for emacs-devel@gnu.org; Thu, 23 Aug 2007 16:39:38 -0400 Original-Received: from list by ciao.gmane.org with local (Exim 4.43) id 1IOJSh-0004ws-ET for emacs-devel@gnu.org; Thu, 23 Aug 2007 22:39:27 +0200 Original-Received: from i577bcbe3.versanet.de ([87.123.203.227]) by main.gmane.org with esmtp (Gmexim 0.1 (Debian)) id 1AlnuQ-0007hv-00 for ; Thu, 23 Aug 2007 22:39:27 +0200 Original-Received: from Stephen.Berman by i577bcbe3.versanet.de with local (Gmexim 0.1 (Debian)) id 1AlnuQ-0007hv-00 for ; Thu, 23 Aug 2007 22:39:27 +0200 X-Injected-Via-Gmane: http://gmane.org/ Original-Followup-To: gmane.emacs.devel Original-Lines: 175 Original-X-Complaints-To: usenet@sea.gmane.org X-Gmane-NNTP-Posting-Host: i577bcbe3.versanet.de User-Agent: Gnus/5.11 (Gnus v5.11) Emacs/22.1.50 (gnu/linux) X-Detected-Kernel: Linux 2.6, seldom 2.4 (older, 4) X-BeenThere: emacs-devel@gnu.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: "Emacs development discussions." List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Original-Sender: emacs-devel-bounces+ged-emacs-devel=m.gmane.org@gnu.org Errors-To: emacs-devel-bounces+ged-emacs-devel=m.gmane.org@gnu.org Xref: news.gmane.org gmane.emacs.devel:77049 gmane.emacs.pretest.bugs:19601 Archived-At: On Thu, 23 Aug 2007 19:49:39 +0200 martin rudalics wrote: >> It doesn't make a very big difference: it takes 17 seconds to open >> ChangeLog.12 as opposed to 20 seconds without the patch. (I assume I >> did it right: applied the patch and ran make in emacs/src to rebuild >> the emacs executable, without recompiling the lisp files.) > > I suppose you don't want to run insert-file-contents with gdb. See below. > Could you try to edebug format-decode and tell whether the 17 secs are > spent before calling it, while running it, or after calling it. The 17 seconds elapse before format-decode is called. On Thu, 23 Aug 2007 22:25:15 +0200 martin rudalics wrote: >> I think this has nothing to do with it: Tramp implements insert-file-contents >> in Elisp. > > I was puzzled because according to the OP > >>> ... the slowdown occurs when insert-file-contents is >>> called in find-file-noselect-1. > > Stephen could you tell us how this relates to tramp. Stefan is right, and I was wrong, but didn't see it until running under gdb, as you suggested. I set a breakpoint at fileio.c:3689 (the beginning of the insert-file-contents DEFUN). After going through the tramp stuff and typing RET on ChangeLog.12, execution stopped at the breakpoint: Breakpoint 3, Finsert_file_contents (filename=142792571, visit=137492729, beg=137492681, end=137492681, replace=137492681) at fileio.c:3714 3714 { (gdb) n 3720 int count = SPECPDL_INDEX (); (gdb) n 3733 Lisp_Object old_Vdeactivate_mark = Vdeactivate_mark; (gdb) n 3714 { (gdb) n 3720 int count = SPECPDL_INDEX (); (gdb) n 3736 if (current_buffer->base_buffer && ! NILP (visit)) (gdb) n 3720 int count = SPECPDL_INDEX (); (gdb) n 3733 Lisp_Object old_Vdeactivate_mark = Vdeactivate_mark; (gdb) n 3736 if (current_buffer->base_buffer && ! NILP (visit)) (gdb) n 3739 if (!NILP (current_buffer->read_only)) (gdb) n 3742 val = Qnil; (gdb) n 3749 CHECK_STRING (filename); (gdb) n 3742 val = Qnil; (gdb) n 3749 CHECK_STRING (filename); (gdb) n 3750 filename = Fexpand_file_name (filename, Qnil); (gdb) n 3754 handler = Ffind_file_name_handler (filename, Qinsert_file_contents); (gdb) n 3755 if (!NILP (handler)) (gdb) n 3754 handler = Ffind_file_name_handler (filename, Qinsert_file_contents); (gdb) n 3755 if (!NILP (handler)) (gdb) n 3757 val = call6 (handler, Qinsert_file_contents, filename, (gdb) n Warning: Cannot insert breakpoint -129. Error accessing memory address 0x9317cb93: Input/output error. Then I typed `c' and got the 17 second interval where emacs consumed almost all the CPU, then the breakpoint stopped execution again and I got the following backtrace: #0 Finsert_file_contents (filename=143060787, visit=137492681, beg=137492681, end=137492681, replace=137492681) at fileio.c:3714 #1 0x0815eadf in Ffuncall (nargs=6, args=0xbfd47f60) at eval.c:3040 #2 0x0818992d in Fbyte_code (bytestr=139911115, vector=142565700, maxdepth=) at bytecode.c:679 #3 0x0815e4fa in funcall_lambda (fun=142194052, nargs=5, arg_vector=0xbfd480a4) at eval.c:3213 #4 0x0815e901 in Ffuncall (nargs=6, args=0xbfd480a0) at eval.c:3083 #5 0x08160226 in Fapply (nargs=2, args=0xbfd48164) at eval.c:2514 #6 0x0815ec25 in Ffuncall (nargs=3, args=0xbfd48160) at eval.c:3007 #7 0x0818992d in Fbyte_code (bytestr=139908699, vector=142139364, maxdepth=) at bytecode.c:679 #8 0x0815e4fa in funcall_lambda (fun=142170892, nargs=6, arg_vector=0xbfd48284) at eval.c:3213 #9 0x0815e901 in Ffuncall (nargs=7, args=0xbfd48280) at eval.c:3083 #10 0x08160226 in Fapply (nargs=3, args=0xbfd48344) at eval.c:2514 #11 0x0815ec25 in Ffuncall (nargs=4, args=0xbfd48340) at eval.c:3007 #12 0x0818992d in Fbyte_code (bytestr=139908827, vector=142220436, maxdepth=) at bytecode.c:679 #13 0x0815e4fa in funcall_lambda (fun=142655764, nargs=6, arg_vector=0xbfd48464) at eval.c:3213 #14 0x0815e901 in Ffuncall (nargs=7, args=0xbfd48460) at eval.c:3083 #15 0x0815ec49 in call6 (fn=138355337, arg1=137611529, arg2=142719987, arg3=137492729, arg4=137492681, arg5=137492681, arg6=137492681) at eval.c:2931 #16 0x08129b28 in Finsert_file_contents (filename=142719987, visit=137492729, beg=137492681, end=137492681, replace=137492681) at fileio.c:3757 #17 0x0815eadf in Ffuncall (nargs=3, args=0xbfd5cbd0) at eval.c:3040 #18 0x0818992d in Fbyte_code (bytestr=136198155, vector=136198180, maxdepth=) at bytecode.c:679 #19 0x0815dfb5 in Feval (form=136198141) at eval.c:2363 #20 0x0816063f in internal_lisp_condition_case (var=137492681, bodyform=136198141, handlers=136198213) at eval.c:1433 #21 0x08188c25 in Fbyte_code (bytestr=136197731, vector=136197748, maxdepth=) at bytecode.c:869 #22 0x0815e4fa in funcall_lambda (fun=136197660, nargs=6, arg_vector=0xbfd5cef4) at eval.c:3213 #23 0x0815e901 in Ffuncall (nargs=7, args=0xbfd5cef0) at eval.c:3083 #24 0x0818992d in Fbyte_code (bytestr=136196795, vector=136196812, maxdepth=) at bytecode.c:679 #25 0x0815e4fa in funcall_lambda (fun=136196724, nargs=4, arg_vector=0xbfd5d024) at eval.c:3213 #26 0x0815e901 in Ffuncall (nargs=5, args=0xbfd5d020) at eval.c:3083 #27 0x0818992d in Fbyte_code (bytestr=136192091, vector=136192108, maxdepth=) at bytecode.c:679 #28 0x0815e4fa in funcall_lambda (fun=136192036, nargs=1, arg_vector=0xbfd5d154) ---Type to continue, or q to quit--- at eval.c:3213 #29 0x0815e901 in Ffuncall (nargs=2, args=0xbfd5d150) at eval.c:3083 #30 0x0818992d in Fbyte_code (bytestr=139566787, vector=142412436, maxdepth=) at bytecode.c:679 #31 0x0815e4fa in funcall_lambda (fun=142412572, nargs=0, arg_vector=0xbfd5d274) at eval.c:3213 #32 0x0815e901 in Ffuncall (nargs=1, args=0xbfd5d270) at eval.c:3083 #33 0x08160379 in apply1 (fn=142392345, arg=137492681) at eval.c:2767 #34 0x0815ba00 in Fcall_interactively (function=142392345, record_flag=137492681, keys=137533996) at callint.c:406 #35 0x080fac73 in Fcommand_execute (cmd=142392345, record_flag=137492681, keys=137492681, special=137492681) at keyboard.c:10119 #36 0x0810684b in command_loop_1 () at keyboard.c:1873 #37 0x0815d492 in internal_condition_case (bfun=0x81064d0 , handlers=137538137, hfun=0x8100e20 ) at eval.c:1488 #38 0x08100263 in command_loop_2 () at keyboard.c:1329 #39 0x0815d54a in internal_catch (tag=137531321, func=0x8100240 , arg=137492681) at eval.c:1229 #40 0x08100c5c in command_loop () at keyboard.c:1308 #41 0x08100ffb in recursive_edit_1 () at keyboard.c:1006 #42 0x081010e6 in Frecursive_edit () at keyboard.c:1067 #43 0x080f6dd0 in main (argc=2, argv=0xbfd5db14) at emacs.c:1774 Lisp Backtrace: "insert-file-contents" (0x886ef33) "tramp-handle-insert-file-contents" (0x881bbf3) "apply" (0x88013b9) "tramp-sh-file-name-handler" (0x833c909) "apply" (0x88014c1) "tramp-file-name-handler" (0x833c909) "insert-file-contents" (0x883cdfb) "byte-code" (0x81e380b) "find-file-noselect-1" (0x884a17c) "find-file-noselect" (0x883ffab) "find-file" (0x883ffab) "dired-advertised-find-file" (0x831f8c9) "call-interactively" (0x87cbc19) So the slowdown is at insert-file-contents, but the invocation is from tramp, which I did not see when using edebug before. I tried edebugging in tramp but could not get any further than tramp-file-name-handler. Hopefully someone else (Michael Albinus?) can. Steve Berman