Add vary-dynamic test

[neilstuartcraig]

trafficstars

Hi @mnot This is the PR I mentioned in #49 - adding a test to validate what I have called "dynamic vary". This issue came to my attention during building a traffic management system, we determined that nginx does not create cache object variants when the origin issues a vary header whose value is dependent on the value of a request header (we have some use cases which require this). Failure to support "dynamic vary" can result in flip-flopping - nginx simply overwrites the single cached object with the new object, this obviously ruins cache offload under transitional circumstances. As a ref for nginx, please see this ticket: https://trac.nginx.org/nginx/ticket/955.

My intention through adding this PR is twofold:

1. I'd like to document for others that nginx doesn't support "dynamic vary" as there's not much on the internet about it
2. This might add some weight to HTTP specs (I guess) which in turn might persuade the nginx folks that they should support "dynamic vary"

Varnish does support "dynamic vary" according to our tests.

I'm sure you'll see what I'm trying to achieve by looking at the added test, I believe I've correctly defined the behaviour but please let me know if you think I've done the wrong thing. Currently I see an error on request 3 which I expect not to be cached and indeed it looks to me like nginx did not serve a cached response for that request (I added a custom response header to nginx whose value is $upstream_cache_status, this says MISS):

[root@8b32f5ef0012 cache-tests]# npm run --silent cli --base=http://127.0.0.1:80 --id=vary-dynamic
(node:1045) ExperimentalWarning: The ESM module loader is experimental.
Running vary-dynamic
=== Client request 1
    GET http://127.0.0.1:80/test/19bd78b2-8e6c-4ba2-b1e7-7f7c17fef2ac
    v1: one
    v2: two
    ctrl: a
    Test-Name: An optimal HTTP cache stores and correctly serves multiple object variants when the `Vary` response header value depends on one or more request header values
    Test-ID: vary-dynamic
    Req-Num: 1

=== Server request 1
    GET /test/19bd78b2-8e6c-4ba2-b1e7-7f7c17fef2ac
    host: 127.0.0.1
    v1: one
    v2: two
    ctrl: a
    test-name: An optimal HTTP cache stores and correctly serves multiple object variants when the `Vary` response header value depends on one or more request header values
    test-id: vary-dynamic
    req-num: 1
    accept: */*
    user-agent: node-fetch/1.0 (+https://github.com/bitinn/node-fetch)
    accept-encoding: gzip,deflate

=== Server response 1
    HTTP 200 OK
    expires: Wed, 15 May 2019 14:05:37 GMT
    last-modified: Wed, 15 May 2019 11:52:17 GMT
    date: Wed, 15 May 2019 12:42:17 GMT
    vary: v1, ctrl
    content-type: text/plain
    server-request-count: 1
    server-now: Wed, 15 May 2019 12:42:17 GMT

=== Client response 1
    HTTP 200 OK
    connection: close
    content-length: 36
    content-type: text/plain
    date: Wed, 15 May 2019 12:42:17 GMT
    expires: Wed, 15 May 2019 14:05:37 GMT
    last-modified: Wed, 15 May 2019 11:52:17 GMT
    ngx-cache-status: MISS
    server: nginx/1.16.0
    server-now: Wed, 15 May 2019 12:42:17 GMT
    server-request-count: 1
    vary: v1, ctrl

=== Client request 2
    GET http://127.0.0.1:80/test/19bd78b2-8e6c-4ba2-b1e7-7f7c17fef2ac
    v1: one
    v2: two
    ctrl: a
    Test-Name: An optimal HTTP cache stores and correctly serves multiple object variants when the `Vary` response header value depends on one or more request header values
    Test-ID: vary-dynamic
    Req-Num: 2

=== Client response 2
    HTTP 200 OK
    connection: close
    content-length: 36
    content-type: text/plain
    date: Wed, 15 May 2019 12:42:17 GMT
    expires: Wed, 15 May 2019 14:05:37 GMT
    last-modified: Wed, 15 May 2019 11:52:17 GMT
    ngx-cache-status: HIT
    server: nginx/1.16.0
    server-now: Wed, 15 May 2019 12:42:17 GMT
    server-request-count: 1
    vary: v1, ctrl

=== Client request 3
    GET http://127.0.0.1:80/test/19bd78b2-8e6c-4ba2-b1e7-7f7c17fef2ac
    v1: one
    v2: two
    ctrl: b
    Test-Name: An optimal HTTP cache stores and correctly serves multiple object variants when the `Vary` response header value depends on one or more request header values
    Test-ID: vary-dynamic
    Req-Num: 3

=== Server request 2
    GET /test/19bd78b2-8e6c-4ba2-b1e7-7f7c17fef2ac
    host: 127.0.0.1
    v1: one
    v2: two
    ctrl: b
    test-name: An optimal HTTP cache stores and correctly serves multiple object variants when the `Vary` response header value depends on one or more request header values
    test-id: vary-dynamic
    req-num: 3
    accept: */*
    user-agent: node-fetch/1.0 (+https://github.com/bitinn/node-fetch)
    accept-encoding: gzip,deflate

=== Server response 2
    HTTP 200 OK
    content-type: text/plain
    server-request-count: 2
    server-now: Wed, 15 May 2019 12:42:17 GMT

=== Client response 3
    HTTP 200 OK
    connection: close
    content-length: 36
    content-type: text/plain
    date: Wed, 15 May 2019 12:42:17 GMT
    ngx-cache-status: MISS
    server: nginx/1.16.0
    server-now: Wed, 15 May 2019 12:42:17 GMT
    server-request-count: 2

==== Results
{
  "vary-dynamic": [
    "Assertion",
    "Response 3 comes from cache"
  ]

I suspect that perhaps the server component of cache-tests might be doing the wrong thing here, would you agree? I'll happily do some work on it if you think that is likely to be the issue and if you're interested in this PR so if you could let me know when you have moment, that'd be great.

Many thanks and apologies for the epic message :-) Neil

[mnot]

Hey,

Yes, I'd very much like to see tests like this made; this area of caching is not well-specified or widely understood.

I'll do a review of the pull; there are a couple of nits (nothing huge).

WRT the server component -- yes, from memory the server-side is going to need some reworking to be able to serve traffic like this.

I'm travelling right now but will do the review and take a closer look at the server ASAP.

Thanks!

[neilstuartcraig]

Awesome, thanks @mnot. If there's things you'd rather i'd done on the PR, please let me know so i can make any future contributions better - i'm intending to investigate whether we have any other less/atypical cache use cases and contribute them if so.

Cheers

[neilstuartcraig]

Thanks for the feedback @mnot - i'll get those amended as soon as i get a mo :-)

[neilstuartcraig]

@mnot - apologies for the delay, busy times right now! I believe I have taken care of the above feedback, if you have a moment to check, that'd be great. Also, do you want me to have a look at the server component WRT this?

[mnot]

No worries, apologies for the delay on this side too.

I think this can be made to correctly function if the second request is removed -- all that's doing is checking to make sure the response is cached, correct? If so, that's already covered by other tests.

If that's the case, my testing shows that varnish, squid, traffic server and apache all pass this (in the current master it's now possible to test them with docker, which is a lot easier, btw). Nginx fails because the (now) third request isn't cached, which is interesting. You list that request as setup, but I think it's now part of the test proper; maybe remove that?

I do still plan to make the server more robust (right now it isn't happy when there are cached requests followed by uncached requests), but if you remove the second request it means this won't be blocked on that work.

[neilstuartcraig]

I think this can be made to correctly function if the second request is removed -- all that's doing is checking to make sure the response is cached, correct? If so, that's already covered by other tests. Yep, that is indeed all it does. Quite right, I was faithfully reimplementing our stand-alone test and forgot to consider the context here. The second request can be removed in that case. I'll add a commit to do that.

Nginx fails because the (now) third request isn't cached, which is interesting. This was the bit which made me wonder if something in the server component of this repo needed a tweak. Since both the first and third response vary on ctrl, i'd expect the third response to be cached. Might it be something in the server component do you think? (maybe the "right now it isn't happy when there are cached requests followed by uncached requests" part?)

[neilstuartcraig]

Hi @mnot Great to meet you the other week, apologies again it's taken so long for me to get to re-testing this. I have got the new Docker setup working and rebased my fork. The output I see is:

...
  "vary-dynamic": [
    "Setup",
    "Response 3 does not come from cache"
  ],
...

I don't quite understand the output here, maybe I am being a bit dim but is this telling me that my test failed? (i see "<test name>": true on lots of others which i presume means they passed?).

Also, is the test count (3 in the above example) 0 or 1-based?

The Docker setup you now have is awesome, by the way. Thanks for building that out, it's now infinitely simpler to run tests quickly and reliably 🙌.

Cheers