Why do I get INFO logs when the configuration says ERROR?

Help
1

1. Caddy version (caddy version):

v2.4.6 h1:HGkGICFGvyrodcqOOclHKfvJC0qTU7vny/7FhYp9hNw=

2. How I run Caddy:

Official docker container, :latest tag automatically updated.

c. Service/unit/compose file:

  caddy:
    image: caddy
    container_name: caddy
    volumes:
      - /etc/docker/data/caddy/Caddyfile:/etc/caddy/Caddyfile
      - /etc/docker/data/caddy/data:/data
      - /etc/docker/data/caddy/config:/config
    ports:
      - 80:80
      - 443:443
      - 2015:2015
    environment:
      - ACME_AGREE=true
    restart: unless-stopped

d. My complete Caddyfile or JSON config:

{
	admin 0.0.0.0:2015
	email me@my.email
	# acme_ca https://acme-staging-v02.api.letsencrypt.org/directory
}

(netMatchers) {
	@internet {
		not remote_ip 192.168.10.0/24 192.168.20.0/24 172.19.0.0/16 127.0.0.0/8
	}
	@local {
		remote_ip 192.168.10.0/24 192.168.20.0/24 172.19.0.0/16 127.0.0.0/8
	}
}

# LAN connection, unavailable from outside

(lanCore) {
	log {
	    level ERROR
		format single_field common_log
	} 
	@internet {
		not remote_ip 192.168.10.0/24 192.168.20.0/24 172.19.0.0/16
	}
	@local {
		remote_ip 192.168.10.0/24 192.168.20.0/24 172.19.0.0/16
	}
	respond @internet 200
}

(lan) {
	import lanCore
	reverse_proxy @local {args.0}
}

(lan-skip-insecure) {
	import lanCore
	reverse_proxy @local {args.0} {
		transport http {
			tls
			tls_insecure_skip_verify
		}
	}
}

# internet connection

(internet) {
	log {
	    level ERROR
	}
	reverse_proxy {args.0}
}

# hosts

https://deluge.erazt.eu {
	import lan deluge:8112
}

3. The problem I’m having:

The configuration above sets the logging level to ERROR. Despite that I get logs such as the one below. Please note that "level": "info"

{
  "level": "info",
  "ts": 1640245717.5262256,
  "logger": "http.log.access",
  "msg": "handled request",
  "request": {
    "remote_addr": "172.19.0.1:46784",
    "proto": "HTTP/1.1",
    "method": "POST",
    "host": "deluge.erazt.eu",
    "uri": "/json",
    "headers": {
      "Cookie": [
        "_session_id=4d350b8ea7a2774a01dd64f46286b5e16834c0f13653cf1f542720a1669c85ee4290"
      ],
      "Content-Length": [
        "62"
      ],
      "User-Agent": [
        "GuzzleHttp/6.3.3 curl/7.79.1 PHP/7.3.33"
      ],
      "Content-Type": [
        "application/json"
      ],
      "Accept": [
        "application/json"
      ]
    }
  },
  "common_log": "172.19.0.1 - - [23/Dec/2021:07:48:37 +0000] \"POST /json HTTP/1.1\" 308 0",
  "user_id": "",
  "duration": 0.000039991,
  "size": 0,
  "status": 308,
  "resp_headers": {
    "Content-Type": [],
    "Server": [
      "Caddy"
    ],
    "Connection": [
      "close"
    ],
    "Location": [
      "https://deluge.erazt.eu/json"
    ]
  }
}
2

Caddy v2 doesn’t use this environnement variable anymore. You can remove it.

common_log is deprecated, and will be removed in v2.5.0. Best if you don’t rely on it. You may use this plugin as a replacement:

I’m not sure why setting the log level to error wouldn’t work though. I’m just on my phone right now so I can’t do much to investigate deeper, but if you adapt your config to JSON, you might be able to spot the issue in the logging config.

1 Like
3

Caddy v2 doesn’t use this environment variable anymore. You can remove it.

Ah yes, it was a leftover from my v1 configuration. Thanks.

common_log is deprecated

I removed that after posting my question - I saw in the logs that it is going away. Thanks :slight_smile:

I’m not sure why setting the log level to error wouldn’t work though. I’m just on my phone right now so I can’t do much to investigate deeper, but if you adapt your config to JSON, you might be able to spot the issue in the logging config.

Reading your comment, I had a look at what the API says.

{
  "admin": {
    "listen": "0.0.0.0:2015"
  },
  "apps": {
    "http": {
      "servers": {
        "srv0": {
          "listen": [
            ":443"
          ],
          "logs": {
            "logger_names": {
              "adminer.erzatz.eu": "log31",
              "appdaemon.erzatz.eu": "log10",

(... all my hosts ...)

 "logging": {
    "logs": {
      "default": {
        "exclude": [
          "http.log.access.log13",
          "http.log.access.log26",
          "http.log.access.log7",
(... all the hosts ...)
          "http.log.access.log12",
          "http.log.access.log9"
        ]
      },
      "log0": {
        "include": [
          "http.log.access.log0"
        ],
        "level": "ERROR"
      },
      "log1": {
        "include": [
          "http.log.access.log1"
        ],
        "level": "ERROR"
      },
      "log10": {
        "include": [
          "http.log.access.log10"
        ],
        "level": "ERROR"

(... all the hosts ...)

So it looks like ERROR is correctly applied to all loggers. I am not sure, though, what the "exclude" section is for. It is as long as the list of my hosts (I checked for instance for log31 and it is in all three sections - and logs to INFO instead of ERROR)

1 Like
4

You’re sure you’ve reloaded since you added level ERROR?

Are you sure that log line came from after having made the change, and not before?

Just as a sanity check.

1 Like
5

Yes, this log setting had been there forever, I actually realized something is wrong when looking more closely at caddy logs (because caddy just works :))

EDIT: the text above was written a few days ago and I forgot to actually post it.
In the meantime I heavily butchered (= Christmas cleanup) my docker configuration to get rid of old containers etc, and after that - miracle - the log level is correct.

So it was a mysterious problem on my side.

1 Like
6

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