Skip to content

Commit de2fd7c

Browse files
nammnfealebenpae
authored andcommitted
fix logger and controller-runtime logger (#4104)
# Summary - refactors log creation and handling - better error handling - easier way to add dedicated loggers (e.g. telemetry) - fixes edge-cases when logger is nil - set controller-runtime logger to be the same as our operator logger. Without we are not logging controller-runtime at all, which can cause the following error on startup ``` [controller-runtime] log.SetLogger(...) was never called, logs will not be displayed: goroutine 605 [running]: runtime/debug.Stack() /usr/local/go/src/runtime/debug/stack.go:24 +0x64 ``` ## Proof of Work - example other users with the same problem: rook/rook#12434 and erda-project/erda#6453 - example log from evg: REDACTED - example log ``` {"GVK": "mongodb.com/v1, Kind=MongoDB"} 2025-02-14T14:54:14.557Z INFO controller-runtime.builder builder/webhook.go:193 Registering a validating webhook {"GVK": "mongodb.com/v1, Kind=MongoDB", "path": "/validate-mongodb-com-v1-mongodb"} 2025-02-14T14:54:14.557Z INFO controller-runtime.webhook webhook/server.go:183 Registering webhook {"path": "/validate-mongodb-com-v1-mongodb"} 2025-02-14T14:54:14.557Z INFO operator/mongodbopsmanager_controller.go:951 Registered controller opsmanager-controller 2025-02-14T14:54:14.557Z INFO controller-runtime.builder builder/webhook.go:177 skip registering a mutating webhook, object does not implement admission.Defaulter or WithDefaulter wasn't called {"GVK": "mongodb.com/v1, Kind=MongoDBOpsManager"} 2025-02-14T14:54:14.557Z INFO controller-runtime.builder builder/webhook.go:193 Registering a validating webhook {"GVK": "mongodb.com/v1, Kind=MongoDBOpsManager", "path": "/validate-mongodb-com-v1-mongodbopsmanager"} 2025-02-14T14:54:14.557Z INFO controller-runtime.webhook webhook/server.go:183 Registering webhook {"path": "/validate-mongodb-com-v1-mongodbopsmanager"} 2025-02-14T14:54:14.557Z INFO operator/mongodbuser_controller.go:299 Registered controller mongodbuser-controller 2025-02-14T14:54:14.557Z INFO ops-manager-kubernetes/main.go:204 Registered CRD: mongodb 2025-02-14T14:54:14.557Z INFO ops-manager-kubernetes/main.go:204 Registered CRD: opsmanagers 2025-02-14T14:54:14.557Z INFO ops-manager-kubernetes/main.go:204 Registered CRD: mongodbusers 2025-02-14T14:54:14.557Z INFO ops-manager-kubernetes/main.go:207 Starting the Cmd. 2025-02-14T14:54:14.558Z INFO controller-runtime.metrics server/server.go:208 Starting metrics server 2025-02-14T14:54:14.558Z INFO controller-runtime.webhook webhook/server.go:191 Starting webhook server 2025-02-14T14:54:14.558Z INFO controller-runtime.metrics server/server.go:247 Serving metrics server {"bindAddress": ":8080", "secure": false} 2025-02-14T14:54:14.558Z INFO controller-runtime.certwatcher certwatcher/certwatcher.go:211 Updated current TLS certificate 2025-02-14T14:54:14.558Z INFO controller/controller.go:173 Starting EventSource {"controller": "mongodbshardedcluster-controller", "source": "kind source: *mdb.MongoDB"} 2025-02-14T14:54:14.558Z INFO controller/controller.go:173 Starting EventSource {"controller": "mongodbshardedcluster-controller", "source": "channel source: 0xc000322c40"} 2025-02-14T14:54:14.558Z INFO controller/controller.go:173 Starting EventSource {"controller": "mongodbreplicaset-controller", "source": "kind source: *mdb.MongoDB"} 2025-02-14T14:54:14.558Z INFO controller/controller.go:173 Starting EventSource {"controller": "mongodbreplicaset-controller", "source": "channel source: 0xc000322bd0"} 2025-02-14T14:54:14.558Z INFO controller/controller.go:173 Starting EventSource {"controller": "mongodbreplicaset-controller", "source": "kind source: *v1.StatefulSet"} 2025-02-14T14:54:14.558Z INFO controller/controller.go:173 Starting EventSource {"controller": "mongodbuser-controller", "source": "kind source: *v1.ConfigMap"} 2025-02-14T14:54:14.558Z INFO controller/controller.go:173 Starting EventSource {"controller": "mongodbreplicaset-controller", "source": "kind source: *v1.ConfigMap"} 2025-02-14T14:54:14.558Z INFO controller/controller.go:173 Starting EventSource {"controller": "mongodbreplicaset-controller", "source": "kind source: *v1.Secret"} 2025-02-14T14:54:14.558Z INFO controller/controller.go:181 Starting Controller {"controller": "mongodbreplicaset-controller"} 2025-02-14T14:54:14.558Z INFO controller-runtime.webhook webhook/server.go:242 Serving webhook server {"host": "", "port": 1993} 2025-02-14T14:54:14.558Z INFO controller/controller.go:173 Starting EventSource {"controller": "mongodbstandalone-controller", "source": "kind source: *mdb.MongoDB"} 2025-02-14T14:54:14.558Z INFO controller/controller.go:173 Starting EventSource {"controller": "mongodbshardedcluster-controller", "source": "kind source: *v1.ConfigMap"} 2025-02-14T14:54:14.558Z INFO controller/controller.go:173 Starting EventSource {"controller": "mongodbshardedcluster-controller", "source": "kind source: *v1.Secret"} 2025-02-14T14:54:14.558Z INFO controller/controller.go:181 Starting Controller {"controller": "mongodbshardedcluster-controller"} 2025-02-14T14:54:14.558Z INFO controller-runtime.certwatcher certwatcher/certwatcher.go:133 Starting certificate poll+watcher {"interval": "10s"} 2025-02-14T14:54:14.558Z INFO controller/controller.go:173 Starting EventSource {"controller": "mongodbuser-controller", "source": "kind source: *v1.Secret"} 2025-02-14T14:54:14.558Z INFO controller/controller.go:173 Starting EventSource {"controller": "mongodbuser-controller", "source": "kind source: *user.MongoDBUser"} 2025-02-14T14:54:14.558Z INFO controller/controller.go:173 Starting EventSource {"controller": "mongodbstandalone-controller", "source": "channel source: 0xc000322b60"} 2025-02-14T14:54:14.558Z INFO controller/controller.go:181 Starting Controller {"controller": "mongodbuser-controller"} 2025-02-14T14:54:14.558Z INFO controller/controller.go:173 Starting EventSource {"controller": "mongodbstandalone-controller", "source": "kind source: *v1.ConfigMap"} 2025-02-14T14:54:14.558Z INFO controller/controller.go:173 Starting EventSource {"controller": "mongodbstandalone-controller", "source": "kind source: *v1.Secret"} 2025-02-14T14:54:14.558Z INFO controller/controller.go:181 Starting Controller {"controller": "mongodbstandalone-controller"} 2025-02-14T14:54:14.559Z INFO controller/controller.go:173 Starting EventSource {"controller": "opsmanager-controller", "source": "kind source: *om.MongoDBOpsManager"} 2025-02-14T14:54:14.559Z INFO controller/controller.go:173 Starting EventSource {"controller": "opsmanager-controller", "source": "kind source: *v1.Secret"} 2025-02-14T14:54:14.559Z INFO controller/controller.go:173 Starting EventSource {"controller": "opsmanager-controller", "source": "kind source: *v1.Secret"} 2025-02-14T14:54:14.559Z INFO controller/controller.go:173 Starting EventSource {"controller": "opsmanager-controller", "source": "kind source: *mdb.MongoDB"} 2025-02-14T14:54:14.559Z INFO controller/controller.go:181 Starting Controller {"controller": "opsmanager-controller"} 2025-02-14T14:54:15.359Z INFO controller/controller.go:215 Starting workers {"controller": "mongodbshardedcluster-controller", "worker count": 10} 2025-02-14T14:54:15.410Z INFO controller/controller.go:215 Starting workers {"controller": "mongodbreplicaset-controller", "worker count": 10} 2025-02-14T14:54:15.460Z INFO controller/controller.go:215 Starting workers {"controller": "mongodbstandalone-controller", "worker count": 10} 2025-02-14T14:54:15.610Z INFO controller/controller.go:215 Starting workers {"controller": "mongodbuser-controller", "worker count": 10} 2025-02-14T14:54:15.660Z INFO controller/controller.go:215 Starting workers {"controller": "opsmanager-controller", "worker count": 10} 2025-02-14T14:54:16.471Z ERROR admission admission/http.go:72 bad request {"webhookGroup": "mongodb.com", "webhookKind": "MongoDB", "error": "request body is empty"} sigs.k8s.io/controller-runtime/pkg/webhook/admission.(*Webhook).ServeHTTP /go/pkg/mod/sigs.k8s.io/[email protected]/pkg/webhook/admission/http.go:72 sigs.k8s.io/controller-runtime/pkg/webhook/internal/metrics.InstrumentedHook.InstrumentHandlerInFlight.func1 /go/pkg/mod/github.com/prometheus/[email protected]/prometheus/promhttp/instrument_server.go:60 net/http.HandlerFunc.ServeHTTP /usr/local/go/src/net/http/server.go:2220 github.com/prometheus/client_golang/prometheus/promhttp.InstrumentHandlerCounter.func1 /go/pkg/mod/github.com/prometheus/[email protected]/prometheus/promhttp/instrument_server.go:147 net/http.HandlerFunc.ServeHTTP /usr/local/go/src/net/http/server.go:2220 github.com/prometheus/client_golang/prometheus/promhttp.InstrumentHandlerDuration.func2 /go/pkg/mod/github.com/prometheus/[email protected]/prometheus/promhttp/instrument_server.go:109 net/http.HandlerFunc.ServeHTTP /usr/local/go/src/net/http/server.go:2220 net/http.(*ServeMux).ServeHTTP /usr/local/go/src/net/http/server.go:2747 net/http.serverHandler.ServeHTTP /usr/local/go/src/net/http/server.go:3210 net/http.(*conn).serve /usr/local/go/src/net/http/server.go:2092 ```
1 parent b5ad3ef commit de2fd7c

File tree

3 files changed

+35
-9
lines changed

3 files changed

+35
-9
lines changed

go.mod

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@ module github.com/10gen/ops-manager-kubernetes
55
require (
66
github.com/blang/semver v3.5.1+incompatible
77
github.com/ghodss/yaml v1.0.0
8+
github.com/go-logr/zapr v1.3.0
89
github.com/google/go-cmp v0.6.0
910
github.com/google/uuid v1.6.0
1011
github.com/hashicorp/go-multierror v1.1.1

licenses.csv

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@ github.com/ghodss/yaml,v1.0.0,https://github.com/ghodss/yaml/blob/v1.0.0/LICENSE
1111
github.com/go-jose/go-jose/v4,v4.0.1,https://github.com/go-jose/go-jose/blob/v4.0.1/LICENSE,Apache-2.0
1212
github.com/go-jose/go-jose/v4/json,v4.0.1,https://github.com/go-jose/go-jose/blob/v4.0.1/json/LICENSE,BSD-3-Clause
1313
github.com/go-logr/logr,v1.4.2,https://github.com/go-logr/logr/blob/v1.4.2/LICENSE,Apache-2.0
14+
github.com/go-logr/zapr,v1.3.0,https://github.com/go-logr/zapr/blob/v1.3.0/LICENSE,Apache-2.0
1415
github.com/go-openapi/jsonpointer,v0.19.6,https://github.com/go-openapi/jsonpointer/blob/v0.19.6/LICENSE,Apache-2.0
1516
github.com/go-openapi/jsonreference,v0.20.2,https://github.com/go-openapi/jsonreference/blob/v0.20.2/LICENSE,Apache-2.0
1617
github.com/go-openapi/swag,v0.22.3,https://github.com/go-openapi/swag/blob/v0.22.3/LICENSE,Apache-2.0

main.go

Lines changed: 33 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,7 @@ import (
99
"strconv"
1010
"strings"
1111

12+
"github.com/go-logr/zapr"
1213
"go.uber.org/zap"
1314
"k8s.io/apimachinery/pkg/runtime"
1415
"k8s.io/apimachinery/pkg/types"
@@ -25,6 +26,7 @@ import (
2526
localruntime "runtime"
2627
ctrl "sigs.k8s.io/controller-runtime"
2728
runtime_cluster "sigs.k8s.io/controller-runtime/pkg/cluster"
29+
kubelog "sigs.k8s.io/controller-runtime/pkg/log"
2830
metricsServer "sigs.k8s.io/controller-runtime/pkg/metrics/server"
2931
crWebhook "sigs.k8s.io/controller-runtime/pkg/webhook"
3032

@@ -275,13 +277,7 @@ func setupWebhook(ctx context.Context, cfg *rest.Config, log *zap.SugaredLogger,
275277
}
276278

277279
func initializeEnvironment() {
278-
omOperatorEnv := os.Getenv(util.OmOperatorEnv)
279-
configuredEnv := omOperatorEnv
280-
if !validateEnv(omOperatorEnv) {
281-
omOperatorEnv = operatorEnvironments[0]
282-
}
283-
284-
initLogger(omOperatorEnv)
280+
omOperatorEnv, configuredEnv := getOperatorEnvs()
285281

286282
if configuredEnv != omOperatorEnv {
287283
log.Infof("Configured environment %s, not recognized. Must be one of %v", configuredEnv, operatorEnvironments)
@@ -320,6 +316,15 @@ func initializeEnvironment() {
320316
env.PrintWithPrefix(printableEnvPrefixes)
321317
}
322318

319+
func getOperatorEnvs() (string, string) {
320+
omOperatorEnv := os.Getenv(util.OmOperatorEnv)
321+
configuredEnv := omOperatorEnv
322+
if !validateEnv(omOperatorEnv) {
323+
omOperatorEnv = operatorEnvironments[0]
324+
}
325+
return omOperatorEnv, configuredEnv
326+
}
327+
323328
// quoteKey reports whether key is required to be quoted. Taken from: 1.22.0 mod.go
324329
func quoteKey(key string) bool {
325330
return len(key) == 0 || strings.ContainsAny(key, "= \t\r\n\"`")
@@ -360,22 +365,41 @@ func validateEnv(env string) bool {
360365
return stringutil.Contains(operatorEnvironments[:], env)
361366
}
362367

363-
func initLogger(env string) {
368+
func init() {
369+
InitGlobalLogger()
370+
}
371+
372+
func InitGlobalLogger() {
373+
omOperatorEnv, _ := getOperatorEnvs()
374+
364375
var logger *zap.Logger
365376
var e error
366377

367-
switch env {
378+
switch omOperatorEnv {
368379
case "prod":
369380
logger, e = zap.NewProduction()
370381
case "dev", "local":
371382
// Overriding the default stacktrace behavior - have them only for errors but not for warnings
372383
logger, e = zap.NewDevelopment(zap.AddStacktrace(zap.ErrorLevel))
384+
default:
385+
// if for some reason we didn't set a logger, let's be safe and default to prod
386+
fmt.Println("No OPERATOR_ENV set, defaulting setting logger to prod")
387+
logger, e = zap.NewProduction()
373388
}
374389

375390
if e != nil {
376391
fmt.Println("Failed to create logger, will use the default one")
377392
fmt.Println(e)
393+
// in the worst case logger might stay nil, replacing everything with a nil logger,
394+
// we don't want that
395+
logger = zap.S().Desugar()
378396
}
397+
398+
// Set the global logger used by our operator
379399
zap.ReplaceGlobals(logger)
400+
// Set the logger for controller-runtime based on the general level of the operator
401+
kubelog.SetLogger(zapr.NewLogger(logger))
402+
403+
// Set the logger used by main.go
380404
log = zap.S()
381405
}

0 commit comments

Comments
 (0)