Debugging Response Headers

General
1

Hi,
Even when things are working as expected, it’s nice to be able to verify what’s going on, and really prove it. These response headers are excellent:

x-served-by: cache-den8252-DEN
x-cache: HIT
x-cache-hits: 1

Is it a MISS or HIT, and which cache.

Our web server is sending Response Headers that includes Vary: Cookie, origin. That means the caching decision will be affected by Cookies, which makes sense.

On a certain set of pages, I’m stripping out the Cookies to cause more caching to take place.

unset req.http.Cookie:csrftoken;

Regardless of csrftoken, all users get the same cached content.

I would like to verify this. What comes to mind is another response header something approximately as follows:

x-cache-key: url,Cookie:sessionid

In other words

x-the-caching-decision-factors: full_url,Cookie:sessionid

When analyzing this particular result we would see that the cache decision was based on the URL, and maybe something unexpected, another cookie called “sessionid”. Since each user has a unique sessionid, we know that caching is very inefficient, and most likely each user will get x-cache: MISS because they have a unique sessionid.

To mitigate the problem, remove that cookie too:

unset req.http.Cookie:sessionid;

Retry.

Now, without any sessionid cookie, it says:

x-cache-key: url

Perfect.

The question is, if there is a simple VCL recipe which could add this response header, and return an x-cache-key value which has the above mentioned behavior. List each factor which affected the caching decision. More specific than just saying “Cookies”. Which cookies, for that particular cached webpage.

Thanks.

2

If you want to verify if “all users get the same cached content”, req.digest might be the variable you are looking for.

In vcl_deliver, do

set resp.http.x-cache-key = req.digest;

then you can see if the key is the same of not. Here is the fiddle.

3

To List each factor which affected the caching decision, I feel we need some hard coded check (if you do not want to put the whole value of cookie into the response header x-cahce-key)

In this fiddle,

if (std.strstr(resp.http.vary, "cookie")) {
  log "has cookie";

  set resp.http.x-cache-key = resp.http.x-cache-key "cookie:";
  if (req.http.cookie:flag1) {
    set resp.http.x-cache-key = resp.http.x-cache-key "flag1,";
  }
  if (req.http.cookie:flag2) {
    set resp.http.x-cache-key = resp.http.x-cache-key "flag2,";
  }
  if (req.http.cookie:flag3) {
    set resp.http.x-cache-key = resp.http.x-cache-key "flag3,";
  }
}

when the request header has “cookie:flag1=2;flag3=3;” and response header has “vary:cookie”, we got response header “x-cache-key: url cookie:flag1,flag3,”.

4

Hi noguxun,

Thanks for your reply.

The problem with that example is that it’s hardcoding the checks. Meaning you must know about all the specific cookies, and even the url, in advance. It won’t discover unknown factors which the user hadn’t thought about. It won’t tell you, without your already knowing, what all the caching factors are.

How about the variable req.hash? Based on a brief description this seems to be the desired information.

“Hash value for the object. The hash determines what is unique about an object. Anything added to the hash will cause Varnish to cache objects separately based on that information.”

However it’s unreadable. “STRING can only be set (cannot be read or unset ).”

  • If req.hash were readable, what would the contents look like?
  • Do you agree req.hash sounds like it has the info I’m asking about?
  • Why can’t the variable be read?
5

@sdarwin , see my first comment,

req.digest is a readable req.hash

The digest (hash) of the currently served object, derived from information fed into req.hash during the most recent run of vcl_hash. This variable returns the digest in hexadecimal (64 characters).

6

Isn’t req.digest a single hex value such as fd21e85c4041312e28bc914eedb1b915 ?

However I get a sense that req.hash is more complicated. There is VCL in some examples like this:

  set req.hash += req.url;
  set req.hash += req.http.host;

Which goes back to the question: If req.hash were readable, what would the contents look like? It seems that it might clearly display “req.url” and cookies, so you could decipher it.

7

As we chat about this, it starts to uncover what might be happening.

+= req.url is the contents of the url. Not just the plain word “URL”, of course.

Likewise if cookies were added to the value, it would be the contents of the cookies and not the plain word “Cookie”.

But the contents of the cookies could lead to a security issue. You wouldn’t want to make that available. And this explains why req.hash isn’t readable.

Which means the debugging information which I was hoping for isn’t going to be displayed.

Imagining… data could be generated by having a mechanism in the source code where every time this occurs:

set req.hash += req.url;

It also automatically ran this:

set req.hash_fields += "REQ.URL".

Or

set req.hash += req.http.host;

caused

set req.hash_fields += "REQ.HTTP.HOST";

Those are plain strings, literally “URL”, and not the contents of req.url. Then return req.hash_fields in the headers as debugging information.

Well, just ideas. Looks like it’s not easily possible.

8

I think my previous comment about using req.digest might not be useful for you.
One thing I just remembered that how Fastly handles vary header.
In your case, you have a “Vary: cookie” response header. Fastly will have the same cache key (same req.digest and req.hash) for all requests with the same URL; when these requests have different cookie values, Fastly will save a different “version” of that object.

so your customized header “x-cache-key” should be something “hash factor” + “version factor”.

There is no good way to get information without knowing the name of the factor in advance.

so your customized header “x-cache-key” should be something “hash factor” + “version factor”.

anyway, there is no good way to get info without knowing the factor before head.