bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Dmitry Gutov]

I have ~/.ssh/config set up correctly enough that

ssh <user>@<host> in the terminal connects quickly (and when I Ctrl-D
out of it, it finishes with "Shared connection to <...> closed.")

But I haven't been able to make Tramp reuse the connection.

I (setq tramp-use-connection-share nil) - so it would pick up the user
settings from my ssh config - and the first 'C-x C-f /ssh:user@host:'
takes a lot of time anyway with its "Opening connection ...".

For context: I'm on a high-latency network node geographically, and
using an even slower server for this example. I.e. my ping to it is
~170ms, but the full new ssh connection takes around 4 seconds.

On a related note, are asynchronous processes supposed to use
ControlMaster when it's available? I get "Opening connection ..." for
every M-& call, for example.

In GNU Emacs 30.0.50 (build 7, x86_64-pc-linux-gnu, X toolkit, cairo
  version 1.18.0, Xaw scroll bars) of 2024-05-12 built on potemkin
Repository revision: b20d4ab374fb9b3c80b968df6acd6444f763bd40
Repository branch: master
Windowing system distributor 'The X.Org Foundation', version 11.0.12302000
System Description: Ubuntu 23.10

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Dmitry Gutov <dmitry@gutov.dev> writes:

Hi Dmitry,

> I have ~/.ssh/config set up correctly enough that
>
> ssh <user>@<host> in the terminal connects quickly (and when I Ctrl-D
> out of it, it finishes with "Shared connection to <...> closed.")
>
> But I haven't been able to make Tramp reuse the connection.
>
> I (setq tramp-use-connection-share nil) - so it would pick up the user
> settings from my ssh config - and the first 'C-x C-f /ssh:user@host:'
> takes a lot of time anyway with its "Opening connection ...".

Are you sure you have a recent Tramp? Perhaps you use Tramp from GNU
ELPA?

tramp-use-connection-share can have three different values, t, nil or
`suppress'. And in case it is nil, nothing wrt ControlMaster will be
added to the ssh call.

Could you pls set tramp-verbose to 6, rerun your test, and show the
Tramp debug buffer?

> On a related note, are asynchronous processes supposed to use
> ControlMaster when it's available? I get "Opening connection ..." for
> every M-& call, for example.

Yes, it should do the same wrt ControlMaster.

Best regards, Michael.

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Dmitry Gutov <dmitry@gutov.dev> writes:

> Hi Michael!

Hi Dmitry,

>> tramp-use-connection-share can have three different values, t, nil or
>> `suppress'. And in case it is nil, nothing wrt ControlMaster will be
>> added to the ssh call.
>
> That was the expectation. I experimented with setting ControlMaster
> settings through tramp-ssh-controlmaster-options as well - to the same
> effect - but we should probably concentrate on just one scenario in
> this report.
>
>> Could you pls set tramp-verbose to 6, rerun your test, and show the
>> Tramp debug buffer?
>
> Attached, one scenario in an 'emacs -Q'
> session. tramp-use-connection-share and tramp-verbose are the only two
> settings there.
>
> Hope there's nothing sensitive in here (it's a GNU server).

No, I don't believe so.

The Tramp ssh call looks like it should. Tramp doesn't care about
ControlMaster with your settings:

> 14:41:04.227455 tramp-maybe-open-connection (3) # Sending command ‘exec ssh -l dgutov -e none fencepost.gnu.org || exit’
> 14:41:04.227485 tramp-send-command (6) # exec ssh -l dgutov -e none fencepost.gnu.org || exit
> 14:41:06.037182 tramp-process-actions (6) # 
> Last login: Mon May 13 07:39:46 2024 from 82.102.62.129
> dgutov@fencepost:~$ 

Best regards, Michael.

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Dmitry Gutov]

Hi Michael,

On 14/05/2024 12:01, Michael Albinus wrote:

>>> tramp-use-connection-share can have three different values, t, nil or
>>> `suppress'. And in case it is nil, nothing wrt ControlMaster will be
>>> added to the ssh call.
>>
>> That was the expectation. I experimented with setting ControlMaster
>> settings through tramp-ssh-controlmaster-options as well - to the same
>> effect - but we should probably concentrate on just one scenario in
>> this report.
>>
>>> Could you pls set tramp-verbose to 6, rerun your test, and show the
>>> Tramp debug buffer?
>>
>> Attached, one scenario in an 'emacs -Q'
>> session. tramp-use-connection-share and tramp-verbose are the only two
>> settings there.
>>
>> Hope there's nothing sensitive in here (it's a GNU server).
> 
> No, I don't believe so.
> 
> The Tramp ssh call looks like it should. Tramp doesn't care about
> ControlMaster with your settings:
> 
>> 14:41:04.227455 tramp-maybe-open-connection (3) # Sending command ‘exec ssh -l dgutov -e none fencepost.gnu.org || exit’
>> 14:41:04.227485 tramp-send-command (6) # exec ssh -l dgutov -e none fencepost.gnu.org || exit
>> 14:41:06.037182 tramp-process-actions (6) #
>> Last login: Mon May 13 07:39:46 2024 from 82.102.62.129
>> dgutov@fencepost:~$

Shouldn't it then take advantage of ControlMaster, which has been 
configured for this host?

ssh logs in to the remote server very quickly from the terminal with my 
ControlMaster configuration.

But I don't see any speed improvement in Tramp operations from it. For 
example, I evaluate just 'ls' using M-& (async-shell-command), and the 
time it takes to complete doesn't seem to be affected by the contents of 
my ~/.ssh/config.

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Dmitry Gutov <dmitry@gutov.dev> writes:

> Hi Michael,

Hi Dmitry,
>> The Tramp ssh call looks like it should. Tramp doesn't care about
>> ControlMaster with your settings:
>> 
>>> 14:41:04.227455 tramp-maybe-open-connection (3) # Sending command ‘exec ssh -l dgutov -e none fencepost.gnu.org || exit’
>>> 14:41:04.227485 tramp-send-command (6) # exec ssh -l dgutov -e none fencepost.gnu.org || exit
>>> 14:41:06.037182 tramp-process-actions (6) #
>>> Last login: Mon May 13 07:39:46 2024 from 82.102.62.129
>>> dgutov@fencepost:~$
>
> Shouldn't it then take advantage of ControlMaster, which has been
> configured for this host?

It should. You could check which settings will be used by calling
'ssh -G fencepost.gnu.org'.

> ssh logs in to the remote server very quickly from the terminal with
> my ControlMaster configuration.
>
> But I don't see any speed improvement in Tramp operations from it. For
> example, I evaluate just 'ls' using M-& (async-shell-command), and the
> time it takes to complete doesn't seem to be affected by the contents
> of my ~/.ssh/config.

Sure. The connection is fast. But then, Tramp makes an initial
hand-shake, which needs some roundtrips. Set

(add-to-list 'tramp-connection-properties
             (list (regexp-quote "/ssh:fencepost.gnu.org:")
                   "direct-async-process" t))

prior connecting the host the very first time in Tramp. This should
improve the speed. Since it doesn't ask for passwords interactively, you
might configure your password via auth-source.

See the discussion in (info "(tramp)Improving performance of asynchronous
remote processes")

Best regards, Michael.

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Dmitry Gutov]

Hi Michael,

On 15/05/2024 11:17, Michael Albinus wrote:

>> Shouldn't it then take advantage of ControlMaster, which has been
>> configured for this host?
> 
> It should. You could check which settings will be used by calling
> 'ssh -G fencepost.gnu.org'.

$ ssh -G fencepost.gnu.org | grep -i control
controlmaster auto
controlpath /home/dgutov/.ssh/master-fencepost.gnu.org:22
controlpersist 600

>> ssh logs in to the remote server very quickly from the terminal with
>> my ControlMaster configuration.
>>
>> But I don't see any speed improvement in Tramp operations from it. For
>> example, I evaluate just 'ls' using M-& (async-shell-command), and the
>> time it takes to complete doesn't seem to be affected by the contents
>> of my ~/.ssh/config.
> 
> Sure. The connection is fast. But then, Tramp makes an initial
> hand-shake, which needs some roundtrips.

What gives me pause is that is there is a message in the echo area 
saying "Connecting ..." which stays there for a while.

And that the time to do this does not depend on ControlMaster being 
enabled - it's around 4 seconds either way.

Starting an asynchronous process does start a new connection, right? 
Simply logging in with ssh to fencepost without ControlMaster takes the 
same several seconds.

And if we put asynchronous processes aside: suppose I restart Emacs and 
then try to visit a remote file from history. The message

   Opening connection nil for dgutov@fencepost.gnu.org using ssh...

stays around for several seconds. And the length of time it stays around 
doesn't seem affected by my ControlMaster configuration in .ssh/config 
(I change the hostname in the config, restart Emacs, try this, change 
the hostname back, restart Emacs - and the time to connect is the same). 
So it seems like some problem remains there, which would be nice to try 
to resolve.

> Set
> 
> (add-to-list 'tramp-connection-properties
>               (list (regexp-quote "/ssh:fencepost.gnu.org:")
>                     "direct-async-process" t))
> 
> prior connecting the host the very first time in Tramp. This should
> improve the speed. Since it doesn't ask for passwords interactively, you
> might configure your password via auth-source.

Two observations:

1. First of all, it *is* faster. Thank you, a significant improvement.
2. When I invoke async-shell-command for the first time, it takes about 
a second. And the buffer has "Process *Async Shell Command* finished" at 
the end.

Then, while the *Async Shell Command* buffer exists, I invoke it a 
second time, it works even faster than that (e.g. 300ms), but at the end 
the *Async Shell Command* buffer finished with just the output, no 
"Process *Async Shell Command* finished" text at the end. If I kill the 
buffer, invoking the command takes ~1 second again.

In the first scenario (buffer does not exist), *Messages* contains this:

Tramp: Inserting 
‘/ssh:dgutov@fencepost.gnu.org:/home/d/dgutov/.tramp_history’...done
error: "Cannot resize window #<window 8 on *Messages*>"

In the second (buffer exists), just this:

-l: finished.

I should also note that when async-shell-command is invoked locally, it 
doesn't print the text "Process *Async Shell Command* finished" in 
either case.

> See the discussion in (info "(tramp)Improving performance of asynchronous
> remote processes")

I haven't tried it before partly because 
https://www.gnu.org/software/tramp/#Improving-performance-of-asynchronous-remote-processes 
still says that tramp-remote-path is not supported (I guess this has 
been fixed in the master version). And the tramp-own-remote-path thingy 
is very useful for my work scenario.

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Dmitry Gutov <dmitry@gutov.dev> writes:

> Hi Michael,

Hi Dmitry,

>>> Shouldn't it then take advantage of ControlMaster, which has been
>>> configured for this host?
>> It should. You could check which settings will be used by calling
>> 'ssh -G fencepost.gnu.org'.
>
> $ ssh -G fencepost.gnu.org | grep -i control
> controlmaster auto
> controlpath /home/dgutov/.ssh/master-fencepost.gnu.org:22
> controlpersist 600

This looks proper.

>>> ssh logs in to the remote server very quickly from the terminal with
>>> my ControlMaster configuration.
>>>
>>> But I don't see any speed improvement in Tramp operations from it. For
>>> example, I evaluate just 'ls' using M-& (async-shell-command), and the
>>> time it takes to complete doesn't seem to be affected by the contents
>>> of my ~/.ssh/config.
>> Sure. The connection is fast. But then, Tramp makes an initial
>> hand-shake, which needs some roundtrips.
>
> What gives me pause is that is there is a message in the echo area
> saying "Connecting ..." which stays there for a while.

Well, the message is there not only waiting for the network connection,
but also waiting for Tramp doing its initialization. So you cannot
compare the time with a simple "ssh ..." from the shell.

> And that the time to do this does not depend on ControlMaster being
> enabled - it's around 4 seconds either way.

Yes, because the majority of the time is spent in roundtrips during
initialization.

> And if we put asynchronous processes aside: suppose I restart Emacs
> and then try to visit a remote file from history. The message
>
>   Opening connection nil for dgutov@fencepost.gnu.org using ssh...
>
> stays around for several seconds. And the length of time it stays
> around doesn't seem affected by my ControlMaster configuration in
> .ssh/config (I change the hostname in the config, restart Emacs, try
> this, change the hostname back, restart Emacs - and the time to
> connect is the same). So it seems like some problem remains there,
> which would be nice to try to resolve.

Again, it isn't only the ControlMaster option. And it depends also,
whether there is already an existing connection, which can be reused.

> 2. When I invoke async-shell-command for the first time, it takes
> about a second. And the buffer has "Process *Async Shell Command*
> finished" at the end.
>
> Then, while the *Async Shell Command* buffer exists, I invoke it a
> second time, it works even faster than that (e.g. 300ms), but at the
> end the *Async Shell Command* buffer finished with just the output, no
> "Process *Async Shell Command* finished" text at the end. If I kill
> the buffer, invoking the command takes ~1 second again.
>
> In the first scenario (buffer does not exist), *Messages* contains this:
>
> Tramp: Inserting
> ‘/ssh:dgutov@fencepost.gnu.org:/home/d/dgutov/.tramp_history’...done
> error: "Cannot resize window #<window 8 on *Messages*>"
>
> In the second (buffer exists), just this:
>
> -l: finished.
>
> I should also note that when async-shell-command is invoked locally,
> it doesn't print the text "Process *Async Shell Command* finished" in
> either case.

The "Process ... finished" message comes from a sentinel, IIRC. Tramp
tries to handle it properly, but there might be a bug. Do you mind to
open a new bug report?

>> See the discussion in (info "(tramp)Improving performance of asynchronous
>> remote processes")
>
> I haven't tried it before partly because
> https://www.gnu.org/software/tramp/#Improving-performance-of-asynchronous-remote-processes
> still says that tramp-remote-path is not supported (I guess this has
> been fixed in the master version). And the tramp-own-remote-path
> thingy is very useful for my work scenario.

The web page refers to Tramp's stable version, which is 2.6.3 ATM (the
version in Emacs 29.3). If you build Emacs yourself, you're better to
consult the Info pages. The rerstriction you mention has been removed in
tramp.texi a while ago, and etc/NEWS says

--8<---------------cut here---------------start------------->8---
*** Direct asynchronous processes use 'tramp-remote-path'.
When a direct asynchronous process is invoked, it uses 'tramp-remote-path'
for setting the remote PATH environment variable.
--8<---------------cut here---------------end--------------->8---

Best rtegards, Michael.

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Dmitry Gutov]

Hi Michael,

On 15/05/2024 21:15, Michael Albinus wrote:

>>>> ssh logs in to the remote server very quickly from the terminal with
>>>> my ControlMaster configuration.
>>>>
>>>> But I don't see any speed improvement in Tramp operations from it. For
>>>> example, I evaluate just 'ls' using M-& (async-shell-command), and the
>>>> time it takes to complete doesn't seem to be affected by the contents
>>>> of my ~/.ssh/config.
>>> Sure. The connection is fast. But then, Tramp makes an initial
>>> hand-shake, which needs some roundtrips.
>>
>> What gives me pause is that is there is a message in the echo area
>> saying "Connecting ..." which stays there for a while.
> 
> Well, the message is there not only waiting for the network connection,
> but also waiting for Tramp doing its initialization. So you cannot
> compare the time with a simple "ssh ..." from the shell.

But it looks very similar to the time "ssh ..." takes in the shell.

Except when I set up ControlMaster for the host, "ssh ..." in the shell 
starts taking much less time (not having to establish a new connection, 
I take it).

Whereas the time it takes for Tramp to finish "Connecting ..." seems 
unchanged.

>> And that the time to do this does not depend on ControlMaster being
>> enabled - it's around 4 seconds either way.
> 
> Yes, because the majority of the time is spent in roundtrips during
> initialization.

Does that mean that, somehow, Tramp is faster at establishing the new 
connection than the terminal ssh?

Then it would make sense that the rest of the time is taken by 
additional work.

>> And if we put asynchronous processes aside: suppose I restart Emacs
>> and then try to visit a remote file from history. The message
>>
>>    Opening connection nil for dgutov@fencepost.gnu.org using ssh...
>>
>> stays around for several seconds. And the length of time it stays
>> around doesn't seem affected by my ControlMaster configuration in
>> .ssh/config (I change the hostname in the config, restart Emacs, try
>> this, change the hostname back, restart Emacs - and the time to
>> connect is the same). So it seems like some problem remains there,
>> which would be nice to try to resolve.
> 
> Again, it isn't only the ControlMaster option. And it depends also,
> whether there is already an existing connection, which can be reused.

I test and compare by restarting Emacs at the beginning of each 
scenario, or killing the existing connection anyway.

We're supposed to reuse the external connection established by 
ControlMaster, right? I mean, at least at the lower level of the 
implementation.

>> I should also note that when async-shell-command is invoked locally,
>> it doesn't print the text "Process *Async Shell Command* finished" in
>> either case.
> 
> The "Process ... finished" message comes from a sentinel, IIRC. Tramp
> tries to handle it properly, but there might be a bug. Do you mind to
> open a new bug report?

Okay, I'll do that soon-ish.

>>> See the discussion in (info "(tramp)Improving performance of asynchronous
>>> remote processes")
>>
>> I haven't tried it before partly because
>> https://www.gnu.org/software/tramp/#Improving-performance-of-asynchronous-remote-processes
>> still says that tramp-remote-path is not supported (I guess this has
>> been fixed in the master version). And the tramp-own-remote-path
>> thingy is very useful for my work scenario.
> 
> The web page refers to Tramp's stable version, which is 2.6.3 ATM (the
> version in Emacs 29.3). If you build Emacs yourself, you're better to
> consult the Info pages. The rerstriction you mention has been removed in
> tramp.texi a while ago, and etc/NEWS says
> 
> --8<---------------cut here---------------start------------->8---
> *** Direct asynchronous processes use 'tramp-remote-path'.
> When a direct asynchronous process is invoked, it uses 'tramp-remote-path'
> for setting the remote PATH environment variable.
> --8<---------------cut here---------------end--------------->8---

That makes sense, thank you.

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Dmitry Gutov <dmitry@gutov.dev> writes:

> Hi Michael,

Hi Dmitry,

>> Well, the message is there not only waiting for the network
>> connection,
>> but also waiting for Tramp doing its initialization. So you cannot
>> compare the time with a simple "ssh ..." from the shell.
>
> But it looks very similar to the time "ssh ..." takes in the shell.
>
> Except when I set up ControlMaster for the host, "ssh ..." in the
> shell starts taking much less time (not having to establish a new
> connection, I take it).
>
> Whereas the time it takes for Tramp to finish "Connecting ..." seems
> unchanged.
>
>> Yes, because the majority of the time is spent in roundtrips during
>> initialization.
>
> Does that mean that, somehow, Tramp is faster at establishing the new
> connection than the terminal ssh?
>
> Then it would make sense that the rest of the time is taken by
> additional work.
>
>> Again, it isn't only the ControlMaster option. And it depends also,
>> whether there is already an existing connection, which can be reused.
>
> I test and compare by restarting Emacs at the beginning of each
> scenario, or killing the existing connection anyway.
>
> We're supposed to reuse the external connection established by
> ControlMaster, right? I mean, at least at the lower level of the
> implementation.

If we want to go into detail, we need a clean testbed. In your tests, I
don't know whether another connection already exists which Tramp could
reuse due to your ControlMaster settings. And we need to separate the
time the "ssh ..." call takes inside Tramp, from the other time when
Tramp does some roundtrips for the initialization. We must count the
time Tramp needs when tramp-verbose has a higher level. Etc pp.

Do we need this? We have seen that Tramp doesn't touch Control* options
when you set tramp-use-connection-share to nil. And that's what this bug
report is about.

There is always place for improvement, patches welcome! But for this
purpose, there is already bug#56342.

Best regards, Michael.

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Dmitry Gutov]

Hi Michael,

On 16/05/2024 12:42, Michael Albinus wrote:

> If we want to go into detail, we need a clean testbed. In your tests, I
> don't know whether another connection already exists which Tramp could
> reuse due to your ControlMaster settings.

Like I said, it does: in the background terminal I'm using ssh with the 
same connection. But you could probably replicate the experiment without 
much trouble. Do you have access to fencepost?

> And we need to separate the
> time the "ssh ..." call takes inside Tramp, from the other time when
> Tramp does some roundtrips for the initialization. We must count the
> time Tramp needs when tramp-verbose has a higher level. Etc pp.

I could insert some (benchmark-progn ...) forms at your direction 
instead, to measure some blocks in the code. That's often a more 
expedient investigation tool.

> Do we need this? We have seen that Tramp doesn't touch Control* options
> when you set tramp-use-connection-share to nil. And that's what this bug
> report is about.

My question is, shouldn't ControlMaster be able to speed the process up, 
at least somewhat? The complaint isn't that the operation remains 
somewhat slow (though it does), but that I'm not seeing any 
statistically significant improvement from ControlMaster - which should 
seemingly be used and useful.

I'm planning to write a small article with recommendations on how to 
configure Tramp for performance in a common setup, with the options and 
explanations.

One of them does (the "direct async") - but as documented, it has some 
problems. One I've already mentioned but am yet to file a bug. Another 
is yet trickier: the REPL prompt is not rendered (IRB prompt when 
invoked inside RSpec runner - the details might not matter) with "direct 
async" but it's shown fine without "direct async". This second one, 
naturally, is harder to explain and (maybe) produce a reduced test case.

So I'm thinking if the ControlMaster can produce at least a part of this 
improvement, it should be the first recommendation in the article.

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Dmitry Gutov <dmitry@gutov.dev> writes:

> Hi Michael,

Hi Dmitry,

>> If we want to go into detail, we need a clean testbed. In your tests, I
>> don't know whether another connection already exists which Tramp could
>> reuse due to your ControlMaster settings.
>
> Like I said, it does: in the background terminal I'm using ssh with
> the same connection. But you could probably replicate the experiment
> without much trouble. Do you have access to fencepost?
>
>> And we need to separate the
>> time the "ssh ..." call takes inside Tramp, from the other time when
>> Tramp does some roundtrips for the initialization. We must count the
>> time Tramp needs when tramp-verbose has a higher level. Etc pp.
>
> I could insert some (benchmark-progn ...) forms at your direction
> instead, to measure some blocks in the code. That's often a more
> expedient investigation tool.
>
>> Do we need this? We have seen that Tramp doesn't touch Control* options
>> when you set tramp-use-connection-share to nil. And that's what this bug
>> report is about.
>
> My question is, shouldn't ControlMaster be able to speed the process
> up, at least somewhat? The complaint isn't that the operation remains
> somewhat slow (though it does), but that I'm not seeing any
> statistically significant improvement from ControlMaster - which
> should seemingly be used and useful.

Using ControlMaster or not should make a difference. If you want to
measure time, I recommend to measure only the time Tramp calls "ssh ..."
and receives the prompt. That is in the traces (even with timestamps).

1. On a fresh booted system > 2 sec:

--8<---------------cut here---------------start------------->8---
16:48:11.758022 tramp-send-command (6) # exec ssh -o ControlMaster=auto -o ControlPath=/home/albinus/.cache/emacs/tramp.%C -o ControlPersist=no -e none gandalf || exit
16:48:13.919576 tramp-process-actions (6) #
Last login: Fri May 17 16:48:11 2024 from 2002:6443:eb5:0:f832:242f:9e14:df3d
[albinus@gandalf ~]$
--8<---------------cut here---------------end--------------->8---

2. In another Emacs instance, accessing the same host < 0.2 sec:

--8<---------------cut here---------------start------------->8---
16:50:13.291729 tramp-send-command (6) # exec ssh -o ControlMaster=auto -o ControlPath=/home/albinus/.cache/emacs/tramp.%C -o ControlPersist=no -e none gandalf || exit
16:50:13.481880 tramp-process-actions (6) #
Last login: Fri May 17 16:50:11 2024 from 2002:6443:eb5:0:f832:242f:9e14:df3d
[albinus@gandalf ~]$
--8<---------------cut here---------------end--------------->8---

All other commands after this are Tramp's initialization on that host,
which doesn't depend on ControlMaster.

> I'm planning to write a small article with recommendations on how to
> configure Tramp for performance in a common setup, with the options
> and explanations.

Nice. If you like you could show me this article for comments, before
you publish. But of course, there's no obligation for you to do so.

Best regards, Michael.

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Dmitry Gutov]

Hi Michael,

On 17/05/2024 17:57, Michael Albinus wrote:

> Using ControlMaster or not should make a difference. If you want to
> measure time, I recommend to measure only the time Tramp calls "ssh ..."
> and receives the prompt. That is in the traces (even with timestamps).
> 
> 1. On a fresh booted system > 2 sec:
> 
> --8<---------------cut here---------------start------------->8---
> 16:48:11.758022 tramp-send-command (6) # exec ssh -o ControlMaster=auto -o ControlPath=/home/albinus/.cache/emacs/tramp.%C -o ControlPersist=no -e none gandalf || exit
> 16:48:13.919576 tramp-process-actions (6) #
> Last login: Fri May 17 16:48:11 2024 from 2002:6443:eb5:0:f832:242f:9e14:df3d
> [albinus@gandalf ~]$
> --8<---------------cut here---------------end--------------->8---
> 
> 2. In another Emacs instance, accessing the same host < 0.2 sec:
> 
> --8<---------------cut here---------------start------------->8---
> 16:50:13.291729 tramp-send-command (6) # exec ssh -o ControlMaster=auto -o ControlPath=/home/albinus/.cache/emacs/tramp.%C -o ControlPersist=no -e none gandalf || exit
> 16:50:13.481880 tramp-process-actions (6) #
> Last login: Fri May 17 16:50:11 2024 from 2002:6443:eb5:0:f832:242f:9e14:df3d
> [albinus@gandalf ~]$
> --8<---------------cut here---------------end--------------->8---
> 
> All other commands after this are Tramp's initialization on that host,
> which doesn't depend on ControlMaster.

Thank you.

It seems that ControlMaster does in fast get used - it shaves the 
initial connection from ~3 seconds down to ~1 second or a little less.

I suppose it's just that the remainder of the process takes a while too 
(additional 3 seconds for something as simple as 'ls'), so the 
difference is not as pronounced.

Perhaps it'd make sense to adjust the logging so that the first 
"...done" is printed right after the connection is established.

At the moment it looks like this:

05:26:32.739888 tramp-send-command (6) # exec ssh -q -l dgutov -e none 
fencepost.gnu.org || exit
...
Last login: Fri May 17 22:25:53 2024 from 82.102.62.129
dgutov@fencepost:~$
05:26:33.297344 tramp-process-actions (3) # Waiting for prompts from 
remote shell...done
...
05:26:35.959207 tramp-maybe-open-connection (3) # Opening connection 
*Async Shell Command* for dgutov@fencepost.gnu.org using ssh...done

I'll do some more testing, just in case (on another system).

>> I'm planning to write a small article with recommendations on how to
>> configure Tramp for performance in a common setup, with the options
>> and explanations.
> 
> Nice. If you like you could show me this article for comments, before
> you publish.

Of course, no problem.

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Dmitry Gutov <dmitry@gutov.dev> writes:

> Hi Michael,

Hi Dmitry,

> Perhaps it'd make sense to adjust the logging so that the first
> "...done" is printed right after the connection is established.

That is already the case. Tramp uses a (slightly modified version) of
the progress reporter. You'll see two invocations of it, "Opening
connection ..." and "Waiting for prompts ...". They are cascaded. When
the second, inner progress reporter finishes, ssh has returned the prompt.

--8<---------------cut here---------------start------------->8---
13:01:30.750374 tramp-maybe-open-connection (3) # Opening connection nil for gandalf using ssh...
13:01:30.794366 tramp-send-command (6) # exec ssh -o ControlMaster=auto -o ControlPath=/home/albinus/.cache/emacs/tramp.%C -o ControlPersist=no -e none gandalf || exit
13:01:30.794769 tramp-process-actions (3) # Waiting for prompts from remote shell...
13:01:32.633372 tramp-process-actions (6) #
Last login: Sat May 18 13:01:31 2024 from 2002:6443:eb5:0:f832:242f:9e14:df3d
[albinus@gandalf ~]$
13:01:32.633453 tramp-process-actions (3) # Waiting for prompts from remote shell...done
13:01:35.830072 tramp-maybe-open-connection (3) # Opening connection nil for gandalf using ssh...done
--8<---------------cut here---------------end--------------->8---

One modification of Tramp is, that in case of cascaded progress reportes
only the outer one is visible in the echo area.

Best regards, Michael.

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Dmitry Gutov]

Hi Michael,

On 18/05/2024 14:19, Michael Albinus wrote:
> Dmitry Gutov <dmitry@gutov.dev> writes:

>> Perhaps it'd make sense to adjust the logging so that the first
>> "...done" is printed right after the connection is established.
> 
> That is already the case. Tramp uses a (slightly modified version) of
> the progress reporter. You'll see two invocations of it, "Opening
> connection ..." and "Waiting for prompts ...". They are cascaded. When
> the second, inner progress reporter finishes, ssh has returned the prompt.

That's really what I meant: when looking at the echo area, I'm given the 
impression that the connection itself takes longer than it really does - 
because the "outer" phase said "Opening connection", and it finishes 
much later than the opening of the connection takes.

> --8<---------------cut here---------------start------------->8---
> 13:01:30.750374 tramp-maybe-open-connection (3) # Opening connection nil for gandalf using ssh...
> 13:01:30.794366 tramp-send-command (6) # exec ssh -o ControlMaster=auto -o ControlPath=/home/albinus/.cache/emacs/tramp.%C -o ControlPersist=no -e none gandalf || exit
> 13:01:30.794769 tramp-process-actions (3) # Waiting for prompts from remote shell...
> 13:01:32.633372 tramp-process-actions (6) #
> Last login: Sat May 18 13:01:31 2024 from 2002:6443:eb5:0:f832:242f:9e14:df3d
> [albinus@gandalf ~]$
> 13:01:32.633453 tramp-process-actions (3) # Waiting for prompts from remote shell...done
> 13:01:35.830072 tramp-maybe-open-connection (3) # Opening connection nil for gandalf using ssh...done
> --8<---------------cut here---------------end--------------->8---
> 
> One modification of Tramp is, that in case of cascaded progress reportes
> only the outer one is visible in the echo area.

That by itself seems reasonable - chattiness in the echo area can be a 
problem by itself.

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Dmitry Gutov <dmitry@gutov.dev> writes:

> Hi Michael,

Hi Dmitry,

>> One modification of Tramp is, that in case of cascaded progress
>> reportes only the outer one is visible in the echo area.
>
> That by itself seems reasonable - chattiness in the echo area can be a
> problem by itself.

So I suppose we're done? The bug can be closed?

Best regards, Michael.

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Dmitry Gutov]

On 18/05/2024 20:00, Michael Albinus wrote:
> Dmitry Gutov<dmitry@gutov.dev>  writes:
> 
>> Hi Michael,
> Hi Dmitry,
> 
>>> One modification of Tramp is, that in case of cascaded progress
>>> reportes only the outer one is visible in the echo area.
>> That by itself seems reasonable - chattiness in the echo area can be a
>> problem by itself.
> So I suppose we're done? The bug can be closed?

Do you perhaps see a way to change messaging (to the echo area) that 
would remove the impression that the connection is still being 
established after it has already been established (and we're in the 
process of additional Tramp connection initialization)?

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

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

Dmitry Gutov <dmitry@gutov.dev> writes:

Hi Dmitry,

> Do you perhaps see a way to change messaging (to the echo area) that
> would remove the impression that the connection is still being
> established after it has already been established (and we're in the
> process of additional Tramp connection initialization)?

Tramp messages are grouped in different levels. If we want more
fine-grained information, the respective message should have a higher
level. Tramp is thrifty with level 3 messages.

However, per default Tramp shows only messages up to level 3. A message
with a higher level wouldn't be seen by the majority of the users.

What if we document the meaning of the "Opening connection ..." message
instead? Something like


[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: Type: text/x-patch, Size: 793 bytes --]

diff --git a/doc/misc/tramp.texi b/doc/misc/tramp.texi
index d1c58d83aeb..45be1e27931 100644
--- a/doc/misc/tramp.texi
+++ b/doc/misc/tramp.texi
@@ -2940,6 +2940,13 @@ Ssh setup
 set to @code{t} or @code{suppress}, @command{plink} is called with the
 option @option{-share} or @option{-noshare}, respectively.

+@strong{Note} that the @value{tramp} message @samp{Opening connection
+...} in the echo area spans not only the time until @command{ssh} or
+@command{plink} return the echo prompt.  It includes also the time for
+initialization @value{tramp} performs on the remote host.  Therefore,
+the effect of the @code{tramp-use-connection-share} setting isn't
+determined by this time period completely.
+

 @subsection Configure direct copying between two remote servers


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


Best regards, Michael.

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Dmitry Gutov]

On 18/05/2024 20:47, Michael Albinus wrote:
> Dmitry Gutov <dmitry@gutov.dev> writes:
> 
> Hi Dmitry,
> 
>> Do you perhaps see a way to change messaging (to the echo area) that
>> would remove the impression that the connection is still being
>> established after it has already been established (and we're in the
>> process of additional Tramp connection initialization)?
> 
> Tramp messages are grouped in different levels. If we want more
> fine-grained information, the respective message should have a higher
> level. Tramp is thrifty with level 3 messages.
> 
> However, per default Tramp shows only messages up to level 3. A message
> with a higher level wouldn't be seen by the majority of the users.
> 
> What if we document the meaning of the "Opening connection ..." message
> instead? Something like

It's probably an improvement.

But I haven't read the entirely of the Tramp manual myself, so this 
section, however well-written, likely wouldn't have helped me.

Here's two potential alternatives:

1. Somehow have a message that only spans the time the connection is 
established, and don't print the rest by default (the user will note 
when the action finished anyway, and there likely will be other messages 
corresponding to different operations - copying a file, opening it, 
etc). I'm not sure how to fit that into the described framework, but 
what if the new message was level 3 and the current was moved to level 4?

2. Change the current text's message so it doesn't say "Opening 
connection" but refers to something more complex like "Connection 
finalization" - that one still not very specific, perhaps you'll have a 
better idea?

1 implies 2, but they might also be combined.

> diff --git a/doc/misc/tramp.texi b/doc/misc/tramp.texi
> index d1c58d83aeb..45be1e27931 100644
> --- a/doc/misc/tramp.texi
> +++ b/doc/misc/tramp.texi
> @@ -2940,6 +2940,13 @@ Ssh setup
>   set to @code{t} or @code{suppress}, @command{plink} is called with the
>   option @option{-share} or @option{-noshare}, respectively.
> 
> +@strong{Note} that the @value{tramp} message @samp{Opening connection
> +...} in the echo area spans not only the time until @command{ssh} or
> +@command{plink} return the echo prompt.  It includes also the time for
> +initialization @value{tramp} performs on the remote host.  Therefore,
> +the effect of the @code{tramp-use-connection-share} setting isn't
> +determined by this time period completely.
> +
> 
>   @subsection Configure direct copying between two remote servers
> 
> 
> 
> Best regards, Michael.

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

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

Dmitry Gutov <dmitry@gutov.dev> writes:

Hi Dmitry,

> 1. Somehow have a message that only spans the time the connection is
> established, and don't print the rest by default (the user will note
> when the action finished anyway, and there likely will be other
> messages corresponding to different operations - copying a file,
> opening it, etc). I'm not sure how to fit that into the described
> framework, but what if the new message was level 3 and the current was
> moved to level 4?

I've changed it such a way that the message "Opening connection ..."
appears only until the prompt from remote is seen. For the rest, there
will be another message "Setup connection ...".

As bonus, the "Opening connection ..." message appears now for every hop
in the multi-hop case. This is new.

Could you pls check the appended patch?

Best regards, Michael.


[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: Type: text/x-patch, Size: 2887 bytes --]

diff --git a/lisp/tramp-sh.el b/lisp/tramp-sh.el
index 569922a9..1233c635 100644
--- a/lisp/tramp-sh.el
+++ b/lisp/tramp-sh.el
@@ -5263,18 +5263,7 @@ connection if a previous connection has died for some reason."
       ;; New connection must be opened.
       (condition-case err
 	  (unless (process-live-p p)
-	    (with-tramp-progress-reporter
-		vec 3
-		(if (tramp-string-empty-or-nil-p (tramp-file-name-user vec))
-		    (format "Opening connection %s for %s using %s"
-			    process-name
-			    (tramp-file-name-host vec)
-			    (tramp-file-name-method vec))
-		  (format "Opening connection %s for %s@%s using %s"
-			  process-name
-			  (tramp-file-name-user vec)
-			  (tramp-file-name-host vec)
-			  (tramp-file-name-method vec)))
+	    (progn

 	      (catch 'uname-changed
 		;; Start new process.
@@ -5424,15 +5413,23 @@ connection if a previous connection has died for some reason."
 			" "))

 		      ;; Send the command.
-		      (tramp-message vec 3 "Sending command `%s'" command)
-		      (tramp-send-command vec command t t)
-		      (tramp-process-actions
-		       p vec
-		       (min
-			pos (with-current-buffer (process-buffer p) (point-max)))
-		       tramp-actions-before-shell connection-timeout)
-		      (tramp-message
-		       vec 3 "Found remote shell prompt on `%s'" l-host)
+		      (with-tramp-progress-reporter
+			  vec 3
+			  (if (tramp-string-empty-or-nil-p l-user)
+			      (format "Opening connection %s for %s using %s"
+				      process-name l-host l-method)
+			    (format "Opening connection %s for %s@%s using %s"
+				    process-name l-user l-host l-method))
+
+			(tramp-message vec 3 "Sending command `%s'" command)
+			(tramp-send-command vec command t t)
+			(tramp-process-actions
+			 p vec
+			 (min
+			  pos (with-current-buffer (process-buffer p) (point-max)))
+			 tramp-actions-before-shell connection-timeout)
+			(tramp-message
+			 vec 3 "Found remote shell prompt on `%s'" l-host))

 		      ;; Next hop.
 		      (setq options ""
@@ -5446,7 +5443,18 @@ connection if a previous connection has died for some reason."
 		     #'tramp-timeout-session vec))

 		  ;; Make initial shell settings.
-		  (tramp-open-connection-setup-interactive-shell p vec)
+		  (with-tramp-progress-reporter
+		      vec 3
+		      (if (tramp-string-empty-or-nil-p
+			   (tramp-file-name-user vec))
+			  (format "Setup connection %s for %s using %s"
+				  process-name (tramp-file-name-host vec)
+				  (tramp-file-name-method vec))
+			(format "Setup connection %s for %s@%s using %s"
+				process-name (tramp-file-name-user vec)
+				(tramp-file-name-host vec)
+				(tramp-file-name-method vec)))
+		    (tramp-open-connection-setup-interactive-shell p vec))

 		  ;; Mark it as connected.
 		  (tramp-set-connection-property p "connected" t)))))

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Dmitry Gutov]

Hi Michael,

On 23/05/2024 19:25, Michael Albinus wrote:

> I've changed it such a way that the message "Opening connection ..."
> appears only until the prompt from remote is seen. For the rest, there
> will be another message "Setup connection ...".
> 
> As bonus, the "Opening connection ..." message appears now for every hop
> in the multi-hop case. This is new.
> 
> Could you pls check the appended patch?

It's working well, thank you.

A minor downside is more messages, but at level 3 Tramp is fairly chatty 
anyway - so people who would be bothered by it should reduce the value 
of 'tramp-verbose'. But now the connection process looks more clear.

Best regards,
Dmitry

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Version: 30.1

Dmitry Gutov <dmitry@gutov.dev> writes:

> Hi Michael,

Hi Dmitry,

>> I've changed it such a way that the message "Opening connection ..."
>> appears only until the prompt from remote is seen. For the rest, there
>> will be another message "Setup connection ...".
>> As bonus, the "Opening connection ..." message appears now for every
>> hop
>> in the multi-hop case. This is new.
>> Could you pls check the appended patch?
>
> It's working well, thank you.

Thanks for the feedback. Pushed to master, closing the bug.

> A minor downside is more messages, but at level 3 Tramp is fairly
> chatty anyway - so people who would be bothered by it should reduce
> the value of 'tramp-verbose'. But now the connection process looks
> more clear.

You cannot have both: dividing the message into two different ones, and
not making Tramp more chatty. And if you change the message level of
"Setup connection ..." to something different, there will be a quiet
Tramp saying "Opening connection ... done" w/o returning control to the
user for a while. Another source of complaints I like to avoid.

The change, that Tramp says now "Opening connection ..." for every hop
in a multi-hop environment is an advantage I believe. You have a better
view on where Tramp is working (and maybe being blocked).

> Best regards,
> Dmitry

Best regards, Michael.

bug#70901: 30.0.50; Tramp doesn't use ControlMaster even with (setq tramp-use-connection-share nil)

[Dmitry Gutov]

On 15/05/2024 22:55, Dmitry Gutov wrote:
>>> I should also note that when async-shell-command is invoked locally,
>>> it doesn't print the text "Process *Async Shell Command* finished" in
>>> either case.
>>
>> The "Process ... finished" message comes from a sentinel, IIRC. Tramp
>> tries to handle it properly, but there might be a bug. Do you mind to
>> open a new bug report?
> 
> Okay, I'll do that soon-ish.

Please see bug#71049 and also bug#71050.