Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

cookies not sent to dotless host using PSL build #3676

Closed
bagder opened this issue Mar 12, 2019 · 17 comments
Closed

cookies not sent to dotless host using PSL build #3676

bagder opened this issue Mar 12, 2019 · 17 comments
Labels

Comments

@bagder
Copy link
Member

bagder commented Mar 12, 2019

$ curl --version
curl 7.64.0 (x86_64-pc-msys) libcurl/7.64.0 OpenSSL/1.1.1b zlib/1.2.11 brotli/1.0.7 libidn2/2.1.1 libpsl/0.20.2 (+libidn2/2.1.1) libssh2/1.8.0 nghttp2/1.36.0
Release-Date: 2019-02-06
Protocols: dict file ftp ftps gopher http https imap imaps pop3 pop3s rtsp scp sftp smb smbs smtp smtps telnet tftp
Features: AsynchDNS Debug TrackMemory IDN IPv6 Largefile GSS-API Kerberos SPNEGO NTLM NTLM_WB SSL libz brotli TLS-SRP HTTP2 UnixSockets HTTPS-proxy PSL Metalink

I use a binary version of curl embedded in MSYS2 (freely downloadable at https://www.msys2.org/). This binary is built with the features mentioned above.
My problem is linked to local hostname. The URL I would like curl to connect to is "https://fronteo-keycloak-rmm:8443" (a Redhat SSO server instance). Here is a log (I've removed some useless lines):

> GET /auth/realms/fhome/protocol/openid-connect/auth?response_type=code&scope=aisp&client_id=3466687a-7e3f-4c8f-b4a3-bf15fb11aaa4&state=12345&redirect_uri=http://localhost:8080 HTTP/2
> Host: fronteo-keycloak-rmm:8443
> User-Agent: curl/7.64.0
> Accept: */*
>
* STATE: DO => DO_DONE handle 0x600055128; line 1716 (connection #0)
* multi changed, check CONNECT_PEND queue!
* STATE: DO_DONE => WAITPERFORM handle 0x600055128; line 1840 (connection #0)
* STATE: WAITPERFORM => PERFORM handle 0x600055128; line 1855 (connection #0)
{ [5 bytes data]
* Connection state changed (MAX_CONCURRENT_STREAMS == 4294967295)!
} [5 bytes data]
* multi changed, check CONNECT_PEND queue!
{ [5 bytes data]
* HTTP/2 found, allow multiplexing
< HTTP/2 200
< cache-control: no-store, must-revalidate, max-age=0
* Added cookie AUTH_SESSION_ID="8696e8d7-3b93-4687-a9a4-12dc9ece0cb4.fronteo-keycloak-rmm" for domain fronteo-keycloak-rmm, path /auth/realms/fhome/, expire 0
< set-cookie: AUTH_SESSION_ID=8696e8d7-3b93-4687-a9a4-12dc9ece0cb4.fronteo-keycloak-rmm; Version=1; Path=/auth/realms/fhome/; HttpOnly
* Added cookie KC_RESTART="eyJhbGciOiJIUzI1NiIsInR5cCIgOiAiSldUIiwia2lkIiA6ICIyOTNiZDllMy0wMDJlLTQ4OTYtYjg0Ny0xODdlMDkzNjdmZGQifQ.eyJjaWQiOiIzNDY2Njg3YS03ZTNmLTRjOGYtYjRhMy1iZjE1ZmIxMWFhYTQiLCJwdHkiOiJvcGVuaWQtY29ubmVjdCIsInJ1cmkiOiJodHRwOi8vbG9jYWxob3N0OjgwODAiLCJhY3QiOiJBVVRIRU5USUNBVEUiLCJub3RlcyI6eyJzY29wZSI6ImFpc3AiLCJpc3MiOiJodHRwczovL2Zyb250ZW8ta2V5Y2xvYWstcm1tOjg0NDMvYXV0aC9yZWFsbXMvZmhvbWUiLCJyZXNwb25zZV90eXBlIjoiY29kZSIsImNvZGVfY2hhbGxlbmdlX21ldGhvZCI6InBsYWluIiwicmVkaXJlY3RfdXJpIjoiaHR0cDovL2xvY2FsaG9zdDo4MDgwIiwic3RhdGUiOiIxMjM0NSJ9fQ.JhMJmSKLESr_flL3SRZgmaFw4T1e5ueg-1z9OEFoRX8" for domain fronteo-keycloak-rmm, path /auth/realms/fhome/, expire 0
< set-cookie: KC_RESTART=eyJhbGciOiJIUzI1NiIsInR5cCIgOiAiSldUIiwia2lkIiA6ICIyOTNiZDllMy0wMDJlLTQ4OTYtYjg0Ny0xODdlMDkzNjdmZGQifQ.eyJjaWQiOiIzNDY2Njg3YS03ZTNmLTRjOGYtYjRhMy1iZjE1ZmIxMWFhYTQiLCJwdHkiOiJvcGVuaWQtY29ubmVjdCIsInJ1cmkiOiJodHRwOi8vbG9jYWxob3N0OjgwODAiLCJhY3QiOiJBVVRIRU5USUNBVEUiLCJub3RlcyI6eyJzY29wZSI6ImFpc3AiLCJpc3MiOiJodHRwczovL2Zyb250ZW8ta2V5Y2xvYWstcm1tOjg0NDMvYXV0aC9yZWFsbXMvZmhvbWUiLCJyZXNwb25zZV90eXBlIjoiY29kZSIsImNvZGVfY2hhbGxlbmdlX21ldGhvZCI6InBsYWluIiwicmVkaXJlY3RfdXJpIjoiaHR0cDovL2xvY2FsaG9zdDo4MDgwIiwic3RhdGUiOiIxMjM0NSJ9fQ.JhMJmSKLESr_flL3SRZgmaFw4T1e5ueg-1z9OEFoRX8; Version=1; Path=/auth/realms/fhome/; HttpOnly
< x-xss-protection: 1; mode=block
< x-frame-options: SAMEORIGIN
< content-security-policy: frame-src 'self'; frame-ancestors 'self'; object-src 'none';
< date: Tue, 12 Mar 2019 14:22:06 GMT
< x-robots-tag: none
< strict-transport-security: max-age=31536000; includeSubDomains
< x-content-type-options: nosniff
< content-type: text/html;charset=utf-8
< content-language: fr
<
{ [15509 bytes data]
* nread <= 0, server closed connection, bailing
* STATE: PERFORM => DONE handle 0x600055128; line 2052 (connection #0)
* multi_done
* Connection #0 to host fronteo-keycloak-rmm left intact
* Expire cleared (transfer 0x600055128)
POST URL https://fronteo-keycloak-rmm:8443/auth/realms/fhome/login-actions/authenticate?session_code=GJrBBqxLoIhXdOGItEhE3qPOFX380SelqRveHwaYBxA&execution=f65ccedb-cc7a-4f46-b386-f59408012698&client_id=3466687a-7e3f-4c8f-b4a3-bf15fb11aaa4&tab_id=Y4joE-fW6mE
* Expire in 0 ms for 6 (transfer 0x600055128)
* STATE: INIT => CONNECT handle 0x600055128; line 1443 (connection #-5000)
* Added connection 0. The cache now contains 1 members
* Expire in 1 ms for 1 (transfer 0x600055128)
* STATE: CONNECT => WAITRESOLVE handle 0x600055128; line 1484 (connection #0)
* Expire in 0 ms for 1 (transfer 0x600055128)
* Expire in 1 ms for 1 (transfer 0x600055128)
*   Trying 192.100.2.31...
* TCP_NODELAY set
* Expire in 200 ms for 4 (transfer 0x600055128)
* STATE: WAITRESOLVE => WAITCONNECT handle 0x600055128; line 1565 (connection #0)
* Connected to fronteo-keycloak-rmm (192.100.2.31) port 8443 (#0)
* STATE: WAITCONNECT => SENDPROTOCONNECT handle 0x600055128; line 1619 (connection #0)
* Marked for [keep alive]: HTTP default
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*   CAfile: /usr/ssl/certs/ca-bundle.crt
  CApath: none
} [5 bytes data]
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
} [512 bytes data]
* STATE: SENDPROTOCONNECT => PROTOCONNECT handle 0x600055128; line 1633 (connection #0)
{ [5 bytes data]
* TLSv1.3 (IN), TLS handshake, Server hello (2):
{ [94 bytes data]
* TLSv1.2 (IN), TLS handshake, Certificate (11):
{ [815 bytes data]
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
{ [333 bytes data]
* TLSv1.2 (IN), TLS handshake, Server finished (14):
{ [4 bytes data]
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
} [70 bytes data]
* TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1):
} [1 bytes data]
* TLSv1.2 (OUT), TLS handshake, Finished (20):
} [16 bytes data]
* TLSv1.2 (IN), TLS handshake, Finished (20):
{ [16 bytes data]
* SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
* ALPN, server accepted to use h2
* Server certificate:
*  subject: C=BE; L=LLN; O=Mainsys; CN=keycloak
*  start date: Feb 11 14:23:59 2019 GMT
*  expire date: Feb 11 14:23:59 2039 GMT
*  issuer: C=BE; L=LLN; O=Mainsys; CN=keycloak
*  SSL certificate verify result: self signed certificate (18), continuing anyway.
* STATE: PROTOCONNECT => DO handle 0x600055128; line 1654 (connection #0)
* Using HTTP2, server supports multi-use
* Connection state changed (HTTP/2 confirmed)
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
} [5 bytes data]
* Using Stream ID: 1 (easy handle 0x600055128)
} [5 bytes data]
> POST /auth/realms/fhome/login-actions/authenticate?session_code=GJrBBqxLoIhXdOGItEhE3qPOFX380SelqRveHwaYBxA&execution=f65ccedb-cc7a-4f46-b386-f59408012698&client_id=3466687a-7e3f-4c8f-b4a3-bf15fb11aaa4&tab_id=Y4joE-fW6mE HTTP/2
> Host: fronteo-keycloak-rmm:8443
> User-Agent: curl/7.64.0
> Accept: */*
> Content-Length: 27
> Content-Type: application/x-www-form-urlencoded
>
* STATE: DO => DO_DONE handle 0x600055128; line 1716 (connection #0)
* multi changed, check CONNECT_PEND queue!
* STATE: DO_DONE => WAITPERFORM handle 0x600055128; line 1840 (connection #0)
* STATE: WAITPERFORM => PERFORM handle 0x600055128; line 1855 (connection #0)
} [5 bytes data]
* We are completely uploaded and fine
{ [5 bytes data]
* Connection state changed (MAX_CONCURRENT_STREAMS == 4294967295)!
} [5 bytes data]
* multi changed, check CONNECT_PEND queue!
{ [5 bytes data]
* HTTP/2 found, allow multiplexing
< HTTP/2 500
< cache-control: no-store, must-revalidate, max-age=0
< content-length: 0
< date: Tue, 12 Mar 2019 14:22:06 GMT
<

Here is the file containing the cookies:
cookies-in.txt

Hope this helps,
Pierre

Originally posted by @Largo2005 in #3649 (comment)

@bagder
Copy link
Member Author

bagder commented Mar 12, 2019

@Largo2005, I really can't see how test 331 is not verifying a dotless host name that sets cookies that are then used in the second request. Can you modify that test so that it reproduces your problem?

Your log output doesn't show, but you're sure the second request actually uses the cookie file the first request saved? The second request reconnects according to the log, which indicates that it doesn't reuse the handle?

@Largo2005
Copy link

I don't know how you test framework is working so it's difficult for me to adapt the testcase. I will attach the script I'm using and a new trace with "-x" option of bash activate, so you can see all system calls. As a reminder, this script is working properly with curl 7.40.0 which shows that the cookies engine usage is correct...

curl_trace.txt
test-cert.sh.txt

@bagder
Copy link
Member Author

bagder commented Mar 13, 2019

As it stores the cookie file, it seems the problem is in the Curl_cookie_getlist function where it should fetch all matching cookies. Can you apply this debug patch and see what output it generates in this case? It fprintfs to stderr.

diff --git a/lib/cookie.c b/lib/cookie.c
index 44851a52f..fc27b37f7 100644
--- a/lib/cookie.c
+++ b/lib/cookie.c
@@ -1345,12 +1345,21 @@ struct Cookie *Curl_cookie_getlist(struct CookieInfo *c,
             matches++;
           }
           else
             goto fail;
         }
+        else
+          fprintf(stderr, "cookie-not-matched: %s bad path match: %s != %s\n",
+                  co->name, co->spath, path);
       }
+      else
+        fprintf(stderr, "cookie-not-matched: %s bad domain match: %s != %s\n",
+                co->name, co->domain, host);
     }
+    else
+      fprintf(stderr, "cookie-not-matched: %s not secure: %d\n",
+              co->name, co->secure);
     co = co->next;
   }
 
   if(matches) {
     /* Now we need to make sure that if there is a name appearing more than

@rockdaboot
Copy link
Contributor

The problem is that c->cookies[myhash] is NULL, so that Curl_cookie_getlist() immediately returns.

@rockdaboot
Copy link
Contributor

Here is an example from my local network:

src/curl -vvv --insecure -c cookie.jar https://blitz-lx:443/dokuwiki/doku.php?id=start >out 2>&1

creates cookie.jar with a single entry

#HttpOnly_blitz-lx      FALSE   /dokuwiki/      TRUE    0       DokuWiki        gu8b15edorsc2onopmtfvkn6f7

Now executing the same curl line again and grepping the output for 'cookie':

$ grep -i 'Cookie' out
< Vary: Cookie,Accept-Encoding
* Added cookie DokuWiki="hhj5cqo3q136u0hn4979nm8rt3" for domain blitz-lx, path /dokuwiki/, expire 0
< Set-Cookie: DokuWiki=hhj5cqo3q136u0hn4979nm8rt3; path=/dokuwiki/; secure; HttpOnly
* Added cookie DWb539d53bcb155331d24d78dda5feb08e="deleted" for domain blitz-lx, path /dokuwiki/, expire 1
< Set-Cookie: DWb539d53bcb155331d24d78dda5feb08e=deleted; expires=Thu, 01-Jan-1970 00:00:01 GMT; Max-Age=0; path=/dokuwiki/; secure; HttpOnly

Curl_cookie_getlist() immediately returns because of c->cookies[myhash] being NULL with myhash being 213.

@bagder
Copy link
Member Author

bagder commented Mar 13, 2019

Thanks @rockdaboot! This is still strange to me, because I can't reproduce that even using the exact same host name, but I think I'm just missing something:

$ ./src/curl -v http://blitz-lx/cookie.cgi -c cookies.txt
$ ./src/curl -v http://blitz-lx/cookie.cgi -b cookies.txt

The second invoke includes the cookie in the request that was stored from the first. But I also get a 'myhash' that is d5 / 213 both when the cookie is stored and when the cookies are matched so there's no NULL there for me? What hash does it store the cookies at for you?

My test URL returns:

HTTP/1.1 200 OK
Date: Wed, 13 Mar 2019 11:31:37 GMT
Server: Apache/2.4.38 (Debian)
Set-Cookie: name=weird; HttpOnly
Upgrade: h2c
Connection: Upgrade
Content-Length: 4
Content-Type: text/plain

hej

And my cookies.txt:

# Netscape HTTP Cookie File
# https://curl.haxx.se/docs/http-cookies.html
# This file was generated by libcurl! Edit at your own risk.

#HttpOnly_blitz-lx      FALSE   /       FALSE   0       name    weird

I log the hashes used like this:

diff --git a/lib/cookie.c b/lib/cookie.c
index 44851a52f..2dd733f55 100644
--- a/lib/cookie.c
+++ b/lib/cookie.c
@@ -1064,16 +1064,15 @@ Curl_cookie_add(struct Curl_easy *data,
     }
     lastc = clist;
     clist = clist->next;
   }
 
-  if(c->running)
     /* Only show this when NOT reading the cookies from a file */
     infof(data, "%s cookie %s=\"%s\" for domain %s, path %s, "
-          "expire %" CURL_FORMAT_CURL_OFF_T "\n",
+          "expire %" CURL_FORMAT_CURL_OFF_T " myhash %x\n",
           replace_old?"Replaced":"Added", co->name, co->value,
-          co->domain, co->path, co->expires);
+          co->domain, co->path, co->expires, myhash);
 
   if(!replace_old) {
     /* then make the last item point on this new one */
     if(lastc)
       lastc->next = co;
@@ -1303,10 +1302,12 @@ struct Cookie *Curl_cookie_getlist(struct CookieInfo *c,
   struct Cookie *mainco = NULL;
   size_t matches = 0;
   bool is_ip;
   const size_t myhash = cookiehash(host);
 
+  fprintf(stderr, "myhash %x\n", myhash);
+
   if(!c || !c->cookies[myhash])
     return NULL; /* no cookie struct or no cookies in the struct */
 
   /* at first, remove expired cookies */
   remove_expired(c);

@rockdaboot
Copy link
Contributor

rockdaboot commented Mar 13, 2019

With your fprint lines myhash shows d5 every time.

* Added cookie DokuWiki="bm63ho5eol2mk58he3kpttd4n2" for domain blitz-lx, path /dokuwiki/, expire 0 myhash d5
* Added cookie DWb539d53bcb155331d24d78dda5feb08e="deleted" for domain blitz-lx, path /dokuwiki/, expire 1 myhash d5

@bagder
Copy link
Member Author

bagder commented Mar 13, 2019

With your fprint lines myhash shows d5 every time.

Okay, that's good at least.

Can you spot how the pointer ends up NULL then? Does it expire both cookies before c->cookies[myhash];?

curl/lib/cookie.c

Line 1317 in dd8a19f

co = c->cookies[myhash];

@rockdaboot
Copy link
Contributor

I added a fprintf(stderr,"cookie expired %ld %ld\n",co->expires,now); in remove_expired() and what I see in the output from above is

* Added cookie DokuWiki="bm63ho5eol2mk58he3kpttd4n2" for domain blitz-lx, path /dokuwiki/, expire 0 myhash d5
* Added cookie DWb539d53bcb155331d24d78dda5feb08e="deleted" for domain blitz-lx, path /dokuwiki/, expire 1 myhash d5
< Set-Cookie: DWb539d53bcb155331d24d78dda5feb08e=deleted; expires=Thu, 01-Jan-1970 00:00:01 GMT; Max-Age=0; path=/dokuwiki/; secure; HttpOnly
cookie expired 1 1552478918

Which is expected since the 'expires' is 1. Nothing else gets removed. I have to start my IDE before I go any deeper :-)

@rockdaboot
Copy link
Contributor

To me it looks like Curl_cookie_getlist() is called before cookie.jar is read. Curl_cookie_add() is called later than Curl_cookie_getlist() here.

@bagder
Copy link
Member Author

bagder commented Mar 13, 2019

The later _add calls are probably the incoming cookies from the response?

@rockdaboot
Copy link
Contributor

rockdaboot commented Mar 14, 2019

Putting a fprintf(stderr, "%s: file=%s\n", __func__, file); at the beginning of Curl_cookie_init() shows that this function is only called once (from vsetopt(), L737) and with file = 'NULL'. It looks like -c cookie.jar is a no-op regarding reading from disk. But maybe I understand '-c' wrongly.

@rockdaboot
Copy link
Contributor

Ah, curl's man page gave me a hard time... there was only one cookie option (-c) with a file argument, so I never had a doubt that -c is the right option for reading + writing. Since -b has a '' argument, so I didn't read the description (what for ?). Please update the docs/man page to something like

-b, --cookie <file|data>

to catch a fast reader's attention.

With -c cookie.jar -b cookie.jar curl (latest master) works as expected (with PSL) and adds the Cookie: header:

> GET /dokuwiki/doku.php?id=start HTTP/1.1^M
> Host: blitz-lx^M
> User-Agent: curl/7.64.1-DEV^M
> Accept: */*^M
> Cookie: DokuWiki=9logjnu50sn8dscvflrftrpqc2^M

Doing more testing...
The issue is reproducible with Curl 7.64, but not with latest master.

Curl on Debian unstable:

$ curl --version
curl 7.64.0 (x86_64-pc-linux-gnu) libcurl/7.64.0 OpenSSL/1.1.1b zlib/1.2.11 libpsl/0.20.2 (+libidn2/2.0.5) libssh2/1.8.0 nghttp2/1.36.0 librtmp/2.3
Release-Date: 2019-02-06
Protocols: dict file ftp ftps gopher http https imap imaps ldap ldaps pop3 pop3s rtmp rtsp scp sftp smb smbs smtp smtps telnet tftp 
Features: AsynchDNS IPv6 Largefile GSS-API Kerberos SPNEGO NTLM NTLM_WB SSL libz TLS-SRP HTTP2 UnixSockets HTTPS-proxy PSL

Curl built from latest master:

$ src/curl --version
curl 7.64.1-DEV (x86_64-pc-linux-gnu) libcurl/7.64.1-DEV OpenSSL/1.1.1b zlib/1.2.11 brotli/1.0.7 libidn2/2.0.4 libpsl/0.20.2 (+libidn2/2.0.5) nghttp2/1.36.0 librtmp/2.3
Release-Date: [unreleased]
Protocols: dict file ftp ftps gopher http https imap imaps ldap ldaps pop3 pop3s rtmp rtsp smb smbs smtp smtps telnet tftp 
Features: AsynchDNS brotli HTTP2 HTTPS-proxy IDN IPv6 Largefile libz NTLM NTLM_WB PSL SSL TLS-SRP UnixSockets

bagder added a commit that referenced this issue Mar 14, 2019
From a discussion in #3676

Suggested-by: Tim Rühsen
@bagder
Copy link
Member Author

bagder commented Mar 14, 2019

Thanks a lot @rockdaboot. @Largo2005, can you reproduce this issue with current master?

@rockdaboot
Copy link
Contributor

rockdaboot commented Mar 14, 2019

Checking out curl-7_64_0 and this issue appears, for both PSL and non-PSL builds (no Cookie: header set in the GET request).

So this seems to be fixed after 7.64.0, for PSL and non-PSL builds (tested with current master).

The original issue (Cookies aren't saved for hostnames #3649) is not reproducible with current master, neither with PSL nor with non-PSL builds. All on Debian unstable.

bagder added a commit that referenced this issue Mar 14, 2019
From a discussion in #3676

Suggested-by: Tim Rühsen

Closes #3682
bagder added a commit that referenced this issue Mar 14, 2019
From a discussion in #3676

Suggested-by: Tim Rühsen

Closes #3682
@Largo2005
Copy link

Sorry for this late reply but I have to setup a new mingw64 environment (to be in the same condition as I was) and it took me some time.
I've made some tests with the new curl version (with and without libpsl). Now everything is working as expected for me.

@bagder
Copy link
Member Author

bagder commented Mar 15, 2019

Thanks, so lots of chasing after a bug that was already fixed. Case closed.

@bagder bagder closed this as completed Mar 15, 2019
@lock lock bot locked as resolved and limited conversation to collaborators Jun 14, 2019
@bagder bagder added the cookies label Nov 17, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Development

No branches or pull requests

3 participants