PowerShell / PowerShell/Win32-OpenSSH

Delay Connecting from Ubuntu

Open
#1,414 8 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Issue-Discussion-Deprecated/use GitHub discussions
Dominant language
No language data
Stars
8.3k
Forks
819
PR merge metrics
No merged PRs in 30d

Description

Troubleshooting steps
https://github.com/PowerShell/Win32-OpenSSH/wiki/Troubleshooting-Steps

Terminal issue? please go through wiki
https://github.com/PowerShell/Win32-OpenSSH/wiki/TTY-PTY-support-in-Windows-OpenSSH

Please answer the following

"OpenSSH for Windows" version
((Get-Item (Get-Command sshd).Source).VersionInfo.FileVersion)
Command doesn't work but it's 8.0.0 (I downloaded today)

Server OperatingSystem
((Get-ItemProperty "HKLM:\SOFTWARE\Microsoft\Windows nt\CurrentVersion\" -Name ProductName).ProductName)
Windows 7 Professional

Client OperatingSystem
Ubuntu 14.04 LTS (Trusty)

What is failing
Connecting from Ubuntu LTS trusy, the connection is very often pausing at...
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_6.6.1p1 Ubuntu-2ubuntu2.10

Then continues quickly from this line
debug1: Remote protocol version 2.0, remote software version OpenSSH_for_Windows_8.0

The strange thing is, if I restart the service, I can connect quickly a number of times (in this case 2) and then it will start delaying again

Server Log:
5628 2019-07-03 13:23:52.152 debug1: do_cleanup
2468 2019-07-03 13:24:40.578 debug1: inetd sockets after dupping: 4, 4
2468 2019-07-03 13:24:40.578 Connection from 10.X.X port 38317 on 10.X.X port 22
2468 2019-07-03 13:24:40.578 debug1: Local version string SSH-2.0-OpenSSH_for_Windows_8.0
2468 2019-07-03 13:24:40.578 debug1: Remote protocol version 2.0, remote software version OpenSSH_6.6.1p1 Ubuntu-2ubuntu2.10
2468 2019-07-03 13:24:40.578 debug1: match: OpenSSH_6.6.1p1 Ubuntu-2ubuntu2.10 pat OpenSSH_6.6.1* compat 0x04000002
2468 2019-07-03 13:24:40.672 debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
2468 2019-07-03 13:24:40.672 debug1: SSH2_MSG_KEXINIT sent [preauth]
2468 2019-07-03 13:24:40.672 debug1: SSH2_MSG_KEXINIT received [preauth]
2468 2019-07-03 13:24:40.672 debug1: kex: algorithm: curve25519-sha256@libssh.org [preauth]
2468 2019-07-03 13:24:40.672 debug1: kex: host key algorithm: ecdsa-sha2-nistp256 [preauth]
2468 2019-07-03 13:24:40.672 debug1: kex: client->server cipher: aes128-ctr MAC: hmac-sha1-etm@openssh.com compression: none [preauth]
2468 2019-07-03 13:24:40.672 debug1: kex: server->client cipher: aes128-ctr MAC: hmac-sha1-etm@openssh.com compression: none [preauth]
2468 2019-07-03 13:24:40.672 debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
2468 2019-07-03 13:24:40.678 debug1: rekey out after 4294967296 blocks [preauth]
2468 2019-07-03 13:24:40.678 debug1: SSH2_MSG_NEWKEYS sent [preauth]
2468 2019-07-03 13:24:40.678 debug1: expecting SSH2_MSG_NEWKEYS [preauth]
2468 2019-07-03 13:24:40.682 debug1: SSH2_MSG_NEWKEYS received [preauth]
2468 2019-07-03 13:24:40.682 debug1: rekey in after 4294967296 blocks [preauth]
2468 2019-07-03 13:24:40.682 debug1: KEX done [preauth]
2468 2019-07-03 13:24:40.888 debug1: userauth-request for user administrator service ssh-connection method none [preauth]
2468 2019-07-03 13:24:40.888 debug1: attempt 0 failures 0 [preauth]
2468 2019-07-03 13:24:40.890 debug1: user administrator matched group list administrators at line 87
2468 2019-07-03 13:24:40.895 debug1: userauth-request for user administrator service ssh-connection method publickey [preauth]
2468 2019-07-03 13:24:40.895 debug1: attempt 1 failures 0 [preauth]
2468 2019-07-03 13:24:40.895 debug1: userauth_pubkey: test pkalg ssh-rsa pkblob RSA SHA256:V3HXXXXXXXXXX [preauth]
2468 2019-07-03 13:24:40.895 debug1: trying public key file PROGRAMDATA/ssh/administrators_authorized_keys
2468 2019-07-03 13:24:40.895 debug1: PROGRAMDATA/ssh/administrators_authorized_keys:1: matching key found: RSA SHA256:V3HeTAXXXXXXXXX
2468 2019-07-03 13:24:40.896 debug1: PROGRAMDATA/ssh/administrators_authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
2468 2019-07-03 13:24:40.896 Accepted key RSA SHA256:V3XXXXXXX found at PROGRAMDATA/ssh/administrators_authorized_keys:1
2468 2019-07-03 13:24:40.902 Postponed publickey for administrator from 10.X.X port 38317 ssh2 [preauth]
2468 2019-07-03 13:24:40.902 debug1: userauth-request for user administrator service ssh-connection method publickey [preauth]
2468 2019-07-03 13:24:40.902 debug1: attempt 2 failures 0 [preauth]
2468 2019-07-03 13:24:40.902 debug1: trying public key file PROGRAMDATA/ssh/administrators_authorized_keys
2468 2019-07-03 13:24:40.902 debug1: PROGRAMDATA/ssh/administrators_authorized_keys:1: matching key found: RSA SHA256:V3XXXXXXX
2468 2019-07-03 13:24:40.902 debug1: PROGRAMDATA/ssh/administrators_authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
2468 2019-07-03 13:24:40.902 Accepted key RSA SHA256:V3XXXXXfound at PROGRAMDATA/ssh/administrators_authorized_keys:1
2468 2019-07-03 13:24:40.902 debug1: auth_activate_options: setting new authentication options
2468 2019-07-03 13:24:40.902 Accepted publickey for administrator from 10.X.X port 38317 ssh2: RSA SHA256:V3XXXXX
2468 2019-07-03 13:24:40.903 debug1: monitor_child_preauth: administrator has been authenticated by privileged process
2468 2019-07-03 13:24:40.909 debug1: auth_activate_options: setting new authentication options [preauth]
2468 2019-07-03 13:24:40.910 debug1: monitor_read_log: child log fd closed
2468 2019-07-03 13:24:40.926 User child is on pid 9012
9012 2019-07-03 13:24:40.971 debug1: user administrator matched group list administrators at line 87
9012 2019-07-03 13:24:40.972 debug1: rekey in after 4294967296 blocks
9012 2019-07-03 13:24:40.972 debug1: rekey out after 4294967296 blocks
9012 2019-07-03 13:24:40.972 debug1: ssh_packet_set_postauth: called
9012 2019-07-03 13:24:40.972 debug1: active: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
9012 2019-07-03 13:24:40.972 debug1: Entering interactive session for SSH2.
9012 2019-07-03 13:24:40.972 debug1: server_init_dispatch
9012 2019-07-03 13:24:40.972 debug1: server_input_channel_open: ctype session rchan 0 win 2097152 max 32768
9012 2019-07-03 13:24:40.972 debug1: input_session_request
9012 2019-07-03 13:24:40.972 debug1: channel 0: new [server-session]
9012 2019-07-03 13:24:40.972 debug1: session_new: session 0
9012 2019-07-03 13:24:40.972 debug1: session_open: channel 0
9012 2019-07-03 13:24:40.972 debug1: session_open: session 0: link with channel 0
9012 2019-07-03 13:24:40.972 debug1: server_input_channel_open: confirm session
9012 2019-07-03 13:24:40.972 debug1: server_input_global_request: rtype no-more-sessions@openssh.com want_reply 0
9012 2019-07-03 13:24:41.012 debug1: server_input_channel_req: channel 0 request env reply 0
9012 2019-07-03 13:24:41.013 debug1: session_by_channel: session 0 channel 0
9012 2019-07-03 13:24:41.013 debug1: session_input_channel_req: session 0 req env
9012 2019-07-03 13:24:41.013 debug1: server_input_channel_req: channel 0 request exec reply 1
9012 2019-07-03 13:24:41.013 debug1: session_by_channel: session 0 channel 0
9012 2019-07-03 13:24:41.013 debug1: session_input_channel_req: session 0 req exec
9012 2019-07-03 13:24:41.013 Starting session: command for administrator from 10.194.105.36 port 38317 id 0
9012 2019-07-03 13:24:41.055 debug1: Received SIGCHLD.
9012 2019-07-03 13:24:41.055 debug1: session_by_pid: pid 9760
9012 2019-07-03 13:24:41.055 debug1: session_exit_message: session 0 channel 0 pid 9760
9012 2019-07-03 13:24:41.055 debug1: session_exit_message: release channel 0
9012 2019-07-03 13:24:41.056 debug1: session_by_channel: session 0 channel 0
9012 2019-07-03 13:24:41.056 debug1: session_close_by_channel: channel 0 child 0
9012 2019-07-03 13:24:41.056 Close session: user administrator from 10.X.X port 38317 id 0
9012 2019-07-03 13:24:41.056 debug1: channel 0: free: server-session, nchannels 1
9012 2019-07-03 13:24:41.056 Received disconnect from 10.X.X port 38317:11: disconnected by user
9012 2019-07-03 13:24:41.056 Disconnected from 10.X.X port 38317
9012 2019-07-03 13:24:41.056 debug1: do_cleanup
2468 2019-07-03 13:24:41.057 debug1: do_cleanup

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start with the linked Troubleshooting Steps and TTY/PTY support wiki pages, then reproduce the intermittent delay using the Ubuntu 14.04 client and Windows 7 server while comparing the supplied client and server logs. Done means the cause of the post-restart delay is identified and a specific fix or documented workaround is validated.

Written by the indexing model from the issue text.

Assessment

Tech stack
ubuntu
Domain
networking, operating-systems
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.