Howdy, Stranger!

It looks like you're new here. If you want to get involved, click one of these buttons!

Sign In Register

Quick Links


Categories

In this Discussion

› › Help with slow SSH connection after authentication
New on LowEndTalk? Please Register and read our Community Rules.

All new Registrations are manually reviewed and approved, so a short delay after registration may occur before your account becomes active.

Help with slow SSH connection after authentication

Daniel15Daniel15 Veteran
in General

I have a few VPSes where SSH'ing into them can take a minute or so before I get a prompt. I connected with ssh -vvv and it hangs after authentication succeeds, so it's none of the usual stuff (UseDNS no, disabling GSSAPI, etc).

In the logs, I see this:

debug1: Authentication succeeded (publickey).
Authenticated to xxxx.example.com ([2a01:.......]:22).
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug3: send packet: type 90
debug1: Requesting [email protected]
debug3: send packet: type 80
debug1: Entering interactive session.
debug1: pledge: network
debug1: ENABLE_VIRTUAL_TERMINAL_INPUT is supported. Reading the VTSequence from console
debug3: This windows OS supports conpty
debug1: ENABLE_VIRTUAL_TERMINAL_PROCESSING is supported. Console supports the ansi parsing
debug3: Successfully set console output code page from:65001 to 65001
debug3: Successfully set console input code page from:437 to 65001

then it hangs for a while, then it continues like normal:

debug3: send packet: type 80
debug3: send packet: type 80
debug3: receive packet: type 80
debug1: client_input_global_request: rtype [email protected] want_reply 0
debug3: receive packet: type 4
debug1: Remote: /home/daniel/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
debug3: receive packet: type 4
debug1: Remote: /home/daniel/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
debug3: receive packet: type 91
debug2: channel_input_open_confirmation: channel 0: callback start

and connects instantly after that.

The actual session is fine, but I can't figure out what's happening during the hang when initially connecting.

Any ideas?

Comments

  • DPDP Administrator, The Domain Guy

    Assuming you're using bash, have you tried to connect using a different shell (ssh -t user@host /bin/sh) instead?

  • Daniel15Daniel15 Veteran

    @DP said:
    Assuming you're using bash, have you tried to connect using a different shell (ssh -t user@host /bin/sh) instead?

    Same issue, unfortunately. Even with /bin/false it's slow:

    daniel@Daniel-PC:~$ time ssh -t [email protected] /bin/false
Connection to example.com closed.

real    1m2.394s
user    0m0.000s
sys     0m0.016s
  • DPDP Administrator, The Domain Guy

    @Daniel15 said:

    @DP said:
    Assuming you're using bash, have you tried to connect using a different shell (ssh -t user@host /bin/sh) instead?

    Same issue, unfortunately. Even with /bin/false it's slow:

    daniel@Daniel-PC:~$ time ssh -t [email protected] /bin/false
Connection to example.com closed.

real    1m2.394s
user    0m0.000s
sys     0m0.016s

    Have you tried to ssh into a fresh/new (test) account?

    Just to rule out if it has anything to do with your current user's shell-related scripts.

  • Daniel15Daniel15 Veteran

    It's a newly-provisioned OpenVZ VPS with no customizations made other than adding my SSH keys and disabling password authentication. :confused:

  • rincewindrincewind Member

    Are you running ssh.socket? Check systemctl -a | grep ssh. That sometimes causes headaches.

    Also do a strace on your sshd server before starting an ssh connect

    root@backup44:~# ps ax | grep ssh
    290 ?        Ss     0:00 sshd: /usr/sbin/sshd -D [listener] 0 of 10-100 startups
  11455 ?        Ss     0:00 sshd: root@pts/0
  11566 ?        Ss     0:00 sshd: root@pts/1
root@backup44:~# strace -p 290

    On a separate console, do ssh again and check the trace

    Thanked by 1Daniel15
  • Daniel15Daniel15 Veteran
    edited October 2023

    @rincewind said: Are you running ssh.socket? Check systemctl -a | grep ssh. That sometimes causes headaches.

    I'm using ssh.service not ssh.socket.

    @rincewind said: Also do a strace on your sshd server before starting an ssh connect

    I just tried strace but unfortunately SSH seems to fork to the child process before the hang, so there's nothing useful in the trace

    Edit: I started an strace on the child process while it was hung, but there was no output until after the hang. I'm not sure how to attach to it with strace as soon as it's spawned to get the initial output.

    Edit 2: Through strace, I noticed it writing something that looks like a log immediately after the hang:

    getpid()                                = 798
sendto(3, "<83>Oct 23 07:31:03 sshd[798]: p"..., 104, MSG_NOSIGNAL, NULL, 0) = 104
close(5)                                = 0

    I checked the systemd journal and this is the full message:

    Oct 23 07:23:09 bg02 sshd[772]: pam_unix(sshd:session): session opened for user daniel(uid=1000) by (uid=0)
Oct 23 07:25:09 bg02 sshd[772]: pam_systemd(sshd:session): Failed to create session: Connection timed out

    Now to figure out what connection is timing out...

  • rincewindrincewind Member
    edited October 2023

    strace -ff -p <pid>
    -ff follows forks and shows child output separately

    Thanked by 3Daniel15 DP 0xC7
  • rincewindrincewind Member

    Also try ltrace -f -p <pid>. ltrace traces library calls. Again -f is to follow forks

    Thanked by 2Daniel15 0xC7
  • Daniel15Daniel15 Veteran
    edited October 2023

    @rincewind said:
    strace -ff -p <pid>
    -ff follows forks and shows child output separately

    @rincewind Perfect, thank you!! Looks like it's hanging on a DBUS call. It opens a socket connection to /run/dbus/system_bus_socket and writes data to it, then seems to fail with an error:

    [pid   855] recvmsg(5, {msg_namelen=0}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable)

    immediately before the hang. This error in the systemd journal

    Oct 23 07:25:09 bg02 sshd[772]: pam_systemd(sshd:session): Failed to create session: Connection timed out

    is immediately after the hang.

    I just uninstalled DBUS (nothing else on this system depends on DBUS) and libpam-systemd which seemed to fix the hang, and logging in still works fine. ¯\_(ツ)_/¯

    apt remove dbus dbus-user-session libpam-systemd

    I guess I should figure out the actual fix in case I ever need DBUS on this server, but this will do for now. Thanks for your help!!

    @rincewind said:
    Also try ltrace -f -p <pid>. ltrace traces library calls. Again -f is to follow forks

    Unfortunately there was way too much output from ltrace due to all the string manipulation performed by the crypto algorithms.

    Thanked by 1rincewind
  • rincewindrincewind Member

    Cool! BTW, both strace and ltrace have options to filter on regex expressions. ltrace may be the way if you want to dig deeper, but its output is really hairy.

  • TimboJonesTimboJones Member

    Give up openvz, it ain't worth the hassles.

    Firewalld would break regularly for openvz and dbus was often involved. It just exists to break shit and force shitty kludges to be implemented.

    Not having full kernel module permissions is a fucking nightmare and should be taken out back and shot.

    tl;dr my money is on openvz module permission shit.

    Thanked by 2ScreenReader Daniel15
  • Daniel15Daniel15 Veteran

    @TimboJones I'd love to not use OpenVZ, but a bunch of the VPSes I use on dnstools.ws are NAT VPSes, and most of those use OpenVZ.

Sign In or Register to comment.