unofficial mirror of bug-gnu-emacs@gnu.org 
 help / color / mirror / code / Atom feed
* bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks
@ 2022-07-01 17:14 Paul Pogonyshev
  2022-07-02 15:58 ` Michael Albinus
  0 siblings, 1 reply; 18+ messages in thread
From: Paul Pogonyshev @ 2022-07-01 17:14 UTC (permalink / raw)
  To: 56342

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

Emacs version: GNU Emacs 28.1.50 (build 1, x86_64-pc-linux-gnu, GTK+
Version 2.24.33, cairo version 1.16.0) of 2022-05-24

I have an internet connection with a relatively large ping, so TRAMP for me
works quite slowly. I notice this when editing and saving files (also when
Emacs stores backup copies), with Magit and otherwise.

I tried to understand why it is _so_ slow for me. I have found out variable
`tramp-verbose' and used it to figure out which commands TRAMP executes on
the remote machine. For testing, I used a real library's (Logview's) buffer
refreshing command  that boils down to this:

    (with-temp-buffer
      (insert-file-contents the-file nil from-somewhere-in-the-middle nil)
      ; do something about the data
      )

In other words, it inserts into a buffer not the whole file, but a part of
it (the reason is irrelevant here).

Well, this results in _eleven_ commands from TRAMP! Here they are:

1) check if connection is alive (`echo are you awake');
2) test if the file exists;
3) creating a temporary file for the chunk to be inserted; I guess it tries
until it finds an unused filename, e.g. here it seems to be done after
`test -e /tmp/tramp.OD3cCu', which doesn't exist;
4) 'touch' on the temporary file, presumably to create it;
5) 'chmod' on the temporary, presumably so that other users cannot read it;
6) copying the requested chunk from the full file into the temporary (using
`dd');
7) finding the real name of the temporary with `readlink';
8) finding attributes of the temporary with `stat';
9) gzipping the temporary for transmition from the remote to the local
machine;
10) testing if the temporary is a directory (WTF?);
11) removing the temporary.

I guess it should be obvious that this is a bit too much for one
`insert-file-contents' call.

Suggested improvements:

* TRAMP should issue just one `stat' command to find out most of the things
about a file: whether it exists, if it is a directory, its real name when
dereferencing links and whatever stats it is used to find now; from `$ stat
--help' this seems to be possible. In other words, TRAMP shouldn't use
simple commands like `test -e': any ping, even nominal, will negate any
gains from using a tad faster command. Instead, if it needs to find
anything about a file, it should ask the remote about as many things as
possible in one go: it is very likely that the additional information will
be needed soon and even if not, this is basically free compared to ping
anyway.

* TRAMP code should prefer the approach "try do something and handle
resulting errors" where possible. For example, don't check if the file
exists, try to read it right away and handle failures properly. Code like
`(when (file-exists-p ...) do-something)' adds an unnecessary command call
and creates a racing condition anyway. Also, error-free requests should be
more frequent, so they should be the main optimization goal. I'm not sure
if it is applicable to TRAMP itself and doesn't come from a higher level,
though.

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

^ permalink raw reply	[flat|nested] 18+ messages in thread

* bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks
  2022-07-01 17:14 bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks Paul Pogonyshev
@ 2022-07-02 15:58 ` Michael Albinus
  2022-07-02 18:14   ` Paul Pogonyshev
  2022-07-04 10:33   ` Michael Albinus
  0 siblings, 2 replies; 18+ messages in thread
From: Michael Albinus @ 2022-07-02 15:58 UTC (permalink / raw)
  To: Paul Pogonyshev; +Cc: 56342

Paul Pogonyshev <pogonyshev@gmail.com> writes:

Hi Paul,

> 1) check if connection is alive (`echo are you awake');
> 2) test if the file exists;
> 3) creating a temporary file for the chunk to be inserted; I guess it
> tries until it finds an unused filename, e.g. here it seems to be done
> after `test -e /tmp/tramp.OD3cCu', which doesn't exist;
> 4) 'touch' on the temporary file, presumably to create it;
> 5) 'chmod' on the temporary, presumably so that other users cannot
> read it;
> 6) copying the requested chunk from the full file into the temporary
> (using `dd');
> 7) finding the real name of the temporary with `readlink';
> 8) finding attributes of the temporary with `stat';
> 9) gzipping the temporary for transmition from the remote to the local
> machine;
> 10) testing if the temporary is a directory (WTF?);
> 11) removing the temporary.
>
> I guess it should be obvious that this is a bit too much for one
> `insert-file-contents' call.

In general, I agree. However, some of the commands are caused by
primitive file operations, like file-exists-p. Tramp cannot know what
will be the next call, and it doesn't have all the opportunities to
optimize, compared with the overall picture you see in the eleven steps.

> Suggested improvements:
>
> * TRAMP should issue just one `stat' command to find out most of the
> things about a file: whether it exists, if it is a directory, its real
> name when dereferencing links and whatever stats it is used to find
> now; from `$ stat --help' this seems to be possible. In other words,
> TRAMP shouldn't use simple commands like `test -e': any ping, even
> nominal, will negate any gains from using a tad faster command.
> Instead, if it needs to find anything about a file, it should ask the
> remote about as many things as possible in one go: it is very likely
> that the additional information will be needed soon and even if not,
> this is basically free compared to ping anyway.

Not all remote hosts carry a stat command, and not all existing stat's
are GNU compatible. But yes, if possible, Tramp shall gather as much
information in one run, and cache the results for further use.

I will see what could be done. Will come back with a proposal next days
(note that this will be for Emacs 29, ie git master).

> * TRAMP code should prefer the approach "try do something and handle
> resulting errors" where possible. For example, don't check if the file
> exists, try to read it right away and handle failures properly. Code
> like `(when (file-exists-p ...) do-something)' adds an unnecessary
> command call and creates a racing condition anyway. Also, error-free
> requests should be more frequent, so they should be the main
> optimization goal. I'm not sure if it is applicable to TRAMP itself
> and doesn't come from a higher level, though.

Indeed, this is not Tramp's responsibility. Tramp is a stupid
library. If there is a call for file-exists-p, it must return the
answer. It doesn't know what will be the next request. So I'm rather
pesimistic that Tramp can improve here.

Best regards, Michael.





^ permalink raw reply	[flat|nested] 18+ messages in thread

* bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks
  2022-07-02 15:58 ` Michael Albinus
@ 2022-07-02 18:14   ` Paul Pogonyshev
  2022-07-03 12:16     ` Michael Albinus
  2022-07-04 10:33   ` Michael Albinus
  1 sibling, 1 reply; 18+ messages in thread
From: Paul Pogonyshev @ 2022-07-02 18:14 UTC (permalink / raw)
  To: Michael Albinus; +Cc: 56342

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

Some more thoughts. Why does it even need `echo are you awake'? It's a
network connection, it can still fail even if it worked fine 1 ms before
when you checked. So, why not just let the first command fail if the
connection is dead and restart the connection if it fails in such a way as
to suspect that it is dead (i.e. no output)? Maybe limit this to read
commands.

A way to let higher-level code avoid certain `file-exists-p' calls: add a
dynamic variable that tells TRAMP to skip certain commands if the result is
not available from a cache. Something similar to
`process-file-side-effects'. Calling code could then do sth. like this:

    (when (let ((tramp-may-skip-if-not-cached `((file-exists-p unknown
,file))))
            (file-exists-p file))  ; TRAMP will return t or nil if it knows
or 'unknown if not cached; for local files there is no effect
      ...)

Suggested semantics: list of (FUNCTION INSTANT-RESULT-IF-NOT-CACHED
ARGUMENT...). Any element of the list with unknown function name etc. would
be simply ignored.

Code that doesn't let-bind this variable will behave as before. Code that
cares can be optimized.

Paul

On Sat, 2 Jul 2022 at 17:58, Michael Albinus <michael.albinus@gmx.de> wrote:

> Paul Pogonyshev <pogonyshev@gmail.com> writes:
>
> Hi Paul,
>
> > 1) check if connection is alive (`echo are you awake');
> > 2) test if the file exists;
> > 3) creating a temporary file for the chunk to be inserted; I guess it
> > tries until it finds an unused filename, e.g. here it seems to be done
> > after `test -e /tmp/tramp.OD3cCu', which doesn't exist;
> > 4) 'touch' on the temporary file, presumably to create it;
> > 5) 'chmod' on the temporary, presumably so that other users cannot
> > read it;
> > 6) copying the requested chunk from the full file into the temporary
> > (using `dd');
> > 7) finding the real name of the temporary with `readlink';
> > 8) finding attributes of the temporary with `stat';
> > 9) gzipping the temporary for transmition from the remote to the local
> > machine;
> > 10) testing if the temporary is a directory (WTF?);
> > 11) removing the temporary.
> >
> > I guess it should be obvious that this is a bit too much for one
> > `insert-file-contents' call.
>
> In general, I agree. However, some of the commands are caused by
> primitive file operations, like file-exists-p. Tramp cannot know what
> will be the next call, and it doesn't have all the opportunities to
> optimize, compared with the overall picture you see in the eleven steps.
>
> > Suggested improvements:
> >
> > * TRAMP should issue just one `stat' command to find out most of the
> > things about a file: whether it exists, if it is a directory, its real
> > name when dereferencing links and whatever stats it is used to find
> > now; from `$ stat --help' this seems to be possible. In other words,
> > TRAMP shouldn't use simple commands like `test -e': any ping, even
> > nominal, will negate any gains from using a tad faster command.
> > Instead, if it needs to find anything about a file, it should ask the
> > remote about as many things as possible in one go: it is very likely
> > that the additional information will be needed soon and even if not,
> > this is basically free compared to ping anyway.
>
> Not all remote hosts carry a stat command, and not all existing stat's
> are GNU compatible. But yes, if possible, Tramp shall gather as much
> information in one run, and cache the results for further use.
>
> I will see what could be done. Will come back with a proposal next days
> (note that this will be for Emacs 29, ie git master).
>
> > * TRAMP code should prefer the approach "try do something and handle
> > resulting errors" where possible. For example, don't check if the file
> > exists, try to read it right away and handle failures properly. Code
> > like `(when (file-exists-p ...) do-something)' adds an unnecessary
> > command call and creates a racing condition anyway. Also, error-free
> > requests should be more frequent, so they should be the main
> > optimization goal. I'm not sure if it is applicable to TRAMP itself
> > and doesn't come from a higher level, though.
>
> Indeed, this is not Tramp's responsibility. Tramp is a stupid
> library. If there is a call for file-exists-p, it must return the
> answer. It doesn't know what will be the next request. So I'm rather
> pesimistic that Tramp can improve here.
>
> Best regards, Michael.
>

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

^ permalink raw reply	[flat|nested] 18+ messages in thread

* bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks
  2022-07-02 18:14   ` Paul Pogonyshev
@ 2022-07-03 12:16     ` Michael Albinus
  2022-07-03 14:00       ` Paul Pogonyshev
  0 siblings, 1 reply; 18+ messages in thread
From: Michael Albinus @ 2022-07-03 12:16 UTC (permalink / raw)
  To: Paul Pogonyshev; +Cc: 56342

Paul Pogonyshev <pogonyshev@gmail.com> writes:

Hi Paul,

> Some more thoughts. Why does it even need `echo are you awake'? It's a
> network connection, it can still fail even if it worked fine 1 ms
> before when you checked. So, why not just let the first command fail
> if the connection is dead and restart the connection if it fails in
> such a way as to suspect that it is dead (i.e. no output)? Maybe limit
> this to read commands.

This is a sanity check. It avoids to hang in a blocked connection,
because this special command is surrounded by a timeout of 10 sec. Other
commands w/o this protection could hang forever. See also the comment in
tramp-maybe-open-connection.

> A way to let higher-level code avoid certain `file-exists-p' calls:
> add a dynamic variable that tells TRAMP to skip certain commands if
> the result is not available from a cache. Something similar to
> `process-file-side-effects'. Calling code could then do sth. like
> this:
>
>     (when (let ((tramp-may-skip-if-not-cached `((file-exists-p unknown
> ,file))))
>             (file-exists-p file))  ; TRAMP will return t or nil if it
> knows or 'unknown if not cached; for local files there is no effect
>       ...)
>
> Suggested semantics: list of (FUNCTION INSTANT-RESULT-IF-NOT-CACHED
> ARGUMENT...). Any element of the list with unknown function name etc.
> would be simply ignored.
>
> Code that doesn't let-bind this variable will behave as before. Code
> that cares can be optimized.

If a caller can live w/o a valid result of file-exists-p, it shouldn't
call it. Everything else is too sophisticated and good for trouble, I believe.

In general, packages shall not care what's the implementation of a given
function like file-exists-p. If they care, they could still use
file-remote-p in order to distinguish.

> Paul

Best regards, Michael.





^ permalink raw reply	[flat|nested] 18+ messages in thread

* bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks
  2022-07-03 12:16     ` Michael Albinus
@ 2022-07-03 14:00       ` Paul Pogonyshev
  2022-07-03 18:47         ` Michael Albinus
  0 siblings, 1 reply; 18+ messages in thread
From: Paul Pogonyshev @ 2022-07-03 14:00 UTC (permalink / raw)
  To: Michael Albinus; +Cc: 56342

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

> This is a sanity check. It avoids to hang in a blocked connection,
> because this special command is surrounded by a timeout of 10 sec. Other
> commands w/o this protection could hang forever. See also the comment in
> tramp-maybe-open-connection.

Maybe you could then single out commands that are supposed to return result
nearly-instantly anyway, e.g. `stat' or `test' (though the latter I have
suggested to replace with `stat' before). If they fail to produce the
result in 10 seconds, the connection can be assumed dead, just as with
`echo are you awake'. Commands that involve transmitting (potentially)
large amount of data this or that way can work as now. So, you would
usually avoid one extra command (which with a high ping means sth. like 0.2
s, already pretty noticeable in UI) and achieve the same result.

Sanity checks are good. but not if they visibly slow down normal operation.

> If a caller can live w/o a valid result of file-exists-p, it shouldn't
> call it. Everything else is too sophisticated and good for trouble, I
believe.

It might be easier to convince the rest of Emacs developers to use an extra
variable to possibly skip `file-exists-p' on only remote files than to
remove the call altogether. Though in either case it is required that
`file-missing' error is handled properly which is, incidentally, easier to
test if the call to `file-exists-p' is dropped. A target here would be
`insert-file-contents' and whatever it calls, and this is a part of Emacs,
not some external library.

Yet another idea: removing temporary should be done asynchronously (I
haven't checked, maybe it's already the case, but likely not). The caller
doesn't really care about call result and even if it has succeeded. Again,
not sure if this is easy to achieve interface-wise, maybe it's from a
higher level. But I suspect it's something like `with-temp-file' and can be
optimized: one-time optimization are worth it even if that costs
readability.

Paul


On Sun, 3 Jul 2022 at 14:16, Michael Albinus <michael.albinus@gmx.de> wrote:

> Paul Pogonyshev <pogonyshev@gmail.com> writes:
>
> Hi Paul,
>
> > Some more thoughts. Why does it even need `echo are you awake'? It's a
> > network connection, it can still fail even if it worked fine 1 ms
> > before when you checked. So, why not just let the first command fail
> > if the connection is dead and restart the connection if it fails in
> > such a way as to suspect that it is dead (i.e. no output)? Maybe limit
> > this to read commands.
>
> This is a sanity check. It avoids to hang in a blocked connection,
> because this special command is surrounded by a timeout of 10 sec. Other
> commands w/o this protection could hang forever. See also the comment in
> tramp-maybe-open-connection.
>
> > A way to let higher-level code avoid certain `file-exists-p' calls:
> > add a dynamic variable that tells TRAMP to skip certain commands if
> > the result is not available from a cache. Something similar to
> > `process-file-side-effects'. Calling code could then do sth. like
> > this:
> >
> >     (when (let ((tramp-may-skip-if-not-cached `((file-exists-p unknown
> > ,file))))
> >             (file-exists-p file))  ; TRAMP will return t or nil if it
> > knows or 'unknown if not cached; for local files there is no effect
> >       ...)
> >
> > Suggested semantics: list of (FUNCTION INSTANT-RESULT-IF-NOT-CACHED
> > ARGUMENT...). Any element of the list with unknown function name etc.
> > would be simply ignored.
> >
> > Code that doesn't let-bind this variable will behave as before. Code
> > that cares can be optimized.
>
> If a caller can live w/o a valid result of file-exists-p, it shouldn't
> call it. Everything else is too sophisticated and good for trouble, I
> believe.
>
> In general, packages shall not care what's the implementation of a given
> function like file-exists-p. If they care, they could still use
> file-remote-p in order to distinguish.
>
> > Paul
>
> Best regards, Michael.
>

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

^ permalink raw reply	[flat|nested] 18+ messages in thread

* bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks
  2022-07-03 14:00       ` Paul Pogonyshev
@ 2022-07-03 18:47         ` Michael Albinus
  2022-07-03 19:52           ` Paul Pogonyshev
  0 siblings, 1 reply; 18+ messages in thread
From: Michael Albinus @ 2022-07-03 18:47 UTC (permalink / raw)
  To: Paul Pogonyshev; +Cc: 56342

Paul Pogonyshev <pogonyshev@gmail.com> writes:

Hi Paul,

> Maybe you could then single out commands that are supposed to return
> result nearly-instantly anyway, e.g. `stat' or `test' (though the
> latter I have suggested to replace with `stat' before). If they fail
> to produce the result in 10 seconds, the connection can be assumed
> dead, just as with `echo are you awake'. Commands that involve
> transmitting (potentially) large amount of data this or that way can
> work as now. So, you would usually avoid one extra command (which with
> a high ping means sth. like 0.2 s, already pretty noticeable in UI)
> and achieve the same result.
>
> Sanity checks are good. but not if they visibly slow down normal
> operation.

I will see whether I can do something along these lines.

> It might be easier to convince the rest of Emacs developers to use an
> extra variable to possibly skip `file-exists-p' on only remote files
> than to remove the call altogether. Though in either case it is
> required that `file-missing' error is handled properly which is,
> incidentally, easier to test if the call to `file-exists-p' is
> dropped. A target here would be `insert-file-contents' and whatever it
> calls, and this is a part of Emacs, not some external library.

Tramp has an own implementation of insert-file-contents, called
tramp-handle-insert-file-contents. And indeed, file-exists-p is called
in order to raise the file-missing error if needed. I have no idea how
we could generate this otherwise. Perhaps changing the order: First try
to insert the file contents, and if this errs out, a call with
file-exists-p in order to raise the error. I'll play with this.

OTOH, with longer cache expiration time (see below), file-exists-p
doesn't cost a roundtrip.

> Yet another idea: removing temporary should be done asynchronously (I
> haven't checked, maybe it's already the case, but likely not). The
> caller doesn't really care about call result and even if it has
> succeeded. Again, not sure if this is easy to achieve interface-wise,
> maybe it's from a higher level. But I suspect it's something like
> `with-temp-file' and can be optimized: one-time optimization are worth
> it even if that costs readability.

Doing it asynchronously would require a second connection to the remote
host. Performance would rather degrade.

One thing you could do w/o code change is to change the value of
remote-file-name-inhibit-cache. Its default value is 10, meaning caches
expire already after 10 seconds. With your slow connection, a higher
value should help already.

> Paul

Best regards, Michael.





^ permalink raw reply	[flat|nested] 18+ messages in thread

* bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks
  2022-07-03 18:47         ` Michael Albinus
@ 2022-07-03 19:52           ` Paul Pogonyshev
  2022-07-04 11:19             ` Michael Albinus
  0 siblings, 1 reply; 18+ messages in thread
From: Paul Pogonyshev @ 2022-07-03 19:52 UTC (permalink / raw)
  To: Michael Albinus; +Cc: 56342

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

> I will see whether I can do something along these lines.

Thank you. I'm just spewing out ideas here, you know the code better and
what will and will not work.

> Perhaps changing the order: First try
> to insert the file contents, and if this errs out, a call with
> file-exists-p in order to raise the error. I'll play with this.

Yes, this would be a better way from my point of view. I don't care how
slowly (unless it is like 50 times slower) it fails, that is an unlikely
case. The most likely one, when the file exists, should be the benchmark.

> Doing it asynchronously would require a second connection to the remote
> host. Performance would rather degrade.

Maybe not really asynchronously, just let it return early, not waiting for
the result? I'm not sure how TRAMP receives responses, but can it just keep
executing commands sequentially, as now, but give control back to the
caller in case of commands where the result doesn't really matter (cleanup,
e.g. deleting a temporary file). Of course, this means that if an
"important" command is issued right away, it has to wait for the response
to the previous inessential command. But when such an inessential command
is the last in a batch, this waiting would be effectively merged with
Emacs' idling in the normal UI command loop, making things more responsive
for the user.

> One thing you could do w/o code change is to change the value of
> remote-file-name-inhibit-cache.

Thank you for the hint, will try.

Paul


On Sun, 3 Jul 2022 at 20:47, Michael Albinus <michael.albinus@gmx.de> wrote:

> Paul Pogonyshev <pogonyshev@gmail.com> writes:
>
> Hi Paul,
>
> > Maybe you could then single out commands that are supposed to return
> > result nearly-instantly anyway, e.g. `stat' or `test' (though the
> > latter I have suggested to replace with `stat' before). If they fail
> > to produce the result in 10 seconds, the connection can be assumed
> > dead, just as with `echo are you awake'. Commands that involve
> > transmitting (potentially) large amount of data this or that way can
> > work as now. So, you would usually avoid one extra command (which with
> > a high ping means sth. like 0.2 s, already pretty noticeable in UI)
> > and achieve the same result.
> >
> > Sanity checks are good. but not if they visibly slow down normal
> > operation.
>
> I will see whether I can do something along these lines.
>
> > It might be easier to convince the rest of Emacs developers to use an
> > extra variable to possibly skip `file-exists-p' on only remote files
> > than to remove the call altogether. Though in either case it is
> > required that `file-missing' error is handled properly which is,
> > incidentally, easier to test if the call to `file-exists-p' is
> > dropped. A target here would be `insert-file-contents' and whatever it
> > calls, and this is a part of Emacs, not some external library.
>
> Tramp has an own implementation of insert-file-contents, called
> tramp-handle-insert-file-contents. And indeed, file-exists-p is called
> in order to raise the file-missing error if needed. I have no idea how
> we could generate this otherwise. Perhaps changing the order: First try
> to insert the file contents, and if this errs out, a call with
> file-exists-p in order to raise the error. I'll play with this.
>
> OTOH, with longer cache expiration time (see below), file-exists-p
> doesn't cost a roundtrip.
>
> > Yet another idea: removing temporary should be done asynchronously (I
> > haven't checked, maybe it's already the case, but likely not). The
> > caller doesn't really care about call result and even if it has
> > succeeded. Again, not sure if this is easy to achieve interface-wise,
> > maybe it's from a higher level. But I suspect it's something like
> > `with-temp-file' and can be optimized: one-time optimization are worth
> > it even if that costs readability.
>
> Doing it asynchronously would require a second connection to the remote
> host. Performance would rather degrade.
>
> One thing you could do w/o code change is to change the value of
> remote-file-name-inhibit-cache. Its default value is 10, meaning caches
> expire already after 10 seconds. With your slow connection, a higher
> value should help already.
>
> > Paul
>
> Best regards, Michael.
>

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

^ permalink raw reply	[flat|nested] 18+ messages in thread

* bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks
  2022-07-02 15:58 ` Michael Albinus
  2022-07-02 18:14   ` Paul Pogonyshev
@ 2022-07-04 10:33   ` Michael Albinus
  1 sibling, 0 replies; 18+ messages in thread
From: Michael Albinus @ 2022-07-04 10:33 UTC (permalink / raw)
  To: Paul Pogonyshev; +Cc: 56342

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

Hi Paul,

>> Suggested improvements:
>>
>> * TRAMP should issue just one `stat' command to find out most of the
>> things about a file: whether it exists, if it is a directory, its real
>> name when dereferencing links and whatever stats it is used to find
>> now; from `$ stat --help' this seems to be possible. In other words,
>> TRAMP shouldn't use simple commands like `test -e': any ping, even
>> nominal, will negate any gains from using a tad faster command.
>> Instead, if it needs to find anything about a file, it should ask the
>> remote about as many things as possible in one go: it is very likely
>> that the additional information will be needed soon and even if not,
>> this is basically free compared to ping anyway.
>
> Not all remote hosts carry a stat command, and not all existing stat's
> are GNU compatible. But yes, if possible, Tramp shall gather as much
> information in one run, and cache the results for further use.

FTR, stat is not sufficient to detect the real file name. Example:

# touch /tmp/a
# ln -s /tmp/a /tmp/b
# ln -s /tmp/b /tmp/c
# stat -c %N /tmp/c

It returns "'/tmp/c' -> '/tmp/b'". However, we need "/tmp/a". So we must
still use "readlink --canonicalize".

Best regards, Michael.





^ permalink raw reply	[flat|nested] 18+ messages in thread

* bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks
  2022-07-03 19:52           ` Paul Pogonyshev
@ 2022-07-04 11:19             ` Michael Albinus
  2022-07-04 14:42               ` Paul Pogonyshev
  0 siblings, 1 reply; 18+ messages in thread
From: Michael Albinus @ 2022-07-04 11:19 UTC (permalink / raw)
  To: Paul Pogonyshev; +Cc: 56342

Paul Pogonyshev <pogonyshev@gmail.com> writes:

Hi Paul,

>> Doing it asynchronously would require a second connection to the remote
>> host. Performance would rather degrade.
>
> Maybe not really asynchronously, just let it return early, not waiting
> for the result? I'm not sure how TRAMP receives responses, but can it
> just keep executing commands sequentially, as now, but give control
> back to the caller in case of commands where the result doesn't really
> matter (cleanup, e.g. deleting a temporary file). Of course, this
> means that if an "important" command is issued right away, it has to
> wait for the response to the previous inessential command. But when
> such an inessential command is the last in a batch, this waiting would
> be effectively merged with Emacs' idling in the normal UI command
> loop, making things more responsive for the user.

Tramps communication with the remote host is like a REPL engine. It
sends shell commands to the remote hosts, reads the result, and waits
for the shell prompt. If it doesn't wait for the final shell prompt, it
is likely that the result or the shell prompt will be seen when reading
the output of the next command. This confuses. So no, I don't see a
chance to implement this kind of "asynchronity".

> Paul

Best regards, Michael.





^ permalink raw reply	[flat|nested] 18+ messages in thread

* bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks
  2022-07-04 11:19             ` Michael Albinus
@ 2022-07-04 14:42               ` Paul Pogonyshev
  2022-07-04 16:30                 ` Michael Albinus
  0 siblings, 1 reply; 18+ messages in thread
From: Paul Pogonyshev @ 2022-07-04 14:42 UTC (permalink / raw)
  To: Michael Albinus; +Cc: 56342

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

> It returns "'/tmp/c' -> '/tmp/b'". However, we need "/tmp/a". So we must
> still use "readlink --canonicalize".

According to a quick search, it is possible to merge output of several
shell commands together. This seems to work even with dumb `sh', it's not a
Bash extension:

    $ sh -c '{ stat xxx && readlink xxx; }'

I guess TRAMP could just sth. similar, as I understand it doesn't have to
be strictly one executable call, just one command given to the remote shell.

> Tramps communication with the remote host is like a REPL engine. It
> sends shell commands to the remote hosts, reads the result, and waits
> for the shell prompt. If it doesn't wait for the final shell prompt, it
> is likely that the result or the shell prompt will be seen when reading
> the output of the next command. This confuses. So no, I don't see a
> chance to implement this kind of "asynchronity".

I see parameter `nooutput' to `tramp-send-command'. Couldn't that be used?

Even if not, I could imagine sth. like this:

    (defvar pending-commands nil)
    (defvar reading-output nil)

    (defun send-command (x output-inessential)
      (if output-inessential
          (setf pending-commands (nconc pending-commands (list x)))
        (while reading-output  ; make sure the connection is free for the
next essential command
          (read-next-output-chunk)
          (when (and (not reading-output) pending-commands)
            (do-send-command (pop pending-commands))))
        (do-send-command x)
        (read-output-now)))

    (defun do-send-command (x)
      (really-do-send-it x)
      (setf reading-output t))

    (defun read-output-now ()
      (while reading-output
        (read-next-output-chunk))
      (extract-received-output-from-process-buffer))

    (defun emacs-idling ()  ; hooked up using `run-with-idle-timer' or
something like that
      (cond (reading-output
             (read-next-output-chunk))
            (pending-commands
             (do-send-command (pop pending-commands)))))

    (defun read-next-output-chunk ()
      (when reading-output
        (do-read-output-chunk)  ; this should be non-blocking
        (when (end-of-command-output)
          (setf reading-output nil))))

Paul

On Mon, 4 Jul 2022 at 13:19, Michael Albinus <michael.albinus@gmx.de> wrote:

> Paul Pogonyshev <pogonyshev@gmail.com> writes:
>
> Hi Paul,
>
> >> Doing it asynchronously would require a second connection to the remote
> >> host. Performance would rather degrade.
> >
> > Maybe not really asynchronously, just let it return early, not waiting
> > for the result? I'm not sure how TRAMP receives responses, but can it
> > just keep executing commands sequentially, as now, but give control
> > back to the caller in case of commands where the result doesn't really
> > matter (cleanup, e.g. deleting a temporary file). Of course, this
> > means that if an "important" command is issued right away, it has to
> > wait for the response to the previous inessential command. But when
> > such an inessential command is the last in a batch, this waiting would
> > be effectively merged with Emacs' idling in the normal UI command
> > loop, making things more responsive for the user.
>
> Tramps communication with the remote host is like a REPL engine. It
> sends shell commands to the remote hosts, reads the result, and waits
> for the shell prompt. If it doesn't wait for the final shell prompt, it
> is likely that the result or the shell prompt will be seen when reading
> the output of the next command. This confuses. So no, I don't see a
> chance to implement this kind of "asynchronity".
>
> > Paul
>
> Best regards, Michael.
>

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

^ permalink raw reply	[flat|nested] 18+ messages in thread

* bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks
  2022-07-04 14:42               ` Paul Pogonyshev
@ 2022-07-04 16:30                 ` Michael Albinus
  2022-07-26  8:00                   ` Paul Pogonyshev
  0 siblings, 1 reply; 18+ messages in thread
From: Michael Albinus @ 2022-07-04 16:30 UTC (permalink / raw)
  To: Paul Pogonyshev; +Cc: 56342

Paul Pogonyshev <pogonyshev@gmail.com> writes:

Hi Paul,

>> It returns "'/tmp/c' -> '/tmp/b'". However, we need "/tmp/a". So we must
>> still use "readlink --canonicalize".
>
> According to a quick search, it is possible to merge output of several
> shell commands together. This seems to work even with dumb `sh', it's
> not a Bash extension:
>
>     $ sh -c '{ stat xxx && readlink xxx; }'
>
> I guess TRAMP could just sth. similar, as I understand it doesn't have
> to be strictly one executable call, just one command given to the
> remote shell.

I'll check, perhaps it could be used in this special case.

But Tramp uses already combination of shell commands, and it uses even
private shell functions when applicable. Don't expect too much in
general.

>> Tramps communication with the remote host is like a REPL engine. It
>> sends shell commands to the remote hosts, reads the result, and waits
>> for the shell prompt. If it doesn't wait for the final shell prompt, it
>> is likely that the result or the shell prompt will be seen when reading
>> the output of the next command. This confuses. So no, I don't see a
>> chance to implement this kind of "asynchronity".
>
> I see parameter `nooutput' to `tramp-send-command'. Couldn't that be
> used?

No. This argument tells tramp-send-command not to call the final
accept-process-output. But this is only because on the caller side,
accept-process-output will be called with other arguments but the
default ones.

> Even if not, I could imagine sth. like this:
>
>     (defvar pending-commands nil)
>     (defvar reading-output nil)
>
>     (defun send-command (x output-inessential)
>       (if output-inessential
>           (setf pending-commands (nconc pending-commands (list x)))
>         (while reading-output  ; make sure the connection is free for
> the next essential command
>           (read-next-output-chunk)
>           (when (and (not reading-output) pending-commands)
>             (do-send-command (pop pending-commands))))
>         (do-send-command x)
>         (read-output-now)))
>
>     (defun do-send-command (x)
>       (really-do-send-it x)
>       (setf reading-output t))
>
>     (defun read-output-now ()
>       (while reading-output
>         (read-next-output-chunk))
>       (extract-received-output-from-process-buffer))
>
>     (defun emacs-idling ()  ; hooked up using `run-with-idle-timer' or
> something like that
>       (cond (reading-output
>              (read-next-output-chunk))
>             (pending-commands
>              (do-send-command (pop pending-commands)))))
>
>     (defun read-next-output-chunk ()
>       (when reading-output
>         (do-read-output-chunk)  ; this should be non-blocking
>         (when (end-of-command-output)
>           (setf reading-output nil))))

Something like this could be done, yes. Perhaps not with an (idle)
timer, because they are known to interrupt Tramp's REPL engine at any
point, with (sometimes) desastrous results. In general, one shall try to
avoid Tramp actions in timers, process sentinels and process filters.

So we could use this for deleting temporary files and alike, but there
won't be too many performance boosters I fear.

I will play with this idea, perhaps it helps. But for sure it will be an
opt-in feature only.

> Paul

Best regards, Michael.





^ permalink raw reply	[flat|nested] 18+ messages in thread

* bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks
  2022-07-04 16:30                 ` Michael Albinus
@ 2022-07-26  8:00                   ` Paul Pogonyshev
  2022-07-26 14:18                     ` Michael Albinus
  0 siblings, 1 reply; 18+ messages in thread
From: Paul Pogonyshev @ 2022-07-26  8:00 UTC (permalink / raw)
  To: Michael Albinus; +Cc: 56342

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

Hello,

any news on this?

Paul

On Mon, 4 Jul 2022 at 18:30, Michael Albinus <michael.albinus@gmx.de> wrote:

> Paul Pogonyshev <pogonyshev@gmail.com> writes:
>
> Hi Paul,
>
> >> It returns "'/tmp/c' -> '/tmp/b'". However, we need "/tmp/a". So we must
> >> still use "readlink --canonicalize".
> >
> > According to a quick search, it is possible to merge output of several
> > shell commands together. This seems to work even with dumb `sh', it's
> > not a Bash extension:
> >
> >     $ sh -c '{ stat xxx && readlink xxx; }'
> >
> > I guess TRAMP could just sth. similar, as I understand it doesn't have
> > to be strictly one executable call, just one command given to the
> > remote shell.
>
> I'll check, perhaps it could be used in this special case.
>
> But Tramp uses already combination of shell commands, and it uses even
> private shell functions when applicable. Don't expect too much in
> general.
>
> >> Tramps communication with the remote host is like a REPL engine. It
> >> sends shell commands to the remote hosts, reads the result, and waits
> >> for the shell prompt. If it doesn't wait for the final shell prompt, it
> >> is likely that the result or the shell prompt will be seen when reading
> >> the output of the next command. This confuses. So no, I don't see a
> >> chance to implement this kind of "asynchronity".
> >
> > I see parameter `nooutput' to `tramp-send-command'. Couldn't that be
> > used?
>
> No. This argument tells tramp-send-command not to call the final
> accept-process-output. But this is only because on the caller side,
> accept-process-output will be called with other arguments but the
> default ones.
>
> > Even if not, I could imagine sth. like this:
> >
> >     (defvar pending-commands nil)
> >     (defvar reading-output nil)
> >
> >     (defun send-command (x output-inessential)
> >       (if output-inessential
> >           (setf pending-commands (nconc pending-commands (list x)))
> >         (while reading-output  ; make sure the connection is free for
> > the next essential command
> >           (read-next-output-chunk)
> >           (when (and (not reading-output) pending-commands)
> >             (do-send-command (pop pending-commands))))
> >         (do-send-command x)
> >         (read-output-now)))
> >
> >     (defun do-send-command (x)
> >       (really-do-send-it x)
> >       (setf reading-output t))
> >
> >     (defun read-output-now ()
> >       (while reading-output
> >         (read-next-output-chunk))
> >       (extract-received-output-from-process-buffer))
> >
> >     (defun emacs-idling ()  ; hooked up using `run-with-idle-timer' or
> > something like that
> >       (cond (reading-output
> >              (read-next-output-chunk))
> >             (pending-commands
> >              (do-send-command (pop pending-commands)))))
> >
> >     (defun read-next-output-chunk ()
> >       (when reading-output
> >         (do-read-output-chunk)  ; this should be non-blocking
> >         (when (end-of-command-output)
> >           (setf reading-output nil))))
>
> Something like this could be done, yes. Perhaps not with an (idle)
> timer, because they are known to interrupt Tramp's REPL engine at any
> point, with (sometimes) desastrous results. In general, one shall try to
> avoid Tramp actions in timers, process sentinels and process filters.
>
> So we could use this for deleting temporary files and alike, but there
> won't be too many performance boosters I fear.
>
> I will play with this idea, perhaps it helps. But for sure it will be an
> opt-in feature only.
>
> > Paul
>
> Best regards, Michael.
>

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

^ permalink raw reply	[flat|nested] 18+ messages in thread

* bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks
  2022-07-26  8:00                   ` Paul Pogonyshev
@ 2022-07-26 14:18                     ` Michael Albinus
  2022-07-26 16:17                       ` Paul Pogonyshev
  0 siblings, 1 reply; 18+ messages in thread
From: Michael Albinus @ 2022-07-26 14:18 UTC (permalink / raw)
  To: Paul Pogonyshev; +Cc: 56342

Paul Pogonyshev <pogonyshev@gmail.com> writes:

> Hello,

Hi Paul,

> any news on this?

I've worked last weeks almost full time on this. With limited success.

Combining stat and readlink into one remote command have even slowed
down the machinery. Likely, because it isn't needed always, but it
always consumes more time to compute both on the remote side, and to
read all the results.

Moving the check of the existence of a file to the end, and let the
commands fail in case the file doesn't exist, isn't possible. Often,
Tramp needs to know in advance the size of a given file, for example to
decide whether to encode/decode the file or to invoke scp, or to know
whether the file shall be compressed prior transfer. Checking the file
size is much the same as checking the file existence.

Avoiding the "are you awake" command is still on my todo list, but it
isn't trivial. There is a complex machinery to be invoked in case the
command fails, in order to reestablish the connection in the
background. It still might be possible to change this, but it isn't
trivial.

Bu there are also some results. With commit
9ed5c39aad09571314097be91cb28e7504614421 I've refactored major Tramp
parts in order to have a better chance to apply performance
changes. This includes already some changes to combine several commands
(avoiding superfluous roundtrips) and alike. There's also commit
dfa16cadc18930fad76fa6113750eaa27d367e72 fixing a regression which was
introduced with the former patch.

In my test environment, performance improvement of these changes is not
overwhelming. But I sit in a LAN, with good connections. Perhaps you
give it a try to see, whether your use cases behave better.

I'll continue to work on this, but don't expect wonders.

> Paul

Best regards, Michael.





^ permalink raw reply	[flat|nested] 18+ messages in thread

* bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks
  2022-07-26 14:18                     ` Michael Albinus
@ 2022-07-26 16:17                       ` Paul Pogonyshev
  2022-07-26 17:51                         ` Michael Albinus
  0 siblings, 1 reply; 18+ messages in thread
From: Paul Pogonyshev @ 2022-07-26 16:17 UTC (permalink / raw)
  To: Michael Albinus; +Cc: 56342

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

> I've worked last weeks almost full time on this.

Thank you!

> Combining stat and readlink into one remote command have even slowed
> down the machinery. Likely, because it isn't needed always, but it
> always consumes more time to compute both on the remote side, and to
> read all the results.

Well, that's hard to believe. I mean, it is understandable that `readlink'
(whatever Elisp call results in that shell command) is not often needed,
but how long can that take on a modern computer, 1 ms? It might be that we
evaluate performance changes differently. I care more about worst cases
(since they affect me directly, yeah) and not so much if Tramp becomes 1 ms
slower "per user-visible operation" on average.

> Perhaps you
give it a try to see, whether your use cases behave better.

I tested it a bit now. Initially mentioned usecase (`insert-file-contents',
but only a file part, not the whole file) appears to be considerably faster
after the changes (hard to say, feels like 30-50% faster). The connection
log says that number of commands is 10 now, with the originally mentioned
list heavily changed. However, there must still be space for improvement,
e.g. `M-x occur tramp-send RET' suggests there are outright duplicated
commands now:

    18:03:41.617738 tramp-send-command (6) # \readlink
--canonicalize-missing /tmp/tramp.H3AZYb 2>/dev/null; echo
tramp_exit_status $?
    18:03:41.650294 tramp-send-command (6) # tramp_stat_file_attributes
/tmp/tramp.H3AZYb 2>/dev/null; echo tramp_exit_status $?
    18:03:41.699627 tramp-send-command (6) # base64 -d -i
>/tmp/tramp.H3AZYb <<'9190079abe64738d52b0f040fd94461c' 2>/dev/null; echo
tramp_exit_status $?
    18:03:41.731669 tramp-send-command (6) # chown 1000:1001
/tmp/tramp.H3AZYb
    18:03:41.760145 tramp-send-command (6) # dd bs=1 skip=8166969 if=[...]
of=/tmp/tramp.H3AZYb
    18:03:41.843785 tramp-send-command (6) # \readlink
--canonicalize-missing /tmp/tramp.H3AZYb 2>/dev/null; echo
tramp_exit_status $?
    18:03:41.872072 tramp-send-command (6) # tramp_stat_file_attributes
/tmp/tramp.H3AZYb 2>/dev/null; echo tramp_exit_status $?
    18:03:41.902388 tramp-send-command (6) # (env GZIP= gzip
</tmp/tramp.H3AZYb | base64) 2>/dev/null; echo tramp_exit_status $?
    18:03:41.952283 tramp-send-command (6) # rm -f /tmp/tramp.H3AZYb
2>/dev/null; echo tramp_exit_status $?

On the other hand, refreshing a remote-tracking Magit (Emacs Git
interface) buffer doesn't feel any faster than before. Logs also suggest
that number of commands that tramp send stays as before (43). Some commands
are certainly excessive, e.g. it repeats `test -d [...] 2>/dev/null; echo
tramp_exit_status $?' 4 times for the same directory (intermixed with other
commands), suggesting that Tramp doesn't cache the result. Three times it
issues `test -r ...' for the same directory, the source checkout root. Most
other commands cannot be generically skipped by Tramp though, this would
rather depend on Magit.

Paul

On Tue, 26 Jul 2022 at 16:18, Michael Albinus <michael.albinus@gmx.de>
wrote:

> Paul Pogonyshev <pogonyshev@gmail.com> writes:
>
> > Hello,
>
> Hi Paul,
>
> > any news on this?
>
> I've worked last weeks almost full time on this. With limited success.
>
> Combining stat and readlink into one remote command have even slowed
> down the machinery. Likely, because it isn't needed always, but it
> always consumes more time to compute both on the remote side, and to
> read all the results.
>
> Moving the check of the existence of a file to the end, and let the
> commands fail in case the file doesn't exist, isn't possible. Often,
> Tramp needs to know in advance the size of a given file, for example to
> decide whether to encode/decode the file or to invoke scp, or to know
> whether the file shall be compressed prior transfer. Checking the file
> size is much the same as checking the file existence.
>
> Avoiding the "are you awake" command is still on my todo list, but it
> isn't trivial. There is a complex machinery to be invoked in case the
> command fails, in order to reestablish the connection in the
> background. It still might be possible to change this, but it isn't
> trivial.
>
> Bu there are also some results. With commit
> 9ed5c39aad09571314097be91cb28e7504614421 I've refactored major Tramp
> parts in order to have a better chance to apply performance
> changes. This includes already some changes to combine several commands
> (avoiding superfluous roundtrips) and alike. There's also commit
> dfa16cadc18930fad76fa6113750eaa27d367e72 fixing a regression which was
> introduced with the former patch.
>
> In my test environment, performance improvement of these changes is not
> overwhelming. But I sit in a LAN, with good connections. Perhaps you
> give it a try to see, whether your use cases behave better.
>
> I'll continue to work on this, but don't expect wonders.
>
> > Paul
>
> Best regards, Michael.
>

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

^ permalink raw reply	[flat|nested] 18+ messages in thread

* bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks
  2022-07-26 16:17                       ` Paul Pogonyshev
@ 2022-07-26 17:51                         ` Michael Albinus
  2022-08-01 20:20                           ` Paul Pogonyshev
  0 siblings, 1 reply; 18+ messages in thread
From: Michael Albinus @ 2022-07-26 17:51 UTC (permalink / raw)
  To: Paul Pogonyshev; +Cc: 56342

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

Paul Pogonyshev <pogonyshev@gmail.com> writes:

Hi Paul,

>> Combining stat and readlink into one remote command have even slowed
>> down the machinery. Likely, because it isn't needed always, but it
>> always consumes more time to compute both on the remote side, and to
>> read all the results.
>
> Well, that's hard to believe. I mean, it is understandable that
> `readlink' (whatever Elisp call results in that shell command) is not
> often needed, but how long can that take on a modern computer, 1 ms?
> It might be that we evaluate performance changes differently. I care
> more about worst cases (since they affect me directly, yeah) and not
> so much if Tramp becomes 1 ms slower "per user-visible operation" on
> average.

As said, I live in a pretty good connected LAN. remote commands do not
result in heavy performance degradations, compared with the rest of
Elisp computing.

> I tested it a bit now. Initially mentioned usecase
> (`insert-file-contents', but only a file part, not the whole file)
> appears to be considerably faster after the changes (hard to say,
> feels like 30-50% faster).

Oh, good. In my environment it was something about 5%.

> The connection log says that number of
> commands is 10 now, with the originally mentioned list heavily
> changed. However, there must still be space for improvement, e.g. `M-x
> occur tramp-send RET' suggests there are outright duplicated commands
> now:

Pretty sure there's still place for improvements!

> On the other hand, refreshing a remote-tracking Magit (Emacs Git
> interface) buffer doesn't feel any faster than before. Logs also
> suggest that number of commands that tramp send stays as before (43).
> Some commands are certainly excessive, e.g. it repeats `test -d [...]
> 2>/dev/null; echo tramp_exit_status $?' 4 times for the same directory
> (intermixed with other commands), suggesting that Tramp doesn't cache
> the result. Three times it issues `test -r ...' for the same
> directory, the source checkout root. Most other commands cannot be
> generically skipped by Tramp though, this would rather depend on
> Magit.

Caches are problematic. They are limited to 10 seconds by default, did
you try to increase that number? VC related commands are also
problematic, Emacs tests different VC's for availability. It is always a
good idea to reduce the number of VC backends. If you completely trust
in magit, you shall deactivate Emacs' vc.el. Something like (setq
vc-handled-backends nil) should help.

And directories are also problematic for caches. As soon as something
changes there (creation or deletion of a file, for example), the cached
values of the directory must be flushed.

I propose we try step by step. That is, we investigate typical code
snippets, and see what Tramp does. Case by case.

The Tramp debug buffer is a little bit noisy. So you could do

(progn
  (trace-function-background 'tramp-send-command)
  (trace-function-background 'tramp-file-name-handler))

By this, only the calls of tramp-send-command (go remote) and
tramp-file-name-handler (any invocation of Tramp) are traced. The latter
is important to know, what has triggered a given remote command.

Starting with your initial example

(with-temp-buffer
  (insert-file-contents "/ssh:detlef:.emacs" nil 100 nil))

I get the *trace-output* buffer as appended. Let's study this first, and
see, what could be done in order to improve this case. Obviously, most
of the commands are about the temporary file /tmp/tramp.qgnQ01, which is
superfluous. I'll check whether handling temporary files could be
handled better.

When we're happy with this example, let's go to the next example.

> Paul

Best regards, Michael.

PS: Next 2 or 3 days I'm kind of absent: my granddaughter will visit
us. Sorry, but you know: priorities :-)


[-- Attachment #2: Type: text/plain, Size: 16023 bytes --]

======================================================================
1 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:.emacs" nil)
1 <- tramp-file-name-handler: "/ssh:detlef:/home/albinus/.emacs"
======================================================================
1 -> (tramp-file-name-handler insert-file-contents "/ssh:detlef:/home/albinus/.emacs" nil 2 4 nil)
| 2 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/home/albinus/.emacs" nil)
| 2 <- tramp-file-name-handler: "/ssh:detlef:/home/albinus/.emacs"
| 2 -> (tramp-file-name-handler expand-file-name "tramp." "/ssh:detlef:/tmp")
| 2 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp."
| 2 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp." "/tmp/")
| 2 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp."
| 2 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| 2 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| 2 -> (tramp-file-name-handler write-region "" nil #1="/ssh:detlef:/tmp/tramp.qgnQ01" nil silent #1# excl)
| | 3 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | 3 -> (tramp-file-name-handler file-truename "/ssh:detlef:/tmp/tramp.qgnQ01")
| | | 4 -> (tramp-file-name-handler file-remote-p "/ssh:detlef:/tmp/tramp.qgnQ01" localname nil)
| | | | 5 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | | 4 <- tramp-file-name-handler: "/tmp/tramp.qgnQ01"
| | | 4 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | | 4 -> (tramp-file-name-handler file-remote-p "/ssh:detlef:/tmp/tramp.qgnQ01" localname nil)
| | | | 5 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | | 4 <- tramp-file-name-handler: "/tmp/tramp.qgnQ01"
| | | 4 -> (tramp-file-name-handler file-remote-p "/ssh:detlef:/tmp/tramp.qgnQ01" nil nil)
| | | | 5 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | | 4 <- tramp-file-name-handler: "/ssh:detlef:"
| | | 4 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil "/tmp/tramp.qgnQ01" nil) "\\readlink --canonicalize-missing /tmp/tramp.qgnQ01 2>/dev/null; echo tramp_exit_status $?")
| | | | 5 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil "/tmp/tramp.qgnQ01" nil) "echo are you awake" t t)
| | | | 5 <- tramp-send-command: nil
| | | 4 <- tramp-send-command: 39
| | | 4 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | | 4 -> (tramp-file-name-handler file-symlink-p "/ssh:detlef:/tmp/tramp.qgnQ01")
| | | | 5 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | | | 5 -> (tramp-file-name-handler file-attributes "/ssh:detlef:/tmp/tramp.qgnQ01")
| | | | | 6 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | | | 6 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | | | | 6 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil "/tmp/tramp.qgnQ01" nil) "tramp_stat_file_attributes /tmp/tramp.qgnQ01 2>/dev/null; echo tramp_exit_status $?")
| | | | | 6 <- tramp-send-command: 25
| | | | 5 <- tramp-file-name-handler: nil
| | | 4 <- tramp-file-name-handler: nil
| | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | 3 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | 3 -> (tramp-file-name-handler file-exists-p "/ssh:detlef:/tmp/tramp.qgnQ01")
| | 3 <- tramp-file-name-handler: nil
| | 3 -> (tramp-file-name-handler file-locked-p "/ssh:detlef:/tmp/tramp.qgnQ01")
| | | 4 -> (tramp-file-name-handler make-lock-file-name "/ssh:detlef:/tmp/tramp.qgnQ01")
| | | 4 <- tramp-file-name-handler: nil
| | 3 <- tramp-file-name-handler: nil
| | 3 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | 3 -> (tramp-file-name-handler file-attributes "/ssh:detlef:/tmp/tramp.qgnQ01" integer)
| | | 4 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | 3 <- tramp-file-name-handler: nil
| | 3 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | 3 -> (tramp-file-name-handler file-attributes "/ssh:detlef:/tmp/tramp.qgnQ01" integer)
| | | 4 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | 3 <- tramp-file-name-handler: nil
| | 3 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | 3 -> (tramp-file-name-handler file-acl "/ssh:detlef:/tmp/tramp.qgnQ01")
| | 3 <- tramp-file-name-handler: nil
| | 3 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | 3 -> (tramp-file-name-handler file-selinux-context "/ssh:detlef:/tmp/tramp.qgnQ01")
| | 3 <- tramp-file-name-handler: (nil nil nil nil)
| | 3 -> (tramp-file-name-handler file-name-nondirectory "/ssh:detlef:/tmp/tramp.qgnQ01")
| | 3 <- tramp-file-name-handler: "tramp.qgnQ01"
| | 3 -> (tramp-file-name-handler file-remote-p "/ssh:detlef:/tmp/tramp.qgnQ01" nil nil)
| | | 4 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | 3 <- tramp-file-name-handler: "/ssh:detlef:"
| | 3 -> (tramp-file-name-handler lock-file "/ssh:detlef:/tmp/tramp.qgnQ01")
| | | 4 -> (tramp-file-name-handler file-locked-p "/ssh:detlef:/tmp/tramp.qgnQ01")
| | | | 5 -> (tramp-file-name-handler make-lock-file-name "/ssh:detlef:/tmp/tramp.qgnQ01")
| | | | 5 <- tramp-file-name-handler: nil
| | | 4 <- tramp-file-name-handler: nil
| | | 4 -> (tramp-file-name-handler make-lock-file-name "/ssh:detlef:/tmp/tramp.qgnQ01")
| | | 4 <- tramp-file-name-handler: nil
| | | 4 -> (tramp-file-name-handler make-lock-file-name "/ssh:detlef:/tmp/tramp.qgnQ01")
| | | 4 <- tramp-file-name-handler: nil
| | 3 <- tramp-file-name-handler: nil
| | 3 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | 3 -> (tramp-file-name-handler file-modes "/ssh:detlef:/tmp/tramp.qgnQ01" nofollow)
| | | 4 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | | 4 -> (tramp-file-name-handler file-attributes "/ssh:detlef:/tmp/tramp.qgnQ01")
| | | | 5 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | | 4 <- tramp-file-name-handler: nil
| | 3 <- tramp-file-name-handler: nil
| | 3 -> (tramp-file-name-handler file-name-nondirectory "/ssh:detlef:/tmp/tramp.qgnQ01")
| | 3 <- tramp-file-name-handler: "tramp.qgnQ01"
| | 3 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil "/tmp/tramp.qgnQ01" nil) "base64 -d -i >/tmp/tramp.qgnQ01 <<'b03f0306a9a1e716a81252ccc4134b92' 2>/dev/null; echo tramp_exit_status $?\nb03f0306a9a1e716a81252ccc4134b92")
| | 3 <- tramp-send-command: 21
| | 3 -> (tramp-file-name-handler file-name-directory "/ssh:detlef:/tmp/tramp.qgnQ01")
| | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/"
| | 3 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/" nil)
| | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/"
| | 3 -> (tramp-file-name-handler directory-file-name "/ssh:detlef:/tmp/")
| | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp"
| | 3 -> (tramp-file-name-handler file-modes "/ssh:detlef:/tmp" nil)
| | | 4 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp" nil)
| | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp"
| | | 4 -> (tramp-file-name-handler file-attributes "/ssh:detlef:/tmp")
| | | | 5 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp" nil)
| | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp"
| | | | 5 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil "/tmp" nil) "tramp_stat_file_attributes /tmp 2>/dev/null; echo tramp_exit_status $?")
| | | | 5 <- tramp-send-command: 129
| | | 4 <- tramp-file-name-handler: (t 30 0 0 (25305 58381 0 0) (25312 7412 0 0) (25312 7412 0 0) 135168 "drwxrwxrwt" t 3801089 (-1 . 2))
| | 3 <- tramp-file-name-handler: 1023
| | 3 -> (tramp-file-name-handler tramp-set-file-uid-gid "/ssh:detlef:/tmp/tramp.qgnQ01" 1000 1000)
| | | 4 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil "/tmp/tramp.qgnQ01" nil) "chown 1000:1000 /tmp/tramp.qgnQ01")
| | | 4 <- tramp-send-command: 1
| | 3 <- tramp-file-name-handler: 1
| | 3 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" "~/")
| | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | 3 -> (tramp-file-name-handler set-file-acl "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | 4 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | 3 <- tramp-file-name-handler: nil
| | 3 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" "~/")
| | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | 3 -> (tramp-file-name-handler set-file-selinux-context "/ssh:detlef:/tmp/tramp.qgnQ01" (nil nil nil nil))
| | 3 <- tramp-file-name-handler: nil
| | 3 -> (tramp-file-name-handler unlock-file "/ssh:detlef:/tmp/tramp.qgnQ01")
| | | 4 -> (tramp-file-name-handler make-lock-file-name "/ssh:detlef:/tmp/tramp.qgnQ01")
| | | 4 <- tramp-file-name-handler: nil
| | 3 <- tramp-file-name-handler: nil
| 2 <- tramp-file-name-handler: nil
| 2 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil "/home/albinus/.emacs" nil) "dd bs=1 skip=2 if=/home/albinus/.emacs count=2 of=/tmp/tramp.qgnQ01")
| 2 <- tramp-send-command: 72
| 2 -> (tramp-file-name-handler file-local-copy "/ssh:detlef:/tmp/tramp.qgnQ01")
| | 3 -> (tramp-file-name-handler file-truename "/ssh:detlef:/tmp/tramp.qgnQ01")
| | | 4 -> (tramp-file-name-handler file-remote-p "/ssh:detlef:/tmp/tramp.qgnQ01" localname nil)
| | | | 5 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | | 4 <- tramp-file-name-handler: "/tmp/tramp.qgnQ01"
| | | 4 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | | 4 -> (tramp-file-name-handler file-remote-p "/ssh:detlef:/tmp/tramp.qgnQ01" localname nil)
| | | | 5 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | | 4 <- tramp-file-name-handler: "/tmp/tramp.qgnQ01"
| | | 4 -> (tramp-file-name-handler file-remote-p "/ssh:detlef:/tmp/tramp.qgnQ01" nil nil)
| | | | 5 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | | 4 <- tramp-file-name-handler: "/ssh:detlef:"
| | | 4 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil "/tmp/tramp.qgnQ01" nil) "\\readlink --canonicalize-missing /tmp/tramp.qgnQ01 2>/dev/null; echo tramp_exit_status $?")
| | | 4 <- tramp-send-command: 39
| | | 4 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | | 4 -> (tramp-file-name-handler file-symlink-p "/ssh:detlef:/tmp/tramp.qgnQ01")
| | | | 5 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | | | 5 -> (tramp-file-name-handler file-attributes "/ssh:detlef:/tmp/tramp.qgnQ01")
| | | | | 6 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | | | 6 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | | | | 6 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil "/tmp/tramp.qgnQ01" nil) "tramp_stat_file_attributes /tmp/tramp.qgnQ01 2>/dev/null; echo tramp_exit_status $?")
| | | | | 6 <- tramp-send-command: 148
| | | | 5 <- tramp-file-name-handler: (nil 1 1000 1000 (25312 7412 0 0) (25312 7412 0 0) (25312 7412 0 0) 2 "-rw-rw-r--" nil 3821258 (-1 . 2))
| | | 4 <- tramp-file-name-handler: nil
| | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | 3 -> (tramp-file-name-handler file-name-nondirectory "/ssh:detlef:/tmp/tramp.qgnQ01")
| | 3 <- tramp-file-name-handler: "tramp.qgnQ01"
| | 3 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | 3 -> (tramp-file-name-handler file-attributes "/ssh:detlef:/tmp/tramp.qgnQ01")
| | | 4 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | 3 <- tramp-file-name-handler: (nil 1 1000 1000 (25312 7412 0 0) (25312 7412 0 0) (25312 7412 0 0) 2 "-rw-rw-r--" nil 3821258 (-1 . 2))
| | 3 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil "/tmp/tramp.qgnQ01" nil) "base64 </tmp/tramp.qgnQ01 2>/dev/null; echo tramp_exit_status $?")
| | 3 <- tramp-send-command: 26
| | 3 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | 3 -> (tramp-file-name-handler file-modes "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | 4 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | | 4 -> (tramp-file-name-handler file-attributes "/ssh:detlef:/tmp/tramp.qgnQ01")
| | | | 5 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | | 4 <- tramp-file-name-handler: (nil 1 1000 1000 (25312 7412 0 0) (25312 7412 0 0) (25312 7412 0 0) 2 "-rw-rw-r--" nil 3821258 (-1 . 2))
| | 3 <- tramp-file-name-handler: 436
| 2 <- tramp-file-name-handler: "/tmp/tramp.6ce5x9.qgnQ01"
| 2 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| 2 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| 2 -> (tramp-file-name-handler file-directory-p "/ssh:detlef:/tmp/tramp.qgnQ01")
| 2 <- tramp-file-name-handler: nil
| 2 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| 2 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| 2 -> (tramp-file-name-handler delete-file "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | 3 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
| | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
| | 3 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil "/tmp/tramp.qgnQ01" nil) "rm -f /tmp/tramp.qgnQ01 2>/dev/null; echo tramp_exit_status $?")
| | 3 <- tramp-send-command: 21
| 2 <- tramp-file-name-handler: t
1 <- tramp-file-name-handler: ("/ssh:detlef:/home/albinus/.emacs" 2)

^ permalink raw reply	[flat|nested] 18+ messages in thread

* bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks
  2022-07-26 17:51                         ` Michael Albinus
@ 2022-08-01 20:20                           ` Paul Pogonyshev
  2022-08-02 14:23                             ` Michael Albinus
  0 siblings, 1 reply; 18+ messages in thread
From: Paul Pogonyshev @ 2022-08-01 20:20 UTC (permalink / raw)
  To: Michael Albinus; +Cc: 56342

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

> As said, I live in a pretty good connected LAN. remote commands do not
> result in heavy performance degradations, compared with the rest of
> Elisp computing.

Understood, but I propose to adopt a different benchmark: number of
remote commands.  As soon as you are not in a LAN, even not when using
a particularly slow network, this becomes an order or two of magnitude
more important than everything else.  E.g. with slightly slower
commands or particularly inefficient Elisp you can make it 2-10 ms
slower for everyone.  But with unoptimized command flow (i.e. more
remote commands) it can be 100-500 ms slower, though not for everyone,
but people using this over non-LAN.  I think in such cases extremes
are more important than the average.

> > On the other hand, refreshing a remote-tracking Magit (Emacs Git
> > interface) buffer doesn't feel any faster than before. Logs also
> > suggest that number of commands that tramp send stays as before (43).
> > Some commands are certainly excessive, e.g. it repeats `test -d [...]
> > 2>/dev/null; echo tramp_exit_status $?' 4 times for the same directory
> > (intermixed with other commands), suggesting that Tramp doesn't cache
> > the result. Three times it issues `test -r ...' for the same
> > directory, the source checkout root. Most other commands cannot be
> > generically skipped by Tramp though, this would rather depend on
> > Magit.
>
> Caches are problematic. They are limited to 10 seconds by default, did
> you try to increase that number?

Yes, `remote-file-name-inhibit-cache' is now 600 here.

> And directories are also problematic for caches. As soon as something
> changes there (creation or deletion of a file, for example), the cached
> values of the directory must be flushed.

Yeah, I suppose Tramp has no generic way to know that Magit issues
reading commands.  Can we devise a generic interface that would tell
Tramp: "Commands within this block will not modify file system",
e.g. with let-binding some variable?

In general, it feels like Tramp flushes its caches too often or maybe
doesn't even cache certain things at all.  I.e. it's not about those
10 seconds (following your advice I have even increased that).  It's
that while serving one user-level command here (i.e. within 3 seconds
at most), it can issue the same remote command several times, thus
not reusing previous results.

E.g. in the traces you have attached this can be seen.  The following
two commands repeat twice:

| | | 4 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil
"/tmp/tramp.qgnQ01" nil) "\\readlink --canonicalize-missing
/tmp/tramp.qgnQ01 2>/dev/null; echo tramp_exit_status $?")
...
| | | 4 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil
"/tmp/tramp.qgnQ01" nil) "\\readlink --canonicalize-missing
/tmp/tramp.qgnQ01 2>/dev/null; echo tramp_exit_status $?")

and

| | | | | 6 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef"
nil "/tmp/tramp.qgnQ01" nil) "tramp_stat_file_attributes /tmp/tramp.qgnQ01
2>/dev/null; echo tramp_exit_status $?")
...
| | | | | 6 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef"
nil "/tmp/tramp.qgnQ01" nil) "tramp_stat_file_attributes /tmp/tramp.qgnQ01
2>/dev/null; echo tramp_exit_status $?")

Paul

On Tue, 26 Jul 2022 at 19:51, Michael Albinus <michael.albinus@gmx.de>
wrote:

> Paul Pogonyshev <pogonyshev@gmail.com> writes:
>
> Hi Paul,
>
> >> Combining stat and readlink into one remote command have even slowed
> >> down the machinery. Likely, because it isn't needed always, but it
> >> always consumes more time to compute both on the remote side, and to
> >> read all the results.
> >
> > Well, that's hard to believe. I mean, it is understandable that
> > `readlink' (whatever Elisp call results in that shell command) is not
> > often needed, but how long can that take on a modern computer, 1 ms?
> > It might be that we evaluate performance changes differently. I care
> > more about worst cases (since they affect me directly, yeah) and not
> > so much if Tramp becomes 1 ms slower "per user-visible operation" on
> > average.
>
> As said, I live in a pretty good connected LAN. remote commands do not
> result in heavy performance degradations, compared with the rest of
> Elisp computing.
>
> > I tested it a bit now. Initially mentioned usecase
> > (`insert-file-contents', but only a file part, not the whole file)
> > appears to be considerably faster after the changes (hard to say,
> > feels like 30-50% faster).
>
> Oh, good. In my environment it was something about 5%.
>
> > The connection log says that number of
> > commands is 10 now, with the originally mentioned list heavily
> > changed. However, there must still be space for improvement, e.g. `M-x
> > occur tramp-send RET' suggests there are outright duplicated commands
> > now:
>
> Pretty sure there's still place for improvements!
>
> > On the other hand, refreshing a remote-tracking Magit (Emacs Git
> > interface) buffer doesn't feel any faster than before. Logs also
> > suggest that number of commands that tramp send stays as before (43).
> > Some commands are certainly excessive, e.g. it repeats `test -d [...]
> > 2>/dev/null; echo tramp_exit_status $?' 4 times for the same directory
> > (intermixed with other commands), suggesting that Tramp doesn't cache
> > the result. Three times it issues `test -r ...' for the same
> > directory, the source checkout root. Most other commands cannot be
> > generically skipped by Tramp though, this would rather depend on
> > Magit.
>
> Caches are problematic. They are limited to 10 seconds by default, did
> you try to increase that number? VC related commands are also
> problematic, Emacs tests different VC's for availability. It is always a
> good idea to reduce the number of VC backends. If you completely trust
> in magit, you shall deactivate Emacs' vc.el. Something like (setq
> vc-handled-backends nil) should help.
>
> And directories are also problematic for caches. As soon as something
> changes there (creation or deletion of a file, for example), the cached
> values of the directory must be flushed.
>
> I propose we try step by step. That is, we investigate typical code
> snippets, and see what Tramp does. Case by case.
>
> The Tramp debug buffer is a little bit noisy. So you could do
>
> (progn
>   (trace-function-background 'tramp-send-command)
>   (trace-function-background 'tramp-file-name-handler))
>
> By this, only the calls of tramp-send-command (go remote) and
> tramp-file-name-handler (any invocation of Tramp) are traced. The latter
> is important to know, what has triggered a given remote command.
>
> Starting with your initial example
>
> (with-temp-buffer
>   (insert-file-contents "/ssh:detlef:.emacs" nil 100 nil))
>
> I get the *trace-output* buffer as appended. Let's study this first, and
> see, what could be done in order to improve this case. Obviously, most
> of the commands are about the temporary file /tmp/tramp.qgnQ01, which is
> superfluous. I'll check whether handling temporary files could be
> handled better.
>
> When we're happy with this example, let's go to the next example.
>
> > Paul
>
> Best regards, Michael.
>
> PS: Next 2 or 3 days I'm kind of absent: my granddaughter will visit
> us. Sorry, but you know: priorities :-)
>
> ======================================================================
> 1 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:.emacs" nil)
> 1 <- tramp-file-name-handler: "/ssh:detlef:/home/albinus/.emacs"
> ======================================================================
> 1 -> (tramp-file-name-handler insert-file-contents
> "/ssh:detlef:/home/albinus/.emacs" nil 2 4 nil)
> | 2 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/home/albinus/.emacs" nil)
> | 2 <- tramp-file-name-handler: "/ssh:detlef:/home/albinus/.emacs"
> | 2 -> (tramp-file-name-handler expand-file-name "tramp."
> "/ssh:detlef:/tmp")
> | 2 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp."
> | 2 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/tramp."
> "/tmp/")
> | 2 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp."
> | 2 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | 2 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | 2 -> (tramp-file-name-handler write-region "" nil
> #1="/ssh:detlef:/tmp/tramp.qgnQ01" nil silent #1# excl)
> | | 3 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | 3 -> (tramp-file-name-handler file-truename
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | | 4 -> (tramp-file-name-handler file-remote-p
> "/ssh:detlef:/tmp/tramp.qgnQ01" localname nil)
> | | | | 5 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | | 4 <- tramp-file-name-handler: "/tmp/tramp.qgnQ01"
> | | | 4 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | | 4 -> (tramp-file-name-handler file-remote-p
> "/ssh:detlef:/tmp/tramp.qgnQ01" localname nil)
> | | | | 5 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | | 4 <- tramp-file-name-handler: "/tmp/tramp.qgnQ01"
> | | | 4 -> (tramp-file-name-handler file-remote-p
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil nil)
> | | | | 5 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | | 4 <- tramp-file-name-handler: "/ssh:detlef:"
> | | | 4 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil
> "/tmp/tramp.qgnQ01" nil) "\\readlink --canonicalize-missing
> /tmp/tramp.qgnQ01 2>/dev/null; echo tramp_exit_status $?")
> | | | | 5 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef"
> nil "/tmp/tramp.qgnQ01" nil) "echo are you awake" t t)
> | | | | 5 <- tramp-send-command: nil
> | | | 4 <- tramp-send-command: 39
> | | | 4 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | | 4 -> (tramp-file-name-handler file-symlink-p
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | | | 5 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | | | 5 -> (tramp-file-name-handler file-attributes
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | | | | 6 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | | | 6 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | | | | 6 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef"
> nil "/tmp/tramp.qgnQ01" nil) "tramp_stat_file_attributes /tmp/tramp.qgnQ01
> 2>/dev/null; echo tramp_exit_status $?")
> | | | | | 6 <- tramp-send-command: 25
> | | | | 5 <- tramp-file-name-handler: nil
> | | | 4 <- tramp-file-name-handler: nil
> | | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | 3 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | 3 -> (tramp-file-name-handler file-exists-p
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | 3 <- tramp-file-name-handler: nil
> | | 3 -> (tramp-file-name-handler file-locked-p
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | | 4 -> (tramp-file-name-handler make-lock-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | | 4 <- tramp-file-name-handler: nil
> | | 3 <- tramp-file-name-handler: nil
> | | 3 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | 3 -> (tramp-file-name-handler file-attributes
> "/ssh:detlef:/tmp/tramp.qgnQ01" integer)
> | | | 4 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | 3 <- tramp-file-name-handler: nil
> | | 3 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | 3 -> (tramp-file-name-handler file-attributes
> "/ssh:detlef:/tmp/tramp.qgnQ01" integer)
> | | | 4 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | 3 <- tramp-file-name-handler: nil
> | | 3 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | 3 -> (tramp-file-name-handler file-acl "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | 3 <- tramp-file-name-handler: nil
> | | 3 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | 3 -> (tramp-file-name-handler file-selinux-context
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | 3 <- tramp-file-name-handler: (nil nil nil nil)
> | | 3 -> (tramp-file-name-handler file-name-nondirectory
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | 3 <- tramp-file-name-handler: "tramp.qgnQ01"
> | | 3 -> (tramp-file-name-handler file-remote-p
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil nil)
> | | | 4 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | 3 <- tramp-file-name-handler: "/ssh:detlef:"
> | | 3 -> (tramp-file-name-handler lock-file
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | | 4 -> (tramp-file-name-handler file-locked-p
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | | | 5 -> (tramp-file-name-handler make-lock-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | | | 5 <- tramp-file-name-handler: nil
> | | | 4 <- tramp-file-name-handler: nil
> | | | 4 -> (tramp-file-name-handler make-lock-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | | 4 <- tramp-file-name-handler: nil
> | | | 4 -> (tramp-file-name-handler make-lock-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | | 4 <- tramp-file-name-handler: nil
> | | 3 <- tramp-file-name-handler: nil
> | | 3 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | 3 -> (tramp-file-name-handler file-modes
> "/ssh:detlef:/tmp/tramp.qgnQ01" nofollow)
> | | | 4 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | | 4 -> (tramp-file-name-handler file-attributes
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | | | 5 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | | 4 <- tramp-file-name-handler: nil
> | | 3 <- tramp-file-name-handler: nil
> | | 3 -> (tramp-file-name-handler file-name-nondirectory
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | 3 <- tramp-file-name-handler: "tramp.qgnQ01"
> | | 3 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil
> "/tmp/tramp.qgnQ01" nil) "base64 -d -i >/tmp/tramp.qgnQ01
> <<'b03f0306a9a1e716a81252ccc4134b92' 2>/dev/null; echo tramp_exit_status
> $?\nb03f0306a9a1e716a81252ccc4134b92")
> | | 3 <- tramp-send-command: 21
> | | 3 -> (tramp-file-name-handler file-name-directory
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/"
> | | 3 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp/" nil)
> | | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/"
> | | 3 -> (tramp-file-name-handler directory-file-name "/ssh:detlef:/tmp/")
> | | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp"
> | | 3 -> (tramp-file-name-handler file-modes "/ssh:detlef:/tmp" nil)
> | | | 4 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp"
> nil)
> | | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp"
> | | | 4 -> (tramp-file-name-handler file-attributes "/ssh:detlef:/tmp")
> | | | | 5 -> (tramp-file-name-handler expand-file-name "/ssh:detlef:/tmp"
> nil)
> | | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp"
> | | | | 5 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef"
> nil "/tmp" nil) "tramp_stat_file_attributes /tmp 2>/dev/null; echo
> tramp_exit_status $?")
> | | | | 5 <- tramp-send-command: 129
> | | | 4 <- tramp-file-name-handler: (t 30 0 0 (25305 58381 0 0) (25312
> 7412 0 0) (25312 7412 0 0) 135168 "drwxrwxrwt" t 3801089 (-1 . 2))
> | | 3 <- tramp-file-name-handler: 1023
> | | 3 -> (tramp-file-name-handler tramp-set-file-uid-gid
> "/ssh:detlef:/tmp/tramp.qgnQ01" 1000 1000)
> | | | 4 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil
> "/tmp/tramp.qgnQ01" nil) "chown 1000:1000 /tmp/tramp.qgnQ01")
> | | | 4 <- tramp-send-command: 1
> | | 3 <- tramp-file-name-handler: 1
> | | 3 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" "~/")
> | | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | 3 -> (tramp-file-name-handler set-file-acl
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | 4 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | 3 <- tramp-file-name-handler: nil
> | | 3 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" "~/")
> | | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | 3 -> (tramp-file-name-handler set-file-selinux-context
> "/ssh:detlef:/tmp/tramp.qgnQ01" (nil nil nil nil))
> | | 3 <- tramp-file-name-handler: nil
> | | 3 -> (tramp-file-name-handler unlock-file
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | | 4 -> (tramp-file-name-handler make-lock-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | | 4 <- tramp-file-name-handler: nil
> | | 3 <- tramp-file-name-handler: nil
> | 2 <- tramp-file-name-handler: nil
> | 2 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil
> "/home/albinus/.emacs" nil) "dd bs=1 skip=2 if=/home/albinus/.emacs count=2
> of=/tmp/tramp.qgnQ01")
> | 2 <- tramp-send-command: 72
> | 2 -> (tramp-file-name-handler file-local-copy
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | 3 -> (tramp-file-name-handler file-truename
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | | 4 -> (tramp-file-name-handler file-remote-p
> "/ssh:detlef:/tmp/tramp.qgnQ01" localname nil)
> | | | | 5 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | | 4 <- tramp-file-name-handler: "/tmp/tramp.qgnQ01"
> | | | 4 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | | 4 -> (tramp-file-name-handler file-remote-p
> "/ssh:detlef:/tmp/tramp.qgnQ01" localname nil)
> | | | | 5 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | | 4 <- tramp-file-name-handler: "/tmp/tramp.qgnQ01"
> | | | 4 -> (tramp-file-name-handler file-remote-p
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil nil)
> | | | | 5 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | | 4 <- tramp-file-name-handler: "/ssh:detlef:"
> | | | 4 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil
> "/tmp/tramp.qgnQ01" nil) "\\readlink --canonicalize-missing
> /tmp/tramp.qgnQ01 2>/dev/null; echo tramp_exit_status $?")
> | | | 4 <- tramp-send-command: 39
> | | | 4 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | | 4 -> (tramp-file-name-handler file-symlink-p
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | | | 5 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | | | 5 -> (tramp-file-name-handler file-attributes
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | | | | 6 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | | | 6 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | | | | 6 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef"
> nil "/tmp/tramp.qgnQ01" nil) "tramp_stat_file_attributes /tmp/tramp.qgnQ01
> 2>/dev/null; echo tramp_exit_status $?")
> | | | | | 6 <- tramp-send-command: 148
> | | | | 5 <- tramp-file-name-handler: (nil 1 1000 1000 (25312 7412 0 0)
> (25312 7412 0 0) (25312 7412 0 0) 2 "-rw-rw-r--" nil 3821258 (-1 . 2))
> | | | 4 <- tramp-file-name-handler: nil
> | | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | 3 -> (tramp-file-name-handler file-name-nondirectory
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | 3 <- tramp-file-name-handler: "tramp.qgnQ01"
> | | 3 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | 3 -> (tramp-file-name-handler file-attributes
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | | 4 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | 3 <- tramp-file-name-handler: (nil 1 1000 1000 (25312 7412 0 0) (25312
> 7412 0 0) (25312 7412 0 0) 2 "-rw-rw-r--" nil 3821258 (-1 . 2))
> | | 3 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil
> "/tmp/tramp.qgnQ01" nil) "base64 </tmp/tramp.qgnQ01 2>/dev/null; echo
> tramp_exit_status $?")
> | | 3 <- tramp-send-command: 26
> | | 3 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | 3 -> (tramp-file-name-handler file-modes
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | 4 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | 4 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | | 4 -> (tramp-file-name-handler file-attributes
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | | | | 5 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | | | 5 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | | 4 <- tramp-file-name-handler: (nil 1 1000 1000 (25312 7412 0 0)
> (25312 7412 0 0) (25312 7412 0 0) 2 "-rw-rw-r--" nil 3821258 (-1 . 2))
> | | 3 <- tramp-file-name-handler: 436
> | 2 <- tramp-file-name-handler: "/tmp/tramp.6ce5x9.qgnQ01"
> | 2 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | 2 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | 2 -> (tramp-file-name-handler file-directory-p
> "/ssh:detlef:/tmp/tramp.qgnQ01")
> | 2 <- tramp-file-name-handler: nil
> | 2 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | 2 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | 2 -> (tramp-file-name-handler delete-file
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | 3 -> (tramp-file-name-handler expand-file-name
> "/ssh:detlef:/tmp/tramp.qgnQ01" nil)
> | | 3 <- tramp-file-name-handler: "/ssh:detlef:/tmp/tramp.qgnQ01"
> | | 3 -> (tramp-send-command (tramp-file-name "ssh" nil nil "detlef" nil
> "/tmp/tramp.qgnQ01" nil) "rm -f /tmp/tramp.qgnQ01 2>/dev/null; echo
> tramp_exit_status $?")
> | | 3 <- tramp-send-command: 21
> | 2 <- tramp-file-name-handler: t
> 1 <- tramp-file-name-handler: ("/ssh:detlef:/home/albinus/.emacs" 2)
>

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

^ permalink raw reply	[flat|nested] 18+ messages in thread

* bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks
  2022-08-01 20:20                           ` Paul Pogonyshev
@ 2022-08-02 14:23                             ` Michael Albinus
  2024-05-20  0:04                               ` Dmitry Gutov
  0 siblings, 1 reply; 18+ messages in thread
From: Michael Albinus @ 2022-08-02 14:23 UTC (permalink / raw)
  To: Paul Pogonyshev; +Cc: 56342

Paul Pogonyshev <pogonyshev@gmail.com> writes:

Hi Paul,

> Understood, but I propose to adopt a different benchmark: number of
> remote commands.  As soon as you are not in a LAN, even not when using
> a particularly slow network, this becomes an order or two of magnitude
> more important than everything else.  E.g. with slightly slower
> commands or particularly inefficient Elisp you can make it 2-10 ms
> slower for everyone.  But with unoptimized command flow (i.e. more
> remote commands) it can be 100-500 ms slower, though not for everyone,
> but people using this over non-LAN.  I think in such cases extremes
> are more important than the average.

I agree, sending something over the wire is always slower than computing
clever caches locally.

>> And directories are also problematic for caches. As soon as something
>> changes there (creation or deletion of a file, for example), the cached
>> values of the directory must be flushed.
>
> Yeah, I suppose Tramp has no generic way to know that Magit issues
> reading commands.  Can we devise a generic interface that would tell
> Tramp: "Commands within this block will not modify file system",
> e.g. with let-binding some variable?

They will modify the file system, although sometimes only the
timestamps.

Until now we have only something similar for synchronous
processes: process-file-side-effects. I have no idea whether package
authors are aware of this, and let-bind it to nil in case of. In the
magit sources, I haven't found this variable.

> In general, it feels like Tramp flushes its caches too often or maybe
> doesn't even cache certain things at all.  I.e. it's not about those
> 10 seconds (following your advice I have even increased that).  It's
> that while serving one user-level command here (i.e. within 3 seconds
> at most), it can issue the same remote command several times, thus
> not reusing previous results.

Well, that's right. If, for example, the file modes are changed, Tramp
flushes all caches for that file, although some of them
("file-exists-p", "file-directory-p" etc) aren't affected.

> E.g. in the traces you have attached this can be seen.  The following
> two commands repeat twice:

I haven't investigated this special case yet, but last days I'm working
on exact this problem. Flushing caches shouldn't be a sledge hammer, but
fine grained, selecting the needed properties to be flushed. Let's see
where we land.

> Paul

Best regards, Michael.





^ permalink raw reply	[flat|nested] 18+ messages in thread

* bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks
  2022-08-02 14:23                             ` Michael Albinus
@ 2024-05-20  0:04                               ` Dmitry Gutov
  0 siblings, 0 replies; 18+ messages in thread
From: Dmitry Gutov @ 2024-05-20  0:04 UTC (permalink / raw)
  To: Michael Albinus, Paul Pogonyshev; +Cc: 56342

Hi Michael and Paul,

I've found this report to be relevant, since the original scenario looks 
fairly similar to the pain point I'm seeing (which is the synchronized 
delay during 'save-buffer'. C-x C-s is something I hit pretty regularly, 
so I think it's one of the scenarios to optimize first.

Almost 2 years have passed since the last message in this thread, so 
maybe you'll want to give an update, if you have particular changes in mind.

I'd like to offer some profiler output with the latest Tramp and maybe a 
few suggestions.

On 02/08/2022 17:23, Michael Albinus wrote:
>> E.g. in the traces you have attached this can be seen.  The following
>> two commands repeat twice:
> I haven't investigated this special case yet, but last days I'm working
> on exact this problem. Flushing caches shouldn't be a sledge hammer, but
> fine grained, selecting the needed properties to be flushed. Let's see
> where we land.

I was wondering whether the cache in question was useful for the case 
where we regularly change the contents and update the modification time. 
But perhaps it is, if going by the profiler output below.

Anyway, the scenario is:

1. (setq remote-file-name-inhibit-locks t) ; big QoL improvement
2. visit some file on a remote host, via /ssh:
3. insert char (e.g. by pressing RET)
4. save buffer
5. repeat steps 3 and 4 10-15 times quickly, without pause

The profiler report:

         6341  77% - command-execute
         6341  77%  - call-interactively
         6341  77%   - apply
         6341  77%    - call-interactively@ido-cr+-record-current-command
         6341  77%     - apply
         6341  77%      - #<primitive-function call-interactively>
         6150  75%       - funcall-interactively
         6134  75%        - save-buffer
         6132  75%         - basic-save-buffer
         3592  43%          - basic-save-buffer-1
         3592  43%           - basic-save-buffer-2
         3260  39%            - write-region
         3260  39%             - tramp-file-name-handler
         3260  39%              - apply
         3260  39%               - tramp-sh-file-name-handler
         3260  39%                - apply
         3260  39%                 - tramp-sh-handle-write-region
         1771  21%                  - tramp-barf-unless-okay
         1771  21%                   + tramp-send-command-and-check
         1299  15%                  - file-attributes
         1299  15%                   - tramp-file-name-handler
         1299  15%                    - apply
         1299  15%                     - tramp-sh-file-name-handler
         1299  15%                      - apply
         1299  15%                       - tramp-sh-handle-file-attributes
         1299  15%                        + 
tramp-do-file-attributes-with-stat
          171   2%                  + file-truename
            7   0%                  + #<byte-code-function 3D6>
            4   0%                  + expand-file-name
            4   0%                    write-region
            4   0%                  + tramp-message
          332   4%            + file-writable-p
         2536  31%          - verify-visited-file-modtime
         2536  31%           - tramp-file-name-handler
         2536  31%            - apply
         2536  31%             - tramp-sh-file-name-handler
         2536  31%              - apply
         2536  31%               - 
tramp-sh-handle-verify-visited-file-modtime
         2536  31%                - file-attributes
         2536  31%                 - tramp-file-name-handler
         2536  31%                  - apply
         2536  31%                   - tramp-sh-file-name-handler
         2536  31%                    - apply
         2536  31%                     - tramp-sh-handle-file-attributes
         2528  30%                      + tramp-do-file-attributes-with-stat
            4   0%                      + tramp-get-file-property

What I see here is a few things:

1. First we look at the file in verify-visited-file-modtime and then in 
write-region. It might be more economical to combine that in some script 
sent to the remote host to be executed. But that seems hard (even aside 
the coding required - it'd need a new file handler, I guess, one that 
would basically do the whole job of basic-save-buffer).

2. There are tramp-sh-handle-file-attributes calls in different branches 
that a fair amount of time gets spent in. Could those be cached, to only 
issue one call? Could a binding for 'process-file-side-effects' help?

3. The file-truename call. Curiously, it's only called by 
tramp-sh-handle-write-region. Does the handler really need to know the 
canonical file name? It seems like it'd be okay if it wrote to one of 
the symlinked names instead. Ah, looking at tramp-skeleton-write-region, 
this seems to have something to do with locking. Could we optimize this 
at least for the case when remote-file-name-inhibit-locks is set to t?

Here's also some filtered output from the Tramp debug log from *one* 
save-buffer call:

02:39:44.488432 tramp-send-command (6) # tramp_stat_file_attributes 
/home/d/dgutov/git-test/b/c/caca 2>/dev/null; echo tramp_exit_status $?
02:39:44.688011 tramp-send-command (6) # test -e 
/home/d/dgutov/git-test/b/c/ 2>/dev/null; echo tramp_exit_status $?
02:39:44.890427 tramp-send-command (6) # test -w 
/home/d/dgutov/git-test/b/c/ 2>/dev/null; echo tramp_exit_status $?
02:39:45.097458 tramp-send-command (6) # (if test -h 
"/srv/data/home/d/dgutov/git-test/b/c/caca"; then echo t; else echo nil; 
fi) && \readlink --canonicalize-missing 
/srv/data/home/d/dgutov/git-test/b/c/caca 2>/dev/null; echo 
tramp_exit_status $?
02:39:45.303095 tramp-send-command (6) # tramp_stat_file_attributes 
/home/d/dgutov/git-test/b/c/caca 2>/dev/null; echo tramp_exit_status $?
02:39:45.508024 tramp-send-command (6) # base64 -d -i 
 >/home/d/dgutov/git-test/b/c/caca <<'45aa0e36081f9f2cbcfda421e708711e' 
2>/dev/null; echo tramp_exit_status $?
02:39:45.708813 tramp-send-command (6) # tramp_stat_file_attributes 
/home/d/dgutov/git-test/b/c/caca 2>/dev/null; echo tramp_exit_status $?

It seems to stat the file (with tramp_stat_file_attributes) 3 times. One 
of these is from verify-visited-file-modtime, and two others - from 
other branches of execution.

And another verify-visited-file-modtime call (with another 
tramp-do-file-attributes-with-stat) happens whenever you type the first 
character after saving the buffer. Which also contributes to perceived 
latency.

Could these be cached by adding some new process-file-side-effects bindings?

Other things we see above is several separate 'test' calls. Not sure if 
those could be combined (by having a command return all the data 
together, and then have it cached?), but that'd be nice.





^ permalink raw reply	[flat|nested] 18+ messages in thread

end of thread, other threads:[~2024-05-20  0:04 UTC | newest]

Thread overview: 18+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2022-07-01 17:14 bug#56342: TRAMP (sh) issues way too many commands, thus being very slow over high-ping networks Paul Pogonyshev
2022-07-02 15:58 ` Michael Albinus
2022-07-02 18:14   ` Paul Pogonyshev
2022-07-03 12:16     ` Michael Albinus
2022-07-03 14:00       ` Paul Pogonyshev
2022-07-03 18:47         ` Michael Albinus
2022-07-03 19:52           ` Paul Pogonyshev
2022-07-04 11:19             ` Michael Albinus
2022-07-04 14:42               ` Paul Pogonyshev
2022-07-04 16:30                 ` Michael Albinus
2022-07-26  8:00                   ` Paul Pogonyshev
2022-07-26 14:18                     ` Michael Albinus
2022-07-26 16:17                       ` Paul Pogonyshev
2022-07-26 17:51                         ` Michael Albinus
2022-08-01 20:20                           ` Paul Pogonyshev
2022-08-02 14:23                             ` Michael Albinus
2024-05-20  0:04                               ` Dmitry Gutov
2022-07-04 10:33   ` Michael Albinus

Code repositories for project(s) associated with this public inbox

	https://git.savannah.gnu.org/cgit/emacs.git

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).