Entropy collection in sshd (was Re: Entropy and DSA key)

[Ed Phillips]

On Tue, 6 Nov 2001, Lutz Jaenicke wrote:

> Date: Tue, 6 Nov 2001 21:44:41 +0100
> From: Lutz Jaenicke <Lutz.Jaenicke at aet.TU-Cottbus.DE>
> To: OpenSSH Development <openssh-unix-dev at mindrot.org>
> Subject: Re: Entropy collection in sshd (was Re: Entropy and DSA key)
>
> On Tue, Nov 06, 2001 at 08:57:01PM +0100, Gert Doering wrote:
> > On Tue, Nov 06, 2001 at 12:48:53PM -0500, Ed Phillips wrote:
> > > I'm not following you... the problem of "it takes 2 freakin minutes to get
> > > logged into my SS1+" is a direct result of entropy collection performed by
> > > sshd.
> >
> > No, it's not.  I use NetBSD on a Sparc LX with /dev/random, and ssh takes
> > still 2 minutes - the delay is NOT caused by the random number generation
> > but by slow crypto on ancient Sparc hardware.  ssh protocol 1 is much
> > quicker (and also needs random).
>
> I is hard to comment about a platform I don't know in detail, but I tend
> to sit in front of a good old HP 9000/710 (1991?), 50MHz. It took me
> some tries, but by tuning OpenSSL's flags I could gain a great deal
> of performance. Have a look into the BN_LLONG and company flags.
> Two minutes seems to be really slow to me.

Okay, I start "ssh -v -v -v" and then it sits there for a long time at:

...
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY

On the server side, the bulk of the time is spent as indicated in the
DEBUG3 syslog messages below:

Nov  6 16:59:42 ls1.nss.udel.edu sshd[1316]: debug2: kex_parse_kexinit: reserved 0
Nov  6 16:59:42 ls1.nss.udel.edu sshd[1316]: debug2: mac_init: found hmac-md5
Nov  6 16:59:42 ls1.nss.udel.edu sshd[1316]: debug1: kex: client->server aes128-cbc hmac-md5 none
Nov  6 16:59:43 ls1.nss.udel.edu sshd[1316]: debug2: mac_init: found hmac-md5
Nov  6 16:59:43 ls1.nss.udel.edu sshd[1316]: debug1: kex: server->client aes128-cbc hmac-md5 none
Nov  6 16:59:43 ls1.nss.udel.edu sshd[1316]: debug1: SSH2_MSG_KEX_DH_GEX_REQUEST received
Nov  6 16:59:44 ls1.nss.udel.edu sshd[1316]: debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent
Nov  6 17:00:28 ls1.nss.udel.edu sshd[1316]: debug1: dh_gen_key: priv key bits set: 142/256
Nov  6 17:00:28 ls1.nss.udel.edu sshd[1316]: debug1: bits set: 1609/3191
Nov  6 17:00:28 ls1.nss.udel.edu sshd[1316]: debug1: expecting SSH2_MSG_KEX_DH_GEX_INIT
Nov  6 17:00:28 ls1.nss.udel.edu sshd[1316]: debug1: bits set: 1570/3191
Nov  6 17:01:27 ls1.nss.udel.edu sshd[1316]: debug1: SSH2_MSG_KEX_DH_GEX_REPLY sent
Nov  6 17:01:27 ls1.nss.udel.edu sshd[1316]: debug1: kex_derive_keys
Nov  6 17:01:27 ls1.nss.udel.edu sshd[1316]: debug1: newkeys: mode 1
Nov  6 17:01:28 ls1.nss.udel.edu sshd[1316]: debug1: SSH2_MSG_NEWKEYS sent
Nov  6 17:01:28 ls1.nss.udel.edu sshd[1316]: debug1: waiting for SSH2_MSG_NEWKEYS

Okay... so now I'm confused.  It would appear, that like you say, there is
a long pause during computation in two spots in sshd.

I just talk with my collegue who did the install and he tells me that the
severe, long-running prng commands that timeout are during the startup of
sshd.  So all this time, I've been raving about sshd running the prng
commands for every client connection... this doesn't actually occur?  Oh
sheesh... what a waste of typing...

So the real problem is that compiling OpenSSL with solaris-sparcv7-cc just
doesn't generate code that can crunch fast enough to allow login in less
than 1.5 minutes?  Oh well, I guess we can live with it.  Hopefully in the
next few months we'll replace any of our sun4c systems with at least a
sun4m running Sol2.6 or higher (probably Sol8).

Sorry for the wasted bandwidth guys... hasn't been the first time...
probably won't be the last. ;-)

So, why is ssh-1.2.27 almost instantaneous (5-10 seconds) compared to the
above (give me a FAQ-smack if you feel the need)?

	Ed

Ed Phillips <ed at udel.edu> University of Delaware (302) 831-6082
Systems Programmer III, Network and Systems Services
finger -l ed at polycut.nss.udel.edu for PGP public key