I’ve recently added ETag support to this blog. There’s a post coming soon on how to use the Rails cache helpers to short-circuit the generation of dynamic content that your user’s browser already has. While I was monitoring the situation with the Heroku logs command, I saw something a little strange in the requests being processed. Here is a request from Pingdom for the home page of the blog (with the times removed to save space)
app[web.1]: Started GET "/" for 126.96.36.199 at 2012-12-20 01:00:29 +0000 app[web.1]: Processing by MainController#show as HTML app[web.1]: Filter chain halted as :load_posts rendered or redirected app[web.1]: Completed 304 Not Modified in 10ms (ActiveRecord: 3.0ms | Dalli: 18.2ms) heroku[router]: at=info method=GET path=/ host=blog.craz8.com fwd=188.8.131.52 dyno=web.1 queue=0 wait=0ms connect=1ms service=41ms status=200 bytes=56586 heroku[nginx]: 184.108.40.206 - - [20/Dec/2012:01:00:29 +0000] "GET / HTTP/1.0" 200 56586 "-" "Pingdom.com_bot_version_1.4_(http://www.pingdom.com)" blog.craz8.com
The main thing to notice here is that my application code returned a 304 Not Modified response, but Heroku returned a 200 OK response to the client. Heroku doesn’t cache responses for Cedar apps, so what’s going on here?
The big clue was this data: Dalli: 18.2ms (Dalli is a memcache client library). For such a small request, why is so much time spent getting data from memcache? Perhaps it’s because the entire response actually came from memcache somewhere in the middleware stack that doesn’t log its output. Which other middleware uses memcache?
Following along with the code, I’ve discovered that the Rack::Cache middleware is doing all the work here. If you’ve marked a response with an ETag, Rack::Cache remembers this as part of the cached reponse data. If a request comes from a client without an ETag then Rack::Cache will add the ETag they just looked up and pass that up to your application. If you return a 304 Not Modified response, then they can return the response body that matches that ETag.
Rack::Cache works with ETags in your application to allow you to bypass creation of dynamic content even for clients that have never visited before. I have yet to see any documentation on this feature, but it makes the use of Rails cache helpers - stale? and fresh_when - much more useful.