From a198c4a968abe8a5722447ac670eec3ae71ba0de Mon Sep 17 00:00:00 2001 From: ajanikow <12255597+ajanikow@users.noreply.github.com> Date: Mon, 11 Jul 2022 11:03:18 +0000 Subject: [PATCH] [Bugfix] Add Panic Handler --- CHANGELOG.md | 1 + docs/generated/metrics/README.md | 1 + ...angodb_operator_engine_panics_recovered.md | 11 ++ internal/metrics.yaml | 11 +- pkg/deployment/reconcile/plan_executor.go | 23 ++- ...angodb_operator_engine_panics_recovered.go | 39 ++++ pkg/logging/logger_test.go | 175 ------------------ pkg/util/errors/panics/error.go | 88 +++++++++ pkg/util/errors/panics/logger.go | 27 +++ pkg/util/errors/panics/metric.go | 90 +++++++++ pkg/util/errors/panics/recovery.go | 35 ++++ pkg/util/errors/panics/recovery_test.go | 76 ++++++++ pkg/util/errors/panics/stack.go | 74 ++++++++ pkg/util/tests/logging.go | 116 ++++++++++++ pkg/util/tests/logging_test.go | 115 ++++++++++++ 15 files changed, 704 insertions(+), 178 deletions(-) create mode 100644 docs/generated/metrics/arangodb_operator_engine_panics_recovered.md create mode 100644 pkg/generated/metric_descriptions/arangodb_operator_engine_panics_recovered.go delete mode 100644 pkg/logging/logger_test.go create mode 100644 pkg/util/errors/panics/error.go create mode 100644 pkg/util/errors/panics/logger.go create mode 100644 pkg/util/errors/panics/metric.go create mode 100644 pkg/util/errors/panics/recovery.go create mode 100644 pkg/util/errors/panics/recovery_test.go create mode 100644 pkg/util/errors/panics/stack.go create mode 100644 pkg/util/tests/logging.go create mode 100644 pkg/util/tests/logging_test.go diff --git a/CHANGELOG.md b/CHANGELOG.md index e94be90f5..d0bd8ac7f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -30,6 +30,7 @@ - (Bugfix) Add DistributeShardsLike support - (Feature) Member restarts metric - (Bugfix) Infinite loop fix in ArangoD AsyncClient +- (Bugfix) Add Panic Handler ## [1.2.13](https://github.com/arangodb/kube-arangodb/tree/1.2.13) (2022-06-07) - (Bugfix) Fix arangosync members state inspection diff --git a/docs/generated/metrics/README.md b/docs/generated/metrics/README.md index 6bf14dab9..f44066473 100644 --- a/docs/generated/metrics/README.md +++ b/docs/generated/metrics/README.md @@ -14,6 +14,7 @@ | [arangodb_operator_agency_cache_member_serving](./arangodb_operator_agency_cache_member_serving.md) | arangodb_operator | agency_cache | Gauge | Determines if agency member is reachable | | [arangodb_operator_agency_cache_present](./arangodb_operator_agency_cache_present.md) | arangodb_operator | agency_cache | Gauge | Determines if local agency cache is present | | [arangodb_operator_agency_cache_serving](./arangodb_operator_agency_cache_serving.md) | arangodb_operator | agency_cache | Gauge | Determines if agency is serving | +| [arangodb_operator_engine_panics_recovered](./arangodb_operator_engine_panics_recovered.md) | arangodb_operator | engine | Counter | Number of Panics recovered inside Operator reconciliation loop | | [arangodb_operator_members_unexpected_container_exit_codes](./arangodb_operator_members_unexpected_container_exit_codes.md) | arangodb_operator | members | Counter | Counter of unexpected restarts in pod (Containers/InitContainers/EphemeralContainers) | | [arangodb_operator_rebalancer_enabled](./arangodb_operator_rebalancer_enabled.md) | arangodb_operator | rebalancer | Gauge | Determines if rebalancer is enabled | | [arangodb_operator_rebalancer_moves_current](./arangodb_operator_rebalancer_moves_current.md) | arangodb_operator | rebalancer | Gauge | Define how many moves are currently in progress | diff --git a/docs/generated/metrics/arangodb_operator_engine_panics_recovered.md b/docs/generated/metrics/arangodb_operator_engine_panics_recovered.md new file mode 100644 index 000000000..e67a5ddcf --- /dev/null +++ b/docs/generated/metrics/arangodb_operator_engine_panics_recovered.md @@ -0,0 +1,11 @@ +# arangodb_operator_engine_panics_recovered (Counter) + +## Description + +Number of Panics recovered inside Operator reconciliation loop. Section represents recovery section + +## Labels + +| Label | Description | +|:-------:|:--------------| +| section | Panic Section | diff --git a/internal/metrics.yaml b/internal/metrics.yaml index c6cfe15ae..8650bd0d0 100644 --- a/internal/metrics.yaml +++ b/internal/metrics.yaml @@ -166,4 +166,13 @@ namespaces: - key: container_type description: "Container/InitContainer/EphemeralContainer" - key: code - description: "ExitCode" \ No newline at end of file + description: "ExitCode" + engine: + panics_recovered: + shortDescription: "Number of Panics recovered inside Operator reconciliation loop" + description: "Number of Panics recovered inside Operator reconciliation loop. Section represents recovery section" + type: "Counter" + labels: + - key: section + description: "Panic Section" + \ No newline at end of file diff --git a/pkg/deployment/reconcile/plan_executor.go b/pkg/deployment/reconcile/plan_executor.go index de46b57d9..b72821186 100644 --- a/pkg/deployment/reconcile/plan_executor.go +++ b/pkg/deployment/reconcile/plan_executor.go @@ -30,6 +30,7 @@ import ( api "github.com/arangodb/kube-arangodb/pkg/apis/deployment/v1" "github.com/arangodb/kube-arangodb/pkg/metrics" "github.com/arangodb/kube-arangodb/pkg/util/errors" + "github.com/arangodb/kube-arangodb/pkg/util/errors/panics" "github.com/arangodb/kube-arangodb/pkg/util/k8sutil" ) @@ -305,7 +306,7 @@ func (d *Reconciler) executeAction(ctx context.Context, planAction api.Action, a if !planAction.IsStarted() { // Not started yet - ready, err := action.Start(ctx) + ready, err := d.executeActionStart(ctx, action) if err != nil { if g := getStartFailureGracePeriod(action); g > 0 && !planAction.CreationTime.IsZero() { if time.Since(planAction.CreationTime.Time) < g { @@ -333,7 +334,7 @@ func (d *Reconciler) executeAction(ctx context.Context, planAction api.Action, a } // First action of plan has been started, check its progress - ready, abort, err := action.CheckProgress(ctx) + ready, abort, err := d.executeActionCheckProgress(ctx, action) if err != nil { log.Err(err).Debug("Failed to check action progress") return false, false, false, false, errors.WithStack(err) @@ -362,6 +363,24 @@ func (d *Reconciler) executeAction(ctx context.Context, planAction api.Action, a return false, false, true, false, nil } +func (d *Reconciler) executeActionCheckProgress(ctx context.Context, action Action) (ready bool, abort bool, retErr error) { + retErr = panics.RecoverWithSection("ActionProgress", func() (err error) { + ready, abort, err = action.CheckProgress(ctx) + return + }) + + return +} + +func (d *Reconciler) executeActionStart(ctx context.Context, action Action) (done bool, retErr error) { + retErr = panics.RecoverWithSection("ActionStart", func() (err error) { + done, err = action.Start(ctx) + return + }) + + return +} + // createAction create action object based on action type func (d *Reconciler) createAction(action api.Action) (Action, ActionContext) { actionCtx := newActionContext(d.log, d.context, &d.metrics) diff --git a/pkg/generated/metric_descriptions/arangodb_operator_engine_panics_recovered.go b/pkg/generated/metric_descriptions/arangodb_operator_engine_panics_recovered.go new file mode 100644 index 000000000..2e9ac64aa --- /dev/null +++ b/pkg/generated/metric_descriptions/arangodb_operator_engine_panics_recovered.go @@ -0,0 +1,39 @@ +// +// DISCLAIMER +// +// Copyright 2016-2022 ArangoDB GmbH, Cologne, Germany +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +// +// Copyright holder is ArangoDB GmbH, Cologne, Germany +// + +package metric_descriptions + +import "github.com/arangodb/kube-arangodb/pkg/util/metrics" + +var ( + arangodbOperatorEnginePanicsRecovered = metrics.NewDescription("arangodb_operator_engine_panics_recovered", "Number of Panics recovered inside Operator reconciliation loop", []string{`section`}, nil) +) + +func init() { + registerDescription(arangodbOperatorEnginePanicsRecovered) +} + +func ArangodbOperatorEnginePanicsRecovered() metrics.Description { + return arangodbOperatorEnginePanicsRecovered +} + +func ArangodbOperatorEnginePanicsRecoveredCounter(value float64, section string) metrics.Metric { + return ArangodbOperatorEnginePanicsRecovered().Gauge(value, section) +} \ No newline at end of file diff --git a/pkg/logging/logger_test.go b/pkg/logging/logger_test.go deleted file mode 100644 index d40c6cd57..000000000 --- a/pkg/logging/logger_test.go +++ /dev/null @@ -1,175 +0,0 @@ -// -// DISCLAIMER -// -// Copyright 2016-2022 ArangoDB GmbH, Cologne, Germany -// -// Licensed under the Apache License, Version 2.0 (the "License"); -// you may not use this file except in compliance with the License. -// You may obtain a copy of the License at -// -// http://www.apache.org/licenses/LICENSE-2.0 -// -// Unless required by applicable law or agreed to in writing, software -// distributed under the License is distributed on an "AS IS" BASIS, -// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -// See the License for the specific language governing permissions and -// limitations under the License. -// -// Copyright holder is ArangoDB GmbH, Cologne, Germany -// - -package logging - -import ( - "bytes" - "encoding/json" - "testing" - "time" - - "github.com/rs/zerolog" - "github.com/stretchr/testify/require" -) - -func logScanner() (Factory, <-chan string, func()) { - b := bytes.NewBuffer(nil) - l := zerolog.New(b) - f := NewFactory(l) - - out := make(chan string) - - closer := make(chan struct{}) - - go func() { - defer close(out) - t := time.NewTicker(time.Millisecond) - defer t.Stop() - - z := "" - - for { - for b.Len() > 0 { - q, _, _ := b.ReadRune() - if q == '\n' { - out <- z - z = "" - } else { - z = z + string(q) - } - } - - select { - case <-closer: - return - case <-t.C: - } - } - }() - - return f, out, func() { - close(closer) - } -} - -func readData(in <-chan string) (string, bool) { - t := time.NewTimer(100 * time.Millisecond) - defer t.Stop() - - select { - case text := <-in: - return text, true - case <-t.C: - return "", false - } -} - -func expectTimeout(t *testing.T, in <-chan string) { - _, ok := readData(in) - require.False(t, ok, "Data should be not present") -} - -func expectData(t *testing.T, in <-chan string) { - s, ok := readData(in) - require.True(t, ok, "Data should be present") - - var q map[string]string - - require.NoError(t, json.Unmarshal([]byte(s), &q)) -} - -func Test_Logger(t *testing.T) { - f, data, c := logScanner() - defer c() - - q := f.Get("foo") - - t.Run("Run on unregistered logger", func(t *testing.T) { - q.Info("Data") - - expectTimeout(t, data) - }) - - t.Run("Register logger", func(t *testing.T) { - f.RegisterLogger("foo", Info) - }) - - t.Run("Run on registered logger", func(t *testing.T) { - q.Info("Data") - - expectData(t, data) - }) - - t.Run("Run on too low log level logger", func(t *testing.T) { - q.Debug("Data") - - expectTimeout(t, data) - }) - - t.Run("Change log level", func(t *testing.T) { - f.ApplyLogLevels(map[string]Level{ - "foo": Debug, - }) - - q.Debug("Data") - - expectData(t, data) - - require.Equal(t, Debug, f.LogLevels()["foo"]) - }) - - t.Run("Change all log levels", func(t *testing.T) { - f.ApplyLogLevels(map[string]Level{ - "all": Info, - }) - - q.Debug("Data") - - expectTimeout(t, data) - - require.Equal(t, Info, f.LogLevels()["foo"]) - }) - - t.Run("Change invalid level", func(t *testing.T) { - f.ApplyLogLevels(map[string]Level{ - "invalid": Info, - }) - - q.Debug("Data") - - expectTimeout(t, data) - - require.Equal(t, Info, f.LogLevels()["foo"]) - }) - - t.Run("Change all log levels with override", func(t *testing.T) { - f.ApplyLogLevels(map[string]Level{ - "all": Debug, - "foo": Info, - }) - - q.Debug("Data") - - expectTimeout(t, data) - - require.Equal(t, Info, f.LogLevels()["foo"]) - }) -} diff --git a/pkg/util/errors/panics/error.go b/pkg/util/errors/panics/error.go new file mode 100644 index 000000000..6a4e04543 --- /dev/null +++ b/pkg/util/errors/panics/error.go @@ -0,0 +1,88 @@ +// +// DISCLAIMER +// +// Copyright 2016-2022 ArangoDB GmbH, Cologne, Germany +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +// +// Copyright holder is ArangoDB GmbH, Cologne, Germany +// + +package panics + +import ( + "time" + + "github.com/arangodb/kube-arangodb/pkg/util/errors" + "github.com/arangodb/kube-arangodb/pkg/version" +) + +type PanicErrorDetails struct { + OperatorVersion version.InfoV1 + + Time time.Time +} + +type PanicError interface { + error + + Details() PanicErrorDetails + PanicCause() interface{} + Stack() StackEntries +} + +func IsPanicError(err error) (PanicError, bool) { + if err == nil { + return nil, false + } + + if e, ok := err.(PanicError); ok { + return e, true + } + + return IsPanicError(errors.CauseWithNil(err)) +} + +func newPanicError(cause interface{}, stack StackEntries) PanicError { + return panicError{ + cause: cause, + stack: stack, + details: PanicErrorDetails{ + OperatorVersion: version.GetVersionV1(), + Time: time.Now(), + }, + } +} + +type panicError struct { + cause interface{} + + stack StackEntries + details PanicErrorDetails +} + +func (p panicError) Details() PanicErrorDetails { + return p.details +} + +func (p panicError) PanicCause() interface{} { + return p.cause +} + +func (p panicError) Stack() StackEntries { + return p.stack +} + +func (p panicError) Error() string { + return "Panic Received" +} diff --git a/pkg/util/errors/panics/logger.go b/pkg/util/errors/panics/logger.go new file mode 100644 index 000000000..b60730c48 --- /dev/null +++ b/pkg/util/errors/panics/logger.go @@ -0,0 +1,27 @@ +// +// DISCLAIMER +// +// Copyright 2016-2022 ArangoDB GmbH, Cologne, Germany +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +// +// Copyright holder is ArangoDB GmbH, Cologne, Germany +// + +package panics + +import "github.com/arangodb/kube-arangodb/pkg/logging" + +var ( + logger = logging.Global().RegisterAndGetLogger("panics", logging.Error) +) diff --git a/pkg/util/errors/panics/metric.go b/pkg/util/errors/panics/metric.go new file mode 100644 index 000000000..e348b9dea --- /dev/null +++ b/pkg/util/errors/panics/metric.go @@ -0,0 +1,90 @@ +// +// DISCLAIMER +// +// Copyright 2016-2022 ArangoDB GmbH, Cologne, Germany +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +// +// Copyright holder is ArangoDB GmbH, Cologne, Germany +// + +package panics + +import ( + "sync" + + "github.com/prometheus/client_golang/prometheus" + + "github.com/arangodb/kube-arangodb/pkg/generated/metric_descriptions" + "github.com/arangodb/kube-arangodb/pkg/logging" + "github.com/arangodb/kube-arangodb/pkg/util/metrics" +) + +func init() { + prometheus.MustRegister(panicsReceived) +} + +var ( + panicsReceived = &panicsReceiver{ + panics: map[string]uint{}, + } +) + +type panicsReceiver struct { + panics map[string]uint + lock sync.Mutex +} + +func (p *panicsReceiver) Describe(descs chan<- *prometheus.Desc) { + +} + +func (p *panicsReceiver) Collect(c chan<- prometheus.Metric) { + p.lock.Lock() + defer p.lock.Unlock() + + out := metrics.NewPushMetric(c) + + for k, v := range p.panics { + out.Push(metric_descriptions.ArangodbOperatorEnginePanicsRecoveredCounter(float64(v), k)) + } +} + +func (p *panicsReceiver) register(section string) { + p.lock.Lock() + defer p.lock.Unlock() + + p.panics[section] = p.panics[section] + 1 +} + +func recoverWithSection(log logging.Logger, section string, in func() error) error { + err := recoverPanic(5, in) + + if err != nil { + if perr, ok := IsPanicError(err); ok { + panicsReceived.register(section) + + log.Strs("stack", perr.Stack().String()...).Str("section", section).Error("Panic Recovered") + } + } + + return err +} + +func RecoverWithSection(section string, in func() error) error { + return recoverWithSection(logger, section, in) +} + +func RecoverWithSectionL(log logging.Logger, section string, in func() error) error { + return recoverWithSection(log, section, in) +} diff --git a/pkg/util/errors/panics/recovery.go b/pkg/util/errors/panics/recovery.go new file mode 100644 index 000000000..3a54e4f05 --- /dev/null +++ b/pkg/util/errors/panics/recovery.go @@ -0,0 +1,35 @@ +// +// DISCLAIMER +// +// Copyright 2016-2022 ArangoDB GmbH, Cologne, Germany +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +// +// Copyright holder is ArangoDB GmbH, Cologne, Germany +// + +package panics + +func recoverPanic(skipFrames int, in func() error) (err error) { + defer func() { + if r := recover(); r != nil { + err = newPanicError(r, GetStack(skipFrames)) + } + }() + + return in() +} + +func Recover(in func() error) (err error) { + return recoverPanic(4, in) +} diff --git a/pkg/util/errors/panics/recovery_test.go b/pkg/util/errors/panics/recovery_test.go new file mode 100644 index 000000000..1f89d6f7f --- /dev/null +++ b/pkg/util/errors/panics/recovery_test.go @@ -0,0 +1,76 @@ +// +// DISCLAIMER +// +// Copyright 2016-2022 ArangoDB GmbH, Cologne, Germany +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +// +// Copyright holder is ArangoDB GmbH, Cologne, Germany +// + +package panics + +import ( + "testing" + "time" + + "github.com/stretchr/testify/require" + + "github.com/arangodb/kube-arangodb/pkg/logging" + "github.com/arangodb/kube-arangodb/pkg/util/tests" +) + +func Test_Panic(t *testing.T) { + tests.WithLogScanner(t, "Panic", func(t *testing.T, s tests.LogScanner) { + g := s.Factory().RegisterAndGetLogger("panic", logging.Error) + err := RecoverWithSectionL(g, "foo", func() error { + panic(3) + }) + + d, ok := IsPanicError(err) + + require.True(t, ok) + + var data map[string]interface{} + + require.True(t, s.GetData(t, 100*time.Millisecond, &data)) + t.Run("stack", func(t *testing.T) { + require.Contains(t, data, "stack") + + stack, ok := data["stack"].([]interface{}) + require.True(t, ok) + + require.Len(t, stack, len(d.Stack())) + + for id := range stack { + s, ok := stack[id].(string) + require.True(t, ok) + + require.Equal(t, d.Stack()[id].String(), s) + } + }) + + t.Run("section", func(t *testing.T) { + require.Contains(t, data, "section") + + s, ok := data["section"].(string) + require.True(t, ok) + + require.Equal(t, "foo", s) + }) + + t.Run("value", func(t *testing.T) { + require.EqualValues(t, 3, d.PanicCause()) + }) + }) +} diff --git a/pkg/util/errors/panics/stack.go b/pkg/util/errors/panics/stack.go new file mode 100644 index 000000000..7b823fb77 --- /dev/null +++ b/pkg/util/errors/panics/stack.go @@ -0,0 +1,74 @@ +// +// DISCLAIMER +// +// Copyright 2016-2022 ArangoDB GmbH, Cologne, Germany +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +// +// Copyright holder is ArangoDB GmbH, Cologne, Germany +// + +package panics + +import ( + "fmt" + "runtime" +) + +func GetStack(skip int) StackEntries { + frames := make([]uintptr, 30) + + f := runtime.Callers(skip, frames) + fr := runtime.CallersFrames(frames[0:f]) + ret := make(StackEntries, f) + + id := 0 + for { + f, ok := fr.Next() + if !ok { + ret = ret[0:id] + break + } + + ret[id] = StackEntry{ + File: f.File, + Function: f.Function, + Line: f.Line, + } + + id++ + } + + return ret +} + +type StackEntries []StackEntry + +func (s StackEntries) String() []string { + r := make([]string, len(s)) + + for id := range s { + r[id] = s[id].String() + } + + return r +} + +type StackEntry struct { + File, Function string + Line int +} + +func (s StackEntry) String() string { + return fmt.Sprintf("%s:%d - %s()", s.File, s.Line, s.Function) +} diff --git a/pkg/util/tests/logging.go b/pkg/util/tests/logging.go new file mode 100644 index 000000000..e5bf51c58 --- /dev/null +++ b/pkg/util/tests/logging.go @@ -0,0 +1,116 @@ +// +// DISCLAIMER +// +// Copyright 2016-2022 ArangoDB GmbH, Cologne, Germany +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +// +// Copyright holder is ArangoDB GmbH, Cologne, Germany +// + +package tests + +import ( + "bytes" + "encoding/json" + "testing" + "time" + + "github.com/rs/zerolog" + "github.com/stretchr/testify/require" + + "github.com/arangodb/kube-arangodb/pkg/logging" +) + +type LogScanner interface { + Factory() logging.Factory + + Get(timeout time.Duration) (string, bool) + GetData(t *testing.T, timeout time.Duration, obj interface{}) bool +} + +type logScanner struct { + factory logging.Factory + + in <-chan string +} + +func (l *logScanner) GetData(t *testing.T, timeout time.Duration, obj interface{}) bool { + if s, ok := l.Get(timeout); !ok { + return false + } else { + require.NoError(t, json.Unmarshal([]byte(s), obj)) + return true + } +} + +func (l *logScanner) Factory() logging.Factory { + return l.factory +} + +func (l *logScanner) Get(timeout time.Duration) (string, bool) { + t := time.NewTicker(timeout) + defer t.Stop() + + for { + select { + case text := <-l.in: + return text, true + case <-t.C: + return "", false + } + } +} + +func WithLogScanner(t *testing.T, name string, in func(t *testing.T, s LogScanner)) { + t.Run(name, func(t *testing.T) { + b := bytes.NewBuffer(nil) + l := zerolog.New(b) + f := logging.NewFactory(l) + + out := make(chan string) + + closer := make(chan struct{}) + + go func() { + defer close(out) + t := time.NewTicker(time.Millisecond) + defer t.Stop() + + z := "" + + for { + for b.Len() > 0 { + q, _, _ := b.ReadRune() + if q == '\n' { + out <- z + z = "" + } else { + z = z + string(q) + } + } + + select { + case <-closer: + return + case <-t.C: + } + } + }() + + in(t, &logScanner{ + factory: f, + in: out, + }) + }) +} diff --git a/pkg/util/tests/logging_test.go b/pkg/util/tests/logging_test.go new file mode 100644 index 000000000..b962d0cb5 --- /dev/null +++ b/pkg/util/tests/logging_test.go @@ -0,0 +1,115 @@ +// +// DISCLAIMER +// +// Copyright 2016-2022 ArangoDB GmbH, Cologne, Germany +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +// +// Copyright holder is ArangoDB GmbH, Cologne, Germany +// + +package tests + +import ( + "testing" + "time" + + "github.com/stretchr/testify/require" + + "github.com/arangodb/kube-arangodb/pkg/logging" +) + +func Test_Logger(t *testing.T) { + WithLogScanner(t, "Logger", func(t *testing.T, s LogScanner) { + f := s.Factory() + q := f.Get("foo") + + t.Run("Run on unregistered logger", func(t *testing.T) { + q.Info("Data") + + _, ok := s.Get(100 * time.Millisecond) + require.False(t, ok) + }) + + t.Run("Register logger", func(t *testing.T) { + f.RegisterLogger("foo", logging.Info) + }) + + t.Run("Run on registered logger", func(t *testing.T) { + q.Info("Data") + + _, ok := s.Get(100 * time.Millisecond) + require.True(t, ok) + }) + + t.Run("Run on too low log level logger", func(t *testing.T) { + q.Debug("Data") + + _, ok := s.Get(100 * time.Millisecond) + require.False(t, ok) + }) + + t.Run("Change log level", func(t *testing.T) { + f.ApplyLogLevels(map[string]logging.Level{ + "foo": logging.Debug, + }) + + q.Debug("Data") + + _, ok := s.Get(100 * time.Millisecond) + require.True(t, ok) + + require.Equal(t, logging.Debug, f.LogLevels()["foo"]) + }) + + t.Run("Change all log levels", func(t *testing.T) { + f.ApplyLogLevels(map[string]logging.Level{ + "all": logging.Info, + }) + + q.Debug("Data") + + _, ok := s.Get(100 * time.Millisecond) + require.False(t, ok) + + require.Equal(t, logging.Info, f.LogLevels()["foo"]) + }) + + t.Run("Change invalid level", func(t *testing.T) { + f.ApplyLogLevels(map[string]logging.Level{ + "invalid": logging.Info, + }) + + q.Debug("Data") + + _, ok := s.Get(100 * time.Millisecond) + require.False(t, ok) + + require.Equal(t, logging.Info, f.LogLevels()["foo"]) + }) + + t.Run("Change all log levels with override", func(t *testing.T) { + f.ApplyLogLevels(map[string]logging.Level{ + "all": logging.Debug, + "foo": logging.Info, + }) + + q.Debug("Data") + + _, ok := s.Get(100 * time.Millisecond) + require.False(t, ok) + + require.Equal(t, logging.Info, f.LogLevels()["foo"]) + }) + }) +}