From 6b80477a14a0d7ee69ea78bee64b0b381a322d42 Mon Sep 17 00:00:00 2001 From: rosstimothy <39066650+rosstimothy@users.noreply.github.com> Date: Thu, 19 Dec 2024 16:35:18 -0500 Subject: [PATCH] Convert lib/web to use slog (#50407) --- integration/kube_integration_test.go | 4 +- lib/service/service.go | 6 +- lib/web/addr.go | 9 +- lib/web/apiserver.go | 230 ++++++++++++++------------- lib/web/apiserver_test.go | 10 +- lib/web/apiserver_test_utils.go | 4 +- lib/web/apps.go | 14 +- lib/web/autoupdate_rfd109.go | 4 +- lib/web/desktop.go | 67 +++++--- lib/web/desktop/playback.go | 21 +-- lib/web/desktop/playback_test.go | 3 +- lib/web/desktop_playback.go | 6 +- lib/web/device_trust.go | 18 +-- lib/web/features.go | 14 +- lib/web/features_test.go | 1 - lib/web/headless.go | 2 +- lib/web/integrations_awsoidc.go | 2 +- lib/web/join_tokens.go | 37 +++-- lib/web/kube.go | 64 +++++--- lib/web/server.go | 13 +- lib/web/sessions.go | 146 +++++++++-------- lib/web/terminal.go | 89 +++++------ lib/web/terminal/terminal.go | 39 ++--- lib/web/terminal_test.go | 5 +- lib/web/tty_playback.go | 33 ++-- lib/web/ui/app.go | 8 +- lib/web/user_groups.go | 4 +- lib/web/web.go | 34 ---- 28 files changed, 459 insertions(+), 428 deletions(-) delete mode 100644 lib/web/web.go diff --git a/integration/kube_integration_test.go b/integration/kube_integration_test.go index ad7d745d89452..c9fd5ff21efdb 100644 --- a/integration/kube_integration_test.go +++ b/integration/kube_integration_test.go @@ -1768,7 +1768,7 @@ func testKubeExecWeb(t *testing.T, suite *KubeSuite) { ws := openWebsocketAndReadSession(t, endpoint, req) - wsStream := terminal.NewWStream(context.Background(), ws, suite.log, nil) + wsStream := terminal.NewWStream(context.Background(), ws, utils.NewSlogLoggerForTests(), nil) // Check for the expected string in the output. findTextInReader(t, wsStream, testNamespace, time.Second*2) @@ -1789,7 +1789,7 @@ func testKubeExecWeb(t *testing.T, suite *KubeSuite) { ws := openWebsocketAndReadSession(t, endpoint, req) - wsStream := terminal.NewWStream(context.Background(), ws, suite.log, nil) + wsStream := terminal.NewWStream(context.Background(), ws, utils.NewSlogLoggerForTests(), nil) // Read first prompt from the server. readData := make([]byte, 255) diff --git a/lib/service/service.go b/lib/service/service.go index 39666c2aa1d91..ebdb99b6a282b 100644 --- a/lib/service/service.go +++ b/lib/service/service.go @@ -4723,7 +4723,7 @@ func (process *TeleportProcess) initProxyEndpoint(conn *Connector) error { }, }, Handler: webHandler, - Log: process.log.WithField(teleport.ComponentKey, teleport.Component(teleport.ComponentReverseTunnelServer, process.id)), + Log: process.logger.With(teleport.ComponentKey, teleport.Component(teleport.ComponentReverseTunnelServer, process.id)), }) if err != nil { return trace.Wrap(err) @@ -5517,7 +5517,7 @@ func (process *TeleportProcess) initMinimalReverseTunnel(listeners *proxyListene return nil }) - log := process.log.WithField(teleport.ComponentKey, teleport.Component(teleport.ComponentReverseTunnelServer, process.id)) + log := process.logger.With(teleport.ComponentKey, teleport.Component(teleport.ComponentReverseTunnelServer, process.id)) minimalWebServer, err := web.NewServer(web.ServerConfig{ Server: &http.Server{ @@ -5526,7 +5526,7 @@ func (process *TeleportProcess) initMinimalReverseTunnel(listeners *proxyListene ReadHeaderTimeout: defaults.ReadHeadersTimeout, WriteTimeout: apidefaults.DefaultIOTimeout, IdleTimeout: apidefaults.DefaultIdleTimeout, - ErrorLog: utils.NewStdlogger(log.Error, teleport.ComponentReverseTunnelServer), + ErrorLog: slog.NewLogLogger(log.Handler(), slog.LevelError), }, Handler: minimalWebHandler, Log: log, diff --git a/lib/web/addr.go b/lib/web/addr.go index f82173b6f7796..3c23bf0637c85 100644 --- a/lib/web/addr.go +++ b/lib/web/addr.go @@ -20,13 +20,14 @@ package web import ( "bufio" + "context" + "log/slog" "net" "net/http" "net/netip" "strings" "github.com/gravitational/trace" - "github.com/sirupsen/logrus" "github.com/gravitational/teleport/lib/authz" "github.com/gravitational/teleport/lib/utils" @@ -56,7 +57,7 @@ func NewXForwardedForMiddleware(next http.Handler) http.Handler { // Serve with updated client source address. default: next.ServeHTTP( - responseWriterWithClientSrcAddr(w, clientSrcAddr), + responseWriterWithClientSrcAddr(r.Context(), w, clientSrcAddr), requestWithClientSrcAddr(r, clientSrcAddr), ) } @@ -113,11 +114,11 @@ func requestWithClientSrcAddr(r *http.Request, clientSrcAddr net.Addr) *http.Req return r } -func responseWriterWithClientSrcAddr(w http.ResponseWriter, clientSrcAddr net.Addr) http.ResponseWriter { +func responseWriterWithClientSrcAddr(ctx context.Context, w http.ResponseWriter, clientSrcAddr net.Addr) http.ResponseWriter { // Returns the original ResponseWriter if not a http.Hijacker. _, ok := w.(http.Hijacker) if !ok { - logrus.Debug("Provided ResponseWriter is not a hijacker.") + slog.DebugContext(ctx, "Provided ResponseWriter is not a hijacker") return w } diff --git a/lib/web/apiserver.go b/lib/web/apiserver.go index 597360e64df8a..a81932f586de4 100644 --- a/lib/web/apiserver.go +++ b/lib/web/apiserver.go @@ -49,7 +49,6 @@ import ( "github.com/gravitational/trace" "github.com/jonboulle/clockwork" "github.com/julienschmidt/httprouter" - "github.com/sirupsen/logrus" "go.opentelemetry.io/otel/exporters/otlp/otlptrace" oteltrace "go.opentelemetry.io/otel/trace" tracepb "go.opentelemetry.io/proto/otlp/trace/v1" @@ -102,6 +101,7 @@ import ( "github.com/gravitational/teleport/lib/session" "github.com/gravitational/teleport/lib/tlsca" "github.com/gravitational/teleport/lib/utils" + logutils "github.com/gravitational/teleport/lib/utils/log" "github.com/gravitational/teleport/lib/web/app" websession "github.com/gravitational/teleport/lib/web/session" "github.com/gravitational/teleport/lib/web/terminal" @@ -146,8 +146,6 @@ type healthCheckAppServerFunc func(ctx context.Context, publicAddr string, clust // Handler is HTTP web proxy handler type Handler struct { - // TODO(greedy52) deprecate logrus.FieldLogger. - log logrus.FieldLogger logger *slog.Logger sync.Mutex @@ -356,12 +354,12 @@ func (h *APIHandler) handlePreflight(w http.ResponseWriter, r *http.Request) { servers, err := app.Match(r.Context(), h.handler.cfg.AccessPoint, app.MatchPublicAddr(publicAddr)) if err != nil { - h.handler.log.Info("failed to match application with public addr %s", publicAddr) + h.handler.logger.InfoContext(r.Context(), "failed to match application with public addr", "public_addr", publicAddr) return } if len(servers) == 0 { - h.handler.log.Info("failed to match application with public addr %s", publicAddr) + h.handler.logger.InfoContext(r.Context(), "failed to match application with public addr", "public_addr", publicAddr) return } @@ -454,7 +452,6 @@ func NewHandler(cfg Config, opts ...HandlerOption) (*APIHandler, error) { h := &Handler{ cfg: cfg, - log: newPackageLogger(), logger: slog.Default().With(teleport.ComponentKey, teleport.ComponentWeb), clock: clockwork.NewRealClock(), clusterFeatures: cfg.ClusterFeatures, @@ -512,6 +509,7 @@ func NewHandler(cfg Config, opts ...HandlerOption) (*APIHandler, error) { clock: h.clock, sessionLingeringThreshold: sessionLingeringThreshold, proxySigner: cfg.PROXYSigner, + logger: h.logger, }) if err != nil { return nil, trace.Wrap(err) @@ -521,8 +519,11 @@ func NewHandler(cfg Config, opts ...HandlerOption) (*APIHandler, error) { if cfg.ProxySSHAddr.String() != "" { _, sshPort, err := net.SplitHostPort(cfg.ProxySSHAddr.String()) if err != nil { - h.log.WithError(err).Warnf("Invalid SSH proxy address %q, will use default port %v.", - cfg.ProxySSHAddr.String(), defaults.SSHProxyListenPort) + h.logger.WarnContext(h.cfg.Context, "Invalid SSH proxy address, will use default port", + "error", err, + "ssh_proxy_addr", logutils.StringerAttr(&cfg.ProxySSHAddr), + "default_port", defaults.SSHProxyListenPort, + ) } else { sshPortValue = sshPort } @@ -581,7 +582,7 @@ func NewHandler(cfg Config, opts ...HandlerOption) (*APIHandler, error) { if cfg.StaticFS != nil { index, err := cfg.StaticFS.Open("/index.html") if err != nil { - h.log.WithError(err).Error("Failed to open index file.") + h.logger.ErrorContext(h.cfg.Context, "Failed to open index file", "error", err) return nil, trace.Wrap(err) } defer index.Close() @@ -598,7 +599,7 @@ func NewHandler(cfg Config, opts ...HandlerOption) (*APIHandler, error) { etagFromAppHash, err := readEtagFromAppHash(cfg.StaticFS) if err != nil { - h.log.WithError(err).Error("Could not read apphash from embedded webassets. Using version only as ETag for Web UI assets.") + h.logger.ErrorContext(h.cfg.Context, "Could not read apphash from embedded webassets. Using version only as ETag for Web UI assets", "error", err) } else { etag = etagFromAppHash } @@ -653,12 +654,12 @@ func NewHandler(cfg Config, opts ...HandlerOption) (*APIHandler, error) { } else if strings.HasPrefix(r.URL.Path, "/web/") || r.URL.Path == "/web" { csrfToken, err := csrf.AddCSRFProtection(w, r) if err != nil { - h.log.WithError(err).Warn("Failed to generate CSRF token.") + h.logger.WarnContext(r.Context(), "Failed to generate CSRF token", "error", err) } session, err := h.authenticateWebSession(w, r) if err != nil { - h.log.Debugf("Could not authenticate: %v", err) + h.logger.DebugContext(r.Context(), "Could not authenticate", "error", err) } session.XCSRF = csrfToken @@ -666,7 +667,7 @@ func NewHandler(cfg Config, opts ...HandlerOption) (*APIHandler, error) { httplib.SetIndexContentSecurityPolicy(w.Header(), cfg.ClusterFeatures, r.URL.Path) if err := indexPage.Execute(w, session); err != nil { - h.log.WithError(err).Error("Failed to execute index page template.") + h.logger.ErrorContext(r.Context(), "Failed to execute index page template", "error", err) } } else { http.NotFound(w, r) @@ -1274,7 +1275,7 @@ func (h *Handler) AccessGraphAddr() utils.NetAddr { return h.cfg.AccessGraphAddr } -func localSettings(cap types.AuthPreference) (webclient.AuthenticationSettings, error) { +func localSettings(ctx context.Context, cap types.AuthPreference, logger *slog.Logger) (webclient.AuthenticationSettings, error) { as := webclient.AuthenticationSettings{ Type: constants.Local, SecondFactor: types.LegacySecondFactorFromSecondFactors(cap.GetSecondFactors()), @@ -1298,7 +1299,7 @@ func localSettings(cap types.AuthPreference) (webclient.AuthenticationSettings, case err == nil: as.U2F = &webclient.U2FSettings{AppID: u2f.AppID} case !trace.IsNotFound(err): - log.WithError(err).Warnf("Error reading U2F settings") + logger.WarnContext(ctx, "Error reading U2F settings", "error", err) } // Webauthn settings. @@ -1308,7 +1309,7 @@ func localSettings(cap types.AuthPreference) (webclient.AuthenticationSettings, RPID: webConfig.RPID, } case !trace.IsNotFound(err): - log.WithError(err).Warnf("Error reading WebAuthn settings") + logger.WarnContext(ctx, "Error reading WebAuthn settings", "error", err) } return as, nil @@ -1386,7 +1387,7 @@ func deviceTrustDisabled(cap types.AuthPreference) bool { return dtconfig.GetEffectiveMode(cap.GetDeviceTrust()) == constants.DeviceTrustModeOff } -func getAuthSettings(ctx context.Context, authClient authclient.ClientI) (webclient.AuthenticationSettings, error) { +func getAuthSettings(ctx context.Context, authClient authclient.ClientI, logger *slog.Logger) (webclient.AuthenticationSettings, error) { authPreference, err := authClient.GetAuthPreference(ctx) if err != nil { return webclient.AuthenticationSettings{}, trace.Wrap(err) @@ -1396,7 +1397,7 @@ func getAuthSettings(ctx context.Context, authClient authclient.ClientI) (webcli switch authPreference.GetType() { case constants.Local: - as, err = localSettings(authPreference) + as, err = localSettings(ctx, authPreference, logger) if err != nil { return webclient.AuthenticationSettings{}, trace.Wrap(err) } @@ -1475,18 +1476,18 @@ func getAuthSettings(ctx context.Context, authClient authclient.ClientI) (webcli func (h *Handler) traces(w http.ResponseWriter, r *http.Request, _ httprouter.Params, _ *SessionContext) (interface{}, error) { body, err := utils.ReadAtMost(r.Body, teleport.MaxHTTPResponseSize) if err != nil { - h.log.WithError(err).Error("Failed to read traces request") + h.logger.ErrorContext(r.Context(), "Failed to read traces request", "error", err) w.WriteHeader(http.StatusBadRequest) return nil, nil } if err := r.Body.Close(); err != nil { - h.log.WithError(err).Warn("Failed to close traces request body") + h.logger.WarnContext(r.Context(), "Failed to close traces request body", "error", err) } var data tracepb.TracesData if err := protojson.Unmarshal(body, &data); err != nil { - h.log.WithError(err).Error("Failed to unmarshal traces request") + h.logger.ErrorContext(r.Context(), "Failed to unmarshal traces request", "error", err) w.WriteHeader(http.StatusBadRequest) return nil, nil } @@ -1531,7 +1532,7 @@ func (h *Handler) traces(w http.ResponseWriter, r *http.Request, _ httprouter.Pa ctx, cancel := context.WithTimeout(context.Background(), 30*time.Second) defer cancel() if err := h.cfg.TraceClient.UploadTraces(ctx, data.ResourceSpans); err != nil { - h.log.WithError(err).Error("Failed to upload traces") + h.logger.ErrorContext(ctx, "Failed to upload traces", "error", err) } }() @@ -1541,7 +1542,7 @@ func (h *Handler) traces(w http.ResponseWriter, r *http.Request, _ httprouter.Pa func (h *Handler) ping(w http.ResponseWriter, r *http.Request, p httprouter.Params) (interface{}, error) { var err error - authSettings, err := getAuthSettings(r.Context(), h.cfg.ProxyClient) + authSettings, err := getAuthSettings(r.Context(), h.cfg.ProxyClient, h.logger) if err != nil { return nil, trace.Wrap(err) } @@ -1635,7 +1636,7 @@ func (h *Handler) pingWithConnector(w http.ResponseWriter, r *http.Request, p ht hasMessageOfTheDay := cap.GetMessageOfTheDay() != "" if slices.Contains(constants.SystemConnectors, connectorName) { - response.Auth, err = localSettings(cap) + response.Auth, err = localSettings(r.Context(), cap, h.logger) if err != nil { return nil, trace.Wrap(err) } @@ -1706,7 +1707,7 @@ func (h *Handler) getWebConfig(w http.ResponseWriter, r *http.Request, p httprou // get all OIDC connectors oidcConnectors, err := h.cfg.ProxyClient.GetOIDCConnectors(r.Context(), false) if err != nil { - h.log.WithError(err).Error("Cannot retrieve OIDC connectors.") + h.logger.ErrorContext(r.Context(), "Cannot retrieve OIDC connectors", "error", err) } for _, item := range oidcConnectors { authProviders = append(authProviders, webclient.WebConfigAuthProvider{ @@ -1720,7 +1721,7 @@ func (h *Handler) getWebConfig(w http.ResponseWriter, r *http.Request, p httprou // get all SAML connectors samlConnectors, err := h.cfg.ProxyClient.GetSAMLConnectors(r.Context(), false) if err != nil { - h.log.WithError(err).Error("Cannot retrieve SAML connectors.") + h.logger.ErrorContext(r.Context(), "Cannot retrieve SAML connectors", "error", err) } for _, item := range samlConnectors { authProviders = append(authProviders, webclient.WebConfigAuthProvider{ @@ -1734,7 +1735,7 @@ func (h *Handler) getWebConfig(w http.ResponseWriter, r *http.Request, p httprou // get all Github connectors githubConnectors, err := h.cfg.ProxyClient.GetGithubConnectors(r.Context(), false) if err != nil { - h.log.WithError(err).Error("Cannot retrieve GitHub connectors.") + h.logger.ErrorContext(r.Context(), "Cannot retrieve GitHub connectors", "error", err) } for _, item := range githubConnectors { authProviders = append(authProviders, webclient.WebConfigAuthProvider{ @@ -1748,7 +1749,7 @@ func (h *Handler) getWebConfig(w http.ResponseWriter, r *http.Request, p httprou // get auth type & second factor type var authSettings webclient.WebConfigAuthSettings if cap, err := h.cfg.ProxyClient.GetAuthPreference(r.Context()); err != nil { - h.log.WithError(err).Error("Cannot retrieve AuthPreferences.") + h.logger.ErrorContext(r.Context(), "Cannot retrieve AuthPreferences", "error", err) authSettings = webclient.WebConfigAuthSettings{ Providers: authProviders, SecondFactor: constants.SecondFactorOff, @@ -1782,7 +1783,7 @@ func (h *Handler) getWebConfig(w http.ResponseWriter, r *http.Request, p httprou tunnelPublicAddr := "" proxyConfig, err := h.cfg.ProxySettings.GetProxySettings(r.Context()) if err != nil { - h.log.WithError(err).Warn("Cannot retrieve ProxySettings, tunnel address won't be set in Web UI.") + h.logger.WarnContext(r.Context(), "Cannot retrieve ProxySettings, tunnel address won't be set in Web UI", "error", err) } else { if clusterFeatures.GetCloud() { tunnelPublicAddr = proxyConfig.SSH.TunnelPublicAddr @@ -1793,7 +1794,7 @@ func (h *Handler) getWebConfig(w http.ResponseWriter, r *http.Request, p httprou canJoinSessions := true recCfg, err := h.cfg.ProxyClient.GetSessionRecordingConfig(r.Context()) if err != nil { - h.log.WithError(err).Error("Cannot retrieve SessionRecordingConfig.") + h.logger.ErrorContext(r.Context(), "Cannot retrieve SessionRecordingConfig", "error", err) } else { canJoinSessions = !services.IsRecordAtProxy(recCfg.GetMode()) } @@ -1803,7 +1804,7 @@ func (h *Handler) getWebConfig(w http.ResponseWriter, r *http.Request, p httprou if automaticUpgradesEnabled { automaticUpgradesTargetVersion, err = h.cfg.AutomaticUpgradesChannels.DefaultVersion(r.Context()) if err != nil { - h.log.WithError(err).Error("Cannot read target version") + h.logger.ErrorContext(r.Context(), "Cannot read target version", "error", err) } } @@ -1834,7 +1835,7 @@ func (h *Handler) getWebConfig(w http.ResponseWriter, r *http.Request, p httprou resource, err := h.cfg.ProxyClient.GetClusterName() if err != nil { - h.log.WithError(err).Warn("Failed to query cluster name.") + h.logger.WarnContext(r.Context(), "Failed to query cluster name", "error", err) } else { webCfg.ProxyClusterName = resource.GetClusterName() } @@ -1979,18 +1980,18 @@ func (h *Handler) motd(w http.ResponseWriter, r *http.Request, p httprouter.Para } func (h *Handler) githubLoginWeb(w http.ResponseWriter, r *http.Request, p httprouter.Params) string { - logger := h.log.WithField("auth", "github") - logger.Debug("Web login start.") + logger := h.logger.With("auth", "github") + logger.DebugContext(r.Context(), "Web login start") req, err := ParseSSORequestParams(r) if err != nil { - logger.WithError(err).Error("Failed to extract SSO parameters from request.") + logger.ErrorContext(r.Context(), "Failed to extract SSO parameters from request", "error", err) return client.LoginFailedRedirectURL } remoteAddr, _, err := net.SplitHostPort(r.RemoteAddr) if err != nil { - logger.WithError(err).Error("Failed to parse request remote address.") + logger.ErrorContext(r.Context(), "Failed to parse request remote address", "error", err) return client.LoginFailedRedirectURL } @@ -2002,7 +2003,7 @@ func (h *Handler) githubLoginWeb(w http.ResponseWriter, r *http.Request, p httpr ClientUserAgent: r.UserAgent(), }) if err != nil { - logger.WithError(err).Error("Error creating auth request.") + logger.ErrorContext(r.Context(), "Error creating auth request", "error", err) return client.LoginFailedRedirectURL } @@ -2010,23 +2011,23 @@ func (h *Handler) githubLoginWeb(w http.ResponseWriter, r *http.Request, p httpr } func (h *Handler) githubLoginConsole(w http.ResponseWriter, r *http.Request, p httprouter.Params) (interface{}, error) { - logger := h.log.WithField("auth", "github") - logger.Debug("Console login start.") + logger := h.logger.With("auth", "github") + logger.DebugContext(r.Context(), "Console login start") req := new(client.SSOLoginConsoleReq) if err := httplib.ReadResourceJSON(r, req); err != nil { - logger.WithError(err).Error("Error reading json.") + logger.ErrorContext(r.Context(), "Error reading json", "error", err) return nil, trace.AccessDenied(SSOLoginFailureMessage) } if err := req.CheckAndSetDefaults(); err != nil { - logger.WithError(err).Error("Missing request parameters.") + logger.ErrorContext(r.Context(), "Missing request parameters", "error", err) return nil, trace.AccessDenied(SSOLoginFailureMessage) } remoteAddr, _, err := net.SplitHostPort(r.RemoteAddr) if err != nil { - logger.WithError(err).Error("Failed to parse request remote address.") + logger.ErrorContext(r.Context(), "Failed to parse request remote address", "error", err) return nil, trace.AccessDenied(SSOLoginFailureMessage) } @@ -2044,7 +2045,7 @@ func (h *Handler) githubLoginConsole(w http.ResponseWriter, r *http.Request, p h ClientLoginIP: remoteAddr, }) if err != nil { - logger.WithError(err).Error("Failed to create GitHub auth request.") + logger.ErrorContext(r.Context(), "Failed to create GitHub auth request", "error", err) if strings.Contains(err.Error(), auth.InvalidClientRedirectErrorMessage) { return nil, trace.AccessDenied(SSOLoginFailureInvalidRedirect) } @@ -2057,12 +2058,12 @@ func (h *Handler) githubLoginConsole(w http.ResponseWriter, r *http.Request, p h } func (h *Handler) githubCallback(w http.ResponseWriter, r *http.Request, p httprouter.Params) string { - logger := h.log.WithField("auth", "github") - logger.Debugf("Callback start: %v.", r.URL.Query()) + logger := h.logger.With("auth", "github") + logger.DebugContext(r.Context(), "Callback start", "query", r.URL.Query()) response, err := h.cfg.ProxyClient.ValidateGithubAuthCallback(r.Context(), r.URL.Query()) if err != nil { - logger.WithError(err).Error("Error while processing callback.") + logger.ErrorContext(r.Context(), "Error while processing callback", "error", err) // try to find the auth request, which bears the original client redirect URL. // if found, use it to terminate the flow. @@ -2084,7 +2085,7 @@ func (h *Handler) githubCallback(w http.ResponseWriter, r *http.Request, p httpr // if we created web session, set session cookie and redirect to original url if response.Req.CreateWebSession { - logger.Infof("Redirecting to web browser.") + logger.InfoContext(r.Context(), "Redirecting to web browser") res := &SSOCallbackResponse{ CSRFToken: response.Req.CSRFToken, @@ -2094,26 +2095,26 @@ func (h *Handler) githubCallback(w http.ResponseWriter, r *http.Request, p httpr } if err := SSOSetWebSessionAndRedirectURL(w, r, res, true); err != nil { - logger.WithError(err).Error("Error setting web session.") + logger.ErrorContext(r.Context(), "Error setting web session.", "error", err) return client.LoginFailedRedirectURL } if dwt := response.Session.GetDeviceWebToken(); dwt != nil { - logger.Debug("GitHub WebSession created with device web token") + logger.DebugContext(r.Context(), "GitHub WebSession created with device web token") // if a device web token is present, we must send the user to the device authorize page // to upgrade the session. redirectPath, err := BuildDeviceWebRedirectPath(dwt, res.ClientRedirectURL) if err != nil { - logger.WithError(err).Debug("Invalid device web token.") + logger.DebugContext(r.Context(), "Invalid device web token", "error", err) } return redirectPath } return res.ClientRedirectURL } - logger.Infof("Callback is redirecting to console login.") + logger.InfoContext(r.Context(), "Callback is redirecting to console login") if len(response.Req.SSHPubKey)+len(response.Req.TLSPubKey) == 0 { - logger.Error("Not a web or console login request.") + logger.ErrorContext(r.Context(), "Not a web or console login request") return client.LoginFailedRedirectURL } @@ -2128,7 +2129,7 @@ func (h *Handler) githubCallback(w http.ResponseWriter, r *http.Request, p httpr FIPS: h.cfg.FIPS, }) if err != nil { - logger.WithError(err).Error("Error constructing ssh response") + logger.ErrorContext(r.Context(), "Error constructing ssh response", "error", err) return client.LoginFailedRedirectURL } @@ -2407,7 +2408,7 @@ func (h *Handler) createWebSession(w http.ResponseWriter, r *http.Request, p htt return nil, trace.AccessDenied("direct login with password+otp not supported by this cluster") } if err != nil { - h.log.WithError(err).Warnf("Access attempt denied for user %q.", req.User) + h.logger.WarnContext(r.Context(), "Access attempt denied for user", "user", req.User, "error", err) // Since checking for private key policy meant that they passed authn, // return policy error as is to help direct user. if keys.IsPrivateKeyPolicyError(err) { @@ -2423,7 +2424,7 @@ func (h *Handler) createWebSession(w http.ResponseWriter, r *http.Request, p htt ctx, err := h.auth.newSessionContextFromSession(r.Context(), webSession) if err != nil { - h.log.WithError(err).Warnf("Access attempt denied for user %q.", req.User) + h.logger.WarnContext(r.Context(), "Access attempt denied for user", "user", req.User, "error", err) return nil, trace.AccessDenied("need auth") } @@ -2453,9 +2454,10 @@ func clientMetaFromReq(r *http.Request) *authclient.ForwardedClientMetadata { func (h *Handler) deleteWebSession(w http.ResponseWriter, r *http.Request, _ httprouter.Params, ctx *SessionContext) (interface{}, error) { clt, err := ctx.GetClient() if err != nil { - h.log. - WithError(err). - Warnf("Failed to retrieve user client, SAML single logout will be skipped for user %s.", ctx.GetUser()) + h.logger.WarnContext(r.Context(), "Failed to retrieve user client, SAML single logout will be skipped for user", + "user", ctx.GetUser(), + "error", err, + ) } var user types.User @@ -2463,9 +2465,10 @@ func (h *Handler) deleteWebSession(w http.ResponseWriter, r *http.Request, _ htt if err == nil { user, err = clt.GetUser(r.Context(), ctx.GetUser(), false) if err != nil { - h.log. - WithError(err). - Warnf("Failed to retrieve user during logout, SAML single logout will be skipped for user %s.", ctx.GetUser()) + h.logger.WarnContext(r.Context(), "Failed to retrieve user during logout, SAML single logout will be skipped for user", + "user", ctx.GetUser(), + "error", err, + ) } } @@ -2486,17 +2489,17 @@ func (h *Handler) deleteWebSession(w http.ResponseWriter, r *http.Request, _ htt func (h *Handler) logout(ctx context.Context, w http.ResponseWriter, sctx *SessionContext) error { if err := sctx.Invalidate(ctx); err != nil { - h.log. - WithError(err). - WithField("user", sctx.GetUser()). - Warn("Failed to invalidate sessions") + h.logger.WarnContext(ctx, "Failed to invalidate sessions", + "user", sctx.GetUser(), + "error", err, + ) } - if err := h.auth.releaseResources(sctx.GetUser(), sctx.GetSessionID()); err != nil { - h.log. - WithError(err). - WithField("session_id", sctx.GetSessionID()). - Debug("sessionCache: Failed to release web session") + if err := h.auth.releaseResources(ctx, sctx.GetUser(), sctx.GetSessionID()); err != nil { + h.logger.DebugContext(ctx, "sessionCache: Failed to release web session", + "session_id", sctx.GetSessionID(), + "error", err, + ) } clearSessionCookies(w) @@ -2679,7 +2682,7 @@ func (h *Handler) createResetPasswordToken(w http.ResponseWriter, r *http.Reques func (h *Handler) getResetPasswordTokenHandle(w http.ResponseWriter, r *http.Request, p httprouter.Params) (interface{}, error) { result, err := h.getResetPasswordToken(r.Context(), p.ByName("token")) if err != nil { - h.log.WithError(err).Warn("Failed to fetch a reset password token.") + h.logger.WarnContext(r.Context(), "Failed to fetch a reset password token", "error", err) // We hide the error from the remote user to avoid giving any hints. return nil, trace.AccessDenied("bad or expired token") } @@ -3039,7 +3042,7 @@ func (h *Handler) getUserGroupLookup(ctx context.Context, clt apiclient.GetResou UseSearchAsRoles: true, }) if err != nil { - h.log.Infof("Unable to fetch user groups while listing applications, unable to display associated user groups: %v", err) + h.logger.InfoContext(ctx, "Unable to fetch user groups while listing applications, unable to display associated user groups", "error", err) } for _, userGroup := range userGroups { @@ -3109,7 +3112,7 @@ func (h *Handler) clusterUnifiedResourcesGet(w http.ResponseWriter, request *htt AppClusterName: site.GetName(), AllowedAWSRolesLookup: allowedAWSRolesLookup, UserGroupLookup: getUserGroupLookup(), - Logger: h.log, + Logger: h.logger, RequiresRequest: enriched.RequiresRequest, }) unifiedResources = append(unifiedResources, app) @@ -3129,7 +3132,7 @@ func (h *Handler) clusterUnifiedResourcesGet(w http.ResponseWriter, request *htt AppClusterName: site.GetName(), AllowedAWSRolesLookup: allowedAWSRolesLookup, UserGroupLookup: getUserGroupLookup(), - Logger: h.log, + Logger: h.logger, RequiresRequest: enriched.RequiresRequest, }) unifiedResources = append(unifiedResources, app) @@ -3533,9 +3536,9 @@ func (h *Handler) siteNodeConnect( clusterName := site.GetName() if req.SessionID.IsZero() { // An existing session ID was not provided so we need to create a new one. - sessionData, err = h.generateSession(&req, clusterName, sessionCtx) + sessionData, err = h.generateSession(r.Context(), &req, clusterName, sessionCtx) if err != nil { - h.log.WithError(err).Debug("Unable to generate new ssh session.") + h.logger.DebugContext(r.Context(), "Unable to generate new ssh session", "error", err) return nil, trace.Wrap(err) } } else { @@ -3556,19 +3559,23 @@ func (h *Handler) siteNodeConnect( } } - h.log.Debugf("New terminal request for server=%s, login=%s, sid=%s, websid=%s.", - req.Server, req.Login, sessionData.ID, sessionCtx.GetSessionID()) + h.logger.DebugContext(r.Context(), "New terminal request", + "server", req.Server, + "login", req.Login, + "sid", sessionData.ID, + "websid", sessionCtx.GetSessionID(), + ) authAccessPoint, err := site.CachingAccessPoint() if err != nil { - h.log.Debugf("Unable to get auth access point: %v", err) + h.logger.DebugContext(r.Context(), "Unable to get auth access point", "error", err) return nil, trace.Wrap(err) } dialTimeout := apidefaults.DefaultIOTimeout keepAliveInterval := apidefaults.KeepAliveInterval() if netConfig, err := authAccessPoint.GetClusterNetworkingConfig(ctx); err != nil { - h.log.WithError(err).Debug("Unable to fetch cluster networking config.") + h.logger.DebugContext(r.Context(), "Unable to fetch cluster networking config", "error", err) } else { dialTimeout = netConfig.GetSSHDialTimeout() keepAliveInterval = netConfig.GetKeepAliveInterval() @@ -3621,7 +3628,7 @@ func (h *Handler) siteNodeConnect( }, }) if err != nil { - h.log.WithError(err).Error("Unable to create terminal.") + h.logger.ErrorContext(r.Context(), "Unable to create terminal", "error", err) return nil, trace.Wrap(err) } @@ -3629,7 +3636,6 @@ func (h *Handler) siteNodeConnect( defer h.userConns.Add(-1) // start the websocket session with a web-based terminal: - h.log.Infof("Getting terminal to %#v.", req) httplib.MakeTracingHandler(term, teleport.ComponentProxy).ServeHTTP(w, r) return nil, nil @@ -3703,8 +3709,13 @@ func (h *Handler) podConnect( Command: execReq.Command, } - h.log.Debugf("New kube exec request for namespace=%s pod=%s container=%s, sid=%s, websid=%s.", - execReq.Namespace, execReq.Pod, execReq.Container, sess.ID, sctx.GetSessionID()) + h.logger.DebugContext(r.Context(), "New kube exec request", + "namespace", execReq.Namespace, + "pod", execReq.Pod, + "container", execReq.Container, + "sid", sess.ID, + "websid", sctx.GetSessionID(), + ) authAccessPoint, err := site.CachingAccessPoint() if err != nil { @@ -3738,7 +3749,6 @@ func (h *Handler) podConnect( teleportCluster: site.GetName(), ws: ws, keepAliveInterval: keepAliveInterval, - log: h.log.WithField(teleport.ComponentKey, "pod"), logger: h.logger.With(teleport.ComponentKey, "pod"), userClient: clt, localCA: hostCA, @@ -3802,9 +3812,9 @@ func (h *Handler) getKubeExecClusterData(netConfig types.ClusterNetworkingConfig return "https://" + net.JoinHostPort(host, port), tlsServerName, nil } -func (h *Handler) generateSession(req *TerminalRequest, clusterName string, scx *SessionContext) (session.Session, error) { +func (h *Handler) generateSession(ctx context.Context, req *TerminalRequest, clusterName string, scx *SessionContext) (session.Session, error) { owner := scx.cfg.User - h.log.Infof("Generating new session for %s\n", clusterName) + h.logger.InfoContext(ctx, "Generating new session", "cluster", clusterName) host, port, err := serverHostPort(req.Server) if err != nil { @@ -3840,7 +3850,7 @@ func (h *Handler) fetchExistingSession(ctx context.Context, clt authclient.Clien if err != nil { return session.Session{}, nil, trace.Wrap(err) } - h.log.Infof("Attempting to join existing session: %s\n", sessionID) + h.logger.InfoContext(ctx, "Attempting to join existing session", "session_id", sessionID) tracker, err := clt.GetSessionTracker(ctx, string(*sessionID)) if err != nil { @@ -4351,7 +4361,7 @@ func (h *Handler) validateTrustedCluster(w http.ResponseWriter, r *http.Request, validateResponse, err := h.auth.ValidateTrustedCluster(r.Context(), validateRequest) if err != nil { - h.log.WithError(err).Error("Failed validating trusted cluster") + h.logger.ErrorContext(r.Context(), "Failed validating trusted cluster", "error", err) if trace.IsAccessDenied(err) { return nil, trace.AccessDenied("access denied: the cluster token has been rejected") } @@ -4398,7 +4408,7 @@ func (h *Handler) WithClusterAuth(fn ClusterHandler) httprouter.Handle { }) } -func (h *Handler) writeErrToWebSocket(ws *websocket.Conn, err error) { +func (h *Handler) writeErrToWebSocket(ctx context.Context, ws *websocket.Conn, err error) { if err == nil { return } @@ -4409,11 +4419,11 @@ func (h *Handler) writeErrToWebSocket(ws *websocket.Conn, err error) { } env, err := errEnvelope.Marshal() if err != nil { - h.log.WithError(err).Error("error marshaling proto") + h.logger.ErrorContext(ctx, "error marshaling proto", "error", err) return } if err := ws.WriteMessage(websocket.BinaryMessage, env); err != nil { - h.log.WithError(err).Error("error writing proto") + h.logger.ErrorContext(ctx, "error writing proto", "error", err) return } } @@ -4443,7 +4453,7 @@ func (h *Handler) WithClusterAuthWebSocket(fn ClusterWebsocketHandler) httproute // which should be done by downstream users defer ws.Close() if _, err := fn(w, r, p, sctx, site, ws); err != nil { - h.writeErrToWebSocket(ws, err) + h.writeErrToWebSocket(r.Context(), ws, err) } return nil, nil }) @@ -4460,7 +4470,7 @@ func (h *Handler) authenticateWSRequestWithCluster(w http.ResponseWriter, r *htt return nil, nil, nil, trace.Wrap(err) } - site, err := h.getSiteByParams(sctx, p) + site, err := h.getSiteByParams(r.Context(), sctx, p) if err != nil { return nil, nil, nil, trace.Wrap(err) } @@ -4478,7 +4488,7 @@ func (h *Handler) authenticateRequestWithCluster(w http.ResponseWriter, r *http. return nil, nil, trace.Wrap(err) } - site, err := h.getSiteByParams(sctx, p) + site, err := h.getSiteByParams(r.Context(), sctx, p) if err != nil { return nil, nil, trace.Wrap(err) } @@ -4488,18 +4498,18 @@ func (h *Handler) authenticateRequestWithCluster(w http.ResponseWriter, r *http. // getSiteByParams gets the remoteSite (which can represent this local cluster or a // remote trusted cluster) as specified by the ":site" url parameter. -func (h *Handler) getSiteByParams(sctx *SessionContext, p httprouter.Params) (reversetunnelclient.RemoteSite, error) { +func (h *Handler) getSiteByParams(ctx context.Context, sctx *SessionContext, p httprouter.Params) (reversetunnelclient.RemoteSite, error) { clusterName := p.ByName("site") if clusterName == currentSiteShortcut { res, err := h.cfg.ProxyClient.GetClusterName() if err != nil { - h.log.WithError(err).Warn("Failed to query cluster name.") + h.logger.WarnContext(ctx, "Failed to query cluster name", "error", err) return nil, trace.Wrap(err) } clusterName = res.GetClusterName() } - site, err := h.getSiteByClusterName(sctx, clusterName) + site, err := h.getSiteByClusterName(ctx, sctx, clusterName) if err != nil { return nil, trace.Wrap(err) } @@ -4507,16 +4517,16 @@ func (h *Handler) getSiteByParams(sctx *SessionContext, p httprouter.Params) (re return site, nil } -func (h *Handler) getSiteByClusterName(ctx *SessionContext, clusterName string) (reversetunnelclient.RemoteSite, error) { - proxy, err := h.ProxyWithRoles(ctx) +func (h *Handler) getSiteByClusterName(ctx context.Context, sctx *SessionContext, clusterName string) (reversetunnelclient.RemoteSite, error) { + proxy, err := h.ProxyWithRoles(ctx, sctx) if err != nil { - h.log.WithError(err).Warn("Failed to get proxy with roles.") + h.logger.WarnContext(ctx, "Failed to get proxy with roles", "error", err) return nil, trace.Wrap(err) } site, err := proxy.GetSite(clusterName) if err != nil { - h.log.WithError(err).WithField("cluster-name", clusterName).Warn("Failed to query site.") + h.logger.WarnContext(ctx, "Failed to query site", "error", err, "cluster", clusterName) return nil, trace.Wrap(err) } @@ -4540,7 +4550,7 @@ type clusterClientProvider struct { // UserClientForCluster returns a client to the local or remote cluster // identified by clusterName and is authenticated with the identity of the user. func (r clusterClientProvider) UserClientForCluster(ctx context.Context, clusterName string) (authclient.ClientI, error) { - site, err := r.h.getSiteByClusterName(r.ctx, clusterName) + site, err := r.h.getSiteByClusterName(ctx, r.ctx, clusterName) if err != nil { return nil, trace.Wrap(err) } @@ -4594,7 +4604,7 @@ func (h *Handler) WithProvisionTokenAuth(fn ProvisionTokenHandler) httprouter.Ha site, err := h.cfg.Proxy.GetSite(h.auth.clusterName) if err != nil { - h.log.WithError(err).WithField("cluster-name", h.auth.clusterName).Warn("Failed to query cluster.") + h.logger.WarnContext(ctx, "Failed to query cluster", "error", err, "cluster", h.auth.clusterName) return nil, trace.Wrap(err) } @@ -4675,7 +4685,7 @@ func (h *Handler) WithMetaRedirect(fn redirectHandlerFunc) httprouter.Handle { } err := app.MetaRedirect(w, redirectURL) if err != nil { - h.log.WithError(err).Warn("Failed to issue a redirect.") + h.logger.WarnContext(r.Context(), "Failed to issue a redirect", "error", err) } } } @@ -4903,7 +4913,7 @@ func (h *Handler) AuthenticateRequestWS(w http.ResponseWriter, r *http.Request) Message: "invalid token", }) if writeErr != nil { - log.Errorf("Error while writing invalid token error to websocket: %s", writeErr) + h.logger.ErrorContext(r.Context(), "Error while writing invalid token error to websocket", "error", writeErr) } return nil, nil, trace.Wrap(err) @@ -4930,10 +4940,10 @@ func (h *Handler) AuthenticateRequestWS(w http.ResponseWriter, r *http.Request) // ProxyWithRoles returns a reverse tunnel proxy verifying the permissions // of the given user. -func (h *Handler) ProxyWithRoles(ctx *SessionContext) (reversetunnelclient.Tunnel, error) { - accessChecker, err := ctx.GetUserAccessChecker() +func (h *Handler) ProxyWithRoles(ctx context.Context, sctx *SessionContext) (reversetunnelclient.Tunnel, error) { + accessChecker, err := sctx.GetUserAccessChecker() if err != nil { - h.log.WithError(err).Warn("Failed to get client roles.") + h.logger.WarnContext(ctx, "Failed to get client roles", "error", err) return nil, trace.Wrap(err) } @@ -5138,7 +5148,7 @@ func (h *Handler) authExportPublic(w http.ResponseWriter, r *http.Request, p htt }, ) if err != nil { - h.log.WithError(err).Debug("Failed to generate CA Certs.") + h.logger.DebugContext(r.Context(), "Failed to generate CA Certs", "error", err) http.Error(w, err.Error(), trace.ErrorToCode(err)) return } diff --git a/lib/web/apiserver_test.go b/lib/web/apiserver_test.go index 48a9ff61179a5..f3a71ebb78945 100644 --- a/lib/web/apiserver_test.go +++ b/lib/web/apiserver_test.go @@ -1776,7 +1776,7 @@ func TestNewTerminalHandler(t *testing.T) { require.Equal(t, validCfg.Term, term.term) require.Equal(t, validCfg.DisplayLogin, term.displayLogin) // newly added - require.NotNil(t, term.log) + require.NotNil(t, term.logger) } func TestUIConfig(t *testing.T) { @@ -8209,7 +8209,7 @@ func createProxy(ctx context.Context, t *testing.T, proxyID string, node *regula go func() { if err := mux.Serve(); err != nil && !utils.IsOKNetworkError(err) { - log.WithError(err).Error("Mux encountered err serving") + slog.ErrorContext(context.Background(), "Mux encountered error serving", "error", err) } }() @@ -8283,7 +8283,7 @@ func createProxy(ctx context.Context, t *testing.T, proxyID string, node *regula go func() { if err := sshGRPCServer.Serve(mux.TLS()); err != nil && !utils.IsOKNetworkError(err) { - log.WithError(err).Error("gRPC proxy server terminated unexpectedly") + slog.ErrorContext(context.Background(), "gRPC proxy server terminated unexpectedly", "error", err) } }() @@ -8358,7 +8358,7 @@ func createProxy(ctx context.Context, t *testing.T, proxyID string, node *regula t.Cleanup(webServer.Close) go func() { if err := proxyServer.Serve(mux.SSH()); err != nil && !utils.IsOKNetworkError(err) { - log.WithError(err).Error("SSH proxy server terminated unexpectedly") + slog.ErrorContext(context.Background(), "SSH proxy server terminated unexpectedly", "error", err) } }() @@ -10677,7 +10677,7 @@ func TestWebSocketClosedBeforeSSHSessionCreated(t *testing.T) { // not yet established. stream := terminal.NewStream(ctx, terminal.StreamConfig{ WS: ws, - Logger: utils.NewLogger(), + Logger: utils.NewSlogLoggerForTests(), Handlers: map[string]terminal.WSHandlerFunc{ defaults.WebsocketSessionMetadata: func(ctx context.Context, envelope terminal.Envelope) { if envelope.Type != defaults.WebsocketSessionMetadata { diff --git a/lib/web/apiserver_test_utils.go b/lib/web/apiserver_test_utils.go index e3d1f3c4ba9b1..d7fe5cd0bb3d7 100644 --- a/lib/web/apiserver_test_utils.go +++ b/lib/web/apiserver_test_utils.go @@ -19,6 +19,8 @@ package web import ( + "context" + "log/slog" "net/http" "os" "path/filepath" @@ -38,7 +40,7 @@ func newDebugFileSystem() (http.FileSystem, error) { return nil, trace.Wrap(err) } } - log.Infof("Using filesystem for serving web assets: %s.", assetsPath) + slog.InfoContext(context.TODO(), "Using filesystem for serving web assets", "assets_path", assetsPath) return http.Dir(assetsPath), nil } diff --git a/lib/web/apps.go b/lib/web/apps.go index 5e809d2df29e1..8ae0dc5525468 100644 --- a/lib/web/apps.go +++ b/lib/web/apps.go @@ -69,7 +69,7 @@ func (h *Handler) clusterAppsGet(w http.ResponseWriter, r *http.Request, p httpr UseSearchAsRoles: true, }) if err != nil { - h.log.Debugf("Unable to fetch user groups while listing applications, unable to display associated user groups: %v", err) + h.logger.DebugContext(r.Context(), "Unable to fetch user groups while listing applications, unable to display associated user groups", "error", err) } userGroupLookup := make(map[string]types.UserGroup, len(userGroups)) @@ -94,7 +94,7 @@ func (h *Handler) clusterAppsGet(w http.ResponseWriter, r *http.Request, p httpr if app.IsAWSConsole() { allowedAWSRoles, err := accessChecker.GetAllowedLoginsForResource(app) if err != nil { - h.log.Debugf("Unable to find allowed AWS Roles for app %s, skipping", app.GetName()) + h.logger.DebugContext(r.Context(), "Unable to find allowed AWS Roles for app, skipping", "app", app.GetName()) continue } @@ -105,7 +105,7 @@ func (h *Handler) clusterAppsGet(w http.ResponseWriter, r *http.Request, p httpr for _, userGroupName := range app.GetUserGroups() { userGroup := userGroupLookup[userGroupName] if userGroup == nil { - h.log.Debugf("Unable to find user group %s when creating user groups, skipping", userGroupName) + h.logger.DebugContext(r.Context(), "Unable to find user group when creating user groups, skipping", "user_group", userGroupName) continue } @@ -172,7 +172,7 @@ func (h *Handler) getAppDetails(w http.ResponseWriter, r *http.Request, p httpro for _, required := range requiredAppNames { res, err := h.resolveApp(r.Context(), ctx, ResolveAppParams{ClusterName: clusterName, AppName: required}) if err != nil { - h.log.Errorf("Error getting app details for %s, a required app for %s", required, result.App.GetName()) + h.logger.ErrorContext(r.Context(), "Error getting app details for associated required app", "required_app", required, "app", result.App.GetName()) continue } resp.RequiredAppFQDNs = append(resp.RequiredAppFQDNs, res.App.GetPublicAddr()) @@ -218,12 +218,12 @@ func (h *Handler) createAppSession(w http.ResponseWriter, r *http.Request, p htt return nil, trace.Wrap(err, "unable to resolve FQDN: %v", req.FQDNHint) } - h.log.Debugf("Creating application web session for %v in %v.", result.App.GetPublicAddr(), result.ClusterName) + h.logger.DebugContext(r.Context(), "Creating application web session", "app_public_addr", result.App.GetPublicAddr(), "cluster", result.ClusterName) // Ensuring proxy can handle the connection is only done when the request is // coming from the WebUI. if h.healthCheckAppServer != nil && !app.HasClientCert(r) { - h.log.Debugf("Ensuring proxy can handle requests requests for application %q.", result.App.GetName()) + h.logger.DebugContext(r.Context(), "Ensuring proxy can handle requests requests for application", "app", result.App.GetName()) err := h.healthCheckAppServer(r.Context(), result.App.GetPublicAddr(), result.ClusterName) if err != nil { return nil, trace.ConnectionProblem(err, "Unable to serve application requests. Please try again. If the issue persists, verify if the Application Services are connected to Teleport.") @@ -315,7 +315,7 @@ func (h *Handler) resolveApp(ctx context.Context, scx *SessionContext, params Re } // Get a reverse tunnel proxy aware of the user's permissions. - proxy, err := h.ProxyWithRoles(scx) + proxy, err := h.ProxyWithRoles(ctx, scx) if err != nil { return nil, trace.Wrap(err) } diff --git a/lib/web/autoupdate_rfd109.go b/lib/web/autoupdate_rfd109.go index 3bbdd0175b106..7b2a438e7f477 100644 --- a/lib/web/autoupdate_rfd109.go +++ b/lib/web/autoupdate_rfd109.go @@ -62,10 +62,10 @@ func (h *Handler) automaticUpgrades109(w http.ResponseWriter, r *http.Request, p // Finally, we treat the request based on its type switch requestType { case "version": - h.log.Debugf("Agent requesting version for channel %s", channelName) + h.logger.DebugContext(r.Context(), "Agent requesting version for channel", "channel", channelName) return h.automaticUpgradesVersion109(w, r, channelName) case "critical": - h.log.Debugf("Agent requesting criticality for channel %s", channelName) + h.logger.DebugContext(r.Context(), "Agent requesting criticality for channel", "channel", channelName) return h.automaticUpgradesCritical109(w, r, channelName) default: return nil, trace.BadParameter("requestType path must end with 'version' or 'critical'") diff --git a/lib/web/desktop.go b/lib/web/desktop.go index b72d4108b5ef8..63a6bdee24508 100644 --- a/lib/web/desktop.go +++ b/lib/web/desktop.go @@ -25,6 +25,7 @@ import ( "crypto/tls" "errors" "io" + "log/slog" "math/rand/v2" "net" "net/http" @@ -33,7 +34,6 @@ import ( "github.com/gorilla/websocket" "github.com/gravitational/trace" "github.com/julienschmidt/httprouter" - "github.com/sirupsen/logrus" "github.com/gravitational/teleport/api/client/proto" "github.com/gravitational/teleport/api/constants" @@ -48,6 +48,7 @@ import ( "github.com/gravitational/teleport/lib/reversetunnelclient" "github.com/gravitational/teleport/lib/srv/desktop/tdp" "github.com/gravitational/teleport/lib/utils" + logutils "github.com/gravitational/teleport/lib/utils/log" ) // GET /webapi/sites/:site/desktops/:desktopName/connect?access_token=&username= @@ -64,15 +65,18 @@ func (h *Handler) desktopConnectHandle( return nil, trace.BadParameter("missing desktopName in request URL") } - log := sctx.cfg.Log.WithField("desktop-name", desktopName).WithField("cluster-name", site.GetName()) - log.Debug("New desktop access websocket connection") + log := sctx.cfg.Log.With( + "desktop_name", desktopName, + "cluster_name", site.GetName(), + ) + log.DebugContext(r.Context(), "New desktop access websocket connection") if err := h.createDesktopConnection(r, desktopName, site.GetName(), log, sctx, site, ws); err != nil { // createDesktopConnection makes a best effort attempt to send an error to the user // (via websocket) before terminating the connection. We log the error here, but // return nil because our HTTP middleware will try to write the returned error in JSON // format, and this will fail since the HTTP connection has been upgraded to websockets. - log.Error(err) + log.ErrorContext(r.Context(), "creating desktop connection failed", "error", err) } return nil, nil @@ -82,7 +86,7 @@ func (h *Handler) createDesktopConnection( r *http.Request, desktopName string, clusterName string, - log *logrus.Entry, + log *slog.Logger, sctx *SessionContext, site reversetunnelclient.RemoteSite, ws *websocket.Conn, @@ -102,7 +106,7 @@ func (h *Handler) createDesktopConnection( if err != nil { return sendTDPError(err) } - log.Debugf("Attempting to connect to desktop using username=%v\n", username) + log.DebugContext(ctx, "Attempting to connect to desktop", "username", username) // Read the tdp.ClientScreenSpec from the websocket. // This is always the first thing sent by the client. @@ -123,7 +127,11 @@ func (h *Handler) createDesktopConnection( )) } - log.Debugf("Attempting to connect to desktop using username=%v, width=%v, height=%v\n", username, width, height) + log.DebugContext(ctx, "Attempting to connect to desktop", + "username", username, + "width", width, + "height", height, + ) // Pick a random Windows desktop service as our gateway. // When agent mode is implemented in the service, we'll have to filter out @@ -190,7 +198,7 @@ func (h *Handler) createDesktopConnection( clientSrcAddr: clientSrcAddr, clientDstAddr: clientDstAddr, } - serviceConn, _, err := c.connectToWindowsService(clusterName, validServiceIDs) + serviceConn, _, err := c.connectToWindowsService(ctx, clusterName, validServiceIDs) if err != nil { return sendTDPError(trace.Wrap(err, "cannot connect to Windows Desktop Service")) } @@ -201,7 +209,7 @@ func (h *Handler) createDesktopConnection( if err := serviceConnTLS.HandshakeContext(ctx); err != nil { return sendTDPError(err) } - log.Debug("Connected to windows_desktop_service") + log.DebugContext(ctx, "Connected to windows_desktop_service") tdpConn := tdp.NewConn(serviceConnTLS) @@ -217,7 +225,7 @@ func (h *Handler) createDesktopConnection( return sendTDPError(err) } for _, msg := range withheld { - log.Debugf("Sending withheld message: %v", msg) + log.DebugContext(ctx, "Sending withheld message", "messgage", logutils.TypeAttr(msg)) if err := tdpConn.WriteMessage(msg); err != nil { return sendTDPError(err) } @@ -228,7 +236,10 @@ func (h *Handler) createDesktopConnection( // proxyWebsocketConn hangs here until connection is closed handleProxyWebsocketConnErr( - proxyWebsocketConn(ws, serviceConnTLS), log) + ctx, + proxyWebsocketConn(ws, serviceConnTLS), + log, + ) return nil } @@ -410,7 +421,7 @@ func (h *Handler) performSessionMFACeremony( if tdp.MessageType(buf[0]) != tdp.TypeMFA { // This is not an MFA message, withhold it for later. msg, err := tdp.Decode(buf) - h.log.Debugf("Received non-MFA message, withholding:", msg) + h.logger.DebugContext(ctx, "Received non-MFA message, withholding", "msg_type", logutils.TypeAttr(msg)) if err != nil { return nil, trace.Wrap(err) } @@ -465,7 +476,7 @@ func readClientScreenSpec(ws *websocket.Conn) (*tdp.ClientScreenSpec, error) { } type connector struct { - log *logrus.Entry + log *slog.Logger clt authclient.ClientI site reversetunnelclient.RemoteSite clientSrcAddr net.Addr @@ -476,17 +487,21 @@ type connector struct { // by trying each of the services provided. It returns an error if it could not connect // to any of the services or if it encounters an error that is not a connection problem. func (c *connector) connectToWindowsService( + ctx context.Context, clusterName string, desktopServiceIDs []string, ) (conn net.Conn, version string, err error) { for _, id := range desktopServiceIDs { - conn, ver, err := c.tryConnect(clusterName, id) + conn, ver, err := c.tryConnect(ctx, clusterName, id) if err != nil && !trace.IsConnectionProblem(err) { return nil, "", trace.WrapWithMessage(err, "error connecting to windows_desktop_service %q", id) } if trace.IsConnectionProblem(err) { - c.log.Warnf("failed to connect to windows_desktop_service %q: %v", id, err) + c.log.WarnContext(ctx, "failed to connect to windows_desktop_service", + "windows_desktop_service_id", id, + "error", err, + ) continue } if err == nil { @@ -496,17 +511,19 @@ func (c *connector) connectToWindowsService( return nil, "", trace.Errorf("failed to connect to any windows_desktop_service") } -func (c *connector) tryConnect(clusterName, desktopServiceID string) (conn net.Conn, version string, err error) { - service, err := c.clt.GetWindowsDesktopService(context.Background(), desktopServiceID) +func (c *connector) tryConnect(ctx context.Context, clusterName, desktopServiceID string) (conn net.Conn, version string, err error) { + service, err := c.clt.GetWindowsDesktopService(ctx, desktopServiceID) if err != nil { - log.Errorf("Error finding service with id %s", desktopServiceID) + c.log.ErrorContext(ctx, "Error finding service", "service_id", desktopServiceID, "error", err) return nil, "", trace.NotFound("could not find windows desktop service %s: %v", desktopServiceID, err) } ver := service.GetTeleportVersion() - *c.log = *c.log.WithField("windows-service-version", ver) - *c.log = *c.log.WithField("windows-service-uuid", service.GetName()) - *c.log = *c.log.WithField("windows-service-addr", service.GetAddr()) + *c.log = *c.log.With( + "windows_service_version", ver, + "windows_service_uuid", service.GetName(), + "windows_service_addr", service.GetAddr(), + ) conn, err = c.site.DialTCP(reversetunnelclient.DialParams{ From: c.clientSrcAddr, @@ -625,9 +642,9 @@ func proxyWebsocketConn(ws *websocket.Conn, wds net.Conn) error { // handleProxyWebsocketConnErr handles the error returned by proxyWebsocketConn by // unwrapping it and determining whether to log an error. -func handleProxyWebsocketConnErr(proxyWsConnErr error, log *logrus.Entry) { +func handleProxyWebsocketConnErr(ctx context.Context, proxyWsConnErr error, log *slog.Logger) { if proxyWsConnErr == nil { - log.Debug("proxyWebsocketConn returned with no error") + log.DebugContext(ctx, "proxyWebsocketConn returned with no error") return } @@ -645,7 +662,7 @@ func handleProxyWebsocketConnErr(proxyWsConnErr error, log *logrus.Entry) { switch closeErr.Code { case websocket.CloseNormalClosure, // when the user hits "disconnect" from the menu websocket.CloseGoingAway: // when the user closes the tab - log.Debugf("Web socket closed by client with code: %v", closeErr.Code) + log.DebugContext(ctx, "Web socket closed by client", "close_code", closeErr.Code) return } return @@ -656,7 +673,7 @@ func handleProxyWebsocketConnErr(proxyWsConnErr error, log *logrus.Entry) { } } - log.WithError(proxyWsConnErr).Warning("Error proxying a desktop protocol websocket to windows_desktop_service") + log.WarnContext(ctx, "Error proxying a desktop protocol websocket to windows_desktop_service", "error", proxyWsConnErr) } // sendTDPAlert sends a tdp Notification over the supplied websocket with the diff --git a/lib/web/desktop/playback.go b/lib/web/desktop/playback.go index 38fcb8c38b0b9..db283af906c7d 100644 --- a/lib/web/desktop/playback.go +++ b/lib/web/desktop/playback.go @@ -22,10 +22,10 @@ import ( "context" "encoding/json" "fmt" + "log/slog" "time" "github.com/gorilla/websocket" - "github.com/sirupsen/logrus" "github.com/gravitational/teleport/api/types/events" "github.com/gravitational/teleport/lib/player" @@ -65,7 +65,8 @@ type actionMessage struct { // ReceivePlaybackActions handles logic for receiving playbackAction messages // over the websocket and updating the player state accordingly. func ReceivePlaybackActions( - log logrus.FieldLogger, + ctx context.Context, + logger *slog.Logger, ws *websocket.Conn, player *player.Player) { // playback always starts in a playing state @@ -78,7 +79,7 @@ func ReceivePlaybackActions( // Connection close errors are expected if the user closes the tab. // Only log unexpected errors to avoid cluttering the logs. if !utils.IsOKNetworkError(err) { - log.Warnf("websocket read error: %v", err) + logger.WarnContext(ctx, "websocket read error", "error", err) } return } @@ -98,7 +99,7 @@ func ReceivePlaybackActions( case actionSeek: player.SetPos(time.Duration(action.Pos) * time.Millisecond) default: - log.Warnf("invalid desktop playback action: %v", action.Action) + slog.WarnContext(ctx, "invalid desktop playback action", "action", action.Action) return } } @@ -108,7 +109,7 @@ func ReceivePlaybackActions( // over a websocket. func PlayRecording( ctx context.Context, - log logrus.FieldLogger, + log *slog.Logger, ws *websocket.Conn, player *player.Player) { player.Play() @@ -122,18 +123,18 @@ func PlayRecording( // Attempt to JSONify the error (escaping any quotes) msg, err := json.Marshal(playerErr.Error()) if err != nil { - log.Warnf("failed to marshal player error message: %v", err) + log.WarnContext(ctx, "failed to marshal player error message", "error", err) msg = []byte(`"internal server error"`) } //lint:ignore QF1012 this write needs to happen in a single operation bytes := []byte(fmt.Sprintf(`{"message":"error", "errorText":%s}`, string(msg))) if err := ws.WriteMessage(websocket.BinaryMessage, bytes); err != nil { - log.Errorf("failed to write error message: %v", err) + log.ErrorContext(ctx, "failed to write error message", "error", err) } return } if err := ws.WriteMessage(websocket.BinaryMessage, []byte(`{"message":"end"}`)); err != nil { - log.Errorf("failed to write end message: %v", err) + log.ErrorContext(ctx, "failed to write end message", "error", err) } return } @@ -145,7 +146,7 @@ func PlayRecording( } msg, err := utils.FastMarshal(evt) if err != nil { - log.Errorf("failed to marshal desktop event: %v", err) + log.ErrorContext(ctx, "failed to marshal desktop event", "error", err) ws.WriteMessage(websocket.BinaryMessage, []byte(`{"message":"error","errorText":"server error"}`)) return } @@ -153,7 +154,7 @@ func PlayRecording( // Connection close errors are expected if the user closes the tab. // Only log unexpected errors to avoid cluttering the logs. if !utils.IsOKNetworkError(err) { - log.Warnf("websocket write error: %v", err) + log.WarnContext(ctx, "websocket write error", "error", err) } return } diff --git a/lib/web/desktop/playback_test.go b/lib/web/desktop/playback_test.go index 12c52ad7e2862..da284e4d18792 100644 --- a/lib/web/desktop/playback_test.go +++ b/lib/web/desktop/playback_test.go @@ -82,7 +82,6 @@ func newServer(t *testing.T, streamInterval time.Duration, events []apievents.Au fs := eventstest.NewFakeStreamer(events, streamInterval) log := utils.NewSlogLoggerForTests() - logrusLogger := utils.NewLoggerForTests() s := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { upgrader := websocket.Upgrader{ @@ -103,7 +102,7 @@ func newServer(t *testing.T, streamInterval time.Duration, events []apievents.Au }) assert.NoError(t, err) player.Play() - desktop.PlayRecording(r.Context(), logrusLogger, ws, player) + desktop.PlayRecording(r.Context(), log, ws, player) })) t.Cleanup(s.Close) diff --git a/lib/web/desktop_playback.go b/lib/web/desktop_playback.go index 1467c14a28165..37611058a8131 100644 --- a/lib/web/desktop_playback.go +++ b/lib/web/desktop_playback.go @@ -58,7 +58,7 @@ func (h *Handler) desktopPlaybackHandle( Context: r.Context(), }) if err != nil { - h.log.Errorf("couldn't create player for session %v: %v", sID, err) + h.logger.ErrorContext(r.Context(), "couldn't create player for session", "session_id", sID, "error", err) ws.WriteMessage(websocket.BinaryMessage, []byte(`{"message": "error", "errorText": "Internal server error"}`)) return nil, nil @@ -71,13 +71,13 @@ func (h *Handler) desktopPlaybackHandle( go func() { defer cancel() - desktop.ReceivePlaybackActions(h.log, ws, player) + desktop.ReceivePlaybackActions(ctx, h.logger, ws, player) }() go func() { defer cancel() defer ws.Close() - desktop.PlayRecording(ctx, h.log, ws, player) + desktop.PlayRecording(ctx, h.logger, ws, player) }() <-ctx.Done() diff --git a/lib/web/device_trust.go b/lib/web/device_trust.go index dce54528bdcc7..1739ff583faf0 100644 --- a/lib/web/device_trust.go +++ b/lib/web/device_trust.go @@ -66,17 +66,17 @@ func (h *Handler) deviceWebConfirm(w http.ResponseWriter, r *http.Request, _ htt }) switch { case err != nil: - h.log. - WithError(err). - WithField("user", sessionCtx.GetUser()). - Warn("Device web authentication confirm failed") + h.logger.WarnContext(ctx, "Device web authentication confirm failed", + "error", err, + "user", sessionCtx.GetUser(), + ) // err swallowed on purpose. default: // Preemptively release session from cache, as its certificates are now // updated. // The WebSession watcher takes care of this in other proxy instances // (see [sessionCache.watchWebSessions]). - h.auth.releaseResources(sessionCtx.GetUser(), sessionCtx.GetSessionID()) + h.auth.releaseResources(r.Context(), sessionCtx.GetUser(), sessionCtx.GetSessionID()) } // Always redirect back to the dashboard, regardless of outcome. @@ -84,10 +84,10 @@ func (h *Handler) deviceWebConfirm(w http.ResponseWriter, r *http.Request, _ htt redirectTo, err := h.getRedirectPath(unsafeRedirectURI) if err != nil { - h.log. - WithError(err). - WithField("redirect_uri", unsafeRedirectURI). - Debug("Unable to parse redirectURI") + h.logger.DebugContext(ctx, "Unable to parse redirectURI", + "error", err, + "redirect_uri", unsafeRedirectURI, + ) } http.Redirect(w, r, redirectTo, http.StatusSeeOther) diff --git a/lib/web/features.go b/lib/web/features.go index 7eeb70eb9f060..a05085417e6f9 100644 --- a/lib/web/features.go +++ b/lib/web/features.go @@ -33,7 +33,7 @@ func (h *Handler) SetClusterFeatures(features proto.Features) { defer h.Mutex.Unlock() if !bytes.Equal(h.clusterFeatures.CloudAnonymizationKey, features.CloudAnonymizationKey) { - h.log.Info("Received new cloud anonymization key from server") + h.logger.InfoContext(h.cfg.Context, "Received new cloud anonymization key from server") } entitlements.BackfillFeatures(&features) @@ -54,25 +54,25 @@ func (h *Handler) GetClusterFeatures() proto.Features { // The watcher doesn't ping the auth server immediately upon start because features are // already set by the config object in `NewHandler`. func (h *Handler) startFeatureWatcher() { - ticker := h.clock.NewTicker(h.cfg.FeatureWatchInterval) - h.log.WithField("interval", h.cfg.FeatureWatchInterval).Info("Proxy handler features watcher has started") ctx := h.cfg.Context + ticker := h.clock.NewTicker(h.cfg.FeatureWatchInterval) + h.logger.InfoContext(ctx, "Proxy handler features watcher has started", "interval", h.cfg.FeatureWatchInterval) defer ticker.Stop() for { select { case <-ticker.Chan(): - h.log.Info("Pinging auth server for features") + h.logger.InfoContext(ctx, "Pinging auth server for features") pingResponse, err := h.GetProxyClient().Ping(ctx) if err != nil { - h.log.WithError(err).Error("Auth server ping failed") + h.logger.ErrorContext(ctx, "Auth server ping failed", "error", err) continue } h.SetClusterFeatures(*pingResponse.ServerFeatures) - h.log.WithField("features", pingResponse.ServerFeatures).Info("Done updating proxy features") + h.logger.InfoContext(ctx, "Done updating proxy features", "features", pingResponse.ServerFeatures) case <-ctx.Done(): - h.log.Info("Feature service has stopped") + h.logger.InfoContext(ctx, "Feature service has stopped") return } } diff --git a/lib/web/features_test.go b/lib/web/features_test.go index 3798e819b46eb..52fcbddc91d0a 100644 --- a/lib/web/features_test.go +++ b/lib/web/features_test.go @@ -71,7 +71,6 @@ func TestFeaturesWatcher(t *testing.T) { }, clock: clock, clusterFeatures: proto.Features{}, - log: newPackageLogger(), logger: slog.Default().With(teleport.ComponentKey, teleport.ComponentWeb), } diff --git a/lib/web/headless.go b/lib/web/headless.go index 882bc1f374d3c..4542a4dd0522b 100644 --- a/lib/web/headless.go +++ b/lib/web/headless.go @@ -48,7 +48,7 @@ func (h *Handler) getHeadless(_ http.ResponseWriter, r *http.Request, params htt if err != nil { // Log the error, but return something more user-friendly. // Context exceeded or invalid request states are more confusing than helpful. - h.log.Debug("failed to get headless session: %v", err) + h.logger.DebugContext(r.Context(), "failed to get headless session", "error", err) return nil, trace.BadParameter("requested invalid headless session") } diff --git a/lib/web/integrations_awsoidc.go b/lib/web/integrations_awsoidc.go index 0597faa8e5425..44444f191c149 100644 --- a/lib/web/integrations_awsoidc.go +++ b/lib/web/integrations_awsoidc.go @@ -1035,7 +1035,7 @@ func (h *Handler) awsOIDCCreateAWSAppAccess(w http.ResponseWriter, r *http.Reque AppClusterName: site.GetName(), AllowedAWSRolesLookup: allowedAWSRolesLookup, UserGroupLookup: getUserGroupLookup(), - Logger: h.log, + Logger: h.logger, }), nil } diff --git a/lib/web/join_tokens.go b/lib/web/join_tokens.go index 16da9906cbd2f..033040a8545e0 100644 --- a/lib/web/join_tokens.go +++ b/lib/web/join_tokens.go @@ -382,7 +382,7 @@ func (h *Handler) getAutoUpgrades(ctx context.Context) (bool, string, error) { if autoUpgrades { autoUpgradesVersion, err = h.cfg.AutomaticUpgradesChannels.DefaultVersion(ctx) if err != nil { - log.WithError(err).Info("Failed to get auto upgrades version.") + h.logger.InfoContext(ctx, "Failed to get auto upgrades version", "error", err) return false, "", trace.Wrap(err) } } @@ -409,14 +409,14 @@ func (h *Handler) getNodeJoinScriptHandle(w http.ResponseWriter, r *http.Request script, err := getJoinScript(r.Context(), settings, h.GetProxyClient()) if err != nil { - log.WithError(err).Info("Failed to return the node install script.") + h.logger.InfoContext(r.Context(), "Failed to return the node install script", "error", err) w.Write(scripts.ErrorBashScript) return nil, nil } w.WriteHeader(http.StatusOK) if _, err := fmt.Fprintln(w, script); err != nil { - log.WithError(err).Info("Failed to return the node install script.") + h.logger.InfoContext(r.Context(), "Failed to return the node install script", "error", err) w.Write(scripts.ErrorBashScript) } @@ -429,14 +429,20 @@ func (h *Handler) getAppJoinScriptHandle(w http.ResponseWriter, r *http.Request, name, err := url.QueryUnescape(queryValues.Get("name")) if err != nil { - log.WithField("query-param", "name").WithError(err).Debug("Failed to return the app install script.") + h.logger.DebugContext(r.Context(), "Failed to return the app install script", + "query_param", "name", + "error", err, + ) w.Write(scripts.ErrorBashScript) return nil, nil } uri, err := url.QueryUnescape(queryValues.Get("uri")) if err != nil { - log.WithField("query-param", "uri").WithError(err).Debug("Failed to return the app install script.") + h.logger.DebugContext(r.Context(), "Failed to return the app install script", + "query_param", "uri", + "error", err, + ) w.Write(scripts.ErrorBashScript) return nil, nil } @@ -458,14 +464,14 @@ func (h *Handler) getAppJoinScriptHandle(w http.ResponseWriter, r *http.Request, script, err := getJoinScript(r.Context(), settings, h.GetProxyClient()) if err != nil { - log.WithError(err).Info("Failed to return the app install script.") + h.logger.InfoContext(r.Context(), "Failed to return the app install script", "error", err) w.Write(scripts.ErrorBashScript) return nil, nil } w.WriteHeader(http.StatusOK) if _, err := fmt.Fprintln(w, script); err != nil { - log.WithError(err).Debug("Failed to return the app install script.") + h.logger.DebugContext(r.Context(), "Failed to return the app install script", "error", err) w.Write(scripts.ErrorBashScript) } @@ -490,14 +496,14 @@ func (h *Handler) getDatabaseJoinScriptHandle(w http.ResponseWriter, r *http.Req script, err := getJoinScript(r.Context(), settings, h.GetProxyClient()) if err != nil { - log.WithError(err).Info("Failed to return the database install script.") + h.logger.InfoContext(r.Context(), "Failed to return the database install script", "error", err) w.Write(scripts.ErrorBashScript) return nil, nil } w.WriteHeader(http.StatusOK) if _, err := fmt.Fprintln(w, script); err != nil { - log.WithError(err).Debug("Failed to return the database install script.") + h.logger.DebugContext(r.Context(), "Failed to return the database install script", "error", err) w.Write(scripts.ErrorBashScript) } @@ -517,12 +523,17 @@ func (h *Handler) getDiscoveryJoinScriptHandle(w http.ResponseWriter, r *http.Re discoveryGroup, err := url.QueryUnescape(queryValues.Get(discoveryGroupQueryParam)) if err != nil { - log.WithField("query-param", discoveryGroupQueryParam).WithError(err).Debug("Failed to return the discovery install script.") + h.logger.DebugContext(r.Context(), "Failed to return the discovery install script", + "error", err, + "query_param", discoveryGroupQueryParam, + ) w.Write(scripts.ErrorBashScript) return nil, nil } if discoveryGroup == "" { - log.WithField("query-param", discoveryGroupQueryParam).Debug("Failed to return the discovery install script. Missing required fields.") + h.logger.DebugContext(r.Context(), "Failed to return the discovery install script. Missing required fields", + "query_param", discoveryGroupQueryParam, + ) w.Write(scripts.ErrorBashScript) return nil, nil } @@ -537,14 +548,14 @@ func (h *Handler) getDiscoveryJoinScriptHandle(w http.ResponseWriter, r *http.Re script, err := getJoinScript(r.Context(), settings, h.GetProxyClient()) if err != nil { - log.WithError(err).Info("Failed to return the discovery install script.") + h.logger.InfoContext(r.Context(), "Failed to return the discovery install script", "error", err) w.Write(scripts.ErrorBashScript) return nil, nil } w.WriteHeader(http.StatusOK) if _, err := fmt.Fprintln(w, script); err != nil { - log.WithError(err).Debug("Failed to return the discovery install script.") + h.logger.DebugContext(r.Context(), "Failed to return the discovery install script", "error", err) w.Write(scripts.ErrorBashScript) } diff --git a/lib/web/kube.go b/lib/web/kube.go index ccfd76380103f..195c6674d92ad 100644 --- a/lib/web/kube.go +++ b/lib/web/kube.go @@ -32,7 +32,6 @@ import ( "github.com/gogo/protobuf/proto" "github.com/gorilla/websocket" "github.com/gravitational/trace" - "github.com/sirupsen/logrus" oteltrace "go.opentelemetry.io/otel/trace" v1 "k8s.io/api/core/v1" "k8s.io/client-go/kubernetes" @@ -49,6 +48,7 @@ import ( "github.com/gravitational/teleport/lib/defaults" "github.com/gravitational/teleport/lib/services" "github.com/gravitational/teleport/lib/session" + logutils "github.com/gravitational/teleport/lib/utils/log" "github.com/gravitational/teleport/lib/web/terminal" ) @@ -62,7 +62,6 @@ type podHandler struct { sctx *SessionContext ws *websocket.Conn keepAliveInterval time.Duration - log *logrus.Entry logger *slog.Logger userClient authclient.ClientI localCA types.CertAuthority @@ -130,7 +129,10 @@ func (p *podHandler) ServeHTTP(_ http.ResponseWriter, r *http.Request) { sessionMetadataResponse, err := json.Marshal(siteSessionGenerateResponse{Session: p.sess}) if err != nil { - p.sendAndLogError(err) + p.logger.ErrorContext(r.Context(), "failed marshaling session data", "error", err) + if err := p.sendErrorMessage(err); err != nil { + p.logger.ErrorContext(r.Context(), "failed to send error message to client", "error", err) + } return } @@ -142,18 +144,29 @@ func (p *podHandler) ServeHTTP(_ http.ResponseWriter, r *http.Request) { envelopeBytes, err := proto.Marshal(envelope) if err != nil { - p.sendAndLogError(err) + p.logger.ErrorContext(r.Context(), "failed marshaling message envelope", "error", err) + if err := p.sendErrorMessage(err); err != nil { + p.logger.ErrorContext(r.Context(), "failed to send error message to client", "error", err) + } + return } err = p.ws.WriteMessage(websocket.BinaryMessage, envelopeBytes) if err != nil { - p.sendAndLogError(err) + p.logger.ErrorContext(r.Context(), "failed write session data message", "error", err) + if err := p.sendErrorMessage(err); err != nil { + p.logger.ErrorContext(r.Context(), "failed to send error message to client", "error", err) + } + return } if err := p.handler(r); err != nil { - p.sendAndLogError(err) + p.logger.ErrorContext(r.Context(), "handling kube session unexpectedly terminated", "error", err) + if err := p.sendErrorMessage(err); err != nil { + p.logger.ErrorContext(r.Context(), "failed to send error message to client", "error", err) + } } } @@ -161,11 +174,9 @@ func (p *podHandler) Close() error { return trace.Wrap(p.ws.Close()) } -func (p *podHandler) sendAndLogError(err error) { - p.log.Error(err) - +func (p *podHandler) sendErrorMessage(err error) error { if p.closedByClient.Load() { - return + return nil } envelope := &terminal.Envelope{ @@ -176,16 +187,17 @@ func (p *podHandler) sendAndLogError(err error) { envelopeBytes, err := proto.Marshal(envelope) if err != nil { - p.log.WithError(err).Error("failed to marshal error message") - return + return trace.Wrap(err, "creating envelope payload") } if err := p.ws.WriteMessage(websocket.BinaryMessage, envelopeBytes); err != nil { - p.log.WithError(err).Error("failed to send error message") + return trace.Wrap(err, "writing error message") } + + return nil } func (p *podHandler) handler(r *http.Request) error { - p.log.Debug("Creating websocket stream for a kube exec request") + p.logger.DebugContext(r.Context(), "Creating websocket stream for a kube exec request") // Create a context for signaling when the terminal session is over and // link it first with the trace context from the request context @@ -196,7 +208,7 @@ func (p *podHandler) handler(r *http.Request) error { defaultCloseHandler := p.ws.CloseHandler() p.ws.SetCloseHandler(func(code int, text string) error { p.closedByClient.Store(true) - p.log.Debug("websocket connection was closed by client") + p.logger.DebugContext(r.Context(), "websocket connection was closed by client") cancel() // Call the default close handler if one was set. @@ -229,7 +241,13 @@ func (p *podHandler) handler(r *http.Request) error { Width: p.req.Term.Winsize().Width, Height: p.req.Term.Winsize().Height, }) - stream := terminal.NewStream(ctx, terminal.StreamConfig{WS: p.ws, Logger: p.log, Handlers: map[string]terminal.WSHandlerFunc{defaults.WebsocketResize: p.handleResize(resizeQueue)}}) + stream := terminal.NewStream(ctx, terminal.StreamConfig{ + WS: p.ws, + Logger: p.logger, + Handlers: map[string]terminal.WSHandlerFunc{ + defaults.WebsocketResize: p.handleResize(resizeQueue), + }, + }) certsReq := clientproto.UserCertsRequest{ TLSPublicKey: publicKeyPEM, @@ -284,7 +302,7 @@ func (p *podHandler) handler(r *http.Request) error { } kubeReq.VersionedParams(option, scheme.ParameterCodec) - p.log.Debugf("Web kube exec request URL: %s", kubeReq.URL()) + p.logger.DebugContext(ctx, "Web kube exec request created", "url", logutils.StringerAttr(kubeReq.URL())) wsExec, err := remotecommand.NewWebSocketExecutor(restConfig, "POST", kubeReq.URL().String()) if err != nil { @@ -315,16 +333,16 @@ func (p *podHandler) handler(r *http.Request) error { if p.req.IsInteractive { // Send close envelope to web terminal upon exit without an error. if err := stream.SendCloseMessage(""); err != nil { - p.log.WithError(err).Error("unable to send close event to web client.") + p.logger.ErrorContext(ctx, "unable to send close event to web client", "error", err) } } if err := stream.Close(); err != nil { - p.log.WithError(err).Error("unable to close websocket stream to web client.") + p.logger.ErrorContext(ctx, "unable to close websocket stream to web client", "error", err) return nil } - p.log.Debug("Sent close event to web client.") + p.logger.DebugContext(ctx, "Sent close event to web client", "error", err) return nil } @@ -333,19 +351,19 @@ func (p *podHandler) handleResize(termSizeQueue *termSizeQueue) func(context.Con return func(ctx context.Context, envelope terminal.Envelope) { var e map[string]any if err := json.Unmarshal([]byte(envelope.Payload), &e); err != nil { - p.log.Warnf("Failed to parse resize payload: %v", err) + p.logger.WarnContext(ctx, "Failed to parse resize payload", "error", err) return } size, ok := e["size"].(string) if !ok { - p.log.Errorf("expected size to be of type string, got type %T instead", size) + p.logger.ErrorContext(ctx, "got unexpected size type, expected type string", "size_type", logutils.TypeAttr(size)) return } params, err := session.UnmarshalTerminalParams(size) if err != nil { - p.log.Warnf("Failed to retrieve terminal size: %v", err) + p.logger.WarnContext(ctx, "Failed to retrieve terminal size", "error", err) return } diff --git a/lib/web/server.go b/lib/web/server.go index 0af94831d30e6..a1f113cd53995 100644 --- a/lib/web/server.go +++ b/lib/web/server.go @@ -20,17 +20,16 @@ package web import ( "context" + "log/slog" "net" "net/http" "sync" "time" "github.com/gravitational/trace" - "github.com/sirupsen/logrus" "github.com/gravitational/teleport" "github.com/gravitational/teleport/lib/defaults" - "github.com/gravitational/teleport/lib/utils" ) // ServerConfig provides dependencies required to create a [Server]. @@ -40,7 +39,7 @@ type ServerConfig struct { // Handler web handler Handler *APIHandler // Log to write log messages - Log logrus.FieldLogger + Log *slog.Logger // ShutdownPollPeriod sets polling period for shutdown ShutdownPollPeriod time.Duration } @@ -60,7 +59,7 @@ func (c *ServerConfig) CheckAndSetDefaults() error { } if c.Log == nil { - c.Log = utils.NewLogger().WithField(teleport.ComponentKey, teleport.ComponentProxy) + c.Log = slog.With(teleport.ComponentKey, teleport.ComponentProxy) } return nil @@ -138,7 +137,7 @@ func (s *Server) Shutdown(ctx context.Context) error { return trace.NewAggregate(err, s.cfg.Handler.Close()) } - s.cfg.Log.Infof("Shutdown: waiting for %v connections to finish.", activeConnections) + s.cfg.Log.InfoContext(ctx, "Shutdown: waiting for active connections to finish", "active_connection_count", activeConnections) lastReport := time.Time{} ticker := time.NewTicker(s.cfg.ShutdownPollPeriod) defer ticker.Stop() @@ -151,11 +150,11 @@ func (s *Server) Shutdown(ctx context.Context) error { return trace.NewAggregate(err, s.cfg.Handler.Close()) } if time.Since(lastReport) > 10*s.cfg.ShutdownPollPeriod { - s.cfg.Log.Infof("Shutdown: waiting for %v connections to finish.", activeConnections) + s.cfg.Log.InfoContext(ctx, "Shutdown: waiting for active connections to finish", "active_connection_count", activeConnections) lastReport = time.Now() } case <-ctx.Done(): - s.cfg.Log.Infof("Context canceled wait, returning.") + s.cfg.Log.InfoContext(ctx, "Context canceled wait, returning") return trace.ConnectionProblem(trace.NewAggregate(err, s.cfg.Handler.Close()), "context canceled") } } diff --git a/lib/web/sessions.go b/lib/web/sessions.go index b429920d45708..67f21be47db5c 100644 --- a/lib/web/sessions.go +++ b/lib/web/sessions.go @@ -25,6 +25,7 @@ import ( "errors" "fmt" "io" + "log/slog" "net" "sync" "sync/atomic" @@ -32,7 +33,6 @@ import ( "github.com/gravitational/trace" "github.com/jonboulle/clockwork" - "github.com/sirupsen/logrus" "go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc" "golang.org/x/crypto/ssh" "golang.org/x/crypto/ssh/agent" @@ -62,6 +62,7 @@ import ( "github.com/gravitational/teleport/lib/sshutils" "github.com/gravitational/teleport/lib/tlsca" "github.com/gravitational/teleport/lib/utils" + logutils "github.com/gravitational/teleport/lib/utils/log" ) // SessionContext is a context associated with a user's @@ -86,7 +87,7 @@ type SessionContext struct { type SessionContextConfig struct { // Log is used to emit logs - Log *logrus.Entry + Log *slog.Logger // User is the name of the current user User string @@ -139,10 +140,10 @@ func (c *SessionContextConfig) CheckAndSetDefaults() error { } if c.Log == nil { - c.Log = log.WithFields(logrus.Fields{ - "user": c.User, - "session": c.Session.GetShortName(), - }) + c.Log = slog.With( + "user", c.User, + "session", c.Session.GetShortName(), + ) } if c.newRemoteClient == nil { @@ -202,8 +203,12 @@ func (c *SessionContext) validateBearerToken(ctx context.Context, token string) } if fetchedToken.GetUser() != c.cfg.User { - c.cfg.Log.Warnf("Failed validating bearer token: the user[%s] in bearer token[%s] did not match the user[%s] for session[%s]", - fetchedToken.GetUser(), token, c.cfg.User, c.GetSessionID()) + c.cfg.Log.WarnContext(ctx, "Failed validating bearer token: the user in bearer token did not match the user for session", + "token_user", fetchedToken.GetUser(), + "token", token, + "session_user", c.cfg.User, + "session_id", c.GetSessionID(), + ) return trace.AccessDenied("access denied") } @@ -260,7 +265,10 @@ func (c *SessionContext) remoteClient(ctx context.Context, site reversetunnelcli // the session context is closed. err = c.remoteClientCache.addRemoteClient(site, rClt) if err != nil { - c.cfg.Log.WithError(err).Info("Failed closing stale remote client for site: ", site.GetName()) + c.cfg.Log.InfoContext(ctx, "Failed closing stale remote client for site", + "remote_site", site.GetName(), + "error", err, + ) } return rClt, nil @@ -595,7 +603,7 @@ func (c *SessionContext) expired(ctx context.Context) bool { // was removed during user logout, expire the session immediately. return true default: - c.cfg.Log.WithError(err).Debug("Failed to query web session.") + c.cfg.Log.DebugContext(ctx, "Failed to query web session", "error", err) } // If the session has no expiry time, then also by definition it @@ -634,6 +642,7 @@ type sessionCacheOptions struct { sessionWatcherStartImmediately bool // See [sessionCache.sessionWatcherEventProcessedChannel]. Used for testing. sessionWatcherEventProcessedChannel chan struct{} + logger *slog.Logger } // newSessionCache creates a [sessionCache] from the provided [config] and @@ -649,6 +658,10 @@ func newSessionCache(ctx context.Context, config sessionCacheOptions) (*sessionC config.clock = clockwork.NewRealClock() } + if config.logger == nil { + config.logger = slog.Default() + } + cache := &sessionCache{ clusterName: clusterName.GetClusterName(), proxyClient: config.proxyClient, @@ -658,7 +671,7 @@ func newSessionCache(ctx context.Context, config sessionCacheOptions) (*sessionC authServers: config.servers, closer: utils.NewCloseBroadcaster(), cipherSuites: config.cipherSuites, - log: newPackageLogger(), + log: config.logger, clock: config.clock, sessionLingeringThreshold: config.sessionLingeringThreshold, proxySigner: config.proxySigner, @@ -678,7 +691,7 @@ func newSessionCache(ctx context.Context, config sessionCacheOptions) (*sessionC // sessionCache handles web session authentication, // and holds in-memory contexts associated with each session type sessionCache struct { - log logrus.FieldLogger + log *slog.Logger proxyClient authclient.ClientI authServers []utils.NetAddr accessPoint authclient.ReadProxyAccessPoint @@ -724,7 +737,7 @@ type sessionCache struct { // Close closes all allocated resources and stops goroutines func (s *sessionCache) Close() error { - s.log.Info("Closing session cache.") + s.log.InfoContext(context.Background(), "Closing session cache") return s.closer.Close() } @@ -757,8 +770,8 @@ func (s *sessionCache) clearExpiredSessions(ctx context.Context) { if !c.expired(ctx) { continue } - s.removeSessionContextLocked(c.cfg.Session.GetUser(), c.cfg.Session.GetName()) - s.log.WithField("ctx", c.String()).Debug("Context expired.") + s.removeSessionContextLocked(ctx, c.cfg.Session.GetUser(), c.cfg.Session.GetName()) + s.log.DebugContext(ctx, "Context expired", "context", logutils.StringerAttr(c)) } } @@ -775,12 +788,12 @@ func (s *sessionCache) watchWebSessions(ctx context.Context) { linear.First = 0 } - s.log.Debug("sessionCache: Starting WebSession watcher") + s.log.DebugContext(ctx, "sessionCache: Starting WebSession watcher") for { select { // Stop when the context tells us to. case <-ctx.Done(): - s.log.Debug("sessionCache: Stopping WebSession watcher") + s.log.DebugContext(ctx, "sessionCache: Stopping WebSession watcher") return case <-linear.After(): @@ -791,7 +804,7 @@ func (s *sessionCache) watchWebSessions(ctx context.Context) { const msg = "" + "sessionCache: WebSession watcher aborted, re-connecting. " + "This may have an impact in device trust web sessions." - s.log.WithError(err).Warn(msg) + s.log.WarnContext(ctx, msg, "error", err) } } } @@ -840,9 +853,9 @@ func (s *sessionCache) watchWebSessionsOnce(ctx context.Context, reset func()) e case event := <-watcher.Events(): reset() // Reset linear backoff attempts. - s.log. - WithField("event", event). - Trace("sessionCache: Received watcher event") + s.log.Log(ctx, logutils.TraceLevel, "sessionCache: Received watcher event", + "event", logutils.StringerAttr(event), + ) if event.Type != types.OpPut { continue // We only care about OpPut at the moment. @@ -850,25 +863,25 @@ func (s *sessionCache) watchWebSessionsOnce(ctx context.Context, reset func()) e session, ok := event.Resource.(types.WebSession) if !ok { - s.log. - WithField("resource_type", fmt.Sprintf("%T", event.Resource)). - Warn("sessionCache: Received unexpected resource type") + s.log.WarnContext(ctx, "sessionCache: Received unexpected resource type", + "resource_type", logutils.TypeAttr(event.Resource), + ) continue } if !session.GetHasDeviceExtensions() { - s.log. - WithField("session_id", session.GetName()). - Debug("sessionCache: Updated session doesn't have device extensions, skipping") + s.log.DebugContext(ctx, "sessionCache: Updated session doesn't have device extensions, skipping", + "session_id", session.GetName(), + ) notifyProcessed() continue } // Release existing and non-device-aware session. - if err := s.releaseResourcesIfNoDeviceExtensions(session.GetUser(), session.GetName()); err != nil { - s.log. - WithError(err). - WithField("session_id", session.GetName()). - Debug("sessionCache: Failed to release updated session") + if err := s.releaseResourcesIfNoDeviceExtensions(ctx, session.GetUser(), session.GetName()); err != nil { + s.log.DebugContext(ctx, "sessionCache: Failed to release updated session", + "error", err, + "session_id", session.GetName(), + ) } notifyProcessed() @@ -876,7 +889,7 @@ func (s *sessionCache) watchWebSessionsOnce(ctx context.Context, reset func()) e } } -func (s *sessionCache) releaseResourcesIfNoDeviceExtensions(user, sessionID string) error { +func (s *sessionCache) releaseResourcesIfNoDeviceExtensions(ctx context.Context, user, sessionID string) error { s.mu.Lock() defer s.mu.Unlock() @@ -885,16 +898,16 @@ func (s *sessionCache) releaseResourcesIfNoDeviceExtensions(user, sessionID stri case !ok: return nil // Session not found case sessionCtx.cfg.Session.GetHasDeviceExtensions(): - s.log. - WithField("session_id", sessionID). - Debug("sessionCache: Session already has device extensions, skipping") + s.log.DebugContext(ctx, "sessionCache: Session already has device extensions, skipping", + "session_id", sessionID, + ) return nil } - s.log. - WithField("session_id", sessionID). - Debug("sessionCache: Releasing session resources due to device extensions upgrade") - return s.releaseResourcesLocked(user, sessionID) + s.log.DebugContext(ctx, "sessionCache: Releasing session resources due to device extensions upgrade", + "session_id", sessionID, + ) + return s.releaseResourcesLocked(ctx, user, sessionID) } // AuthWithOTP authenticates the specified user with the given password and OTP token. @@ -1055,40 +1068,40 @@ func (s *sessionCache) insertContext(user string, sctx *SessionContext) (exists return false } -func (s *sessionCache) releaseResources(user, sessionID string) error { +func (s *sessionCache) releaseResources(ctx context.Context, user, sessionID string) error { s.mu.Lock() defer s.mu.Unlock() - return s.releaseResourcesLocked(user, sessionID) + return s.releaseResourcesLocked(ctx, user, sessionID) } -func (s *sessionCache) removeSessionContextLocked(user, sessionID string) error { +func (s *sessionCache) removeSessionContextLocked(ctx context.Context, user, sessionID string) error { id := sessionKey(user, sessionID) - ctx, ok := s.sessions[id] + sess, ok := s.sessions[id] if !ok { return nil } delete(s.sessions, id) - err := ctx.Close() + err := sess.Close() if err != nil { - s.log.WithFields(logrus.Fields{ - "ctx": ctx.String(), - logrus.ErrorKey: err, - }).Warn("Failed to close session context.") + s.log.WarnContext(ctx, "Failed to close session context", + "context", logutils.StringerAttr(sess), + "error", err, + ) return trace.Wrap(err) } return nil } -func (s *sessionCache) releaseResourcesLocked(user, sessionID string) error { +func (s *sessionCache) releaseResourcesLocked(ctx context.Context, user, sessionID string) error { var errors []error - err := s.removeSessionContextLocked(user, sessionID) + err := s.removeSessionContextLocked(ctx, user, sessionID) if err != nil { errors = append(errors, err) } - if ctx, ok := s.resources[user]; ok { + if sess, ok := s.resources[user]; ok { delete(s.resources, user) - if err := ctx.Close(); err != nil { - s.log.WithError(err).Warn("Failed to clean up session context.") + if err := sess.Close(); err != nil { + s.log.WarnContext(ctx, "Failed to clean up session context", "error", err) errors = append(errors, err) } } @@ -1102,10 +1115,10 @@ func (s *sessionCache) upsertSessionContext(user string) *sessionResources { return ctx } ctx := &sessionResources{ - log: s.log.WithFields(logrus.Fields{ - teleport.ComponentKey: "user-session", - "user": user, - }), + log: s.log.With( + teleport.ComponentKey, "user-session", + "user", user, + ), } s.resources[user] = ctx return ctx @@ -1143,10 +1156,10 @@ func (s *sessionCache) newSessionContextFromSession(ctx context.Context, session } sctx, err := NewSessionContext(SessionContextConfig{ - Log: s.log.WithFields(logrus.Fields{ - "user": session.GetUser(), - "session": session.GetShortName(), - }), + Log: s.log.With( + "user", session.GetUser(), + "session", session.GetShortName(), + ), User: session.GetUser(), RootClient: userClient, UnsafeCachedAuthClient: s.accessPoint, @@ -1217,7 +1230,6 @@ func (c *sessionResources) Close() error { closers := c.transferClosers() var errors []error for _, closer := range closers { - c.log.Debugf("Closing %v.", closer) if err := closer.Close(); err != nil { errors = append(errors, err) } @@ -1228,7 +1240,7 @@ func (c *sessionResources) Close() error { // sessionResources persists resources initiated by a web session // but which might outlive the session. type sessionResources struct { - log logrus.FieldLogger + log *slog.Logger mu sync.Mutex closers []io.Closer @@ -1336,7 +1348,7 @@ const ( // the server to send the session ID it's using. The returned function // will return the current session ID from the server or a reason why // one wasn't received. -func prepareToReceiveSessionID(ctx context.Context, log *logrus.Entry, nc *client.NodeClient) func() (session.ID, sessionIDStatus) { +func prepareToReceiveSessionID(ctx context.Context, log *slog.Logger, nc *client.NodeClient) func() (session.ID, sessionIDStatus) { // send the session ID received from the server var gotSessionID atomic.Bool sessionIDFromServer := make(chan session.ID, 1) @@ -1349,7 +1361,7 @@ func prepareToReceiveSessionID(ctx context.Context, log *logrus.Entry, nc *clien sid, err := session.ParseID(string(req.Payload)) if err != nil { - log.WithError(err).Warn("Unable to parse session ID.") + log.WarnContext(ctx, "Unable to parse session ID", "error", err) return nil } @@ -1368,7 +1380,7 @@ func prepareToReceiveSessionID(ctx context.Context, log *logrus.Entry, nc *clien go func() { resp, _, err := nc.Client.SendRequest(ctx, teleport.SessionIDQueryRequest, true, nil) if err != nil { - log.WithError(err).Warn("Failed to send session ID query request") + log.WarnContext(ctx, "Failed to send session ID query request", "error", err) serverWillSetSessionID <- false } else { serverWillSetSessionID <- resp diff --git a/lib/web/terminal.go b/lib/web/terminal.go index 9326140447eac..d9f20cd5396d7 100644 --- a/lib/web/terminal.go +++ b/lib/web/terminal.go @@ -39,7 +39,6 @@ import ( "github.com/gorilla/websocket" "github.com/gravitational/trace" "github.com/jonboulle/clockwork" - "github.com/sirupsen/logrus" oteltrace "go.opentelemetry.io/otel/trace" "golang.org/x/crypto/ssh" @@ -123,10 +122,6 @@ func NewTerminal(ctx context.Context, cfg TerminalHandlerConfig) (*TerminalHandl return &TerminalHandler{ sshBaseHandler: sshBaseHandler{ - log: logrus.WithFields(logrus.Fields{ - teleport.ComponentKey: teleport.ComponentWebsocket, - "session_id": cfg.SessionData.ID.String(), - }), logger: cfg.Logger.With( teleport.ComponentKey, teleport.ComponentWebsocket, "session_id", cfg.SessionData.ID.String(), @@ -268,8 +263,6 @@ func (t *TerminalHandlerConfig) CheckAndSetDefaults() error { // sshBaseHandler is a base handler for web SSH connections. type sshBaseHandler struct { - // log holds the structured logger. - log *logrus.Entry // logger holds the structured logger. logger *slog.Logger // ctx is a web session context for the currently logged-in user. @@ -365,14 +358,14 @@ func (t *TerminalHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) { err := ws.SetReadDeadline(deadlineForInterval(t.keepAliveInterval)) if err != nil { - t.log.WithError(err).Error("Error setting websocket readline") + t.logger.ErrorContext(r.Context(), "Error setting websocket readline", "error", err) return } t.handler(ws, r) } -func (t *TerminalHandler) writeSessionData() error { +func (t *TerminalHandler) writeSessionData(ctx context.Context) error { envelope := &terminal.Envelope{ Version: defaults.WebsocketVersion, Type: defaults.WebsocketSessionMetadata, @@ -387,7 +380,7 @@ func (t *TerminalHandler) writeSessionData() error { sessionDataTemp.Login = t.displayLogin sessionMetadataResponse, err := json.Marshal(siteSessionGenerateResponse{Session: sessionDataTemp}) if err != nil { - t.sendError("unable to marshal session response", err, t.stream) + t.sendError(ctx, "unable to marshal session response", err, t.stream) return trace.Wrap(err) } envelope.Payload = string(sessionMetadataResponse) @@ -406,7 +399,7 @@ func (t *TerminalHandler) writeSessionData() error { sessionMetadataResponse, err := json.Marshal(siteSessionGenerateResponse{Session: sessionDataTemp}) if err != nil { - t.sendError("unable to marshal session response", err, t.stream) + t.sendError(ctx, "unable to marshal session response", err, t.stream) return trace.Wrap(err) } envelope.Payload = string(sessionMetadataResponse) @@ -414,12 +407,12 @@ func (t *TerminalHandler) writeSessionData() error { envelopeBytes, err := proto.Marshal(envelope) if err != nil { - t.sendError("unable to marshal session data event for web client", err, t.stream) + t.sendError(ctx, "unable to marshal session data event for web client", err, t.stream) return trace.Wrap(err) } if err := t.stream.WriteMessage(websocket.BinaryMessage, envelopeBytes); err != nil { - t.sendError("unable to write message to socket", err, t.stream) + t.sendError(ctx, "unable to write message to socket", err, t.stream) return trace.Wrap(err) } @@ -455,23 +448,23 @@ func (t *TerminalHandler) handler(ws *websocket.Conn, r *http.Request) { tctx := oteltrace.ContextWithRemoteSpanContext(context.Background(), oteltrace.SpanContextFromContext(r.Context())) ctx, cancel := context.WithCancel(tctx) defer cancel() - t.stream = terminal.NewStream(ctx, terminal.StreamConfig{WS: ws, Logger: t.log}) + t.stream = terminal.NewStream(ctx, terminal.StreamConfig{WS: ws, Logger: t.logger}) // Create a Teleport client, if not able to, show the reason to the user in // the terminal. tc, err := t.makeClient(ctx, t.stream, ws.RemoteAddr().String()) if err != nil { - t.log.WithError(err).Info("Failed creating a client for session") - t.stream.WriteError(err.Error()) + t.logger.InfoContext(ctx, "Failed creating a client for session", "error", err) + t.stream.WriteError(ctx, err.Error()) return } - t.log.Debug("Creating websocket stream") + t.logger.DebugContext(ctx, "Creating websocket stream") defaultCloseHandler := ws.CloseHandler() ws.SetCloseHandler(func(code int, text string) error { t.closedByClient.Store(true) - t.log.Debug("web socket was closed by client - terminating session") + t.logger.DebugContext(ctx, "web socket was closed by client - terminating session") // Call the default close handler if one was set. if defaultCloseHandler != nil { @@ -490,7 +483,7 @@ func (t *TerminalHandler) handler(ws *websocket.Conn, r *http.Request) { // Block until the terminal session is complete. t.streamTerminal(ctx, tc) - t.log.Debug("Closing websocket stream") + t.logger.DebugContext(ctx, "Closing websocket stream") } type stderrWriter struct { @@ -498,7 +491,7 @@ type stderrWriter struct { } func (s stderrWriter) Write(b []byte) (int, error) { - s.stream.WriteError(string(b)) + s.stream.WriteError(context.Background(), string(b)) return len(b), nil } @@ -547,12 +540,12 @@ func (t *TerminalHandler) makeClient(ctx context.Context, stream *terminal.Strea // The web session was closed by the client while the ssh connection was being established. // Attempt to close the SSH session instead of proceeding with the window change request. if t.closedByClient.Load() { - t.log.Debug("websocket was closed by client, terminating established ssh connection to host") + t.logger.DebugContext(ctx, "websocket was closed by client, terminating established ssh connection to host") return false, trace.Wrap(s.Close()) } if err := s.WindowChange(ctx, t.term.H, t.term.W); err != nil { - t.log.Error(err) + t.logger.ErrorContext(ctx, "failed to send window change request", "error", err) } return false, nil @@ -569,7 +562,7 @@ func (t *sshBaseHandler) issueSessionMFACerts(ctx context.Context, tc *client.Te ctx, span := t.tracer.Start(ctx, "terminal/issueSessionMFACerts") defer span.End() - log.Debug("Attempting to issue a single-use user certificate with an MFA check.") + t.logger.DebugContext(ctx, "Attempting to issue a single-use user certificate with an MFA check") // Prepare MFA check request. mfaRequiredReq := &authproto.IsMFARequiredRequest{ @@ -812,8 +805,8 @@ func (t *TerminalHandler) streamTerminal(ctx context.Context, tc *client.Telepor nc, err := t.connectToHost(ctx, t.stream, tc, t.connectToNodeWithMFA) if err != nil { - t.log.WithError(err).Warn("Unable to stream terminal - failure connecting to host") - t.stream.WriteError(err.Error()) + t.logger.WarnContext(ctx, "Unable to stream terminal - failure connecting to host", "error", err) + t.stream.WriteError(ctx, err.Error()) return } defer nc.Close() @@ -823,7 +816,7 @@ func (t *TerminalHandler) streamTerminal(ctx context.Context, tc *client.Telepor // by the client from here on out should either get caught in the OnShellCreated callback // set on the [tc] or in [TerminalHandler.Close]. if t.closedByClient.Load() { - t.log.Debug("websocket was closed by client, aborting establishing ssh connection to host") + t.logger.DebugContext(ctx, "websocket was closed by client, aborting establishing ssh connection to host") return } @@ -833,7 +826,7 @@ func (t *TerminalHandler) streamTerminal(ctx context.Context, tc *client.Telepor nc.OnMFA = func() { baseCeremony := newMFACeremony(t.stream.WSStream, nil) if err := t.presenceChecker(ctx, out, t.userAuthClient, t.sessionData.ID.String(), baseCeremony); err != nil { - t.log.WithError(err).Warn("Unable to stream terminal - failure performing presence checks") + t.logger.WarnContext(ctx, "Unable to stream terminal - failure performing presence checks", "error", err) return } } @@ -844,7 +837,7 @@ func (t *TerminalHandler) streamTerminal(ctx context.Context, tc *client.Telepor defer monitorCancel() go func() { if err := monitorSessionLatency(monitorCtx, t.clock, t.stream.WSStream, nc.Client); err != nil { - t.log.WithError(err).Warn("failure monitoring session latency") + t.logger.WarnContext(monitorCtx, "failure monitoring session latency", "error", err) } }() @@ -852,8 +845,8 @@ func (t *TerminalHandler) streamTerminal(ctx context.Context, tc *client.Telepor // If we are joining a session, send the session data right away, we // know the session ID if t.tracker != nil { - if err := t.writeSessionData(); err != nil { - t.log.WithError(err).Warn("Failure sending session data") + if err := t.writeSessionData(ctx); err != nil { + t.logger.WarnContext(ctx, "Failure sending session data", "error", err) } close(sessionDataSent) } else { @@ -862,7 +855,7 @@ func (t *TerminalHandler) streamTerminal(ctx context.Context, tc *client.Telepor // created and the server sends us the session ID it is using writeSessionCtx, writeSessionCancel := context.WithCancel(ctx) defer writeSessionCancel() - waitForSessionID := prepareToReceiveSessionID(writeSessionCtx, t.log, nc) + waitForSessionID := prepareToReceiveSessionID(writeSessionCtx, t.logger, nc) // wait in a new goroutine because the server won't set a // session ID until we open a shell @@ -875,13 +868,13 @@ func (t *TerminalHandler) streamTerminal(ctx context.Context, tc *client.Telepor t.sessionData.ID = sid fallthrough case sessionIDNotModified: - if err := t.writeSessionData(); err != nil { - t.log.WithError(err).Warn("Failure sending session data") + if err := t.writeSessionData(ctx); err != nil { + t.logger.WarnContext(ctx, "Failure sending session data", "error", err) } case sessionIDNotSent: - t.log.Warn("Failed to receive session data") + t.logger.WarnContext(ctx, "Failed to receive session data") default: - t.log.Warnf("Invalid session ID status %v", status) + t.logger.WarnContext(ctx, "Invalid session ID status", "status", status) } }() } @@ -890,7 +883,7 @@ func (t *TerminalHandler) streamTerminal(ctx context.Context, tc *client.Telepor // either an error occurs or it completes successfully. if err = nc.RunInteractiveShell(ctx, t.participantMode, t.tracker, nil, beforeStart); err != nil { if !t.closedByClient.Load() { - t.stream.WriteError(err.Error()) + t.stream.WriteError(ctx, err.Error()) } return } @@ -904,15 +897,15 @@ func (t *TerminalHandler) streamTerminal(ctx context.Context, tc *client.Telepor // Send close envelope to web terminal upon exit without an error. if err := t.stream.SendCloseMessage(t.sessionData.ServerID); err != nil { - t.log.WithError(err).Error("Unable to send close event to web client.") + t.logger.ErrorContext(ctx, "Unable to send close event to web client", "error", err) } if err := t.stream.Close(); err != nil && !errors.Is(err, io.EOF) { - t.log.WithError(err).Error("Unable to close client web socket.") + t.logger.ErrorContext(ctx, "Unable to close client web socket", "error", err) return } - t.log.Debug("Sent close event to web client.") + t.logger.DebugContext(ctx, "Sent close event to web client") } // connectToNode attempts to connect to the host with the already @@ -920,7 +913,7 @@ func (t *TerminalHandler) streamTerminal(ctx context.Context, tc *client.Telepor func (t *sshBaseHandler) connectToNode(ctx context.Context, ws terminal.WSConn, tc *client.TeleportClient, accessChecker services.AccessChecker, getAgent teleagent.Getter, signer agentless.SignerCreator) (*client.NodeClient, error) { conn, err := t.router.DialHost(ctx, ws.RemoteAddr(), ws.LocalAddr(), t.sessionData.ServerID, strconv.Itoa(t.sessionData.ServerHostPort), tc.SiteName, accessChecker, getAgent, signer) if err != nil { - t.log.WithError(err).Warn("Unable to stream terminal - failed to dial host.") + t.logger.WarnContext(ctx, "Unable to stream terminal - failed to dial host", "error", err) if errors.Is(err, trace.NotFound(teleport.NodeIsAmbiguous)) { const message = "error: ambiguous host could match multiple nodes\n\nHint: try addressing the node by unique id (ex: user@node-id)\n" @@ -1010,7 +1003,7 @@ func (t *sshBaseHandler) connectToNodeWithMFABase(ctx context.Context, ws termin } // sendError sends an error message to the client using the provided websocket. -func (t *sshBaseHandler) sendError(errMsg string, err error, ws terminal.WSConn) { +func (t *sshBaseHandler) sendError(ctx context.Context, errMsg string, err error, ws terminal.WSConn) { envelope := &terminal.Envelope{ Version: defaults.WebsocketVersion, Type: defaults.WebsocketError, @@ -1019,10 +1012,10 @@ func (t *sshBaseHandler) sendError(errMsg string, err error, ws terminal.WSConn) envelopeBytes, err := proto.Marshal(envelope) if err != nil { - t.log.WithError(err).Error("failed to marshal error message") + t.logger.ErrorContext(ctx, "failed to marshal error message", "error", err) } if err := ws.WriteMessage(websocket.BinaryMessage, envelopeBytes); err != nil { - t.log.WithError(err).Error("failed to send error message") + t.logger.ErrorContext(ctx, "failed to send error message", "error", err) } } @@ -1033,22 +1026,22 @@ func (t *TerminalHandler) streamEvents(ctx context.Context, tc *client.TeleportC select { // Send push events that come over the events channel to the web client. case event := <-tc.EventsChannel(): - logger := t.log.WithField("event", event.GetType()) + logger := t.logger.With("event", event.GetType()) data, err := json.Marshal(event) if err != nil { - logger.WithError(err).Error("Unable to marshal audit event") + logger.ErrorContext(ctx, "Unable to marshal audit event", "error", err) continue } - logger.Debug("Sending audit event to web client.") + logger.DebugContext(ctx, "Sending audit event to web client") if err := t.stream.WriteAuditEvent(data); err != nil { if errors.Is(err, websocket.ErrCloseSent) { - logger.WithError(err).Debug("Websocket was closed, no longer streaming events") + logger.DebugContext(ctx, "Websocket was closed, no longer streaming events", "error", err) return } - logger.WithError(err).Error("Unable to send audit event to web client") + logger.ErrorContext(ctx, "Unable to send audit event to web client", "error", err) continue } diff --git a/lib/web/terminal/terminal.go b/lib/web/terminal/terminal.go index 334b7adb1b440..72c9b2d7499c1 100644 --- a/lib/web/terminal/terminal.go +++ b/lib/web/terminal/terminal.go @@ -22,6 +22,7 @@ import ( "errors" "fmt" "io" + "log/slog" "net" "strings" "sync" @@ -30,7 +31,6 @@ import ( "github.com/gogo/protobuf/proto" "github.com/gorilla/websocket" "github.com/gravitational/trace" - "github.com/sirupsen/logrus" "golang.org/x/text/encoding" "golang.org/x/text/encoding/unicode" @@ -41,6 +41,7 @@ import ( "github.com/gravitational/teleport/lib/defaults" "github.com/gravitational/teleport/lib/session" "github.com/gravitational/teleport/lib/utils" + logutils "github.com/gravitational/teleport/lib/utils/log" ) // WSConn is a gorilla/websocket minimal interface used by our web implementation. @@ -95,7 +96,7 @@ type WSStream struct { WSConn // log holds the structured logger. - log logrus.FieldLogger + log *slog.Logger } // Replace \n with \r\n so the message is correctly aligned. @@ -114,9 +115,9 @@ func (t *WSStream) WriteMessage(messageType int, data []byte) error { } // WriteError displays an error in the terminal window. -func (t *WSStream) WriteError(msg string) { +func (t *WSStream) WriteError(ctx context.Context, msg string) { if _, err := replacer.WriteString(t, msg); err != nil && !errors.Is(err, websocket.ErrCloseSent) { - t.log.WithError(err).Warnf("Unable to send error to terminal: %v", msg) + t.log.WarnContext(ctx, "Unable to send error to terminal", "message", msg, "error", err) } } @@ -156,19 +157,19 @@ func (t *WSStream) processMessages(ctx context.Context) { select { case <-ctx.Done(): default: - t.WriteError(msg) + t.WriteError(ctx, msg) return } } if ty != websocket.BinaryMessage { - t.WriteError(fmt.Sprintf("Expected binary message, got %v", ty)) + t.WriteError(ctx, fmt.Sprintf("Expected binary message, got %v", ty)) return } var envelope Envelope if err := proto.Unmarshal(bytes, &envelope); err != nil { - t.WriteError(fmt.Sprintf("Unable to parse message payload %v", err)) + t.WriteError(ctx, fmt.Sprintf("Unable to parse message payload %v", err)) return } @@ -196,7 +197,7 @@ func (t *WSStream) processMessages(ctx context.Context) { handler, ok := t.handlers[envelope.Type] if !ok { - t.log.Warnf("Received web socket envelope with unknown type %v", envelope.Type) + t.log.WarnContext(ctx, "Received web socket envelope with unknown type", "envelope_type", logutils.TypeAttr(envelope.Type)) continue } @@ -427,13 +428,13 @@ type StreamConfig struct { // The websocket to operate over. Required. WS WSConn // A logger to emit log messages. Optional. - Logger logrus.FieldLogger + Logger *slog.Logger // A custom set of handlers to process messages received // over the websocket. Optional. Handlers map[string]WSHandlerFunc } -func NewWStream(ctx context.Context, ws WSConn, log logrus.FieldLogger, handlers map[string]WSHandlerFunc) *WSStream { +func NewWStream(ctx context.Context, ws WSConn, log *slog.Logger, handlers map[string]WSHandlerFunc) *WSStream { w := &WSStream{ log: log, WSConn: ws, @@ -473,7 +474,7 @@ func NewStream(ctx context.Context, cfg StreamConfig) *Stream { } if cfg.Logger == nil { - cfg.Logger = utils.NewLogger() + cfg.Logger = slog.Default() } t.WSStream = NewWStream(ctx, cfg.WS, cfg.Logger, cfg.Handlers) @@ -497,19 +498,19 @@ func (t *Stream) handleWindowResize(ctx context.Context, envelope Envelope) { var e map[string]interface{} err := json.Unmarshal([]byte(envelope.Payload), &e) if err != nil { - t.log.Warnf("Failed to parse resize payload: %v", err) + t.log.WarnContext(ctx, "Failed to parse resize payload", "error", err) return } size, ok := e["size"].(string) if !ok { - t.log.Errorf("expected size to be of type string, got type %T instead", size) + t.log.ErrorContext(ctx, "got unexpected size type, expected type string", "size_type", logutils.TypeAttr(size)) return } params, err := session.UnmarshalTerminalParams(size) if err != nil { - t.log.Warnf("Failed to retrieve terminal size: %v", err) + t.log.WarnContext(ctx, "Failed to retrieve terminal size", "error", err) return } @@ -519,7 +520,7 @@ func (t *Stream) handleWindowResize(ctx context.Context, envelope Envelope) { } if err := t.sshSession.WindowChange(ctx, params.H, params.W); err != nil { - t.log.Error(err) + t.log.ErrorContext(ctx, "failed to send window change request", "error", err) } } @@ -541,7 +542,7 @@ func (t *Stream) handleFileTransferDecision(ctx context.Context, envelope Envelo } approved, ok := e["approved"].(bool) if !ok { - t.log.Error("Unable to find approved status on response") + t.log.ErrorContext(ctx, "Unable to find approved status on response") return } @@ -551,7 +552,7 @@ func (t *Stream) handleFileTransferDecision(ctx context.Context, envelope Envelo err = t.sshSession.DenyFileTransferRequest(ctx, e.GetString("requestId")) } if err != nil { - t.log.WithError(err).Error("Unable to respond to file transfer request") + t.log.ErrorContext(ctx, "Unable to respond to file transfer request", "error", err) } } @@ -573,7 +574,7 @@ func (t *Stream) handleFileTransferRequest(ctx context.Context, envelope Envelop } download, ok := e["download"].(bool) if !ok { - t.log.Error("Unable to find download param in response") + t.log.ErrorContext(ctx, "Unable to find download param in response") return } @@ -582,7 +583,7 @@ func (t *Stream) handleFileTransferRequest(ctx context.Context, envelope Envelop Location: e.GetString("location"), Filename: e.GetString("filename"), }); err != nil { - t.log.WithError(err).Error("Unable to request file transfer") + t.log.ErrorContext(ctx, "Unable to request file transfer", "error", err) } } diff --git a/lib/web/terminal_test.go b/lib/web/terminal_test.go index 615993c89710a..ea6182464bf9b 100644 --- a/lib/web/terminal_test.go +++ b/lib/web/terminal_test.go @@ -24,6 +24,7 @@ import ( "encoding/json" "fmt" "io" + "log/slog" "net/http" "net/http/httptest" "net/url" @@ -77,7 +78,7 @@ func TestTerminalReadFromClosedConn(t *testing.T) { ctx, cancel := context.WithCancel(context.Background()) t.Cleanup(cancel) - stream := terminal.NewStream(ctx, terminal.StreamConfig{WS: conn, Logger: utils.NewLoggerForTests()}) + stream := terminal.NewStream(ctx, terminal.StreamConfig{WS: conn, Logger: utils.NewSlogLoggerForTests()}) // close the stream before we attempt to read from it, // this will produce a net.ErrClosed error on the read @@ -203,7 +204,7 @@ func connectToHost(ctx context.Context, cfg connectConfig) (*testTerminal, error t.stream = terminal.NewStream(ctx, terminal.StreamConfig{ WS: ws, - Logger: utils.NewLogger(), + Logger: slog.Default(), Handlers: cfg.handlers, }) diff --git a/lib/web/tty_playback.go b/lib/web/tty_playback.go index 76c456a4a7010..838c1b45d1efd 100644 --- a/lib/web/tty_playback.go +++ b/lib/web/tty_playback.go @@ -34,6 +34,7 @@ import ( "github.com/gravitational/teleport/lib/reversetunnelclient" "github.com/gravitational/teleport/lib/session" "github.com/gravitational/teleport/lib/utils" + logutils "github.com/gravitational/teleport/lib/utils/log" ) const ( @@ -111,14 +112,14 @@ func (h *Handler) ttyPlaybackHandle( return nil, trace.Wrap(err) } - h.log.Debug("upgrading to websocket") + h.logger.DebugContext(r.Context(), "upgrading to websocket") upgrader := websocket.Upgrader{ ReadBufferSize: 1024, WriteBufferSize: 1024, } ws, err := upgrader.Upgrade(w, r, nil) if err != nil { - h.log.Warn("failed upgrade", err) + h.logger.WarnContext(r.Context(), "failed upgrade", "error", err) // if Upgrade fails, it automatically replies with an HTTP error // (this means we don't need to return an error here) return nil, nil @@ -132,7 +133,7 @@ func (h *Handler) ttyPlaybackHandle( Context: r.Context(), }) if err != nil { - h.log.Warn("player error", err) + h.logger.WarnContext(r.Context(), "player error", "error", err) writeError(ws, err) return nil, nil } @@ -146,18 +147,18 @@ func (h *Handler) ttyPlaybackHandle( typ, b, err := ws.ReadMessage() if err != nil { if !utils.IsOKNetworkError(err) { - log.Warnf("websocket read error: %v", err) + h.logger.WarnContext(ctx, "websocket read error", "error", err) } return } if typ != websocket.BinaryMessage { - log.Debugf("skipping unknown websocket message type %v", typ) + h.logger.DebugContext(ctx, "skipping unknown websocket message type", "message_type", logutils.TypeAttr(typ)) continue } if err := handlePlaybackAction(b, player); err != nil { - log.Warnf("skipping bad action: %v", err) + h.logger.WarnContext(ctx, "skipping bad action", "error", err) continue } } @@ -166,12 +167,12 @@ func (h *Handler) ttyPlaybackHandle( go func() { defer cancel() defer func() { - h.log.Debug("closing websocket") + h.logger.DebugContext(ctx, "closing websocket") if err := ws.WriteMessage(websocket.CloseMessage, nil); err != nil { - h.log.Debugf("error sending close message: %v", err) + h.logger.DebugContext(r.Context(), "error sending close message", "error", err) } if err := ws.Close(); err != nil { - h.log.Debugf("error closing websocket: %v", err) + h.logger.DebugContext(ctx, "error closing websocket", "error", err) } }() @@ -209,7 +210,7 @@ func (h *Handler) ttyPlaybackHandle( writeSize := func(size string) error { ts, err := session.UnmarshalTerminalParams(size) if err != nil { - h.log.Debugf("Ignoring invalid terminal size %q", size) + h.logger.DebugContext(ctx, "Ignoring invalid terminal size", "terminal_size", size) return nil // don't abort playback due to a bad event } @@ -230,7 +231,7 @@ func (h *Handler) ttyPlaybackHandle( if !ok { // send any playback errors to the browser if err := writeError(ws, player.Err()); err != nil { - h.log.Warnf("failed to send error message to browser: %v", err) + h.logger.WarnContext(ctx, "failed to send error message to browser", "error", err) } return } @@ -238,13 +239,13 @@ func (h *Handler) ttyPlaybackHandle( switch evt := evt.(type) { case *events.SessionStart: if err := writeSize(evt.TerminalSize); err != nil { - h.log.Debugf("Failed to write resize: %v", err) + h.logger.DebugContext(ctx, "Failed to write resize", "error", err) return } case *events.SessionPrint: if err := writePTY(evt.Data, uint64(evt.DelayMilliseconds)); err != nil { - h.log.Debugf("Failed to send PTY data: %v", err) + h.logger.DebugContext(ctx, "Failed to send PTY data", "error", err) return } @@ -253,20 +254,20 @@ func (h *Handler) ttyPlaybackHandle( // at the end of the recording is processed and the allow // the progress bar to go to 100% if err := writePTY(nil, uint64(evt.EndTime.Sub(evt.StartTime)/time.Millisecond)); err != nil { - h.log.Debugf("Failed to send session end data: %v", err) + h.logger.DebugContext(ctx, "Failed to send session end data", "error", err) return } case *events.Resize: if err := writeSize(evt.TerminalSize); err != nil { - h.log.Debugf("Failed to write resize: %v", err) + h.logger.DebugContext(ctx, "Failed to write resize", "error", err) return } case *events.SessionLeave: // do nothing default: - h.log.Debugf("unexpected event type %T", evt) + h.logger.DebugContext(ctx, "unexpected event type", "event_type", logutils.TypeAttr(evt)) } } } diff --git a/lib/web/ui/app.go b/lib/web/ui/app.go index 5661d3290960c..934978ccb8d44 100644 --- a/lib/web/ui/app.go +++ b/lib/web/ui/app.go @@ -20,10 +20,10 @@ package ui import ( "cmp" + "context" + "log/slog" "sort" - "github.com/sirupsen/logrus" - "github.com/gravitational/teleport/api/types" "github.com/gravitational/teleport/lib/ui" "github.com/gravitational/teleport/lib/utils" @@ -113,7 +113,7 @@ type MakeAppsConfig struct { // UserGroupLookup is a map of user groups to provide to each App UserGroupLookup map[string]types.UserGroup // Logger is a logger used for debugging while making an app - Logger logrus.FieldLogger + Logger *slog.Logger // RequireRequest indicates if a returned resource is only accessible after an access request RequiresRequest bool } @@ -126,7 +126,7 @@ func MakeApp(app types.Application, c MakeAppsConfig) App { for _, userGroupName := range app.GetUserGroups() { userGroup := c.UserGroupLookup[userGroupName] if userGroup == nil { - c.Logger.Debugf("Unable to find user group %s when creating user groups, skipping", userGroupName) + c.Logger.DebugContext(context.Background(), "Unable to find user group when creating user groups, skipping", "user_group", userGroupName) continue } diff --git a/lib/web/user_groups.go b/lib/web/user_groups.go index 4e0927dabf55e..a61340491e8d8 100644 --- a/lib/web/user_groups.go +++ b/lib/web/user_groups.go @@ -57,7 +57,7 @@ func (h *Handler) getUserGroups(_ http.ResponseWriter, r *http.Request, params h UseSearchAsRoles: true, }) if err != nil { - h.log.Debugf("Unable to fetch applications while listing user groups, unable to display associated applications: %v", err) + h.logger.DebugContext(r.Context(), "Unable to fetch applications while listing user groups, unable to display associated applications", "error", err) } appServerLookup := make(map[string]types.AppServer, len(appServers)) @@ -71,7 +71,7 @@ func (h *Handler) getUserGroups(_ http.ResponseWriter, r *http.Request, params h for _, appName := range userGroup.GetApplications() { app := appServerLookup[appName] if app == nil { - h.log.Debugf("Unable to find application %s when creating user groups, skipping", appName) + h.logger.DebugContext(r.Context(), "Unable to find application when creating user groups, skipping", "app", appName) continue } apps = append(apps, app.GetApp()) diff --git a/lib/web/web.go b/lib/web/web.go deleted file mode 100644 index ab73f43324f92..0000000000000 --- a/lib/web/web.go +++ /dev/null @@ -1,34 +0,0 @@ -/* - * Teleport - * Copyright (C) 2023 Gravitational, Inc. - * - * This program is free software: you can redistribute it and/or modify - * it under the terms of the GNU Affero General Public License as published by - * the Free Software Foundation, either version 3 of the License, or - * (at your option) any later version. - * - * This program is distributed in the hope that it will be useful, - * but WITHOUT ANY WARRANTY; without even the implied warranty of - * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the - * GNU Affero General Public License for more details. - * - * You should have received a copy of the GNU Affero General Public License - * along with this program. If not, see . - */ - -package web - -import ( - "github.com/sirupsen/logrus" - - "github.com/gravitational/teleport" -) - -var log = newPackageLogger() - -// newPackageLogger returns a new instance of the logger -// configured for the package -func newPackageLogger(subcomponents ...string) logrus.FieldLogger { - return logrus.WithField(teleport.ComponentKey, - teleport.Component(append([]string{teleport.ComponentWeb}, subcomponents...)...)) -}