Skip to content

Commit 75db0fa

Browse files
t-kikuct-kikuc
authored
Enhanced EventWatcher logs (#5558)
* Show push error log earlier than reporting Signed-off-by: t-kikuc <tkikuchi07f@gmail.com> * Use WarnLog in retry Signed-off-by: t-kikuc <tkikuchi07f@gmail.com> * clarify log messages Signed-off-by: t-kikuc <tkikuchi07f@gmail.com> * clarify log messages Signed-off-by: t-kikuc <tkikuchi07f@gmail.com> * add TestDoCalls for asserting counts Signed-off-by: t-kikuc <tkikuchi07f@gmail.com> * add eventIDs in log Signed-off-by: t-kikuc <tkikuchi07f@gmail.com> * enrich logs in updateValues Signed-off-by: t-kikuc <tkikuchi07f@gmail.com> * nits Signed-off-by: t-kikuc <tkikuchi07f@gmail.com> * Revert "add TestDoCalls for asserting counts" This reverts commit de3f112. Signed-off-by: t-kikuc <tkikuchi07f@gmail.com> --------- Signed-off-by: t-kikuc <tkikuchi07f@gmail.com>
1 parent f52a27b commit 75db0fa

File tree

1 file changed

+35
-10
lines changed

1 file changed

+35
-10
lines changed

‎pkg/app/piped/eventwatcher/eventwatcher.go‎

Lines changed: 35 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -183,7 +183,7 @@ func (w *watcher) run(ctx context.Context, repo git.Repo, repoCfg config.PipedRe
183183
case <-ticker.C:
184184
err := repo.Pull(ctx, repo.GetClonedBranch())
185185
if err != nil {
186-
w.logger.Error("failed to perform git pull",
186+
w.logger.Error("failed to perform git pull. will retry in the next loop",
187187
zap.String("repo-id", repoCfg.RepoID),
188188
zap.String("branch", repo.GetClonedBranch()),
189189
zap.Error(err),
@@ -233,6 +233,7 @@ func (w *watcher) run(ctx context.Context, repo git.Repo, repoCfg config.PipedRe
233233
if err := w.updateValues(ctx, repo, repoCfg.RepoID, cfg.Events, commitMsg); err != nil {
234234
w.logger.Error("failed to update the values",
235235
zap.String("repo-id", repoCfg.RepoID),
236+
zap.String("branch", repo.GetClonedBranch()),
236237
zap.Error(err),
237238
)
238239
}
@@ -294,6 +295,7 @@ func (w *watcher) run(ctx context.Context, repo git.Repo, repoCfg config.PipedRe
294295
if err := w.execute(ctx, repo, repoCfg.RepoID, cfgs); err != nil {
295296
w.logger.Error("failed to execute the event from application configuration",
296297
zap.String("repo-id", repoCfg.RepoID),
298+
zap.String("branch", repo.GetClonedBranch()),
297299
zap.Error(err),
298300
)
299301
}
@@ -456,28 +458,40 @@ func (w *watcher) execute(ctx context.Context, repo git.Repo, repoID string, eve
456458
var responseError error
457459
retry := backoff.NewRetry(retryPushNum, backoff.NewConstant(retryPushInterval))
458460
for branch, events := range branchHandledEvents {
461+
eventIDs := make([]string, 0, len(events))
462+
for _, e := range events {
463+
eventIDs = append(eventIDs, e.Id)
464+
}
465+
zlogger := w.logger.With(
466+
zap.String("repo-id", repoID),
467+
zap.String("branch", tmpRepo.GetClonedBranch()),
468+
zap.Strings("event-ids", eventIDs),
469+
)
470+
459471
_, err = retry.Do(ctx, func() (interface{}, error) {
460472
if err := tmpRepo.Push(ctx, branch); err != nil {
461-
w.logger.Error("failed to push commits", zap.String("repo-id", repoID), zap.String("branch", branch), zap.Error(err))
473+
zlogger.Warn(fmt.Sprintf("failed to push commits. retry attempt %d/%d", retry.Calls(), retryPushNum), zap.Error(err))
462474
return nil, err
463475
}
464476
return nil, nil
465477
})
466478

467479
if err == nil {
468480
if _, err := w.apiClient.ReportEventStatuses(ctx, &pipedservice.ReportEventStatusesRequest{Events: events}); err != nil {
469-
w.logger.Error("failed to report event statuses", zap.Error(err))
481+
zlogger.Error("failed to report event statuses", zap.Error(err))
470482
}
471483
w.executionMilestoneMap.Store(repoID, maxTimestamp)
472484
continue
473485
}
474486

475487
// If push fails because the local branch was not fresh, exit to retry again in the next interval.
476488
if err == git.ErrBranchNotFresh {
477-
w.logger.Warn("failed to push commits", zap.Error(err))
489+
zlogger.Warn("failed to push commits. local branch was not up-to-date. will retry in the next loop", zap.Error(err))
478490
continue
479491
}
480492

493+
zlogger.Error("failed to push commits", zap.Error(err))
494+
481495
// If push fails because of the other reason, re-set all statuses to FAILURE.
482496
for i := range events {
483497
if events[i].Status == model.EventStatus_EVENT_FAILURE {
@@ -487,7 +501,7 @@ func (w *watcher) execute(ctx context.Context, repo git.Repo, repoID string, eve
487501
events[i].StatusDescription = fmt.Sprintf("Failed to push changed files: %v", err)
488502
}
489503
if _, err := w.apiClient.ReportEventStatuses(ctx, &pipedservice.ReportEventStatusesRequest{Events: events}); err != nil {
490-
w.logger.Error("failed to report event statuses", zap.Error(err))
504+
zlogger.Error("failed to report event statuses", zap.Error(err))
491505
}
492506
w.executionMilestoneMap.Store(repoID, maxTimestamp)
493507
responseError = errors.Join(responseError, err)
@@ -600,17 +614,27 @@ func (w *watcher) updateValues(ctx context.Context, repo git.Repo, repoID string
600614
return nil
601615
}
602616

617+
eventIDs := make([]string, 0, len(handledEvents))
618+
for _, e := range handledEvents {
619+
eventIDs = append(eventIDs, e.Id)
620+
}
621+
zlogger := w.logger.With(
622+
zap.String("repo-id", repoID),
623+
zap.String("branch", tmpRepo.GetClonedBranch()),
624+
zap.Strings("event-ids", eventIDs),
625+
)
626+
603627
retry := backoff.NewRetry(retryPushNum, backoff.NewConstant(retryPushInterval))
604628
_, err = retry.Do(ctx, func() (interface{}, error) {
605629
if err := tmpRepo.Push(ctx, tmpRepo.GetClonedBranch()); err != nil {
606-
w.logger.Error("failed to push commits", zap.String("repo-id", repoID), zap.String("branch", tmpRepo.GetClonedBranch()), zap.Error(err))
630+
zlogger.Warn(fmt.Sprintf("failed to push commits. retry attempt %d/%d", retry.Calls(), retryPushNum), zap.Error(err))
607631
return nil, err
608632
}
609633
return nil, nil
610634
})
611635
if err == nil {
612636
if _, err := w.apiClient.ReportEventStatuses(ctx, &pipedservice.ReportEventStatusesRequest{Events: handledEvents}); err != nil {
613-
w.logger.Error("failed to report event statuses", zap.Error(err))
637+
zlogger.Error("failed to report event statuses", zap.Error(err))
614638
return err
615639
}
616640
w.milestoneMap.Store(repoID, maxTimestamp)
@@ -619,10 +643,12 @@ func (w *watcher) updateValues(ctx context.Context, repo git.Repo, repoID string
619643

620644
// If push fails because the local branch was not fresh, exit to retry again in the next interval.
621645
if err == git.ErrBranchNotFresh {
622-
w.logger.Warn("failed to push commits", zap.Error(err))
646+
zlogger.Warn("failed to push commits. local branch was not up-to-date. will retry in the next loop", zap.Error(err))
623647
return nil
624648
}
625649

650+
zlogger.Error("failed to push commits", zap.Error(err))
651+
626652
// If push fails because of the other reason, re-set all statuses to FAILURE.
627653
for i := range handledEvents {
628654
if handledEvents[i].Status == model.EventStatus_EVENT_FAILURE {
@@ -632,11 +658,10 @@ func (w *watcher) updateValues(ctx context.Context, repo git.Repo, repoID string
632658
handledEvents[i].StatusDescription = fmt.Sprintf("Failed to push changed files: %v", err)
633659
}
634660
if _, err := w.apiClient.ReportEventStatuses(ctx, &pipedservice.ReportEventStatusesRequest{Events: handledEvents}); err != nil {
635-
w.logger.Error("failed to report event statuses: %w", zap.Error(err))
661+
zlogger.Error("failed to report event statuses: %w", zap.Error(err))
636662
return err
637663
}
638664
w.milestoneMap.Store(repoID, maxTimestamp)
639-
w.logger.Error("failed to push commits", zap.Error(err))
640665
return err
641666
}
642667

0 commit comments

Comments
 (0)