Purging the cache causes a non-rewritten, old version of a file to be served

[AssortedParrot]

I'm using nginx 1.8.1 with ngx_pagespeed 1.10.33.2 on Debian 8.4, running Linux 3.16 on a x64 VM.

I'm having a problem where after purging the cache for a file, any subsequent requests will return a old version of the file without any filters applied.

root@mybox:/var/www/htdocs# cat scripts.js
// Some comment
// Another comment
stuff.that('looks', {"like": 'a script'});
alert('some alert');
root@mybox:/var/www/htdocs# cat request.txt
GET /scripts.js HTTP/1.1
Host: mysite.com

Not sure if it's related to this issue, but if I make the request three times, I get three different responses; after the third request the response seems to stay more or less the same. Starting with the third request, the file is rewritten, so clearly ngx_pagespeed is active, but I'm intrigued by the missing X-Page-Speed header.

root@mybox:/var/www/htdocs# nc localhost 80 < request.txt
HTTP/1.1 200 OK
Server: nginx/1.8.1
Date: Wed, 06 Apr 2016 16:12:36 GMT
Content-Type: application/javascript
Content-Length: 99
Last-Modified: Tue, 05 Apr 2016 15:01:11 GMT
Connection: keep-alive
ETag: "5703d337-68"
Accept-Ranges: bytes

// Some comment
// Another comment
stuff.that('looks', {"like": 'a script'});
alert('some alert');^C
root@mybox:/var/www/htdocs# nc localhost 80 < request.txt
HTTP/1.1 200 OK
Server: nginx/1.8.1
Content-Type: application/javascript
Connection: keep-alive
ETag: "5703d337-68"
Accept-Ranges: bytes
Date: Wed, 06 Apr 2016 16:12:36 GMT
Expires: Wed, 06 Apr 2016 16:17:36 GMT
Cache-Control: max-age=300
X-Original-Content-Length: 99
Vary: Accept-Encoding
Vary: Accept-Encoding
Content-Length: 99

// Some comment
// Another comment
stuff.that('looks', {"like": 'a script'});
alert('some alert');^C
root@mybox:/var/www/htdocs# nc localhost 80 < request.txt
HTTP/1.1 200 OK
Server: nginx/1.8.1
Content-Type: application/javascript
Connection: keep-alive
Accept-Ranges: bytes
X-Original-Content-Length: 60
Vary: Accept-Encoding
Vary: Accept-Encoding
Content-Length: 60
ETag: W/"PSA-aj-q2leciObKQ"
Date: Wed, 06 Apr 2016 16:14:57 GMT
Expires: Wed, 06 Apr 2016 16:17:36 GMT
Cache-Control: max-age=158

stuff.that('looks',{"like":'a script'});alert('some alert');^C

Now, trying to change the contents of the file and purging the cache produces the problem:

root@mybox:/var/www/htdocs# cat purge.txt
PURGE /scripts.js HTTP/1.1
Host: mysite.com

root@mybox:/var/www/htdocs# cat > scripts.js
// Modified comment
alert('Modified alert');
root@mybox:/var/www/htdocs# nc localhost 80 < purge.txt
HTTP/1.1 200 OK
Server: nginx/1.8.1
Content-Type: text/html
Transfer-Encoding: chunked
Connection: keep-alive
Date: Wed, 06 Apr 2016 16:20:16 GMT
Expires: Wed, 06 Apr 2016 16:20:16 GMT
Cache-Control: max-age=0, no-cache

10
Purge successful
0^C
root@mybox:/var/www/htdocs# nc localhost 80 < request.txt
HTTP/1.1 200 OK
Server: nginx/1.8.1
Content-Type: application/javascript
Connection: keep-alive
ETag: "5703d337-68"
Accept-Ranges: bytes
Date: Wed, 06 Apr 2016 16:18:39 GMT
Expires: Wed, 06 Apr 2016 16:23:39 GMT
Cache-Control: max-age=300
X-Original-Content-Length: 99
Vary: Accept-Encoding
Vary: Accept-Encoding
Content-Length: 99

// Some comment
// Another comment
stuff.that('looks', {"like": 'a script'});
alert('some alert');

As you can see, it serves the non-rewritten old version of the file. It will continue serving the old version without rewriting it for a while (I believe it's 5 minutes, just like the Expires header suggests), after that it will start serving and rewriting the new version.

What could be causing this issue and how to I fix it? Also, why is the X-Page-Speed header missing and why is the Vary header sent twice?

Here's my configuration:

nginx http block:

    ##
    # Pagespeed Settings
    ##
    pagespeed EnableCachePurge on;
    pagespeed PurgeMethod PURGE;
    pagespeed Domain mysite.com;

This is my server block:

server {
    listen 80;
    listen [::]:80;

    root /var/www/htdocs;

    # Add index.php to the list if you are using PHP
    index index.html index.htm index.nginx-debian.html;

    server_name mysite.com;

    ##
    # Pagespeed Settings
    ##
    pagespeed on;
    pagespeed FileCachePath /var/ngx_pagespeed_cache;

    # Ensure requests for pagespeed optimized resources go to the pagespeed handler
    # and no extraneous headers get set.
    location ~ "\.pagespeed\.([a-z]\.)?[a-z]{2}\.[^.]{10}\.[^.]+" {
        add_header "" "";
    }
    location ~ "^/pagespeed_static/" { }
    location ~ "^/ngx_pagespeed_beacon$" { }
}

[hillsp]

Thanks for the amazingly clear bug report! I was able to reproduce this without much effort, it does indeed look like a bug. I'll poke at it a bit more.

The duplicate Vary headers were at least partially fixed in our latest beta. You might want to upgrade and see if that solves that particular problem.

[jeffkaufman]

@hillsp Could you try running your reproduction again, now that #1193 is merged, since @jmarantz thought #1193 might fix this bug?

[hillsp]

I can no longer repro this on trunk, so I'm guessing Josh's fix did the trick. Closing.