From 294b0007ef2a856d4e00a1b01db221800c734660 Mon Sep 17 00:00:00 2001 From: Phil Date: Thu, 1 Feb 2024 07:55:00 -0500 Subject: [PATCH 1/3] gazctl shards prune: fail fast instead of pruning unpersisted fragments If someone accidentally runs `shards prune` with a selector that doesn't include all the shards that use a forked recovery log, it's possible for it to try to prune the current fragment for a journal. This adds a check for that condition so that we can provide visibility and stop the prune operation. Attempting to prune an unpersisted fragment would fail anyway, but this at least gives a clearer error message. --- cmd/gazctl/gazctlcmd/shards_prune.go | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/cmd/gazctl/gazctlcmd/shards_prune.go b/cmd/gazctl/gazctlcmd/shards_prune.go index 20910640..516a362f 100644 --- a/cmd/gazctl/gazctlcmd/shards_prune.go +++ b/cmd/gazctl/gazctlcmd/shards_prune.go @@ -102,6 +102,17 @@ func (cmd *cmdShardsPrune) Execute([]string) error { metrics.bytesTotal += spec.ContentLength() if !overlapsAnySegment(segments, spec) { + if spec.ModTime == 0 { + // This shouldn't ever happen, as long as the label selector covers all shards that are using + // each journal. But we don't validate that up front, so failing fast is the next best thing. + log.WithFields(log.Fields{ + "journal": spec.Journal, + "name": spec.ContentName(), + "begin": spec.Begin, + "end": spec.End, + "hintedSegments": segments, + }).Fatal("unpersisted fragment does not overlap any hinted segments (the label selector argument does not include all shards using this log)") + } log.WithFields(log.Fields{ "log": spec.Journal, "name": spec.ContentName(), From 1e7563d652716af134b2ca026f39ea770adc412e Mon Sep 17 00:00:00 2001 From: Phil Date: Mon, 5 Feb 2024 17:54:25 -0500 Subject: [PATCH 2/3] gazctl shards prune: improve audit logging Adds a lot more information to the logs when fragments are deleted. The intent is to run with JSON logs, to enable automated audits and analysis of prune operations. Because we're logging out so much more information as part of the logs, I also turned down the log level on some of the other messages. I also added in some additional warning logs for conditions that should never be encountered. --- cmd/gazctl/gazctlcmd/shards_prune.go | 36 ++++++++++++++++++++++------ 1 file changed, 29 insertions(+), 7 deletions(-) diff --git a/cmd/gazctl/gazctlcmd/shards_prune.go b/cmd/gazctl/gazctlcmd/shards_prune.go index 516a362f..751357f1 100644 --- a/cmd/gazctl/gazctlcmd/shards_prune.go +++ b/cmd/gazctl/gazctlcmd/shards_prune.go @@ -49,6 +49,8 @@ func (cmd *cmdShardsPrune) Execute([]string) error { var metrics = shardsPruneMetrics{} var logSegmentSets = make(map[pb.Journal][]recoverylog.Segment) var skipRecoveryLogs = make(map[pb.Journal]bool) + // Retain the raw hints responses, so that we can log them if they're used to prune fragments + var rawHintsResponses = make(map[pb.Journal][]pc.GetHintsResponse) for _, shard := range listShards(rsc, cmd.Selector).Shards { metrics.shardsTotal++ @@ -59,6 +61,7 @@ func (cmd *cmdShardsPrune) Execute([]string) error { mbp.Must(err, "failed to fetch hints") var recoveryLog = shard.Spec.RecoveryLog() + rawHintsResponses[recoveryLog] = append(rawHintsResponses[recoveryLog], *allHints) for _, curHints := range append(allHints.BackupHints, allHints.PrimaryHints) { var hints = curHints.Hints @@ -82,7 +85,7 @@ func (cmd *cmdShardsPrune) Execute([]string) error { "shard": shard.Spec.Id, "reason": reason, "journal": recoveryLog, - }).Warn("will skip pruning recovery log journal") + }).Debug("will skip pruning recovery log journal") break } @@ -91,10 +94,11 @@ func (cmd *cmdShardsPrune) Execute([]string) error { for journal, segments := range logSegmentSets { if skipRecoveryLogs[journal] { - log.WithField("journal", journal).Warn("skipping journal because another shard is missing hints that cover it") + log.WithField("journal", journal).Warn("skipping journal because a shard is missing hints that cover it") continue } log.WithField("journal", journal).Debug("checking fragments of journal") + var prunedFragments []pb.Fragment for _, f := range fetchFragments(ctx, rjc, journal) { var spec = f.Spec @@ -114,23 +118,35 @@ func (cmd *cmdShardsPrune) Execute([]string) error { }).Fatal("unpersisted fragment does not overlap any hinted segments (the label selector argument does not include all shards using this log)") } log.WithFields(log.Fields{ - "log": spec.Journal, - "name": spec.ContentName(), - "size": spec.ContentLength(), - "mod": spec.ModTime, - }).Info("pruning fragment") + "log": spec.Journal, + "name": spec.ContentName(), + "size": spec.ContentLength(), + "mod": spec.ModTime, + "begin": spec.Begin, + "end": spec.End, + }).Debug("pruning fragment") metrics.fragmentsPruned++ metrics.bytesPruned += spec.ContentLength() + prunedFragments = append(prunedFragments, spec) if !cmd.DryRun { mbp.Must(fragment.Remove(ctx, spec), "error removing fragment", "path", spec.ContentPath()) } } } + if len(prunedFragments) > 0 { + log.WithFields(log.Fields{ + "journal": journal, + "allHints": rawHintsResponses[journal], + "liveSegments": segments, + "prunedFragments": prunedFragments, + }).Info("pruned fragments") + } logShardsPruneMetrics(metrics, journal.String(), "finished pruning log") } logShardsPruneMetrics(metrics, "", "finished pruning logs for all shards") + return nil } @@ -141,6 +157,12 @@ func overlapsAnySegment(segments []recoverylog.Segment, fragment pb.Fragment) bo return true } } + if len(segments) == 0 { + log.WithFields(log.Fields{ + "log": fragment.Journal, + }).Warn("no live segments for log") + return true + } return false } From 076038b3a5925a43df2ca6cdfc2207b8f8ff7737 Mon Sep 17 00:00:00 2001 From: Phil Date: Tue, 6 Feb 2024 07:11:48 -0500 Subject: [PATCH 3/3] gazctl shards prune: continue pruning after failure to delete fragments This allows recovery log pruning to continue after encountering an error removing a fragment. We now operate Gazette clusters that use a variety of different storage buckets, and it seems unavoidable that some of them might have permissions misconfigured or return an error for some other reason. In that case, we'll now log a warning and continue the prune operation. Gazctl will still exit non-zero if it has encountered any errors removing fragments, to ensure it never fails silently. --- cmd/gazctl/gazctlcmd/shards_prune.go | 24 +++++++++++++++++++----- 1 file changed, 19 insertions(+), 5 deletions(-) diff --git a/cmd/gazctl/gazctlcmd/shards_prune.go b/cmd/gazctl/gazctlcmd/shards_prune.go index 751357f1..beb0ba7c 100644 --- a/cmd/gazctl/gazctlcmd/shards_prune.go +++ b/cmd/gazctl/gazctlcmd/shards_prune.go @@ -126,12 +126,21 @@ func (cmd *cmdShardsPrune) Execute([]string) error { "end": spec.End, }).Debug("pruning fragment") - metrics.fragmentsPruned++ - metrics.bytesPruned += spec.ContentLength() - prunedFragments = append(prunedFragments, spec) - + var removed = true if !cmd.DryRun { - mbp.Must(fragment.Remove(ctx, spec), "error removing fragment", "path", spec.ContentPath()) + if err := fragment.Remove(ctx, spec); err != nil { + removed = false + metrics.failedToRemove++ + log.WithFields(log.Fields{ + "fragment": spec, + "error": err, + }).Warn("failed to remove fragment (skipping)") + } + } + if removed { + metrics.fragmentsPruned++ + metrics.bytesPruned += spec.ContentLength() + prunedFragments = append(prunedFragments, spec) } } } @@ -147,6 +156,9 @@ func (cmd *cmdShardsPrune) Execute([]string) error { } logShardsPruneMetrics(metrics, "", "finished pruning logs for all shards") + if metrics.failedToRemove > 0 { + log.WithField("failures", metrics.failedToRemove).Fatal("failed to remove fragments") + } return nil } @@ -203,6 +215,7 @@ type shardsPruneMetrics struct { bytesTotal int64 bytesPruned int64 skippedJournals int64 + failedToRemove int64 } func logShardsPruneMetrics(m shardsPruneMetrics, journal, message string) { @@ -215,6 +228,7 @@ func logShardsPruneMetrics(m shardsPruneMetrics, journal, message string) { "bytesPruned": m.bytesPruned, "bytesKept": m.bytesTotal - m.bytesPruned, "skippedJournals": m.skippedJournals, + "failedToRemove": m.failedToRemove, } if journal != "" { fields["journal"] = journal