feat: add prometheus observability metrics for dbpurge (#21074)

Related to
[`internal#1139`](https://github.com/coder/internal/issues/1139)

This implements some prometheus metrics for records being removed from
the database. Currently we're tracking the following fields being
removed from the DB by this. They're viewable in the
`/api/v2/debug/metrics` endpoint.

* `expired_api_keys`
* `aibridge_records`
* `connection_logs`
* `duration`

```
# HELP coderd_dbpurge_iteration_duration_seconds Duration of each dbpurge iteration in seconds.
# TYPE coderd_dbpurge_iteration_duration_seconds histogram
coderd_dbpurge_iteration_duration_seconds_bucket{success="true",le="1"} 1
coderd_dbpurge_iteration_duration_seconds_bucket{success="true",le="5"} 1
coderd_dbpurge_iteration_duration_seconds_bucket{success="true",le="10"} 1
coderd_dbpurge_iteration_duration_seconds_bucket{success="true",le="30"} 1
coderd_dbpurge_iteration_duration_seconds_bucket{success="true",le="60"} 1
coderd_dbpurge_iteration_duration_seconds_bucket{success="true",le="300"} 1
coderd_dbpurge_iteration_duration_seconds_bucket{success="true",le="600"} 1
coderd_dbpurge_iteration_duration_seconds_bucket{success="true",le="+Inf"} 1
coderd_dbpurge_iteration_duration_seconds_sum{success="true"} 0.014787814
coderd_dbpurge_iteration_duration_seconds_count{success="true"} 1
# HELP coderd_dbpurge_records_purged_total Total number of records purged by type.
# TYPE coderd_dbpurge_records_purged_total counter
coderd_dbpurge_records_purged_total{record_type="aibridge_records"} 0
coderd_dbpurge_records_purged_total{record_type="audit_logs"} 0
coderd_dbpurge_records_purged_total{record_type="connection_logs"} 0
coderd_dbpurge_records_purged_total{record_type="expired_api_keys"} 0
coderd_dbpurge_records_purged_total{record_type="workspace_agent_logs"} 0
```

| Position | Pull-request |
| -------- | ------------ |
|  | [feat: add prometheus observability metrics for
`dbpurge`](https://github.com/coder/coder/pull/21074) |
| | [feat: add rbac specificity for
`dbpurge`](https://github.com/coder/coder/pull/21088) |
This commit is contained in:
Jake Howell
2025-12-20 00:20:57 +11:00
committed by GitHub
parent 5b3c24c02f
commit 00793cc0b5
3 changed files with 154 additions and 15 deletions
+1 -1
View File
@@ -1038,7 +1038,7 @@ func (r *RootCmd) Server(newAPI func(context.Context, *coderd.Options) (*coderd.
defer shutdownConns()
// Ensures that old database entries are cleaned up over time!
purger := dbpurge.New(ctx, logger.Named("dbpurge"), options.Database, options.DeploymentValues, quartz.NewReal())
purger := dbpurge.New(ctx, logger.Named("dbpurge"), options.Database, options.DeploymentValues, quartz.NewReal(), options.PrometheusRegistry)
defer purger.Close()
// Updates workspace usage
+33 -1
View File
@@ -7,6 +7,8 @@ import (
"golang.org/x/xerrors"
"github.com/prometheus/client_golang/prometheus"
"cdr.dev/slog"
"github.com/coder/coder/v2/coderd/database"
@@ -40,13 +42,30 @@ const (
// It is the caller's responsibility to call Close on the returned instance.
//
// This is for cleaning up old, unused resources from the database that take up space.
func New(ctx context.Context, logger slog.Logger, db database.Store, vals *codersdk.DeploymentValues, clk quartz.Clock) io.Closer {
func New(ctx context.Context, logger slog.Logger, db database.Store, vals *codersdk.DeploymentValues, clk quartz.Clock, reg prometheus.Registerer) io.Closer {
closed := make(chan struct{})
ctx, cancelFunc := context.WithCancel(ctx)
//nolint:gocritic // The system purges old db records without user input.
ctx = dbauthz.AsSystemRestricted(ctx)
iterationDuration := prometheus.NewHistogramVec(prometheus.HistogramOpts{
Namespace: "coderd",
Subsystem: "dbpurge",
Name: "iteration_duration_seconds",
Help: "Duration of each dbpurge iteration in seconds.",
Buckets: []float64{1, 5, 10, 30, 60, 300, 600}, // 1s to 10min
}, []string{"success"})
reg.MustRegister(iterationDuration)
recordsPurged := prometheus.NewCounterVec(prometheus.CounterOpts{
Namespace: "coderd",
Subsystem: "dbpurge",
Name: "records_purged_total",
Help: "Total number of records purged by type.",
}, []string{"record_type"})
reg.MustRegister(recordsPurged)
// Start the ticker with the initial delay.
ticker := clk.NewTicker(delay)
doTick := func(ctx context.Context, start time.Time) {
@@ -164,9 +183,22 @@ func New(ctx context.Context, logger slog.Logger, db database.Store, vals *coder
slog.F("duration", clk.Since(start)),
)
duration := clk.Since(start)
iterationDuration.WithLabelValues("true").Observe(duration.Seconds())
recordsPurged.WithLabelValues("workspace_agent_logs").Add(float64(purgedWorkspaceAgentLogs))
recordsPurged.WithLabelValues("expired_api_keys").Add(float64(expiredAPIKeys))
recordsPurged.WithLabelValues("aibridge_records").Add(float64(purgedAIBridgeRecords))
recordsPurged.WithLabelValues("connection_logs").Add(float64(purgedConnectionLogs))
recordsPurged.WithLabelValues("audit_logs").Add(float64(purgedAuditLogs))
return nil
}, database.DefaultTXOptions().WithID("db_purge")); err != nil {
logger.Error(ctx, "failed to purge old database entries", slog.Error(err))
// Record metrics for failed purge iteration.
duration := clk.Since(start)
iterationDuration.WithLabelValues("false").Observe(duration.Seconds())
return
}
}
+120 -13
View File
@@ -12,14 +12,17 @@ import (
"time"
"github.com/google/uuid"
"github.com/prometheus/client_golang/prometheus"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
"go.uber.org/goleak"
"go.uber.org/mock/gomock"
"golang.org/x/xerrors"
"cdr.dev/slog"
"cdr.dev/slog/sloggers/slogtest"
"github.com/coder/coder/v2/coderd/coderdtest/promhelp"
"github.com/coder/coder/v2/coderd/database"
"github.com/coder/coder/v2/coderd/database/dbgen"
"github.com/coder/coder/v2/coderd/database/dbmock"
@@ -52,11 +55,114 @@ func TestPurge(t *testing.T) {
done := awaitDoTick(ctx, t, clk)
mDB := dbmock.NewMockStore(gomock.NewController(t))
mDB.EXPECT().InTx(gomock.Any(), database.DefaultTXOptions().WithID("db_purge")).Return(nil).Times(2)
purger := dbpurge.New(context.Background(), testutil.Logger(t), mDB, &codersdk.DeploymentValues{}, clk)
purger := dbpurge.New(context.Background(), testutil.Logger(t), mDB, &codersdk.DeploymentValues{}, clk, prometheus.NewRegistry())
<-done // wait for doTick() to run.
require.NoError(t, purger.Close())
}
//nolint:paralleltest // It uses LockIDDBPurge.
func TestMetrics(t *testing.T) {
t.Run("SuccessfulIteration", func(t *testing.T) {
ctx, cancel := context.WithTimeout(context.Background(), testutil.WaitShort)
defer cancel()
reg := prometheus.NewRegistry()
clk := quartz.NewMock(t)
now := time.Date(2025, 1, 15, 7, 30, 0, 0, time.UTC)
clk.Set(now).MustWait(ctx)
db, _ := dbtestutil.NewDB(t)
logger := slogtest.Make(t, &slogtest.Options{IgnoreErrors: true})
user := dbgen.User(t, db, database.User{})
oldExpiredKey, _ := dbgen.APIKey(t, db, database.APIKey{
UserID: user.ID,
ExpiresAt: now.Add(-8 * 24 * time.Hour), // Expired 8 days ago
TokenName: "old-expired-key",
})
_, err := db.GetAPIKeyByID(ctx, oldExpiredKey.ID)
require.NoError(t, err, "key should exist before purge")
done := awaitDoTick(ctx, t, clk)
closer := dbpurge.New(ctx, logger, db, &codersdk.DeploymentValues{
Retention: codersdk.RetentionConfig{
APIKeys: serpent.Duration(7 * 24 * time.Hour), // 7 days retention
},
}, clk, reg)
defer closer.Close()
testutil.TryReceive(ctx, t, done)
hist := promhelp.HistogramValue(t, reg, "coderd_dbpurge_iteration_duration_seconds", prometheus.Labels{
"success": "true",
})
require.NotNil(t, hist)
require.Greater(t, hist.GetSampleCount(), uint64(0), "should have at least one sample")
expiredAPIKeys := promhelp.CounterValue(t, reg, "coderd_dbpurge_records_purged_total", prometheus.Labels{
"record_type": "expired_api_keys",
})
require.Greater(t, expiredAPIKeys, 0, "should have deleted at least one expired API key")
_, err = db.GetAPIKeyByID(ctx, oldExpiredKey.ID)
require.Error(t, err, "key should be deleted after purge")
workspaceAgentLogs := promhelp.CounterValue(t, reg, "coderd_dbpurge_records_purged_total", prometheus.Labels{
"record_type": "workspace_agent_logs",
})
require.GreaterOrEqual(t, workspaceAgentLogs, 0)
aibridgeRecords := promhelp.CounterValue(t, reg, "coderd_dbpurge_records_purged_total", prometheus.Labels{
"record_type": "aibridge_records",
})
require.GreaterOrEqual(t, aibridgeRecords, 0)
connectionLogs := promhelp.CounterValue(t, reg, "coderd_dbpurge_records_purged_total", prometheus.Labels{
"record_type": "connection_logs",
})
require.GreaterOrEqual(t, connectionLogs, 0)
auditLogs := promhelp.CounterValue(t, reg, "coderd_dbpurge_records_purged_total", prometheus.Labels{
"record_type": "audit_logs",
})
require.GreaterOrEqual(t, auditLogs, 0)
})
t.Run("FailedIteration", func(t *testing.T) {
ctx, cancel := context.WithTimeout(context.Background(), testutil.WaitShort)
defer cancel()
reg := prometheus.NewRegistry()
clk := quartz.NewMock(t)
now := clk.Now()
clk.Set(now).MustWait(ctx)
ctrl := gomock.NewController(t)
mDB := dbmock.NewMockStore(ctrl)
mDB.EXPECT().InTx(gomock.Any(), database.DefaultTXOptions().WithID("db_purge")).
Return(xerrors.New("simulated database error")).
MinTimes(1)
logger := slogtest.Make(t, &slogtest.Options{IgnoreErrors: true})
done := awaitDoTick(ctx, t, clk)
closer := dbpurge.New(ctx, logger, mDB, &codersdk.DeploymentValues{}, clk, reg)
defer closer.Close()
testutil.TryReceive(ctx, t, done)
hist := promhelp.HistogramValue(t, reg, "coderd_dbpurge_iteration_duration_seconds", prometheus.Labels{
"success": "false",
})
require.NotNil(t, hist)
require.Greater(t, hist.GetSampleCount(), uint64(0), "should have at least one sample")
successHist := promhelp.MetricValue(t, reg, "coderd_dbpurge_iteration_duration_seconds", prometheus.Labels{
"success": "true",
})
require.Nil(t, successHist, "should not have success=true metric on failure")
})
}
//nolint:paralleltest // It uses LockIDDBPurge.
func TestDeleteOldWorkspaceAgentStats(t *testing.T) {
ctx, cancel := context.WithTimeout(context.Background(), testutil.WaitLong)
@@ -130,7 +236,7 @@ func TestDeleteOldWorkspaceAgentStats(t *testing.T) {
})
// when
closer := dbpurge.New(ctx, logger, db, &codersdk.DeploymentValues{}, clk)
closer := dbpurge.New(ctx, logger, db, &codersdk.DeploymentValues{}, clk, prometheus.NewRegistry())
defer closer.Close()
// then
@@ -155,7 +261,7 @@ func TestDeleteOldWorkspaceAgentStats(t *testing.T) {
// Start a new purger to immediately trigger delete after rollup.
_ = closer.Close()
closer = dbpurge.New(ctx, logger, db, &codersdk.DeploymentValues{}, clk)
closer = dbpurge.New(ctx, logger, db, &codersdk.DeploymentValues{}, clk, prometheus.NewRegistry())
defer closer.Close()
// then
@@ -250,7 +356,8 @@ func TestDeleteOldWorkspaceAgentLogs(t *testing.T) {
Retention: codersdk.RetentionConfig{
WorkspaceAgentLogs: serpent.Duration(7 * 24 * time.Hour),
},
}, clk)
}, clk, prometheus.NewRegistry())
defer closer.Close()
<-done // doTick() has now run.
@@ -464,7 +571,7 @@ func TestDeleteOldWorkspaceAgentLogsRetention(t *testing.T) {
done := awaitDoTick(ctx, t, clk)
closer := dbpurge.New(ctx, logger, db, &codersdk.DeploymentValues{
Retention: tc.retentionConfig,
}, clk)
}, clk, prometheus.NewRegistry())
defer closer.Close()
testutil.TryReceive(ctx, t, done)
@@ -555,7 +662,7 @@ func TestDeleteOldProvisionerDaemons(t *testing.T) {
require.NoError(t, err)
// when
closer := dbpurge.New(ctx, logger, db, &codersdk.DeploymentValues{}, clk)
closer := dbpurge.New(ctx, logger, db, &codersdk.DeploymentValues{}, clk, prometheus.NewRegistry())
defer closer.Close()
// then
@@ -659,7 +766,7 @@ func TestDeleteOldAuditLogConnectionEvents(t *testing.T) {
// Run the purge
done := awaitDoTick(ctx, t, clk)
closer := dbpurge.New(ctx, logger, db, &codersdk.DeploymentValues{}, clk)
closer := dbpurge.New(ctx, logger, db, &codersdk.DeploymentValues{}, clk, prometheus.NewRegistry())
defer closer.Close()
// Wait for tick
testutil.TryReceive(ctx, t, done)
@@ -822,7 +929,7 @@ func TestDeleteOldTelemetryHeartbeats(t *testing.T) {
require.NoError(t, err)
done := awaitDoTick(ctx, t, clk)
closer := dbpurge.New(ctx, logger, db, &codersdk.DeploymentValues{}, clk)
closer := dbpurge.New(ctx, logger, db, &codersdk.DeploymentValues{}, clk, prometheus.NewRegistry())
defer closer.Close()
<-done // doTick() has now run.
@@ -941,7 +1048,7 @@ func TestDeleteOldConnectionLogs(t *testing.T) {
done := awaitDoTick(ctx, t, clk)
closer := dbpurge.New(ctx, logger, db, &codersdk.DeploymentValues{
Retention: tc.retentionConfig,
}, clk)
}, clk, prometheus.NewRegistry())
defer closer.Close()
testutil.TryReceive(ctx, t, done)
@@ -1197,7 +1304,7 @@ func TestDeleteOldAIBridgeRecords(t *testing.T) {
Retention: serpent.Duration(tc.retention),
},
},
}, clk)
}, clk, prometheus.NewRegistry())
defer closer.Close()
testutil.TryReceive(ctx, t, done)
@@ -1284,7 +1391,7 @@ func TestDeleteOldAuditLogs(t *testing.T) {
done := awaitDoTick(ctx, t, clk)
closer := dbpurge.New(ctx, logger, db, &codersdk.DeploymentValues{
Retention: tc.retentionConfig,
}, clk)
}, clk, prometheus.NewRegistry())
defer closer.Close()
testutil.TryReceive(ctx, t, done)
@@ -1374,7 +1481,7 @@ func TestDeleteOldAuditLogs(t *testing.T) {
Retention: codersdk.RetentionConfig{
AuditLogs: serpent.Duration(retentionPeriod),
},
}, clk)
}, clk, prometheus.NewRegistry())
defer closer.Close()
testutil.TryReceive(ctx, t, done)
@@ -1494,7 +1601,7 @@ func TestDeleteExpiredAPIKeys(t *testing.T) {
done := awaitDoTick(ctx, t, clk)
closer := dbpurge.New(ctx, logger, db, &codersdk.DeploymentValues{
Retention: tc.retentionConfig,
}, clk)
}, clk, prometheus.NewRegistry())
defer closer.Close()
testutil.TryReceive(ctx, t, done)