From e8152e53fc1eb98cdd7712b1cb92c4ffab06e5f2 Mon Sep 17 00:00:00 2001 From: Nico <32375741+nulmete@users.noreply.github.com> Date: Wed, 25 Feb 2026 18:35:29 -0300 Subject: [PATCH] Log response body in PostJSONWithTimeout error case (#40509) # Checklist for submitter - [x] Changes file added for user-visible changes in `changes/`, `orbit/changes/` or `ee/fleetd-chrome/changes`. See [Changes files](https://github.com/fleetdm/fleet/blob/main/docs/Contributing/guides/committing-changes.md#changes-files) for more information. ## Testing - [ ] QA'd all new/changed functionality manually --- changes/14276-post-json-redact-response-body | 1 + cmd/fleet/cron.go | 8 +++++--- cmd/fleet/serve.go | 4 +++- cmd/fleet/serve_test.go | 9 +++++---- ee/server/service/devices.go | 2 +- server/datastore/mysql/testing_utils.go | 5 ++++- server/fleet/calendar.go | 4 +++- server/logging/webhook.go | 2 +- server/service/activities_test.go | 5 ++++- server/service/osquery.go | 1 + server/service/testing_utils.go | 7 +++++-- server/utils.go | 14 ++++++++++++-- server/webhooks/failing_policies.go | 2 +- server/webhooks/host_status.go | 8 ++++---- server/webhooks/vulnerabilities.go | 6 +++--- 15 files changed, 53 insertions(+), 25 deletions(-) create mode 100644 changes/14276-post-json-redact-response-body diff --git a/changes/14276-post-json-redact-response-body b/changes/14276-post-json-redact-response-body new file mode 100644 index 0000000000..1cbd5bfe75 --- /dev/null +++ b/changes/14276-post-json-redact-response-body @@ -0,0 +1 @@ +* Changed PostJSONWithTimeout to log response body in error case. diff --git a/cmd/fleet/cron.go b/cmd/fleet/cron.go index 4b41c4db0b..9c73d991b5 100644 --- a/cmd/fleet/cron.go +++ b/cmd/fleet/cron.go @@ -4,6 +4,7 @@ import ( "context" "errors" "fmt" + "log/slog" "net/url" "os" "strconv" @@ -1285,6 +1286,7 @@ func newUsageStatisticsSchedule(ctx context.Context, instanceID string, ds fleet name = string(fleet.CronUsageStatistics) defaultInterval = 1 * time.Hour ) + slogLogger := logger.SlogLogger() s := schedule.New( ctx, name, instanceID, defaultInterval, ds, ds, schedule.WithLogger(logger.With("cron", name)), @@ -1293,7 +1295,7 @@ func newUsageStatisticsSchedule(ctx context.Context, instanceID string, ds fleet func(ctx context.Context) error { // NOTE(mna): this is not a route from the fleet server (not in server/service/handler.go) so it // will not automatically support the /latest/ versioning. Leaving it as /v1/ for that reason. - return trySendStatistics(ctx, ds, fleet.StatisticsFrequency, "https://fleetdm.com/api/v1/webhooks/receive-usage-analytics", config) + return trySendStatistics(ctx, ds, fleet.StatisticsFrequency, "https://fleetdm.com/api/v1/webhooks/receive-usage-analytics", config, slogLogger) }, ), ) @@ -1301,7 +1303,7 @@ func newUsageStatisticsSchedule(ctx context.Context, instanceID string, ds fleet return s, nil } -func trySendStatistics(ctx context.Context, ds fleet.Datastore, frequency time.Duration, url string, config config.FleetConfig) error { +func trySendStatistics(ctx context.Context, ds fleet.Datastore, frequency time.Duration, url string, config config.FleetConfig, logger *slog.Logger) error { ac, err := ds.AppConfig(ctx) if err != nil { return err @@ -1320,7 +1322,7 @@ func trySendStatistics(ctx context.Context, ds fleet.Datastore, frequency time.D return nil } - if err := server.PostJSONWithTimeout(ctx, url, stats); err != nil { + if err := server.PostJSONWithTimeout(ctx, url, stats, logger); err != nil { return err } diff --git a/cmd/fleet/serve.go b/cmd/fleet/serve.go index 12f250980a..78d413fecb 100644 --- a/cmd/fleet/serve.go +++ b/cmd/fleet/serve.go @@ -1813,7 +1813,9 @@ func createActivityBoundedContext(svc fleet.Service, dbConns *common_mysql.DBCon dbConns, activityAuthorizer, activityACLAdapter, - server.PostJSONWithTimeout, + func(ctx context.Context, url string, payload any) error { + return server.PostJSONWithTimeout(ctx, url, payload, logger) + }, logger, ) // Create auth middleware for activity bounded context diff --git a/cmd/fleet/serve_test.go b/cmd/fleet/serve_test.go index 2e2aaecea0..c1bc87e820 100644 --- a/cmd/fleet/serve_test.go +++ b/cmd/fleet/serve_test.go @@ -7,6 +7,7 @@ import ( "encoding/json" "errors" "io" + "log/slog" "net/http" "net/http/httptest" "os" @@ -137,7 +138,7 @@ func TestMaybeSendStatistics(t *testing.T) { } ctx := license.NewContext(context.Background(), &fleet.LicenseInfo{Tier: fleet.TierPremium}) - err := trySendStatistics(ctx, ds, fleet.StatisticsFrequency, ts.URL, fleetConfig) + err := trySendStatistics(ctx, ds, fleet.StatisticsFrequency, ts.URL, fleetConfig, slog.Default()) require.NoError(t, err) assert.True(t, recorded) require.True(t, cleanedup) @@ -175,7 +176,7 @@ func TestMaybeSendStatisticsSkipsSendingIfNotNeeded(t *testing.T) { } ctx := license.NewContext(context.Background(), &fleet.LicenseInfo{Tier: fleet.TierPremium}) - err := trySendStatistics(ctx, ds, fleet.StatisticsFrequency, ts.URL, fleetConfig) + err := trySendStatistics(ctx, ds, fleet.StatisticsFrequency, ts.URL, fleetConfig, slog.Default()) require.NoError(t, err) assert.False(t, recorded) assert.False(t, cleanedup) @@ -199,7 +200,7 @@ func TestMaybeSendStatisticsSkipsIfNotConfigured(t *testing.T) { } ctx := license.NewContext(context.Background(), &fleet.LicenseInfo{Tier: fleet.TierFree}) - err := trySendStatistics(ctx, ds, fleet.StatisticsFrequency, ts.URL, fleetConfig) + err := trySendStatistics(ctx, ds, fleet.StatisticsFrequency, ts.URL, fleetConfig, slog.Default()) require.NoError(t, err) assert.False(t, called) } @@ -229,7 +230,7 @@ func TestMaybeSendStatisticsSendsIfNotConfiguredForPremium(t *testing.T) { ds.RecordStatisticsSentFunc = func(ctx context.Context) error { return nil } ctx := license.NewContext(context.Background(), &fleet.LicenseInfo{Tier: fleet.TierPremium}) - err := trySendStatistics(ctx, ds, fleet.StatisticsFrequency, ts.URL, fleetConfig) + err := trySendStatistics(ctx, ds, fleet.StatisticsFrequency, ts.URL, fleetConfig, slog.Default()) require.NoError(t, err) assert.True(t, called) } diff --git a/ee/server/service/devices.go b/ee/server/service/devices.go index 9b89b06b59..2c8382f311 100644 --- a/ee/server/service/devices.go +++ b/ee/server/service/devices.go @@ -81,7 +81,7 @@ func (svc *Service) TriggerMigrateMDMDevice(ctx context.Context, host *fleet.Hos p.Host.UUID = host.UUID p.Host.HardwareSerial = host.HardwareSerial - if err := server.PostJSONWithTimeout(ctx, ac.MDM.MacOSMigration.WebhookURL, p); err != nil { + if err := server.PostJSONWithTimeout(ctx, ac.MDM.MacOSMigration.WebhookURL, p, svc.logger.SlogLogger()); err != nil { return ctxerr.Wrap(ctx, err, "posting macOS migration webhook") } diff --git a/server/datastore/mysql/testing_utils.go b/server/datastore/mysql/testing_utils.go index e89f04dfec..19aecbe732 100644 --- a/server/datastore/mysql/testing_utils.go +++ b/server/datastore/mysql/testing_utils.go @@ -1032,7 +1032,10 @@ func NewTestActivityService(t testing.TB, ds *Datastore) activity_api.Service { aclAdapter := activityacl.NewFleetServiceAdapter(lookupSvc) // Create service via bootstrap (the public API for creating the bounded context) - svc, _ := activity_bootstrap.New(dbConns, &testingAuthorizer{}, aclAdapter, server.PostJSONWithTimeout, slog.New(slog.DiscardHandler)) + discardLogger := slog.New(slog.DiscardHandler) + svc, _ := activity_bootstrap.New(dbConns, &testingAuthorizer{}, aclAdapter, func(ctx context.Context, url string, payload any) error { + return server.PostJSONWithTimeout(ctx, url, payload, discardLogger) + }, discardLogger) return svc } diff --git a/server/fleet/calendar.go b/server/fleet/calendar.go index e474d5fef7..2e3aab52c0 100644 --- a/server/fleet/calendar.go +++ b/server/fleet/calendar.go @@ -3,6 +3,7 @@ package fleet import ( "context" "fmt" + "log/slog" "time" _ "time/tzdata" // embed timezone information in the program @@ -102,6 +103,7 @@ func FireCalendarWebhook( hostDisplayName string, failingCalendarPolicies []PolicyCalendarData, err string, + logger *slog.Logger, ) error { if err := server.PostJSONWithTimeout(context.Background(), webhookURL, &CalendarWebhookPayload{ Timestamp: time.Now(), @@ -110,7 +112,7 @@ func FireCalendarWebhook( HostSerialNumber: hostHardwareSerial, FailingPolicies: failingCalendarPolicies, Error: err, - }); err != nil { + }, logger); err != nil { return fmt.Errorf("POST to %q: %w", server.MaskSecretURLParams(webhookURL), server.MaskURLError(err)) } return nil diff --git a/server/logging/webhook.go b/server/logging/webhook.go index b240ef6ffc..fe90c06f5f 100644 --- a/server/logging/webhook.go +++ b/server/logging/webhook.go @@ -45,7 +45,7 @@ func (w *webhookLogWriter) Write(ctx context.Context, logs []json.RawMessage) er "url", server.MaskSecretURLParams(w.url), ) - if err := server.PostJSONWithTimeout(ctx, w.url, payload); err != nil { + if err := server.PostJSONWithTimeout(ctx, w.url, payload, w.logger.SlogLogger()); err != nil { level.Error(w.logger).Log( "msg", fmt.Sprintf("failed to send automation webhook to %s", server.MaskSecretURLParams(w.url)), "err", server.MaskURLError(err).Error(), diff --git a/server/service/activities_test.go b/server/service/activities_test.go index 1fb89c7a09..d9b4344ee9 100644 --- a/server/service/activities_test.go +++ b/server/service/activities_test.go @@ -213,7 +213,10 @@ func TestActivityWebhooks(t *testing.T) { }, nil }, } - realActivitySvc := activity_bootstrap.NewForUnitTests(providers, fleetserver.PostJSONWithTimeout, slog.New(slog.DiscardHandler)) + discardLogger := slog.New(slog.DiscardHandler) + realActivitySvc := activity_bootstrap.NewForUnitTests(providers, func(ctx context.Context, url string, payload any) error { + return fleetserver.PostJSONWithTimeout(ctx, url, payload, discardLogger) + }, discardLogger) opts.ActivityMock.Delegate = realActivitySvc var activityUser *activity_api.User diff --git a/server/service/osquery.go b/server/service/osquery.go index a6064a8748..86c51c8735 100644 --- a/server/service/osquery.go +++ b/server/service/osquery.go @@ -1373,6 +1373,7 @@ func processCalendarPolicies( if err := fleet.FireCalendarWebhook( team.Config.Integrations.GoogleCalendar.WebhookURL, host.ID, host.HardwareSerial, host.DisplayName(), failingCalendarPolicies, "", + logger.SlogLogger(), ); err != nil { var statusCoder kithttp.StatusCoder if errors.As(err, &statusCoder) && statusCoder.StatusCode() == http.StatusTooManyRequests { diff --git a/server/service/testing_utils.go b/server/service/testing_utils.go index d567c8291f..5e974f14de 100644 --- a/server/service/testing_utils.go +++ b/server/service/testing_utils.go @@ -486,12 +486,15 @@ func RunServerForTestsWithServiceWithDS(t *testing.T, ctx context.Context, ds fl require.NoError(t, err) activityAuthorizer := authz.NewAuthorizerAdapter(legacyAuthorizer) activityACLAdapter := activityacl.NewFleetServiceAdapter(svc) + slogLogger := logger.SlogLogger() activitySvc, activityRoutesFn := activity_bootstrap.New( opts[0].DBConns, activityAuthorizer, activityACLAdapter, - server.PostJSONWithTimeout, - logger.SlogLogger(), + func(ctx context.Context, url string, payload any) error { + return server.PostJSONWithTimeout(ctx, url, payload, slogLogger) + }, + slogLogger, ) svc.SetActivityService(activitySvc) if opts[0].ActivityModule != nil { diff --git a/server/utils.go b/server/utils.go index 0f99e9e328..ce843cba00 100644 --- a/server/utils.go +++ b/server/utils.go @@ -13,6 +13,7 @@ import ( "fmt" "html/template" "io" + "log/slog" "net/http" "strings" "time" @@ -64,7 +65,7 @@ func (e *errWithStatus) StatusCode() int { return e.statusCode } -func PostJSONWithTimeout(ctx context.Context, url string, v interface{}) error { +func PostJSONWithTimeout(ctx context.Context, url string, v any, logger *slog.Logger) error { jsonBytes, err := json.Marshal(v) if err != nil { return err @@ -86,7 +87,16 @@ func PostJSONWithTimeout(ctx context.Context, url string, v interface{}) error { if !httpSuccessStatus(resp.StatusCode) { body, _ := io.ReadAll(resp.Body) - return &errWithStatus{err: fmt.Sprintf("error posting to %s: %d. %s", MaskSecretURLParams(url), resp.StatusCode, string(body)), statusCode: resp.StatusCode} + bodyStr := string(body) + if len(bodyStr) > 512 { + bodyStr = bodyStr[:512] + } + logger.DebugContext(ctx, "non-success response from POST", + "url", MaskSecretURLParams(url), + "status_code", resp.StatusCode, + "body", bodyStr, + ) + return &errWithStatus{err: fmt.Sprintf("error posting to %s", MaskSecretURLParams(url)), statusCode: resp.StatusCode} } return nil diff --git a/server/webhooks/failing_policies.go b/server/webhooks/failing_policies.go index 34785c1412..9dcb7af847 100644 --- a/server/webhooks/failing_policies.go +++ b/server/webhooks/failing_policies.go @@ -79,7 +79,7 @@ func SendFailingPoliciesBatchedPOSTs( jsonBytes = endpointer.DuplicateJSONKeys(jsonBytes, rules, endpointer.DuplicateJSONKeysOpts{Compact: true}) } - if err := server.PostJSONWithTimeout(ctx, webhookURL.String(), json.RawMessage(jsonBytes)); err != nil { + if err := server.PostJSONWithTimeout(ctx, webhookURL.String(), json.RawMessage(jsonBytes), logger); err != nil { return ctxerr.Wrapf(ctx, server.MaskURLError(err), "posting to %q", server.MaskSecretURLParams(webhookURL.String())) } if err := failingPoliciesSet.RemoveHosts(policy.ID, batch); err != nil { diff --git a/server/webhooks/host_status.go b/server/webhooks/host_status.go index 7c27f12f2a..9e5a116cf9 100644 --- a/server/webhooks/host_status.go +++ b/server/webhooks/host_status.go @@ -34,10 +34,10 @@ func triggerGlobalHostStatusWebhook(ctx context.Context, ds fleet.Datastore, log logger.DebugContext(ctx, "host status webhook triggered", "global", true) - return processWebhook(ctx, ds, nil, appConfig.WebhookSettings.HostStatusWebhook) + return processWebhook(ctx, ds, nil, appConfig.WebhookSettings.HostStatusWebhook, logger) } -func processWebhook(ctx context.Context, ds fleet.Datastore, teamID *uint, settings fleet.HostStatusWebhookSettings) error { +func processWebhook(ctx context.Context, ds fleet.Datastore, teamID *uint, settings fleet.HostStatusWebhookSettings, logger *slog.Logger) error { total, unseen, err := ds.TotalAndUnseenHostsSince(ctx, teamID, settings.DaysCount) if err != nil { return ctxerr.Wrap(ctx, err, "getting total and unseen hosts") @@ -67,7 +67,7 @@ func processWebhook(ctx context.Context, ds fleet.Datastore, teamID *uint, setti payload["data"].(map[string]any)["team_id"] = *teamID } - err = server.PostJSONWithTimeout(ctx, url, &payload) + err = server.PostJSONWithTimeout(ctx, url, &payload, logger) if err != nil { return ctxerr.Wrapf(ctx, err, "posting to %s", url) } @@ -94,7 +94,7 @@ func triggerTeamHostStatusWebhook(ctx context.Context, ds fleet.Datastore, logge continue } logger.DebugContext(ctx, "host status webhook triggered", "fleet_id", id) - err = processWebhook(ctx, ds, &id, *team.Config.WebhookSettings.HostStatusWebhook) + err = processWebhook(ctx, ds, &id, *team.Config.WebhookSettings.HostStatusWebhook, logger) if err != nil { multiErr = multierror.Append(multiErr, ctxerr.Wrap(ctx, err, "processing webhook")) } diff --git a/server/webhooks/vulnerabilities.go b/server/webhooks/vulnerabilities.go index d9c3e56c40..e6e03e4e61 100644 --- a/server/webhooks/vulnerabilities.go +++ b/server/webhooks/vulnerabilities.go @@ -52,7 +52,7 @@ func TriggerVulnerabilitiesWebhook( limit = batchSize } payload := mapper.GetPayload(serverURL, hosts[:limit], cve, args.Meta[cve]) - if err := sendVulnerabilityHostBatch(ctx, targetURL, payload, args.Time); err != nil { + if err := sendVulnerabilityHostBatch(ctx, targetURL, payload, args.Time, logger); err != nil { return ctxerr.Wrap(ctx, err, "send vulnerability host batch") } hosts = hosts[limit:] @@ -62,13 +62,13 @@ func TriggerVulnerabilitiesWebhook( return nil } -func sendVulnerabilityHostBatch(ctx context.Context, targetURL string, vuln WebhookPayload, now time.Time) error { +func sendVulnerabilityHostBatch(ctx context.Context, targetURL string, vuln WebhookPayload, now time.Time, logger *slog.Logger) error { payload := map[string]interface{}{ "timestamp": now, "vulnerability": vuln, } - if err := server.PostJSONWithTimeout(ctx, targetURL, &payload); err != nil { + if err := server.PostJSONWithTimeout(ctx, targetURL, &payload, logger); err != nil { return ctxerr.Wrapf(ctx, err, "posting to %s", targetURL) } return nil