Caddy: v2: Logs configuration doesn't work when port is non-standard on Docker

[amir20]

This is a follow up regarding this issue I opened in the forums.

I first discovered this while I was migrating to v2.

Goal
Migrate to v2 and keep the logging the way it has been. I am not ready to use JSON yet as it is mostly a side project where I tail to look for errors.

Problem
While doing the migration, I noticed format single_field common_log didn't work. In fact, nothing worked with format .... So I started creating a small example. Here is the Caddyfile I used.

http://localhost {
    respond "Hello, world!" 

    log {
        format single_field common_log
    }
}

I ran the code with docker using docker run -v $(pwd)/Caddyfile:/etc/caddy/Caddyfile -p 81234:80 -it caddy

Which prints

2020/06/10 16:49:38.494 INFO    http.log.access handled request {"request": {"method": "GET", "uri": "/", "proto": "HTTP/1.1", "remote_addr": "172.17.0.1:52422", "host": "localhost:8123", "headers": {"User-Agent": ["Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/83.0.4103.97 Safari/537.36"], "Sec-Fetch-Site": ["none"], "Sec-Fetch-Mode": ["navigate"], "Connection": ["keep-alive"], "Upgrade-Insecure-Requests": ["1"], "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"], "Sec-Fetch-User": ["?1"], "Sec-Fetch-Dest": ["document"], "Accept-Encoding": ["gzip, deflate, br"], "Accept-Language": ["en-US,en;q=0.9"]}}, "common_log": "172.17.0.1 - - [10/Jun/2020:16:49:38 +0000] \"GET / HTTP/1.1\" 200 13", "duration": 0.0000262, "size": 13, "status": 200, "resp_headers": {"Server": ["Caddy"], "Content-Type": []}}

More investigation
I initially thought the problem might be something with interactive mode in Docker. But as Mathew pointed out in the forum, this seems to be related to the port.

Doing docker run -v (pwd)/Caddyfile:/etc/caddy/Caddyfile -p 80:80 -it caddy fixed the problem.

When using docker, port 80 is usually randomly mapped, which makes this bug even more relevant.

[francislavoie]

I'm pretty sure the specific reason for the issue is the log handler not matching against the Host which the request has as localhost:8123, while the configured server is localhost.

I think the log handler should try with "hostport" first, and if that doesn't have a logger_names match, should try with "host" without the port next. That might have some unintended side-effects though, so I delegate to @mholt

[danlsgiga]

I just hit this issue and I can confirm the issue is exactly how @francislavoie described. As soon as I set the Host with the same port defined via http_port the log config is honoured

[mholt]

Thanks for the report - can you please try #3522 and see if that fixes it for you all?

[danlsgiga]

@mholt Confirmed! Working as expected now! Thanks!