Logs configuration doesn't work in Docker + Caddy2

1. Caddy version (caddy version):

caddy version
v2.0.0 h1:pQSaIJGFluFvu8KDGDODV8u4/QRED/OPyIR+MWYYse8=

via docker run caddy

2. How I run Caddy:

docker run -v $(pwd)/Caddyfile:/etc/caddy/Caddyfile -p 8123:80 caddy

a. System environment:

Docker on Mac Os stable 2.3.0.3

b. Command:

c. Service/unit/compose file:

n/a

d. My complete Caddyfile or JSON config:

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

    log {
        format single_field common_log
    }
}

3. The problem I’m having:

Docker logs don’t seem to be respecting the config. I’d expect to see

::1 - - [09/Jun/2020:12:33:02 -0700] "GET / HTTP/1.1" 200 13
::1 - - [09/Jun/2020:12:33:02 -0700] "GET /favicon.ico HTTP/1.1" 200 13

But instead I am seeing

{"level":"info","ts":1591731228.3394825,"logger":"http.log.access","msg":"handled request","request":{"method":"GET","uri":"/","proto":"HTTP/1.1","remote_addr":"172.17.0.1:55342","host":"localhost:8123","headers":{"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-Mode":["navigate"],"Sec-Fetch-User":["?1"],"Sec-Fetch-Dest":["document"],"Accept-Language":["en-US,en;q=0.9"],"Connection":["keep-alive"],"Cache-Control":["max-age=0"],"Upgrade-Insecure-Requests":["1"],"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":["cross-site"],"Accept-Encoding":["gzip, deflate, br"]}},"common_log":"172.17.0.1 - - [09/Jun/2020:19:33:48 +0000] \"GET / HTTP/1.1\" 200 13","duration":0.00002,"size":13,"status":200,"resp_headers":{"Server":["Caddy"],"Content-Type":[]}}

4. Error messages and/or full log output:

{"level":"info","ts":1591731290.1942115,"msg":"using provided configuration","config_file":"/etc/caddy/Caddyfile","config_adapter":"caddyfile"}
{"level":"info","ts":1591731290.1965184,"logger":"admin","msg":"admin endpoint started","address":"tcp/localhost:2019","enforce_origin":false,"origins":["localhost:2019","[::1]:2019","127.0.0.1:2019"]}
{"level":"info","ts":1591731290.1966531,"logger":"http","msg":"server is listening only on the HTTP port, so no automatic HTTPS will be applied to this server","server_name":"srv0","http_port":80}
{"level":"info","ts":1591731290.1967478,"logger":"tls","msg":"cleaned up storage units"}
2020/06/09 19:34:50 [INFO][cache:0xc00060c320] Started certificate maintenance routine
{"level":"info","ts":1591731290.1970928,"msg":"autosaved config","file":"/config/caddy/autosave.json"}
{"level":"info","ts":1591731290.1971185,"msg":"serving initial configuration"}
{"level":"info","ts":1591731291.0741756,"logger":"http.log.access","msg":"handled request","request":{"method":"GET","uri":"/","proto":"HTTP/1.1","remote_addr":"172.17.0.1:55346","host":"localhost:8123","headers":{"Upgrade-Insecure-Requests":["1"],"Sec-Fetch-Mode":["navigate"],"Sec-Fetch-User":["?1"],"Accept-Language":["en-US,en;q=0.9"],"Cache-Control":["max-age=0"],"Connection":["keep-alive"],"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"],"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-Site":["cross-site"],"Sec-Fetch-Dest":["document"],"Accept-Encoding":["gzip, deflate, br"]}},"common_log":"172.17.0.1 - - [09/Jun/2020:19:34:51 +0000] \"GET / HTTP/1.1\" 200 13","duration":0.0000277,"size":13,"status":200,"resp_headers":{"Server":["Caddy"],"Content-Type":[]}}



5. What I already tried:

When I use Caddy locally via brew and caddy run then it seems to work. So it got me thinking, maybe it is the lack of interactive mode in docker. I tried running with docker run -it ... but still same results.

6. Links to relevant resources:

n/a

I can’t be the only one with this problem. I have a feeling something is wrong with the docker build. But I hope someone else can point me to what might be missing.

1 Like

I’m seeing some really weird behaviour. I don’t think it’s actually related to Docker. Caddy version: v2.0.0 h1:pQSaIJGFluFvu8KDGDODV8u4/QRED/OPyIR+MWYYse8=

For this Caddyfile:

{
  https_port 8443
}

https://localhost {
  respond "OK!" 200
  log {
    format single_field common_log
  }
}

curl https://localhost:8443/ produces:

2020/06/10 04:47:21.492 INFO http.log.access handled request {"request": {"method": "GET", "uri": "/", "proto": "HTTP/2.0", "remote_addr": "[::1]:57781", "host": "localhost:8443", "headers": {"Accept": ["*/*"], "User-Agent": ["curl/7.64.1"]}, "tls": {"resumed": false, "version": 771, "ciphersuite": 49196, "proto": "h2", "proto_mutual": true, "server_name": "localhost"}}, "common_log": "::1 - - [10/Jun/2020:14:47:21 +1000] \"GET / HTTP/2.0\" 200 3", "duration": 0.000013717, "size": 3, "status": 200, "resp_headers": {"Server": ["Caddy"], "Content-Type": []}}

However, this Caddyfile:

https://localhost:8443 {
  respond "OK!" 200
  log {
    format single_field common_log
  }
}

curl https://localhost:8443/ produces:

::1 - - [10/Jun/2020:14:47:35 +1000] "GET / HTTP/2.0" 200 3

I think it’s actually to do with the host.

If the host includes a non-standard port that isn’t specified, it’s like it’s being caught by the site block itself based on the host only, and logged, but the format specified only applies if the host matches exactly.

In your case it’s showing because you’re translating the port; I assume you are requesting localhost:8123, because that’s what you’re exposing Caddy’s port 80 on via Docker proxy, but as shown above, just using the default port changing global options seems to mess with things.

You are right. I changed Docker to -p 80:80 and it logs correctly now. :thinking:

This does sound like a weird bug. Right? Should I open a Github issue?

1 Like

Yes, please!

Im seeing the same thing I think, my external port at the router is not the port which is used by caddy. Its forwarding externally from x to 443 internally. There are no logs hitting the log file at all but all are visible in the caddy console (systemctl status caddy). I’m doing this as I am using 443 already for an TLS VPN, and the page is fine hosting off of another port. Internally though I’d like to serve the pages off 443.

Caddy console shows host as <hostname>:<ext_port> but the config file is set for https:// (e.g. 443)

This topic was automatically closed after 30 days. New replies are no longer allowed.