Session timeout caused by long time calculation on KeyExchangeDiffieHellman->PopulateClientExchangeValue

[edika99]

Hello, I'm experiencing some problem connecting to an SSH server using a private key file.
This is the log of the connection:

SshNet.Logging Verbose: 9 : Initiating connection to '*************:22'.
SshNet.Logging Verbose: 9 : Server version '2.0' on 'GoAnywhere5.3.8'.
SshNet.Logging Verbose: 12 : [] Received message 'KeyExchangeInitMessage' from server: 'SSH_MSG_KEXINIT'.
SshNet.Logging Verbose: 12 : [] Sending message 'KeyExchangeInitMessage' to server: 'SSH_MSG_KEXINIT'.
SshNet.Logging Verbose: 12 : [] Sending message 'KeyExchangeDhGroupExchangeRequest' to server: 'SSH_MSG_KEX_DH_GEX_REQUEST'.
SshNet.Logging Verbose: 12 : [] Received message 'KeyExchangeDhGroupExchangeGroup' from server: 'SSH_MSG_KEX_DH_GEX_GROUP'.

At this point is thrown the exception SshOperationTimeoutException from Session.cs at line 822

then the log continue like this:

SshNet.Logging Verbose: 12 : [] Sending message 'KeyExchangeDhGroupExchangeInit' to server: 'SSH_MSG_KEX_DH_GEX_INIT'.
SshNet.Logging Verbose: 12 : [] Received message 'KeyExchangeDhGroupExchangeReply' from server: 'SSH_MSG_KEX_DH_GEX_REPLY'.
SshNet.Logging Verbose: 9 : Disposing client.
SshNet.Logging Verbose: 9 : Disconnecting client.
SshNet.Logging Verbose: 9 : [] Disposing session.
SshNet.Logging Verbose: 9 : [] Disconnecting session.
SshNet.Logging Verbose: 9 : [] Shutting down socket.
SshNet.Logging Verbose: 9 : [] Disposing socket.
SshNet.Logging Verbose: 9 : [] Disposed socket.
SshNet.Logging Verbose: 12 : [] Raised exception: Renci.SshNet.Common.SshConnectionException: Client not connected.
in Renci.SshNet.Session.SendMessage(Message message) in D:\Documenti\Visual Studio 2015\Projects\SSH.Net\Session.cs:riga 838
in Renci.SshNet.Security.KeyExchange.SendMessage(Message message) in D:\Documenti\Visual Studio 2015\Projects\SSH.Net\Security\KeyExchange.cs:riga 340
in Renci.SshNet.Security.KeyExchange.Finish() in D:\Documenti\Visual Studio 2015\Projects\SSH.Net\Security\KeyExchange.cs:riga 165
in Renci.SshNet.Security.KeyExchangeDiffieHellmanGroupExchangeShaBase.Finish() in D:\Documenti\Visual Studio 2015\Projects\SSH.Net\Security\KeyExchangeDiffieHellmanGroupExchangeShaBase.cs:riga 67
in Renci.SshNet.Security.KeyExchangeDiffieHellmanGroupExchangeShaBase.Session_KeyExchangeDhGroupExchangeReplyReceived(Object sender, MessageEventArgs`1 e) in D:\Documenti\Visual Studio 2015\Projects\SSH.Net\Security\KeyExchangeDiffieHellmanGroupExchangeShaBase.cs:riga 110
in Renci.SshNet.Session.OnKeyExchangeDhGroupExchangeReplyReceived(KeyExchangeDhGroupExchangeReply message) in D:\Documenti\Visual Studio 2015\Projects\SSH.Net\Session.cs:riga 1194
in Renci.SshNet.Messages.Transport.KeyExchangeDhGroupExchangeReply.Process(Session session) in D:\Documenti\Visual Studio 2015\Projects\SSH.Net\Messages\Transport\KeyExchangeDhGroupExchangeReply.cs:riga 78
in Renci.SshNet.Session.MessageListener() in D:\Documenti\Visual Studio 2015\Projects\SSH.Net\Session.cs:riga 1869
'BdlStatGui.vshost.exe' (CLR v4.0.30319: BdlStatGui.vshost.exe): caricamento di 'D:\Documenti\Visual Studio 2015\Projects\BdlStatLib\BdlStatGui\bin\Debug\it\EDK4Net.resources.dll' completato. Modulo compilato senza simboli.
Il thread 0x2aa0 è terminato con il codice 0 (0x0).
Il thread 0x740 è terminato con il codice 0 (0x0).
SshNet.Logging Verbose: 9 : Disconnecting client.

I've found the problem is in 'KeyExchangeDiffieHellman' at method 'PopulateClientExchangeValue'. The exception is thrown when is executed this line:

_clientExchangeValue = BigInteger.ModPow(_group, _randomValue, _prime);

it looks that the ModPow is too long to execute and cause the timeout.
setting the random value to a little number the timeout is not thrown, so it is definitely the executiong time of the ModPow that cause the timeout.
the variables _prime is incredibly bigger, in my case this is the value: 1090748135619415929450294929359784500348155124953172211774101106966150168922785639028532473848836817769712164169076432969224698752674677662739994265785437233596157045970922338040698100507861033047312331823982435279475700199860971612732540528796554502867919746776983759391475987142521315878719577519148811830879919426939958487087540965716419167467499326156226529675209172277001377591248147563782880558861083327174154014975134893125116015776318890295960698011614157721282527539468816519319333337503114777192360412281721018955834377615480468479252748867320362385355596601795122806756217713579819870634321561907813255153703950795271232652404894983869492174481652303803498881366210508647263668376514131031102336837488999775744046733651827239395353540348414872854639719294694323450186884189822544540647226987292160693184734654941906936646576130260972193280317171696418971553954161446191759093719524951116705577362073481319296041201283516154269044389257727700289684119460283480452306204130024913879981135908026983868205969318167819680850998649694416907952712904962404937775789698917207356355227455066183815847669135530549755439819480321732925869069136146085326382334628745456398071603058051634209386708703306545903199608523824513729625136659128221100967735450519952404248198262813831097374261650380017277916975324134846574681307337017380830353680623216336949471306191686438249305686413380231046096450953594089375540285037292470929395114028305547452584962074309438151825437902976012891749355198678420603722034900311364893046495761404333938686140037848030916292543273684533640032637639100774502371542479302473698388692892420946478947733800387782741417786484770190108867879778991633218628640533982619322466154883011452291890252336487236086654396093853898628805813177559162076363154436494477507871294119841637867701722166609831201845484078070518041336869808398454625586921201308185638888082699408686536045192649569198110353659943111802300636106509865023943661829436426563007917282050894429388841748885398290707743052973605359277515749619730823773215894755121761467887865327707115573804264519206349215850195195364813387526811742474131549802130246506341207020335797706780705406945275438806265978516209706795702579244075380490231741030862614968783306207869687868108423639971983209077624758080499988275591392787267627182442892809646874228263172435642368588260139161962836121481966092745325488641054238839295138992979335446110090325230955276870524611359124918392740353154294858383359
I think this is the problem of the long time operation.

My temporary solution is to change the _randomValue to a constant value (2 in my case) instead of _prime.BitLength like in the code. This make the calculation execution very fast and the timeout problem disappear.
Should be better to understand why there is a _prime value so big and if it's correct, or limit the _randomValue dimension.

[olegkap]

Hi Edika,

You right, it seems like there is an issue with calculating ModPow value.

Can you replace:
_clientExchangeValue = BigInteger.ModPow(_group, _randomValue, _prime);
with
_clientExchangeValue = (_group ^ _randomValue) % _prime;

Which should be exactly the same operation as RFC Describes:

1. C generates a random number x (1 < x < q) and computes
   e = g^x mod p. C sends e to S.

I don't have SSH server currently to test so wanted to be sure it will work in all situations.

Thanks,
Oleg

[edika99]

Hello Oleg,

I've test the new code but it does not work.
Same timeout error. I think the problem is not the ModPow function, infact it works perfectly when _randomNumber is a little value.
I've read the RFC and from what I've understood should be better to check the random number instead of the _clientExchangeValue.
if the RFC says:
C generates a random number x (1 < x < q) and computes e = g^x mod p. C sends e to S.

I've also tried this code to reflect the rfc:
do{
_randomValue = BigInteger.Random(bitLength);
}while (_randomValue>1 && _randomValue<q)
clientExchangeValue = (_group ^ _randomValue) % _prime;

I've not well understood which variable is the 'q' of the RFC in SSH.NET code.
I've tried using _prime-1 in place of q but does not work, and also _pimet.BitLenght but same error, timeout, even if this time the timeout is not caused by the long ModPow execution.
The procedure works well if I set a constant value of 2 for _randomValue using the default code with ModPow.

[olegkap]

Ok, I will have to install local ubuntu version so I could test it out since its been a while and no longer have local version to test it so I will keep looking into it its just will take me some time

[edika99]

Ok thanks. In the meantime I'm trying to debug deeper the error.

[drieseng]

I had to revert the changes to BigInteger.Random(int bitLength) as they caused a regression (issue #147).

[drieseng]

@edika99 Can you provide the values for _prime, _group and _clientExchangeValue to allow me to reproduce this issue (and add a regression test)? Thx!

[drieseng]

@olegkap Were you referring to RFC 4419 in your first comment ?

That RFC states the following:

C generates a random number x, where 1 < x < (p-1)/2. It computes e = g^x mod p, and sends "e" to S.

Our code currently look like this:

var bitLength = _prime.BitLength;

do
{
    _randomValue = BigInteger.Random(bitLength);

    _clientExchangeValue = BigInteger.ModPow(_group, _randomValue, _prime);

} while (_clientExchangeValue < 1 || _clientExchangeValue > (_prime - 1));

Shouldn't it be more like this?

var maxRandomValue = (_prime - BigInteger.One) / 2;
var maxBitLength = maxRandomValue.BitLength;

do
{
    _randomValue = BigInteger.Random(maxBitLength);
} while (_randomValue < BigInteger.One || _randomValue > maxRandomValue);

_clientExchangeValue = BigInteger.ModPow(_group, _randomValue, _prime);

Note that this won't change the fact that ModPow takes a long time to execute, but at least we'll only execute it once.