WIP: Log with slog to stdout in JSON form

[wallrj]

Before:

go run ./ agent --one-shot --output-path /foo/bar --api-token should-not-be-required  --agent-config-file examples/cert-manager-agent.yaml 2>stderr >stdout

stdout

stderr

2024/10/15 11:56:20 Preflight agent version: development ()
2024/10/15 11:56:20 Using the Jetstack Secure API Token auth mode since --api-token was specified.
2024/10/15 11:56:20 Using deprecated Endpoint configuration. User Server instead.
2024/10/15 11:56:20 starting "k8s/secrets.v1" datagatherer
2024/10/15 11:56:20 starting "k8s/certificates.v1alpha2.cert-manager.io" datagatherer
2024/10/15 11:56:20 starting "k8s/ingresses.v1beta1.networking.k8s.io" datagatherer
2024/10/15 11:56:20 starting "k8s/certificaterequests.v1alpha2.cert-manager.io" datagatherer
W1015 11:56:20.490541  347732 reflector.go:561] pkg/mod/k8s.io/client-go@v0.31.1/tools/cache/reflector.go:243: failed to list networking.k8s.io/v1beta1, Resource=ingresses: the server could not find the requested resource
2024/10/15 11:56:20 server missing resource for datagatherer of "networking.k8s.io/v1beta1, Resource=ingresses"
W1015 11:56:20.495094  347732 reflector.go:561] pkg/mod/k8s.io/client-go@v0.31.1/tools/cache/reflector.go:243: failed to list cert-manager.io/v1alpha2, Resource=certificaterequests: the server could not find the requested resource
2024/10/15 11:56:20 server missing resource for datagatherer of "cert-manager.io/v1alpha2, Resource=certificaterequests"
W1015 11:56:20.497450  347732 reflector.go:561] pkg/mod/k8s.io/client-go@v0.31.1/tools/cache/reflector.go:243: failed to list cert-manager.io/v1alpha2, Resource=certificates: the server could not find the requested resource
2024/10/15 11:56:20 server missing resource for datagatherer of "cert-manager.io/v1alpha2, Resource=certificates"
W1015 11:56:21.904811  347732 reflector.go:561] pkg/mod/k8s.io/client-go@v0.31.1/tools/cache/reflector.go:243: failed to list cert-manager.io/v1alpha2, Resource=certificaterequests: the server could not find the requested resource
2024/10/15 11:56:21 server missing resource for datagatherer of "cert-manager.io/v1alpha2, Resource=certificaterequests"
W1015 11:56:22.043669  347732 reflector.go:561] pkg/mod/k8s.io/client-go@v0.31.1/tools/cache/reflector.go:243: failed to list cert-manager.io/v1alpha2, Resource=certificates: the server could not find the requested resource
2024/10/15 11:56:22 server missing resource for datagatherer of "cert-manager.io/v1alpha2, Resource=certificates"
W1015 11:56:22.080127  347732 reflector.go:561] pkg/mod/k8s.io/client-go@v0.31.1/tools/cache/reflector.go:243: failed to list networking.k8s.io/v1beta1, Resource=ingresses: the server could not find the requested resource
2024/10/15 11:56:22 server missing resource for datagatherer of "networking.k8s.io/v1beta1, Resource=ingresses"
W1015 11:56:23.938818  347732 reflector.go:561] pkg/mod/k8s.io/client-go@v0.31.1/tools/cache/reflector.go:243: failed to list cert-manager.io/v1alpha2, Resource=certificates: the server could not find the requested resource
2024/10/15 11:56:23 server missing resource for datagatherer of "cert-manager.io/v1alpha2, Resource=certificates"
W1015 11:56:24.441234  347732 reflector.go:561] pkg/mod/k8s.io/client-go@v0.31.1/tools/cache/reflector.go:243: failed to list networking.k8s.io/v1beta1, Resource=ingresses: the server could not find the requested resource
2024/10/15 11:56:24 server missing resource for datagatherer of "networking.k8s.io/v1beta1, Resource=ingresses"
W1015 11:56:24.564356  347732 reflector.go:561] pkg/mod/k8s.io/client-go@v0.31.1/tools/cache/reflector.go:243: failed to list cert-manager.io/v1alpha2, Resource=certificaterequests: the server could not find the requested resource
2024/10/15 11:56:24 server missing resource for datagatherer of "cert-manager.io/v1alpha2, Resource=certificaterequests"
2024/10/15 11:56:25 failed to complete initial sync of "k8s-dynamic" data gatherer "k8s/certificates.v1alpha2.cert-manager.io": timed out waiting for Kubernetes caches to sync
2024/10/15 11:56:25 failed to complete initial sync of "k8s-dynamic" data gatherer "k8s/ingresses.v1beta1.networking.k8s.io": timed out waiting for Kubernetes caches to sync
2024/10/15 11:56:25 failed to complete initial sync of "k8s-dynamic" data gatherer "k8s/certificaterequests.v1alpha2.cert-manager.io": timed out waiting for Kubernetes caches to sync
2024/10/15 11:56:25 successfully gathered 22 items from "k8s/secrets.v1" datagatherer
2024/10/15 11:56:25 successfully gathered 0 items from "k8s/certificates.v1alpha2.cert-manager.io" datagatherer
2024/10/15 11:56:25 successfully gathered 0 items from "k8s/ingresses.v1beta1.networking.k8s.io" datagatherer
2024/10/15 11:56:25 successfully gathered 0 items from "k8s/certificaterequests.v1alpha2.cert-manager.io" datagatherer
2024/10/15 11:56:25 failed to output to local file: open /foo/bar: no such file or directory
exit status 1

One-shot output with deliberate config error

$ go run ./ agent --one-shot --output-path /foo/bar --api-token should-not-be-required
{"time":"2024-10-15T11:28:22.360581783+01:00","level":"INFO","msg":"Preflight agent version: development ()"}
{"time":"2024-10-15T11:28:22.361846945+01:00","level":"INFO","msg":"Using the Jetstack Secure API Token auth mode since --api-token was specified."}
{"time":"2024-10-15T11:28:22.361875051+01:00","level":"INFO","msg":"ignoring the venafi-cloud.uploader_id field in the config file. This field is not needed in Jetstack Secure API Token mode."}
{"time":"2024-10-15T11:28:22.361899488+01:00","level":"INFO","msg":"starting \"dummy\" datagatherer"}
{"time":"2024-10-15T11:28:22.361919085+01:00","level":"INFO","msg":"starting \"dummy-fail\" datagatherer"}
{"time":"2024-10-15T11:28:22.361970856+01:00","level":"INFO","msg":"failed to output to local file: open /foo/bar: no such file or directory"}
exit status 1

Command line help

$ go run ./ agent --one-shot --output-path /foo/bar --api-token should-not-be-required  -h
The agent will periodically gather data for the configured data
        gatherers and send it to a remote backend for evaluation

Usage:
  preflight agent [flags]
  preflight agent [command]

Available Commands:
  info        print several internal parameters of the agent
  rbac        print the agent's minimal RBAC manifest

Flags:
  -c, --agent-config-file agent.yaml                      Config file location, default is agent.yaml in the current working directory. (default "./agent.yaml")
      --api-token string                                  Turns on the Jetstack Secure API Token mode. Defaults to the value of the env var API_TOKEN.
      --backoff-max-time duration                         Max time for retrying failed data gatherers (given as XhYmZs). (default 10m0s)
      --client-id string                                  Turns on the Venafi Cloud Key Pair Service Account mode. If you use this flag you don't need to use --venafi-cloud as it will assume you are authenticating with Venafi Cloud. Using this removes the need to use a credentials file.
  -k, --credentials-file string                           Location of the credentials file. For the Jetstack Secure OAuth and Venafi Cloud Key Pair Service Account modes.
      --enable-metrics                                    Enables Prometheus metrics server on the agent (port: 8081).
      --enable-pprof                                      Enables the pprof profiling server on the agent (port: 6060).
  -h, --help                                              help for agent
      --input-path string                                 For testing purposes. In conjunction with --one-shot, it allows you to push manually crafted data readings (in JSON format) to the Venafi Cloud API without the need to connect to a Kubernetes cluster.
      --install-namespace string                          For testing purposes. Namespace in which the agent is running. Only needed with the Venafi Cloud VenafiConnection modewhen running the agent outside of Kubernetes.
      --one-shot                                          For testing purposes. The agent will run once and exit. It is often used in conjunction with --output-path and/or --input-path.
      --output-path string                                For testing purposes. In conjunction with --one-shot, it allows you to write the data readings to a file instead of uploading to the server.
  -p, --period duration                                   Override time between scans in the configuration file (given as XhYmZs).
      --private-key-path string                           To be used in conjunction with --client-id. The path to the private key file for the service account.
      --strict                                            Runs agent in strict mode. No retry attempts will be made for a missing data gatherer's data.
      --venafi-connection string                          Turns on the Venafi Cloud VenafiConnection mode. This flag configures the name of the VenafiConnection to be used.
      --venafi-connection-namespace allowReferencesFrom   Namespace of the VenafiConnection to be used. It is only useful when the VenafiConnection isn't in the same namespace as the agent. The field allowReferencesFrom must be present on the cross-namespace VenafiConnection for the agent to use it.

Global Flags:
  -v, --log-level int   Set the logging verbosity. 8: >= ERROR, 4: >= WARN, 0: >=INFO, -4: >= DEBUG

Use "preflight agent [command] --help" for more information about a command.

Unit Test output

$ go test ./pkg/logs/... -v
=== RUN   TestLogs
vCert: 2024/10/15 11:07:15 log before initialize
vCert: 2024/10/15 11:07:15 INFO slog before initialize
--- PASS: TestLogs (0.00s)
PASS
ok      github.com/jetstack/preflight/pkg/logs  (cached)

Example logs from the E2E test with a deliberate config error:

{"time":"2024-10-15T10:09:19.118854375Z","level":"INFO","msg":"Preflight agent version: v1.1.0-3-gd97130c33e1830-dirty (d97130c33e183044ac01116511b11779d6f38408)"}
{"time":"2024-10-15T10:09:19.124213625Z","level":"INFO","msg":"Using the Venafi Cloud VenafiConnection auth mode since --venafi-connection was specified."}
{"time":"2024-10-15T10:09:19.124446355Z","level":"INFO","msg":"ignoring the server field specified in the config file. In Venafi Cloud VenafiConnection mode, this field is not needed."}
{"time":"2024-10-15T10:09:19.124459725Z","level":"INFO","msg":"ignoring the venafi-cloud.upload_path field in the config file. In Venafi Cloud VenafiConnection mode, this field is not needed."}
{"time":"2024-10-15T10:09:19.124464355Z","level":"INFO","msg":"ignoring the venafi-cloud.uploader_id field in the config file. This field is not needed in Venafi Cloud VenafiConnection mode."}
{"time":"2024-10-15T10:09:19.124486005Z","level":"INFO","msg":"Using period from config 1m0s"}
{"time":"2024-10-15T10:09:19.168849156Z","level":"INFO","msg":"Prometheus was enabled.\nRunning prometheus on port :8081"}
{"time":"2024-10-15T10:09:24.191872114Z","level":"INFO","msg":"Posting data to: "}
{"time":"2024-10-15T10:09:24.355308739Z","level":"INFO","msg":"retrying in 43.757356959s after error: post to server failed: while loading the VenafiConnection venafi/venafi-components: connection is not ready yet (building connection failed): chain element 1 (VCPOAuth) error: Post \"https://api.venafi.eu.example/v1/oauth2/v2.0/9a0cab61-2b00-11ee-ba09-0733b0fe5adc/token\": dial tcp: lookup api.venafi.eu.example on 34.118.224.10:53: no such host"}
{"time":"2024-10-15T10:10:08.115125429Z","level":"INFO","msg":"Posting data to: "}
{"time":"2024-10-15T10:10:08.191519822Z","level":"INFO","msg":"retrying in 42.657399976s after error: post to server failed: while loading the VenafiConnection venafi/venafi-components: connection is not ready yet (building connection failed): chain element 1 (VCPOAuth) error: Post \"https://api.venafi.eu.example/v1/oauth2/v2.0/9a0cab61-2b00-11ee-ba09-0733b0fe5adc/token\": dial tcp: lookup api.venafi.eu.example on 34.118.224.10:53: no such host"}
{"time":"2024-10-15T10:10:50.850078426Z","level":"INFO","msg":"Posting data to: "}
{"time":"2024-10-15T10:10:50.910425557Z","level":"INFO","msg":"retrying in 43.526318066s after error: post to server failed: while loading the VenafiConnection venafi/venafi-components: connection is not ready yet (building connection failed): chain element 1 (VCPOAuth) error: Post \"https://api.venafi.eu.example/v1/oauth2/v2.0/9a0cab61-2b00-11ee-ba09-0733b0fe5adc/token\": dial tcp: lookup api.venafi.eu.example on 34.118.224.10:53: no such host"}
{"time":"2024-10-15T10:11:34.437054765Z","level":"INFO","msg":"Posting data to: "}
{"time":"2024-10-15T10:11:34.507746957Z","level":"INFO","msg":"retrying in 2m27.200451291s after error: post to server failed: while loading the VenafiConnection venafi/venafi-components: connection is not ready yet (building connection failed): chain element 1 (VCPOAuth) error: Post \"https://api.venafi.eu.example/v1/oauth2/v2.0/9a0cab61-2b00-11ee-ba09-0733b0fe5adc/token\": dial tcp: lookup api.venafi.eu.example on 34.118.224.10:53: no such host"}
{"time":"2024-10-15T10:14:01.70912232Z","level":"INFO","msg":"Posting data to: "}
{"time":"2024-10-15T10:14:01.765769857Z","level":"INFO","msg":"retrying in 1m44.386748573s after error: post to server failed: while loading the VenafiConnection venafi/venafi-components: connection is not ready yet (building connection failed): chain element 1 (VCPOAuth) error: Post \"https://api.venafi.eu.example/v1/oauth2/v2.0/9a0cab61-2b00-11ee-ba09-0733b0fe5adc/token\": dial tcp: lookup api.venafi.eu.example on 34.118.224.10:53: no such host"}
{"time":"2024-10-15T10:15:46.152698136Z","level":"INFO","msg":"Posting data to: "}
{"time":"2024-10-15T10:15:46.230646545Z","level":"INFO","msg":"retrying in 1m59.783143995s after error: post to server failed: while loading the VenafiConnection venafi/venafi-components: connection is not ready yet (building connection failed): chain element 1 (VCPOAuth) error: Post \"https://api.venafi.eu.example/v1/oauth2/v2.0/9a0cab61-2b00-11ee-ba09-0733b0fe5adc/token\": dial tcp: lookup api.venafi.eu.example on 34.118.224.10:53: no such host"}
{"time":"2024-10-15T10:17:46.014726631Z","level":"INFO","msg":"Posting data to: "}
{"time":"2024-10-15T10:17:46.077177178Z","level":"INFO","msg":"retrying in 2m51.121170931s after error: post to server failed: while loading the VenafiConnection venafi/venafi-components: connection is not ready yet (building connection failed): chain element 1 (VCPOAuth) error: Post \"https://api.venafi.eu.example/v1/oauth2/v2.0/9a0cab61-2b00-11ee-ba09-0733b0fe5adc/token\": dial tcp: lookup api.venafi.eu.example on 34.118.224.10:53: no such host"}
{"time":"2024-10-15T10:20:37.199232157Z","level":"INFO","msg":"Posting data to: "}
{"time":"2024-10-15T10:20:37.260874746Z","level":"INFO","msg":"Exiting due to fatal error uploading: post to server failed: while loading the VenafiConnection venafi/venafi-components: connection is not ready yet (building connection failed): chain element 1 (VCPOAuth) error: Post \"https://api.venafi.eu.example/v1/oauth2/v2.0/9a0cab61-2b00-11ee-ba09-0733b0fe5adc/token\": dial tcp: lookup api.venafi.eu.example on 34.118.224.10:53: no such host"}

[wallrj]

I chose a different approach. Using klog in #596