openssh bugs - Oct 2020 - [Bug 3220] New: Possible bug if ControlMaster + ControlPersist and `-t`

https://bugzilla.mindrot.org/show_bug.cgi?id=3220

            Bug ID: 3220
           Summary: Possible bug if ControlMaster + ControlPersist and
                    `-t`
           Product: Portable OpenSSH
           Version: 8.4p1
          Hardware: Other
                OS: Linux
            Status: NEW
          Severity: enhancement
          Priority: P5
         Component: ssh
          Assignee: unassigned-bugs at mindrot.org
          Reporter: mikko.rantalainen at peda.net

Steps to reproduce:

$ cat ~/.ssh/config
ControlMaster auto
ControlPath   ~/.ssh/connections/%r@%h:%p
ControlPersist 1

Host workstation
        HostName remote.example.com
        HostKeyAlias workstation
        ForwardX11 yes
        ForwardX11Timeout 10h
        AddKeysToAgent yes
        ForwardAgent yes

With two local terminal sessions A and B.

A: ssh workstation
B: ssh workstation
A: logout

The ssh connection to workstation is immediately completed but stderr
gets an extra message

  Shared connection to remote.example.com closed.

This is problematic for two reasons:

(1) The message is incorrect. The shared connection is in fact still
running because connection in terminal B is still using it. The message
should say "Disconnected from shared connection to %s".

(2) The whole message is only suitable for debugging and should not be
emitted in normal cases. I understand that it would be nice with `-v`.

The problematic code is at
https://github.com/openssh/openssh-portable/blob/396d32f3a1a16e54df2a76b2a9b237868580dcbe/mux.c#L2081

Note that all the other mux related messages are emitted with debug1:

ssh -v workstation
...
debug1: Authentication succeeded (publickey).
Authenticated to remote.example.com ([1.2.3.4]:22).
debug1: setting up multiplex master socket
debug1: channel 0: new
[/home/USER/.ssh/connections/USER at remote.example.com:22]
debug1: control_persist_detach: backgrounding master process
debug1: forking to background
debug1: Entering interactive session.
debug1: pledge: id
debug1: multiplexing control connection
debug1: channel 1: new [mux-control]
debug1: channel 2: new [client-session]
debug1: client_input_global_request: rtype hostkeys-00 at openssh.com
want_reply 0
debug1: Requesting X11 forwarding with authentication spoofing.
debug1: Requesting authentication agent forwarding.
debug1: Sending environment.
...
debug1: mux_client_request_session: master session id: 2

As a result, I would suggest that the above code should be fixed to
emit
the message at level debug1 only AND the actual message content should
be fixed, too.

Note that the actual verbose output already says during disconnect
...
debug1: client_input_channel_req: channel 2 rtype exit-status reply 0
debug1: client_input_channel_req: channel 2 rtype eow at openssh.com reply
0
debug1: channel 2: free: client-session, nchannels 3
debug1: channel 1: free: mux-control, nchannels 2
Shared connection to remote.example.com closed.
USER at LOCALDOMAIN:~ $ debug1: ControlPersist timeout expired
debug1: channel 0: free:
/home/USER/.ssh/connections/USER at remote.example.com:22, nchannels 1
Transferred: sent 3684, received 3904 bytes, in 158.6 seconds
Bytes per second: sent 23.2, received 24.6
debug1: Exit status -1

Note how the message in question is emitted and ssh process ends (local
prompt is displayed) before ControlPersist timout actually happens.

-- 
You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3220

Mikko Rantalainen <mikko.rantalainen at peda.net> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
            Version|8.4p1                       |7.6p1

-- 
You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3220

--- Comment #1 from Mikko Rantalainen <mikko.rantalainen at peda.net> ---
See also: https://unix.stackexchange.com/a/203346/20336

-- 
You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3220

Damien Miller <djm at mindrot.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |djm at mindrot.org

--- Comment #2 from Damien Miller <djm at mindrot.org> ---
I'm not seeing a problem here. The message is sent to stderr, IMO
accurate and can be suppressed using -q/Loglevel=quiet

-- 
You are receiving this mail because:
You are watching someone on the CC list of the bug.
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3220

--- Comment #3 from Mikko Rantalainen <mikko.rantalainen at peda.net>
---
> I'm not seeing a problem here.
[About issue (2):]
All the other messages related to mux handling are debug1:

debug1: setting up multiplex master socket
debug1: control_persist_detach: backgrounding master process
debug1: forking to background

Why does this one specific message should be silenced only with
Loglevel=quiet?

I'd expect stderr (literally "standard error stream") to stay
quiet by
*default* unless there is at least one error. If I use verbose log
level, then sure, emit these messages.
> The message is sent to stderr, IMO accurate [...]
[About issue (1):]
Did you understand that that the shared connection *is not closed*
despite the fact that the message says so? The process emitting that
message is detaching from the shared connection but the shared
connection is active and will not be closed because of process "B" in
the example still using it.


My point is that (1) the message is incorrect and (2) the message is
not worth emitting unless verbose log is requested. With the current
log level, even if you disable all warnings, errors and fatal
errors(!), this message is still emitted.

If you disagree with either (1) or (2), could you elaborate your
reasoning?

-- 
You are receiving this mail because:
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3220

Damien Miller <djm at mindrot.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
         Resolution|---                         |WONTFIX
             Status|NEW                         |RESOLVED

--- Comment #4 from Damien Miller <djm at mindrot.org> ---
We don't plan to change this behaviour

-- 
You are receiving this mail because:
You are watching someone on the CC list of the bug.
You are watching the assignee of the bug.