diff --git a/echo/builder_test.go b/echo/builder_test.go index 8f02d87..891cd89 100644 --- a/echo/builder_test.go +++ b/echo/builder_test.go @@ -14,11 +14,12 @@ package echo import ( + "net" "net/http" "net/http/httptest" "testing" - "github.com/labstack/echo/v4" + "github.com/labstack/echo/v5" "github.com/prometheus/client_golang/prometheus" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" @@ -27,7 +28,7 @@ import ( type helloRegister struct{} func (h *helloRegister) RegisterRoute(e *echo.Echo) { - e.GET("/hello", func(c echo.Context) error { + e.GET("/hello", func(c *echo.Context) error { return c.NoContent(http.StatusOK) }) } @@ -90,3 +91,55 @@ func TestBuilder_MetricsRegistrationError(t *testing.T) { Build() assert.Error(t, err) } + +type clientRegister struct{} + +func (r *clientRegister) RegisterRoute(e *echo.Echo) { + e.GET("/client", func(c *echo.Context) error { + return c.String(http.StatusOK, c.Scheme()+" "+c.RealIP()) + }) +} + +func TestBuilder_IPAndSchemeExtractors(t *testing.T) { + _, proxyNetwork, err := net.ParseCIDR("203.0.113.0/24") + require.NoError(t, err) + tests := []struct { + name string + configure func(b *Builder) + // expected is the scheme and the IP address of the client, as seen by the handler. + expected string + }{ + { + // The forwarding headers can be spoofed by any client, so they are not trusted from a public address by default. + name: "default", + configure: func(*Builder) {}, + expected: "http 203.0.113.10", + }, + { + name: "trusted proxy", + configure: func(b *Builder) { + b.IPExtractor(echo.ExtractIPFromXFFHeader(echo.TrustIPRange(proxyNetwork))). + SchemeExtractor(echo.ExtractSchemeFromHeaders(echo.TrustIPRange(proxyNetwork))) + }, + expected: "https 198.51.100.7", + }, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + builder := NewBuilder().APIRegistration(&clientRegister{}).OverrideDefaultMiddleware(true) + tt.configure(builder) + handler, err := builder.BuildHandler() + require.NoError(t, err) + + // The request comes from a proxy with a public address (like a cloud load balancer). + req := httptest.NewRequest(http.MethodGet, "/client", nil) + req.RemoteAddr = "203.0.113.10:1234" + req.Header.Set(echo.HeaderXForwardedFor, "198.51.100.7") + req.Header.Set(echo.HeaderXForwardedProto, "https") + rec := httptest.NewRecorder() + handler.ServeHTTP(rec, req) + require.Equal(t, http.StatusOK, rec.Code) + assert.Equal(t, tt.expected, rec.Body.String()) + }) + } +} diff --git a/echo/error_handler.go b/echo/error_handler.go new file mode 100644 index 0000000..96c9b76 --- /dev/null +++ b/echo/error_handler.go @@ -0,0 +1,85 @@ +// Copyright The Perses Authors +// 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. + +package echo + +import ( + "context" + "errors" + + "github.com/labstack/echo/v5" + "github.com/labstack/echo/v5/middleware" + "github.com/sirupsen/logrus" + + persesMiddleware "github.com/perses/common/echo/middleware" +) + +var defaultHTTPErrorHandler = echo.DefaultHTTPErrorHandler(false) + +// contextKeyRequestContext is the key of the echo context in which saveRequestContext saves the context of the request. +const contextKeyRequestContext = "github.com/perses/common/echo.requestContext" + +// saveRequestContext is a middleware, executed before every other one, that saves the context of the request as received +// by the server. The middlewares and the handlers can replace the context of the request (like the middleware ContextTimeout, +// which cancels its own context once the request is handled), so only this one tells if the client went away. +func saveRequestContext(next echo.HandlerFunc) echo.HandlerFunc { + return func(c *echo.Context) error { + c.Set(contextKeyRequestContext, c.Request().Context()) + return next(c) + } +} + +// requestContext returns the context of the request as received by the server (see saveRequestContext). +func requestContext(c *echo.Context) context.Context { + if ctx, ok := c.Get(contextKeyRequestContext).(context.Context); ok { + return ctx + } + return c.Request().Context() +} + +// handleError is the central error handler of the server, called with the error returned by the middleware chain. +// The panics recovered by the middleware Recover and the errors that don't carry an HTTP status (unexpected errors) +// are logged, as nothing turned them into a response. Then, like the default echo handler, it writes the error as a JSON +// response without exposing the internal errors. +func handleError(c *echo.Context, err error) { + // A panic is checked first: its value can carry an HTTP status (like panic(echo.NewHTTPError(...))). + if panicErr, ok := errors.AsType[*middleware.PanicStackError](err); ok { + requestLogEntry(c).WithError(panicErr.Err).WithField("stack", string(panicErr.Stack)).Error("panic recovered while handling the request") + } else if echo.StatusCode(err) == 0 { + requestLogEntry(c).WithError(err).Log(unexpectedErrorLevel(c, err), "unexpected error while handling the request") + } + defaultHTTPErrorHandler(c, err) +} + +// requestLogEntry returns a log entry describing the request like the access log: with the method and the escaped path +// of the request as received, as the handlers can rewrite them (see persesMiddleware.RequestMethod and RequestPath). +func requestLogEntry(c *echo.Context) *logrus.Entry { + return logrus.WithFields(logrus.Fields{ + "method": persesMiddleware.RequestMethod(c), + "uri": persesMiddleware.RequestPath(c), + }) +} + +// unexpectedErrorLevel returns the level of the log of an unexpected error. +// The error is less severe when it is caused by the client that went away, or when the response is already sent. +func unexpectedErrorLevel(c *echo.Context, err error) logrus.Level { + if errors.Is(err, context.Canceled) && requestContext(c).Err() != nil { + // The request is canceled when the client closes the connection, and the error is caused by this cancellation. + return logrus.DebugLevel + } + if response, _ := echo.UnwrapResponse(c.Response()); response != nil && response.Committed { + // The client already received the status of the response, which the error cannot change anymore. + return logrus.WarnLevel + } + return logrus.ErrorLevel +} diff --git a/echo/error_handler_test.go b/echo/error_handler_test.go new file mode 100644 index 0000000..3534d03 --- /dev/null +++ b/echo/error_handler_test.go @@ -0,0 +1,357 @@ +// Copyright The Perses Authors +// 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. + +package echo + +import ( + "context" + "errors" + "io" + "net/http" + "net/http/httptest" + "regexp" + "strconv" + "testing" + "time" + + echoLib "github.com/labstack/echo/v5" + "github.com/labstack/echo/v5/middleware" + "github.com/prometheus/client_golang/prometheus" + "github.com/sirupsen/logrus" + logrustest "github.com/sirupsen/logrus/hooks/test" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// newLogHook captures the logs of the standard logrus logger, at every level, until the end of the test. +// The logs are not written to the output during the test. +func newLogHook(t *testing.T) *logrustest.Hook { + t.Helper() + logger := logrus.StandardLogger() + origHooks := logger.ReplaceHooks(make(logrus.LevelHooks)) + origLevel := logger.GetLevel() + origOutput := logger.Out + logger.SetLevel(logrus.TraceLevel) + logger.SetOutput(io.Discard) + t.Cleanup(func() { + logger.ReplaceHooks(origHooks) + logger.SetLevel(origLevel) + logger.SetOutput(origOutput) + }) + return logrustest.NewLocal(logger) +} + +// findLogEntry returns the first entry captured by the hook with the given message. +func findLogEntry(hook *logrustest.Hook, message string) *logrus.Entry { + for _, entry := range hook.AllEntries() { + if entry.Message == message { + return entry + } + } + return nil +} + +// counterValue returns the value of the counter with the given name and labels, or 0 if it doesn't exist. +func counterValue(t *testing.T, registry *prometheus.Registry, name string, labels map[string]string) float64 { + t.Helper() + families, err := registry.Gather() + require.NoError(t, err) + for _, family := range families { + if family.GetName() != name { + continue + } + for _, metric := range family.GetMetric() { + matched := 0 + for _, label := range metric.GetLabel() { + if value, ok := labels[label.GetName()]; ok && value == label.GetValue() { + matched++ + } + } + if matched == len(labels) { + return metric.GetCounter().GetValue() + } + } + } + return 0 +} + +type errorRegister struct{} + +func (r *errorRegister) RegisterRoute(e *echoLib.Echo) { + e.GET("/panic", func(_ *echoLib.Context) error { + panic("boom") + }) + e.GET("/panic-http-error", func(_ *echoLib.Context) error { + panic(echoLib.NewHTTPError(http.StatusServiceUnavailable, "maintenance")) + }) + // Like a reverse proxy, these handlers modify the path of the request before failing. + e.GET("/rewrite-then-panic", func(c *echoLib.Context) error { + c.Request().URL.Path = "/rewritten" + panic("boom") + }) + e.GET("/rewrite-then-fail", func(c *echoLib.Context) error { + c.Request().URL.Path = "/rewritten" + return errors.New("unexpected failure") + }) + e.GET("/rewrite-method-then-fail", func(c *echoLib.Context) error { + c.Request().Method = http.MethodPost + return errors.New("unexpected failure") + }) + e.GET("/unexpected", func(_ *echoLib.Context) error { + return errors.New("unexpected failure") + }) + e.GET("/fail-after-response", func(c *echoLib.Context) error { + if err := c.JSON(http.StatusOK, map[string]string{"message": "partial"}); err != nil { + return err + } + return errors.New("unexpected failure") + }) + // Like a handler calling a datasource, the error is caused by the cancellation of the request when the client went away. + e.GET("/canceled", func(c *echoLib.Context) error { + return c.Request().Context().Err() + }) + // Like a handler aborting its own work, the handler cancels the context of the request, while the client is still there. + e.GET("/canceled-by-the-server", func(c *echoLib.Context) error { + ctx, cancel := context.WithCancel(c.Request().Context()) + c.SetRequest(c.Request().WithContext(ctx)) + cancel() + return ctx.Err() + }) + e.GET("/unauthorized", func(_ *echoLib.Context) error { + return echoLib.NewHTTPError(http.StatusUnauthorized, "missing token") + }) + e.GET("/bad-gateway", func(_ *echoLib.Context) error { + return echoLib.NewHTTPError(http.StatusBadGateway, "datasource unreachable") + }) +} + +// goroutineHeader matches the first line of the stack of a goroutine (like "goroutine 7 [running]:"). +var goroutineHeader = regexp.MustCompile(`(?m)^goroutine \d+ \[`) + +func TestServer_ErrorHandling(t *testing.T) { + tests := []struct { + name string + path string + route string + // canceled cancels the request before it is handled, like when the client went away. + canceled bool + // middlewares are added after the default ones. + middlewares []echoLib.MiddlewareFunc + expectedCode int + expectedBody string + // expectedError is the message of the error logged (if any) with the level expectedLevel. + expectedError string + expectedLevel logrus.Level + // expectedPanic is the error of the panic logged with its stack trace. + expectedPanic string + }{ + { + name: "panic", + path: "/panic", + route: "/panic", + expectedCode: http.StatusInternalServerError, + expectedBody: `{"message":"Internal Server Error"}`, + expectedError: "panic recovered while handling the request", + expectedLevel: logrus.ErrorLevel, + expectedPanic: "boom", + }, + { + // The value of the panic carries an HTTP status, it must be logged as a panic anyway. + name: "panic with an HTTP error", + path: "/panic-http-error", + route: "/panic-http-error", + expectedCode: http.StatusServiceUnavailable, + expectedBody: `{"message":"maintenance"}`, + expectedError: "panic recovered while handling the request", + expectedLevel: logrus.ErrorLevel, + expectedPanic: echoLib.NewHTTPError(http.StatusServiceUnavailable, "maintenance").Error(), + }, + { + // The error log and the access log use the path requested by the client. + name: "panic after the path is rewritten", + path: "/rewrite-then-panic", + route: "/rewrite-then-panic", + expectedCode: http.StatusInternalServerError, + expectedBody: `{"message":"Internal Server Error"}`, + expectedError: "panic recovered while handling the request", + expectedLevel: logrus.ErrorLevel, + expectedPanic: "boom", + }, + { + name: "unexpected error after the path is rewritten", + path: "/rewrite-then-fail", + route: "/rewrite-then-fail", + expectedCode: http.StatusInternalServerError, + expectedBody: `{"message":"Internal Server Error"}`, + expectedError: "unexpected error while handling the request", + expectedLevel: logrus.ErrorLevel, + }, + { + // Like a proxy, the handler rewrites the method: the logs and the metrics use the method received. + name: "unexpected error after the method is rewritten", + path: "/rewrite-method-then-fail", + route: "/rewrite-method-then-fail", + expectedCode: http.StatusInternalServerError, + expectedBody: `{"message":"Internal Server Error"}`, + expectedError: "unexpected error while handling the request", + expectedLevel: logrus.ErrorLevel, + }, + { + name: "unexpected error", + path: "/unexpected", + route: "/unexpected", + expectedCode: http.StatusInternalServerError, + expectedBody: `{"message":"Internal Server Error"}`, + expectedError: "unexpected error while handling the request", + expectedLevel: logrus.ErrorLevel, + }, + { + // The middleware ContextTimeout cancels its own context once the request is handled: the client didn't go away. + name: "unexpected error with a middleware canceling its context", + path: "/unexpected", + route: "/unexpected", + middlewares: []echoLib.MiddlewareFunc{middleware.ContextTimeout(time.Minute)}, + expectedCode: http.StatusInternalServerError, + expectedBody: `{"message":"Internal Server Error"}`, + expectedError: "unexpected error while handling the request", + expectedLevel: logrus.ErrorLevel, + }, + { + // The error is caused by a cancellation, but the client didn't go away: the server canceled its own context. + name: "cancellation by the server", + path: "/canceled-by-the-server", + route: "/canceled-by-the-server", + expectedCode: http.StatusInternalServerError, + expectedBody: `{"message":"Internal Server Error"}`, + expectedError: "unexpected error while handling the request", + expectedLevel: logrus.ErrorLevel, + }, + { + // The client went away, but the error is not caused by the cancellation of the request. + name: "unexpected error not caused by the client that went away", + path: "/unexpected", + route: "/unexpected", + canceled: true, + expectedCode: http.StatusInternalServerError, + expectedBody: `{"message":"Internal Server Error"}`, + expectedError: "unexpected error while handling the request", + expectedLevel: logrus.ErrorLevel, + }, + { + // The client already received the status of the response, which the error cannot change. + name: "unexpected error after the response is sent", + path: "/fail-after-response", + route: "/fail-after-response", + expectedCode: http.StatusOK, + expectedBody: `{"message":"partial"}`, + expectedError: "unexpected error while handling the request", + expectedLevel: logrus.WarnLevel, + }, + { + // The error is caused by the client that went away. + name: "unexpected error after the client went away", + path: "/canceled", + route: "/canceled", + canceled: true, + expectedCode: http.StatusInternalServerError, + expectedBody: `{"message":"Internal Server Error"}`, + expectedError: "unexpected error while handling the request", + expectedLevel: logrus.DebugLevel, + }, + { + name: "HTTP error", + path: "/unauthorized", + route: "/unauthorized", + expectedCode: http.StatusUnauthorized, + expectedBody: `{"message":"missing token"}`, + }, + { + name: "HTTP error with a 5xx status", + path: "/bad-gateway", + route: "/bad-gateway", + expectedCode: http.StatusBadGateway, + expectedBody: `{"message":"datasource unreachable"}`, + }, + { + name: "route not found", + path: "/does-not-exist", + expectedCode: http.StatusNotFound, + expectedBody: `{"message":"Not Found"}`, + }, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + hook := newLogHook(t) + registry := prometheus.NewRegistry() + builder := NewBuilder(). + APIRegistration(&errorRegister{}). + MetricNamespace("test"). + PrometheusRegisterer(registry) + for _, mdw := range tt.middlewares { + builder.Middleware(mdw) + } + handler, err := builder.BuildHandler() + require.NoError(t, err) + + req := httptest.NewRequest(http.MethodGet, tt.path, nil) + if tt.canceled { + ctx, cancel := context.WithCancel(t.Context()) + cancel() + req = req.WithContext(ctx) + } + rec := httptest.NewRecorder() + handler.ServeHTTP(rec, req) + + assert.Equal(t, tt.expectedCode, rec.Code) + assert.JSONEq(t, tt.expectedBody, rec.Body.String()) + + // The access log and the metrics report the status of the response sent. + var accessLog *logrus.Entry + for _, entry := range hook.AllEntries() { + if entry.Data["uri"] == tt.path && entry.Data["status"] != nil { + accessLog = entry + } + } + require.NotNil(t, accessLog) + assert.Equal(t, tt.expectedCode, accessLog.Data["status"]) + assert.Equal(t, http.MethodGet, accessLog.Data["method"]) + labels := map[string]string{"code": strconv.Itoa(tt.expectedCode), "method": http.MethodGet} + if tt.route != "" { + labels["handler"] = tt.route + } + assert.Equal(t, float64(1), counterValue(t, registry, "test_http_requests_total", labels)) + + // Only the errors that don't carry an HTTP status are logged. + if tt.expectedError == "" { + for _, entry := range hook.AllEntries() { + assert.NotContains(t, []logrus.Level{logrus.WarnLevel, logrus.ErrorLevel}, entry.Level, entry.Message) + } + return + } + errorEntry := findLogEntry(hook, tt.expectedError) + require.NotNil(t, errorEntry) + assert.Equal(t, tt.expectedLevel, errorEntry.Level) + assert.Equal(t, http.MethodGet, errorEntry.Data["method"]) + assert.Equal(t, tt.path, errorEntry.Data["uri"]) + if tt.expectedPanic != "" { + loggedErr, ok := errorEntry.Data[logrus.ErrorKey].(error) + require.True(t, ok, "the value of the panic must be logged as an error") + assert.EqualError(t, loggedErr, tt.expectedPanic) + // Only the stack of the goroutine that panicked is logged. + stack, ok := errorEntry.Data["stack"].(string) + require.True(t, ok, "the stack must be logged") + assert.Len(t, goroutineHeader.FindAllString(stack, -1), 1, stack) + } + }) + } +} diff --git a/echo/logging.go b/echo/logging.go new file mode 100644 index 0000000..d8bdb16 --- /dev/null +++ b/echo/logging.go @@ -0,0 +1,200 @@ +// Copyright The Perses Authors +// 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. + +package echo + +import ( + "context" + "log/slog" + "maps" + "net" + "runtime" + "slices" + "strings" + + "github.com/sirupsen/logrus" +) + +// logrusHandler is a slog.Handler writing the records with the standard logger of logrus. +// echo v5 logs with log/slog, so this handler is given to echo to have its logs with the same format, level and output as the other logs. +// The attributes are written as logrus fields. The keys of the attributes in a group are prefixed by the name of the group (like "group.key"). +type logrusHandler struct { + // fields are the attributes added by WithAttrs. + fields logrus.Fields + // groupPrefix prefixes the keys of the next attributes. It is built from the groups added by WithGroup. + groupPrefix string + // reportCaller tells if logrus reports the caller (see newLogrusHandler). + reportCaller bool +} + +// newLogrusHandler returns a logrusHandler for the current configuration of logrus. +// logrus has no way to read if it reports the caller without racing with SetReportCaller, so this setting is read once, +// here: logrus must be configured before (like app.Runner does). +func newLogrusHandler() logrusHandler { + return logrusHandler{reportCaller: logrus.StandardLogger().ReportCaller} +} + +func (h logrusHandler) Enabled(_ context.Context, level slog.Level) bool { + return logrus.IsLevelEnabled(logrusLevel(level)) +} + +func (h logrusHandler) Handle(ctx context.Context, record slog.Record) error { + fields := make(logrus.Fields, len(h.fields)+record.NumAttrs()) + maps.Copy(fields, h.fields) + record.Attrs(func(attr slog.Attr) bool { + addField(fields, h.groupPrefix, attr) + return true + }) + // The entry is built directly, as WithContext, WithTime and WithFields would copy it each time. + // logrus uses the current time when the time of the record is zero. + entry := &logrus.Entry{Logger: logrus.StandardLogger(), Data: fields, Time: record.Time, Context: ctx} + // When logrus reports the caller, it would report this method, so the caller of slog is given instead. + // It is only set in this case, as logrus writes the caller as soon as it is set. + if h.reportCaller && record.PC != 0 { + frame, _ := runtime.CallersFrames([]uintptr{record.PC}).Next() + entry.Caller = &frame + } + entry.Log(logrusLevel(record.Level), record.Message) + return nil +} + +func (h logrusHandler) WithAttrs(attrs []slog.Attr) slog.Handler { + fields := make(logrus.Fields, len(h.fields)+len(attrs)) + maps.Copy(fields, h.fields) + for _, attr := range attrs { + addField(fields, h.groupPrefix, attr) + } + // h is a copy: the receiver is not modified, and the other settings are kept. + h.fields = fields + return h +} + +func (h logrusHandler) WithGroup(name string) slog.Handler { + if name == "" { + return h + } + h.groupPrefix += name + "." + return h +} + +// addField adds the attribute to the fields. The attributes of a group are added one by one, prefixed by the name of the group. +func addField(fields logrus.Fields, prefix string, attr slog.Attr) { + attr.Value = attr.Value.Resolve() + if attr.Value.Kind() == slog.KindGroup { + // Like the handlers of slog, the attributes of a group without key are inlined. + if attr.Key != "" { + prefix += attr.Key + "." + } + for _, groupAttr := range attr.Value.Group() { + addField(fields, prefix, groupAttr) + } + return + } + // An attribute without key (like the empty attributes, ignored by the handlers of slog) cannot be a logrus field. + if attr.Key == "" { + return + } + fields[prefix+attr.Key] = attr.Value.Any() +} + +// logrusLevel converts a slog level to the closest logrus level. +// slog has no level above Error, so the levels Fatal and Panic of logrus (for the errors stopping the process) are never returned. +func logrusLevel(level slog.Level) logrus.Level { + switch { + case level >= slog.LevelError: + return logrus.ErrorLevel + case level >= slog.LevelWarn: + return logrus.WarnLevel + case level >= slog.LevelInfo: + return logrus.InfoLevel + case level >= slog.LevelDebug: + return logrus.DebugLevel + default: + return logrus.TraceLevel + } +} + +// httpServerErrorWriter writes with logrus every line logged by the http.Server. +// Most of these errors are caused by the clients (like the TLS handshake errors, or the HTTP/2 protocol errors), so they are +// logged as warnings, as any client can trigger them. Only the defects of the server (see httpServerDefects) are logged as errors. +type httpServerErrorWriter struct { + // reportCaller tells if logrus reports the caller (see newLogrusHandler). + reportCaller bool +} + +// newHTTPServerErrorWriter returns an httpServerErrorWriter for the current configuration of logrus (see newLogrusHandler). +func newHTTPServerErrorWriter() httpServerErrorWriter { + return httpServerErrorWriter{reportCaller: logrus.StandardLogger().ReportCaller} +} + +// httpServerDefects are the beginnings of the errors logged by the http.Server (net/http and its HTTP/2 server) +// that are caused by the server itself: a handler, or the system. +var httpServerDefects = []string{ + "http: panic serving", + "http2: panic serving", + "http: superfluous response.WriteHeader call", + // response.Write and response.WriteHeader on a hijacked connection. + "http: response.Write", + "http: invalid Content-Length", + "http: WriteHeader called with both Transfer-Encoding", + "ignoring invalid trailer", + "http: Accept error", + "http: error reading directory", +} + +func (w httpServerErrorWriter) Write(p []byte) (int, error) { + message := strings.TrimSuffix(string(p), "\n") + level := logrus.WarnLevel + if slices.ContainsFunc(httpServerDefects, func(prefix string) bool { return strings.HasPrefix(message, prefix) }) { + level = logrus.ErrorLevel + } + entry := logrus.NewEntry(logrus.StandardLogger()) + // When logrus reports the caller, it would report this method, so the code of net/http that logged is given instead. + if w.reportCaller { + entry.Caller = httpServerLogCaller() + } + entry.Log(level, message) + return len(p), nil +} + +// httpServerLogCaller returns the code that logged with the error logger of the http.Server. +// It skips this writer, the package log, and the logging functions of net/http (like Server.logf, used by the code logging). +func httpServerLogCaller() *runtime.Frame { + var pcs [16]uintptr + // runtime.Callers, httpServerLogCaller and httpServerErrorWriter.Write are skipped. + frames := runtime.CallersFrames(pcs[:runtime.Callers(3, pcs[:])]) + for { + frame, more := frames.Next() + isLogging := strings.HasPrefix(frame.Function, "log.") || + (strings.HasPrefix(frame.Function, "net/http") && strings.HasSuffix(frame.Function, "logf")) + if frame.Function != "" && !isLogging { + return &frame + } + if !more { + // logrus reports its own caller when none is given. + return nil + } + } +} + +// logListenerAddr logs the address listened by the server, unless it is hidden with the flag --web.hide-port. +func (s *server) logListenerAddr(addr net.Addr) { + if hidePort { + return + } + scheme := "http" + if s.cert != "" { + scheme = "https" + } + logrus.Infof("%s server started on %s", scheme, addr) +} diff --git a/echo/logging_test.go b/echo/logging_test.go new file mode 100644 index 0000000..471edc4 --- /dev/null +++ b/echo/logging_test.go @@ -0,0 +1,314 @@ +// Copyright The Perses Authors +// 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. + +package echo + +import ( + "context" + "errors" + "fmt" + "log" + "log/slog" + "net" + "net/http" + "net/http/httptest" + "slices" + "strings" + "testing" + "time" + + echoLib "github.com/labstack/echo/v5" + "github.com/sirupsen/logrus" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +func TestLogrusHandler(t *testing.T) { + testErr := errors.New("boom") + tests := []struct { + name string + log func(logger *slog.Logger) + expectedLevel logrus.Level + expectedFields logrus.Fields + }{ + { + name: "debug", + log: func(logger *slog.Logger) { logger.Debug("message") }, + expectedLevel: logrus.DebugLevel, + expectedFields: logrus.Fields{}, + }, + { + name: "info with attributes", + log: func(logger *slog.Logger) { logger.Info("message", "address", "127.0.0.1:8080", "count", 2) }, + expectedLevel: logrus.InfoLevel, + expectedFields: logrus.Fields{"address": "127.0.0.1:8080", "count": int64(2)}, + }, + { + name: "warning", + log: func(logger *slog.Logger) { logger.Warn("message") }, + expectedLevel: logrus.WarnLevel, + expectedFields: logrus.Fields{}, + }, + { + name: "error with the error as attribute", + log: func(logger *slog.Logger) { logger.Error("message", "error", testErr) }, + expectedLevel: logrus.ErrorLevel, + expectedFields: logrus.Fields{logrus.ErrorKey: testErr}, + }, + { + // slog has no level above error: the levels above it are logged as errors. + name: "level above error", + log: func(logger *slog.Logger) { logger.Log(context.Background(), slog.LevelError+4, "message") }, + expectedLevel: logrus.ErrorLevel, + expectedFields: logrus.Fields{}, + }, + { + name: "attributes and groups added to the logger", + log: func(logger *slog.Logger) { + logger.With("component", "echo").WithGroup("request").With("method", http.MethodGet). + Info("message", "status", http.StatusOK, slog.Group("user", "name", "admin")) + }, + expectedLevel: logrus.InfoLevel, + expectedFields: logrus.Fields{ + "component": "echo", + "request.method": http.MethodGet, + "request.status": int64(http.StatusOK), + "request.user.name": "admin", + }, + }, + { + name: "empty attributes are ignored, and the attributes of a group without key are inlined", + log: func(logger *slog.Logger) { + logger.WithGroup("").Info("message", slog.Attr{}, slog.Group("", "inlined", true), slog.Group("empty")) + }, + expectedLevel: logrus.InfoLevel, + expectedFields: logrus.Fields{"inlined": true}, + }, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + hook := newLogHook(t) + tt.log(slog.New(logrusHandler{})) + require.Len(t, hook.AllEntries(), 1) + entry := hook.LastEntry() + assert.Equal(t, "message", entry.Message) + assert.Equal(t, tt.expectedLevel, entry.Level) + assert.Equal(t, tt.expectedFields, entry.Data) + }) + } +} + +func TestLogrusHandler_Enabled(t *testing.T) { + hook := newLogHook(t) + logrus.SetLevel(logrus.WarnLevel) + logger := slog.New(logrusHandler{}) + assert.False(t, logger.Enabled(context.Background(), slog.LevelInfo)) + assert.True(t, logger.Enabled(context.Background(), slog.LevelWarn)) + logger.Info("message") + assert.Empty(t, hook.AllEntries()) +} + +func TestLogrusHandler_Caller(t *testing.T) { + hook := newLogHook(t) + // The caller is not set when logrus doesn't report it, as logrus writes it as soon as it is set. + slog.New(newLogrusHandler()).Info("message") + entry := hook.LastEntry() + require.NotNil(t, entry) + assert.Nil(t, entry.Caller) + + // When logrus reports the caller, it is the code calling slog, not the handler. + setReportCaller(t, true) + slog.New(newLogrusHandler()).With("key", "value").WithGroup("group").Info("message") + entry = hook.LastEntry() + require.NotNil(t, entry.Caller) + assert.Equal(t, "github.com/perses/common/echo.TestLogrusHandler_Caller", entry.Caller.Function) +} + +// setReportCaller sets if logrus reports the caller until the end of the test. +func setReportCaller(t *testing.T, reportCaller bool) { + t.Helper() + origReportCaller := logrus.StandardLogger().ReportCaller + logrus.SetReportCaller(reportCaller) + t.Cleanup(func() { + logrus.SetReportCaller(origReportCaller) + }) +} + +type doubleWriteRegister struct{} + +func (r *doubleWriteRegister) RegisterRoute(e *echoLib.Echo) { + e.GET("/double-write", func(c *echoLib.Context) error { + if err := c.NoContent(http.StatusOK); err != nil { + return err + } + return c.NoContent(http.StatusAccepted) + }) +} + +func TestServer_EchoLogsWithLogrus(t *testing.T) { + hook := newLogHook(t) + handler, err := NewBuilder().APIRegistration(&doubleWriteRegister{}).OverrideDefaultMiddleware(true).BuildHandler() + require.NoError(t, err) + + rec := httptest.NewRecorder() + handler.ServeHTTP(rec, httptest.NewRequest(http.MethodGet, "/double-write", nil)) + assert.Equal(t, http.StatusOK, rec.Code) + + // echo logs with log/slog that the response was already written: the log is written with logrus. + entry := findLogEntry(hook, "echo: response already written to client") + require.NotNil(t, entry) + assert.Equal(t, logrus.ErrorLevel, entry.Level) +} + +func TestHTTPServerErrorWriter(t *testing.T) { + tests := []struct { + name string + line string + expectedLevel logrus.Level + }{ + { + name: "TLS handshake error", + line: "http: TLS handshake error from 127.0.0.1:1234: EOF", + expectedLevel: logrus.WarnLevel, + }, + { + name: "HTTP/2 preface sent by the client", + line: `http2: server: error reading preface from client 127.0.0.1:1234: bogus greeting "GET / HTTP/1.1"`, + expectedLevel: logrus.WarnLevel, + }, + { + name: "HTTP/2 protocol error of the client", + line: "http2: server connection error from 127.0.0.1:1234: connection error: PROTOCOL_ERROR", + expectedLevel: logrus.WarnLevel, + }, + { + name: "panic not recovered by a middleware", + line: "http: panic serving 127.0.0.1:1234: boom\ngoroutine 7 [running]:", + expectedLevel: logrus.ErrorLevel, + }, + { + name: "HTTP/2 panic not recovered by a middleware", + line: "http2: panic serving 127.0.0.1:1234: boom\ngoroutine 7 [running]:", + expectedLevel: logrus.ErrorLevel, + }, + { + name: "handler writing the header twice", + line: "http: superfluous response.WriteHeader call from main.handler (main.go:12)", + expectedLevel: logrus.ErrorLevel, + }, + { + name: "connections not accepted", + line: "http: Accept error: accept tcp 127.0.0.1:8080: accept: too many open files; retrying in 5ms", + expectedLevel: logrus.ErrorLevel, + }, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + hook := newLogHook(t) + log.New(httpServerErrorWriter{}, "", 0).Print(tt.line) + entry := hook.LastEntry() + require.NotNil(t, entry) + assert.Equal(t, tt.expectedLevel, entry.Level) + assert.Equal(t, tt.line, entry.Message) + }) + } +} + +func TestHTTPServerErrorWriter_Caller(t *testing.T) { + hook := newLogHook(t) + // The caller is not set when logrus doesn't report it, as logrus writes it as soon as it is set. + log.New(newHTTPServerErrorWriter(), "", 0).Print("http: TLS handshake error from 127.0.0.1:1234: EOF") + entry := hook.LastEntry() + require.NotNil(t, entry) + assert.Nil(t, entry.Caller) + + // When logrus reports the caller, it is the code of net/http that logged the error, not the writer or the package log. + setReportCaller(t, true) + server := httptest.NewUnstartedServer(http.NotFoundHandler()) + server.Config.ErrorLog = log.New(newHTTPServerErrorWriter(), "", 0) + server.StartTLS() + t.Cleanup(server.Close) + hook.Reset() + // A client sending HTTP to the HTTPS server makes it log a TLS handshake error. + conn, err := net.Dial("tcp", server.Listener.Addr().String()) + require.NoError(t, err) + t.Cleanup(func() { + _ = conn.Close() + }) + _, err = conn.Write([]byte("GET / HTTP/1.1\r\nHost: localhost\r\n\r\n")) + require.NoError(t, err) + require.Eventually(t, func() bool { + return hook.LastEntry() != nil + }, 5*time.Second, 10*time.Millisecond) + entry = hook.LastEntry() + assert.Equal(t, logrus.WarnLevel, entry.Level) + assert.Contains(t, entry.Message, "http: TLS handshake error") + require.NotNil(t, entry.Caller) + assert.Equal(t, "net/http.(*conn).serve", entry.Caller.Function) +} + +func TestServer_LogListenerAddr(t *testing.T) { + tests := []struct { + name string + hidePort bool + expectedLogged bool + }{ + { + name: "the address is logged", + expectedLogged: true, + }, + { + name: "the address is hidden with --web.hide-port", + hidePort: true, + }, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + origHidePort := hidePort + hidePort = tt.hidePort + t.Cleanup(func() { + hidePort = origHidePort + }) + hook := newLogHook(t) + address := freeAddress(t) + builder := NewBuilder().APIRegistration(&helloRegister{}).OverrideDefaultMiddleware(true) + builder.ListenAddress(address) + runServer(t, builder) + + // Once the server answers, it has logged that it started (or not). + client := &http.Client{Timeout: time.Second} + require.Eventually(t, func() bool { + resp, err := client.Get("http://" + address + "/hello") + if err != nil { + return false + } + _ = resp.Body.Close() + return resp.StatusCode == http.StatusOK + }, 5*time.Second, 10*time.Millisecond) + logged := slices.ContainsFunc(hook.AllEntries(), func(entry *logrus.Entry) bool { + return strings.Contains(fmt.Sprint(entry.Message, entry.Data), address) + }) + assert.Equal(t, tt.expectedLogged, logged) + }) + } +} + +// freeAddress returns a local address with a port that is free when the function returns. +func freeAddress(t *testing.T) string { + t.Helper() + listener, err := net.Listen("tcp", "127.0.0.1:0") + require.NoError(t, err) + address := listener.Addr().String() + require.NoError(t, listener.Close()) + return address +} diff --git a/echo/metrics.go b/echo/metrics.go index 5fe5bd3..25d51bd 100644 --- a/echo/metrics.go +++ b/echo/metrics.go @@ -16,7 +16,7 @@ package echo import ( "flag" - "github.com/labstack/echo/v4" + "github.com/labstack/echo/v5" "github.com/prometheus/client_golang/prometheus" "github.com/prometheus/client_golang/prometheus/promhttp" ) diff --git a/echo/middleware/logger.go b/echo/middleware/logger.go index 863e525..2543498 100644 --- a/echo/middleware/logger.go +++ b/echo/middleware/logger.go @@ -14,8 +14,8 @@ package middleware import ( - "github.com/labstack/echo/v4" - "github.com/labstack/echo/v4/middleware" + "github.com/labstack/echo/v5" + "github.com/labstack/echo/v5/middleware" "github.com/perses/common/slices" "github.com/sirupsen/logrus" ) @@ -37,10 +37,15 @@ var defaultLoggerConfig = LoggerConfig{ }, } +// Logger returns a middleware that logs every request (its method, escaped path and status) with logrus, once it is handled. +// It must be executed before the middleware Recover, so the panics are logged too. +// The error returned by the next handler is not handled here: it is returned, to be handled once by the central error handler of echo. +// The status logged is the one of the response that the error handler will send. func Logger() echo.MiddlewareFunc { return LoggerWithConfig(defaultLoggerConfig) } +// LoggerWithConfig returns a Logger middleware (see Logger) with the given configuration. func LoggerWithConfig(config LoggerConfig) echo.MiddlewareFunc { if config.Skipper == nil { config.Skipper = defaultLoggerConfig.Skipper @@ -49,28 +54,62 @@ func LoggerWithConfig(config LoggerConfig) echo.MiddlewareFunc { config.BlackListEndpoint = defaultLoggerConfig.BlackListEndpoint } return func(next echo.HandlerFunc) echo.HandlerFunc { - return func(c echo.Context) error { + return func(c *echo.Context) error { if config.Skipper(c) { return next(c) } - // The request is described before calling the next handler, as it can modify it (like a reverse proxy rewriting the path). + // The request is described before calling the next handler, as it can modify it (like a reverse proxy rewriting the path or the method). // Only the escaped path is logged: the query string can contain sensitive data (tokens, OAuth codes, etc.), // and the escaped path cannot contain control characters. - path := c.Request().URL.EscapedPath() + request := loggedRequest{method: c.Request().Method, path: c.Request().URL.EscapedPath()} + // The request is saved, so the other logs about it (like the one of the central error handler) describe it the same way. + c.Set(contextKeyLoggedRequest, request) route := c.Path() - if err := next(c); err != nil { - c.Error(err) - } - entry := logrus.WithField("method", c.Request().Method). - WithField("uri", path). - WithField("status", c.Response().Status) + // The error is not handled here, it is returned to be handled by the central error handler of echo. + // The status logged is the one of the response that will be sent, resolved from this error. + err := next(c) + _, status := echo.ResolveResponseStatus(c.Response(), err) + entry := logrus.WithFields(logrus.Fields{ + "method": request.method, + "uri": request.path, + "status": status, + }) if slices.InvertSubContains(config.BlackListEndpoint, route) { entry.Debug() } else { entry.Info() } - return nil + return err } } } + +// loggedRequest describes the request as logged by the Logger middleware. +type loggedRequest struct { + method string + path string +} + +// contextKeyLoggedRequest is the key of the echo context in which the Logger middleware saves the request it logs. +const contextKeyLoggedRequest = "github.com/perses/common/echo/middleware.loggedRequest" + +// RequestMethod returns the method of the request as logged by the Logger middleware, before the next handlers +// possibly rewrote it (like a reverse proxy). Like that, every log about the same request uses the same method. +// It returns the current method of the request when the Logger middleware didn't handle it. +func RequestMethod(c *echo.Context) string { + if request, ok := c.Get(contextKeyLoggedRequest).(loggedRequest); ok { + return request.method + } + return c.Request().Method +} + +// RequestPath returns the escaped path of the request as logged by the Logger middleware, before the next handlers +// possibly rewrote it (like a reverse proxy). Like that, every log about the same request uses the same path. +// It returns the current escaped path of the request when the Logger middleware didn't handle it. +func RequestPath(c *echo.Context) string { + if request, ok := c.Get(contextKeyLoggedRequest).(loggedRequest); ok { + return request.path + } + return c.Request().URL.EscapedPath() +} diff --git a/echo/middleware/logger_test.go b/echo/middleware/logger_test.go index eebd29a..51eaaca 100644 --- a/echo/middleware/logger_test.go +++ b/echo/middleware/logger_test.go @@ -14,12 +14,14 @@ package middleware import ( + "errors" "io" "net/http" "net/http/httptest" "testing" - "github.com/labstack/echo/v4" + "github.com/labstack/echo/v5" + echoMiddleware "github.com/labstack/echo/v5/middleware" "github.com/sirupsen/logrus" logrusTest "github.com/sirupsen/logrus/hooks/test" "github.com/stretchr/testify/assert" @@ -41,18 +43,29 @@ func TestLogger(t *testing.T) { hook := logrusTest.NewLocal(logger) e := echo.New() - e.Use(Logger()) - handler := func(c echo.Context) error { + // Like the default middlewares, the logger is executed before the middleware Recover, so it logs the panics too. + e.Use(Logger(), echoMiddleware.Recover()) + handler := func(c *echo.Context) error { return c.NoContent(http.StatusOK) } e.GET("/api/v1/users", handler) e.GET("/api/v1/projects/:project", handler) e.GET("/metrics", handler) - // Like a reverse proxy, this handler modifies the path of the request. - e.GET("/proxy/*", func(c echo.Context) error { + // Like a reverse proxy, this handler modifies the path and the method of the request. + e.GET("/proxy/*", func(c *echo.Context) error { c.Request().URL.Path = "/rewritten" + c.Request().Method = http.MethodPost return c.NoContent(http.StatusOK) }) + e.GET("/error", func(*echo.Context) error { + return errors.New("unexpected failure") + }) + e.GET("/forbidden", func(*echo.Context) error { + return echo.ErrForbidden + }) + e.GET("/panic", func(*echo.Context) error { + panic("boom") + }) tests := []struct { name string @@ -97,12 +110,33 @@ func TestLogger(t *testing.T) { expectedURI: "/metrics-hidden", }, { - name: "the path requested by the client is logged, even if the handler modifies it", + name: "the path and the method requested by the client are logged, even if the handler modifies them", target: "/proxy/api/v1/query", expectedStatus: http.StatusOK, expectedLevel: logrus.InfoLevel, expectedURI: "/proxy/api/v1/query", }, + { + name: "the status of an unexpected error is the one sent by the error handler", + target: "/error", + expectedStatus: http.StatusInternalServerError, + expectedLevel: logrus.InfoLevel, + expectedURI: "/error", + }, + { + name: "the status of an HTTP error is the one carried by the error", + target: "/forbidden", + expectedStatus: http.StatusForbidden, + expectedLevel: logrus.InfoLevel, + expectedURI: "/forbidden", + }, + { + name: "a panic is logged", + target: "/panic", + expectedStatus: http.StatusInternalServerError, + expectedLevel: logrus.InfoLevel, + expectedURI: "/panic", + }, { name: "the control characters are escaped", target: "/api/v1/projects/a%0Ab", @@ -122,6 +156,60 @@ func TestLogger(t *testing.T) { require.NotNil(t, entry) assert.Equal(t, tt.expectedLevel, entry.Level) assert.Equal(t, tt.expectedURI, entry.Data["uri"]) + assert.Equal(t, http.MethodGet, entry.Data["method"]) + assert.Equal(t, tt.expectedStatus, entry.Data["status"]) + }) + } +} + +func TestRequestMethodAndPath(t *testing.T) { + tests := []struct { + name string + middleware []echo.MiddlewareFunc + expectedMethod string + expectedPath string + }{ + { + name: "the method and the path logged by the logger are returned, even if the handler modifies them", + middleware: []echo.MiddlewareFunc{LoggerWithConfig(LoggerConfig{})}, + expectedMethod: http.MethodGet, + expectedPath: "/proxy/api%2Fv1", + }, + { + name: "the current method and path are returned when the logger doesn't handle the request", + middleware: []echo.MiddlewareFunc{LoggerWithConfig(LoggerConfig{Skipper: func(*echo.Context) bool { return true }})}, + expectedMethod: http.MethodPost, + expectedPath: "/rewritten", + }, + { + name: "the current method and path are returned without the logger", + expectedMethod: http.MethodPost, + expectedPath: "/rewritten", + }, + } + origOutput := logrus.StandardLogger().Out + logrus.SetOutput(io.Discard) + t.Cleanup(func() { + logrus.SetOutput(origOutput) + }) + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + var method, path string + e := echo.New() + e.Use(tt.middleware...) + // Like a reverse proxy, this handler modifies the path and the method of the request. + e.GET("/proxy/*", func(c *echo.Context) error { + c.Request().URL.Path = "/rewritten" + c.Request().Method = http.MethodPost + method = RequestMethod(c) + path = RequestPath(c) + return c.NoContent(http.StatusOK) + }) + rec := httptest.NewRecorder() + e.ServeHTTP(rec, httptest.NewRequest(http.MethodGet, "/proxy/api%2Fv1", nil)) + require.Equal(t, http.StatusOK, rec.Code) + assert.Equal(t, tt.expectedMethod, method) + assert.Equal(t, tt.expectedPath, path) }) } } diff --git a/echo/middleware/metrics.go b/echo/middleware/metrics.go index 4e09a32..7fd66b6 100644 --- a/echo/middleware/metrics.go +++ b/echo/middleware/metrics.go @@ -19,7 +19,7 @@ import ( "strconv" "time" - "github.com/labstack/echo/v4" + "github.com/labstack/echo/v5" "github.com/prometheus/client_golang/prometheus" "github.com/sirupsen/logrus" ) @@ -66,15 +66,16 @@ func (m *Metrics) Describe(ch chan<- *prometheus.Desc) { // ProcessHTTPRequest is an echo middleware. It will intercept all responses. // It will increase the metrics that count the number of HTTP request and calculate the time took to respond. +// It must be executed before the middleware Recover, so the panics are counted too. +// The error returned by the next handler is returned as is, to be handled by the central error handler of echo. +// The status code counted is the one of the response that will be sent, resolved from this error. func (m *Metrics) ProcessHTTPRequest(next echo.HandlerFunc) echo.HandlerFunc { - return func(ctx echo.Context) error { + return func(ctx *echo.Context) error { start := time.Now() - if err := next(ctx); err != nil { - // Note: if this method is called, the code won't go further. - ctx.Error(err) - } - elapsedTime := time.Since(start).Seconds() + // The method is read before calling the next handler, as it can modify it (like a reverse proxy). method := ctx.Request().Method + err := next(ctx) + elapsedTime := time.Since(start).Seconds() if method != http.MethodPost && method != http.MethodGet && method != http.MethodHead && @@ -88,21 +89,22 @@ func (m *Metrics) ProcessHTTPRequest(next echo.HandlerFunc) echo.HandlerFunc { method = "not_standard" } - status := strconv.Itoa(ctx.Response().Status) - counter, err := m.totalHTTPRequest.GetMetricWith(prometheus.Labels{labelCode: status, labelHandler: ctx.Path(), labelMethod: method}) - if err != nil { - logrus.WithError(err).Error("unable to get the counter metrics in the api monitoring") + _, code := echo.ResolveResponseStatus(ctx.Response(), err) + status := strconv.Itoa(code) + counter, metricErr := m.totalHTTPRequest.GetMetricWith(prometheus.Labels{labelCode: status, labelHandler: ctx.Path(), labelMethod: method}) + if metricErr != nil { + logrus.WithError(metricErr).Error("unable to get the counter metrics in the api monitoring") // maybe not a really smart choice, but for the moment let's not impact the business if the monitoring somehow failed (which will unlikely happen) - return nil + return err } counter.Inc() - sum, err := m.durationHTTPRequest.GetMetricWith(prometheus.Labels{labelHandler: ctx.Path(), labelMethod: method}) - if err != nil { - logrus.WithError(err).Error("unable to get the summary metrics in the api monitoring") + sum, metricErr := m.durationHTTPRequest.GetMetricWith(prometheus.Labels{labelHandler: ctx.Path(), labelMethod: method}) + if metricErr != nil { + logrus.WithError(metricErr).Error("unable to get the summary metrics in the api monitoring") // maybe not a really smart choice, but for the moment let's not impact the business if the monitoring somehow failed (which will unlikely happen) - return nil + return err } sum.Observe(elapsedTime) - return nil + return err } } diff --git a/echo/server.go b/echo/server.go index 6a0500c..5281d0c 100644 --- a/echo/server.go +++ b/echo/server.go @@ -58,14 +58,16 @@ import ( "errors" "flag" "fmt" + "log" + "log/slog" "net/http" "net/http/pprof" "slices" "strings" "time" - "github.com/labstack/echo/v4" - "github.com/labstack/echo/v4/middleware" + "github.com/labstack/echo/v5" + "github.com/labstack/echo/v5/middleware" "github.com/perses/common/async" "github.com/prometheus/client_golang/prometheus" "github.com/prometheus/client_golang/prometheus/collectors/version" @@ -86,7 +88,7 @@ const ( var ( // http address listened addr string - // hide port when printing the server status on stdout + // hide the address listened when logging that the server started hidePort bool // https cert for server cert string @@ -102,7 +104,7 @@ var ( func InitFlag() { flag.StringVar(&addr, "web.listen-address", defaultAddr, "The address to listen on for HTTP requests, web interface and telemetry.") - flag.BoolVar(&hidePort, "web.hide-port", false, "If true, it won't be print on stdout the port listened to receive the HTTP request") + flag.BoolVar(&hidePort, "web.hide-port", false, "If true, the address listened to receive the HTTP requests is not logged when the server starts") flag.StringVar(&cert, "web.tls-cert-file", "", "The path to the cert to use for the HTTPS server. It is reloaded when the file changes.") flag.StringVar(&key, "web.tls-key-file", "", "The path to the key to use for the HTTPS server. It is reloaded when the file changes.") flag.StringVar(&tlsMinVersion, "web.tls-min-version", "", "Minimum TLS version (e.g., \"1.2\", \"1.3\")") @@ -192,6 +194,8 @@ type Builder struct { readTimeout time.Duration writeTimeout time.Duration idleTimeout time.Duration + ipExtractor echo.IPExtractor + schemeExtractor echo.SchemeExtractor } func NewBuilder() *Builder { @@ -292,6 +296,28 @@ func (b *Builder) IdleTimeout(timeout time.Duration) *Builder { return b } +// IPExtractor sets how echo.Context.RealIP gets the IP address of the client. +// By default, the address of the direct peer (http.Request.RemoteAddr) is used, as the headers X-Forwarded-For and X-Real-IP +// can be spoofed by any client. When the server is behind proxies, use an extractor that only trusts the headers set by them, +// for example: +// +// builder.IPExtractor(echo.ExtractIPFromXFFHeader(echo.TrustIPRange(proxyNetwork))) +func (b *Builder) IPExtractor(extractor echo.IPExtractor) *Builder { + b.ipExtractor = extractor + return b +} + +// SchemeExtractor sets how echo.Context.Scheme gets the scheme (http or https) used by the client. +// By default, the headers like X-Forwarded-Proto are only trusted when the request comes from a loopback, link-local or +// private network address. When the server is behind a proxy with another address (like a CDN or a cloud load balancer), +// use an extractor that trusts it, for example: +// +// builder.SchemeExtractor(echo.ExtractSchemeFromHeaders(echo.TrustIPRange(proxyNetwork))) +func (b *Builder) SchemeExtractor(extractor echo.SchemeExtractor) *Builder { + b.schemeExtractor = extractor + return b +} + func (b *Builder) Build() (async.Task, error) { return b.build() } @@ -332,19 +358,9 @@ func (b *Builder) build() (*server, error) { if b.gzipSkipper == nil { b.gzipSkipper = middleware.DefaultSkipper } - defaultMiddleware := []echo.MiddlewareFunc{ - // Activate recover middleware to recover from panics anywhere in the chain. - // It prints stack trace and handles the control to the centralized HTTPErrorHandler. - // More information here: https://echo.labstack.com/middleware/recover - middleware.Recover(), - persesMiddleware.Logger(), - middleware.GzipWithConfig( - middleware.GzipConfig{ - Skipper: b.gzipSkipper, - Level: 5, - }, - ), - } + // The logger and the metrics are executed first, so they see the result of every request. + // It includes the panics, as the middleware Recover turns them into errors returned to the previous middlewares. + defaultMiddleware := []echo.MiddlewareFunc{persesMiddleware.Logger()} if b.promRegisterer == nil { b.promRegisterer = prometheus.DefaultRegisterer } @@ -354,8 +370,20 @@ func (b *Builder) build() (*server, error) { return nil, err } defaultMiddleware = append(defaultMiddleware, metricMiddleware.ProcessHTTPRequest) - } + defaultMiddleware = append(defaultMiddleware, + // Recover from the panics anywhere in the rest of the chain. + // The panic is returned as an error (with the stack trace) that is logged by the central error handler. + // Only the stack of the goroutine that panicked is kept: getting the stacks of all the goroutines stops the world. + // More information here: https://echo.labstack.com/docs/middleware/recover + middleware.RecoverWithConfig(middleware.RecoverConfig{DisableStackAll: true}), + middleware.GzipWithConfig( + middleware.GzipConfig{ + Skipper: b.gzipSkipper, + Level: 5, + }, + ), + ) mdws = append(defaultMiddleware, mdws...) } @@ -382,9 +410,13 @@ func (b *Builder) build() (*server, error) { logrus.Warn("--web.tls-min-version, --web.tls-max-version and --web.tls-cipher-suites have no effect because HTTPS is not enabled (--web.tls-cert-file and --web.tls-key-file are not set)") } - e := echo.New() - e.HideBanner = true - e.HidePort = hidePort + e := echo.NewWithConfig(echo.Config{ + // echo logs with log/slog: its logs are written with logrus, like the other logs. + Logger: slog.New(newLogrusHandler()), + HTTPErrorHandler: handleError, + IPExtractor: b.ipExtractor, + SchemeExtractor: b.schemeExtractor, + }) readHeaderTimeout := b.readHeaderTimeout if readHeaderTimeout == 0 { readHeaderTimeout = defaultReadHeaderTimeout @@ -393,25 +425,23 @@ func (b *Builder) build() (*server, error) { readHeaderTimeout = min(b.readTimeout, defaultReadHeaderTimeout) } } - for _, httpServer := range []*http.Server{e.Server, e.TLSServer} { - httpServer.ReadHeaderTimeout = readHeaderTimeout - httpServer.ReadTimeout = b.readTimeout - httpServer.WriteTimeout = b.writeTimeout - httpServer.IdleTimeout = cmp.Or(b.idleTimeout, defaultIdleTimeout) - } return &server{ - addr: b.addr, - apis: b.apis, - e: e, - cert: cert, - key: key, - tlsMinVersion: parsedMinVersion, - tlsMaxVersion: parsedMaxVersion, - tlsCipherSuites: parsedCipherSuites, - mdws: mdws, - preMDWs: b.preMDWs, - shutdownTimeout: 30 * time.Second, - activatePprof: b.activatePprof, + addr: b.addr, + apis: b.apis, + e: e, + cert: cert, + key: key, + tlsMinVersion: parsedMinVersion, + tlsMaxVersion: parsedMaxVersion, + tlsCipherSuites: parsedCipherSuites, + mdws: mdws, + preMDWs: b.preMDWs, + shutdownTimeout: 30 * time.Second, + activatePprof: b.activatePprof, + readHeaderTimeout: readHeaderTimeout, + readTimeout: b.readTimeout, + writeTimeout: b.writeTimeout, + idleTimeout: cmp.Or(b.idleTimeout, defaultIdleTimeout), }, nil } @@ -441,18 +471,24 @@ func (b *Builder) registerMetrics() (*persesMiddleware.Metrics, error) { type server struct { async.Task - addr string - apis []Register - e *echo.Echo - cert string - key string - tlsMinVersion uint16 - tlsMaxVersion uint16 - tlsCipherSuites []uint16 - mdws []echo.MiddlewareFunc - preMDWs []echo.MiddlewareFunc - shutdownTimeout time.Duration - activatePprof bool + addr string + apis []Register + e *echo.Echo + cert string + key string + tlsMinVersion uint16 + tlsMaxVersion uint16 + tlsCipherSuites []uint16 + mdws []echo.MiddlewareFunc + preMDWs []echo.MiddlewareFunc + shutdownTimeout time.Duration + activatePprof bool + readHeaderTimeout time.Duration + readTimeout time.Duration + writeTimeout time.Duration + idleTimeout time.Duration + // shutdownErr is the error of the graceful shutdown done by Execute (like a timeout), returned by Finalize. + shutdownErr error } func (s *server) String() string { @@ -460,6 +496,8 @@ func (s *server) String() string { } func (s *server) Initialize() error { + // The context of the request is saved before any middleware can replace it (see saveRequestContext). + s.e.Pre(saveRequestContext) // init global middleware // Remove trailing slash middleware a trailing slash from the request URI s.e.Pre(middleware.RemoveTrailingSlash()) @@ -478,42 +516,63 @@ func (s *server) Initialize() error { } func (s *server) Execute(ctx context.Context, cancelFunc context.CancelFunc) error { - // start server - // The channel is buffered, so the go routine is not blocked when the server is stopped after the end of this method. - serverErr := make(chan error, 1) - go func() { - var err error - if s.cert != "" && s.key != "" { - err = s.startTLS() - } else { - err = s.e.Start(s.addr) + startConfig := echo.StartConfig{ + Address: s.addr, + HideBanner: true, + // The address is logged by logListenerAddr instead of echo, to tell if the server uses HTTPS (like echo v4). + HidePort: true, + ListenerAddrFunc: s.logListenerAddr, + GracefulTimeout: s.shutdownTimeout, + // echo logs this error and returns nil. It is returned by Finalize instead, so the task reports the failure. + // It is called before Start returns, so before Finalize is called. + OnShutdownError: func(err error) { + s.shutdownErr = err + }, + BeforeServeFunc: func(httpServer *http.Server) error { + s.configureHTTPServer(httpServer) + return nil + }, + } + if s.cert != "" && s.key != "" { + tlsConfig, err := s.tlsConfig() + if err != nil { + cancelFunc() + return fmt.Errorf("http server stopped unexpectedly: %w", err) } - logrus.Debug("go routine running the http server has been stopped.") - serverErr <- err - }() - // Wait for the end of the task or cancellation - select { - case err := <-serverErr: - // Server ended unexpectedly (for example, the address is already in use, or the TLS certificate cannot be loaded) + startConfig.TLSConfig = tlsConfig + } + // Start blocks until the context is canceled, then it gracefully shuts down the server. + // It returns before if the server cannot start or stops unexpectedly (for example, when the address is already in use). + err := startConfig.Start(ctx, s.e) + logrus.Debug("http server has been stopped") + if ctx.Err() == nil { // In our ecosystem, as we are producing each time an HTTP API, if the HTTP api stopped, we want to stop the whole application. // That's why we are calling the parent cancelFunc cancelFunc() - if err != nil && !errors.Is(err, http.ErrServerClosed) { - return fmt.Errorf("http server stopped unexpectedly: %w", err) - } - case <-ctx.Done(): - // Cancellation requested by the parent context. The server is stopped by the method Finalize. - logrus.Debug("server cancellation requested") + } + if err != nil { + return fmt.Errorf("http server stopped unexpectedly: %w", err) } return nil } -// startTLS starts the HTTPS server. -// echo.StartTLS is not used because it replaces the TLS configuration, and it loads the certificate only once. -func (s *server) startTLS() error { +// configureHTTPServer sets the timeouts and the error logger of the http.Server created by echo. +// Every timeout is set, even when it is zero, as echo sets a default ReadTimeout. +func (s *server) configureHTTPServer(httpServer *http.Server) { + httpServer.ReadHeaderTimeout = s.readHeaderTimeout + httpServer.ReadTimeout = s.readTimeout + httpServer.WriteTimeout = s.writeTimeout + httpServer.IdleTimeout = s.idleTimeout + // echo logs every error of the server as an error, but most of them are caused by the clients (see httpServerErrorWriter). + httpServer.ErrorLog = log.New(newHTTPServerErrorWriter(), "", 0) +} + +// tlsConfig builds the TLS configuration of the HTTPS server. +// The certificate is provided by a reloader, so a rotated certificate is used without restarting the server. +func (s *server) tlsConfig() (*tls.Config, error) { reloader, err := newCertificateReloader(s.cert, s.key) if err != nil { - return err + return nil, err } tlsConfig := &tls.Config{ MinVersion: s.tlsMinVersion, @@ -521,21 +580,20 @@ func (s *server) startTLS() error { CipherSuites: s.tlsCipherSuites, GetCertificate: reloader.GetCertificate, } - switch { - case s.e.DisableHTTP2: - case !isHTTP2Compatible(s.tlsMinVersion, s.tlsCipherSuites): - logrus.Warn("HTTP/2 is disabled because --web.tls-cipher-suites contains neither TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 nor TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, required by HTTP/2") - default: + if isHTTP2Compatible(s.tlsMinVersion, s.tlsCipherSuites) { tlsConfig.NextProtos = []string{"h2"} + } else { + logrus.Warn("HTTP/2 is disabled because --web.tls-cipher-suites contains neither TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 nor TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, one of which HTTP/2 requires with TLS 1.2 (RFC 7540, section 9.2.2)") } - s.e.TLSServer.Addr = s.addr - s.e.TLSServer.TLSConfig = tlsConfig - return s.e.StartServer(s.e.TLSServer) + return tlsConfig, nil } // isHTTP2Compatible tells if HTTP/2 can be offered with the given TLS settings. -// HTTP/2 requires one of these cipher suites when TLS 1.2 is allowed (RFC 7540, section 9.2.2), -// otherwise net/http refuses to start the server. +// With TLS 1.2, HTTP/2 deployments must support TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 (RFC 7540, section 9.2.2), so every +// HTTP/2 client can negotiate a cipher suite allowed by HTTP/2 (the connections using a cipher suite forbidden by +// RFC 7540, appendix A, are rejected). net/http checks it only when the TLS configuration is set on the http.Server, +// not on the listener like here. So, like net/http, HTTP/2 is only offered when TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 +// or TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256 is configured. func isHTTP2Compatible(minVersion uint16, cipherSuites []uint16) bool { if len(cipherSuites) == 0 || minVersion >= tls.VersionTLS13 { return true @@ -547,12 +605,9 @@ func isHTTP2Compatible(minVersion uint16, cipherSuites []uint16) bool { } func (s *server) Finalize() error { - logrus.Debug("try to shutdown the http server") - shutdownCtx, shutdownCancelFunc := context.WithTimeout(context.Background(), s.shutdownTimeout) - // call shutdownCancelFunc to release the resources in case the task ended before the timeout - defer shutdownCancelFunc() - if err := s.e.Shutdown(shutdownCtx); err != nil { - return fmt.Errorf("server shutdown not properly: %w", err) + // The server is gracefully stopped by Execute once the context is canceled. + if s.shutdownErr != nil { + return fmt.Errorf("server shutdown not properly: %w", s.shutdownErr) } return nil } diff --git a/echo/server_test.go b/echo/server_test.go index 3818399..83b44c3 100644 --- a/echo/server_test.go +++ b/echo/server_test.go @@ -17,11 +17,12 @@ import ( "context" "crypto/tls" "net" + "net/http" "strings" "testing" "time" - echoLib "github.com/labstack/echo/v4" + echoLib "github.com/labstack/echo/v5" "github.com/prometheus/client_golang/prometheus" "github.com/sirupsen/logrus" logrustest "github.com/sirupsen/logrus/hooks/test" @@ -407,6 +408,30 @@ func TestBuild_TLSFlagValues(t *testing.T) { assert.Equal(t, "/path/key.pem", s.key) } +func TestServer_ConfigureHTTPServer(t *testing.T) { + hook := newLogHook(t) + s, err := NewBuilder(). + APIRegistration(&mockRegister{}). + OverrideDefaultMiddleware(true). + build() + require.NoError(t, err) + + // echo creates the http.Server with a ReadTimeout of 30s, which must not be kept, as there is no read timeout by default. + httpServer := &http.Server{ReadTimeout: 30 * time.Second} + s.configureHTTPServer(httpServer) + assert.Equal(t, defaultReadHeaderTimeout, httpServer.ReadHeaderTimeout) + assert.Equal(t, time.Duration(0), httpServer.ReadTimeout) + assert.Equal(t, time.Duration(0), httpServer.WriteTimeout) + assert.Equal(t, defaultIdleTimeout, httpServer.IdleTimeout) + + // The errors of the server are logged with logrus (their levels are tested by TestHTTPServerErrorWriter). + require.NotNil(t, httpServer.ErrorLog) + httpServer.ErrorLog.Print("http: TLS handshake error from 127.0.0.1:1234: EOF") + entry := hook.LastEntry() + require.NotNil(t, entry) + assert.Equal(t, "http: TLS handshake error from 127.0.0.1:1234: EOF", entry.Message) +} + func TestIsHTTP2Compatible(t *testing.T) { tests := []struct { name string @@ -660,3 +685,120 @@ func TestBuild_PartialTLSConfigurationDoesNotModifyTheBuilder(t *testing.T) { _, err = builder.Build() require.NoError(t, err) } + +// runServer runs the server built by the builder until the end of the test, when it is stopped and finalized. +func runServer(t *testing.T, builder *Builder) { + t.Helper() + task, err := builder.Build() + require.NoError(t, err) + require.NoError(t, task.Initialize()) + + ctx, cancel := context.WithCancel(t.Context()) + done := make(chan struct{}) + var executeErr error + go func() { + defer close(done) + executeErr = task.Execute(ctx, cancel) + }() + t.Cleanup(func() { + cancel() + <-done + assert.NoError(t, executeErr) + assert.NoError(t, task.Finalize()) + }) +} + +// startServer runs the server built by the builder on a random port until the end of the test, and returns its address, +// read from the logs. +func startServer(t *testing.T, hook *logrustest.Hook, builder *Builder) string { + t.Helper() + builder.ListenAddress("127.0.0.1:0") + runServer(t, builder) + return waitForListenAddress(t, hook) +} + +// waitForListenAddress waits for the server to log the address it listens on, and returns it. +func waitForListenAddress(t *testing.T, hook *logrustest.Hook) string { + t.Helper() + var address string + require.Eventually(t, func() bool { + for _, entry := range hook.AllEntries() { + if after, ok := strings.CutPrefix(entry.Message, "http server started on "); ok { + address = after + return true + } + } + return false + }, 5*time.Second, 10*time.Millisecond) + return address +} + +type blockingRegister struct { + started chan struct{} + release chan struct{} +} + +func (r *blockingRegister) RegisterRoute(e *echoLib.Echo) { + e.GET("/block", func(c *echoLib.Context) error { + close(r.started) + <-r.release + return c.NoContent(http.StatusOK) + }) +} + +func TestServer_FinalizeReturnsTheShutdownTimeout(t *testing.T) { + hook := newLogHook(t) + api := &blockingRegister{started: make(chan struct{}), release: make(chan struct{})} + builder := NewBuilder().APIRegistration(api).OverrideDefaultMiddleware(true) + builder.ListenAddress("127.0.0.1:0") + s, err := builder.build() + require.NoError(t, err) + s.shutdownTimeout = 50 * time.Millisecond + require.NoError(t, s.Initialize()) + + ctx, cancel := context.WithCancel(t.Context()) + defer cancel() + done := make(chan struct{}) + var executeErr error + go func() { + defer close(done) + executeErr = s.Execute(ctx, cancel) + }() + address := waitForListenAddress(t, hook) + + // A request is still running when the server is stopped, so the graceful shutdown reaches its timeout. + requestErr := make(chan error, 1) + go func() { + client := &http.Client{Timeout: 5 * time.Second} + resp, reqErr := client.Get("http://" + address + "/block") + if reqErr == nil { + reqErr = resp.Body.Close() + } + requestErr <- reqErr + }() + select { + case <-api.started: + case reqErr := <-requestErr: + t.Fatalf("the request ended before reaching the handler: %v", reqErr) + case <-time.After(5 * time.Second): + t.Fatal("the request didn't reach the handler") + } + cancel() + <-done + close(api.release) + // The shutdown timeout doesn't interrupt the request still running: it ends normally once released. + assert.NoError(t, <-requestErr) + + // The server stopped as requested, but its shutdown failed: the task must report it, like before echo v5. + assert.NoError(t, executeErr) + err = s.Finalize() + assert.ErrorIs(t, err, context.DeadlineExceeded) + assert.ErrorContains(t, err, "server shutdown not properly") +} + +func TestServer_FinalizeWithoutShutdownError(t *testing.T) { + hook := newLogHook(t) + address := startServer(t, hook, NewBuilder().APIRegistration(&mockRegister{}).OverrideDefaultMiddleware(true)) + assert.NotEmpty(t, address) + // startServer stops the server and checks Finalize returns no error at the end of the test. +} diff --git a/echo/timeout_test.go b/echo/timeout_test.go index b0a65cc..a6f57d9 100644 --- a/echo/timeout_test.go +++ b/echo/timeout_test.go @@ -17,7 +17,6 @@ import ( "context" "io" "net" - "net/http" "testing" "time" @@ -133,12 +132,10 @@ func TestBuild_HTTPServerTimeouts(t *testing.T) { tt.configure(builder) s, err := builder.build() require.NoError(t, err) - for _, httpServer := range []*http.Server{s.e.Server, s.e.TLSServer} { - assert.Equal(t, tt.expectedReadHeaderTimeout, httpServer.ReadHeaderTimeout) - assert.Equal(t, tt.expectedReadTimeout, httpServer.ReadTimeout) - assert.Equal(t, tt.expectedWriteTimeout, httpServer.WriteTimeout) - assert.Equal(t, tt.expectedIdleTimeout, httpServer.IdleTimeout) - } + assert.Equal(t, tt.expectedReadHeaderTimeout, s.readHeaderTimeout) + assert.Equal(t, tt.expectedReadTimeout, s.readTimeout) + assert.Equal(t, tt.expectedWriteTimeout, s.writeTimeout) + assert.Equal(t, tt.expectedIdleTimeout, s.idleTimeout) }) } } diff --git a/go.mod b/go.mod index 748c70f..146ea53 100644 --- a/go.mod +++ b/go.mod @@ -5,7 +5,7 @@ go 1.27.1 require ( github.com/flc1125/go-cron/v4 v4.14.0 github.com/fsnotify/fsnotify v1.10.1 - github.com/labstack/echo/v4 v4.16.2 + github.com/labstack/echo/v5 v5.4.4 github.com/nexucis/lamenv v0.5.2 github.com/prometheus/client_golang v1.25.0 github.com/prometheus/common v0.72.1 @@ -23,23 +23,15 @@ require ( github.com/go-logr/stdr v1.2.2 // indirect github.com/google/uuid v1.6.0 // indirect github.com/kr/text v0.2.0 // indirect - github.com/labstack/gommon v0.5.0 // indirect - github.com/mattn/go-colorable v0.1.15 // indirect - github.com/mattn/go-isatty v0.0.22 // indirect github.com/munnerz/goautoneg v0.0.0-20191010083416-a7dc8b61c822 // indirect github.com/prometheus/client_model v0.6.3 // indirect github.com/prometheus/procfs v0.22.0 // indirect - github.com/valyala/bytebufferpool v1.0.0 // indirect - github.com/valyala/fasttemplate v1.2.2 // indirect go.opentelemetry.io/auto/sdk v1.2.1 // indirect go.opentelemetry.io/otel/log v1.47.0 // indirect go.opentelemetry.io/otel/metric v1.47.0 // indirect go.opentelemetry.io/otel/trace v1.47.0 // indirect go.yaml.in/yaml/v3 v3.0.5 // indirect - golang.org/x/crypto v0.58.0 // indirect - golang.org/x/net v0.61.0 // indirect golang.org/x/sys v0.49.0 // indirect - golang.org/x/text v0.43.0 // indirect golang.org/x/time v0.15.0 // indirect google.golang.org/protobuf v1.36.12 // indirect ) diff --git a/go.sum b/go.sum index aaab321..3f23857 100644 --- a/go.sum +++ b/go.sum @@ -24,14 +24,8 @@ github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY= github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE= github.com/kylelemons/godebug v1.1.0 h1:RPNrshWIDI6G2gRW9EHilWtl7Z6Sb1BR0xunSBf0SNc= github.com/kylelemons/godebug v1.1.0/go.mod h1:9/0rRGxNHcop5bhtWyNeEfOS8JIWk580+fNqagV/RAw= -github.com/labstack/echo/v4 v4.16.2 h1:WFPVqfogOZGH4dTr1UCIB1sqjFIQ/k7vIk5ByL6oWjY= -github.com/labstack/echo/v4 v4.16.2/go.mod h1:V/EQaTVHYJH92QhbQe7kFQ4mjgcjxLQQUQtAN87zZdw= -github.com/labstack/gommon v0.5.0 h1:6VSQ2NOzsnEJ5W6+84E0RbcaDDmgB6NIAzWCczTEe6c= -github.com/labstack/gommon v0.5.0/go.mod h1:Rzlg7HHy1maLfzBYGg9NZcVuz1sA68HHhLjhcEllYE0= -github.com/mattn/go-colorable v0.1.15 h1:+u9SLTRGnXv73cEsnsmoZBom+dMU88B2M0aDcWy0/jY= -github.com/mattn/go-colorable v0.1.15/go.mod h1:6LmQG8QLFO4G5z1gPvYEzlUgJ2wF+stgPZH1UqBm1s8= -github.com/mattn/go-isatty v0.0.22 h1:j8l17JJ9i6VGPUFUYoTUKPSgKe/83EYU2zBC7YNKMw4= -github.com/mattn/go-isatty v0.0.22/go.mod h1:ZXfXG4SQHsB/w3ZeOYbR0PrPwLy+n6xiMrJlRFqopa4= +github.com/labstack/echo/v5 v5.4.4 h1:Nag9Mee0M9sOcKjProYuDNiw60QisysgfbIgz5US5Cw= +github.com/labstack/echo/v5 v5.4.4/go.mod h1:4iEGNQiPPZnkfYpNR/L6fINd3NLiGWUD5+eBotFALas= github.com/munnerz/goautoneg v0.0.0-20191010083416-a7dc8b61c822 h1:C3w9PqII01/Oq1c1nUAm88MOHcQC9l5mIlSMApZMrHA= github.com/munnerz/goautoneg v0.0.0-20191010083416-a7dc8b61c822/go.mod h1:+n7T8mK8HuQTcFwEeznm/DIxMOiR9yIdICNftLE1DvQ= github.com/nexucis/lamenv v0.5.2 h1:tK/u3XGhCq9qIoVNcXsK9LZb8fKopm0A5weqSRvHd7M= @@ -50,10 +44,6 @@ github.com/sirupsen/logrus v1.10.2 h1:G2SED73/qrAu6YwbdxOD6peLkCBI3z7L+ykJFTXJBB github.com/sirupsen/logrus v1.10.2/go.mod h1:SLEg8TqYulVKKfIGHldVp2K2aYz2DKSVBq4g/H5bR7Q= github.com/stretchr/testify v1.12.1 h1:EuwCh5fleGS7H32xRwO3wRGT7DxrDhLAT6FF8MpWDWE= github.com/stretchr/testify v1.12.1/go.mod h1:MDEgiDPPsNp5cuIrHPPCyornHKgEVbtFUmoNlxoYthg= -github.com/valyala/bytebufferpool v1.0.0 h1:GqA5TC/0021Y/b9FG4Oi9Mr3q7XYx6KllzawFIhcdPw= -github.com/valyala/bytebufferpool v1.0.0/go.mod h1:6bBcMArwyJ5K/AmCkWv1jt77kVWyCJ6HpOuEn7z0Csc= -github.com/valyala/fasttemplate v1.2.2 h1:lxLXG0uE3Qnshl9QyaK6XJxMXlQZELvChBOCmQD0Loo= -github.com/valyala/fasttemplate v1.2.2/go.mod h1:KHLXt3tVN2HBp8eijSv/kGJopbvo7S+qRAEEKiv+SiQ= go.opentelemetry.io/auto/sdk v1.2.1 h1:jXsnJ4Lmnqd11kwkBV2LgLoFMZKizbCi5fNZ/ipaZ64= go.opentelemetry.io/auto/sdk v1.2.1/go.mod h1:KRTj+aOaElaLi+wW1kO/DZRXwkF4C5xPbEe3ZiIhN7Y= go.opentelemetry.io/otel v1.47.0 h1:j7ALJ/zgkS7Z6aeJW09p8VC9804bC+PpeTfCD4XPnOM= @@ -74,8 +64,6 @@ go.yaml.in/yaml/v2 v2.4.4 h1:tuyd0P+2Ont/d6e2rl3be67goVK4R6deVxCUX5vyPaQ= go.yaml.in/yaml/v2 v2.4.4/go.mod h1:gMZqIpDtDqOfM0uNfy0SkpRhvUryYH0Z6wdMYcacYXQ= go.yaml.in/yaml/v3 v3.0.5 h1:N6y/pJk8buWs9NY5ERU2HSMfm+IuD/OtfdAnq6kESPw= go.yaml.in/yaml/v3 v3.0.5/go.mod h1:HVTZu1O7/Vkt2N+BFy8Zza+lnLsABggaTM2ZpNIGuKg= -golang.org/x/crypto v0.58.0 h1:COkYLr4k7nDI4r6QtMML2AfzeIswWHAJthLS6K/M/54= -golang.org/x/crypto v0.58.0/go.mod h1:Xh+kl5A+M0gMiWDytH2Hhr5Z7WbNCpv/eB/EFgfSk+w= golang.org/x/net v0.61.0 h1:RR+6j/BTBCrggOLugxa+66R8FvoN6MHlzDlZIbN9YFw= golang.org/x/net v0.61.0/go.mod h1:WgDCOTH8iwtB66T4/GfI94AHo/hhdb7Hah9NDseQfiI= golang.org/x/sys v0.49.0 h1:XbzkgYJHdqh/8m2Uu0W/dQv8nktxx4BFHp1M0gROTXA=