feat: support writing audit events to stdout for log #3113

markphelps · 2024-05-26T20:56:40Z

Allows writing audit logs to stdout if using log sink with no file specified

It looks like this when enabled along side existing logs to stdout:

2024-05-26T16:43:10-04:00	INFO	finished unary call with code OK	{"server": "grpc", "grpc.start_time": "2024-05-26T16:43:10-04:00", "system": "grpc", "span.kind": "server", "grpc.service": "flipt.Flipt", "grpc.method": "UpdateFlag", "peer.address": "127.0.0.1:51395", "grpc.code": "OK", "grpc.time_ms": 8.519}
{"version":"0.1","type":"flag","action":"updated","metadata":{"actor":{"authentication":"none","ip":"127.0.0.1"}},"payload":{"description":"Manages the rollout of updates to our IoT devices","enabled":false,"key":"iot-deviceUpdateControl","name":"iot-deviceUpdateControl","namespace_key":"default"},"timestamp":"2024-05-26T16:43:10-04:00"}
2024-05-26T16:43:10-04:00	INFO	finished unary call with code OK	{"server": "grpc", "grpc.start_time": "2024-05-26T16:43:10-04:00", "system": "grpc", "span.kind": "server", "grpc.service": "flipt.Flipt", "grpc.method": "GetFlag", "peer.address": "127.0.0.1:51395", "grpc.code": "OK", "grpc.time_ms": 0.857}

Im not 💯 on if this is the functionality we want though as its hard to parse visually with both types of logs (audit and application) intertwined like this.

I guess one argument could be that if you're setting audit logs to stdout then you'd likely either:

send application logs to a file or
set the application log level to something high like ERROR so that they arent as chatty and would make audit logs easier to spot/parse

Another thing we could support is allowing the user to configure which file handle to write both application logs and audit logs to (either STDOUT or STDERR), so they could separate the logs that way if they didn't want to / couldn't write to a file for either?

wdyt @erka @GeorgeMac ?

Signed-off-by: Mark Phelps <[email protected]>

GeorgeMac

Where did we end up on the stance of using the existing zap logger instead?

As in, instead of using a JSON encoder over STDOUT, just adapt audit events into fields on the zap logger and add a distinguising field like type == audit so that a log aggregator can then distinguish these?

Was it just the leveling debate? I vaguely remember we thought about just having distinct level for the audit events.

Also, looking at zap's encoder config:
https://pkg.go.dev/go.uber.org/[email protected]/zapcore#EncoderConfig

It seems like you can set the levelKey to empty string to omit it from output.
Or it looks like there might be a way (via a LevelEncoder perhaps?) to get our own level = audit in there somehow.

erka · 2024-05-27T12:59:30Z

We have not forgotten that logging could have encoding set to json which will provide a bit different output

{"L":"DEBUG","T":"2024-05-27T15:44:49+03:00","M":"using driver","server":"grpc","driver":"sqlite3"}
{"L":"DEBUG","T":"2024-05-27T15:44:49+03:00","M":"migrations up to date","server":"grpc"}
{"L":"DEBUG","T":"2024-05-27T15:44:49+03:00","M":"constructing builder","server":"grpc","prepared_statements":true}
{"L":"DEBUG","T":"2024-05-27T15:44:49+03:00","M":"database driver configured","server":"grpc","driver":"sqlite3"}

I really like @GeorgeMac idea to reuse zap somehow and have level set to AUDIT.

markphelps · 2024-05-27T22:32:21Z

Where did we end up on the stance of using the existing zap logger instead?

As in, instead of using a JSON encoder over STDOUT, just adapt audit events into fields on the zap logger and add a distinguising field like type == audit so that a log aggregator can then distinguish these?

Was it just the leveling debate? I vaguely remember we thought about just having distinct level for the audit events.

Also, looking at zap's encoder config: https://pkg.go.dev/go.uber.org/[email protected]/zapcore#EncoderConfig

It seems like you can set the levelKey to empty string to omit it from output. Or it looks like there might be a way (via a LevelEncoder perhaps?) to get our own level = audit in there somehow.

if we reuse the existing zap logger then we still have the issue of which zap level audit events are logged at.

Do you mean we use a new instance of zap logger that is always say set to log at the lowest level and then we simply exclue that levelKey in the output so that its empty?

I did some more research and it looks like its still not really possible for us to define our own log levels (at least not in a supported way), see: uber-go/zap#1277 (comment)

GeorgeMac · 2024-05-28T11:03:28Z

Do you mean we use a new instance of zap logger that is always say set to log at the lowest level and then we simply exclue that levelKey in the output so that its empty?

I think this is an option, but speaking without trying it myself.

I think the main thing though is that whatever the approach is, a nice experience would be for the log output to match the encoding of the existing logger. So if its console, then audit logs come out in console too, if its JSON, they all come out in JSON. And that there is a way to distinguish, through structure logging, an audit event from a standard log line.

Signed-off-by: Mark Phelps <[email protected]>

markphelps · 2024-06-05T14:39:28Z

I've now tried switching to use a new zap logger for this functionality, seems promising:

{"T":"2024-06-05T10:37:59-04:00","M":"audit","event":{"version":"0.1","type":"flag","action":"updated","metadata":{"actor":{"authentication":"none","ip":"127.0.0.1"}},"payload":{"description":"Testing newest framework of the week","enabled":true,"key":"beta-new-ui-framework","name":"beta-new-ui-framework","namespace_key":"default"},"timestamp":"2024-06-05T10:37:59-04:00"}}

markphelps · 2024-06-05T14:52:57Z

I've now tried switching to use a new zap logger for this functionality, seems promising:

{"T":"2024-06-05T10:37:59-04:00","M":"audit","event":{"version":"0.1","type":"flag","action":"updated","metadata":{"actor":{"authentication":"none","ip":"127.0.0.1"}},"payload":{"description":"Testing newest framework of the week","enabled":true,"key":"beta-new-ui-framework","name":"beta-new-ui-framework","namespace_key":"default"},"timestamp":"2024-06-05T10:37:59-04:00"}}

The only problem is that when written to a file, it breaks backward compatibility with our previous audit log format, which simply marshalls the event like:

{"version":"0.1","type":"flag","action":"updated","metadata":{"actor":{"authentication":"none","ip":"127.0.0.1 "}},"payload":{"description":"Manages the rollout of updates to our IoT devices","enabled":true,"key":"iot-deviceUpdateControl","name":"iot-deviceUpdateControl","namespace_key":"default"},"timestamp":"2024-06-05T10:51:24-04:00"}

markphelps · 2024-06-05T15:27:13Z

I got it a bit closer when using file based logging:

{
  "event": {
    "version": "0.1",
    "type": "flag",
    "action": "updated",
    "metadata": {
      "actor": {
        "authentication": "none",
        "ip": "127.0.0.1"
      }
    },
    "payload": {
      "description": "Testing newest framework of the week",
      "enabled": false,
      "key": "beta-new-ui-framework",
      "name": "beta-new-ui-framework",
      "namespace_key": "default"
    },
    "timestamp": "2024-06-05T11:25:27-04:00"
  }
}

I think this is good enough IMO

markphelps · 2024-06-05T15:44:42Z

Here's what the console log looks like:

2024-06-05T11:37:56-04:00	AUDIT	{"event": {"version":"0.1","type":"flag","action":"updated","metadata":{"actor":{"authentication":"none","ip":"127.0.0.1"}},"payload":{"description":"Manages the rollout of updates to our IoT devices","enabled":false,"key":"iot-deviceUpdateControl","name":"iot-deviceUpdateControl","namespace_key":"default"},"timestamp":"2024-06-05T11:37:56-04:00"}}

…into audit-logs-stdout * 'audit-logs-stdout' of https://github.com/flipt-io/flipt: docs: add levlaz as a contributor for doc (#3148)

markphelps · 2024-06-05T17:26:09Z

ok, I think this is ready for another round of comments, im going to be adding tests as well

/cc @erka @GeorgeMac

Signed-off-by: Mark Phelps <[email protected]>

markphelps · 2024-06-05T19:22:37Z

config/flipt.schema.json

+                },
+                "encoding": {
+                  "type": "string",
+                  "enum": ["json", "console", ""]


the "" is required so that by default it inherits the same encoding as log.encoding, although i guess we could make an explicit inherit option?

Signed-off-by: Mark Phelps <[email protected]>

internal/server/audit/log/log.go

Signed-off-by: Mark Phelps <[email protected]>

GeorgeMac

🤙 Nice

erka · 2024-06-06T13:48:16Z

@markphelps this will be a breaking change for people
My audit configuration

audit:
  sinks:
    log:
      enabled: true
      file: audit.log

Audit log for v1.40.2 sends

{"version":"0.1","type":"flag","action":"created","metadata":{"actor":{"authentication":"none"}},"payload":{"description":"","enabled":false,"key":"adf","name":"adf","namespace_key":"default"},"timestamp":"2024-06-06T16:41:21+03:00"}

And this PR will send

{"event": {"version":"0.1","type":"flag","action":"updated","metadata":{"actor":{"authentication":"none","ip":"::1"}},"payload":{"description":"","enabled":false,"key":"adf","name":"adfasdf","namespace_key":"default"},"timestamp":"2024-06-06T16:42:28+03:00"}}

markphelps added 2 commits May 26, 2024 16:48

feat: support writing audit events to stdout for log

47c3608

Signed-off-by: Mark Phelps <[email protected]>

chore: simplify audit log default stdout logic

a4f41e1

Signed-off-by: Mark Phelps <[email protected]>

markphelps requested a review from a team as a code owner May 26, 2024 20:56

markphelps marked this pull request as draft May 26, 2024 20:58

markphelps added the needs docs Requires documentation updates label May 26, 2024

GeorgeMac reviewed May 27, 2024

View reviewed changes

Merge branch 'main' into audit-logs-stdout

9ee4f0b

markphelps added 2 commits June 4, 2024 17:07

feat: support writing audit events to stdout for log

fed391e

Signed-off-by: Mark Phelps <[email protected]>

chore: simplify audit log default stdout logic

8ebf2c8

Signed-off-by: Mark Phelps <[email protected]>

markphelps added 2 commits June 5, 2024 10:55

chore: switch to zap logger

5a59b77

chore: merge

8734335

markphelps added 4 commits June 5, 2024 11:44

Merge branch 'main' into audit-logs-stdout

fbe9ed8

chore: fix schemas

6c1e0f5

Merge branch 'audit-logs-stdout' of https://github.com/flipt-io/flipt …

f5887bd

…into audit-logs-stdout * 'audit-logs-stdout' of https://github.com/flipt-io/flipt: docs: add levlaz as a contributor for doc (#3148)

chore: key for AUDIT; inherit global log encoding if not set

19e40a4

chore: add audit log test

8e98c39

Signed-off-by: Mark Phelps <[email protected]>

markphelps marked this pull request as ready for review June 5, 2024 19:08

markphelps requested a review from GeorgeMac June 5, 2024 19:21

markphelps commented Jun 5, 2024

View reviewed changes

chore: change error msg

e2b4355

Signed-off-by: Mark Phelps <[email protected]>

markphelps commented Jun 5, 2024

View reviewed changes

internal/server/audit/log/log.go Show resolved Hide resolved

markphelps marked this pull request as draft June 5, 2024 19:35

markphelps added 2 commits June 5, 2024 15:35

chore: push failing non-existent dir test

997a00c

Signed-off-by: Mark Phelps <[email protected]>

chore: create dir if not exists

b314368

Signed-off-by: Mark Phelps <[email protected]>

markphelps marked this pull request as ready for review June 5, 2024 19:42

GeorgeMac approved these changes Jun 6, 2024

View reviewed changes

markphelps merged commit 59b6f0e into main Jun 6, 2024
30 checks passed

markphelps deleted the audit-logs-stdout branch June 6, 2024 13:18

erka mentioned this pull request Jun 6, 2024

fix(audit): preserve audit log scheme #3151

Merged

markphelps added needs docs Requires documentation updates and removed needs docs Requires documentation updates labels Jun 9, 2024

markphelps mentioned this pull request Jun 9, 2024

chore: document upcoming audit log file changes flipt-io/docs#228

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

feat: support writing audit events to stdout for log #3113

feat: support writing audit events to stdout for log #3113

markphelps commented May 26, 2024

GeorgeMac left a comment

erka commented May 27, 2024

markphelps commented May 27, 2024 •

edited

Loading

GeorgeMac commented May 28, 2024

markphelps commented Jun 5, 2024

markphelps commented Jun 5, 2024 •

edited

Loading

markphelps commented Jun 5, 2024

markphelps commented Jun 5, 2024 •

edited

Loading

markphelps commented Jun 5, 2024

markphelps Jun 5, 2024

GeorgeMac left a comment

erka commented Jun 6, 2024 •

edited

Loading

feat: support writing audit events to stdout for log #3113

feat: support writing audit events to stdout for log #3113

Conversation

markphelps commented May 26, 2024

GeorgeMac left a comment

Choose a reason for hiding this comment

erka commented May 27, 2024

markphelps commented May 27, 2024 • edited Loading

GeorgeMac commented May 28, 2024

markphelps commented Jun 5, 2024

markphelps commented Jun 5, 2024 • edited Loading

markphelps commented Jun 5, 2024

markphelps commented Jun 5, 2024 • edited Loading

markphelps commented Jun 5, 2024

markphelps Jun 5, 2024

Choose a reason for hiding this comment

GeorgeMac left a comment

Choose a reason for hiding this comment

erka commented Jun 6, 2024 • edited Loading

markphelps commented May 27, 2024 •

edited

Loading

markphelps commented Jun 5, 2024 •

edited

Loading

markphelps commented Jun 5, 2024 •

edited

Loading

erka commented Jun 6, 2024 •

edited

Loading