More Help with Error Logs?

1. The problem I’m having:

I hate to bother (again) - I feel like I’ve been annoying everyone with questions about logs, and I just can’t seem to get it right.

I’m just trying to get the stream of error logs out - on other platforms, this is done by assigning destinations for access_log and error_log. (Configuring Logging | NGINX Documentation)

I tried following this (http.errors - Caddy User Guide) but “errors” is no longer supported.

Right now I’m getting 400 errors in my access log, but I don’t (seem) to have the raw request, and can’t seem to figure it out.

Here is my caddy file:

{
    "apps": {
        "http": {
            "servers": {
                "spartacus_server": {
                    "listen": [
                        ":443",
                        ":80"
                    ],
                    "routes": [
                        {
                            "handle": [
                                {
                                    "handler": "spartacus"
                                }
                            ],
                            "terminal": true
                        },
                        {
                            "match": [
                                {
                                    "host": [
                                        "i.mydomain.org",
                                        "localhost",
                                        "127.0.0.1"
                                    ]
                                }
                            ]
                        }
                    ],
                    "logs": {
                        "logger_names": {
                            "localhost": [
                                "spartacusAccessLogger",
                                "spartacusErrorLogger"
                            ],
                            "127.0.0.1": [
                                "spartacusAccessLogger",
                                "spartacusErrorLogger"
                            ],
                            "i.mydomain.org": [
                                "spartacusAccessLogger",
                                "spartacusErrorLogger"
                            ]
                        }
                    },
                    "errors": {
                        "routes": [
                            {
                                "match": [
                                    {
                                        "host": [
                                            "i.mydomain.org",
                                            "localhost",
                                            "127.0.0.1"
                                        ]
                                    }
                                ],
                                "handle": [
                                    {
                                        "handler": "subroute",
                                        "routes": [
                                            {
                                                "handle": [
                                                    {
                                                        "handler": "subroute",
                                                        "routes": [
                                                            {
                                                                "handle": [
                                                                    {
                                                                        "body": "OK.",
                                                                        "handler": "static_response"
                                                                    }
                                                                ]
                                                            }
                                                        ]
                                                    }
                                                ]
                                            }
                                        ]
                                    }
                                ],
                                "terminal": true
                            }
                        ]
                    }
                }
            }
        }
    },
    "logging": {
        "logs": {
            "default": {
                "exclude": [
                    "http.log.access.spartacusAccessLogger",
                    "http.log.error.spartacusErrorLogger"
                ]
            },
            "spartacusAccessLogger": {
                "include": [
                    "http.log.access.spartacusAccessLogger"
                ],
                "level": "DEBUG",
                "writer": {
                    "filename": "/var/log/spartacus/access.json",
                    "output": "file"
                },
                "encoder": {
                    "format": "json"
                }
            },
            "spartacusErrorLogger": {
                "include": [
                    "http.log.error.spartacusErrorLogger"
                ],
                "level": "DEBUG",
                "writer": {
                    "filename": "/var/log/spartacus/error.json",
                    "output": "file"
                },
                "encoder": {
                    "format": "json"
                }
            }
        }
    },
    "storage": {
        "module": "file_system",
        "root": "caddy_data"
    }
}

Sorry this feels like I just can’t get it right!

Yeah that’s for Caddy v1, completely irrelevant. Caddy v2 was a rewrite.

What do you mean by “raw request”?

Remember that in Caddy, there’s a difference between access logs and runtime logs (i.e. logs that aren’t access logs, anything else).

There’s no such thing as http.log.error.* logs, we don’t produce those.

Your access logs (i.e. http.log.access.*) will have the request (including headers, but not the body) and the response (also headers, but not the body) and the status, duration, etc.

I’m not clear on what you think is missing from your logs. Your question is incomplete. You didn’t completely fill out the help topic template, so we’re missing context here.

1 Like

My apologies - i didn’t use the template because i didn’t think my question was a bug.

OK - i threw together a very simple repo to demonstrate what I’d like to do. GitHub - aronchick/Docker-NGINX-Gunicorn-Flask-Python-Example

Basically, in there, we have four sets of logs - Docker-NGINX-Gunicorn-Flask-Python-Example/logs at main · aronchick/Docker-NGINX-Gunicorn-Flask-Python-Example · GitHub

nginx access logs in common log format:

192.168.65.1 - - [16/May/2024:19:06:38 +0000] "GET /good HTTP/1.1" 200 34 "-" "curl/8.4.0"
192.168.65.1 - - [16/May/2024:19:06:38 +0000] "GET /bad HTTP/1.1" 500 72 "-" "curl/8.4.0"
192.168.65.1 - - [16/May/2024:19:06:38 +0000] "GET /error-bug HTTP/1.1" 500 49 "-" "curl/8.4.0"
192.168.65.1 - - [16/May/2024:19:06:38 +0000] "GET /error-memory HTTP/1.1" 502 157 "-" "curl/8.4.0"
192.168.65.1 - - [16/May/2024:20:47:54 +0000] "GET /good HTTP/1.1" 502 157 "-" "curl/8.4.0"
192.168.65.1 - - [16/May/2024:20:47:54 +0000] "GET /bad HTTP/1.1" 502 157 "-" "curl/8.4.0"

nginx error logs:

2024/05/16 19:06:38 [debug] 9#9: *7 chain writer out: 0000000000000000
2024/05/16 19:06:38 [debug] 9#9: *7 event timer del: 10: 346354487
2024/05/16 19:06:38 [debug] 9#9: *7 event timer add: 10: 60000:346354494
2024/05/16 19:06:38 [debug] 9#9: *7 http upstream request: "/error-memory?"
2024/05/16 19:06:38 [debug] 9#9: *7 http upstream process header
2024/05/16 19:06:38 [debug] 9#9: *7 malloc: 0000AAAAC68E8D40:4096
2024/05/16 19:06:38 [debug] 9#9: *7 recv: eof:1, avail:-1
2024/05/16 19:06:38 [debug] 9#9: *7 recv: fd:10 0 of 4096
2024/05/16 19:06:38 [error] 9#9: *7 upstream prematurely closed connection while reading response header from upstream, client: 192.168.65.1, server: localhost, request: "GET /error-memory HTTP/1.1", upstream: "http://127.0.0.1:5000/error-memory", host: "localhost:9999"
2024/05/16 19:06:38 [debug] 9#9: *7 http next upstream, 2
2024/05/16 19:06:38 [debug] 9#9: *7 free rr peer 1 4
2024/05/16 19:06:38 [debug] 9#9: *7 finalize http upstream request: 502

gunicorn access logs:

127.0.0.1 - - [16/May/2024:19:06:38 +0000] "GET /good HTTP/1.0" 200 34 "-" "curl/8.4.0"
127.0.0.1 - - [16/May/2024:19:06:38 +0000] "GET /bad HTTP/1.0" 500 72 "-" "curl/8.4.0"
127.0.0.1 - - [16/May/2024:19:06:38 +0000] "GET /error-bug HTTP/1.0" 500 49 "-" "curl/8.4.0"

gunicorn error logs (containing python or gunicorn stack traces/errors):

2024-05-16 20:51:50 +0000] [11] [DEBUG] GET /good
[2024-05-16 20:51:50 +0000] [11] [DEBUG] GET /bad
[2024-05-16 20:51:50 +0000] [11] [DEBUG] GET /error-bug
[2024-05-16 20:51:50 +0000] [11] [DEBUG] GET /error-memory
[2024-05-16 20:51:50 +0000] [7] [ERROR] Worker (pid:11) was sent SIGKILL! Perhaps out of memory?
[2024-05-16 20:51:50 +0000] [14] [INFO] Booting worker with pid: 14
[2024-05-16 20:52:42 +0000] [7] [DEBUG] Current configuration:

My mental model for thinking about Caddy with a custom module is:

nginx access logs -> Caddy http.access.logs
nginx error logs -> ?? (these go into access?)
gunicorn access logs -> Caddy http.access.logs (my go module is running in the Caddy process, so this makes sense)
gunicorn/flask error logs -> ??

It’s mostly the last one i’d love to figure out - where do i stick my module error logs - putting them directly into my ‘access’ logs feels wrong - but maybe that’s how caddy works?

Correct (though obviously Caddy emits structured logs, not “common log” format, but you could configure it to do so with the GitHub - caddyserver/transform-encoder: Log encoder module for custom log formats plugin if you want)

No, those look like error logs coming from specific HTTP handlers. Those would be using logger like http.handlers.reverse_proxy for the reverse_proxy handler, possibly at DEBUG or INFO or ERROR level.

I’m not sure how this relates. How are you serving your Python app from Caddy?

So i just threw that together with Python because i was trying to build something out that was familiar to me (more familiar than building in a module in go).

What I’m looking for is basically:

  • Information about the server itself (errors, is it running, etc)
  • Information about the module (any logger.Info type messages)
  • Something that gives me as much as i had with the Common Log Format (or more!)
  • Errors that might have occurred in the module - e.g. nil pointer, bad parsing, etc.

I was just trying to map that to how I would have gotten this previously with nginx and flask.

Just make a logger that writes somewhere with no include or exclude (meaning include everything), at DEBUG level, and see what you get. That’s everything Caddy emits. (And at least "logs": {} inside your server to enable access logs)

1 Like

what a great idea - thanks!

1 Like