Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]


Groups > linux.debian.user > #245615

Re: Weird delay in ssh login

From Stefan Monnier <monnier@iro.umontreal.ca>
Newsgroups linux.debian.user
Subject Re: Weird delay in ssh login
Date 2022-02-22 14:50 +0100
Message-ID <DTDId-3AaI-7@gated-at.bofh.it> (permalink)
References <DTr4l-3sej-1@gated-at.bofh.it> <DTv7X-3uGY-3@gated-at.bofh.it>
Organization linux.* mail to news gateway

Show all headers | View raw


>> The connection looks like:
>> 
>>     % ssh -v ...
>>     [...]
>>     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]
>>     [ !!! a bit more than 1m30s delay here !!! ]
>
> This smells like your VM's ssh server is trying to reverse-resolve
> the client's IP address to a name until the resolver times out.

My intuition also suggests this possibility but I tried to put `UseDNS
no` in /etc/ssh/sshd_config and it made no difference.

But this prompted me to try and increase sshd's logging to `DEBUG3` and
now I do something apparently related in the log: right when the delay
ends I get:

    Feb 22 08:43:20 ... systemd[1]: user@1001.service: start operation timed out. Terminating.
    Feb 22 08:43:20 ... systemd[1]: user@1001.service: Main process exited, code=exited, status=1/FAILURE
    Feb 22 08:43:20 ... systemd[1]: user@1001.service: Killing process 3659208 (gpgconf) with signal SIGKILL.
    Feb 22 08:43:20 ... systemd[1]: user@1001.service: Killing process 3659209 (awk) with signal SIGKILL.
    Feb 22 08:43:20 ... systemd[1]: user@1001.service: Killing process 3659214 (dirmngr) with signal SIGKILL.
    Feb 22 08:43:20 ... systemd[1]: user@1001.service: Failed with result 'timeout'.
    Feb 22 08:43:20 ... systemd[1]: user@1001.service: Unit process 3659208 (gpgconf) remains running after unit stopped.
    Feb 22 08:43:20 ... systemd[1]: user@1001.service: Unit process 3659209 (awk) remains running after unit stopped.
    Feb 22 08:43:20 ... systemd[1]: user@1001.service: Unit process 3659214 (dirmngr) remains running after unit stopped.
    Feb 22 08:43:20 ... systemd[1]: Failed to start User Manager for UID 1001.
    Feb 22 08:43:20 ... systemd[1]: Started Session 50020 of user <USERNAME>.

Any idea what that systemd's "start operation timed out" might be about
or how to track it down?


        Stefan

Back to linux.debian.user | Previous | Next — Previous in thread | Next in thread | Find similar | Unroll thread


Thread

Weird delay in ssh login Stefan Monnier <monnier@iro.umontreal.ca> - 2022-02-22 01:20 +0100
  Re: Weird delay in ssh login <tomas@tuxteam.de> - 2022-02-22 05:40 +0100
    Re: Weird delay in ssh login Stefan Monnier <monnier@iro.umontreal.ca> - 2022-02-22 14:50 +0100
      Re: Weird delay in ssh login <tomas@tuxteam.de> - 2022-02-22 20:40 +0100

csiph-web