logging: Experimental except option for delete filter

[francislavoie]

This is an awkward PR because it's a branch off my other branch in another PR, but I wanted to keep this separate. Please just look at the last commit (as of this writing - may be more commits if I revise it)

This is a first attempt at #3562, to delete everything in a certain zap field except things in a whitelist. FYI @danlsgiga

I don't love this because I'm using reflection, which pretty clearly seems like the wrong thing to do... but it seems to work. It's probably not that safe though.

Anyways the reason for reflection is because the underlying map could be any type, but we only really care that it is a map, such that we can delete any of the keys that aren't in the except list.

One thing I'm concerned about and and I'm not sure how this will work... if we make changes to the map when logging here, e.g. http.Header that is being logged, does that also modify the list of headers on the request currently handled? If so, this implementation is a total no-go, but I'm not sure how that works. Since zap is "zero allocation", I figure it's just a reference to those headers being passed around and not a copy.

Anyways, Caddyfile would look like this:

log {
    output stdout
    format filter {
        wrap console
        fields {
            request>headers delete {
                except Foo
            }
        }
    }
}

Making a request:

$ curl -H "Foo: Bar" localhost:8883

Log line:

1.5993709935395644e+09	info	http.log.access.log0	handled request	{"request": {"remote_addr": "127.0.0.1:58846", "proto": "HTTP/1.1", "method": "GET", "host": "localhost:8883", "uri": "/", "headers": {"Foo": ["Bar"]}}, "common_log": "127.0.0.1 - - [06/Sep/2020:01:43:13 -0400] \"GET / HTTP/1.1\" 0 0", "duration": 0.000002615, "size": 0, "status": 0, "resp_headers": {"Server": ["Caddy"]}}

Without this, the headers being logged would look like this (headers from curl):

"headers": {"User-Agent": ["curl/7.68.0"], "Accept": ["*/*"]}

[danlsgiga]

Thanks for working on this @francislavoie... I think this gives a lot of flexibility power to handle edge cases of headers log handling... specially of applications that use multiple headers containing sensitive information.

[mholt]

Honestly this is looking pretty good, and the reflection is only used if any exceptions are configured.

But I'm worried that it may be tricky to support the variety of possible types it could encounter. Maybe a map and struct/object are enough for 99% of them though.

[mholt]

What if it's a struct/object with fields instead of a map with keys?

[francislavoie]

I don't know. I didn't look that deeply to see how that would work. I was primarily concerned with the header usecase because that sounds like the most common usecase. Can you think of an example field where that would apply, that I could test for?

[mholt]

The request field (parent of header, I think) is a struct/object. Granted, they're not as dynamic since they're strongly typed, but I can see users might want to delete the whole object except for one property.

Honestly this is fine, we can do more based on feature requests if necessary.

Is this still a draft?

[francislavoie]

If you're happy with this, then cool.

I'm still a bit concerned about the part where we're straight up modifying the http.Request, seems "destructive". But if this is always the last thing in the middleware chain, then I guess it's fine? But 😬

Anyways - we should merge the other filter PR first, then I'll un-draft this and rebase, to keep those separate.

[mholt]

Okay... thanks for bringing that up again. Yeah, modifying the underlying map is going to be a problem. You can verify this with:

respond {header.User-Agent}

(Obviously in conjunction with filtered logs.) And I bet you will not see anything in the response, despite clients setting it.

[francislavoie]

Yeah, confirmed. respond {header.User-Agent} returns empty when except is used.

I don't know how we could do this otherwise...

[mholt]

The reason this isn't working is because it's a hack on the design. The proper way to do this is to have some other Caddy app module (or any other external log aggregator service) ingest the logs and filter them after being encoded. I don't know another way to do it.

[francislavoie]

I think I'll close this PR since the approach isn't good enough due to the modification of the request. I'll try and think of another approach.

[mholt]

Thanks Francis. Sorry it doesn't appear to be feasible like this. :( Appreciate your efforts though.

I really do hope someone writes a log ingestor app for Caddy one of these days.