Bug 2433 - please add debug output when resolving
Summary: please add debug output when resolving
Status: CLOSED FIXED
Alias: None
Product: Portable OpenSSH
Classification: Unclassified
Component: ssh (show other bugs)
Version: 6.7p1
Hardware: Other Linux
: P5 enhancement
Assignee: Assigned to nobody
URL:
Keywords:
Depends on:
Blocks: V_7_2
  Show dependency treegraph
 
Reported: 2015-07-24 02:50 AEST by Vincent Lefevre
Modified: 2016-08-02 10:41 AEST (History)
1 user (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Vincent Lefevre 2015-07-24 02:50:32 AEST
There's missing debug output when using -vvv, which makes finding the cause of a problem harder, like below.

I often get a 5-second or 10-second delay *before* the connection. For instance:

0.000008 OpenSSH_6.7p1 Debian-6, OpenSSL 1.0.2d 9 Jul 2015
0.000071 debug1: Reading configuration data /home/vinc17/.ssh/config
0.000083 debug1: /home/vinc17/.ssh/config line 88: Applying options for ioooi
0.000092 debug1: /home/vinc17/.ssh/config line 374: Applying options for *
0.000099 debug1: Reading configuration data /etc/ssh/ssh_config
0.000107 debug1: /etc/ssh/ssh_config line 19: Applying options for *
0.000114 debug1: Hostname has changed; re-reading configuration
0.000121 debug1: Reading configuration data /home/vinc17/.ssh/config
0.000128 debug2: add_identity_file: ignoring duplicate key ~/.ssh/id_rsa-internal
0.000135 debug2: add_identity_file: ignoring duplicate key ~/.ssh/id_rsa
0.000143 debug1: /home/vinc17/.ssh/config line 374: Applying options for *
0.000150 debug1: Reading configuration data /etc/ssh/ssh_config
0.000157 debug1: /etc/ssh/ssh_config line 19: Applying options for *
0.000164 debug1: Control socket "/tmp/ssh-ioooi.vinc17.net-22-vinc17" does not exist
5.078375 debug2: ssh_connect: needpriv 0
5.078423 debug1: Connecting to ioooi.vinc17.net [92.243.22.117] port 22.
5.155833 debug1: Connection established.
[...]

even if a few seconds before, there was no such problem. When I run "ping ioooi.vinc17.net" during this test, there isn't any problem shown in the ping output (i.e. I get an answer every second).

So, I wasn't wondering what happened between "Control socket..." and "ssh_connect: needpriv 0". This was a mystery... until I tried with strace, where I could see things related to resolving, with a timeout in the connection to the DNS server just before the 5-second delay.
Comment 1 Damien Miller 2015-09-04 14:56:36 AEST
Good point, openssh-7.2 will do:

debug2: resolving "foo.example.com" port 22
Comment 2 Damien Miller 2016-08-02 10:41:39 AEST
Close all resolved bugs after 7.3p1 release