Transformations are needlessly performed and never cached when browser has up-to-date image.

[ccbrown]

If the browser has an up-to-date, transformed image in its cache, requests from that browser to the proxy will cause needless transformations to be performed unless that transformed image is also in the proxy's cache. If it is not in the proxy's cache, the proxy will perform the transformation on every request before responding with 304 and will never cache the transformed image (until a different browser requests it).

Here's an example timeline:

• Browser requests an image with a transformation such as http://localhost:8080/500,fit/https://static.pexels.com/photos/189349/pexels-photo-189349.jpeg.
• The proxy does the transformation and caches the response.
• The proxy is restarted or the image is evicted from the proxy's cache.
• The browser requests that same image with IF-X headers.
• The proxy does the transformation and responds with a 304.
• The browser requests that same image with IF-X headers.
• The proxy does the transformation and responds with a 304.
• The browser requests that same image with IF-X headers.
• The proxy does the transformation and responds with a 304.
• And so on... until a different browser requests the image, at which point the transformation will be done one last time and the result will be cached again.

There's a should304(req, resp) check in the RoundTripper that would fix this behavior if it ever returned true: https://github.com/willnorris/imageproxy/blob/ebcfb52f3ad5fd8011432861e08dbbcbe3ead4e4/imageproxy.go#L318

If the 304 was returned at that point, the transformation would be avoided and all would be good. Based on the commit (d64b0f81c998f925ff70dacd2bbbcd4361d6a152) and discussion (https://github.com/willnorris/imageproxy/issues/92), I assume this worked at some point, but it doesn't seem to any more.

The problem is that should304(req, resp) never returns true. The "If-Modified-Since" and "If-None-Match" headers that the browser sent never make it to that request:

https://github.com/willnorris/imageproxy/blob/ebcfb52f3ad5fd8011432861e08dbbcbe3ead4e4/imageproxy.go#L144

It seems like the proxy should do something a little closer to this instead:

forwardedReq, err := http.NewRequest("GET", req.String(), nil)
if err != nil {
	msg := fmt.Sprintf("error creating remote image request: %v", err)
	log.Print(msg)
	http.Error(w, msg, http.StatusInternalServerError)
	return
}
for _, k := range []string{"If-Modified-Since", "If-None-Match"} {
	if v, ok := r.Header[k]; ok {
		forwardedReq.Header[k] = v
	}
}

resp, err := p.Client.Do(forwardedReq)

But it's apparently not this simple since if the RoundTripper then returns 304, the image proxy just panics when it tries to copy httpcache's response:

2018/01/23 21:06:53 http: panic serving 127.0.0.1:54783: runtime error: invalid memory address or nil pointer dereference
goroutine 6 [running]:
net/http.(*conn).serve.func1(0xc4201ca820)
	/usr/local/go/src/net/http/server.go:1697 +0xd0
panic(0x1748000, 0x1cb4250)
	/usr/local/go/src/runtime/panic.go:491 +0x283
willnorris.com/go/imageproxy/vendor/github.com/gregjones/httpcache.(*cachingReadCloser).Close(0xc420230180, 0x0, 0x0)
	/Users/chris/go/src/willnorris.com/go/imageproxy/vendor/github.com/gregjones/httpcache/httpcache.go:548 +0x29
panic(0x1748000, 0x1cb4250)
	/usr/local/go/src/runtime/panic.go:491 +0x283
willnorris.com/go/imageproxy/vendor/github.com/gregjones/httpcache.(*cachingReadCloser).Read(0xc420230180, 0xc42060c000, 0x8000, 0x8000, 0x0, 0xc42034c100, 0x2c5bce8)
	/Users/chris/go/src/willnorris.com/go/imageproxy/vendor/github.com/gregjones/httpcache/httpcache.go:539 +0x3e
io.copyBuffer(0x1c75ce0, 0xc42034c190, 0x59e0568, 0xc420230180, 0xc42060c000, 0x8000, 0x8000, 0xc42034c190, 0xc42034c190, 0x1774bc0)
	/usr/local/go/src/io/io.go:392 +0x123
io.CopyBuffer(0x1c75ce0, 0xc42034c190, 0x59e0568, 0xc420230180, 0xc42060c000, 0x8000, 0x8000, 0x2, 0x1750140, 0x16733e2)
	/usr/local/go/src/io/io.go:373 +0x82
net/http.(*response).ReadFrom(0xc4201e0000, 0x59e0568, 0xc420230180, 0x0, 0x0, 0x0)
	/usr/local/go/src/net/http/server.go:564 +0x557
io.copyBuffer(0x1c73120, 0xc4201e0000, 0x59e0568, 0xc420230180, 0x0, 0x0, 0x0, 0x1750140, 0x182a000, 0x59e0568)
	/usr/local/go/src/io/io.go:386 +0x2bb
io.Copy(0x1c73120, 0xc4201e0000, 0x59e0568, 0xc420230180, 0xc420230180, 0x1, 0xc420180200)
	/usr/local/go/src/io/io.go:362 +0x68
willnorris.com/go/imageproxy.(*Proxy).serveImage(0xc420182180, 0x1c7b320, 0xc4201e0000, 0xc420180100)
	/Users/chris/go/src/willnorris.com/go/imageproxy/imageproxy.go:185 +0xa58

It also leaks a response body as this line seems to be misplaced:

https://github.com/willnorris/imageproxy/blob/ebcfb52f3ad5fd8011432861e08dbbcbe3ead4e4/imageproxy.go#L323

So I think caching for transformed images is broken and I suspect it comes down to this block not doing what it's supposed to do:

https://github.com/willnorris/imageproxy/blob/ebcfb52f3ad5fd8011432861e08dbbcbe3ead4e4/imageproxy.go#L318

I assume this all worked at the time of d64b0f81c998f925ff70dacd2bbbcd4361d6a152, but I can't figure out how...

[ccbrown]

Btw for some context on where this is coming from: The next Mattermost release will include support for proxying hot-linked, user-posted images via this or Camo. It's primarily because we want to be able to check off the "everything is served via HTTPS" boxes for customers, but we do have use-cases for the resizing capabilities of the proxy as well. We just need to make sure that it scales reasonably well, and right now, in horizontally scaling setups where proxy instances come and go, this is a bit of a problem.

So @willnorris maybe you know what's going on here, or maybe I'm overlooking something obvious to you. Otherwise, I'll be happy to put some time into developing a PR myself, but I want to at least get some weigh in first.

[willnorris]

Do you know if the proxy is passing along the IF-X headers to the origin server? If so, it's possible that it's receiving a 304 response from there, not actually doing a transformation (since it doesn't actually have the image bytes), and then subsequently returning a 304 to the client. At least I can certainly imagine an argument that this is a sane thing to do... I don't recall if that's actually what it does.

If that's not the case and we're actually fetching the image bytes from the origin server and performing the transformation every time, then that definitely sounds like a bug. I'm not likely going to have time to look into it, so have at it.

[ccbrown]

I don't think it's passing the headers to the origin server, but I don't think that's really much of an issue either. It's not fetching the image bytes on every request, but it is doing the transformation every time. Here's what the console output (with a println added for transformations) looks like in my above example timeline:

As you can see, after a server restart, the image is fetched one more time from the origin. That might not be optimal, but is a relatively minor issue. The bigger problem is that the image is transformed on every request after that.

[willnorris]

okay, gotcha... I think I misunderstood. So it looks to be fetching the image bytes from the remote server on first load and caching the unmodified image, it's just the transformed version that is failing to get cached, thus forcing it to perform the transformation on every request. Is that correct?

[ccbrown]

Yep, that's correct.

[willnorris]

okay, definitely a bug :) But unfortunately I don't have any bright ideas off the top of my head... you'll likely just need to trace the request a bit more closely through the system and see why it's not getting cached. I'll try and jump in and take a look as well when I've got some time.

[Micr0mega]

It also leaks a response body as this line seems to be misplaced

We have run into this and I have created a pull request to fix it: #153