Runtime: Curl exception: Problem with the SSL CA cert (path? access rights?) on centos, fedora, redhat.

Created on 15 Feb 2017  路  89Comments  路  Source: dotnet/runtime

https://ci.dot.net/job/dotnet_corefx/job/master/job/outerloop_portablelinux_debug/lastCompletedBuild/testReport/System.Net.Tests/HttpWebRequestHeaderTest/GetResponse_UseDefaultCredentials_ExpectSuccess_remoteServer__https___corefx_net_cloudapp_net_Echo_ashx_/

MESSAGE:
System.Net.WebException : An error occurred while sending the request. Problem with the SSL CA cert (path? access rights?)\n---- System.Net.Http.HttpRequestException : An error occurred while sending the request.\n-------- System.Net.Http.CurlException : Problem with the SSL CA cert (path? access rights?)
+++++++++++++++++++
STACK TRACE:
at System.Net.HttpWebRequest.GetResponse() in /mnt/resource/j/workspace/dotnet_corefx/master/outerloop_portablelinux_debug/src/System.Net.Requests/src/System/Net/HttpWebRequest.cs:line 989 at System.Net.Tests.HttpWebRequestHeaderTest.GetResponse_UseDefaultCredentials_ExpectSuccess(Uri remoteServer) in /mnt/resource/j/workspace/dotnet_corefx/master/outerloop_portablelinux_debug/src/System.Net.Requests/tests/HttpWebRequestHeaderTest.cs:line 46 ----- Inner Stack Trace ----- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult() at System.Net.Http.HttpClient.<FinishSendAsyncUnbuffered>d__59.MoveNext() in /mnt/resource/j/workspace/dotnet_corefx/master/outerloop_portablelinux_debug/src/System.Net.Http/src/System/Net/Http/HttpClient.cs:line 487 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult() at System.Net.HttpWebRequest.<SendRequest>d__188.MoveNext() in /mnt/resource/j/workspace/dotnet_corefx/master/outerloop_portablelinux_debug/src/System.Net.Requests/src/System/Net/HttpWebRequest.cs:line 1192 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult() at System.Net.HttpWebRequest.GetResponse() in /mnt/resource/j/workspace/dotnet_corefx/master/outerloop_portablelinux_debug/src/System.Net.Requests/src/System/Net/HttpWebRequest.cs:line 985 ----- Inner Stack Trace ----- at System.Net.Http.CurlHandler.ThrowIfCURLEError(CURLcode error) in /mnt/resource/j/workspace/dotnet_corefx/master/outerloop_portablelinux_debug/src/System.Net.Http/src/System/Net/Http/Unix/CurlHandler.cs:line 640 at System.Net.Http.CurlHandler.MultiAgent.FinishRequest(StrongToWeakReference`1 easyWrapper, CURLcode messageResult) in /mnt/resource/j/workspace/dotnet_corefx/master/outerloop_portablelinux_debug/src/System.Net.Http/src/System/Net/Http/Unix/CurlHandler.MultiAgent.cs:line 852

@steveharter @Priya91 please either fix or (presumably) disable today, so we can get a green badge.

area-System.Net.Http bug os-linux test-run-core

Most helpful comment

The issue seems to be concurrency-related, and affects arbitrary .NET Core applications. With this program, I'm able to reproduce the problem about 25% of the time, using a 4-core CentOS 7 VM.

Decreasing the number of threads seems to make the problem happen less frequently, with the problem not reproducible at all with only one thread. Increasing the number of threads did not significantly increase probability.

```c#
using System;
using System.Linq;
using System.Net;
using System.Threading;

namespace ConsoleApp2
{
class Program
{
const string URI = "https://example.com";
static int Main(string[] args)
{
int Result = 0;
var Workers = Enumerable.Range(0, 4)
.Select(I => new Thread(() =>
{
try
{
var Req = WebRequest.CreateHttp(URI);
Req.Method = "HEAD";
using ( Req.GetResponseAsync().Result ) ;
}
catch ( Exception ex )
{
Console.WriteLine($"{I}: {ex}");
Result = 1;
}
})
{ IsBackground = true })
.ToArray();
foreach ( var T in Workers )
T.Start();
foreach ( var T in Workers )
T.Join();
return Result;
}
}
}


System/version information:

uname -a

Linux frqaclapp01.expoexchange.com 3.10.0-514.26.2.el7.x86_64 dotnet/corefx#1 SMP Tue Jul 4 15:04:05 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux

dotnet --version

1.0.4

curl --version

curl 7.29.0 (x86_64-redhat-linux-gnu) libcurl/7.29.0 NSS/3.21 Basic ECC zlib/1.2.7 libidn/1.28 libssh2/1.4.3
Protocols: dict file ftp ftps gopher http https imap imaps ldap ldaps pop3 pop3s rtsp scp sftp smtp smtps telnet tftp
Features: AsynchDNS GSS-Negotiate IDN IPv6 Largefile NTLM NTLM_WB SSL libz unix-sockets

rpm -qa | perl -ne 'm/curl|nss\b/&&print'

curl-7.29.0-35.el7.centos.x86_64
nss-softokn-freebl-3.16.2.3-14.4.el7.x86_64
nss-softokn-3.16.2.3-14.4.el7.x86_64
nss-sysinit-3.28.4-1.2.el7_3.x86_64
nss-tools-3.28.4-1.2.el7_3.x86_64
libcurl-7.29.0-35.el7.centos.x86_64
python-pycurl-7.19.0-19.el7.x86_64
nss-softokn-freebl-3.16.2.3-14.4.el7.i686
nss-util-3.28.4-1.0.el7_3.x86_64
nss-3.28.4-1.2.el7_3.x86_64
```

[EDIT] Add C# syntax highlight by @karelz

All 89 comments

Updated the machines to run update-ca-trust to keep the SSL certs database in sync with openssl cert path. This issue shouldn't happen anymore.

@Priya91 any insights?
cc @steveharter @ianhays

This failure seems to happen when curl is compiled with NSS as crypto backend. I tried issuing 200 requests with curl multi handler, and was not able to repro this outside of .NET apis, Tried on centos 7. This could be a .NET bug, cc @stephentoub do you have any ideas on how to proceed to debug this..

#include <stdio.h>
#include <string.h>
#include <curl/curl.h>

#define HANDLECOUNT 200

int main(void)
{
  CURL *handles[HANDLECOUNT];
  CURLM *multi_handle;

  int still_running; 
  int i;

  CURLMsg *msg; 
  int msgs_left; 
  FILE *filep = fopen("output.txt", "wb");
  for(i=0; i<HANDLECOUNT; i++)
  {
    handles[i] = curl_easy_init();
    curl_easy_setopt(handles[i], CURLOPT_URL, "https://corefx-net.cloudapp.net/Echo.ashx");
    curl_easy_setopt(handles[i], CURLOPT_VERBOSE, 1L);
    curl_easy_setopt(handles[i], CURLOPT_STDERR, filep);
  }
  multi_handle = curl_multi_init();

  for(i=0; i<HANDLECOUNT; i++)
    curl_multi_add_handle(multi_handle, handles[i]);
  do
  {
    curl_multi_perform(multi_handle, &still_running);
  } while (still_running != 0);

  while((msg = curl_multi_info_read(multi_handle, &msgs_left))) {
    if(msg->msg == CURLMSG_DONE) {
      printf("HTTP transfer completed with status %d\n", msg->data.result);
    }
  }

  curl_multi_cleanup(multi_handle);

  for(i=0; i<HANDLECOUNT; i++)
    curl_easy_cleanup(handles[i]);

  return 0;
}

The ssl ca cert path issue is the main cause of outerloop rhel, centos and fedora builds failing.

@tmds @omajid we could use your help on this issue ...

@Priya91 if the issue is occuring on some machines and not on others, perhaps we learn something by looking at difference in versions of the nss and curl packages on a working vs failing machine?

rpm -qa | grep nss
rpm -qa | grep curl

@tmds It's not a case of some machines, this failure happens on redhat, centos and fedora images.. Whereas ubuntu and debian which has curl with openssl doesn't have this failure. Also note that, the test is just sending a get response to a https server on azure, no extra certs are being added. Curl is calling for checking for certs from nss datastore.

The versions of curl and nss on the affected images are this,

[lasekar@centos ~]$ rpm -qa | grep curl
python-pycurl-7.19.0-17.el7.x86_64
libcurl-7.29.0-19.el7.x86_64
libcurl-devel-7.29.0-19.el7.x86_64
curl-7.29.0-19.el7.x86_64

[lasekar@centos ~]$ rpm -qa | grep nss
openssh-server-6.6.1p1-12.el7_1.x86_64
openssl-libs-1.0.1e-42.el7.9.x86_64
nss-softokn-freebl-3.16.2.3-12.el7_1.x86_64
nss-3.19.1-5.el7_1.x86_64
nss-sysinit-3.19.1-5.el7_1.x86_64
jansson-2.4-6.el7.x86_64
openssl-devel-1.0.1e-42.el7.9.x86_64
nss-softokn-3.16.2.3-12.el7_1.x86_64
openssh-6.6.1p1-12.el7_1.x86_64
openssh-clients-6.6.1p1-12.el7_1.x86_64
openssl-1.0.1e-42.el7.9.x86_64
nss-util-3.19.1-3.el7_1.x86_64
nss-tools-3.19.1-5.el7_1.x86_64

It's not a case of some machines, this failure happens on redhat, centos and fedora images

I misunderstood, I thought it was working on some rhel/centos/fedora machines.

Looking at the centos packages (http://mirror.centos.org/centos/7/os/x86_64/Packages/) there seem to be newer packages available. Does yum update bring newer versions of these packages? Perhaps they include a fix?

@tmds So i set the curl verbose option, and i didn't see the error from the data that curl prints. Somehow the curl easy agent is storing this error. Not sure what to make of it.

cc @stephentoub @steveharter

  /home/lasekar/corefx/bin/testhost/netcoreapp-Linux-Debug-x64//dotnet xunit.console.netcore.exe System.Net.Requests.Tests.dll  -xml testResults.xml -notrait Benchmark=true -notrait category=nonnetcoreapp1.1tests  -notrait category=failing -notrait category=nonlinuxtests
  ~/corefx/bin/AnyOS.AnyCPU.Debug/System.Net.Requests.Tests/netstandard ~/corefx/src/System.Net.Requests/tests
  xUnit.net console test runner (64-bit .NET Core)
  Copyright (C) 2014 Outercurve Foundation.

  Discovering: System.Net.Requests.Tests
  Discovered:  System.Net.Requests.Tests
  Starting:    System.Net.Requests.Tests
  * About to connect() to 127.0.0.1 port 34450 (#1)
  *   Trying 127.0.0.1...
  * TCP_NODELAY set
  * About to connect() to 127.0.0.1 port 49253 (#3)
  *   Trying 127.0.0.1...
  * TCP_NODELAY set
  * Connected to 127.0.0.1 (127.0.0.1) port 49253 (#3)
  * Connected to 127.0.0.1 (127.0.0.1) port 34450 (#1)
  > GET / HTTP/1.1
  Host: 127.0.0.1:49253
  Accept: */*
  Accept-Encoding: gzip,deflate

  > GET / HTTP/1.1
  Host: 127.0.0.1:34450
  Accept: */*
  Accept-Encoding: gzip,deflate

     System.Net.Tests.FtpWebRequestTest.Ftp_RenameFileSubDir_Success [SKIP]
        Condition(s) not met: \"LocalServerAvailable\"
     System.Net.Tests.FtpWebRequestTest.Ftp_MakeAndRemoveDir_Success [SKIP]
        Condition(s) not met: \"LocalServerAvailable\"
  < HTTP/1.1 200 OK
  < HTTP/1.1 200 OK
  < Date: Sat, 11 Mar 2017 00:00:02 GMT
  < Date: Sat, 11 Mar 2017 00:00:02 GMT
  < Content-Type: application/json;charset=UTF-8
  < Content-Length: 5
  < Content-Length: 5
  < 
  < 
  * Closing connection 3
  * About to connect() to 127.0.0.1 port 42625 (#4)
  *   Trying 127.0.0.1...
  * TCP_NODELAY set
  * Connected to 127.0.0.1 (127.0.0.1) port 42625 (#4)
  > GET / HTTP/1.1
  Host: 127.0.0.1:42625
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Date: Sat, 11 Mar 2017 00:00:02 GMT
  < Content-Type: text/html
  < Content-Length: 5
  < 
  * Closing connection 4
  * About to connect() to 127.0.0.1 port 52488 (#5)
  *   Trying 127.0.0.1...
  * TCP_NODELAY set
  * Connected to 127.0.0.1 (127.0.0.1) port 52488 (#5)
  > GET / HTTP/1.1
  Host: 127.0.0.1:52488
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Date: Sat, 11 Mar 2017 00:00:02 GMT
  < Content-Type: text/html; charset=utf-8
  < Content-Length: 5
  < 
  * Closing connection 5
  * About to connect() to 127.0.0.1 port 34625 (#6)
  *   Trying 127.0.0.1...
  * TCP_NODELAY set
  * Connected to 127.0.0.1 (127.0.0.1) port 34625 (#6)
  > GET / HTTP/1.1
  Host: 127.0.0.1:34625
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Date: Sat, 11 Mar 2017 00:00:02 GMT
  < Content-Type: TypeAndNoSubType
  < Content-Length: 5
  < 
  * Closing connection 6
  * Closing connection 1
  * About to connect() to 127.0.0.1 port 37020 (#7)
  *   Trying 127.0.0.1...
  * TCP_NODELAY set
  * Connected to 127.0.0.1 (127.0.0.1) port 37020 (#7)
  > GET / HTTP/1.1
  Host: 127.0.0.1:37020
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Date: Sat, 11 Mar 2017 00:00:02 GMT
  < Content-Type: application/json;charset=UTF-8
  < Content-Length: 5
  < 
  * Closing connection 7
  * About to connect() to 127.0.0.1 port 50718 (#8)
  *   Trying 127.0.0.1...
  * TCP_NODELAY set
  * Connected to 127.0.0.1 (127.0.0.1) port 50718 (#8)
  > GET / HTTP/1.1
  Host: 127.0.0.1:50718
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  * Connection dotnet/corefx#8 to host 127.0.0.1 left intact
  * About to connect() to 127.0.0.1 port 41451 (#9)
  *   Trying 127.0.0.1...
  * TCP_NODELAY set
  * Connected to 127.0.0.1 (127.0.0.1) port 41451 (#9)
  > GET / HTTP/1.1
  Host: 127.0.0.1:41451
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Date: Sat, 11 Mar 2017 00:00:02 GMT
  < Content-Type: application/json;charset=UTF-8
  < Content-Length: 5
  < 
  * About to connect() to corefx-net.cloudapp.net port 80 (#0)
  * About to connect() to corefx-net.cloudapp.net port 80 (#2)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 80 (#2)
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 80 (#0)
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: qEIGeeo7QcDVNABsNIvLUQ==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:01 GMT
  < Content-Length: 314
  < 
  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: qEIGeeo7QcDVNABsNIvLUQ==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:03 GMT
  < Content-Length: 314
  < 
  * About to connect() to corefx-net.cloudapp.net port 443 (#10)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * About to connect() to corefx-net.cloudapp.net port 443 (#11)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 443 (#10)
  * Initializing NSS with certpath: sql:/etc/pki/nssdb
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 443 (#11)
  *   CAfile: /etc/pki/tls/certs/ca-bundle.crt
    CApath: none
  * Closing connection 11
  * SSL connection using TLS_RSA_WITH_AES_256_CBC_SHA
  * Server certificate:
  *     subject: CN=corefx-net.cloudapp.net,OU=Microsoft Corporation,O=Microsoft Corporation,L=Redmond,ST=WA,C=US
  *     start date: Jan 12 01:18:21 2016 GMT
  *     expire date: Jan 11 01:18:21 2018 GMT
  *     common name: corefx-net.cloudapp.net
  *     issuer: CN=Microsoft IT SSL SHA2,OU=Microsoft IT,O=Microsoft Corporation,L=Redmond,ST=Washington,C=US
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: J2AUBYowrn+h4dfY0T8Y1g==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:04 GMT
  < Content-Length: 313
  < 
  * About to connect() to 127.0.0.1 port 33575 (#12)
  *   Trying 127.0.0.1...
  * TCP_NODELAY set
  * Connected to 127.0.0.1 (127.0.0.1) port 33575 (#12)
  > GET / HTTP/1.1
  Host: 127.0.0.1:33575
  Accept: */*
  Accept-Encoding: gzip,deflate

  * Closing connection 12
     System.Net.Tests.HttpWebRequestTest.GetResponseAsync_UseDefaultCredentials_ExpectSuccess(remoteServer: https://corefx-net.cloudapp.net/Echo.ashx) [FAIL]
        System.Net.WebException : An error occurred while sending the request. Problem with the SSL CA cert (path? access rights?)
        ---- System.Net.Http.HttpRequestException : An error occurred while sending the request.
        -------- System.Net.Http.CurlException : Problem with the SSL CA cert (path? access rights?)
        Stack Trace:
           /home/lasekar/corefx/src/System.Net.Requests/src/System/Net/HttpWebRequest.cs(1246,0): at System.Net.HttpWebRequest.EndGetResponse(IAsyncResult asyncResult)
           /home/lasekar/corefx/src/System.Net.Requests/src/System/Net/WebRequest.cs(552,0): at System.Net.WebRequest.<>c.<GetResponseAsync>b__68_2(IAsyncResult iar)
              at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
           --- End of stack trace from previous location where exception was thrown ---
              at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
              at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
              at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
           /home/lasekar/corefx/src/System.Net.Requests/tests/HttpWebRequestTest.cs(364,0): at System.Net.Tests.HttpWebRequestTest.<GetResponseAsync_UseDefaultCredentials_ExpectSuccess>d__43.MoveNext()
           --- End of stack trace from previous location where exception was thrown ---
              at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
              at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           --- End of stack trace from previous location where exception was thrown ---
              at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
              at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           --- End of stack trace from previous location where exception was thrown ---
              at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
              at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           ----- Inner Stack Trace -----
              at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
              at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
              at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
           /home/lasekar/corefx/src/System.Net.Http/src/System/Net/Http/HttpClient.cs(487,0): at System.Net.Http.HttpClient.<FinishSendAsyncUnbuffered>d__59.MoveNext()
           --- End of stack trace from previous location where exception was thrown ---
              at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
              at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
              at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
           /home/lasekar/corefx/src/System.Net.Requests/src/System/Net/HttpWebRequest.cs(1192,0): at System.Net.HttpWebRequest.<SendRequest>d__188.MoveNext()
           --- End of stack trace from previous location where exception was thrown ---
              at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
              at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
              at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
           /home/lasekar/corefx/src/System.Net.Requests/src/System/Net/HttpWebRequest.cs(1242,0): at System.Net.HttpWebRequest.EndGetResponse(IAsyncResult asyncResult)
           ----- Inner Stack Trace -----
           /home/lasekar/corefx/src/System.Net.Http/src/System/Net/Http/Unix/CurlHandler.cs(640,0): at System.Net.Http.CurlHandler.ThrowIfCURLEError(CURLcode error)
           /home/lasekar/corefx/src/System.Net.Http/src/System/Net/Http/Unix/CurlHandler.MultiAgent.cs(858,0): at System.Net.Http.CurlHandler.MultiAgent.FinishRequest(StrongToWeakReference`1 easyWrapper, CURLcode messageResult)
  * About to connect() to corefx-net.cloudapp.net port 80 (#13)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * About to connect() to corefx-net.cloudapp.net port 80 (#14)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 80 (#13)
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 80 (#14)
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: qEIGeeo7QcDVNABsNIvLUQ==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:05 GMT
  < Content-Length: 314
  < 
  * Closing connection 13
  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: qEIGeeo7QcDVNABsNIvLUQ==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:04 GMT
  < Content-Length: 314
  < 
  * About to connect() to corefx-net.cloudapp.net port 80 (#15)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * About to connect() to corefx-net.cloudapp.net port 443 (#16)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 80 (#15)
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 443 (#16)
  *   CAfile: /etc/pki/tls/certs/ca-bundle.crt
    CApath: none
  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: qEIGeeo7QcDVNABsNIvLUQ==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:06 GMT
  < Content-Length: 314
  < 
  * Closing connection 15
  * SSL connection using TLS_RSA_WITH_AES_256_CBC_SHA
  * Server certificate:
  *     subject: CN=corefx-net.cloudapp.net,OU=Microsoft Corporation,O=Microsoft Corporation,L=Redmond,ST=WA,C=US
  *     start date: Jan 12 01:18:21 2016 GMT
  *     expire date: Jan 11 01:18:21 2018 GMT
  *     common name: corefx-net.cloudapp.net
  *     issuer: CN=Microsoft IT SSL SHA2,OU=Microsoft IT,O=Microsoft Corporation,L=Redmond,ST=Washington,C=US
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: J2AUBYowrn+h4dfY0T8Y1g==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:06 GMT
  < Content-Length: 313
  < 
  * About to connect() to corefx-net.cloudapp.net port 443 (#17)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 443 (#17)
  *   CAfile: /etc/pki/tls/certs/ca-bundle.crt
    CApath: none
  * About to connect() to corefx-net.cloudapp.net port 80 (#18)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * SSL connection using TLS_RSA_WITH_AES_256_CBC_SHA
  * Server certificate:
  *     subject: CN=corefx-net.cloudapp.net,OU=Microsoft Corporation,O=Microsoft Corporation,L=Redmond,ST=WA,C=US
  *     start date: Jan 12 01:18:21 2016 GMT
  *     expire date: Jan 11 01:18:21 2018 GMT
  *     common name: corefx-net.cloudapp.net
  *     issuer: CN=Microsoft IT SSL SHA2,OU=Microsoft IT,O=Microsoft Corporation,L=Redmond,ST=Washington,C=US
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 80 (#18)
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: J2AUBYowrn+h4dfY0T8Y1g==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:06 GMT
  < Content-Length: 313
  < 
  * Closing connection 17
  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: qEIGeeo7QcDVNABsNIvLUQ==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:06 GMT
  < Content-Length: 314
  < 
  * Connection dotnet/runtime#13851 to host corefx-net.cloudapp.net left intact
  * About to connect() to corefx-net.cloudapp.net port 443 (#19)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 443 (#19)
  *   CAfile: /etc/pki/tls/certs/ca-bundle.crt
    CApath: none
  * SSL connection using TLS_RSA_WITH_AES_256_CBC_SHA
  * Server certificate:
  *     subject: CN=corefx-net.cloudapp.net,OU=Microsoft Corporation,O=Microsoft Corporation,L=Redmond,ST=WA,C=US
  *     start date: Jan 12 01:18:21 2016 GMT
  *     expire date: Jan 11 01:18:21 2018 GMT
  *     common name: corefx-net.cloudapp.net
  *     issuer: CN=Microsoft IT SSL SHA2,OU=Microsoft IT,O=Microsoft Corporation,L=Redmond,ST=Washington,C=US
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: J2AUBYowrn+h4dfY0T8Y1g==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:08 GMT
  < Content-Length: 313
  < 
  * Connection dotnet/corefx#19 to host corefx-net.cloudapp.net left intact
  * Could not resolve host: www.68d99c3f-313c-4d16-bfcf-ec15ca7a618d.com; Name or service not known
  * Closing connection 20
  * About to connect() to corefx-net.cloudapp.net port 80 (#21)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 80 (#21)
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: qEIGeeo7QcDVNABsNIvLUQ==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:10 GMT
  < Content-Length: 314
  < 
  * About to connect() to corefx-net.cloudapp.net port 443 (#22)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 443 (#22)
  *   CAfile: /etc/pki/tls/certs/ca-bundle.crt
    CApath: none
  * SSL connection using TLS_RSA_WITH_AES_256_CBC_SHA
  * Server certificate:
  *     subject: CN=corefx-net.cloudapp.net,OU=Microsoft Corporation,O=Microsoft Corporation,L=Redmond,ST=WA,C=US
  *     start date: Jan 12 01:18:21 2016 GMT
  *     expire date: Jan 11 01:18:21 2018 GMT
  *     common name: corefx-net.cloudapp.net
  *     issuer: CN=Microsoft IT SSL SHA2,OU=Microsoft IT,O=Microsoft Corporation,L=Redmond,ST=Washington,C=US
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: J2AUBYowrn+h4dfY0T8Y1g==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:11 GMT
  < Content-Length: 313
  < 
  * About to connect() to corefx-net.cloudapp.net port 80 (#23)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 80 (#23)
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate
  Content-Type: application/json
  Content-Length: 0
  Expect: 100-continue

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: HpbhwQr0VGErhy+YpegSlg==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:13 GMT
  < Content-Length: 414
  < 
  * Connection dotnet/corefx#23 to host corefx-net.cloudapp.net left intact
  * About to connect() to corefx-net.cloudapp.net port 443 (#24)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 443 (#24)
  *   CAfile: /etc/pki/tls/certs/ca-bundle.crt
    CApath: none
  * SSL connection using TLS_RSA_WITH_AES_256_CBC_SHA
  * Server certificate:
  *     subject: CN=corefx-net.cloudapp.net,OU=Microsoft Corporation,O=Microsoft Corporation,L=Redmond,ST=WA,C=US
  *     start date: Jan 12 01:18:21 2016 GMT
  *     expire date: Jan 11 01:18:21 2018 GMT
  *     common name: corefx-net.cloudapp.net
  *     issuer: CN=Microsoft IT SSL SHA2,OU=Microsoft IT,O=Microsoft Corporation,L=Redmond,ST=Washington,C=US
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate
  Content-Type: application/json
  Content-Length: 0
  Expect: 100-continue

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: 3MEA+iUUHCB4fBoD8xCzew==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:14 GMT
  < Content-Length: 413
  < 
  * Connection dotnet/corefx#24 to host corefx-net.cloudapp.net left intact
  * About to connect() to corefx-net.cloudapp.net port 80 (#25)
  * About to connect() to corefx-net.cloudapp.net port 443 (#26)
  *   Trying 40.118.166.132...
  *   Trying 40.118.166.132...
  * * TCP_NODELAY set
  TCP_NODELAY set
  * About to connect() to corefx-net.cloudapp.net port 80 (#27)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 80 (#25)
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 443 (#26)
  *   CAfile: /etc/pki/tls/certs/ca-bundle.crt
    CApath: none
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 80 (#27)
  > POST /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate
  Content-Length: 21

  * upload completely sent off: 21 out of 21 bytes
  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: qEIGeeo7QcDVNABsNIvLUQ==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:14 GMT
  < Content-Length: 314
  < 
  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: UTqpPsxAFRshpQFY8hV6hw==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: POST
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:15 GMT
  < Content-Length: 366
  < 
  * Connection dotnet/corefx#27 to host corefx-net.cloudapp.net left intact
  * SSL connection using TLS_RSA_WITH_AES_256_CBC_SHA
  * Server certificate:
  *     subject: CN=corefx-net.cloudapp.net,OU=Microsoft Corporation,O=Microsoft Corporation,L=Redmond,ST=WA,C=US
  *     start date: Jan 12 01:18:21 2016 GMT
  *     expire date: Jan 11 01:18:21 2018 GMT
  *     common name: corefx-net.cloudapp.net
  *     issuer: CN=Microsoft IT SSL SHA2,OU=Microsoft IT,O=Microsoft Corporation,L=Redmond,ST=Washington,C=US
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: J2AUBYowrn+h4dfY0T8Y1g==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:14 GMT
  < Content-Length: 313
  < 
  * About to connect() to corefx-net.cloudapp.net port 443 (#28)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 443 (#28)
  *   CAfile: /etc/pki/tls/certs/ca-bundle.crt
    CApath: none
  * SSL connection using TLS_RSA_WITH_AES_256_CBC_SHA
  * Server certificate:
  *     subject: CN=corefx-net.cloudapp.net,OU=Microsoft Corporation,O=Microsoft Corporation,L=Redmond,ST=WA,C=US
  *     start date: Jan 12 01:18:21 2016 GMT
  *     expire date: Jan 11 01:18:21 2018 GMT
  *     common name: corefx-net.cloudapp.net
  *     issuer: CN=Microsoft IT SSL SHA2,OU=Microsoft IT,O=Microsoft Corporation,L=Redmond,ST=Washington,C=US
  > POST /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate
  Content-Length: 21

  * upload completely sent off: 21 out of 21 bytes
  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: MpNzZ2AVX/3hEj9uViIkcw==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: POST
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:16 GMT
  < Content-Length: 365
  < 
  * Connection dotnet/corefx#28 to host corefx-net.cloudapp.net left intact
  * About to connect() to corefx-net.cloudapp.net port 80 (#29)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 80 (#29)
  > POST /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate
  Content-Length: 21

  * upload completely sent off: 21 out of 21 bytes
  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: UTqpPsxAFRshpQFY8hV6hw==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: POST
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:16 GMT
  < Content-Length: 366
  < 
  * Connection dotnet/corefx#29 to host corefx-net.cloudapp.net left intact
  * About to connect() to corefx-net.cloudapp.net port 443 (#30)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 443 (#30)
  *   CAfile: /etc/pki/tls/certs/ca-bundle.crt
    CApath: none
  * SSL connection using TLS_RSA_WITH_AES_256_CBC_SHA
  * Server certificate:
  *     subject: CN=corefx-net.cloudapp.net,OU=Microsoft Corporation,O=Microsoft Corporation,L=Redmond,ST=WA,C=US
  *     start date: Jan 12 01:18:21 2016 GMT
  *     expire date: Jan 11 01:18:21 2018 GMT
  *     common name: corefx-net.cloudapp.net
  *     issuer: CN=Microsoft IT SSL SHA2,OU=Microsoft IT,O=Microsoft Corporation,L=Redmond,ST=Washington,C=US
  > POST /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate
  Content-Length: 21

  * upload completely sent off: 21 out of 21 bytes
  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: MpNzZ2AVX/3hEj9uViIkcw==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: POST
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:17 GMT
  < Content-Length: 365
  < 
  * Connection dotnet/corefx#30 to host corefx-net.cloudapp.net left intact
  * About to connect() to corefx-net.cloudapp.net port 80 (#31)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 80 (#31)
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: qEIGeeo7QcDVNABsNIvLUQ==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:19 GMT
  < Content-Length: 314
  < 
  * About to connect() to corefx-net.cloudapp.net port 443 (#32)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 443 (#32)
  *   CAfile: /etc/pki/tls/certs/ca-bundle.crt
    CApath: none
  * SSL connection using TLS_RSA_WITH_AES_256_CBC_SHA
  * Server certificate:
  *     subject: CN=corefx-net.cloudapp.net,OU=Microsoft Corporation,O=Microsoft Corporation,L=Redmond,ST=WA,C=US
  *     start date: Jan 12 01:18:21 2016 GMT
  *     expire date: Jan 11 01:18:21 2018 GMT
  *     common name: corefx-net.cloudapp.net
  *     issuer: CN=Microsoft IT SSL SHA2,OU=Microsoft IT,O=Microsoft Corporation,L=Redmond,ST=Washington,C=US
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: J2AUBYowrn+h4dfY0T8Y1g==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:20 GMT
  < Content-Length: 313
  < 
  * About to connect() to corefx-net.cloudapp.net port 80 (#33)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 80 (#33)
  > GET /StatusCode.ashx?statuscode=404 HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 404 Not Found
  < Cache-Control: private
  < Content-Type: text/html
  < Server: Microsoft-IIS/8.5
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:21 GMT
  < Content-Length: 1245
  < 
  * About to connect() to corefx-net.cloudapp.net port 443 (#34)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 443 (#34)
  *   CAfile: /etc/pki/tls/certs/ca-bundle.crt
    CApath: none
  * SSL connection using TLS_RSA_WITH_AES_256_CBC_SHA
  * Server certificate:
  *     subject: CN=corefx-net.cloudapp.net,OU=Microsoft Corporation,O=Microsoft Corporation,L=Redmond,ST=WA,C=US
  *     start date: Jan 12 01:18:21 2016 GMT
  *     expire date: Jan 11 01:18:21 2018 GMT
  *     common name: corefx-net.cloudapp.net
  *     issuer: CN=Microsoft IT SSL SHA2,OU=Microsoft IT,O=Microsoft Corporation,L=Redmond,ST=Washington,C=US
  > GET /StatusCode.ashx?statuscode=404 HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 404 Not Found
  < Cache-Control: private
  < Content-Type: text/html
  < Server: Microsoft-IIS/8.5
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:22 GMT
  < Content-Length: 1245
  < 
  * About to connect() to corefx-net.cloudapp.net port 80 (#35)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 80 (#35)
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: qEIGeeo7QcDVNABsNIvLUQ==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:23 GMT
  < Content-Length: 314
  < 
  * Connection dotnet/runtime#13855 to host corefx-net.cloudapp.net left intact
  * About to connect() to corefx-net.cloudapp.net port 443 (#36)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 443 (#36)
  *   CAfile: /etc/pki/tls/certs/ca-bundle.crt
    CApath: none
  * SSL connection using TLS_RSA_WITH_AES_256_CBC_SHA
  * Server certificate:
  *     subject: CN=corefx-net.cloudapp.net,OU=Microsoft Corporation,O=Microsoft Corporation,L=Redmond,ST=WA,C=US
  *     start date: Jan 12 01:18:21 2016 GMT
  *     expire date: Jan 11 01:18:21 2018 GMT
  *     common name: corefx-net.cloudapp.net
  *     issuer: CN=Microsoft IT SSL SHA2,OU=Microsoft IT,O=Microsoft Corporation,L=Redmond,ST=Washington,C=US
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: J2AUBYowrn+h4dfY0T8Y1g==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:25 GMT
  < Content-Length: 313
  < 
  * Connection dotnet/runtime#13856 to host corefx-net.cloudapp.net left intact
  * About to connect() to corefx-net.cloudapp.net port 80 (#37)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * About to connect() to corefx-net.cloudapp.net port 443 (#38)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * About to connect() to corefx-net.cloudapp.net port 80 (#39)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 80 (#37)
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 443 (#38)
  *   CAfile: /etc/pki/tls/certs/ca-bundle.crt
    CApath: none
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 80 (#39)
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: qEIGeeo7QcDVNABsNIvLUQ==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:26 GMT
  < Content-Length: 314
  < 
  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: qEIGeeo7QcDVNABsNIvLUQ==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:26 GMT
  < Content-Length: 314
  < 
  * Connection dotnet/corefx#39 to host corefx-net.cloudapp.net left intact
  * SSL connection using TLS_RSA_WITH_AES_256_CBC_SHA
  * Server certificate:
  *     subject: CN=corefx-net.cloudapp.net,OU=Microsoft Corporation,O=Microsoft Corporation,L=Redmond,ST=WA,C=US
  *     start date: Jan 12 01:18:21 2016 GMT
  *     expire date: Jan 11 01:18:21 2018 GMT
  *     common name: corefx-net.cloudapp.net
  *     issuer: CN=Microsoft IT SSL SHA2,OU=Microsoft IT,O=Microsoft Corporation,L=Redmond,ST=Washington,C=US
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: J2AUBYowrn+h4dfY0T8Y1g==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:25 GMT
  < Content-Length: 313
  < 
  * About to connect() to corefx-net.cloudapp.net port 443 (#40)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 443 (#40)
  *   CAfile: /etc/pki/tls/certs/ca-bundle.crt
    CApath: none
  * SSL connection using TLS_RSA_WITH_AES_256_CBC_SHA
  * Server certificate:
  *     subject: CN=corefx-net.cloudapp.net,OU=Microsoft Corporation,O=Microsoft Corporation,L=Redmond,ST=WA,C=US
  *     start date: Jan 12 01:18:21 2016 GMT
  *     expire date: Jan 11 01:18:21 2018 GMT
  *     common name: corefx-net.cloudapp.net
  *     issuer: CN=Microsoft IT SSL SHA2,OU=Microsoft IT,O=Microsoft Corporation,L=Redmond,ST=Washington,C=US
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: J2AUBYowrn+h4dfY0T8Y1g==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:27 GMT
  < Content-Length: 313
  < 
  * Connection dotnet/corefx#40 to host corefx-net.cloudapp.net left intact
  * About to connect() to corefx-net.cloudapp.net port 80 (#41)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 80 (#41)
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: qEIGeeo7QcDVNABsNIvLUQ==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:27 GMT
  < Content-Length: 314
  < 
  * About to connect() to corefx-net.cloudapp.net port 443 (#42)
  *   Trying 40.118.166.132...
  * TCP_NODELAY set
  * Connected to corefx-net.cloudapp.net (40.118.166.132) port 443 (#42)
  *   CAfile: /etc/pki/tls/certs/ca-bundle.crt
    CApath: none
  * SSL connection using TLS_RSA_WITH_AES_256_CBC_SHA
  * Server certificate:
  *     subject: CN=corefx-net.cloudapp.net,OU=Microsoft Corporation,O=Microsoft Corporation,L=Redmond,ST=WA,C=US
  *     start date: Jan 12 01:18:21 2016 GMT
  *     expire date: Jan 11 01:18:21 2018 GMT
  *     common name: corefx-net.cloudapp.net
  *     issuer: CN=Microsoft IT SSL SHA2,OU=Microsoft IT,O=Microsoft Corporation,L=Redmond,ST=Washington,C=US
  > GET /Echo.ashx HTTP/1.1
  Host: corefx-net.cloudapp.net
  Accept: */*
  Accept-Encoding: gzip,deflate

  < HTTP/1.1 200 OK
  < Cache-Control: private
  < Content-Type: application/json; charset=utf-8
  < Content-MD5: J2AUBYowrn+h4dfY0T8Y1g==
  < Server: Microsoft-IIS/8.5
  < X-HttpRequest-Method: GET
  < X-AspNet-Version: 4.0.30319
  < X-Powered-By: ASP.NET
  < Date: Sat, 11 Mar 2017 00:00:29 GMT
  < Content-Length: 313
  < 
     System.Net.Tests.FtpWebRequestTest.Ftp_CreateAndDelete [SKIP]
        Condition(s) not met: \"LocalServerAvailable\"
     System.Net.Tests.FtpWebRequestTest.Ftp_RenameFile [SKIP]
        Condition(s) not met: \"LocalServerAvailable\"
     System.Net.Tests.FtpWebRequestTest.Ftp_AppendFile [SKIP]
        Condition(s) not met: \"LocalServerAvailable\"
     System.Net.Tests.FtpWebRequestTest.Ftp_LargeFile [SKIP]
        Condition(s) not met: \"LocalServerAvailable\"
  Finished:    System.Net.Requests.Tests

  === TEST EXECUTION SUMMARY ===
/home/lasekar/corefx/Tools/tests.targets(249,5): warning :    System.Net.Requests.Tests  Total: 218, Errors: 0, Failed: 1, Skipped: 6, Time: 128.209s [/home/lasekar/corefx/src/System.Net.Requests/tests/System.Net.Requests.Tests.csproj]
  The previous error was converted to a warning because the task was called with ContinueOnError=true.
  ~/corefx/src/System.Net.Requests/tests
  Finished running tests. End time=00:02:10. Return value was 1
/home/lasekar/corefx/Tools/tests.targets(249,5): warning MSB3073: The command "/home/lasekar/corefx/bin/AnyOS.AnyCPU.Debug/System.Net.Requests.Tests/netstandard/RunTests.sh /home/lasekar/corefx/bin/testhost/netcoreapp-Linux-Debug-x64/" exited with code 1. [/home/lasekar/corefx/src/System.Net.Requests/tests/System.Net.Requests.Tests.csproj]
  The previous error was converted to a warning because the task was called with ContinueOnError=true.
  Build continuing because "ContinueOnError" on the task "Exec" is set to "true".
/home/lasekar/corefx/Tools/tests.targets(257,5): error : One or more tests failed while running tests from 'System.Net.Requests.Tests' please check /home/lasekar/corefx/bin/AnyOS.AnyCPU.Debug/System.Net.Requests.Tests/netstandard/testResults.xml for details! [/home/lasekar/corefx/src/System.Net.Requests/tests/System.Net.Requests.Tests.csproj]
Done Building Project "/home/lasekar/corefx/src/System.Net.Requests/tests/System.Net.Requests.Tests.csproj" (Rebuildandtest target(s)) -- FAILED.

Build FAILED.

"/home/lasekar/corefx/src/System.Net.Requests/tests/System.Net.Requests.Tests.csproj" (Rebuildandtest target) (1) ->
(RunTestsForProject target) -> 
  /home/lasekar/corefx/Tools/tests.targets(249,5): warning :    System.Net.Requests.Tests  Total: 218, Errors: 0, Failed: 1, Skipped: 6, Time: 128.209s [/home/lasekar/corefx/src/System.Net.Requests/tests/System.Net.Requests.Tests.csproj]
  /home/lasekar/corefx/Tools/tests.targets(249,5): warning MSB3073: The command "/home/lasekar/corefx/bin/AnyOS.AnyCPU.Debug/System.Net.Requests.Tests/netstandard/RunTests.sh /home/lasekar/corefx/bin/testhost/netcoreapp-Linux-Debug-x64/" exited with code 1. [/home/lasekar/corefx/src/System.Net.Requests/tests/System.Net.Requests.Tests.csproj]


"/home/lasekar/corefx/src/System.Net.Requests/tests/System.Net.Requests.Tests.csproj" (Rebuildandtest target) (1) ->
(RunTestsForProject target) -> 
  /home/lasekar/corefx/Tools/tests.targets(257,5): error : One or more tests failed while running tests from 'System.Net.Requests.Tests' please check /home/lasekar/corefx/bin/AnyOS.AnyCPU.Debug/System.Net.Requests.Tests/netstandard/testResults.xml for details! [/home/lasekar/corefx/src/System.Net.Requests/tests/System.Net.Requests.Tests.csproj]

    2 Warning(s)
    1 Error(s)

Time Elapsed 00:02:13.26

Somehow the curl easy agent is storing this error. Not sure what to make of it.

@Priya91, what information are you trying to gather? You can get all of the diagnostic info we have, including but beyond what libcurl's verbose option spits out, by setting up an EventListener, like https://github.com/dotnet/corefx/blob/master/src/Common/tests/System/Diagnostics/Tracing/ConsoleEventListener.cs, and just having it trace out every event.

what information are you trying to gather?

Looking at what curl spits out from the requests passed down to it from .NET, there is no error 77 (the code responsible for ssl ca path errors) from it. All the curl requests succeed finding the CAFile with messages like below:

* Connected to corefx-net.cloudapp.net (40.118.166.132) port 443 (#36)
  *   CAfile: /etc/pki/tls/certs/ca-bundle.crt
    CApath: none

So I don't understand how .net is reporting this error, when it doesn't happen in curl. Or am I reading this data wrong..

What do you see output from the events I mentioned? They should be fairly detailed, and you can add more.

What do you see output from the events I mentioned?

Tried using the event tracing, and below is the output. I haven't analyzed it yet, posting it here for info.. Are the TPLEventSource lines helpful? Not sure what to read from them..

https://gist.github.com/Priya91/3a27d429340e66e6e251ef8a1f081272

Are the TPLEventSource lines helpful?

For this investigation, no. What's helpful are the Microsoft-System-Net-Http-12 lines. In the future you can pass a string like "Http" to the ConsoleEventListener ctor to filter down to just those.

Not sure what to read from them

This is the relevant part:

  [Microsoft-System-Net-Http-12] (871, 870, CurlDebugFunction, CURLINFO_TEXT: About to connect() to corefx-net.cloudapp.net port 443 (#11)).

  [Microsoft-System-Net-Http-12] (871, 870, CurlDebugFunction, CURLINFO_TEXT: Trying 40.118.166.132...).

  [Microsoft-System-Net-Http-12] (871, 870, CurlDebugFunction, CURLINFO_TEXT: TCP_NODELAY set).

  [Microsoft-System-Net-Http-12] (854, 849, CurlDebugFunction, CURLINFO_TEXT: Connected to corefx-net.cloudapp.net (40.118.166.132) port 443 (#10)).

  [Microsoft-System-Net-Http-12] (854, 849, CurlDebugFunction, CURLINFO_TEXT: Initializing NSS with certpath: sql:/etc/pki/nssdb).

  [Microsoft-System-Net-Http-12] (871, 870, CurlDebugFunction, CURLINFO_TEXT: Connected to corefx-net.cloudapp.net (40.118.166.132) port 443 (#11)).

  [Microsoft-System-Net-Http-12] (871, 870, CurlDebugFunction, CURLINFO_TEXT: Closing connection 11).

  [Microsoft-System-Net-Http-12] (871, 870, FinishRequest, Curl result: 77).

  [Microsoft-System-Net-Http-12] (0, 0, ThrowIfCURLEError, Problem with the SSL CA cert (path? access rights?)).

  [Microsoft-System-Net-Http-12] (871, 870, FailRequest, Failing request: System.Net.Http.CurlException: Problem with the SSL CA cert (path? access rights?)

     at System.Net.Http.CurlHandler.ThrowIfCURLEError(CURLcode error) in /home/lasekar/corefx/src/System.Net.Http/src/System/Net/Http/Unix/CurlHandler.cs:line 640

     at System.Net.Http.CurlHandler.MultiAgent.FinishRequest(StrongToWeakReference`1 easyWrapper, CURLcode messageResult) in /home/lasekar/corefx/src/System.Net.Http/src/System/Net/Http/Unix/CurlHandler.MultiAgent.cs:line 858).

so we're calling FinishRequest (https://github.com/dotnet/corefx/blob/1543bcfce778ef9d124c638cde712ed147e826bd/src/System.Net.Http/src/System/Net/Http/Unix/CurlHandler.MultiAgent.cs#L811) with the error:
https://curl.haxx.se/libcurl/c/libcurl-errors.html

  CURLE_SSL_CACERT_BADFILE,      /* 77 - could not load CACERT file, missing or wrong format */

that would have come from asking curl for the completed operation's info here:
https://github.com/dotnet/corefx/blob/1543bcfce778ef9d124c638cde712ed147e826bd/src/System.Net.Http/src/System/Net/Http/Unix/CurlHandler.MultiAgent.cs#L394

Searching online for CentOS and 77 or CURLE_SSL_CACERT_BADFILE yields some results (which may or may not be related), e.g.
https://bugs.centos.org/view.php?id=7647
http://stackoverflow.com/questions/17064601/curl-not-working-error-77-for-ssl-connections-on-centos-for-non-root-users
http://stackoverflow.com/questions/27987091/ssl-ca-cert-path-access-rights
https://syslint.com/blog/tutorial/curl-77-problem-with-the-ssl-ca-cert-path-access-rights-solved/

@Priya91 have you run yum update to make sure the problem exists also when using the latest curl and nss packages?

@stephentoub Thanks! The issue i'm trying to understand is why the error happens. We already have data on what the error is.. This seems to happen inconsistently when all of the tests are run in the assembly. When that particular test is run, the failure doesn't repro. Also using Curl directly outside of .NET, issuing 200 easy requests with a multi agent doesn't repro the issue.

@tmds Still fails with yum update.

I have seen this error message on my end too (in a VM), while building other repos. Don't have a way to isolate/reproduce it.

I think this issue may be caused by: https://bugzilla.mozilla.org/show_bug.cgi?id=1297397
The fix is in nss 3.29 and worked around in libcurl 7.50.

CC @omajid

Is there a way to detect the problem happen? Can we rerun the test in such case?
Or another way how to avoid hitting the bug?

Alternatives:

  1. Bundle the right version of curl/nss with .NET Core -- quite nasty, lots of work and clashes with portable Linux effort.
  2. Deploy fixed curl/nss on our test machines -- non-trivial work to maintain it long-term. Also, we should IMO try to test combo we officially support without modifications, otherwise we might have missed things.
  3. Wait for newer distros to bundle fixed NSS/curl and migrate testing primarily to the new version, we could disable the tests on older versions of the same distro.

    • @tmds do you know when the fixed NSS/curl will be part of official distros? (RedHat, CentOS and Fedora)

Thoughts?

@omajid and I can build some packages to install on the CI machines. If we no more failures, it's safe to assume we found the root cause. We'll then start the process of getting the packages updated in the distros.

Unfortunately this is not the root cause. While building packages, I found out the rhel 7.29 package has a backport of the fix already :(

We've built a version of curl 7.29 which will output on conditions returning CURLE_SSL_CACERT_BADFILE.
You can download it at:
https://drive.google.com/file/d/0BxjFv_21wKp_NUFzUXhWeW5kUkE/view?usp=sharing
https://drive.google.com/file/d/0BxjFv_21wKp_NEZiS1lRaE42YWM/view?usp=sharing

@Priya91 can you install this on the RHEL and CentOS CI machines?

sudo rpm -U libcurl-7.29.0-39.el7.x86_64.rpm curl-7.29.0-39.el7.x86_64.rpm

It will print in the CurlDebugFunction on these 5 conditions:

   infof(data, "nss_find_slot_by_name failed for '%s'\n", slot_name);
   infof(data, "PK11_FreeSlot failed for '%s'\n", slot_name);
   infof(data, "nss_create_object failed for '%s' '%s'\n", filename, cacert);
   infof(data, "failed to stat capath '%s'\n", capath);
   infof(data, "failed to PR_OpenDir '%s'\n", capath);

I am hesitant to start changing CI machines OS until we fully understand what we are doing. It would change our OS versions test coverage - we need to think that through.
I assume we are able to reproduce the problem (after stressing a set of tests on a machine). Let's verify it in such environment first.

This issue is repro on build 20170326.03, detail: https://mc.dot.net/#/product/netcore/master/source/official~2Fcorefx~2Fmaster~2F/type/test~2Ffunctional~2Fcli~2F/build/20170326.03/workItem/System.Net.Http.Functional.Tests/analysis/xunit/System.Net.Http.Functional.Tests.PostScenarioTest~2FPostUsingContentLengthSemantics_Success(serverUri:%20https:~2F~2Fcorefx-net.cloudapp.net~2FEcho.ashx)

I assume we are able to reproduce the problem (after stressing a set of tests on a machine). Let's verify it in such environment first.

I have not reproduced this problem myself. I only observe it happens via this issue tracker. @Priya91 do you have experience reproducing this?

@tmds Yes, Just use the default rhel 7.2 image from azure, and clone the repo and run the tests.

I get the custom packages on my test vm and try to get additional data.

@tmds When i try to install the custom packages, I get

error: Failed dependencies:
        libcurl = 7.29.0-25.el7 is needed by (installed) libcurl-devel-7.29.0-25.el7.x86_64

Ah yes, you also need updates for the packages which are already on the machine.
devel:
https://drive.google.com/file/d/0BxjFv_21wKp_OUFyUkxySGQ5Tzg/view?usp=sharing
Perhaps debuginfo is installed too:
https://drive.google.com/file/d/0BxjFv_21wKp_YVNoWWllX3J4ZEk/view?usp=sharing

@Priya91 don't know if you saw I provided some additional packages.
@Priya91 @karelz @stephentoub The packages built by Red Hat for RHEL use OpenSSL.

@tmds We may not need to fix this, if dotnet/corefx#17647 happens. Pushing this out for now, to focus on other 2.0 work items. Will revisit in some time again. Thanks for being on top of this :)

Looks like there's no new reports of this failure on this issue, will check for data on jdash and update on next steps.

Looks like there's no new reports of this failure on this issue

The referenced issues above are places I linked to this issue as part of restarting a leg due to this failure.

Been reading curl docs around this failure, and since we don't support ssl scenarios with nss as backend, one option will be to point the cert database to an empty dir location with SSL_DIR env variable, then it should bypass the nss db load initialization here

since we don't support ssl scenarios with nss as backend

We do. We just don't support customizing them, e.g. using a cert validation callback, enabling revocation checking, etc. But you can certainly use HttpClient with such a backend to connect to https endpoints.

@karelz @Priya91 @stephentoub Users running on rhel should use the .NET Core packages of rhel which includes a newer version of libcurl and is linked with openssl.

I've provided some libcurl builds that provide debug info which should help find the root cause of this issue. I don't think these are installed on a CI machine.

Perhaps this issue should no longer target 2.0?

This issue is top test failure, making our Networking test suite unreliable. That's why we are keeping it in 2.0. I would really like it to see addressed (somehow) in 2.0, to lower test-failure noise in 2.x servicing branches.

somehow:

  • investigate root cause and try to solve it (not feasible for 2.0)
  • disable test
  • use curl libraries from dotnet scl
  • other?

Disable test is not feasible, because it shows up in random tests all over.

I am waiting on @Priya91's recommendation ...

@tmds You mention that Users running on rhel should use the .NET Core packages of rhel which includes a newer version of libcurl and is linked with openssl?

Does that mean that on installing a rhel image, the default curl install will now be built with openssl? Also, how do we update the CI machines to get this libcurl version, it would be ideal if we can get it from scl, and not install a custom build, in which case later re-imaging will be difficult. We have the same issue on centos and fedora, would the same upgrade work there as well?

@Priya91 On RHEL the default version of curl is an 'old' one and it stays that way to keep compatibility.
If you install dotnet on RHEL (per https://www.microsoft.com/net/core#linuxredhat), this will include a more recent version of libcurl.
This libcurl does not replace the system version. It is only used when doing dotnet stuff. It gets used because when you do scl enable rh-dotnetcoreXX bash this sets the LD_LIBRARY_PATH envvar which makes it find the more recent libcurl.

You can use this libcurl by installing the dotnet scl and setting the LD_LIBRARY_PATH (to match the envvar when the scl is enabled).

CentOS: there is no dotnet package yet. We will work on this after shipping 2.0 for RHEL. It will work in the same manner as the RHEL package.
Fedora: If this issue does only happen on Fedora 24 (and not on Fedora 25), it's safe to ignore it. 24 is EOL in September 2017.

@Priya91 what is your recommendation? What are the next steps?

I'm gonna first try setting the SSL_DIR env variable to an empty dir on the initialization script as it's easier to set this up than re-imaging.

Made the change to provide empty cert dir with SSL_DIR env variable. Closing as fixed, please re-open if failures reappear.

Great, thanks @Priya91!

This issue is repro on Portable Core Tests in build 20170517.01, detail: https://mc.dot.net/#/product/netcore/master/source/official~2Fcorefx~2Fmaster~2F/type/test~2Ffunctional~2Fportable~2Fcli~2F/build/20170517.01/workItem/System.Net.Http.Functional.Tests/analysis/xunit/System.Net.Http.Functional.Tests.HttpClientHandler_ServerCertificates_Test~2FNoCallback_RevokedCertificate_NoRevocationChecking_Succeeds

The one CI failure is surprising - likely due to stale VM which didn't get the workaround yet.
The MC failure is the first one in a long time. If we see more instances of that, we should create a new bug.

@karelz I have the same issue in my project and I can't make any https request from my .NET Core (1.1.1) application. I face with it when send email with Amazon SDK. https://github.com/aws/aws-sdk-net/issues/662

Is there any workaround?

@sharok so far this issue was only observed on CentOS, Fedora and RHEL. It seems you are hitting this on Ubuntu 14.04. Is that right? Can you check the version of libcurl? Do you have a minimal repro?

@tmds Yes, I use Ubuntu 14.04. I don't have repro, but you can try simple asp.net core application and
put this code in a controller:
```c#
using (var client = new HttpClient())
{
var contents = await client.GetStringAsync("https://httpbin.org/get");
}

This is the output of `curl --version` command:

curl 7.35.0 (x86_64-pc-linux-gnu) libcurl/7.35.0 OpenSSL/1.0.1f zlib/1.2.8 libidn/1.28 librtmp/2.3
Protocols: dict file ftp ftps gopher http https imap imaps ldap ldaps pop3 pop3s rtmp rtsp smtp smtps telnet tftp
Features: AsynchDNS GSS-Negotiate IDN IPv6 Largefile NTLM NTLM_WB SSL libz TLS-SRP
```

In the ticket that I mentioned above you can find info about environment. Btw, the curl itself works fine.

@sharok what is the exact failure you're getting with the code above?

@karelz This is a full stack trace:

2017-05-31T03:59:15.6178500+00:00 0HL57R5JN7J7L [ERR] An error occurred while sending the request. (37785cd4)
System.AggregateException: One or more errors occurred. (An error occurred while sending the request.) ---> System.Net.Http.HttpRequestException: An error occurred while sending the request. ---> System.Net.Http.CurlException: Problem with the SSL CA cert (path? access rights?)
   at System.Net.Http.CurlHandler.ThrowIfCURLEError(CURLcode error)
   at System.Net.Http.CurlHandler.MultiAgent.FinishRequest(StrongToWeakReference`1 easyWrapper, CURLcode messageResult)
   --- End of inner exception stack trace ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
   at System.Net.Http.HttpClient.<FinishSendAsync>d__58.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
   at System.Net.Http.HttpClient.<GetContentAsync>d__32`1.MoveNext()
   --- End of inner exception stack trace ---
   at System.Threading.Tasks.Task`1.GetResultCore(Boolean waitCompletionNotification)
   at log.elmahbucket.io.Controllers.WhoamiController.Get() in C:\BuildAgent\work\d2f849282c12398d\src\log.elmahbucket.io\Controllers\WhoamiController.cs:line 33
   at lambda_method(Closure , Object , Object[] )
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeActionMethodAsync>d__27.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeNextActionFilterAsync>d__25.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Rethrow(ActionExecutedContext context)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeNextExceptionFilterAsync>d__24.MoveNext()
---> (Inner Exception #0) System.Net.Http.HttpRequestException: An error occurred while sending the request. ---> System.Net.Http.CurlException: Problem with the SSL CA cert (path? access rights?)
   at System.Net.Http.CurlHandler.ThrowIfCURLEError(CURLcode error)
   at System.Net.Http.CurlHandler.MultiAgent.FinishRequest(StrongToWeakReference`1 easyWrapper, CURLcode messageResult)
   --- End of inner exception stack trace ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
   at System.Net.Http.HttpClient.<FinishSendAsync>d__58.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
   at System.Net.Http.HttpClient.<GetContentAsync>d__32`1.MoveNext()<---

Does it repro 100%?
Can you try it on .NET Core 2.0 Preview 1?

@karelz It's a production machine, and I don't want to break something, so I will create a new one later and will try on Preview 1.

Great! Let us know how it goes. I doubt it will make the problem to go away, but it will be easier to focus on solution if we have confirmed 100% repro on 2.0 Preview 1. Thanks!

@sharok It could be a number of reasons, if your certs got updated recently, and the cert store was not updated it can result to this error, try running sudo update-ca-certificates. We have not observed this error with openssl crypto backend, if you can, set the env variable CURLHANDLER_DEBUG_VERBOSE=true. You should get some diagnostic data that can help with debugging.

We are seeing this same issue in 1.1.2 running on CentOS... We are randomly getting the SSL failures on a production box. So, if your fix only is targeted at "fixing your tests" and not "fixing the coreclr/curl SSL issue" then I think you are being too narrow minded. For example, installing a custom curl on your build boxes and not documenting and publishing it as a workaround that others could do would just be masking the issue, while on the other hand, bundling curl with coreclr would be a more robust "workaround"... Whatever the outcome is, it will be needed on production boxes, and not just on build/test servers...

The issue seems to be concurrency-related, and affects arbitrary .NET Core applications. With this program, I'm able to reproduce the problem about 25% of the time, using a 4-core CentOS 7 VM.

Decreasing the number of threads seems to make the problem happen less frequently, with the problem not reproducible at all with only one thread. Increasing the number of threads did not significantly increase probability.

```c#
using System;
using System.Linq;
using System.Net;
using System.Threading;

namespace ConsoleApp2
{
class Program
{
const string URI = "https://example.com";
static int Main(string[] args)
{
int Result = 0;
var Workers = Enumerable.Range(0, 4)
.Select(I => new Thread(() =>
{
try
{
var Req = WebRequest.CreateHttp(URI);
Req.Method = "HEAD";
using ( Req.GetResponseAsync().Result ) ;
}
catch ( Exception ex )
{
Console.WriteLine($"{I}: {ex}");
Result = 1;
}
})
{ IsBackground = true })
.ToArray();
foreach ( var T in Workers )
T.Start();
foreach ( var T in Workers )
T.Join();
return Result;
}
}
}


System/version information:

uname -a

Linux frqaclapp01.expoexchange.com 3.10.0-514.26.2.el7.x86_64 dotnet/corefx#1 SMP Tue Jul 4 15:04:05 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux

dotnet --version

1.0.4

curl --version

curl 7.29.0 (x86_64-redhat-linux-gnu) libcurl/7.29.0 NSS/3.21 Basic ECC zlib/1.2.7 libidn/1.28 libssh2/1.4.3
Protocols: dict file ftp ftps gopher http https imap imaps ldap ldaps pop3 pop3s rtsp scp sftp smtp smtps telnet tftp
Features: AsynchDNS GSS-Negotiate IDN IPv6 Largefile NTLM NTLM_WB SSL libz unix-sockets

rpm -qa | perl -ne 'm/curl|nss\b/&&print'

curl-7.29.0-35.el7.centos.x86_64
nss-softokn-freebl-3.16.2.3-14.4.el7.x86_64
nss-softokn-3.16.2.3-14.4.el7.x86_64
nss-sysinit-3.28.4-1.2.el7_3.x86_64
nss-tools-3.28.4-1.2.el7_3.x86_64
libcurl-7.29.0-35.el7.centos.x86_64
python-pycurl-7.19.0-19.el7.x86_64
nss-softokn-freebl-3.16.2.3-14.4.el7.i686
nss-util-3.28.4-1.0.el7_3.x86_64
nss-3.28.4-1.2.el7_3.x86_64
```

[EDIT] Add C# syntax highlight by @karelz

The results @Warr1024 found are also reproducible in 2.0 preview 2, running within a centos 7 docker container. The ratio of errors to success jumps up to about 50% from 25% over an extended period.

System details:

# uname -a
Linux 5fb57c34ad68 4.9.36-moby dotnet/corefx#1 SMP Wed Jul 12 15:29:07 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux

# dotnet --version
2.0.0-preview2-006497

# curl --version
curl 7.29.0 (x86_64-redhat-linux-gnu) libcurl/7.29.0 NSS/3.21 Basic ECC zlib/1.2.7 libidn/1.28 libssh2/1.4.3
Protocols: dict file ftp ftps gopher http https imap imaps ldap ldaps pop3 pop3s rtsp scp sftp smtp smtps telnet tftp
Features: AsynchDNS GSS-Negotiate IDN IPv6 Largefile NTLM NTLM_WB SSL libz unix-sockets

# rpm -qa | perl -ne 'm/curl|nss\b/&&print'
nss-softokn-3.16.2.3-14.4.el7.x86_64
nss-sysinit-3.28.4-1.2.el7_3.x86_64
libcurl-7.29.0-35.el7.centos.x86_64
python-pycurl-7.19.0-19.el7.x86_64
nss-softokn-freebl-3.16.2.3-14.4.el7.x86_64
nss-util-3.28.4-1.0.el7_3.x86_64
nss-3.28.4-1.2.el7_3.x86_64
nss-tools-3.28.4-1.2.el7_3.x86_64
curl-7.29.0-35.el7.centos.x86_64

I'm having the issue using 1.1 on CentOS 7, and I'm having trouble trying the workaround as suggested by @Priya91 and @tmds. I can set the LD_LIBRARY_PATH env var with a path that contains a libcurl built against openssl, and have confirmed in the code it's getting it with an Environment.GetEnvironmentVariable("LD_LIBRARY_PATH") call dumping to the console. And yet, when I enable event tracing I can see the debug message from curlhandler https://github.com/dotnet/corefx/blob/108260a51b52d40c848c99dd903e2e1de4d9eb62/src/System.Net.Http/src/System/Net/Http/Unix/CurlHandler.cs#L172 confirming it's getting the NSS based one

Does the path variable override only work with the 2.0 runtime?

@jaredrsowers

bundling curl with coreclr would be a more robust "workaround"

While you are correct it also comes with huge burden and cost - see https://github.com/dotnet/corefx/issues/16201#issuecomment-288769690. We considered this approach (also from other reasons), but rejected it - see dotnet/corefx#17647.

@tmds @Priya91 can we document clearly how to workaround this problem on older CentOS versions? If we see more customers hitting the problem, we should probably mention it in release notes or supported OS doc

@karelz I am unclear what you mean by

older CentOS versions

This is an easily reproducible issue on the latest, fully patched, CentOS. And, I agree, it would be fantastic to get a clearly documented "workaround" for this.

I am unclear what you mean by

I mixed it up a bit, sorry (too long thread and lack of my expertise on Linux combined) - it is not about older CentOS, it is about CentOS not having .NET Core 2.0 package yet, per @tmds comment here: https://github.com/dotnet/corefx/issues/16201#issuecomment-300264672
The version of curl in CentOS distro is just not working well with .NET Core as I understand it.

I think the perfect "workaround" for CentOS would either be distribute this "more recent version of libcurl" that is installed on RHEL so that we could then set the LD_LIBRARY_PATH for. Or if that isn't possible, outline the steps taken to properly compile it and generate it ourselves...

outline the steps taken to properly compile it and generate it ourselves.

That sounds very reasonable - I am waiting on @tmds or @Priya91 to provide more details here ...

You can either do,

  1. Use env variable SSL_DIR to an empty dir without certs, in which case the nss initialization will not use the default location of /etc/pki/nssdb here, which may contain out of date certs resulting in CURLE_SSL_CACERT_BADFILE, which is the workaround that was used to unblock CI.

  2. Use custom curl install built with openssl. There is documentation on curl site on how to build a custom curl with openssl crypto backend.

  3. If this problem occurred with openssl as backend, do a sudo update-ca-certificates, this is because there may be updates to the certs in /usr/share/ca-certificates that were not notified to openssl cert store location usually /etc/ssl/certs.

For what it's worth, the only way we found to 100% eliminate this issue was to throw a lock around the web call in c#, although we also had success with a retry-on-fail try-catch block.

Red Hat's build of .NET Core comes with a newer version of libcurl. This doesn't replace the system version (for which they are strong API/ABI garantees).
For CentOS we need the same. @Priya91 listed the available options until there is a CentOS build available.

@tmds, I just noticed that Microsoft is now distributing CentOS builds through RPM packages for the install of dotnet core 2 (https://www.microsoft.com/net/learn/get-started/linuxcentos), do these packages include an updated libcurl, or does the issue still exist?

Red Hat's build of .NET Core comes with a newer version of libcurl. This doesn't replace the system version (for which they are strong API/ABI garantees).
For CentOS we need the same. @Priya91 listed the available options until there is a CentOS build available.

do these packages include an updated libcurl

AKAIK, no.

But you can use the RHEL steps on CentOS 7 too: https://stackoverflow.com/a/46733657/3561275

But you can use the RHEL steps on CentOS 7 too: https://stackoverflow.com/a/46733657/3561275

Well whaddya know.... I think that'll work! Thanks!

Was this page helpful?
0 / 5 - 0 ratings

Related issues

EgorBo picture EgorBo  路  3Comments

chunseoklee picture chunseoklee  路  3Comments

bencz picture bencz  路  3Comments

GitAntoinee picture GitAntoinee  路  3Comments

noahfalk picture noahfalk  路  3Comments