V2 rewrite order

[JeanLucLacroix]

Still trying to get my head around the rewrite directive…

Sample test config

test.gaubert:80 {
	root * /var/www/test
	file_server

	# logging
	log {
		output file /var/log/caddy/test.log
		level debug
	}

    # first replace _ by -
	@underscore path_regexp u ^([^_]+)_(.+)$
	rewrite @underscore {re.u.1}-{re.u.2}

    # then, add html extension to pretty URL's
	@shortUrl path_regexp s ^([^.]+)$
	rewrite @shortUrl {re.s.1}.html
}

I read that the order of the execution of the rewrite directives is random in this thread

@francislavoie

Unfortunately, you can’t rely on matchers to run in the order you define them in your Caddyfile. They’ll be run in an arbitrary order.

The same thread groups the rewrite directives in a handle to ensure the the rules are run in turn, but I don’t see how to do that.

I also would like to know if there is a way to see in the log how the rewrite works internally (order of execution).

[francislavoie]

@francislavoie

Unfortunately, you can’t rely on matchers to run in the order you define them in your Caddyfile. They’ll be run in an arbitrary order.

This quote is about matchers that are part of the same named matcher. You instead have two separate named matchers, so it’s not exactly the same.

The Caddyfile adapter will sort matcher/handler pairs first by the directive order, then if they are the same directive, by the length of their path matchers. If they have no path matcher, then one with a named matcher defined will sort higher than one without a named matcher (i.e. match-all).

Note that this is specifically path matchers and not path_regexp matchers. So by these rules, your two directives will be equal in the sorting.

I think that Golang will retain the original order of elements considered equal, but I’m not 100% certain. I’ll need to verify to be sure.

But if you want to be certain about the order these run in, you can wrap both in a route block which will ensure their order is preserved.

In the thread you linked, handle is used to split the named matcher into two distinct phases, essentially like wrapping if blocks inside eachother instead of using a logical AND (which the Caddyfile doesn’t make directly possible, because order matters with AND).

If you use the debug global option, you’ll see a message in the logs about the rewrite when it happens.

Hopefully that all makes sense!

[JeanLucLacroix]

That does not entirely “make sense” as I am not a Caddy dev, but the route block does the magic indeed: the rewrite directives are now executed in the order they are written in the Caddyfile.

route {
	@underscore path_regexp u ^([^_]+)_(.+)$
	rewrite @underscore {re.u.1}-{re.u.2}

	@shortUrl path_regexp s ^([^.]+)$
	rewrite @shortUrl {re.s.1}.html
}

I think I start to see the light, but I am not there just yet! As for the log level debug, for a URI like foo_bar, the file foo-bar.html is now served correctly, but I can not see the rewrite happen in the log that I have set to level debug as you can see in my sample Caddyfile above. The only entry I have :

{
  "level": "info",
  "ts": 1601985110.6761084,
  "logger": "http.log.access.log1",
  "msg": "handled request",
  "request": {
    "remote_addr": "192.168.0.92:49956",
    "proto": "HTTP/1.1",
    "method": "GET",
    "host": "test.gaubert",
    "uri": "/foo_bar",
    "headers": {
      "Connection": [
        "keep-alive"
      ],
      "Upgrade-Insecure-Requests": [
        "1"
      ],
      "Accept-Language": [
        "en-GB,en;q=0.9,fr-FR;q=0.8,fr;q=0.7,fr-BE;q=0.6,nl;q=0.5"
      ],
      "Pragma": [
        "no-cache"
      ],
      "Cache-Control": [
        "no-cache"
      ],
      "User-Agent": [
        "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/83.0.4103.116 Safari/537.36"
      ],
      "Accept": [
        "text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9"
      ],
      "Accept-Encoding": [
        "gzip, deflate"
      ]
    }
  },
  "common_log": "192.168.0.92 - - [06/Oct/2020:13:51:50 +0200] \"GET /foo_bar HTTP/1.1\" 200 25",
  "duration": 0.00116073,
  "size": 25,
  "status": 200,
  "resp_headers": {
    "Last-Modified": [
      "Tue, 06 Oct 2020 11:50:44 GMT"
    ],
    "Accept-Ranges": [
      "bytes"
    ],
    "Content-Length": [
      "25"
    ],
    "Server": [
      "Caddy"
    ],
    "Etag": [
      "\"qhs3kkp\""
    ],
    "Content-Type": [
      "text/html; charset=utf-8"
    ]
  }
}

[francislavoie]

debug is a global option:

Global options (Caddyfile) - Caddy Documentation

[JeanLucLacroix]

Thanks.

I can see now the rewriting process, but all debug logging messages end up in /var/log/daemon.log and /var/log/syslog files. How can I redirect them in a custom file? The debug messages don’t go to the file defined in the log directive that I have under the test.gaubert:80 site block.

[francislavoie]

Unfortunately that’s not possible from the Caddyfile right now, only access log config is available at the moment.

With JSON config you have full control though:

JSON Config Structure - Caddy Documentation

[JeanLucLacroix]

Ok, I’ll give it a try. Thank you Francis.

[JeanLucLacroix]

This did it.

curl -L localhost:2019/config/logging/logs/default \
-X POST -H "Content-Type: application/json" \
-d  '{"level": "DEBUG", "writer": {"filename": "/var/log/caddy/debug.log","output": "file"}}'

Learned something from this thread. Thank you.