Page MenuHomePhabricator

org.apache.http.client.protocol.ResponseProcessCookies : Invalid cookie header for WMF-Last-Access
Closed, ResolvedPublic

Description

This is a spin of a 2015 task T98396 . In Gerrit log (gerrit1001.wikimedia.org /var/log/gerrit/error_log) we have messages such as:

[2021-02-02T11:27:27.879+0000] [ReceiveCommits-23-for-SSH git-receive-pack /operations/puppet.git (xxxx)]
WARN  org.apache.http.client.protocol.ResponseProcessCookies :
  Invalid cookie header:
    "Set-Cookie: WMF-Last-Access=02-Feb-2021;Path=/;HttpOnly;secure;Expires=Sat, 06 Mar 2021 00:00:00 GMT".
    Invalid 'expires' attribute: Sat, 06 Mar 2021 00:00:00 GMT

Note: this is from a thread serving a git push from a client over ssh. There is no reason for a HTTP cookie to be involved. The same can be seen from Zuul ssh commands (as user jenkins-bot).

The previous task hinted at the Java Apache httpclient library: https://svn.apache.org/repos/asf/httpcomponents/httpclient/tags/4.4.1/httpclient/src/main/java/org/apache/http/impl/cookie/RFC2109Spec.java which had:

final static String[] DATE_PATTERNS = {
     DateUtils.PATTERN_RFC1123,
     DateUtils.PATTERN_RFC1036,
     DateUtils.PATTERN_ASCTIME
 };
public static final String PATTERN_RFC1123 = "EEE, dd MMM yyyy HH:mm:ss zzz";
public static final String PATTERN_RFC1036 = "EEE, dd-MMM-yy HH:mm:ss zzz";
public static final String PATTERN_ASCTIME = "EEE MMM d HH:mm:ss yyyy";

The first one (RFC1123) should match Sat, 06 Mar 2021 00:00:00 GMT?

Gerrit 3.2.7 uses:

WORKSPACE
HTTPCOMP_VERS = "4.5.2"
    artifact = "org.apache.httpcomponents:httpclient:" + HTTPCOMP_VERS,

Apache tree https://github.com/apache/httpcomponents-client/tree/rel/v4.5.2 the exception possibly coming from https://github.com/apache/httpcomponents-client/blob/rel/v4.5.2/httpclient/src/main/java/org/apache/http/impl/cookie/LaxExpiresHandler.java#L156-L170

} catch (final NumberFormatException ignore) {
    throw new MalformedCookieException("Invalid 'expires' attribute: " + value);
}
if (!foundTime || !foundDayOfMonth || !foundMonth || !foundYear) {
    throw new MalformedCookieException("Invalid 'expires' attribute: " + value);
}
if (year >= 70 && year <= 99) {
    year = 1900 + year;
}
if (year >= 0 && year <= 69) {
    year = 2000 + year;
}
if (day < 1 || day > 31 || year < 1601 || hour > 23 || minute > 59 || second > 59) {
    throw new MalformedCookieException("Invalid 'expires' attribute: " + value);
}

Or from https://github.com/apache/httpcomponents-client/blob/rel/v4.5.2/httpclient/src/main/java/org/apache/http/impl/cookie/BasicExpiresHandler.java#L61-L65

final Date expiry = DateUtils.parseDate(value, this.datepatterns);
if (expiry == null) {
    throw new MalformedCookieException("Invalid 'expires' attribute: "
            + value);
}

Some extra information by vgutierrez:

Wikimedia CDN sets the cookie via a VCL:

sub set_last_access_cookie__ {
	header.append(resp.http.Set-Cookie,
		"WMF-Last-Access="
		+ req.http.X-NowDay
		+ ";Path=/;HttpOnly;secure;Expires="
		+ std.time(std.time2integer(now + 32d, 0) / 43200 * 43200, now)
	);
}

By RFC 6265 https://httpwg.org/specs/rfc6265.html#sane-set-cookie is intended as a server -> client header

Event Timeline

https://issues.apache.org/jira/browse/HTTPCLIENT-1763 states the default is the Netscape cookie draft which is:

Wdy, DD-Mon-YYYY HH:MM:SS GMT

Which brings me to HttpClient 4.4 release note:

Support for the latest HTTP state management specification (RFC 6265). Please note that the old cookie policy is still used by default for compatibility reasons. RFC 6265 compliant cookie policies need to be explicitly configured by the user. Please also note that as of next feature release support for Netscape draft, RFC 2109 and RFC 2965 cookie policies will be deprecated and disabled by default. It is recommended to use RFC 6265 compliant policies for new applications unless compatibility with RFC 2109 and RFC 2965 is required and to migrate existing applications to the default cookie policy.

And https://stackoverflow.com/questions/36473478/fixing-httpclient-warning-invalid-expires-attribute-using-fluent-api (which reference our WMF-Last-Access) states one should use: RequestConfig.custom().setCookieSpec(CookieSpecs.STANDARD). Maybe that has to be applied to jgit ( https://gerrit.googlesource.com/jgit ):

org.eclipse.jgit.http.apache/src/org/eclipse/jgit/transport/http/apache/HttpClientConnection.java
--- a/org.eclipse.jgit.http.apache/src/org/eclipse/jgit/transport/http/apache/HttpClientConnection.java
+++ b/org.eclipse.jgit.http.apache/src/org/eclipse/jgit/transport/http/apache/HttpClientConnection.java
@@ -127,6 +127,8 @@ private HttpClient getClient() {
                                configBuilder
                                                .setRedirectsEnabled(followRedirects.booleanValue());
                        }
+                       configBuilder.setCookieSpec(CookieSpecs.STANDARD);
+
                        boolean pooled = true;
                        SSLConnectionSocketFactory sslConnectionFactory;
                        if (socketFactory != null) {

Anyway I dont quite know what is going on.

hashar updated the task description. (Show Details)
hashar claimed this task.

After T262996, the log spam has vanished. The last entry was received at Nov 3, 2022 @ 17:03:05.892 UTC

I have edited the Gerrit Kibana Dashboard to remove the invalid cookie header filter.

I had an untested patch for jgit which would maybe make it able to read those cookies:

org.eclipse.jgit.http.apache/src/org/eclipse/jgit/transport/http/apache/HttpClientConnection.java

diff --git a/org.eclipse.jgit.http.apache/src/org/eclipse/jgit/transport/http/apache/HttpClientConnection.java b/org.eclipse.jgit.http.apache/src/org/eclipse/jgit/transport/http/apache/HttpClientConnection.java
index 90348f54b..65b501d88 100644
--- a/org.eclipse.jgit.http.apache/src/org/eclipse/jgit/transport/http/apache/HttpClientConnection.java
+++ b/org.eclipse.jgit.http.apache/src/org/eclipse/jgit/transport/http/apache/HttpClientConnection.java
@@ -125,10 +125,12 @@ private HttpClient getClient() {
                        }
                        if (followRedirects != null) {
                                configBuilder
                                                .setRedirectsEnabled(followRedirects.booleanValue());
                        }
+                       configBuilder.setCookieSpec(CookieSpecs.STANDARD);
+
                        boolean pooled = true;
                        SSLConnectionSocketFactory sslConnectionFactory;
                        if (socketFactory != null) {
                                pooled = usePooling;
                                sslConnectionFactory = socketFactory;

But I never tried it. I wrote that back in June 2022 with no context as to why it might fix it .