Correctly zero ttl in Varnish 4.

[wjywbs]

I found that EXP_Rearm expects exact ttl in Varnish 4.

[wjywbs]

Friendly ping: @lkarsten @aondio

[aondio]

Hi. The test case you provide doesn't seem correct: we would expect an obj.ttl == 0 and not obj.ttl < 0, this is because in libvmod-softpurge we want to have a ttl == 0 ( but not < 0) in order to be able to use the grace. If you give a look at the implementation of EXP_Rearm, you will notice the result of the updated object exp.ttl depends on multiple variables: now, t_origin and ttl, so using ttl == 0 as argument for EXP_Rearm won't set exp.ttl = 0 because there are other two variables to take care of.

Kind regards. A.A.

[wjywbs]

Hello,

Thanks for your reply.

First I agree that ttl (header) should be 0 when the PURGE request completes. The next request will have a negative ttl header because the time between the PURGE request and this request. In the code level, ttl header = 0 means exp.ttl = now - exp.t_origin. Currently this plugin does not set exp.ttl to now - exp.t_origin during the PURGE request in varnish 4.

In varnish 4,

EXP_Rearm: exp.ttl = now + ttl - exp.t_origin; // cache_expire.c
EXP_Ttl = exp.t_origin + exp.ttl

EXP_Rearm(o, now, now - o->exp.t_origin, o->exp.grace, o->exp.keep); // vmod_softpurge.c
exp.ttl = now + (now - o->exp.t_origin) - exp.t_origin = 2 * (now - exp.t_origin) // wrong here
EXP_Ttl = exp.t_origin + exp.ttl = 2*now - exp.t_origin
EXP_Ttl - now = now - exp.t_origin // vmod_softpurge.c, object updated ttl is set to the amount of time since the fetch time

Corrected:
EXP_Rearm(o, now, 0, o->exp.grace, o->exp.keep); // vmod_softpurge.c
exp.ttl = now + 0 - exp.t_origin = now - exp.t_origin
EXP_Ttl = exp.t_origin + exp.ttl = now
EXP_Ttl - now = 0 // vmod_softpurge.c, object updated ttl is set to 0

This is a patch to the test. "XX: object updated. ttl ends in 2.002, grace ends in 602.002 for object 0" will be found in the log. It should output "ttl ends in 0" instead of 2.002.

diff --git a/src/tests/11-really-purged.vtc b/src/tests/11-really-purged.vtc
index 89cc8e8..fbce0eb 100644
--- a/src/tests/11-really-purged.vtc
+++ b/src/tests/11-really-purged.vtc
@@ -12,7 +12,11 @@ server s1 {
    txresp
 } -start

+varnish v1 -cliok "param.set vcc_allow_inline_c true"
+
 varnish v1 -vcl+backend {
+   C{ #include <unistd.h> }C
+
    import softpurge from "${vmod_topbuild}/src/.libs/libvmod_softpurge.so";
    backend b1 {
        .host = "${s1_addr}";
@@ -21,6 +25,7 @@ varnish v1 -vcl+backend {

    sub vcl_recv {
        set req.backend_hint = b1;
+       C{ sleep(2); }C

        if (req.method == "PURGE") { return(hash); }
    }
@@ -70,6 +75,7 @@ client c1 {
    # run the softpurge
    txreq -req "PURGE" -url "/"
    rxresp
+   expect resp.http.x-via == "stop-here"

    # check that grace is used.
    txreq -url "/"

[aondio]

Hi. Can you please provide me a complete test case and not a diff, because I can't find where you define resp.http.x-via and AFAIK there is no such header in softpurge test #11. Thank you.

[wjywbs]

Hello, I fixed and simplified the test. The following patch will produce the same failure: "XX: object updated. ttl ends in 2.002, grace ends in 602.002 for object 0" and "x-object-ttl: 2.000".

diff --git a/src/tests/11-really-purged.vtc b/src/tests/11-really-purged.vtc
index 89cc8e8..f415ca9 100644
--- a/src/tests/11-really-purged.vtc
+++ b/src/tests/11-really-purged.vtc
@@ -67,6 +67,8 @@ client c1 {
    expect resp.status == 200
    expect resp.http.x-via == "hit"

+   delay 2
+
    # run the softpurge
    txreq -req "PURGE" -url "/"
    rxresp
@@ -77,6 +79,7 @@ client c1 {
    expect resp.http.x-via == "hit"
    expect resp.status == 200
    expect resp.http.x-object-hits != 0
+   expect resp.http.x-object-ttl <= 0

    # check that the obj was refreshed via a bgfetch in prev req
    txreq -url "/"

Thanks.

[aondio]

Hi again, I've run the test case you provided me and other test cases and I still get a ttl == 0 as expected. Please note that "XX: object updated. ttl ends in 2.002, grace ends in 602.002 for object 0" and "x-object-ttl: 2.000" is just a line from VSL, it might be we print the wrong value in here, but the object ttl as indicated in the x-object-ttl header is correct.

[wjywbs]

Hello, the plugin prints the wrong value because it sets the wrong value. If I change "delay 2" to "delay 5" in the test, it will set the ttl to 5.000 and print "x-object-ttl: 5.000", "x-ttl: 5.000" and "Age: 5". If I set up varnish with this plugin and use a browser to test, I can see that new page is not immediately fetched when I softpurge and refresh the web page. Instead I can see the ttl header > 0 in my browser (should be <= 0).