22.1.50; insert-file-contents is slow under tramp

22.1.50; insert-file-contents is slow under tramp

[Stephen Berman]

1. emacs -Q

2. I type C-x d and at the prompt type "/localhost:/ RET" and when
prompted type my user password and then complete the path to some
directory that contains a fairly large file (> 1MB is enough to
clearly show the problem), e.g. the lisp directory of the Emacs
sources.

3. I put the cursor on a large file, e.g. ChangeLog.12 (1251246 bytes)
and press RET.  On my machine it takes ~20 seconds for the buffer
visiting this file to appear and during that time emacs is consuming
almost 100% CPU.

If at step 2 I directly enter the path to the lisp directory of the
Emacs sources, avoiding tramp, and then do step 3, the buffer appears
almost instantly, as usual.  So the slowdown is only with tramp (also
if I use a different user, e.g. with /su::/, which is how I first
encountered the problem).  The slowdown seems to be proportional to
the size of the file, so not too long (but noticeable) with small
files.

Using edebug I found the slowdown occurs when insert-file-contents is
called in find-file-noselect-1.  I don't know how to debug it further.
This slowdown did not exist in my previous Emacs build from 2007-06-30.


In GNU Emacs 22.1.50.7 (i686-pc-linux-gnu, GTK+ Version 2.10.6)
 of 2007-08-21 on escher
Windowing system distributor `The X.Org Foundation', version 11.0.70199902
Important settings:
  value of $LC_ALL: nil
  value of $LC_COLLATE: nil
  value of $LC_CTYPE: nil
  value of $LC_MESSAGES: nil
  value of $LC_MONETARY: nil
  value of $LC_NUMERIC: nil
  value of $LC_TIME: nil
  value of $LANG: en_US.UTF-8
  locale-coding-system: utf-8
  default-enable-multibyte-characters: t

Major mode: Group

Minor modes in effect:
  gnus-agent-mode: t
  shell-dirtrack-mode: t
  gnus-topic-mode: t
  gnus-undo-mode: t
  tabbar-mwheel-mode: t
  tabbar-mode: t
  recentf-mode: t
  display-time-mode: t
  show-paren-mode: t
  tooltip-mode: t
  tool-bar-mode: t
  mouse-wheel-mode: t
  menu-bar-mode: t
  file-name-shadow-mode: t
  global-font-lock-mode: t
  font-lock-mode: t
  unify-8859-on-encoding-mode: t
  utf-translate-cjk-mode: t
  auto-compression-mode: t
  temp-buffer-resize-mode: t
  column-number-mode: t
  line-number-mode: t
  transient-mark-mode: identity

Recent input:
<return> e s <tab> <backspace> r <tab> s <tab> c v 
<tab> e <tab> / l i <tab> <M-backspace> l i s <tab> 
<return> <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> <down> <down> 
<down> <down> <down> <down> <down> <down> <down> <down> 
<down> <down> <down> <down> <down> <down> <down> <down> 
<down> <down> <down> <down> <down> <return> <help-echo> 
<help-echo> <help-echo> <help-echo> <help-echo> <help-echo> 
<tool-bar> <kill-buffer> <tool-bar> <kill-buffer> C-c 
j m a <tab> <return> <up> <up> <up> <up> <up> <up> 
/ o 5 0 0 <return> <home> C-s t r a m C-w C-s C-s C-a 
<down> <down> <down> C-s C-s C-r C-r <left> SPC <up> 
SPC <f1> <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> <down> <down> 
<down> <down> <down> <down> <down> <down> <down> <down> 
<down> <down> <down> <down> <down> <down> <down> <down> 
<down> <up> SPC <f1> <down-mouse-1> <mouse-2> <select-window> 
<select-window> <help-echo> <f1> <down> q M-x r e p 
o <tab> r <tab> b <tab> <return>

Recent messages:
Fetching headers for gmane.emacs.devel...done
Loading cl-seq...done
Loading cl-extra...done
Generating summary...done
Mark set
Mark saved where search started [2 times]
Loading w3m-symbol...done
Loading w3m-form...done
Making completion list...
Loading emacsbug...done

Re: 22.1.50; insert-file-contents is slow under tramp

[martin rudalics]

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

> Using edebug I found the slowdown occurs when insert-file-contents is
> called in find-file-noselect-1.  I don't know how to debug it further.
> This slowdown did not exist in my previous Emacs build from 2007-06-30.

Stefan found a bug in my recent changes to `insert-file-contents'.
I can't tell whether it's related to your problem but could you try
with the attached patch?

[-- Attachment #2: fileio.patch --]
[-- Type: text/plain, Size: 2673 bytes --]

*** fileio.c	Sat Aug 18 09:50:08 2007
--- fileio.c	Thu Aug 23 11:04:32 2007
***************
*** 4733,4746 ****
  	  int opoint = PT;
  	  int opoint_byte = PT_BYTE;
  	  int oinserted = ZV - BEGV;
  	  
  	  TEMP_SET_PT_BOTH (BEGV, BEGV_BYTE); 
  	  insval = call3 (Qformat_decode,
  			  Qnil, make_number (oinserted), visit);
  	  CHECK_NUMBER (insval);
! 	  if (XINT (insval) == oinserted)
  	    SET_PT_BOTH (opoint, opoint_byte);
! 	  inserted = XFASTINT (insval);
  	}
  
        /* For consistency with format-decode call these now iff inserted > 0
--- 4733,4753 ----
  	  int opoint = PT;
  	  int opoint_byte = PT_BYTE;
  	  int oinserted = ZV - BEGV;
+ 	  int ochars_modiff = CHARS_MODIFF;
  	  
  	  TEMP_SET_PT_BOTH (BEGV, BEGV_BYTE); 
  	  insval = call3 (Qformat_decode,
  			  Qnil, make_number (oinserted), visit);
  	  CHECK_NUMBER (insval);
! 	  if (ochars_modiff == CHARS_MODIFF)
! 	    /* format_decode didn't modify buffer's characters => move
! 	       point back to position before inserted text and leave
! 	       value of inserted alone. */
  	    SET_PT_BOTH (opoint, opoint_byte);
! 	  else
! 	    /* format_decode modified buffer's characters => consider
! 	       entire buffer changed and leave point at point-min. */
! 	    inserted = XFASTINT (insval);
  	}
  
        /* For consistency with format-decode call these now iff inserted > 0
***************
*** 4763,4777 ****
  	      int opoint = PT;
  	      int opoint_byte = PT_BYTE;
  	      int oinserted = ZV - BEGV;
! 
  	      TEMP_SET_PT_BOTH (BEGV, BEGV_BYTE);
  	      insval = call1 (XCAR (p), make_number (oinserted));
  	      if (!NILP (insval))
  		{
  		  CHECK_NUMBER (insval);
! 		  if (XINT (insval) == oinserted)
  		    SET_PT_BOTH (opoint, opoint_byte);
! 		  inserted = XFASTINT (insval);
  		}
  	    }
  
--- 4770,4793 ----
  	      int opoint = PT;
  	      int opoint_byte = PT_BYTE;
  	      int oinserted = ZV - BEGV;
! 	      int ochars_modiff = CHARS_MODIFF;
! 	      
  	      TEMP_SET_PT_BOTH (BEGV, BEGV_BYTE);
  	      insval = call1 (XCAR (p), make_number (oinserted));
  	      if (!NILP (insval))
  		{
  		  CHECK_NUMBER (insval);
! 		  if (ochars_modiff == CHARS_MODIFF)
! 		    /* after_insert_file_functions didn't modify
! 		       buffer's characters => move point back to
! 		       position before inserted text and leave value of
! 		       inserted alone. */
  		    SET_PT_BOTH (opoint, opoint_byte);
! 		  else
! 		    /* after_insert_file_functions did modify buffer's
! 	               characters => consider entire buffer changed and
! 	               leave point at point-min. */
! 		    inserted = XFASTINT (insval);
  		}
  	    }
  

[-- Attachment #3: Type: text/plain, Size: 142 bytes --]

_______________________________________________
Emacs-devel mailing list
Emacs-devel@gnu.org
http://lists.gnu.org/mailman/listinfo/emacs-devel

Re: 22.1.50; insert-file-contents is slow under tramp

[Stephen Berman]

On Thu, 23 Aug 2007 16:25:32 +0200 martin rudalics <rudalics@gmx.at> wrote:

>> Using edebug I found the slowdown occurs when insert-file-contents is
>> called in find-file-noselect-1.  I don't know how to debug it further.
>> This slowdown did not exist in my previous Emacs build from 2007-06-30.
>
> Stefan found a bug in my recent changes to `insert-file-contents'.
> I can't tell whether it's related to your problem but could you try
> with the attached patch?

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.)

Steve Berman

Re: 22.1.50; insert-file-contents is slow under tramp

[martin rudalics]

> 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.

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.

Re: 22.1.50; insert-file-contents is slow under tramp

[Stefan Monnier]

>> 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.

> 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.

I think this has nothing to do with it: Tramp implements insert-file-contents
in Elisp.


        Stefan

Re: 22.1.50; insert-file-contents is slow under tramp

[martin rudalics]

> 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.

Re: 22.1.50; insert-file-contents is slow under tramp

[Stephen Berman]

On Thu, 23 Aug 2007 19:49:39 +0200 martin rudalics <rudalics@gmx.at> 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 <rudalics@gmx.at> 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=<value optimized out>) 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=<value optimized out>) 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=<value optimized out>) 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=<value optimized out>) 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=<value optimized out>) 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=<value optimized out>) 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=<value optimized out>) at bytecode.c:679
#28 0x0815e4fa in funcall_lambda (fun=136192036, nargs=1, arg_vector=0xbfd5d154)
---Type <return> to continue, or q <return> 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=<value optimized out>) 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 <command_loop_1>,
    handlers=137538137, hfun=0x8100e20 <cmd_error>) at eval.c:1488
#38 0x08100263 in command_loop_2 () at keyboard.c:1329
#39 0x0815d54a in internal_catch (tag=137531321, func=0x8100240 <command_loop_2>,
    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

Re: 22.1.50; insert-file-contents is slow under tramp

[martin rudalics]

> 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,

Did you edebug `tramp-handle-insert-file-contents'?

Re: 22.1.50; insert-file-contents is slow under tramp

[Stephen Berman]

On Thu, 23 Aug 2007 23:01:43 +0200 martin rudalics <rudalics@gmx.at> wrote:

>> 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,
>
> Did you edebug `tramp-handle-insert-file-contents'?

Yes, and the slowdown occurs on evalling (file-local-copy filename).
In file-local-copy the slowdown occurs at (funcall handler
'file-local-copy file), and the value of `handler' is
tramp-file-name-handler and that's where I got stuck.  Edebug iterates
over it hundreds, maybe thousands of times.  If I just hold down `f'
on this function eventually the slowdown occurs, but I cannot see
where within it.  If I tried stepping through it, I'd probably be at
it all night.  So I hope there's a better way.

Steve Berman

Re: 22.1.50; insert-file-contents is slow under tramp

[Michael Albinus]

Stephen Berman <Stephen.Berman@gmx.net> writes:

> So I hope there's a better way.

Yes. I've installed a patch in the trunk, which makes a fast track for
"remote" files being on localhost.

For real remote hosts, I recommend to use scp when accessing huge files.

> Steve Berman

Best regards, Michael.

Re: 22.1.50; insert-file-contents is slow under tramp

[Stephen Berman]

On Fri, 24 Aug 2007 07:34:18 +0200 Michael Albinus <michael.albinus@gmx.de> wrote:

> Stephen Berman <Stephen.Berman@gmx.net> writes:
>
>> So I hope there's a better way.
>
> Yes. I've installed a patch in the trunk, which makes a fast track for
> "remote" files being on localhost.

I confirm that fixes the problem; many thanks!

> For real remote hosts, I recommend to use scp when accessing huge files.

Thanks for the tip.

Steve Berman

Re: 22.1.50; insert-file-contents is slow under tramp

[Stefan Monnier]

>> So I hope there's a better way.
> Yes. I've installed a patch in the trunk, which makes a fast track for
> "remote" files being on localhost.

How does that work?  I mean when accessing files on the localhost with
Tramp, the most likely situation I can think of is the `su' method so how
what does your "fast track" do to transfer the file faster?  Does it copy it
to /tmp at the "remote" end, then make it world-readable, then copy it on
the "local" end, then remove it at the remote end?

> For real remote hosts, I recommend to use scp when accessing huge files.

Reminds me: where is the bottleneck in the inline method?  I mean
fundamentally doing a base64 encoding/decoding shouldn't cost that much
(negligible CPU-wise and a mere 33% in network transfer).  Maybe we could
attack this part to improve performance?


        Stefan

Re: 22.1.50; insert-file-contents is slow under tramp

[Michael Albinus]

Stefan Monnier <monnier@iro.umontreal.ca> writes:

>> Yes. I've installed a patch in the trunk, which makes a fast track for
>> "remote" files being on localhost.
>
> How does that work?  I mean when accessing files on the localhost with
> Tramp, the most likely situation I can think of is the `su' method so how
> what does your "fast track" do to transfer the file faster?  Does it copy it
> to /tmp at the "remote" end, then make it world-readable, then copy it on
> the "local" end, then remove it at the remote end?

Similar approach. It calls `tramp-do-copy-or-rename-file-directly',
which copies the "remote" file to /tmp, and assigns proper
permissions. Then `insert-file-contents' for the _local_ temporary file
is applied, which shows the file in the buffer, and the temporary file
is deleted.

>> For real remote hosts, I recommend to use scp when accessing huge files.
>
> Reminds me: where is the bottleneck in the inline method?  I mean
> fundamentally doing a base64 encoding/decoding shouldn't cost that much
> (negligible CPU-wise and a mere 33% in network transfer).  Maybe we could
> attack this part to improve performance?

I haven't investigated too much. mimencode and base64-decode are pretty
fast, even on my stone-age machine, with an 8MB sized file:

| (with-current-buffer (get-buffer-create "foo")
|   (elp-instrument-function 'call-process)
|   (elp-instrument-function 'base64-decode-region)
|   (erase-buffer)
|
|   (call-process "mimencode" nil t nil "/var/cache/apt/pkgcache.bin")
|   (base64-decode-region (point-min) (point-max))
|   (elp-results))
|
| Function Name         Call Count  Elapsed Time  Average Time
| ====================  ==========  ============  ============
| base64-decode-region  1           7.732203      7.732203
| call-process          1           1.917887      1.917887

But with the installed "fast track", it is remarkable faster than even
these two basic functions:

| (with-current-buffer (get-buffer-create "foo")
|   (elp-instrument-function 'insert-file-contents)
|   (erase-buffer)
|   (setq tramp-verbose 0)
|
|   ;; This opens the connection, including password handover etc
|   (file-attributes "/sudo::")
|
|   (insert-file-contents "/sudo::/var/cache/apt/pkgcache.bin")
|   (elp-results))
|
| Function Name         Call Count  Elapsed Time  Average Time
| ====================  ==========  ============  ============
| insert-file-contents  2           1.64688       0.82344

Without the fast track, the access time is inacceptable large. I suspect
that `tramp-wait-for-output' is the bottleneck, because it must check
for the resulting shell prompt, handle echoing shells, etc. I will
investigate next days whether there can be an improvement.

>         Stefan

Best regards, Michael.

Re: 22.1.50; insert-file-contents is slow under tramp

[David Kastrup]

Michael Albinus <michael.albinus@gmx.de> writes:

> Stefan Monnier <monnier@iro.umontreal.ca> writes:
>
>>> Yes. I've installed a patch in the trunk, which makes a fast track for
>>> "remote" files being on localhost.
>>
>> How does that work?  I mean when accessing files on the localhost with
>> Tramp, the most likely situation I can think of is the `su' method so how
>> what does your "fast track" do to transfer the file faster?  Does it copy it
>> to /tmp at the "remote" end, then make it world-readable, then copy it on
>> the "local" end, then remove it at the remote end?
>
> Similar approach. It calls `tramp-do-copy-or-rename-file-directly',
> which copies the "remote" file to /tmp, and assigns proper
> permissions.  Then `insert-file-contents' for the _local_ temporary
> file is applied, which shows the file in the buffer, and the
> temporary file is deleted.

For the su and sudo functions, in many (but not all) cases the file is
actually world-readable (things like /etc/fstab or /etc/passwd).
Making use of that would probably be by far the fastest way for
getting the file.

Do you do this already?

-- 
David Kastrup, Kriemhildstr. 15, 44793 Bochum

Re: 22.1.50; insert-file-contents is slow under tramp

[Michael Albinus]

David Kastrup <dak@gnu.org> writes:

> For the su and sudo functions, in many (but not all) cases the file is
> actually world-readable (things like /etc/fstab or /etc/passwd).
> Making use of that would probably be by far the fastest way for
> getting the file.
>
> Do you do this already?

Not yet. I'll check.

Best regards, Michael.

Re: 22.1.50; insert-file-contents is slow under tramp

[Stefan Monnier]

>>> Yes. I've installed a patch in the trunk, which makes a fast track for
>>> "remote" files being on localhost.
>> 
>> How does that work?  I mean when accessing files on the localhost with
>> Tramp, the most likely situation I can think of is the `su' method so how
>> what does your "fast track" do to transfer the file faster?  Does it copy it
>> to /tmp at the "remote" end, then make it world-readable, then copy it on
>> the "local" end, then remove it at the remote end?

> Similar approach. It calls `tramp-do-copy-or-rename-file-directly',
> which copies the "remote" file to /tmp, and assigns proper
> permissions.

What would be proper permissions?  I mean: how do you make sure that some
nasty third party won't be able to read the content of that temp file, while
still making it possible for Emacs to access the file?

> I haven't investigated too much. mimencode and base64-decode are pretty
> fast, even on my stone-age machine, with an 8MB sized file:

> | (with-current-buffer (get-buffer-create "foo")
> |   (elp-instrument-function 'call-process)
> |   (elp-instrument-function 'base64-decode-region)
> |   (erase-buffer)
> |
> |   (call-process "mimencode" nil t nil "/var/cache/apt/pkgcache.bin")
> |   (base64-decode-region (point-min) (point-max))
> |   (elp-results))
> |
> | Function Name         Call Count  Elapsed Time  Average Time
> | ====================  ==========  ============  ============
> | base64-decode-region  1           7.732203      7.732203
> | call-process          1           1.917887      1.917887

> But with the installed "fast track", it is remarkable faster than even
> these two basic functions:

1MB/s for base64 sounds terribly slow.  My 266MHz home-router can send
and encrypt data from disk to the network at about that speed.
But admittedly, we're not talking `mimencode' but base64-decode-region which
may include a lot of overhead to extract and insert data from/to the buffer.


        Stefan

Re: 22.1.50; insert-file-contents is slow under tramp

[Michael Albinus]

Stefan Monnier <monnier@iro.umontreal.ca> writes:

>> Similar approach. It calls `tramp-do-copy-or-rename-file-directly',
>> which copies the "remote" file to /tmp, and assigns proper
>> permissions.
>
> What would be proper permissions?  I mean: how do you make sure that some
> nasty third party won't be able to read the content of that temp file, while
> still making it possible for Emacs to access the file?

The current approach(1) is to remove any temporary file immediately after
it has been processes by Emacs (for example, insert-file-contents is
finished). This reduces the time nasty third party can see such a
file.

But I admit, this might not be sufficient wrt security threats. Maybe
one could change it such a way, that temporary files shall be owned by
(user-login-name), and shall carry 0400 permissions.

(1): That's the theory. In practice, there are still some zero-length
temporary files left, for which I haven't debugged yet who is
responsible to remove them. On my todo list.

> 1MB/s for base64 sounds terribly slow.  My 266MHz home-router can send
> and encrypt data from disk to the network at about that speed.
> But admittedly, we're not talking `mimencode' but base64-decode-region which
> may include a lot of overhead to extract and insert data from/to the buffer.

Don't take the absolute values, I just wanted to show the
comparison. Tests were run on my stone-age 700MHz PIII machine.

>         Stefan

Best regards, Michael.

Re: 22.1.50; insert-file-contents is slow under tramp

[Stefan Monnier]

> The current approach(1) is to remove any temporary file immediately after
> it has been processes by Emacs (for example, insert-file-contents is
> finished).  This reduces the time nasty third party can see such a file.

If the file is readable, that's a major security concern.

> But I admit, this might not be sufficient wrt security threats.  Maybe
> one could change it such a way, that temporary files shall be owned by
> (user-login-name), and shall carry 0400 permissions.

How can you do that?  Let's say I access a file of user BAR from user FOO,
how would you go about doing it in such a way that user TOTO can never see
the content of the file?  BAR can't use `chown' (unless it's root).

> (1): That's the theory. In practice, there are still some zero-length
> temporary files left, for which I haven't debugged yet who is
> responsible to remove them. On my todo list.

Oh, I've sen those.  Yes, they need fixing as well, but it's minor: this is
not a security concern.


        Stefan

Re: 22.1.50; insert-file-contents is slow under tramp

[Thien-Thi Nguyen]

() Stefan Monnier <monnier@iro.umontreal.ca>
() Mon, 27 Aug 2007 09:58:32 -0400

   How can you do that?  Let's say I access a file of user
   BAR from user FOO, how would you go about doing it in
   such a way that user TOTO can never see the content of
   the file?  BAR can't use `chown' (unless it's root).

can we use tmpfile(3)?

thi

Re: 22.1.50; insert-file-contents is slow under tramp

[David Kastrup]

Stefan Monnier <monnier@iro.umontreal.ca> writes:

>> The current approach(1) is to remove any temporary file immediately after
>> it has been processes by Emacs (for example, insert-file-contents is
>> finished).  This reduces the time nasty third party can see such a file.
>
> If the file is readable, that's a major security concern.
>
>> But I admit, this might not be sufficient wrt security threats.  Maybe
>> one could change it such a way, that temporary files shall be owned by
>> (user-login-name), and shall carry 0400 permissions.
>
> How can you do that?  Let's say I access a file of user BAR from
> user FOO, how would you go about doing it in such a way that user
> TOTO can never see the content of the file?  BAR can't use `chown'
> (unless it's root).

Huh?  We are talking about tramp here.  The file is transferred
through a ssh session.  On the receiving side, you'll be free to
create a file with whatever permissions you want, and on the sending
side, no change of permissions is required to access the file.

-- 
David Kastrup

Re: 22.1.50; insert-file-contents is slow under tramp

[Michael Albinus]

Stefan Monnier <monnier@iro.umontreal.ca> writes:

> How can you do that?  Let's say I access a file of user BAR from user FOO,
> how would you go about doing it in such a way that user TOTO can never see
> the content of the file?  BAR can't use `chown' (unless it's root).

BAR must give away the ownership of the temporary file to FOO. See
this test (BAR is albinus, FOO is hostmann). Any TOTO cannot see the
contents of the file, despite she is root - in this case we can forget
security at all.

# whoami
albinus
# touch stefan
# chmod 0400 stefan
# ll stefan
-r--------   1 albinus  smc3            0 Aug 27 16:36 stefan
# chown hostmann stefan 
# ll stefan
-r--------   1 hostmann smc3            0 Aug 27 16:36 stefan
# cat stefan
cat: stefan: Permission denied

Note that we are speaking about temporary files. Either FOO or BAR is
always me (locally), for the other user I have a Tramp connection
capable to send UNIX commands. I can send commands under both user
permissions in the order I do need. It's a kind of puzzling who must
give ownership to whom (it depends on the copying direction), but it's
a finite number of cases only.

>         Stefan

Best regards, Michael.

Re: 22.1.50; insert-file-contents is slow under tramp

[Stefan Monnier]

> # whoami
> albinus
> # touch stefan
> # chmod 0400 stefan
> # ll stefan
> -r--------   1 albinus  smc3            0 Aug 27 16:36 stefan
> # chown hostmann stefan 
> # ll stefan
> -r--------   1 hostmann smc3            0 Aug 27 16:36 stefan
> # cat stefan
> cat: stefan: Permission denied

Can you tell me which systems allow you to do that?  I know that under *BSD
there were ways to do that, allowed or not depending on some global setting
because such user-transfer of file ownership can be a security hole in
itself.  Basically only `root' can use `chown' on modern POSIX
systems, AFAIK.


        Stefan

Re: 22.1.50; insert-file-contents is slow under tramp

[Michael Albinus]

Stefan Monnier <monnier@IRO.UMontreal.CA> writes:

> Can you tell me which systems allow you to do that?  I know that under *BSD
> there were ways to do that, allowed or not depending on some global setting
> because such user-transfer of file ownership can be a security hole in
> itself.  Basically only `root' can use `chown' on modern POSIX
> systems, AFAIK.

You're right, I've tested under HP-UX 11.11. Here @home, with Ubuntu, it
is not permitted (although the chown man page doesn't mention this
restriction).

Hmm, my proposal would work only when the source file belongs to root,
accessed by Tramp. This is the most important case, though.

Other temporary files, coming from the local host or a remote host,
might be readable for third parties. One could try that all temporary
files are only readable for the local user (who needs to access these
files for insert-file-contents etc), but this must be checked. Copying
without the "-p" option, or so. I will sleep about.

Another idea would be a special temp directory as user option, where the
user is forced to apply 700 permissions for this directory.

>         Stefan

Best regards, Michael.

Re: 22.1.50; insert-file-contents is slow under tramp

[Michael Albinus]

Stefan Monnier <monnier@iro.umontreal.ca> writes:

> Reminds me: where is the bottleneck in the inline method?  I mean
> fundamentally doing a base64 encoding/decoding shouldn't cost that much
> (negligible CPU-wise and a mere 33% in network transfer).  Maybe we could
> attack this part to improve performance?

The major bottleneck is `accept-process-output', which returns only
small chunks when called again and again. With a `sleep-for' between
two calls, I have improved the performance (but not dramatically).

However, this approach would require to manage when it is desired to
apply `sleep-for', and when not. Most of the commands, Tramp sends to
the remote host, return just one or two lines of output.

I guess it isn't worth the trouble. For local hosts, I have
implemented the fast track (satisfying su and sudo); in all other
cases accessing huge files, scp (or pscp) shall be sufficient.

>         Stefan

Best regards, Michael.

Re: 22.1.50; insert-file-contents is slow under tramp

[David Kastrup]

Michael Albinus <michael.albinus@gmx.de> writes:

> Stefan Monnier <monnier@iro.umontreal.ca> writes:
>
>> Reminds me: where is the bottleneck in the inline method?  I mean
>> fundamentally doing a base64 encoding/decoding shouldn't cost that
>> much (negligible CPU-wise and a mere 33% in network transfer).
>> Maybe we could attack this part to improve performance?
>
> The major bottleneck is `accept-process-output', which returns only
> small chunks when called again and again. With a `sleep-for' between
> two calls, I have improved the performance (but not dramatically).

Same old scheduler problem that prompted both of

w32-pipe-read-delay
process-adaptive-read-buffering

Maybe you should try setting process-adaptive-read-buffering to a
non-nil non-t value?

-- 
David Kastrup

Re: 22.1.50; insert-file-contents is slow under tramp

[Richard Stallman]

    > The major bottleneck is `accept-process-output', which returns only
    > small chunks when called again and again. With a `sleep-for' between
    > two calls, I have improved the performance (but not dramatically).

    Same old scheduler problem that prompted both of

    w32-pipe-read-delay
    process-adaptive-read-buffering

    Maybe you should try setting process-adaptive-read-buffering to a
    non-nil non-t value?

Should the defaults for any of these be changed?

Re: 22.1.50; insert-file-contents is slow under tramp

[David Kastrup]

Richard Stallman <rms@gnu.org> writes:

>     > The major bottleneck is `accept-process-output', which returns only
>     > small chunks when called again and again. With a `sleep-for' between
>     > two calls, I have improved the performance (but not dramatically).
>
>     Same old scheduler problem that prompted both of
>
>     w32-pipe-read-delay
>     process-adaptive-read-buffering
>
>     Maybe you should try setting process-adaptive-read-buffering to a
>     non-nil non-t value?
>
> Should the defaults for any of these be changed?

It is hard to say: basically, they work around deficiencies in the CPU
schedulers of the respective operating systems.

Linux is supposed to get CFS, "completely fair scheduling" in its next
released version, something like 2.6.23.  This should quite help with
the original problem.  Not because of fairness, but because of being
different: pretty much _any_ scheduler should behave better here than
the previous "context switch whenever possible" scheduling strategy.

I was actually surprised to see w32-pipe-read-delay crop up in my
apropos-documentation search.  From the description, it sounds like it
addresses a similar problem, so perhaps it might have been made
redundant by process-adaptive-read-buffering _if_ the latter does its
job reasonably well under Windows.

-- 
David Kastrup, Kriemhildstr. 15, 44793 Bochum

Re: 22.1.50; insert-file-contents is slow under tramp

[Eli Zaretskii]

> From: Stephen Berman <Stephen.Berman@gmx.net>
> Date: Thu, 23 Aug 2007 23:40:22 +0200
> Cc: emacs-devel@gnu.org
> 
> > Did you edebug `tramp-handle-insert-file-contents'?
> 
> Yes, and the slowdown occurs on evalling (file-local-copy filename).
> In file-local-copy the slowdown occurs at (funcall handler
> 'file-local-copy file), and the value of `handler' is
> tramp-file-name-handler and that's where I got stuck.  Edebug iterates
> over it hundreds, maybe thousands of times.  If I just hold down `f'
> on this function eventually the slowdown occurs, but I cannot see
> where within it.  If I tried stepping through it, I'd probably be at
> it all night.  So I hope there's a better way.

For the future: there _is_ a better way: use the elp.el package to
profile the command, and you should be able to see which function
consumes the most of the time.

Re: 22.1.50; insert-file-contents is slow under tramp

[Stephen Berman]

On Fri, 24 Aug 2007 12:28:24 +0300 Eli Zaretskii <eliz@gnu.org> wrote:

>> From: Stephen Berman <Stephen.Berman@gmx.net>
>> Date: Thu, 23 Aug 2007 23:40:22 +0200
>> Cc: emacs-devel@gnu.org
>> 
>> > Did you edebug `tramp-handle-insert-file-contents'?
>> 
>> Yes, and the slowdown occurs on evalling (file-local-copy filename).
>> In file-local-copy the slowdown occurs at (funcall handler
>> 'file-local-copy file), and the value of `handler' is
>> tramp-file-name-handler and that's where I got stuck.  Edebug iterates
>> over it hundreds, maybe thousands of times.  If I just hold down `f'
>> on this function eventually the slowdown occurs, but I cannot see
>> where within it.  If I tried stepping through it, I'd probably be at
>> it all night.  So I hope there's a better way.
>
> For the future: there _is_ a better way: use the elp.el package to
> profile the command, and you should be able to see which function
> consumes the most of the time.

Thanks for the tip!

Steve Berman

Re: 22.1.50; insert-file-contents is slow under tramp

[Richard Stallman]

      If I just hold down `f'
    on this function eventually the slowdown occurs, but I cannot see
    where within it.  If I tried stepping through it, I'd probably be at
    it all night.

How about typing C-z during the slow part?  Then make a backtrace
and you'll see what it's doing.  If you try that a few times
you should see a pattern.