Menu

#1433 POST with Proxy NTLM auth: curl suddenly stops sending Proxy-Authorization

closed-invalid
5
2015-02-20
2014-10-09
No

Our application uses the easy interface to do a simple POST request to a HTTP server. The same curl handle is reused between POST requests. We use a HTTP proxy with NTLM authentication (usually, squid). The application is single-threaded. Our code was working fine with libcurl 7.18.2. However, after upgrading to 7.38.0, the problems started, even though we didn't modify the application.

The problem is that libcurl sometimes suddenly stops sending authentication headers to the proxy. When this happens, the proxy replies with "407 Proxy Authentication Required". libcurl then retries the POST again but without any authentication headers. Therefore, the proxy answers with 407 again. This leads to a loop that causes hundreds of POST requests per second to be send and lasts until the query timeout is reached. The problem is not always reproduceable. One way to reproduce it is by using a firewall and forcing the connection to be closed from the firewall or by using some command. This allows the problem to be reproduced around 3/4 of the time. However, the problem happens sometimes spontaneously even though we didn't forcefully close the connection.

Please see the attached network capture. You can open it under Wireshark. There are several requests at the beggining, which worked fine. We forced the TCP connection to be closed from the firewall and when we performed the next request, the problem happened (starting on packet #69).

We are setting the following parameters with curl_easy_setopt() in the same order they appear here:

  • CURLOPT_PROXY
  • CURLOPT_PROXYUSERPWD: in the form "domain\username:password" (ASCII characters only, URL-encoded using curl_easy_escape())
  • CURLOPT_PROXYAUTH: CURLAUTH_ANY
  • CURLOPT_TIMEOUT: 20 seconds
  • CURLOPT_NOSIGNAL: 1
  • CURLOPT_HTTPHEADER (added cookies)
  • CURLOPT_POSTFIELDS
  • CURLOPT_URL
  • CURLOPT_WRITEFUNCTION
  • CURLOPT_WRITEDATA

and then we call curl_easy_perform(). Interrupting curl with gdb almost always shows the following backtrace (which of course looks normal):

(gdb) bt
#0  0xf7764425 in __kernel_vsyscall ()
#1  0x410fe73b in poll () from /lib/libc.so.6
#2  0xf772607f in Curl_poll () from /usr/lib/libcurl.so.4
#3  0xf77221a8 in curl_multi_wait () from /usr/lib/libcurl.so.4
#4  0xf7718954 in curl_easy_perform () from /usr/lib/libcurl.so.4
1 Attachments

Discussion

  • Anonymous

    Anonymous - 2014-10-09

    When I said "or by using some command" I meant some command to force the connection to be closed.

     
  • Daniel Stenberg

    Daniel Stenberg - 2014-10-22

    Does this happen repeatedly? Why does libcurl "suddenly stop" sending auth? As you're using NTLM, it would not send auth all the time anyway since it'd auth the connection once and then it should be enough, surely?

    Isn't it so that something makes the connection fail and then libcurl starts a new connection on which the new 407 is responded back on? What does the VERBOSE output show in that case? It is hard to understand exactly what's happening with that huge capture only.

    Which platform is this libcurl running on, using which TLS backend?

     
  • Daniel Stenberg

    Daniel Stenberg - 2014-10-22
    • assigned_to: Daniel Stenberg
     
  • Anonymous

    Anonymous - 2014-10-22

    Hi Daniel, thanks for your reply.

    • The problem happens repeatedly.
    • I don't know the exact reason why libcurl would stop sending the auth. In any case, we always set the same authentication options and sometimes it happens, sometimes not.
    • I guess libcurl doesn't need to authenticate on every request but if the HTTP Proxy replies with 407, it shouldn't authenticate, shouldn't it?
    • AFAIK, you're right: the connection fails and when libcurl starts a new connection it gets 407. However, I don't know if libcurl is starting a new connection everytime a 407 is received. I will enable the verbose output and provide you more details.
    • The platform is Linux (custom RPM) using OpenSSL 0.9.8:

    %configure --with-ssl=/usr --with-nss=%{_prefix} --enable-ipv6 --with-ca-bundle=%{_sysconfdir}/pki/tls/certs/ca-bundle.crt --with-gssapi=%{_prefix}/kerberos --with-libidn --enable-ares=$RPM_BUILD_DIR/c-ares-%{CARES_VERSION}/instroot/usr --enable-ldaps --disable-static --with-libssh2

    The problem also happens if we don't use c-ares.

     

    Last edit: Anonymous 2014-10-22
  • Anonymous

    Anonymous - 2014-10-23

    As requested, here is the verbose output.

    First of all, a normal connection is established and works properly:

    * Connected to 192.168.1.1 (192.168.1.1) port 3129 (#0)
    > POST http://64.235.147.56/register HTTP/1.1
    Accept: */*
    Proxy-Connection: Keep-Alive
    Content-Type: application/x-www-form-urlencoded
    Host: 64.235.147.56
    Content-Length: 209
    
    * upload completely sent off: 209 out of 209 bytes
    < HTTP/1.1 407 Proxy Authentication Required
    * Server squid/3.3.11 is not blacklisted
    < Server: squid/3.3.11
    < Mime-Version: 1.0
    < Date: Thu, 23 Oct 2014 09:47:28 GMT
    < Content-Type: text/html
    < Content-Length: 3271
    < X-Squid-Error: ERR_CACHE_ACCESS_DENIED 0
    < Vary: Accept-Language
    < Content-Language: en
    < Proxy-Authenticate: NTLM
    < Proxy-Authenticate: Basic realm="Please authenticate (MSAD fallback)"
    < X-Cache: MISS from hq-proxy
    < X-Cache-Lookup: NONE from hq-proxy:3128
    < Via: 1.1 hq-proxy (squid/3.3.11)
    < Connection: close
    < 
    * Closing connection 0
    * Issue another request to this URL: 'http://64.235.147.56/register'
    * Hostname was found in DNS cache
    *   Trying 192.168.1.1...
    * Connected to 192.168.1.1 (192.168.1.1) port 3129 (#1)
    * Proxy auth using NTLM with user 'domain\username'
    > POST http://64.235.147.56/register HTTP/1.1
    Proxy-Authorization: NTLM TlRMTVNTUAABAAAABoIIAAAAAAAAAAAAAAAAAAAAAAA=
    Accept: */*
    Proxy-Connection: Keep-Alive
    Content-Type: application/x-www-form-urlencoded
    Host: 64.235.147.56
    Content-Length: 0
    
    < HTTP/1.1 407 Proxy Authentication Required
    * Server squid/3.3.11 is not blacklisted
    < Server: squid/3.3.11
    < Mime-Version: 1.0
    < Date: Thu, 23 Oct 2014 09:47:28 GMT
    < Content-Type: text/html
    < Content-Length: 3353
    < X-Squid-Error: ERR_CACHE_ACCESS_DENIED 0
    < Vary: Accept-Language
    < Content-Language: en
    < Proxy-Authenticate: NTLM TlRMTVNTUAACAAAACAAIADAAAAAGgokAmQ64I/b9snMAAAAAAAAAAEQARAA4AAAAUEhJT05ORVQCABAAUABIAEkATwBOAE4ARQBUAAEAEABIAFEALQBQAFIATwBYAFkABAAAAAMAEABIAFEALQBQAFIATwBYAFkAAAAAAA==
    < X-Cache: MISS from hq-proxy
    < X-Cache-Lookup: NONE from hq-proxy:3128
    < Via: 1.1 hq-proxy (squid/3.3.11)
    < Connection: keep-alive
    < 
    * Ignoring the response-body
    * Connection #1 to host 192.168.1.1 left intact
    * Issue another request to this URL: 'http://64.235.147.56/register'
    * Found bundle for host 64.235.147.56: 0x85eece0
    * Re-using existing connection! (#1) with host 192.168.1.1
    * Connected to 192.168.1.1 (192.168.1.1) port 3129 (#1)
    * Proxy auth using NTLM with user 'domain\username'
    > POST http://64.235.147.56/register HTTP/1.1
    Proxy-Authorization: NTLM TlRMTVNTUAADAAAAGAAYAEAAAAB0AHQAWAAAAAgACADMAAAABgAGANQAAAAEAAQA2gAAAAAAAAAAAAAABoKJAKzKYrDHnOJC+8/YC7hYWTuRRG+sMDOlIpGiYQHxES9+5TM53fLLh4ABAQAAAAAAAAD4QFum7s8BkURvrDAzpSIAAAAAAgAQAFAASABJAE8ATgBOAEUAVAABABAASABRAC0AUABSAE8AWABZAAQAAAADABAASABRAC0AUABSAE8AWABZAAAAAAAAAAAAcGhpb25uZXR0ZXN0dXN2Zm5n
    Accept: */*
    Proxy-Connection: Keep-Alive
    Content-Type: application/x-www-form-urlencoded
    Host: 64.235.147.56
    Content-Length: 209
    
    * upload completely sent off: 209 out of 209 bytes
    < HTTP/1.1 200 OK
    * Server nginx is not blacklisted
    < Server: nginx
    < Date: Thu, 23 Oct 2014 09:47:29 GMT
    < Content-Type: application/json
    < Set-Cookie: lease=0.86036345030198; expires=Fri, 24 Oct 2014 09:47:29 GMT
    < X-Cache: MISS from hq-proxy
    < X-Cache-Lookup: MISS from hq-proxy:3128
    < Transfer-Encoding: chunked
    < Via: 1.1 hq-proxy (squid/3.3.11)
    < Connection: keep-alive
    < 
    * Connection #1 to host 192.168.1.1 left intact
    

    Then, sooner or later, when the problem happens we get this:

    * Connection 1 seems to be dead!
    * Closing connection 1
    * NTLM-proxy picked AND auth done set, clear picked!
    * Hostname was NOT found in DNS cache
    *   Trying 192.168.1.1...
    * Connected to 192.168.1.1 (192.168.1.1) port 3129 (#2)
    > POST http://64.235.147.56/lookup HTTP/1.1
    Accept: */*
    Proxy-Connection: Keep-Alive
    Content-Type: application/x-www-form-urlencoded
    Host: 64.235.147.56
    Cookie: lease=0.86036345030198
    Content-Length: 15
    
    * upload completely sent off: 15 out of 15 bytes
    < HTTP/1.1 407 Proxy Authentication Required
    * Server squid/3.3.11 is not blacklisted
    < Server: squid/3.3.11
    < Mime-Version: 1.0
    < Date: Thu, 23 Oct 2014 09:50:13 GMT
    < Content-Type: text/html
    < Content-Length: 3304
    < X-Squid-Error: ERR_CACHE_ACCESS_DENIED 0
    < Vary: Accept-Language
    < Content-Language: en
    < Proxy-Authenticate: NTLM
    < Proxy-Authenticate: Basic realm="Please authenticate (MSAD fallback)"
    < X-Cache: MISS from hq-proxy
    < X-Cache-Lookup: NONE from hq-proxy:3128
    < Via: 1.1 hq-proxy (squid/3.3.11)
    < Connection: close
    < 
    * Closing connection 2
    * Issue another request to this URL: 'http://64.235.147.56/lookup'
    * NTLM-proxy picked AND auth done set, clear picked!
    * Hostname was found in DNS cache
    *   Trying 192.168.1.1...
    * Connected to 192.168.1.1 (192.168.1.1) port 3129 (#3)
    > POST http://64.235.147.56/lookup HTTP/1.1
    Accept: */*
    Proxy-Connection: Keep-Alive
    Content-Type: application/x-www-form-urlencoded
    Host: 64.235.147.56
    Cookie: lease=0.86036345030198
    Content-Length: 15
    
    * upload completely sent off: 15 out of 15 bytes
    < HTTP/1.1 407 Proxy Authentication Required
    * Server squid/3.3.11 is not blacklisted
    < Server: squid/3.3.11
    < Mime-Version: 1.0
    < Date: Thu, 23 Oct 2014 09:50:13 GMT
    < Content-Type: text/html
    < Content-Length: 3304
    < X-Squid-Error: ERR_CACHE_ACCESS_DENIED 0
    < Vary: Accept-Language
    < Content-Language: en
    < Proxy-Authenticate: NTLM
    < Proxy-Authenticate: Basic realm="Please authenticate (MSAD fallback)"
    < X-Cache: MISS from hq-proxy
    < X-Cache-Lookup: NONE from hq-proxy:3128
    < Via: 1.1 hq-proxy (squid/3.3.11)
    < Connection: close
    < 
    * Closing connection 3
    * Issue another request to this URL: 'http://64.235.147.56/lookup'
    * NTLM-proxy picked AND auth done set, clear picked!
    * Hostname was found in DNS cache
    *   Trying 192.168.1.1...
    * Connected to 192.168.1.1 (192.168.1.1) port 3129 (#4)
    > POST http://64.235.147.56/lookup HTTP/1.1
    Accept: */*
    Proxy-Connection: Keep-Alive
    Content-Type: application/x-www-form-urlencoded
    Host: 64.235.147.56
    Cookie: lease=0.86036345030198
    Content-Length: 15
    
    * upload completely sent off: 15 out of 15 bytes
    < HTTP/1.1 407 Proxy Authentication Required
    * Server squid/3.3.11 is not blacklisted
    < Server: squid/3.3.11
    < Mime-Version: 1.0
    < Date: Thu, 23 Oct 2014 09:50:13 GMT
    < Content-Type: text/html
    < Content-Length: 3304
    < X-Squid-Error: ERR_CACHE_ACCESS_DENIED 0
    < Vary: Accept-Language
    < Content-Language: en
    < Proxy-Authenticate: NTLM
    < Proxy-Authenticate: Basic realm="Please authenticate (MSAD fallback)"
    < X-Cache: MISS from hq-proxy
    < X-Cache-Lookup: NONE from hq-proxy:3128
    < Via: 1.1 hq-proxy (squid/3.3.11)
    < Connection: close
    < 
    * Closing connection 4
    

    libcurl then starts to spin, repeating this loop thousands of times.

     
  • Daniel Stenberg

    Daniel Stenberg - 2014-10-23

    It seems to use http://64.235.147.56/register when everything works and it says it uses NTLM and it does in the request.

    When it then POSTs to http://64.235.147.56/lookup there's no NTLM auth anymore, not in the verbose output like for the previous ones and not in the actual request.

    Is this explained in your code?

     
  • Anonymous

    Anonymous - 2014-10-24

    For posting to both URLs, our code has one method which sets up all the curl_easy_setopt() options and then calls curl_easy_perform(), reusing the curl handle between calls. The function does exactly the same for both URLs (there is nothing like if(url==foo) { a; } else { b; } ). The function sets CURLOPT_PROXY, CURLOPT_PROXYUSERPWD and CURLOPT_PROXYAUTH in both cases and always with the same values.

    The problem seems to be that the authentication is sent only for the first time and then, even though the connection was closed and we received the 407 reply, curl doesn't try to authenticate again. I have tried modifying that method to close the curl handle and open a new one on each request. The problem disappeared immediately and it works fine, authenticating when required. Unfortunately, this also means we need to open a new connection and authenticate for each request even if the connection to the proxy was not closed.

     
  • Anonymous

    Anonymous - 2014-10-24

    The problem also seems not to happen if I set CURLOPT_PROXYAUTH to CURLAUTH_NTLM instead of CURLAUTH_ANY. Of course this would prevent other authentication schemes from being used.

     
  • Anonymous

    Anonymous - 2014-10-31

    If I comment out the following lines in create_conn (url.c, line 5613), NTLM authentication works properly again and the authentication loop doesn't happen any longer:

    if((data->state.authproxy.picked & (CURLAUTH_NTLM | CURLAUTH_NTLM_WB)) &&
       data->state.authproxy.done) {
      infof(data, "NTLM-proxy picked AND auth done set, clear picked!\n");
      data->state.authproxy.picked = CURLAUTH_NONE;
    }
    

    These lines were added in commit 898808fa8ca7b4a8e0866a5d7769ed1b50219328.

     
  • Daniel Stenberg

    Daniel Stenberg - 2014-11-03
    • status: open --> pending-needsinfo
     
  • Daniel Stenberg

    Daniel Stenberg - 2014-11-03

    OK, then at least we know that you can do a work-around to get it going. But it doesn't really explain why that code ruins anything since it does create a new connection so it shouldn't inherit NTLM state from the previous... Or can you explain why this changes things for you?

     
  • Daniel Stenberg

    Daniel Stenberg - 2015-02-20
    • status: pending-needsinfo --> closed-invalid
     
  • Daniel Stenberg

    Daniel Stenberg - 2015-02-20

    Abandoned. Closing.