Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: Allow writing logs to custom file #2473

Merged
merged 6 commits into from
Jan 10, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 2 additions & 0 deletions cmd/build/helmify/kustomize-for-helm.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -93,6 +93,7 @@ spec:
- HELMSUBST_DEPLOYMENT_CONTROLLER_MANAGER_DISABLED_BUILTIN
- HELMSUBST_DEPLOYMENT_CONTROLLER_MANAGER_EXEMPT_NAMESPACES
- HELMSUBST_DEPLOYMENT_CONTROLLER_MANAGER_EXEMPT_NAMESPACE_PREFIXES
- HELMSUBST_DEPLOYMENT_CONTROLLER_MANAGER_LOGFILE
imagePullPolicy: "{{ .Values.image.pullPolicy }}"
HELMSUBST_AUDIT_CONTROLLER_MANAGER_DEPLOYMENT_IMAGE_RELEASE: ""
ports:
Expand Down Expand Up @@ -164,6 +165,7 @@ spec:
- --enable-external-data={{ .Values.enableExternalData }}
- --enable-generator-resource-expansion={{ .Values.enableGeneratorResourceExpansion }}
- HELMSUBST_METRICS_BACKEND_ARG
- HELMSUBST_DEPLOYMENT_AUDIT_LOGFILE
- --disable-cert-rotation={{ or .Values.audit.disableCertRotation .Values.externalCertInjection.enabled }}
imagePullPolicy: "{{ .Values.image.pullPolicy }}"
HELMSUBST_AUDIT_CONTROLLER_MANAGER_DEPLOYMENT_IMAGE_RELEASE: ""
Expand Down
10 changes: 10 additions & 0 deletions cmd/build/helmify/replacements.go
Original file line number Diff line number Diff line change
Expand Up @@ -231,4 +231,14 @@ var replacements = map[string]string{
{{- range .Values.controllerManager.exemptNamespacePrefixes}}
- --exempt-namespace-prefix={{ . }}
{{- end }}`,

"- HELMSUBST_DEPLOYMENT_CONTROLLER_MANAGER_LOGFILE": `
{{- if .Values.controllerManager.logFile}}
- --log-file={{ .Values.controllerManager.logFile }}
Copy link
Member

@ritazh ritazh Dec 21, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Do we want to add this new flag to https://github.com/open-policy-agent/gatekeeper/blob/master/Makefile#L65 so we can test it as part of the end to end?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

TBH I'm a little wary of having too many permutations being tested end-to-end, for both test-run-time and being too e2e-test-heavy reasons. IMO this shouldn't change the overall behavior enough to warrant a new e2e tests.

If we tested every permutation of flags, we'd have probably millions of independent e2e tests.

Copy link
Contributor Author

@maxsmythe maxsmythe Dec 22, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I will say that I ran G8r with this flag manually and it works, though

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

As discussed in the 1/4/2023 community call, let's leave this out of e2e as the impact surface is low and optional.

{{- end }}`,

"- HELMSUBST_DEPLOYMENT_AUDIT_LOGFILE": `
{{- if .Values.audit.logFile}}
- --log-file={{ .Values.audit.logFile }}
{{- end }}`,
}
117 changes: 89 additions & 28 deletions main.go
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@ import (
"errors"
"flag"
"fmt"
"io"
"net/http"
_ "net/http/pprof"
"os"
Expand Down Expand Up @@ -92,6 +93,7 @@ var (
)

var (
logFile = flag.String("log-file", "", "Log to file, if specified. Default is to log to stderr.")
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is this mutual exclusive such that you can only choose either or between logFile and stderr? What if someone wants both?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good question. If the logging frameworks support it, we could extend this to allow the flag to be specified multiple times.

Copy link
Member

@ritazh ritazh Jan 5, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So as it's currently implemented, this is mutually exclusive right?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Correct

logLevel = flag.String("log-level", "INFO", "Minimum log level. For example, DEBUG, INFO, WARNING, ERROR. Defaulted to INFO if unspecified.")
logLevelKey = flag.String("log-level-key", "level", "JSON key for the log level field, defaults to `level`")
logLevelEncoder = flag.String("log-level-encoder", "lower", "Encoder for the value of the log level field. Valid values: [`lower`, `capital`, `color`, `capitalcolor`], default: `lower`")
Expand Down Expand Up @@ -123,11 +125,15 @@ func init() {
}

func main() {
os.Exit(innerMain())
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

is this refactor just so we don't call os.Exit() in a bunch of places?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Correct, os.Exit() breaks defer, so defer close() would not reliably be called without this.

}

func innerMain() int {
flag.Parse()
encoder, ok := logLevelEncoders[*logLevelEncoder]
if !ok {
setupLog.Error(fmt.Errorf("invalid log level encoder: %v", *logLevelEncoder), "Invalid log level encoder")
os.Exit(1)
return 1
}

if *enableProfile {
Expand All @@ -138,23 +144,48 @@ func main() {
}()
}

var logStream io.Writer
if *logFile != "" {
handle, err := os.OpenFile(*logFile, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0o644)
if err != nil {
setupLog.Error(fmt.Errorf("unable to open log file %s: %w", *logFile, err), "error initializing logging")
return 1
}
defer handle.Close()
logStream = handle
Comment on lines +154 to +155
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

if there is an err above, the handle will be nil right? won't this cause problems when attempting to close?

Copy link
Contributor Author

@maxsmythe maxsmythe Jan 4, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It would return ErrInvalid, which would be swallowed silently:

https://cs.opensource.google/go/go/+/refs/tags/go1.19.4:src/os/file_posix.go;l=23

Because an error implies nothing was opened, presumably there is nothing to close.

However, a failure to open a logfile should probably be a fatal error, so updating to exit immediately on error.

}

switch *logLevel {
case "DEBUG":
eCfg := zap.NewDevelopmentEncoderConfig()
eCfg.LevelKey = *logLevelKey
eCfg.EncodeLevel = encoder
logger := crzap.New(crzap.UseDevMode(true), crzap.Encoder(zapcore.NewConsoleEncoder(eCfg)))
opts := []crzap.Opts{
crzap.UseDevMode(true),
crzap.Encoder(zapcore.NewConsoleEncoder(eCfg)),
}
if logStream != nil {
opts = append(opts, crzap.WriteTo(logStream))
}
logger := crzap.New(opts...)
ctrl.SetLogger(logger)
klog.SetLogger(logger)
case "WARNING", "ERROR":
setLoggerForProduction(encoder)
setLoggerForProduction(encoder, logStream)
case "INFO":
fallthrough
default:
eCfg := zap.NewProductionEncoderConfig()
eCfg.LevelKey = *logLevelKey
eCfg.EncodeLevel = encoder
logger := crzap.New(crzap.UseDevMode(false), crzap.Encoder(zapcore.NewJSONEncoder(eCfg)))
opts := []crzap.Opts{
crzap.UseDevMode(false),
crzap.Encoder(zapcore.NewJSONEncoder(eCfg)),
}
if logStream != nil {
opts = append(opts, crzap.WriteTo(logStream))
}
logger := crzap.New(opts...)
ctrl.SetLogger(logger)
klog.SetLogger(logger)
}
Expand Down Expand Up @@ -189,7 +220,7 @@ func main() {
})
if err != nil {
setupLog.Error(err, "unable to start manager")
os.Exit(1)
return 1
}

// Make sure certs are generated and valid if cert rotation is enabled.
Expand All @@ -216,7 +247,7 @@ func main() {
ExtKeyUsages: &keyUsages,
}); err != nil {
setupLog.Error(err, "unable to set up cert rotation")
os.Exit(1)
return 1
}
} else {
close(setupFinished)
Expand All @@ -230,14 +261,14 @@ func main() {
tracker, err := readiness.SetupTracker(mgr, mutation.Enabled(), *externaldata.ExternalDataEnabled)
if err != nil {
setupLog.Error(err, "unable to register readiness tracker")
os.Exit(1)
return 1
}

// +kubebuilder:scaffold:builder

if err := mgr.AddHealthzCheck("default", healthz.Ping); err != nil {
setupLog.Error(err, "unable to create health check")
os.Exit(1)
return 1
}

// only setup healthcheck when flag is set and available webhook count > 0
Expand All @@ -246,18 +277,43 @@ func main() {
setupLog.Info("setting up TLS healthcheck probe")
if err := mgr.AddHealthzCheck("tls-check", tlsChecker); err != nil {
setupLog.Error(err, "unable to create tls health check")
os.Exit(1)
return 1
}
}

// Setup controllers asynchronously, they will block for certificate generation if needed.
go setupControllers(mgr, sw, tracker, setupFinished)
setupErr := make(chan error)
go func() {
setupErr <- setupControllers(mgr, sw, tracker, setupFinished)
}()

setupLog.Info("starting manager")
mgrErr := make(chan error)
go func() {
if err := mgr.Start(ctrl.SetupSignalHandler()); err != nil {
setupLog.Error(err, "problem running manager")
mgrErr <- err
}
}()

// block until either setupControllers or mgr has an error, or mgr exits.
// end after two events (one per goroutine) to guard against deadlock.
hadError := false
if err := mgr.Start(ctrl.SetupSignalHandler()); err != nil {
setupLog.Error(err, "problem running manager")
hadError = true
blockingLoop:
for i := 0; i < 2; i++ {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What is this looping 2x?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just a precautionary measure to make sure it's not an infinite loop. If both functions return we should exit (in practice we always return when Manager.Start() exits, but it guards against future whoopsies)

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

could we add your explanation in as a comment?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

added an explanation.

select {
case err := <-setupErr:
if err != nil {
hadError = true
break blockingLoop
}
case err := <-mgrErr:
if err != nil {
hadError = true
}
// if manager has returned, we should exit the program
break blockingLoop
}
}

// Manager stops controllers asynchronously.
Expand All @@ -267,11 +323,12 @@ func main() {
sw.Stop()

if hadError {
os.Exit(1)
return 1
}
return 0
}

func setupControllers(mgr ctrl.Manager, sw *watch.ControllerSwitch, tracker *readiness.Tracker, setupFinished chan struct{}) {
func setupControllers(mgr ctrl.Manager, sw *watch.ControllerSwitch, tracker *readiness.Tracker, setupFinished chan struct{}) error {
// Block until the setup (certificate generation) finishes.
<-setupFinished

Expand All @@ -290,13 +347,13 @@ func setupControllers(mgr ctrl.Manager, sw *watch.ControllerSwitch, tracker *rea
certWatcher, err := certwatcher.New(certFile, keyFile)
if err != nil {
setupLog.Error(err, "unable to create client cert watcher")
os.Exit(1)
return err
}

setupLog.Info("setting up client cert watcher")
if err := mgr.Add(certWatcher); err != nil {
setupLog.Error(err, "unable to register client cert watcher")
os.Exit(1)
return err
}

// register the client cert watcher to the driver
Expand All @@ -309,13 +366,13 @@ func setupControllers(mgr ctrl.Manager, sw *watch.ControllerSwitch, tracker *rea
driver, err := local.New(args...)
if err != nil {
setupLog.Error(err, "unable to set up Driver")
os.Exit(1)
return err
}

client, err := constraintclient.NewClient(constraintclient.Targets(&target.K8sValidationTarget{}), constraintclient.Driver(driver))
if err != nil {
setupLog.Error(err, "unable to set up OPA client")
os.Exit(1)
return err
}

mutationSystem := mutation.NewSystem(mutationOpts)
Expand All @@ -326,17 +383,17 @@ func setupControllers(mgr ctrl.Manager, sw *watch.ControllerSwitch, tracker *rea
if !ok {
err := fmt.Errorf("expected dynamic cache, got: %T", c)
setupLog.Error(err, "fetching dynamic cache")
os.Exit(1)
return err
}

wm, err := watch.New(dc)
if err != nil {
setupLog.Error(err, "unable to create watch manager")
os.Exit(1)
return err
}
if err := mgr.Add(wm); err != nil {
setupLog.Error(err, "unable to register watch manager with the manager")
os.Exit(1)
return err
}

// processExcluder is used for namespace exclusion for specified processes in config
Expand All @@ -359,7 +416,7 @@ func setupControllers(mgr ctrl.Manager, sw *watch.ControllerSwitch, tracker *rea

if err := controller.AddToManager(mgr, &opts); err != nil {
setupLog.Error(err, "unable to register controllers with the manager")
os.Exit(1)
return err
}

if operations.IsAssigned(operations.Webhook) || operations.IsAssigned(operations.MutationWebhook) {
Expand All @@ -372,7 +429,7 @@ func setupControllers(mgr ctrl.Manager, sw *watch.ControllerSwitch, tracker *rea
}
if err := webhook.AddToManager(mgr, webhookDeps); err != nil {
setupLog.Error(err, "unable to register webhooks with the manager")
os.Exit(1)
return err
}
}

Expand All @@ -387,25 +444,29 @@ func setupControllers(mgr ctrl.Manager, sw *watch.ControllerSwitch, tracker *rea
}
if err := audit.AddToManager(mgr, &auditDeps); err != nil {
setupLog.Error(err, "unable to register audit with the manager")
os.Exit(1)
return err
}
}

setupLog.Info("setting up upgrade")
if err := upgrade.AddToManager(mgr); err != nil {
setupLog.Error(err, "unable to register upgrade with the manager")
os.Exit(1)
return err
}

setupLog.Info("setting up metrics")
if err := metrics.AddToManager(mgr); err != nil {
setupLog.Error(err, "unable to register metrics with the manager")
os.Exit(1)
return err
}
return nil
}

func setLoggerForProduction(encoder zapcore.LevelEncoder) {
func setLoggerForProduction(encoder zapcore.LevelEncoder, dest io.Writer) {
sink := zapcore.AddSync(os.Stderr)
if dest != nil {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

is there a minimal unit test we could set up to prove that writing to file works?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In short, no.

Given that these are all library functions, which presumably have their own unit tests, there is no need to duplicate work that is more properly owned by zapcore

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If we wanted to test, e2e would be the appropriate venue, per my answer to Rita's comment, however, I don't think this is a permutation that warrants another e2e run.

sink = zapcore.AddSync(dest)
}
var opts []zap.Option
encCfg := zap.NewProductionEncoderConfig()
encCfg.LevelKey = *logLevelKey
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -67,6 +67,10 @@ spec:
{{- range .Values.metricsBackends}}
- --metrics-backend={{ . }}
{{- end }}

{{- if .Values.audit.logFile}}
- --log-file={{ .Values.audit.logFile }}
{{- end }}
- --disable-cert-rotation={{ or .Values.audit.disableCertRotation .Values.externalCertInjection.enabled }}
command:
- /manager
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -83,6 +83,10 @@ spec:
{{- range .Values.controllerManager.exemptNamespacePrefixes}}
- --exempt-namespace-prefix={{ . }}
{{- end }}

{{- if .Values.controllerManager.logFile}}
- --log-file={{ .Values.controllerManager.logFile }}
{{- end }}
command:
- /manager
env:
Expand Down