| All Forums |
Register |
Login |
Search |
Subscriptions |
My Profile |
Inbox |
| Tool Warehouse |
FAQs |
Resources |
Help |
Member List |
Address Book |
Logout |
|
|
ssh delay?
|
Logged in as: Guest |
| Users viewing this topic: none |
|
Login  |
|
|
 ssh delay? - Jun. 14, '06, 3:24:29 PM
|
|
|
droolinghamster
Posts: 2
Joined: Oct. 4, '05,
Status: offline
|
i get a significant delay when attempting to run ssh, even without actually trying to connect to something. truss shows it to be getting stuck in setids(), but i can't seem to find any info about what that does to figure out if there's something i can fix.
any ideas?
- dan
% truss ssh
tracing pid 1351
getdata() getdata returned 0
getrlimit() getrlimit returned 0
pthread_inform_signals() pthread_inform_signals returned 0
unixpath2win() unixpath2win returned 0
getids() getids returned 0
getids() getids returned 0
getids() getids returned 0
getids() getids returned 0
open("/usr/local/lib/libcrypto.so", 0x1) open failed: errno 2, No such file or directory
open("/usr/local/ssl/lib/libcrypto.so", 0x1) open returned 3
read(3, 0x88EC18, 4096) read returned 4096 0x1000
close(3) close returned 0
unixpath2win() unixpath2win returned 0
open("/usr/local/lib/libz.so", 0x1) open returned 3
read(3, 0x88EBF8, 4096) read returned 4096 0x1000
close(3) close returned 0
unixpath2win() unixpath2win returned 0
open("/usr/local/lib/libcrypt.so", 0x1) open returned 3
read(3, 0x88EBD8, 4096) read returned 4096 0x1000
close(3) close returned 0
unixpath2win() unixpath2win returned 0
open("/usr/local/lib/libc.so.3.5", 0x1) open failed: errno 2, No such file or directory
open("/usr/local/ssl/lib/libc.so.3.5", 0x1) open failed: errno 2, No such file or directory
open("/usr/local/lib/libc.so.3.5", 0x1) open failed: errno 2, No such file or directory
open("/usr/local/ssl/lib/libc.so.3.5", 0x1) open failed: errno 2, No such file or directory
open("/usr/lib/libc.so.3.5", 0x1) open returned 3
read(3, 0x88EBB8, 4096) read returned 4096 0x1000
close(3) close returned 0
unixpath2win() unixpath2win returned 0
open("/usr/local/lib/libm.so.3.5", 0x1) open failed: errno 2, No such file or directory
open("/usr/local/ssl/lib/libm.so.3.5", 0x1) open failed: errno 2, No such file or directory
open("/usr/local/lib/libm.so.3.5", 0x1) open failed: errno 2, No such file or directory
open("/usr/local/ssl/lib/libm.so.3.5", 0x1) open failed: errno 2, No such file or directory
open("/usr/lib/libm.so.3.5", 0x1) open returned 3
read(3, 0x88EB98, 4096) read returned 4096 0x1000
close(3) close returned 0
unixpath2win() unixpath2win returned 0
open("/dev/null", 0x3) open returned 3
close(3) close returned 0
getids() getids returned 0
getids() getids returned 0
setids() [hangs here for nearly a minute] setids returned 0
getpwuid(0x10000001105, 0x0) getpwuid returned 0
umask() umask returned 18 0x12
write(2, 0x462060, 406) usage: ssh [-1246AaCfgkMNnqsTtVvXxY] [-b bind_address] [-c cipher_spec]
[-D [bind_address:]port] [-e escape_char] [-F configfile]
[-i identity_file] [-L [bind_address:]port:host:hostport]
[-l login_name] [-m mac_spec] [-O ctl_cmd] [-o option] [-p port]
[-R [bind_address:]port:host:hostport] [-S ctl_path]
[-w tunnel:tunnel] [user@]hostname [command]
write returned 406 0x196
lseek(0, 1, 0) lseek returned 0
lseek(0, 0, 0) lseek returned 0
exit(255) process exited with status 255
%
OpenSSH_4.3p2, OpenSSL 0.9.8a 11 Oct 2005
System = Interix
Node = DVALENTINE1
Release = 3.5
Version = SP-8.0.1969.1
Machine = x86
Processor = Intel_x86_Family15_Model4_Stepping1
HostSystem = Windows
HostRelease = SP2
HostVersion = 5.1
|
|
|
|
|
RE: ssh delay? - Jun. 14, '06, 3:34:46 PM
|
|
|
steveh
Posts: 195
Joined: Jan. 23, '04,
Status: offline
|
Problem trying to connect to or resolve a domain controller possibly?
|
|
|
|
|
RE: ssh delay? - Jun. 14, '06, 3:48:33 PM
|
|
|
droolinghamster
Posts: 2
Joined: Oct. 4, '05,
Status: offline
|
hmm... i don't think there's a problem connecting to the dc in itself, but non-domain-admin users are not allowed to even list users in the domain. might that cause the delay?
|
|
|
|
|
RE: ssh delay? - Jun. 14, '06, 5:45:26 PM
|
|
|
Rodney
Posts: 3714
Joined: Jul. 9, '02,
From: /Tools lab
Status: offline
|
The API setids() is the actual system call for API's such as setuid() and setgid().
Steve is correct that with this call a lot of consultation happens between the subsystem
and the LSA (Local Security Authority). The LSA in turn does the machine to DC communication.
The requested information will have to do with a series of lookups (groups are a cascading
lookup for example). If there is a delay it can be because of the amount of information,
or the information is not easily available, then the LSA spends a lot of time trying to
get it. If there are some funky permission for users getting information things will slow
as it tries to work with the LSA to get something it can work with.
Truss only shows the system calls happening.
So knowing exactly where in the program it's happening is difficult to pinpoint.
But I expect it's at a point where ssh is trying to make sure real and effective ids
are in-sync so the process has the right permissions (to match the user).
If the user isn't in the user database ssh will tell you:
You don't exist, go away!
The delay is not ssh per se, but the time to fulfill the information request/setting
for the user. The delay will be the communications to the DC.
As a contrast make a local account and use it rather than a domain account.
|
|
|
|
|
RE: ssh delay? - Aug. 22, '06, 4:11:21 PM
|
|
|
ehall
Posts: 31
Joined: May 29, '05,
Status: offline
|
I have the same problem here, all accounts get massive delay with sshd. Fresh W2k3EE server install, and the machine is the DC for the domain. Curiously I do not get the delays with /usr/sbin/in.telnetd. I didn't get the delays with the previous installation either.
|
|
|
|
|
RE: ssh delay? - Aug. 22, '06, 5:14:59 PM
|
|
|
Rodney
Posts: 3714
Joined: Jul. 9, '02,
From: /Tools lab
Status: offline
|
Understand that the telnet daemon doesn't do any host address verification
nor does it have to do the SSL calculations. So if there is a slow communication
with the DNS service/daemon or you have older hardware (the keys are large)
then these can be slow points at the initial connection.
You can run truss or run the sshd in debug mode to look for where
things go slow.
Have you set the all of the users to have home directories?
This can be significant too.
|
|
|
|
|
RE: ssh delay? - Aug. 22, '06, 7:09:38 PM
|
|
|
ehall
Posts: 31
Joined: May 29, '05,
Status: offline
|
Users have UNC home directory mappings defined and they end up in /dev/fs/C/Home/$USERNAME$ appropriately in both sshd and telnetd (without delay in the latter case).
Running sshd in -dd mode produces no obvious errors in sshd or the session. The errors are on the back-end somewere.
It shouldn't be DNS related, since it happens no matter where the connection comes from (even the local console), and the server is the primary for its AD domain. Forward and reverse lookups via the host command resolve correctly too (just tested it).
|
|
|
|
|
RE: ssh delay? - Aug. 22, '06, 10:40:16 PM
|
|
|
Rodney
Posts: 3714
Joined: Jul. 9, '02,
From: /Tools lab
Status: offline
|
> Running sshd in -dd mode produces no obvious errors in sshd or the session.
So while watching the data o/p there is no "pause point"?
> The errors are on the back-end somewere.
What do you mean by this?
Once sshd validates the user and switches the connection to that user
it is then the shell starting up (same as with telnet).
I think that it still might have something to do with the home directory setting.
You write that it's set as UNC. What is the path you have in the user db?
|
|
|
|
|
RE: ssh delay? - Aug. 23, '06, 12:17:26 PM
|
|
|
ehall
Posts: 31
Joined: May 29, '05,
Status: offline
|
quote:
> Running sshd in -dd mode produces no obvious errors in sshd or the session.
So while watching the data o/p there is no "pause point"?
> The errors are on the back-end somewere.
What do you mean by this?
There is a pause but its nothing to do with SSH. Here is the output:
[ 12:11:03 -- omega:/etc/init.d/ ]
[ administrator$ ] /usr/local/sbin/sshd -dd
debug2: load_server_config: filename /usr/local/etc/sshd_config
debug2: load_server_config: done config len = 258
debug2: parse_server_config: config /usr/local/etc/sshd_config len 258
debug1: sshd version OpenSSH_4.3p2
debug1: private host key: #0 type 0 RSA1
debug1: read PEM private key done: type RSA
debug1: private host key: #1 type 1 RSA
debug1: read PEM private key done: type DSA
debug1: private host key: #2 type 2 DSA
debug1: rexec_argv[0]='/usr/local/sbin/sshd'
debug1: rexec_argv[1]='-dd'
sshd started version OpenSSH_4.3
debug2: fd 3 setting O_NONBLOCK
debug1: Bind to port 22 on 0.0.0.0.
Server listening on 0.0.0.0 port 22.
Generating 768 bit RSA key.
RSA key generation complete.
<<startup completes, waiting for connection>>
debug1: Server will not fork when running in debugging mode.
debug1: rexec start in 4 out 4 newsock 4 pipe -1 sock 7
sshd started version OpenSSH_4.3
debug1: inetd sockets after dupping: 3, 3
Connection from 10.29.41.10 port 2035
debug1: Client protocol version 2.0; client software version OpenSSH_4.3
debug1: match: OpenSSH_4.3 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-1.99-OpenSSH_4.3
debug2: fd 3 setting O_NONBLOCK
debug1: list_hostkey_types: ssh-rsa,ssh-dss
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha1,diffie-hellman-gro
up14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour1
28,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-c
tr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour1
28,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-c
tr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@open
ssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@open
ssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib@openssh.com
debug2: kex_parse_kexinit: none,zlib@openssh.com
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha1,diffie-hellman-gro
up14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour1
28,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-c
tr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour1
28,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-c
tr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@open
ssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@open
ssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: mac_init: found hmac-md5
debug1: kex: client->server aes128-cbc hmac-md5 none
debug2: mac_init: found hmac-md5
debug1: kex: server->client aes128-cbc hmac-md5 none
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST received
debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent
debug2: dh_gen_key: priv key bits set: 125/256
debug2: bits set: 510/1024
debug1: expecting SSH2_MSG_KEX_DH_GEX_INIT
debug2: bits set: 481/1024
debug1: SSH2_MSG_KEX_DH_GEX_REPLY sent
debug2: kex_derive_keys
debug2: set_newkeys: mode 1
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug2: set_newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: KEX done
debug1: userauth-request for user jon service ssh-connection method none
debug1: attempt 0 failures 0
debug2: input_userauth_request: setting up authctxt for jon
debug2: input_userauth_request: try method none
Failed none for jon from 10.29.41.10 port 2035 ssh2
debug1: userauth-request for user jon service ssh-connection method hostbased
debug1: attempt 1 failures 1
debug2: input_userauth_request: try method hostbased
debug1: userauth_hostbased: cuser administrator chost omega.hall.family-and-frie
nds.us. pkalg ssh-dss slen 55
debug2: userauth_hostbased: chost omega.hall.family-and-friends.us. resolvedname
omega.hall.family-and-friends.us ipaddr 10.29.41.10
debug2: stripping trailing dot from chost omega.hall.family-and-friends.us.
debug2: auth_rhosts2: clientuser administrator hostname omega.hall.family-and-fr
iends.us ipaddr 10.29.41.10
debug1: temporarily_use_uid: 197726/197121 (e=0/197121)
debug1: restore_uid: 0/197121
debug2: userauth_hostbased: authenticated 0
Failed hostbased for jon from 10.29.41.10 port 2035 ssh2
debug1: userauth-request for user jon service ssh-connection method hostbased
debug1: attempt 2 failures 2
debug2: input_userauth_request: try method hostbased
debug1: userauth_hostbased: cuser administrator chost omega.hall.family-and-frie
nds.us. pkalg ssh-rsa slen 271
debug2: userauth_hostbased: chost omega.hall.family-and-friends.us. resolvedname
omega.hall.family-and-friends.us ipaddr 10.29.41.10
debug2: stripping trailing dot from chost omega.hall.family-and-friends.us.
debug2: auth_rhosts2: clientuser administrator hostname omega.hall.family-and-fr
iends.us ipaddr 10.29.41.10
debug1: temporarily_use_uid: 197726/197121 (e=0/197121)
debug1: restore_uid: 0/197121
debug2: userauth_hostbased: authenticated 0
Failed hostbased for jon from 10.29.41.10 port 2035 ssh2
debug1: userauth-request for user jon service ssh-connection method keyboard-int
eractive
debug1: attempt 3 failures 3
debug2: input_userauth_request: try method keyboard-interactive
debug1: keyboard-interactive devs
debug1: auth2_challenge: user=jon devs=
debug1: kbdint_alloc: devices ''
debug2: auth2_challenge_start: devices
Failed keyboard-interactive for jon from 10.29.41.10 port 2035 ssh2
debug1: userauth-request for user jon service ssh-connection method password
debug1: attempt 4 failures 4
debug2: input_userauth_request: try method password
Accepted password for jon from 10.29.41.10 port 2035 ssh2
debug1: Entering interactive session for SSH2.
debug2: fd 4 setting O_NONBLOCK
debug2: fd 5 setting O_NONBLOCK
debug1: server_init_dispatch_20
debug1: server_input_channel_open: ctype session rchan 0 win 65536 max 16384
debug1: input_session_request
debug1: channel 0: new [server-session]
debug1: session_new: init
debug1: session_new: session 0
debug1: session_open: channel 0
debug1: session_open: session 0: link with channel 0
debug1: server_input_channel_open: confirm session
debug1: server_input_channel_req: channel 0 request pty-req reply 0
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 req pty-req
debug1: Allocating pty.
debug1: session_pty_req: session 0 alloc /dev/ttyp0
debug1: server_input_channel_req: channel 0 request shell reply 0
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 req shell
debug1: Setting controlling tty using TIOCSCTTY.
debug2: fd 3 setting TCP_NODELAY
debug2: channel 0: rfd 7 isatty
debug2: fd 7 setting O_NONBLOCK
<<sshd/login completes, delay starts>>
quote:
I think that it still might have something to do with the home directory setting.
You write that it's set as UNC. What is the path you have in the user db?
Logon script
User profile \\OMEGA\Profiles\jon
Home directory \\OMEGA\Home\jon
Last logon 8/23/2006 12:11 PM
[ jon$ ] sh
$ cd
$ pwd
/dev/fs/C/Home/jon
$
< Message edited by ehall -- Aug. 23, '06, 12:20:27 PM >
|
|
|
|
|
RE: ssh delay? - Aug. 23, '06, 3:13:09 PM
|
|
|
Rodney
Posts: 3714
Joined: Jul. 9, '02,
From: /Tools lab
Status: offline
|
I notice that it tries a number of different methods to log the user
on before it is successful. A larger number than usual I think.
When "jon" is logging on does he give a password?
Have you set up a key exchange for "jon" at all?
Did you register the password for "jon" with regpwd?
Is the configure file the "plain vanilla" that ships or has it been modified?
|
|
|
|
|
RE: ssh delay? - Aug. 23, '06, 3:57:08 PM
|
|
|
ehall
Posts: 31
Joined: May 29, '05,
Status: offline
|
The number of retries is normal for the openssh client in stock config (I used ssh from another local bash shell on that same machine). If I specify the auth method, the negotiation get short-circuited. The result is the same.
Also, there is no delay during the negotiation, it all occurs afterwards.
Further, it is only happening with successful authentication (bad password causes session to end immediately), so in all likelihood it's in the shell creation routines. Let me go poke around in eventlog and see if anything pops out.
|
|
|
|
|
RE: ssh delay? - Aug. 23, '06, 4:15:39 PM
|
|
|
ehall
Posts: 31
Joined: May 29, '05,
Status: offline
|
Looking through security eventlog entries during successful auth, there are two "phases", each separated by the longish pause.
First phase:
Security, Account Logon, Successful audit of user auth ticket
Security, Account Logon, Successful audit of user service ticket
Security, Account Logon, Successful audit of user explicit credentials
Security, Account Logon, Successful audit of user ADVAPI negotiation
Security, Account Logon, Successful audit of user LOGOFF
Security, Account Logon, Successful audit of workstation account LOGOFF
<<20 second delay>>
Second phase:
Security, Directory Access, Successful audit of SAM access
Security, Account Logon, Successful audit of user auth ticket
Security, Account Logon, Successful audit of user service ticket
Security, Account Logon, Successful audit of user explicit credentials
Security, Account Logon, Successful audit of user ADVAPI negotiation
<<shell starts>>
It appears that the local workstation account is logging off and back on, before the user is fully logged in (although user succeeds on both attempts), which is causing the delay. Just have to figure out why now.
< Message edited by ehall -- Aug. 23, '06, 4:32:33 PM >
|
|
|
|
|
RE: ssh delay? - Aug. 23, '06, 4:30:53 PM
|
|
|
ehall
Posts: 31
Joined: May 29, '05,
Status: offline
|
By comparison, here is the sequence of events for in.telnetd
Security, Directory Access, Successful audit of SAM access by lsass
Security, Account Logon, Successful audit of workstation privs
Security, Account Logon, Successful audit of workstation kerberos logon
Security, Account Logon, Successful audit of user auth ticket
Security, Account Logon, Successful audit of user service ticket
Security, Account Logon, Successful audit of user explicit logon
Security, Account Logon, Successful audit of user ADVAPI negotiation
Security, Account Logon, Successful audit of workstation logon
Security, Account Logon, Successful audit of workstation privs
Security, Account Logon, Successful audit of workstation kerberos logon
Security, Account Logon, Successful audit of workstation privs
...
Basically there is more up-front machine-level authentication happening with telnet than with sshd. This is probably because in.telnetd is spawned for each connection while sshd is sitting around waiting for a connection.
It could suggest that sshd is losing its auth credentials tho.
< Message edited by ehall -- Aug. 23, '06, 4:33:56 PM >
|
|
|
|
|
RE: ssh delay? - Aug. 24, '06, 6:35:30 PM
|
|
|
mariusp66
Posts: 4
Joined: Mar. 29, '05,
Status: offline
|
I have same problem. No DNS delays and system is not in domain.
It is shell creation related though since if I try just to excute command over ssh (something like ssh hostname 'ls -al') I have ls output right away. So it should be shell cretion related. And also, on previous versions of sshd Interix there were no such problem. It only appeared after I started to use the latest.
/M.
|
|
|
|
 New Messages |
 No New Messages |
 Hot Topic w/ New Messages |
 Hot Topic w/o New Messages |
|
 Locked w/ New Messages |
 Locked w/o New Messages |
|
 Post New Thread
Reply to Message
Post New Poll
Submit Vote
Delete My Own Post
Delete My Own Thread
Rate Posts |
|
|
|
Printable Version
