From 0245d4d0f005fad0c9a0416f6197700ad882629c Mon Sep 17 00:00:00 2001 From: jgough Date: Tue, 28 May 2024 11:49:15 +0100 Subject: [PATCH 1/2] Move k8s configuration for go to its own pacakge re: AB#9542 --- go.mod | 5 ++- go.sum | 10 +++-- k8sworker/k8soptions.go | 25 +++++++++++ k8sworker/k8sworker.go | 99 +++++++++++++++++++++++++++++++++++++++++ logger/logger.go | 56 ++--------------------- startup/run.go | 16 +++++++ 6 files changed, 153 insertions(+), 58 deletions(-) create mode 100644 k8sworker/k8soptions.go create mode 100644 k8sworker/k8sworker.go diff --git a/go.mod b/go.mod index 6479517..d3a578e 100644 --- a/go.mod +++ b/go.mod @@ -20,7 +20,7 @@ require ( github.com/Azure/azure-sdk-for-go/sdk/storage/azblob v0.4.1 github.com/Azure/go-autorest/autorest v0.11.29 github.com/Azure/go-autorest/autorest/azure/auth v0.5.12 - github.com/KimMachineGun/automemlimit v0.2.6 + github.com/KimMachineGun/automemlimit v0.6.1 github.com/alicebob/miniredis/v2 v2.32.1 github.com/fxamacker/cbor/v2 v2.5.0 github.com/go-redis/redis/v8 v8.11.5 @@ -58,6 +58,7 @@ require ( github.com/lestrrat-go/iter v1.0.2 // indirect github.com/lestrrat-go/option v1.0.1 // indirect github.com/matttproud/golang_protobuf_extensions v1.0.1 // indirect + github.com/pbnjay/memory v0.0.0-20210728143218-7b4eea64cf58 // indirect github.com/pkg/errors v0.9.1 // indirect github.com/prometheus/client_model v0.2.0 // indirect github.com/prometheus/common v0.26.0 // indirect @@ -101,6 +102,6 @@ require ( golang.org/x/sys v0.18.0 // indirect golang.org/x/text v0.14.0 // indirect google.golang.org/genproto/googleapis/api v0.0.0-20230822172742-b8732ec3820d // indirect - google.golang.org/protobuf v1.31.0 // indirect + google.golang.org/protobuf v1.33.0 // indirect gopkg.in/yaml.v3 v3.0.1 // indirect ) diff --git a/go.sum b/go.sum index eecf839..bcef3bc 100644 --- a/go.sum +++ b/go.sum @@ -42,8 +42,8 @@ github.com/Azure/go-autorest/tracing v0.6.0/go.mod h1:+vhtPC754Xsa23ID7GlGsrdKBp github.com/AzureAD/microsoft-authentication-library-for-go v0.4.0 h1:WVsrXCnHlDDX8ls+tootqRE87/hL9S/g4ewig9RsD/c= github.com/AzureAD/microsoft-authentication-library-for-go v0.4.0/go.mod h1:Vt9sXTKwMyGcOxSmLDMnGPgqsUg7m8pe215qMLrDXw4= github.com/BurntSushi/toml v0.3.1/go.mod h1:xHWCNGjB5oqiDr8zfno3MHue2Ht5sIBksp03qcyfWMU= -github.com/KimMachineGun/automemlimit v0.2.6 h1:tQFriVTcIteUkV5EgU9iz03eDY36T8JU5RAjP2r6Kt0= -github.com/KimMachineGun/automemlimit v0.2.6/go.mod h1:pJhTW/nWJMj6SnWSU2TEKSlCaM+1N5Mej+IfS/5/Ol0= +github.com/KimMachineGun/automemlimit v0.6.1 h1:ILa9j1onAAMadBsyyUJv5cack8Y1WT26yLj/V+ulKp8= +github.com/KimMachineGun/automemlimit v0.6.1/go.mod h1:T7xYht7B8r6AG/AqFcUdc7fzd2bIdBKmepfP2S1svPY= github.com/alecthomas/template v0.0.0-20160405071501-a0175ee3bccc/go.mod h1:LOuyumcjzFXgccqObfd/Ljyb9UuFJ6TxHnclSeseNhc= github.com/alecthomas/template v0.0.0-20190718012654-fb15b899a751/go.mod h1:LOuyumcjzFXgccqObfd/Ljyb9UuFJ6TxHnclSeseNhc= github.com/alecthomas/units v0.0.0-20151022065526-2efee857e7cf/go.mod h1:ybxpYRFXyAe+OPACYpWeL0wqObRcbAqCMya13uyzqw0= @@ -234,6 +234,8 @@ github.com/openzipkin-contrib/zipkin-go-opentracing v0.5.0 h1:uhcF5Jd7rP9DVEL10S github.com/openzipkin-contrib/zipkin-go-opentracing v0.5.0/go.mod h1:+oCZ5GXXr7KPI/DNOQORPTq5AWHfALJj9c72b0+YsEY= github.com/openzipkin/zipkin-go v0.4.2 h1:zjqfqHjUpPmB3c1GlCvvgsM1G4LkvqQbBDueDOCg/jA= github.com/openzipkin/zipkin-go v0.4.2/go.mod h1:ZeVkFjuuBiSy13y8vpSDCjMi9GoI3hPpCJSBx/EYFhY= +github.com/pbnjay/memory v0.0.0-20210728143218-7b4eea64cf58 h1:onHthvaw9LFnH4t2DcNVpwGmV9E1BkGknEliJkfwQj0= +github.com/pbnjay/memory v0.0.0-20210728143218-7b4eea64cf58/go.mod h1:DXv8WO4yhMYhSNPKjeNKa5WY9YCIEBRbNzFFPJbWO6Y= github.com/pkg/browser v0.0.0-20210115035449-ce105d075bb4 h1:Qj1ukM4GlMWXNdMBuXcXfz/Kw9s1qm0CLY32QxuSImI= github.com/pkg/browser v0.0.0-20210115035449-ce105d075bb4/go.mod h1:N6UoU20jOqggOuDwUaBQpluzLNDqif3kq9z2wpdYEfQ= github.com/pkg/errors v0.8.0/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= @@ -442,8 +444,8 @@ google.golang.org/protobuf v1.21.0/go.mod h1:47Nbq4nVaFHyn7ilMalzfO3qCViNmqZ2kzi google.golang.org/protobuf v1.23.0/go.mod h1:EGpADcykh3NcUnDUJcl1+ZksZNG86OlYog2l/sGQquU= google.golang.org/protobuf v1.26.0-rc.1/go.mod h1:jlhhOSvTdKEhbULTjvd4ARK9grFBp09yW+WbY/TyQbw= google.golang.org/protobuf v1.26.0/go.mod h1:9q0QmTI4eRPtz6boOQmLYwt+qCgq0jsYwAQnmE0givc= -google.golang.org/protobuf v1.31.0 h1:g0LDEJHgrBl9N9r17Ru3sqWhkIx2NB67okBHPwC7hs8= -google.golang.org/protobuf v1.31.0/go.mod h1:HV8QOd/L58Z+nl8r43ehVNZIU/HEI6OcFqwMG9pJV4I= +google.golang.org/protobuf v1.33.0 h1:uNO2rsAINq/JlFpSdYEKIZ0uKD/R9cpdv0T+yoGwGmI= +google.golang.org/protobuf v1.33.0/go.mod h1:c6P6GXX6sHbq/GpV6MGZEdwhWPcYBgnhAHhKbcUYpos= gopkg.in/alecthomas/kingpin.v2 v2.2.6/go.mod h1:FMv+mEhP44yOT+4EoQTLFTRgOQ1FBLkstjWtayDeSgw= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= diff --git a/k8sworker/k8soptions.go b/k8sworker/k8soptions.go new file mode 100644 index 0000000..d709139 --- /dev/null +++ b/k8sworker/k8soptions.go @@ -0,0 +1,25 @@ +package k8sworker + +type K8sOptions struct { + + // logger used for GoMaxProcs + logger func(string, ...any) +} + +type K8sOption func(*K8sOptions) + +// WithLogger sets the optional logger for goMaxProcs +func WithLogger(logger func(string, ...any)) K8sOption { + return func(ko *K8sOptions) { ko.logger = logger } +} + +// ParseOptions parses the given options into a K8sOptions struct +func ParseOptions(options ...K8sOption) K8sOptions { + k8sOptions := K8sOptions{} + + for _, option := range options { + option(&k8sOptions) + } + + return k8sOptions +} diff --git a/k8sworker/k8sworker.go b/k8sworker/k8sworker.go new file mode 100644 index 0000000..e91722a --- /dev/null +++ b/k8sworker/k8sworker.go @@ -0,0 +1,99 @@ +package k8sworker + +import ( + "log/slog" + "runtime" + "runtime/debug" + + "github.com/KimMachineGun/automemlimit/memlimit" + "go.uber.org/automaxprocs/maxprocs" +) + +var ( + undoMaxProcs func() +) + +// K8sConfig sets the cpu and memory +// +// go configuration for kubernetes. +type K8sConfig struct { + GoMaxProcs int + + GoMemLimit int64 + + GoVersion string +} + +func NewK8Config(opts ...K8sOption) (*K8sConfig, error) { + + options := ParseOptions(opts...) + + k8Config := K8sConfig{ + GoVersion: runtime.Version(), + } + + // Set CPU quota correctly so that stalls on non-existent cores do not occur. + // This must be done as early as possible on task startup - this way all services + // will have this behaviour as this method is called by everyone.. + // + // Refs: https://groups.google.com/forum/#%21topic/prometheus-users/QPQ-UbtvS44 + // https://github.com/golang/go/issues/19378 + // + // To summarise golang applications in kubernetes suffer from intermittent gc + // pauses when the golang application thinks it has access to more cores than + // really available. This results in intermittently high latency when the the + // gc thread stalls when it cannot access the cores it thinks it has.. Both + // Uber and Google noticed this and the solution is to set GOMAXPROCS to the + // number of cores allocated by Kubernetes. This is obtained from the cgroups + // setting and the logic is encapsulated in the automaxprocs package. + // + // At time of writing. archivist has GOMAXPROCS set to 4 but the kubernetes + // setting is 1. This could result in 75% of CPU cycles being lost when the gc + // thread is stalled. + // + // When load testing is implemented, benchmarks should be run and this code + // modified/removed and/or kubernetes limits set more cleverly. + // + // Please note that the runtime.GOMAXPROCS setting will be removed at some + // future date. + // + // See https://github.com/golang/go/issues/33803 for proposal to make this + // go away so that automaxprocs is no longer reqyuired. + k8Config.GoMaxProcs = runtime.GOMAXPROCS(-1) + + // modified/removed and/or kubernetes limits set more cleverly. + var err error + if options.logger != nil { + + memlimit.SetGoMemLimitWithOpts( + memlimit.WithRatio(0.9), + memlimit.WithProvider(memlimit.FromCgroup), + memlimit.WithLogger(slog.Default()), + ) + + undoMaxProcs, err = maxprocs.Set(maxprocs.Logger(options.logger)) + } else { + + memlimit.SetGoMemLimitWithOpts( + memlimit.WithRatio(0.9), + memlimit.WithProvider(memlimit.FromCgroup), + ) + + undoMaxProcs, err = maxprocs.Set() + } + + if err != nil { + return nil, err + } + + // If AUTOMEMLIMIT is not set, it defaults to 0.9. (10% is the headroom for memory sources the Go runtime is unaware of.) + // If GOMEMLIMIT is already set or AUTOMEMLIMIT=off, automatic setting og GMEMLIMIT is disabled. + k8Config.GoMemLimit = debug.SetMemoryLimit(-1) + + return &k8Config, nil +} + +// Close undoes any changes to GoMaxProcs. +func Close() { + undoMaxProcs() +} diff --git a/logger/logger.go b/logger/logger.go index 61b8570..d480900 100644 --- a/logger/logger.go +++ b/logger/logger.go @@ -5,13 +5,9 @@ import ( "errors" "fmt" "log" - "runtime" - "runtime/debug" "strings" "syscall" - _ "github.com/KimMachineGun/automemlimit" - "go.uber.org/automaxprocs/maxprocs" "go.uber.org/zap" "go.uber.org/zap/zapcore" "go.uber.org/zap/zaptest/observer" @@ -20,11 +16,10 @@ import ( ) var ( - Plain *zap.Logger - Sugar *WrappedLogger - undoLogger func() - undoMaxProcs func() - Recorded *observer.ObservedLogs + Plain *zap.Logger + Sugar *WrappedLogger + undoLogger func() + Recorded *observer.ObservedLogs ) const ( @@ -79,7 +74,6 @@ func (l *WrappedLogger) DebugR(msg string, args ...any) { func OnExit() { _ = Sugar.Sync() _ = Plain.Sync() - undoMaxProcs() undoLogger() Recorded = nil } @@ -198,48 +192,6 @@ func New(level string, opts ...any) { Sugar = &WrappedLogger{ Plain.Sugar(), } - - Sugar.Debugf("Go version %s", runtime.Version()) - // Set CPU quota correctly so that stalls on non-existent cores do not occur. - // This must be done as early as possible on task startup - this way all services - // will have this behaviour as this method is called by everyone.. - // - // Refs: https://groups.google.com/forum/#%21topic/prometheus-users/QPQ-UbtvS44 - // https://github.com/golang/go/issues/19378 - // - // To summarise golang applications in kubernetes suffer from intermittent gc - // pauses when the golang application thinks it has access to more cores than - // really available. This results in intermittently high latency when the the - // gc thread stalls when it cannot access the cores it thinks it has.. Both - // Uber and Google noticed this and the solution is to set GOMAXPROCS to the - // number of cores allocated by Kubernetes. This is obtained from the cgroups - // setting and the logic is encapsulated in the automaxprocs package. - // - // At time of writing. archivist has GOMAXPROCS set to 4 but the kubernetes - // setting is 1. This could result in 75% of CPU cycles being lost when the gc - // thread is stalled. - // - // When load testing is implemented, benchmarks should be run and this code - // modified/removed and/or kubernetes limits set more cleverly. - // - // Please note that the runtime.GOMAXPROCS setting will be removed at some - // future date. - // - // See https://github.com/golang/go/issues/33803 for proposal to make this - // go away so that automaxprocs is no longer reqyuired. - var GOMAXPROCS int = runtime.GOMAXPROCS(-1) - Sugar.Debugf("Cores allocation GOMAXPROCS %v", GOMAXPROCS) - // modified/removed and/or kubernetes limits set more cleverly. - undoMaxProcs, err = maxprocs.Set(maxprocs.Logger(Sugar.Infof)) - if err != nil { - Sugar.Infof("Error for automaxprocs: %v", err) - } - Sugar.Debugf("Cores allocation GOMAXPROCS %v", runtime.GOMAXPROCS(-1)) - - // If AUTOMEMLIMIT is not set, it defaults to 0.9. (10% is the headroom for memory sources the Go runtime is unaware of.) - // If GOMEMLIMIT is already set or AUTOMEMLIMIT=off, automatic setting og GMEMLIMIT is disabled. - var GOMEMLIMIT int64 = debug.SetMemoryLimit(-1) - Sugar.Debugf("Memory Limit GOMEMLIMIT %v", GOMEMLIMIT) } func valueFromCarrier(carrier opentracing.TextMapCarrier, key string) string { diff --git a/startup/run.go b/startup/run.go index c8ece03..5c3bdfc 100644 --- a/startup/run.go +++ b/startup/run.go @@ -6,6 +6,7 @@ import ( "os" "github.com/datatrails/go-datatrails-common/environment" + "github.com/datatrails/go-datatrails-common/k8sworker" "github.com/datatrails/go-datatrails-common/logger" "github.com/datatrails/go-datatrails-common/tracing" ) @@ -17,6 +18,17 @@ func Run(serviceName string, run Runner) { logger.New(environment.GetLogLevel()) log := logger.Sugar.WithServiceName(serviceName) + // ensure we configure go max procs and memlimit + // for kubernetes. + k8Config, err := k8sworker.NewK8Config(k8sworker.WithLogger(log.Infof)) + if err != nil { + log.Infof("Error configuring go for kubernetes: %v", err) + os.Exit(1) + } + + // log the useful kubernetes go configuration + log.Infof("Go Configuration: %+v", k8Config) + exitCode := func() int { var exitCode int closer := tracing.NewTracer() @@ -33,6 +45,10 @@ func Run(serviceName string, run Runner) { log.Infof("Shutting down gracefully") logger.OnExit() + + // ensure we reset go configuration back to normal + k8sworker.Close() + os.Exit(exitCode) } From 234000ad378fe2aea308d947b59e90182a24dd16 Mon Sep 17 00:00:00 2001 From: jgough Date: Tue, 28 May 2024 13:02:18 +0100 Subject: [PATCH 2/2] fixup --- k8sworker/k8sworker.go | 34 ++++++++++++++++++++++------------ 1 file changed, 22 insertions(+), 12 deletions(-) diff --git a/k8sworker/k8sworker.go b/k8sworker/k8sworker.go index e91722a..7c50ab7 100644 --- a/k8sworker/k8sworker.go +++ b/k8sworker/k8sworker.go @@ -32,6 +32,27 @@ func NewK8Config(opts ...K8sOption) (*K8sConfig, error) { GoVersion: runtime.Version(), } + // first set the go mem limit + var err error + if options.logger != nil { + + _, err = memlimit.SetGoMemLimitWithOpts( + memlimit.WithRatio(0.9), + memlimit.WithProvider(memlimit.FromCgroup), + memlimit.WithLogger(slog.Default()), + ) + } else { + + _, err = memlimit.SetGoMemLimitWithOpts( + memlimit.WithRatio(0.9), + memlimit.WithProvider(memlimit.FromCgroup), + ) + } + + if err != nil { + return nil, err + } + // Set CPU quota correctly so that stalls on non-existent cores do not occur. // This must be done as early as possible on task startup - this way all services // will have this behaviour as this method is called by everyone.. @@ -62,23 +83,12 @@ func NewK8Config(opts ...K8sOption) (*K8sConfig, error) { k8Config.GoMaxProcs = runtime.GOMAXPROCS(-1) // modified/removed and/or kubernetes limits set more cleverly. - var err error - if options.logger != nil { - memlimit.SetGoMemLimitWithOpts( - memlimit.WithRatio(0.9), - memlimit.WithProvider(memlimit.FromCgroup), - memlimit.WithLogger(slog.Default()), - ) + if options.logger != nil { undoMaxProcs, err = maxprocs.Set(maxprocs.Logger(options.logger)) } else { - memlimit.SetGoMemLimitWithOpts( - memlimit.WithRatio(0.9), - memlimit.WithProvider(memlimit.FromCgroup), - ) - undoMaxProcs, err = maxprocs.Set() }