imageproxy icon indicating copy to clipboard operation
imageproxy copied to clipboard

Add JSON log output support via logrus

Open blakestoddard opened this issue 5 years ago • 0 comments

First pass at adding JSON log output support + traceable transaction IDs (in the form of a UUID-based X-Request-ID) that allows you to tie most log lines to a given request.

This gets a little messy because there is no central log context. Logrus has an example of setting a program-wide field to include, but it doesn't work with something that changes so often (like a transaction ID that changes on every received request). Notably missing here is lack of support for including the transaction ID in log lines from the S3 and GCS cache implementations because I didn't have a way to pass the transaction ID and didn't want to use a global var.

This was really a proof of concept for our own internal usage since we front ImageProxy with nginx for better visibility into how long ImageProxy requests are taking. With these changes, we'll have a way to link nginx logs (we use the standard ECS format) with ImageProxy logs via the transaction ID.

I'd love some feedback here -- whether that's telling me that I'm doing this all wrong and need to start over, or that I should keep this in my own fork, either is okay 😂

(purposely left tests broken)

Before:

./imageproxy -verbose
imageproxy listening on localhost:8080
2020/10/01 14:41:32 fetching remote URL: https://images.apple.com/dm/us/20/1E6B8898-11AD-45E2-92A9-B108787F5756/i/offer_hero_2x.png
2020/10/01 14:41:33 request: {Method:GET URL:https://images.apple.com/dm/us/20/1E6B8898-11AD-45E2-92A9-B108787F5756/i/offer_hero_2x.png#0x0 Proto:HTTP/1.1 ProtoMajor:1 ProtoMinor:1 Header:map[Accept:[image/*] User-Agent:[willnorris/imageproxy]] Body:<nil> GetBody:<nil> ContentLength:0 TransferEncoding:[] Close:false Host:images.apple.com Form:map[] PostForm:map[] MultipartForm:<nil> Trailer:map[] RemoteAddr: RequestURI: TLS:<nil> Cancel:<nil> Response:<nil> ctx:0xc0000340f0} (served from cache: false)

After:

./imageproxy -verbose -logFormat json
imageproxy listening on localhost:8080
{"level":"info","msg":"fetching remote URL: https://images.apple.com/dm/us/20/1E6B8898-11AD-45E2-92A9-B108787F5756/i/offer_hero_2x.png","time":"2020-10-01T17:16:01-04:00","transaction":"d8724bf1-fc0e-4822-b7d5-f9b58dcbe5e1"}
{"level":"info","msg":"request: {Method:GET URL:https://images.apple.com/dm/us/20/1E6B8898-11AD-45E2-92A9-B108787F5756/i/offer_hero_2x.png#0x0 Proto:HTTP/1.1 ProtoMajor:1 ProtoMinor:1 Header:map[Accept:[image/*] User-Agent:[willnorris/imageproxy] X-Request-Id:[d8724bf1-fc0e-4822-b7d5-f9b58dcbe5e1]] Body:\u003cnil\u003e GetBody:\u003cnil\u003e ContentLength:0 TransferEncoding:[] Close:false Host:images.apple.com Form:map[] PostForm:map[] MultipartForm:\u003cnil\u003e Trailer:map[] RemoteAddr: RequestURI: TLS:\u003cnil\u003e Cancel:\u003cnil\u003e Response:\u003cnil\u003e ctx:0xc00012c008} (served from cache: false)","time":"2020-10-01T17:16:02-04:00","transaction":"d8724bf1-fc0e-4822-b7d5-f9b58dcbe5e1"}

blakestoddard avatar Oct 02 '20 14:10 blakestoddard