Seemingly Basic Acces Logging Only Going to STDOUT?

Help
1

1. The problem I’m having:

I’d like to write my logs to a file.

2. Error messages and/or full log output:

No errors, it’s just that the access log keeps going to stdout instead of to the file.

3. Caddy version:

4. How I installed and ran Caddy:

Nothing special - just installed the go library, then ran xcaddy to build it.

a. System environment:

Nothing relevant - latest MacOS

b. Command:

xcaddy run --config caddyfile-logging.json

c. Service/unit/compose file:

N/A

d. My complete Caddy config:

{
    "logging": {
        "logs": {
            "access-formatted": {
                "writer": {
                    "filename": "/tmp/access-foo.log",
                    "output": "file"
                },
                "include": [
                    "http.log.access.foo"
                ]
            },
            "access-json": {
                "writer": {
                    "filename": "/tmp/access-foo.json",
                    "output": "file"
                },
                "encoder": {
                    "format": "json"
                },
                "include": [
                    "http.log.access.foo"
                ]
            },
            "default": {
                "exclude": [
                    "http.log.access.foo"
                ]
            }
        }
    },
    "apps": {
        "http": {
            "servers": {
                "srv0": {
                    "listen": [
                        ":443"
                    ],
                    "routes": [
                        {
                            "match": [
                                {
                                    "host": [
                                        "foo.example.com",
                                        "localhost"
                                    ]
                                }
                            ],
                            "terminal": true
                        }
                    ],
                    "logs": {
                        "logger_names": {
                            "foo.example.com": "foo",
                            "localhost": "bar"
                        }
                    }
                }
            }
        }
    }
}

5. Links to relevant resources:

2

Can you show evidence of the problem? Show how you’re testing this.

What version of Caddy are you using, exactly.

1 Like
3 
$ xcaddy version
v0.4.0 h1:V4n6nNlkRPmrgE+npteBjS7hgMfw24UEmiIONDpIWSo=
$ xcaddy run --config=caddyfile-logging.json

2024/05/12 15:55:58.146	INFO	http.log	server running	{"name": "srv0", "protocols": ["h1", "h2", "h3"]}
2024/05/12 15:55:58.146	INFO	http.log	server running	{"name": "remaining_auto_https_redirects", "protocols": ["h1", "h2", "h3"]}
2024/05/12 15:55:58.146	INFO	http	enabling automatic TLS certificate management	{"domains": ["localhost"]}
2024/05/12 15:55:58.147	WARN	tls	stapling OCSP	{"error": "no OCSP stapling for [localhost]: no OCSP server specified in certificate", "identifiers": ["localhost"]}
2024/05/12 15:55:58.151	INFO	autosaved config (load with --resume flag)	{"file": "/Users/daaronch/Library/Application Support/Caddy/autosave.json"}
2024/05/12 15:55:58.151	INFO	serving initial configuration
2024/05/12 15:55:58.169	WARN	tls	storage cleaning happened too recently; skipping for now	{"storage": "FileStorage:/Users/daaronch/Library/Application Support/Caddy", "instance": "9cfc62d9-28c4-469a-bdd5-97fb30adf0e9", "try_again": "2024/05/13 15:55:58.169", "try_again_in": 86399.999999708}
2024/05/12 15:55:58.169	INFO	tls	finished cleaning storage units

[Now waits for requests]

Second window:

$ curl localhost
$ # Finished correctly

First window (STDOUT - not to the file):

2024/05/12 15:56:42.988	INFO	http.log.access.bar	handled request	{"request": {"remote_ip": "::1", "remote_port": "64853", "client_ip": "::1", "proto": "HTTP/1.1", "method": "GET", "host": "localhost", "uri": "/", "headers": {"Accept": ["*/*"], "User-Agent": ["curl/8.4.0"]}}, "bytes_read": 0, "user_id": "", "duration": 0.000030167, "size": 0, "status": 308, "resp_headers": {"Content-Type": [], "Server": ["Caddy"], "Connection": ["close"], "Location": ["https://localhost/"]}}

List of /tmp (no log files listed):

> ls -la /tmp/access*
>
4

That’s the xcaddy version, not the caddy version. But I guess since you’re not specifying a Caddy version to xcaddy run you’re probably getting v2.7.6.

You didn’t include/exclude this logger in any of your configured loggers (you only have foo, but not bar). Is that an oversight? This means that it’ll end up in the default only because you’re not excluding it, and not including it in the other two which write to files.

What if you try to create the log file by hand first? Do you see the logs there?

The library we use for log rolling isn’t perfect, it might have trouble making the file itself.

Also keep in mind that /tmp is virtualized when running as a systemd service, so it actually ends up in /tmp/systemd-private-<somehash>-caddy.service-<someID>/tmp instead. But that’s probably not the case for you here cause you’re running Caddy directly from CLI.

2 Likes
5

oh, this is interesting as well - can you only write to one log at a time? that’s helpful!

6

i THINK both of these had the same root cause - here’s what I discovered:

7

No, you can definitely write to more than one file. I’m not certain why the file wasn’t being created though. But did you try creating it by hand (i.e. touch command)?

8

just tried touching the file first with the below - no joy.

{
    "logging": {
        "logs": {
            "default": {
                "exclude": [
                    "http.log.access.filelog"
                ]
            },
            "filelog": {
                "writer": {
                    "filename": "access-foo.json",
                    "output": "file"
                },
                "include": [
                    "http.log.access.filelog"
                ]
            }
        }
    },
    "apps": {
        "http": {
            "servers": {
                "spartacus_server": {
                    "listen": [
                        ":443"
                    ],
                    "routes": [
                        {
                            "handle": [
                                {
                                    "body": "Hello",
                                    "handler": "static_response"
                                }
                            ]
                        },
                        {
                            "match": [
                                {
                                    "host": [
                                        "localhost"
                                    ]
                                }
                            ]
                        }
                    ],
                    "logs": {
                        "logger_names": {
                            "spartacus_server": "filelog"
                        }
                    }
                }
            }
        }
    }
}
9

I think it’s because you are sending localhost access logs to a logger named “bar” but you don’t have a logger named “bar” – just “access-formatted” and “access-json” and, of course, “default”.

It’s been a long time since I’ve looked at this code but I think that’s the issue?

2 Likes
10

That was an old one - i misunderstood what that field was for (i thought it was a prefix in your log)

11

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