-
Notifications
You must be signed in to change notification settings - Fork 0
Database Performance Optimizations #4
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change | ||||||||||||||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
|
|
@@ -10,6 +10,7 @@ import ( | |||||||||||||||||||||||||
| "time" | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| "github.com/grafana/grafana/pkg/services/annotations/accesscontrol" | ||||||||||||||||||||||||||
| "github.com/grafana/grafana/pkg/services/sqlstore/migrator" | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| "github.com/grafana/grafana/pkg/infra/db" | ||||||||||||||||||||||||||
| "github.com/grafana/grafana/pkg/infra/log" | ||||||||||||||||||||||||||
|
|
@@ -519,52 +520,135 @@ func (r *xormRepositoryImpl) CleanAnnotations(ctx context.Context, cfg setting.A | |||||||||||||||||||||||||
| var totalAffected int64 | ||||||||||||||||||||||||||
| if cfg.MaxAge > 0 { | ||||||||||||||||||||||||||
| cutoffDate := timeNow().Add(-cfg.MaxAge).UnixNano() / int64(time.Millisecond) | ||||||||||||||||||||||||||
| deleteQuery := `DELETE FROM annotation WHERE id IN (SELECT id FROM (SELECT id FROM annotation WHERE %s AND created < %v ORDER BY id DESC %s) a)` | ||||||||||||||||||||||||||
| sql := fmt.Sprintf(deleteQuery, annotationType, cutoffDate, r.db.GetDialect().Limit(r.cfg.AnnotationCleanupJobBatchSize)) | ||||||||||||||||||||||||||
| // Single-statement approaches, specifically ones using batched sub-queries, seem to deadlock with concurrent inserts on MySQL. | ||||||||||||||||||||||||||
| // We have a bounded batch size, so work around this by first loading the IDs into memory and allowing any locks to flush inside each batch. | ||||||||||||||||||||||||||
| // This may under-delete when concurrent inserts happen, but any such annotations will simply be cleaned on the next cycle. | ||||||||||||||||||||||||||
| // | ||||||||||||||||||||||||||
| // We execute the following batched operation repeatedly until either we run out of objects, the context is cancelled, or there is an error. | ||||||||||||||||||||||||||
| affected, err := untilDoneOrCancelled(ctx, func() (int64, error) { | ||||||||||||||||||||||||||
| cond := fmt.Sprintf(`%s AND created < %v ORDER BY id DESC %s`, annotationType, cutoffDate, r.db.GetDialect().Limit(r.cfg.AnnotationCleanupJobBatchSize)) | ||||||||||||||||||||||||||
| ids, err := r.fetchIDs(ctx, "annotation", cond) | ||||||||||||||||||||||||||
| if err != nil { | ||||||||||||||||||||||||||
| return 0, err | ||||||||||||||||||||||||||
| } | ||||||||||||||||||||||||||
| r.log.Error("Annotations to clean by time", "count", len(ids), "ids", ids, "cond", cond, "err", err) | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| affected, err := r.executeUntilDoneOrCancelled(ctx, sql) | ||||||||||||||||||||||||||
| x, y := r.deleteByIDs(ctx, "annotation", ids) | ||||||||||||||||||||||||||
| r.log.Error("cleaned annotations by time", "count", len(ids), "affected", x, "err", y) | ||||||||||||||||||||||||||
| return x, y | ||||||||||||||||||||||||||
| }) | ||||||||||||||||||||||||||
| totalAffected += affected | ||||||||||||||||||||||||||
| if err != nil { | ||||||||||||||||||||||||||
| return totalAffected, err | ||||||||||||||||||||||||||
| } | ||||||||||||||||||||||||||
| } | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| if cfg.MaxCount > 0 { | ||||||||||||||||||||||||||
| deleteQuery := `DELETE FROM annotation WHERE id IN (SELECT id FROM (SELECT id FROM annotation WHERE %s ORDER BY id DESC %s) a)` | ||||||||||||||||||||||||||
| sql := fmt.Sprintf(deleteQuery, annotationType, r.db.GetDialect().LimitOffset(r.cfg.AnnotationCleanupJobBatchSize, cfg.MaxCount)) | ||||||||||||||||||||||||||
| affected, err := r.executeUntilDoneOrCancelled(ctx, sql) | ||||||||||||||||||||||||||
| // Similar strategy as the above cleanup process, to avoid deadlocks. | ||||||||||||||||||||||||||
| affected, err := untilDoneOrCancelled(ctx, func() (int64, error) { | ||||||||||||||||||||||||||
| cond := fmt.Sprintf(`%s ORDER BY id DESC %s`, annotationType, r.db.GetDialect().LimitOffset(r.cfg.AnnotationCleanupJobBatchSize, cfg.MaxCount)) | ||||||||||||||||||||||||||
| ids, err := r.fetchIDs(ctx, "annotation", cond) | ||||||||||||||||||||||||||
| if err != nil { | ||||||||||||||||||||||||||
| return 0, err | ||||||||||||||||||||||||||
| } | ||||||||||||||||||||||||||
| r.log.Error("Annotations to clean by count", "count", len(ids), "ids", ids, "cond", cond, "err", err) | ||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||
| x, y := r.deleteByIDs(ctx, "annotation", ids) | ||||||||||||||||||||||||||
| r.log.Error("cleaned annotations by count", "count", len(ids), "affected", x, "err", y) | ||||||||||||||||||||||||||
|
Comment on lines
+554
to
+557
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Suggestion: In the max-count cleanup branch, the code again logs the entire slice of annotation IDs at error level for every batch, which can be tens of thousands of IDs and represents normal operation rather than an error; this will bloat logs and slow cleanup. Adjust the logging to only record counts/conditions at debug level and use error logging only when the delete operation actually fails. [performance] Severity Level: Major
|
||||||||||||||||||||||||||
| r.log.Error("Annotations to clean by count", "count", len(ids), "ids", ids, "cond", cond, "err", err) | |
| x, y := r.deleteByIDs(ctx, "annotation", ids) | |
| r.log.Error("cleaned annotations by count", "count", len(ids), "affected", x, "err", y) | |
| r.log.Debug("Annotations to clean by count", "count", len(ids), "cond", cond) | |
| x, y := r.deleteByIDs(ctx, "annotation", ids) | |
| if y != nil { | |
| r.log.Error("Failed to clean annotations by count", "count", len(ids), "err", y) | |
| } else { | |
| r.log.Debug("Cleaned annotations by count", "count", len(ids), "affected", x) | |
| } |
Steps of Reproduction ✅
1. Execute `TestIntegrationAnnotationCleanUp` in
`pkg/services/annotations/annotationsimpl/cleanup_test.go:18-149`, focusing on the test
case `"should only keep three annotations"` at lines 68-81, which configures `MaxCount=3`
in `settingsFn` and sets `annotationCleanupJobBatchSize` at line 71.
2. As in the test, `createTestAnnotations` (`cleanup_test.go:232-292`) inserts many
annotations, and `ProvideCleanupService` is used at `cleanup_test.go:131` to create a
`CleanupServiceImpl` backed by `xormRepositoryImpl`.
3. The call `cleaner.Run(context.Background(), test.cfg)` at `cleanup_test.go:132` invokes
`CleanupServiceImpl.Run` (`cleanup.go:35-57`), which, for this config, calls
`cs.store.CleanAnnotations` with `cfg.AlertingAnnotationCleanupSetting`,
`cfg.APIAnnotationCleanupSettings`, and `cfg.DashboardAnnotationCleanupSettings` where
`MaxCount > 0`, entering `xormRepositoryImpl.CleanAnnotations` at `xorm_store.go:519`.
4. In `CleanAnnotations`, the count-based branch at `xorm_store.go:546-564` executes
`untilDoneOrCancelled` with a batch callback at `xorm_store.go:548-559`; on each batch,
after `r.fetchIDs` at `xorm_store.go:550-553`, the logger at `xorm_store.go:554` logs
`"Annotations to clean by count"` at error level including the full `ids` slice and
condition, then after `r.deleteByIDs` at `xorm_store.go:556-557` another error-level
`"cleaned annotations by count"` log is emitted. With many annotations and small
`MaxCount`, multiple batches are processed, so normal operation produces many large
error-level log entries containing all IDs.Prompt for AI Agent 🤖
This is a comment left during a code review.
**Path:** pkg/services/annotations/annotationsimpl/xorm_store.go
**Line:** 554:557
**Comment:**
*Performance: In the max-count cleanup branch, the code again logs the entire slice of annotation IDs at error level for every batch, which can be tens of thousands of IDs and represents normal operation rather than an error; this will bloat logs and slow cleanup. Adjust the logging to only record counts/conditions at debug level and use error logging only when the delete operation actually fails.
Validate the correctness of the flagged issue. If correct, How can I resolve this? If you propose a fix, implement it and please make it concise.There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Suggestion: The orphaned-tag cleanup also logs the entire list of tag IDs at error level during normal operation, which for large batches can flood logs and slow the job without any actual error; it should instead log summary information at debug level and only emit error-level logs when the delete operation returns an error. This keeps logging proportional and prevents performance degradation from stringifying huge ID slices. [performance]
Severity Level: Major ⚠️
- ⚠️ Orphaned-tag cleanup logs large ID lists as errors.
- ⚠️ Normal tag maintenance floods logs with error entries.
- ⚠️ Tag-related failures harder to distinguish from noise.| r.log.Error("Tags to clean", "count", len(ids), "ids", ids, "cond", cond, "err", err) | |
| x, y := r.deleteByIDs(ctx, "annotation_tag", ids) | |
| r.log.Error("cleaned tags", "count", len(ids), "affected", x, "err", y) | |
| r.log.Debug("Tags to clean", "count", len(ids), "cond", cond) | |
| x, y := r.deleteByIDs(ctx, "annotation_tag", ids) | |
| if y != nil { | |
| r.log.Error("Failed to clean tags", "count", len(ids), "err", y) | |
| } else { | |
| r.log.Debug("Cleaned tags", "count", len(ids), "affected", x) | |
| } |
Steps of Reproduction ✅
1. Run `TestIntegrationAnnotationCleanUp` in
`pkg/services/annotations/annotationsimpl/cleanup_test.go:18-149` with any case where
annotations are actually deleted (e.g., `"should remove annotations created before cut off
point"` at lines 53-66 or `"should only keep three annotations"` at lines 68-81).
2. The test inserts annotations and corresponding tag rows via `createTestAnnotations`
(`cleanup_test.go:232-292`), then constructs a `CleanupServiceImpl` with
`ProvideCleanupService` (`cleanup_test.go:131`) and calls `cleaner.Run` at
`cleanup_test.go:132`.
3. In `CleanupServiceImpl.Run` (`cleanup.go:35-57`), after three calls to
`cs.store.CleanAnnotations` for different annotation types, if `totalCleanedAnnotations >
0` the code at `cleanup.go:54-56` calls `cs.store.CleanOrphanedAnnotationTags(ctx)`, which
dispatches to `xormRepositoryImpl.CleanOrphanedAnnotationTags` at `xorm_store.go:569`.
4. `CleanOrphanedAnnotationTags` uses `untilDoneOrCancelled` (`xorm_store.go:569-582`)
with a batch callback that builds `cond` at `xorm_store.go:571`, then calls `r.fetchIDs`
at `xorm_store.go:572-575`; for each batch, the logger at `xorm_store.go:576` logs `"Tags
to clean"` at error level including the entire `ids` slice and condition, followed by
another error-level `"cleaned tags"` log at `xorm_store.go:579` after `r.deleteByIDs`.
When many orphaned tags exist (e.g., as created in the integration test), this results in
multiple large error-level log entries during normal tag cleanup.Prompt for AI Agent 🤖
This is a comment left during a code review.
**Path:** pkg/services/annotations/annotationsimpl/xorm_store.go
**Line:** 576:579
**Comment:**
*Performance: The orphaned-tag cleanup also logs the entire list of tag IDs at error level during normal operation, which for large batches can flood logs and slow the job without any actual error; it should instead log summary information at debug level and only emit error-level logs when the delete operation returns an error. This keeps logging proportional and prevents performance degradation from stringifying huge ID slices.
Validate the correctness of the flagged issue. If correct, How can I resolve this? If you propose a fix, implement it and please make it concise.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Suggestion: In the time-based cleanup branch, every batch logs the full slice of annotation IDs at error level even on successful execution; with large batch sizes this can generate extremely large log entries and unnecessary error-level noise, impacting performance and log usability. The fix is to log only aggregate information (like counts and conditions), use debug-level for normal operation, and reserve error-level logging for actual errors from the delete call. [performance]
Severity Level: Major⚠️
Steps of Reproduction ✅
Prompt for AI Agent 🤖