amplify testSudo flake

[jelly]

https://cockpit-logs.us-east-1.linodeobjects.com/pull-19308-20230913-142519-facee1fc-fedora-coreos-other/log.html#60
https://cockpit-logs.us-east-1.linodeobjects.com/pull-19318-20230913-133009-d662e758-fedora-coreos-other/log.html
https://cockpit-logs.us-east-1.linodeobjects.com/pull-19304-20230911-105855-919cc0ba-rhel4edge-other/log.html#53-2

[jelly]

@allisonkarlitskaya wew, this reproduces quite a lot. We have debug logs of the bridge now in the journal.

Seeing:

> warning: Peer exited with status 1
> warning: Peer exited with status 1
> warning: Peer exited with status 1
> warning: Peer exited with status 1
> warning: Peer exited with status 1
> log: fail
> warning: ListUnitsFiltered failed:  Your session has been terminated.

It seems something kills the bridge, and that's why we get terminated?

Relevant journal?

Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7fcfcc074450>
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.protocol-DEBUG: sending message 1:4!4 {'reply': [], 'id': '20'}
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7fcfcc074450>
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit._vendor.systemd_ctypes.bus-DEBUG: Doing async method call org.freedesktop.systemd1 /org/freedesktop/systemd1/unit/chronyd_2eservice org.freedesktop.DBus.Introspectable Introspect  ()
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.transports-DEBUG: Read ready on <cockpit.transports.SubprocessTransport object at 0x7fcfcbacc9d0> <cockpit.superuser.SuperuserPeer object at 0x7fcfcbb0e9d0> 19
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.transports-DEBUG:   got EOF
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.peer-DEBUG: Peer SuperuserPeer received unexpected EOF
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.transports-DEBUG: Process exited with status 1
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.peer-DEBUG: Peer SuperuserPeer exited, status 1
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.protocol-DEBUG: connection_lost
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.transports-DEBUG: won't attempt 15 to process 1732.  It exited already.
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.peer-DEBUG: Peer SuperuserPeer connection lost <class 'cockpit.peer.PeerExited'> 1
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.router-DEBUG: shutdown_endpoint(<cockpit.superuser.SuperuserPeer object at 0x7fcfcbb0e9d0>, {'problem': 'terminated', 'message': 'Peer exited with status 1'}) will close {'1:4!9', '1:2!4', '1:4!7', '1:3!2', '1:4!10', '1:4!6'}
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.protocol-DEBUG: sending message  {'command': 'close', 'channel': '1:4!9', 'problem': 'terminated', 'message': 'Peer exited with status 1'}
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7fcfcc074450>
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.router-DEBUG: router dropped channel 1:4!9
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.protocol-DEBUG: sending message  {'command': 'close', 'channel': '1:2!4', 'problem': 'terminated', 'message': 'Peer exited with status 1'}
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7fcfcc074450>
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.router-DEBUG: router dropped channel 1:2!4
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.protocol-DEBUG: sending message  {'command': 'close', 'channel': '1:4!7', 'problem': 'terminated', 'message': 'Peer exited with status 1'}
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7fcfcc074450>
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.router-DEBUG: router dropped channel 1:4!7
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.protocol-DEBUG: sending message  {'command': 'close', 'channel': '1:3!2', 'problem': 'terminated', 'message': 'Peer exited with status 1'}
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7fcfcc074450>
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.router-DEBUG: router dropped channel 1:3!2
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.protocol-DEBUG: sending message  {'command': 'close', 'channel': '1:4!10', 'problem': 'terminated', 'message': 'Peer exited with status 1'}
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7fcfcc074450>
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.router-DEBUG: router dropped channel 1:4!10
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.protocol-DEBUG: sending message  {'command': 'close', 'channel': '1:4!6', 'problem': 'terminated', 'message': 'Peer exited with status 1'}
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7fcfcc074450>
Sep 14 08:34:23 fedora-coreos-127-0-0-2-2301 ws[1656]: cockpit.router-DEBUG: router dropped channel 1:4!6

[martinpitt]

Recent case: https://cockpit-logs.us-east-1.linodeobjects.com/pull-19391-20230926-053034-8ec5062e-rhel4edge-other/log.html#59-2

[martinpitt]

This is our top flake ATM:

Current examples:

• https://cockpit-logs.us-east-1.linodeobjects.com/pull-19458-20231009-162534-6a7d8502-fedora-coreos-other/log.html
• https://cockpit-logs.us-east-1.linodeobjects.com/pull-19451-20231006-052502-3a9f5732-fedora-coreos-other/log.html
• https://cockpit-logs.us-east-1.linodeobjects.com/pull-19453-20231006-205126-07a38066-rhel4edge-other/log.html
• https://cockpit-logs.us-east-1.linodeobjects.com/pull-19449-20231006-051706-da7314c0-rhel4edge-other/log.html

[martinpitt]

@allisonkarlitskaya says that this will completely change with her ongoing work to use the current FernyTransport API in cockpit and unify the implementation of our SSH and sudo channels. Let's put this on the shelf and revisit when it still happens afterwards.

[martinpitt]

For the record: This flake still happens with @allisonkarlitskaya 's FernyTransport rewrite in PR #19668.