chore: improve log messages

This commit is contained in:
garethgeorge
2024-04-08 00:28:41 -07:00
parent 1d0489847e
commit 4b2763cdbb
9 changed files with 38 additions and 36 deletions
+15 -15
View File
@@ -37,11 +37,11 @@ func main() {
resticPath, err := resticinstaller.FindOrInstallResticBinary()
if err != nil {
zap.S().Fatalf("Error finding or installing restic: %v", err)
zap.S().Fatalf("error finding or installing restic: %v", err)
}
if *InstallDepsOnly {
zap.S().Info("Dependencies installed, exiting")
zap.S().Info("dependencies installed, exiting")
return
}
@@ -52,7 +52,7 @@ func main() {
configStore := createConfigProvider()
cfg, err := configStore.Get()
if err != nil {
zap.S().Fatalf("Error loading config: %v", err)
zap.S().Fatalf("error loading config: %v", err)
}
// Create the authenticator
@@ -65,23 +65,23 @@ func main() {
oplog, err := oplog.NewOpLog(oplogFile)
if err != nil {
if !errors.Is(err, bbolt.ErrTimeout) {
zap.S().Fatalf("Timeout while waiting to open database, is the database open elsewhere?")
zap.S().Fatalf("timeout while waiting to open database, is the database open elsewhere?")
}
zap.S().Warnf("Operation log may be corrupted, if errors recur delete the file %q and restart. Your backups stored in your repos are safe.", oplogFile)
zap.S().Fatalf("Error creating oplog : %v", err)
zap.S().Warnf("operation log may be corrupted, if errors recur delete the file %q and restart. Your backups stored in your repos are safe.", oplogFile)
zap.S().Fatalf("error creating oplog : %v", err)
}
defer oplog.Close()
// Create rotating log storage
logStore := rotatinglog.NewRotatingLog(path.Join(config.DataDir(), "rotatinglogs"), 30) // 30 days of logs
if err != nil {
zap.S().Fatalf("Error creating rotating log storage: %v", err)
zap.S().Fatalf("error creating rotating log storage: %v", err)
}
// Create orchestrator and start task loop.
orchestrator, err := orchestrator.NewOrchestrator(resticPath, cfg, oplog, logStore)
if err != nil {
zap.S().Fatalf("Error creating orchestrator: %v", err)
zap.S().Fatalf("error creating orchestrator: %v", err)
}
wg.Add(1)
@@ -112,13 +112,13 @@ func main() {
Handler: h2c.NewHandler(mux, &http2.Server{}), // h2c is HTTP/2 without TLS for grpc-connect support.
}
zap.S().Infof("Starting web server %v", server.Addr)
zap.S().Infof("starting web server %v", server.Addr)
go func() {
<-ctx.Done()
server.Shutdown(context.Background())
}()
if err := server.ListenAndServe(); !errors.Is(err, http.ErrServerClosed) {
zap.L().Error("Error starting server", zap.Error(err))
zap.L().Error("error starting server", zap.Error(err))
}
zap.L().Info("HTTP gateway shutdown")
@@ -157,20 +157,20 @@ func getSecret() []byte {
secretFile := path.Join(config.DataDir(), "jwt-secret")
data, err := os.ReadFile(secretFile)
if err == nil {
zap.L().Debug("Loaded auth secret from file")
zap.L().Debug("loading auth secret from file")
return data
}
zap.L().Info("Generating new auth secret")
zap.L().Info("generating new auth secret")
secret := make([]byte, 64)
if n, err := rand.Read(secret); err != nil || n != 64 {
zap.S().Fatalf("Error generating secret: %v", err)
zap.S().Fatalf("error generating secret: %v", err)
}
if err := os.MkdirAll(config.DataDir(), 0700); err != nil {
zap.S().Fatalf("Error creating data directory: %v", err)
zap.S().Fatalf("error creating data directory: %v", err)
}
if err := os.WriteFile(secretFile, secret, 0600); err != nil {
zap.S().Fatalf("Error writing secret to file: %v", err)
zap.S().Fatalf("error writing secret to file: %v", err)
}
return secret
}
+4 -4
View File
@@ -117,19 +117,19 @@ func (s *BackrestHandler) AddRepo(ctx context.Context, req *connect.Request[v1.R
return nil, fmt.Errorf("failed to init repo: %w", err)
}
zap.L().Debug("Updating config")
zap.L().Debug("updating config", zap.Int32("version", c.Version))
if err := s.config.Update(c); err != nil {
return nil, fmt.Errorf("failed to update config: %w", err)
}
zap.L().Debug("Applying config")
zap.L().Debug("applying config", zap.Int32("version", c.Version))
s.orchestrator.ApplyConfig(c)
// index snapshots for the newly added repository.
zap.L().Debug("Scheduling index snapshots task")
zap.L().Debug("scheduling index snapshots task")
s.orchestrator.ScheduleTask(orchestrator.NewOneoffIndexSnapshotsTask(s.orchestrator, req.Msg.Id, time.Now()), orchestrator.TaskPriorityInteractive+orchestrator.TaskPriorityIndexSnapshots)
zap.L().Debug("Done add repo")
zap.L().Debug("done add repo")
return connect.NewResponse(c), nil
}
+1 -1
View File
@@ -70,7 +70,7 @@ func (c *CachingValidatingStore) Get() (*v1.Config, error) {
// Check if we need to migrate
if config.Version < migrations.CurrentVersion {
zap.S().Infof("Migrating config from version %d to %d", config.Version, migrations.CurrentVersion)
zap.S().Infof("migrating config from version %d to %d", config.Version, migrations.CurrentVersion)
if err := migrations.ApplyMigrations(config); err != nil {
return nil, err
}
+2 -2
View File
@@ -62,7 +62,7 @@ func (e *HookExecutor) ExecuteHooks(repo *v1.Repo, plan *v1.Plan, snapshotId str
Name: name,
},
}
zap.L().Info("Running hook", zap.String("plan", plan.Id), zap.Int64("opId", operation.Id), zap.String("hook", name))
zap.L().Info("running hook", zap.String("plan", plan.Id), zap.Int64("opId", operation.Id), zap.String("hook", name))
e.executeHook(operation, h, event, vars)
}
@@ -81,7 +81,7 @@ func (e *HookExecutor) ExecuteHooks(repo *v1.Repo, plan *v1.Plan, snapshotId str
Name: name,
},
}
zap.L().Info("Running hook", zap.String("plan", plan.Id), zap.Int64("opId", operation.Id), zap.String("hook", name))
zap.L().Info("running hook", zap.String("plan", plan.Id), zap.Int64("opId", operation.Id), zap.String("hook", name))
e.executeHook(operation, h, event, vars)
}
}
+7 -7
View File
@@ -182,7 +182,7 @@ func (r *RepoOrchestrator) Forget(ctx context.Context, plan *v1.Plan) ([]*v1.Res
forgotten = append(forgotten, snapshotProto)
}
zap.L().Debug("Forgot snapshots", zap.String("plan", plan.Id), zap.Int("count", len(forgotten)), zap.Any("policy", policy))
zap.L().Debug("forget snapshots", zap.String("plan", plan.Id), zap.Int("count", len(forgotten)), zap.Any("policy", policy))
return forgotten, nil
}
@@ -191,7 +191,7 @@ func (r *RepoOrchestrator) ForgetSnapshot(ctx context.Context, snapshotId string
r.mu.Lock()
defer r.mu.Unlock()
r.l.Debug("Forget snapshot with ID", zap.String("snapshot", snapshotId))
r.l.Debug("forget snapshot with ID", zap.String("snapshot", snapshotId), zap.String("repo", r.repoConfig.Id))
return r.repo.ForgetSnapshot(ctx, snapshotId)
}
@@ -213,7 +213,7 @@ func (r *RepoOrchestrator) Prune(ctx context.Context, output io.Writer) error {
opts = append(opts, restic.WithFlags("--max-unused", fmt.Sprintf("%v%%", policy.MaxUnusedPercent)))
}
r.l.Debug("Prune snapshots")
r.l.Debug("prune snapshots")
err := r.repo.Prune(ctx, output, opts...)
if err != nil {
return fmt.Errorf("prune snapshots for repo %v: %w", r.repoConfig.Id, err)
@@ -225,7 +225,7 @@ func (r *RepoOrchestrator) Restore(ctx context.Context, snapshotId string, path
r.mu.Lock()
defer r.mu.Unlock()
r.l.Debug("Restore snapshot", zap.String("snapshot", snapshotId), zap.String("target", target))
r.l.Debug("restore snapshot", zap.String("snapshot", snapshotId), zap.String("target", target))
var opts []restic.GenericOption
opts = append(opts, restic.WithFlags("--target", target))
@@ -254,7 +254,7 @@ func (r *RepoOrchestrator) UnlockIfAutoEnabled(ctx context.Context) error {
r.mu.Lock()
defer r.mu.Unlock()
zap.L().Debug("AutoUnlocking repo", zap.String("repo", r.repoConfig.Id))
zap.L().Debug("auto-unlocking repo", zap.String("repo", r.repoConfig.Id))
return r.repo.Unlock(ctx)
}
@@ -263,7 +263,7 @@ func (r *RepoOrchestrator) Unlock(ctx context.Context) error {
r.mu.Lock()
defer r.mu.Unlock()
r.l.Debug("Unlocking repo")
r.l.Debug("unlocking repo", zap.String("repo", r.repoConfig.Id))
r.repo.Unlock(ctx)
return nil
@@ -273,7 +273,7 @@ func (r *RepoOrchestrator) Stats(ctx context.Context) (*v1.RepoStats, error) {
r.mu.Lock()
defer r.mu.Unlock()
r.l.Debug("Get Stats")
r.l.Debug("getting repo stats", zap.String("repo", r.repoConfig.Id))
stats, err := r.repo.Stats(ctx)
if err != nil {
return nil, fmt.Errorf("stats for repo %v: %w", r.repoConfig.Id, err)
+1 -1
View File
@@ -73,7 +73,7 @@ func (t *TaskWithOperation) runWithOpAndContext(ctx context.Context, do func(ctx
errors.Join(err, fmt.Errorf("failed to write log to logstore: %w", e))
}
t.op.Logref = ref
zap.S().Debug("wrote operation log to %v", ref)
zap.S().Debugf("wrote operation log to %v", ref)
}
return err
+2 -2
View File
@@ -145,7 +145,7 @@ func indexSnapshotsHelper(ctx context.Context, orchestrator *Orchestrator, repoI
}
// Print stats at the end of indexing.
zap.L().Debug("Indexed snapshots",
zap.L().Debug("indexed snapshots",
zap.String("repo", repoId),
zap.Duration("duration", time.Since(startTime)),
zap.Int("alreadyIndexed", len(foundIds)),
@@ -174,7 +174,7 @@ func indexCurrentSnapshotIdsForRepo(log *oplog.OpLog, repoId string) (map[string
}); err != nil {
return nil, err
}
zap.S().Debugf("Indexed known (and not forgotten) snapshot IDs for plan %v in %v", repoId, time.Since(startTime))
zap.S().Debugf("indexed known snapshot IDs for repo %v in %v", repoId, time.Since(startTime))
return knownIds, nil
}
+2
View File
@@ -8,6 +8,7 @@ import (
// TestTPQEnqueue tests that enqueued elements are retruned highest priority first.
func TestTPQPriority(t *testing.T) {
t.Parallel()
tpq := NewTimePriorityQueue[int]()
now := time.Now().Add(-time.Second)
@@ -28,6 +29,7 @@ func TestTPQPriority(t *testing.T) {
}
func TestTPQMixedReadinessStates(t *testing.T) {
t.Parallel()
tpq := NewTimePriorityQueue[int]()
now := time.Now()
+4 -4
View File
@@ -123,13 +123,13 @@ func downloadFile(url string, downloadPath string) (string, error) {
hash := sha256.Sum256(body)
if strings.HasSuffix(url, ".bz2") {
zap.S().Infof("Decompressing bz2 archive (size=%v)...", len(body))
zap.S().Infof("decompressing bz2 archive (size=%v)...", len(body))
body, err = io.ReadAll(bzip2.NewReader(bytes.NewReader(body)))
if err != nil {
return "", fmt.Errorf("bz2 decompress body: %w", err)
}
} else if strings.HasSuffix(url, ".zip") {
zap.S().Infof("Decompressing zip archive (size=%v)...", len(body))
zap.S().Infof("decompressing zip archive (size=%v)...", len(body))
archive, err := zip.NewReader(bytes.NewReader(body), int64(len(body)))
if err != nil {
@@ -262,11 +262,11 @@ func FindOrInstallResticBinary() (string, error) {
}
didTryInstall = true
zap.S().Infof("Installing restic %v to %v...", resticInstallPath, RequiredResticVersion)
zap.S().Infof("installing restic %v to %v...", resticInstallPath, RequiredResticVersion)
if err := installResticIfNotExists(resticInstallPath); err != nil {
return "", fmt.Errorf("install restic: %w", err)
}
zap.S().Infof("Installed restic %v", RequiredResticVersion)
zap.S().Infof("installed restic %v", RequiredResticVersion)
removeOldVersions(path.Dir(resticInstallPath))
}