Format Errors with Caddy JSON (client_ip vs remote_ip) about goaccess HOT 17 CLOSED

Hey @juergenhoetzel, thanks for bringing that up. So, just to make sure I understand correctly, prior to version 2.7.0, Caddy didn't include the client_ip field in its logs, but starting from version 2.7.0, it does, right? Currently, this is the log format for Caddy in GoAccess here.

Yes, using this Caddyfile

:80 {
	root * /usr/share/caddy
	file_server
        log {
           format json 
           output stdout
        }
}

Caddy 2.6:

podman run -p 8080:80   -v $PWD/Caddyfile:/etc/caddy/Caddyfile  caddy:2.6

does not include client_ip:

{
  "level": "info",
  "ts": 1716925903.9613523,
  "logger": "http.log.access.log0",
  "msg": "handled request",
  "request": {
    "remote_ip": "127.0.0.1",
    "remote_port": "44684",
    "proto": "HTTP/1.1",
    "method": "GET",
    "host": "localhost:8080",
    "uri": "/",
    "headers": {
      "User-Agent": [
        "curl/8.8.0"
      ],
      "Accept": [
        "*/*"
      ]
    }
  },
  "user_id": "",
  "duration": 0.002602448,
  "size": 18677,
  "status": 200,
  "resp_headers": {
    "Last-Modified": [
      "Thu, 15 Jun 2023 05:29:47 GMT"
    ],
    "Accept-Ranges": [
      "bytes"
    ],
    "Content-Length": [
      "18677"
    ],
    "Server": [
      "Caddy"
    ],
    "Etag": [
      "\"rwa4lneet\""
    ],
    "Content-Type": [
      "text/html; charset=utf-8"
    ]
  }
}

}

whereas Caddy 2.7:

podman run -p 8080:80   -v $PWD/Caddyfile:/etc/caddy/Caddyfile  caddy:2.7

includes the client_ip:

{
  "level": "info",
  "ts": 1716925995.7047846,
  "logger": "http.log.access.log0",
  "msg": "handled request",
  "request": {
    "remote_ip": "127.0.0.1",
    "remote_port": "33548",
    "client_ip": "127.0.0.1",
    "proto": "HTTP/1.1",
    "method": "GET",
    "host": "localhost:8080",
    "uri": "/",
    "headers": {
      "User-Agent": [
        "curl/8.8.0"
      ],
      "Accept": [
        "*/*"
      ]
    }
  },
  "bytes_read": 0,
  "user_id": "",
  "duration": 0.003158078,
  "size": 18630,
  "status": 200,
  "resp_headers": {
    "Content-Type": [
      "text/html; charset=utf-8"
    ],
    "Last-Modified": [
      "Thu, 02 May 2024 00:51:49 GMT"
    ],
    "Accept-Ranges": [
      "bytes"
    ],
    "Content-Length": [
      "18630"
    ],
    "Server": [
      "Caddy"
    ],
    "Etag": [
      "\"scu2ededi\""
    ]
  }
}

from goaccess.

Hi @juergenhoetzel , Are you intentionally combining caddy < 2.7 (Aug '23) with goaccess >= 1.9.2 (Apr '24) or did you come across this combination incidentally? Caddy's latest recommended release is v2.7.6 and you can review the deprecations for v2.7 here.

If you do have a use-case for this combination, you can make a quick edit to your goaccess.conf file, usually found in /etc/goaccess/goaccess.conf

time-format %s
date-format %s
...
# CADDY JSON Structured
-log-format {"ts":"%x.%^","request":{"client_ip":"%h","proto":"%H","method":"%m","host":"%v","uri":"%U","headers":{"User-Agent":["%u"],"Referer":["%R"]},"tls":{"cipher_suite":"%k","proto": "%K"}},"duration": "%T","size": "%b","status": "%s","resp_headers":{"Content-Type":["%M"]}}
+log-format {"ts":"%x.%^","request":{"remote_ip":"%h","proto":"%H","method":"%m","host":"%v","uri":"%U","headers":{"User-Agent":["%u"],"Referer":["%R"]},"tls":{"cipher_suite":"%k","proto": "%K"}},"duration": "%T","size": "%b","status": "%s","resp_headers":{"Content-Type":["%M"]}}

from goaccess.

Hi @juergenhoetzel , Are you intentionally combining caddy < 2.7 (Aug '23) with goaccess >= 1.9.2 (Apr '24) or did you come across this combination incidentally? Caddy's latest recommended release is v2.7.6 and you can review the deprecations for v2.7 here.

I have deliberately used version 2.7.0 here to show that it is the first version adding the client_ip field.

from goaccess.

I just updated as described on the Readme and the error still remains the same:

goaccess -V
GoAccess - 1.9.1.

from goaccess.

Thanks for giving me the heads up on this. Sounds like the default log format isn't quite right. Bummer that I missed it in today's v1.91 release. I'll make sure to include it in the next one. This probably ties into #2601. Anyway, are you able to submit a PR with the right format for this? The relevant lines are here and here. Thanks a bunch!

from goaccess.

I was setting up GoAccess for Caddy today and ran into this as well, but only when configuring Caddy's global log option and asking GoAccess to read it. If you setup only access logging on your domains it should work, and I think GoAccess's default Caddy configuration only expects these logs.

Example Caddyfile:

{ #Global Options
	log {
		# Don't configure your access log here...
	}
}
example.com {
	log {
		# Configure your access logs here.
		output file /var/log/caddy/access.log
	}
	# ...
}

If you have multiple domains, you can use snippets to make things easier.

Then read the log with goaccess:

sudo goaccess /var/log/caddy/access.log --log-format=CADDY

Tested with Caddy v2.7.6 and GoAccess 1.9.1. If the above still gives you any trouble, it might be helpful to include your Caddy version as well.

I don't think this is related to #2601 exactly, which is its own issue that originates with Caddy receiving first-class support for logging client IPs (such as from 'X-Forwared-For' headers) where the typical user might want to see the client_ip instead of remote_ip in the "Visitor Hostnames and IPs" table.

from goaccess.

Hey @Teqed, thanks for catching that and providing the details. I'm thinking, should we consider adding another predefined option for when it's configured globally, like maybe CADDY_GLOBAL? Thoughts?

from goaccess.

actually, looking at my response again, the global approach might be trickier since it doesn't appear to be a valid JSON string, as far as I can tell?

from goaccess.

I attached a censored example entry from a global debug level log.
The JSON seems pretty valid to me:

{
    "level": "debug",
    "ts": 1707272627.5637116,
    "logger": "http.handlers.reverse_proxy",
    "msg": "upstream roundtrip",
    "upstream": "xxxx:8080",
    "duration": 0.00726643,
    "request": {
        "remote_ip": "131.191.11.111",
        "remote_port": "51987",
        "client_ip": "131.191.11.111",
        "proto": "HTTP/2.0",
        "method": "GET",
        "host": "xxxxx.xx",
        "uri": "/config",
        "headers": {
            "Referer": [
                "https://xxxx.xxxxxxx.xx/"
            ],
            "Sec-Fetch-Dest": [
                "empty"
            ],
            "X-Forwarded-For": [
                "131.191.11.111"
            ],
            "Sec-Fetch-Site": [
                "same-origin"
            ],
            "Te": [
                "trailers"
            ],
            "Accept": [
                "application/json, text/plain, */*"
            ],
            "X-Forwarded-Host": [
                "xxxxx.xx"
            ],
            "Dnt": [
                "1"
            ],
            "X-Clientapp": [
                "web_client"
            ],
            "X-Forwarded-Proto": [
                "https"
            ],
            "Accept-Encoding": [
                "gzip, deflate, br"
            ],
            "Sec-Gpc": [
                "1"
            ],
            "Sec-Fetch-Mode": [
                "cors"
            ],
            "User-Agent": [
                "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:121.0) Gecko/20100101 Firefox/121.0"
            ],
            "Accept-Language": [
                "en-US,en;q=0.5"
            ]
        },
        "tls": {
            "resumed": false,
            "version": 772,
            "cipher_suite": 4865,
            "proto": "h2",
            "server_name": "xxxxx.xx"
        }
    },
    "headers": {
        "Date": [
            "Wed, 07 Feb 2024 02:23:47 GMT"
        ],
        "Content-Length": [
            "657"
        ],
        "Content-Type": [
            "text/plain; charset=utf-8"
        ]
    },
    "status": 200
}

from goaccess.

I attached a censored example entry from a local debug level log.
The JSON seems to have the same format as the previous one.
The local configuration works with goaccess. I just confirmed it.

{
    "level": "info",
    "ts": 1707273079.4037006,
    "logger": "http.log.access.log0",
    "msg": "handled request",
    "request": {
        "remote_ip": "11.111.1.111",
        "remote_port": "45873",
        "client_ip": "11.111.1.111",
        "proto": "HTTP/1.1",
        "method": "GET",
        "host": "xxxxx.xx",
        "uri": "xxxx/xxxxx/xxxxx",
        "headers": {
            "Connection": [
                "close"
            ],
            "User-Agent": [
                "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:103.0) Gecko/20100101 Firefox/103.0"
            ],
            "Accept": [
                "text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"
            ],
            "Accept-Language": [
                "en-us,en-gb,en;q=0.7,*;q=0.3"
            ],
            "Accept-Encoding": [
                "gzip"
            ]
        },
        "tls": {
            "resumed": false,
            "version": 772,
            "cipher_suite": 4865,
            "proto": "http/1.1",
            "server_name": "xxxxx.xx"
        }
    },
    "bytes_read": 0,
    "user_id": "",
    "duration": 0.002669453,
    "size": 3436,
    "status": 200,
    "resp_headers": {
        "Accept-Ranges": [
            "bytes"
        ],
        "Last-Modified": [
            "Fri, 07 Jul 2023 10:33:07 GMT"
        ],
        "Cache-Control": [
            "public, max-age=0"
        ],
        "Content-Length": [
            "3436"
        ],
        "Server": [
            "Caddy"
        ],
        "Alt-Svc": [
            "h3=\":443\"; ma=2592000"
        ],
        "Content-Type": [
            "text/html; charset=UTF-8"
        ],
        "Date": [
            "Wed, 07 Feb 2024 02:31:19 GMT"
        ],
        "Etag": [
            "W/\"d6c-1892fe9a07a\""
        ]
    }
}

from goaccess.

As seen in my example I kinda compare oranges and apples. One is a debug level event the other one an info level event.
My guesswork would be that there are some entries (especially in debug logging) which maybe disturbs the parser. But that the "regular" entries working fine. Tbh I have no clue what goaccess does in the background.

from goaccess.

@Robert-Ernst, I was looking at this and noticed some differences between fields like resp_headers vs headers. But it seems like it should work fine for both entries for the most part (see screenshot). The default GoAccess format for CADDY is indeed the 'local/info' format, as you mentioned. However, if necessary, you can customize the log format that GoAccess uses to align with your specific configuration. Making this adjustment is relatively simple.

Are you still encountering any issues in the latest version?

from goaccess.

It works for me in the local info format.
Not with the global one. But that is fine.
I would recommend adding this information to the documentation and this should be fine.
As Teqed suggested it's possible to create snippets and thus local configuration is easily customizable in Caddy.
After the documentation has been created, you can close this ticket.

from goaccess.

Appreciate the feedback. I've made the necessary updates to both the man page and the documentation on the website regarding the log-format configuration.

Closing this, feel free to reopen it if necessary.

from goaccess.

While it's on my mind, I wanted to mention that I think there may be a way to configure logs globally the way we're expecting by including only access log events:

# Globals
{
	log global_access {
		output file /var/log/caddy/access.log
		include http.log.access
	}
}

By using the include directive only available at the global log level, we're able to filter to only the log format we expect, and are able to log across all domains without individually configuring each. I haven't ran this for more than a few minutes to make sure it works at expected, but assuming it does, this is probably the solution most people will want.

It might also be useful for someone to consume Caddy's non-http.log.access events -- which often describe application status, SSL certificate negotiations, configuration reloads, etc. -- but making use of Caddy's complete log would be a different dashboard serving a different purpose.

from goaccess.

"client_ip" is missing when using caddy < 2.7.0. The issue was fixed in the 2.7.0 release:

caddyserver/caddy@05e9974

I was able to reproduce this using my own logs:

$ grep \"client_ip\" access.log |head -n 1|jq .ts
1696963002.4146495
$ date -d @1696963002
Tue Oct 10 08:36:42 PM CEST 2023
$ grep caddy /var/log/pacman.log 
...
[2023-10-10T20:33:53+0200] [ALPM] upgraded caddy (2.6.4-1 -> 2.7.4-1)
...

from goaccess.

Hey @juergenhoetzel, thanks for bringing that up. So, just to make sure I understand correctly, prior to version 2.7.0, Caddy didn't include the client_ip field in its logs, but starting from version 2.7.0, it does, right? Currently, this is the log format for Caddy in GoAccess here. I wonder if we should have two different log formats to accommodate the change... Thoughts?

from goaccess.