Use structured logging

[uablrek]

Use structured logging in json format if -logging-format=json is specified. The same setup functions as for K8s core packages are used (component-base).

Also, contextual logging is used (beta in 1.30, so no feature-gateway is needed).

Fixes #48

This PR will be a draft until all code is changed to use structured/contextual logging.

[uablrek]

/cc @pohly

@pohly Can you please review the updates in main() in the first commit? I don't want to do any fundamental mistakes. The rest I think I can manage.

[uablrek]

Example output:

# kubectl logs -n kube-system   kube-network-policies-8hb7p | jq
...
{
  "ts": 1720002972865.8306,
  "caller": "cache/reflector.go:359",
  "msg": "Caches populated for *v1.Pod from pkg/mod/k8s.io/client-go@v0.30.2/tools/cache/reflector.go:232",
  "v": 2
}
{
  "ts": 1720002972953.2607,
  "caller": "cache/shared_informer.go:320",
  "msg": "Caches are synced for kube-network-policies",
  "v": 0
}
{
  "ts": 1720002972953.3674,
  "caller": "networkpolicy/metrics.go:61",
  "msg": "Registering metrics",
  "v": 0
}
{
  "ts": 1720002972953.4724,
  "caller": "networkpolicy/controller.go:344",
  "msg": "Syncing nftables rules",
  "v": 0
}

[uablrek]

Lint complaints:

Error: cmd/main.go:81:3: exitAfterDefer: os.Exit will exit, and `defer cancel()` will not run (gocritic)

This is just as bad with klog.Fatalf, but lint misses that. A pattern seem to be:

func main() {
  os.Exit(run())
}
func run() int {
  return errorCode
}

~Shall we use it? Else I restore klog.Fatalf in main()~

I will call cancel() explicitly. (but since it's right before exit, it will not really matter)

[aojea]

func main() {
  os.Exit(run())
}
func run() int {
  return errorCode
}

that sounds like the right way to do it

[aojea]

@uablrek what is missing here? it lgtms

/lgtm /approve

[k8s-ci-robot]

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: aojea, uablrek

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files: - ~~[OWNERS](https://github.com/kubernetes-sigs/kube-network-policies/blob/main/OWNERS)~~ [aojea] Approvers can indicate their approval by writing `/approve` in a comment Approvers can cancel approval by writing `/approve cancel` in a comment

[uablrek]

@uablrek what is missing here? it lgtms

Lots and lots of Infof(), and friends, should be changed to InfoS().

Also i was planning to introduce contextual logging, but I think that can wait.

[k8s-ci-robot]

New changes are detected. LGTM label has been removed.

[uablrek]

Structured logging allows a nice optimization possibility. Without this p.String() is always called, regardless of verbosity.

    // evaluatePacket() should be fast unless trace logging is enabled.
    // Logging optimization: We check if V(2) is enabled before hand,
    // rather than evaluating the all parameters make an unnecessary logger call
    tlogger := logger.V(2)
    if tlogger.Enabled() {
        tlogger.Info("Evaluating packet", "packet", p)
        tlogger = tlogger.WithValues("id", p.id)
    }

[uablrek]

Example packet log in JSON format:

{
  "ts": 1720777151838.3552,
  "caller": "networkpolicy/controller.go:461",
  "msg": "Evaluating packet",
  "v": 2,
  "packet": {
    "Id": 9,
    "Family": "IPv4",
    "SrcIP": "11.0.3.3",
    "DstIP": "11.0.2.2",
    "Proto": "TCP",
    "SrcPort": 33803,
    "DstPort": 6000
  }
}

Text output is not altered:

I0712 09:53:52.257809       1 controller.go:461] "Evaluating packet" packet=<
        [8] 11.0.1.3:40243 11.0.2.2:6000 TCP
        00000000  00 00 a0 02 fa f0 19 33  00 00 02 04 05 b4 04 02  |.......3........|
        00000010  08 0a c1 d9 c1 bd 00 00  00 00 01 03 03 07        |..............|
 >

[uablrek]

I will squash commits later

[aojea]

let me know once is ready for merging