Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

logs.skip_hosts is ignored #6248

Closed
Winand opened this issue Apr 18, 2024 · 12 comments · Fixed by #6251
Closed

logs.skip_hosts is ignored #6248

Winand opened this issue Apr 18, 2024 · 12 comments · Fixed by #6251
Labels
bug 🐞 Something isn't working
Milestone

Comments

@Winand
Copy link

Winand commented Apr 18, 2024

Caddy 2.7.6 in Docker. Port forwarding: 80(host) -> 80(caddy), 2999(host) -> 443(caddy)

I have several domain names in Caddyfile, only one of them has log enabled.

domain1.com {
  ...
}
domain2.com {
  log
  ...
}
domain3.com {
  ...
}

In caddy adapt output I see that domain 1 and 3 are added to skip_hosts:

                    "logs": {
                        "logger_names": {
                            "domain2.com": ""
                        },
                        "skip_hosts": [
                            "domain1.com",
                            "domain3.com"
                        ]
                    },

But access log records for all three domains appear in docker logs caddy. Is it the expected behaviour?
Of course I can add skip_log to domains 1 and 3 but why skip_hosts does not disable logs?

@francislavoie
Copy link
Member

We've made significant changes to logging since 2.7.6. Please try with the master branch.

@Winand
Copy link
Author

Winand commented Apr 18, 2024

First I've built caddy using xcaddy build master
Then I've built docker image with modified Dockerfile

...
COPY ./caddy /usr/bin/caddy
RUN setcap cap_net_bind_service=+ep /usr/bin/caddy; \
	chmod +x /usr/bin/caddy; \
	caddy version
...

With this newly built image I have no access log in docker logs caddy output at all with just a log directive in domain2 section. Here's logging part of adapt output:

                    "logs": {
                        "logger_names": {
                            "domain2.com": [
                                ""
                            ]
                        },
                        "skip_hosts": [
                            "domain3.com",
                            "domain1.com"
                        ]
                    },

BUT it works as expected with

  log {
    output stderr
  }

which adds logging section in adapt output:

                    "logs": {
                        "logger_names": {
                            "domain2.com": [
                                "log0"
                            ]
                        },
                        "skip_hosts": [
                            "domain3.com",
                            "domain1.com"
                        ]
                    },
....
    "logging": {
        "logs": {
            "default": {
                "exclude": [
                    "http.log.access.log0"
                ]
            },
            "log0": {
                "include": [
                    "http.log.access.log0"
                ],
                "writer": {
                    "output": "stderr"
                }
            }
        }
    }

@francislavoie
Copy link
Member

Interesting, okay I can replicate this. Investigating...

@francislavoie
Copy link
Member

I think I have a fix in #6251, can you give it a shot? You can build with xcaddy build fix-default-logger or xcaddy build 732653f

@Winand
Copy link
Author

Winand commented Apr 19, 2024

Now it's the same as in v2.7.6. There're access log records for all three domains in stderr, though log directive is only in the 2nd one

domain1.com {
  handle /metrics {
    reverse_proxy node_exporter:9100
  }
}

domain2.com {
  log
  reverse_proxy * firezone:13000
}

domain3.com {
........
}

Here's my Dockerfile to build Caddy.

@francislavoie
Copy link
Member

That's not the behaviour I see. If you redact your domains, I can't know with certainty that we're trying the same thing.

@Winand
Copy link
Author

Winand commented Apr 19, 2024

Ok, I've made a minimal reproducible example:
docker-compose.yml

services:
  caddy:
    image: winand/caddy:2.7.6-default-logger-3
    container_name: caddy
    volumes:
      - ./caddy-data:/data/caddy
      - ./Caddyfile:/etc/caddy/Caddyfile
    ports:
      - "80:80"
      - "2053:443"
    restart: unless-stopped

networks:
  default:
    name: caddy-network

Caddyfile:

domain1.localhost {
  respond "Hello World. I'm domain 1"
}

domain2.localhost {
  log
  respond "Hello World. I'm domain 2"
}

Do requests:

curl -k https://domain2.localhost:2053
curl -k https://domain1.localhost:2053

Docker container logs:

...
{"level":"info","ts":1713546040.6438966,"logger":"http.log.access","msg":"handled request","request":{"remote_ip":"172.18.0.1","remote_port":"52714","client_ip":"172.18.0.1","proto":"HTTP/2.0","method":"GET","host":"domain2.localhost:2053","uri":"/","headers":{"User-Agent":["curl/7.61.1"],"Accept":["*/*"]},"tls":{"resumed":false,"version":772,"cipher_suite":4865,"proto":"h2","server_name":"domain2.localhost"}},"bytes_read":0,"user_id":"","duration":0.000129289,"size":25,"status":200,"resp_headers":{"Server":["Caddy"],"Alt-Svc":["h3=\":443\"; ma=2592000"],"Content-Type":["text/plain; charset=utf-8"]}}
{"level":"info","ts":1713546054.7794793,"logger":"http.log.access","msg":"handled request","request":{"remote_ip":"172.18.0.1","remote_port":"44428","client_ip":"172.18.0.1","proto":"HTTP/2.0","method":"GET","host":"domain1.localhost:2053","uri":"/","headers":{"User-Agent":["curl/7.61.1"],"Accept":["*/*"]},"tls":{"resumed":false,"version":772,"cipher_suite":4865,"proto":"h2","server_name":"domain1.localhost"}},"bytes_read":0,"user_id":"","duration":0.000028357,"size":25,"status":200,"resp_headers":{"Server":["Caddy"],"Alt-Svc":["h3=\":443\"; ma=2592000"],"Content-Type":["text/plain; charset=utf-8"]}}

I assumed that only domain2.localhost:2053 should be logged.

@Winand
Copy link
Author

Winand commented Apr 19, 2024

Update.
✅If I change port to standard - "443:443" in docker compose logging works as expected.
❌If I set https_port 2053 in Caddyfile and - "2053:2053" in docker compose the problem persists

@francislavoie
Copy link
Member

francislavoie commented Apr 19, 2024

Ah right so the problem is with the port being included in the Host. I thought I also fixed that in my PR. I'll take another look. You're sure you used my branch for this last test? (You can run caddy version to make sure)

@Winand
Copy link
Author

Winand commented Apr 19, 2024

You're sure you used my branch for this last test? (You can run caddy version to make sure)

[~]$ docker exec caddy caddy version
v2.7.6-0.20240419023528-732653fcf0ab h1:cIIuO6xno7uoRS23Bh+ptm3zf2N5UChz0ukcYBD3Dl0=

Built using this Dockerfile with command docker buildx build --build-arg="CADDY_VERSION=fix-default-logger" .

@francislavoie
Copy link
Member

francislavoie commented Apr 21, 2024

Okay, I figured it out, I missed a spot when dropping the port when checking logger config. Updated #6251, you can try building from commit ae03e14 (same branch, but Go tooling sometimes doesn't refresh the build if you use the same branch name so you can just use the commit hash instead)

@Winand
Copy link
Author

Winand commented Apr 21, 2024

I run xcaddy in Dockerfile build stage, so each time it's a fresh build for Go tooling.

✅The problem is resolved in version v2.7.6-0.20240421110859-6ef4c4dfcd0f

@mholt mholt added this to the v2.8.0 milestone Apr 22, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug 🐞 Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants