tka: improve logging for Compact and Commit operations

Log whenever we:

* Commit an AUM which was previously soft-deleted (which we don't expect
  to happen in practice, and may indicate an issue with our sync code)
* Purge AUMs during a Compact operation.
* Successfully commit AUMs as part of a bootstrap or sync operation.

All three logs mention `tka` for easy of discoverability.

Updates tailscale/corp#39455

Change-Id: I2b07bb0ef075877f40ec34b80bb668be59e1cdc3
Signed-off-by: Alex Chan <alexc@tailscale.com>
main
Alex Chan 2 weeks ago committed by Alex Chan
parent ec0b23a21f
commit b25920dfc0
  1. 6
      tka/tailchonk.go
  2. 7
      tka/tka.go

@ -597,6 +597,9 @@ func (c *FS) CommitVerifiedAUMs(updates []AUM) error {
for i, aum := range updates { for i, aum := range updates {
h := aum.Hash() h := aum.Hash()
err := c.commit(h, func(info *fsHashInfo) { err := c.commit(h, func(info *fsHashInfo) {
if info.PurgedUnix > 0 {
log.Printf("tka: CommitVerifiedAUMs: committing previously-deleted AUM %s", h.String())
}
info.PurgedUnix = 0 // just in-case it was set for some reason info.PurgedUnix = 0 // just in-case it was set for some reason
info.AUM = &aum info.AUM = &aum
}) })
@ -973,5 +976,8 @@ func Compact(storage CompactableChonk, head AUMHash, opts CompactionOptions) (la
if err := storage.SetLastActiveAncestor(lastActiveAncestor); err != nil { if err := storage.SetLastActiveAncestor(lastActiveAncestor); err != nil {
return AUMHash{}, err return AUMHash{}, err
} }
if len(toDelete) > 0 {
log.Printf("tka compaction: purging %d AUM(s) [%q]", len(toDelete), toDelete)
}
return lastActiveAncestor, storage.PurgeAUMs(toDelete) return lastActiveAncestor, storage.PurgeAUMs(toDelete)
} }

@ -10,6 +10,7 @@ import (
"bytes" "bytes"
"errors" "errors"
"fmt" "fmt"
"log"
"os" "os"
"sort" "sort"
@ -556,6 +557,8 @@ func Bootstrap(storage Chonk, bootstrap AUM) (*Authority, error) {
// Everything looks good, write it to storage. // Everything looks good, write it to storage.
if err := storage.CommitVerifiedAUMs([]AUM{bootstrap}); err != nil { if err := storage.CommitVerifiedAUMs([]AUM{bootstrap}); err != nil {
return nil, fmt.Errorf("commit: %v", err) return nil, fmt.Errorf("commit: %v", err)
} else {
log.Printf("tka.Bootstrap: successfully committed bootstrap AUM (%s)", bootstrap.Hash())
} }
if err := storage.SetLastActiveAncestor(bootstrap.Hash()); err != nil { if err := storage.SetLastActiveAncestor(bootstrap.Hash()); err != nil {
return nil, fmt.Errorf("set ancestor: %v", err) return nil, fmt.Errorf("set ancestor: %v", err)
@ -587,6 +590,7 @@ func (a *Authority) InformIdempotent(storage Chonk, updates []AUM) (Authority, e
} }
stateAt := make(map[AUMHash]State, len(updates)+1) stateAt := make(map[AUMHash]State, len(updates)+1)
toCommit := make([]AUM, 0, len(updates)) toCommit := make([]AUM, 0, len(updates))
toCommitHashes := make([]AUMHash, 0, len(updates))
prevHash := a.Head() prevHash := a.Head()
// The state at HEAD is the current state of the authority. It's likely // The state at HEAD is the current state of the authority. It's likely
@ -636,10 +640,13 @@ func (a *Authority) InformIdempotent(storage Chonk, updates []AUM) (Authority, e
} }
prevHash = hash prevHash = hash
toCommit = append(toCommit, update) toCommit = append(toCommit, update)
toCommitHashes = append(toCommitHashes, update.Hash())
} }
if err := storage.CommitVerifiedAUMs(toCommit); err != nil { if err := storage.CommitVerifiedAUMs(toCommit); err != nil {
return Authority{}, fmt.Errorf("commit: %v", err) return Authority{}, fmt.Errorf("commit: %v", err)
} else {
log.Printf("tka.CommitVerifiedAUMs: successfully committed %d AUMs: %v", len(toCommit), toCommitHashes)
} }
if isHeadChain { if isHeadChain {

Loading…
Cancel
Save