Caddy: Access log defaults to logging post-rewrite URI instead of request URI

[adamwathan]

1. What version of Caddy are you running (caddy -version)?

0.9.3

2. What are you trying to do?

Log requests to the access log

3. What is your entire Caddyfile?

localhost:2020

rewrite {
    to /rewrite.html
}

log access.log

4. How did you run Caddy (give the full command and describe the execution environment)?

caddy

5. What did you expect to see?

Log entries like:

::1 - [30/Sep/2016:10:47:05 -0400] "GET /foo/bar/baz HTTP/1.1" 304 0
::1 - [30/Sep/2016:10:47:05 -0400] "GET /favicon.ico HTTP/1.1" 200 18

The output above is from running the same Caddyfile with Caddy 0.8.3.

6. What did you see instead (give full error messages and/or log)?

Every log entry shows the rewritten URI:

::1 - [30/Sep/2016:10:48:25 -0400] "GET /rewrite.html HTTP/1.1" 304 0
::1 - [30/Sep/2016:10:48:25 -0400] "GET /rewrite.html HTTP/1.1" 200 18

This is the output using Caddy 0.9.3.

7. How can someone who is starting from scratch reproduce this behavior as minimally as possible?

Use this simple repo to reproduce: https://github.com/adamwathan/log-rewrite-issue

[adamwathan]

Caddy 0.8.3 used the request URI in the default access log entries, while 0.9.3 seems to use the post-rewrite URI. I think the request URI is probably what most people would expect, but happy to be convinced otherwise! 😊

[adamwathan]

Never mind! I thought I was running 0.9.3 but was mistakenly running a different version, seems fixed! :)

[adamwathan]

Actually I must've had something else messed up, because this is still definitely happening with 0.9.3.

If anyone wants to pull down that sample repo they should be able to reproduce.

[elcore]

Hello @adamwathan,

to be honest, I prefer post-rewrite URI instead of pre-rewrite URI -- I changed my mind!!!!!!!!!!

[adamwathan]

Haha interesting... If you are using Caddy to serve most PHP applications (even Wordpress for example), it means every single entry in your log shows the same URI which is a bit odd.

[abiosoft]

I think I go with pre-rewrite URI as well.

[elcore]

Hello @adamwathan,

that is odd :disappointed:, sorry! I changed my mind!!!!!!!!!! We need pre-rewrite URI

P.S.: That is embarrassing for me!!!

[mholt]

If you need that, what about specifying a custom log format using this header:{>Caddy-Rewrite-Original-URI}?

[elcore]

@mholt did not know we have that 👍

[mholt]

Yeah, haven't really documented it yet because I'm not sure how permanent it will be, or how useful it would be.

[adamwathan]

Hey @mholt! That's ok with me too, but thought I'd raise the issue anyways since it's different than 0.8.3 behavior.

However, I can't get that to work with a rewrite that points Caddy to something running over fastcgi, like PHP FPM.

It does work in the sample repo above that's just all plain HTML, but with a Caddyfile that looks more like this, I'm just getting "-" for that placeholder:

localhost:2020

fastcgi / /var/run/fpm-valet.socket php

rewrite {
    to /rewrite.php
}

log / access.log "{remote} - [{when}] \"{method} {>Caddy-Rewrite-Original-URI} {proto}\" {status} {size}"

[abiosoft]

The header is actually deleted by fastcgi here https://github.com/mholt/caddy/blob/master/caddyhttp/fastcgi/fastcgi.go#L208.

I think the reverse should be the case. The pre-rewrite url should be logged by default and users can have a way (probably via a header too) to log post-rewrite url if they wish.

[mholt]

Hmm, I can't remember exactly why I deleted the header except maybe to avoid passing it on to PHP scripts -- not that it would matter, though, right?

[abiosoft]

I don't think it matters.

[tobya]

I am having same issue as @adamwathan above with the {>Caddy-Rewrite-Original-URI} not available for fastcgi site

[mholt]

Will keeping the header there cause any problems for PHP backends then? @adamwathan do you think it would mess up any apps run by Valet (or Valet itself)?

[adamwathan]

Hey @mholt!

I can't think of any reason for it to cause any problems. Valet does some integrating with ngrok as well which passes through a bunch of ngrok specific headers and hasn't been an issue for anyone.

[tobya]

Event thought the pull request if accepted will allow

> {>Caddy-Rewrite-Original-URI}

to work, is there an argument here for {path} in the caddy file to log the same value as {>Caddy-Rewrite-Original-URI} as really it is the requested path that is of interest in a log rather than the rewritten path.

Is it worth considering another log placeholder such as {rewrite_path} which would contain what {path} currently contains, ie. the path after rewriting.

[mholt]

There's definitely room for that discussion, although probably in another issue that isn't specific to this bug report. :)