Big delay on SSL Connection before "Enumerating security packages" stage

Question

I have C# tcp client (using .NET Framework 4.0) based on this MSDN article.

Like that:

_tcp = new TcpClient(_host, _port);
NetworkStream ns = _tcp.GetStream();
sslStream = new SslStream(
     ns,
     true,
     new RemoteCertificateValidationCallback(ValidateServerCertificate),
     null,
     EncryptionPolicy.AllowNoEncryption
     );
_cert = new X509Certificate2(_certFile, _certPass);
X509Certificate2Collection certs = null;
certs = new X509Certificate2Collection(_cert);
sslStream.AuthenticateAsClient(_host, certs, SslProtocols.Tls, false);

On most of the clients machines everything works fine (they are located in different cities), but there are some places, where almost every connection takes 10-30 seconds.

System.diagnostics trace shows that big delay occures on "SecureChannel - Enumerating security packages" stage. No other errors or exceptions. On good clients that takes just few milliseconds. [delay at 08:59:04 - 08:59:16]

System.Net.Sockets Verbose: 0 : [6260] TcpClient#2383799::TcpClient(www.our_domain.com)
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.0836341Z
System.Net.Sockets Verbose: 0 : [6260] TcpClient#2383799::Connect(www.our_domain.com)
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.0846341Z
System.Net.Sockets Verbose: 0 : [6260] DNS::GetHostAddresses(www.our_domain.com)
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.0846341Z
System.Net.Sockets Verbose: 0 : [6260] DNS::GetHostByName(www.our_domain.com)
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.0906341Z
System.Net.Sockets Verbose: 0 : [6260] Exiting DNS::GetHostByName()     -> IPHostEntry#21454193
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.7596341Z
System.Net.Sockets Verbose: 0 : [6260] Exiting DNS::GetHostAddresses()  -> IPAddress[]#58870012
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.7636341Z
System.Net.Sockets Verbose: 0 : [6260] Socket#60068066::Socket(AddressFamily#2)
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.7636341Z
System.Net.Sockets Verbose: 0 : [6260] Exiting Socket#60068066::Socket() 
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.7636341Z
System.Net.Sockets Verbose: 0 : [6260] Socket#3741682::Socket(AddressFamily#23)
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.7636341Z
System.Net.Sockets Verbose: 0 : [6260] Exiting Socket#3741682::Socket() 
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.7646341Z
System.Net.Sockets Verbose: 0 : [6260] Socket#60068066::Connect(_our_ip#-293710398)
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.7646341Z
System.Net.Sockets Verbose: 0 : [6260] Socket#60068066::Connect(_our_ip:_our_port#-293709425)
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.7646341Z
System.Net.Sockets Information: 0 : [6260] Socket#60068066 - Created connection from _client_ip:_client_port к _our_ip:_our_port.
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.9036341Z
System.Net.Sockets Verbose: 0 : [6260] Exiting Socket#60068066::Connect() 
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.9036341Z
System.Net.Sockets Verbose: 0 : [6260] Exiting Socket#60068066::Connect() 
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.9036341Z
System.Net.Sockets Verbose: 0 : [6260] Socket#3741682::Close()
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.9036341Z
System.Net.Sockets Verbose: 0 : [6260] Socket#3741682::Dispose()
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.9036341Z
System.Net.Sockets Verbose: 0 : [6260] Exiting Socket#3741682::Close() 
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.9046341Z
System.Net.Sockets Verbose: 0 : [6260] Exiting TcpClient#2383799::Connect() 
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.9046341Z
System.Net.Sockets Verbose: 0 : [6260] Exiting TcpClient#2383799::TcpClient() 
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.9046341Z
System.Net.Sockets Verbose: 0 : [6260] TcpClient#2383799::GetStream()
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.9046341Z
System.Net.Sockets Verbose: 0 : [6260] Exiting TcpClient#2383799::GetStream()   -> NetworkStream#34640832
    ProcessId=6880
    DateTime=2017-11-30T08:59:04.9046341Z
System.Net Information: 0 : [6260] SecureChannel#43332040::.ctor(hostname=www.our_domain.com, #clientCertificates=1, encryptionPolicy=RequireEncryption)
    ProcessId=6880
    DateTime=2017-11-30T08:59:16.1676341Z
System.Net Information: 0 : [6260] Enumerating security packages:
    ProcessId=6880
    DateTime=2017-11-30T08:59:16.1686341Z
System.Net Information: 0 : [6260]     Negotiate
    ProcessId=6880
    DateTime=2017-11-30T08:59:16.1686341Z
System.Net Information: 0 : [6260]     NegoExtender
    ProcessId=6880
    DateTime=2017-11-30T08:59:16.1686341Z
System.Net Information: 0 : [6260]     Kerberos
    ProcessId=6880
    DateTime=2017-11-30T08:59:16.1686341Z
System.Net Information: 0 : [6260]     NTLM
    ProcessId=6880
    DateTime=2017-11-30T08:59:16.1686341Z
System.Net Information: 0 : [6260]     Schannel
    ProcessId=6880
    DateTime=2017-11-30T08:59:16.1686341Z
System.Net Information: 0 : [6260]     Microsoft Unified Security Protocol Provider
    ProcessId=6880
    DateTime=2017-11-30T08:59:16.1696341Z
System.Net Information: 0 : [6260]     WDigest
    ProcessId=6880
    DateTime=2017-11-30T08:59:16.1696341Z
System.Net Information: 0 : [6260]     TSSSP
    ProcessId=6880
    DateTime=2017-11-30T08:59:16.1696341Z
System.Net Information: 0 : [6260]     pku2u
    ProcessId=6880
    DateTime=2017-11-30T08:59:16.1696341Z
System.Net Information: 0 : [6260]     CREDSSP
    ProcessId=6880
    DateTime=2017-11-30T08:59:16.1696341Z
System.Net Information: 0 : [6260] SecureChannel#43332040 - Attempting to restart the session using the user-provided certificate:
<...>

And that's everytime onward, but "Enumerating security packages" shows in trace only at first connection:

<...>
    ProcessId=6880
    DateTime=2017-11-30T08:59:27.8736341Z
System.Net Information: 0 : [6260] SecureChannel#13869071::.ctor(hostname=www.our_domain.com, #clientCertificates=1, encryptionPolicy=RequireEncryption)
    ProcessId=6880
    DateTime=2017-11-30T08:59:36.8386341Z
System.Net Information: 0 : [6260] SecureChannel#13869071 - Attempting to restart the session using the user-provided certificate: [Version]
<...>

Not helping:

Changing DNS-name of host to IP;
Changing port;
Changing server's side proxy;
Changing certificate (correct, trusted, with chain);
Changing SslStream or AuthenticateAsClient parameters.

And it might be just .Net problem, because connections via c++ libraries works fine.

Any ideas why is this happening? Some client's machine settings maybe? Coudn't find any helpful information on that...

Upd: investigating client's PC is:

Name = Windows 7
Edition = Enterprise
Service Pack = Service Pack 1
Version = 6.1.7601.65536
ProcessorBits = Bit64
OSBits = Bit64
ProgramBits = Bit32
IE_VERSION = 11.0.9600.18837
DOT_NET_VERSION = 
    v2.0.50727  2.0.50727.5420  SP2
    v3.0  3.0.30729.5420  SP2
    v3.5  3.5.30729.5420  SP1
    v4  
      Client  4.7.02053
      Full  4.7.02053
    v4.0  
      Client  4.0.0.0

Nope, default settings. `ProcessAuthentication(Protocol=Tls, Cipher=Aes256 256 bit strength, Hash=Sha1 160 bit strength, Key Exchange=44550 256 bit strength)` Client's machine spec is in upd in post. — Alex Moldovanov, Dec 01 '17 at 06:49

Big delay on SSL Connection before "Enumerating security packages" stage

0 Answers0