Skip to content

feat(adapter): log time taken by controller to process webhook events - #2960

Open
zakisk wants to merge 1 commit into
tektoncd:mainfrom
zakisk:SRVKP-14040-add-time-taken-by-webhook
Open

feat(adapter): log time taken by controller to process webhook events#2960
zakisk wants to merge 1 commit into
tektoncd:mainfrom
zakisk:SRVKP-14040-add-time-taken-by-webhook

Conversation

@zakisk

@zakisk zakisk commented Sep 2, 2026

Copy link
Copy Markdown
Member

📝 Description of the Change

Log the duration from when a webhook request is received until the controller responds, and separately the async event processing time. The event ID is extracted from provider-specific headers (GitHub, GitLab, Gitea, Bitbucket Cloud/DC) for log correlation.

🔗 Linked GitHub Issue

Fixes #

https://redhat.atlassian.net/browse/SRVKP-14040

🧪 Testing Strategy

  • Unit tests
  • Integration tests
  • End-to-end tests
  • Manual testing
  • Not Applicable

🤖 AI Assistance

AI assistance can be used for various tasks, such as code generation,
documentation, or testing.

Please indicate whether you have used AI assistance
for this PR and provide details if applicable.

  • I have not used any AI assistance for this PR.
  • I have used AI assistance for this PR.

Important

Slop will be simply rejected, if you are using AI assistance you need to make sure you
understand the code generated and that it meets the project's standards. you
need at least know how to run the code and deploy it (if needed). See
startpaac to make it easy
to deploy and test your code changes.

If the majority of the code in this PR was generated by an AI, please add a Co-authored-by trailer to your commit message.
For example:

Co-authored-by: Claude noreply@anthropic.com

✅ Submitter Checklist

  • 📝 My commit messages are clear, informative, and follow the project's How to write a git commit message guide. The Gitlint linter ensures in CI it's properly validated
  • ✨ I have ensured my commit message prefix (e.g., fix:, feat:) matches the "Type of Change" I selected above.
  • ♽ I have run make test and make lint locally to check for and fix any
    issues. For an efficient workflow, I have considered installing
    pre-commit and running pre-commit install to
    automate these checks.
  • 📖 I have added or updated documentation for any user-facing changes.
  • 🧪 I have added sufficient unit tests for my code changes.
  • 🎁 I have added end-to-end tests where feasible. See README for more details.
  • 🔎 I have addressed any CI test flakiness or provided a clear reason to bypass it.
  • If adding a provider feature, I have filled in the following and updated the provider documentation:
    • GitHub App
    • GitHub Webhook
    • Gitea/Forgejo
    • GitLab
    • Bitbucket Cloud
    • Bitbucket Data Center

@pipelines-as-code

Copy link
Copy Markdown

Paco Review ⚠️

Paco: the Gemini/OpenCode backend exited with an error; check the PipelineRun logs.

Reviewed commit: df9cf21

@codecov

codecov Bot commented Sep 2, 2026

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 85.56%. Comparing base (acf9bce) to head (9fb1886).

Additional details and impacted files
@@            Coverage Diff             @@
##             main    #2960      +/-   ##
==========================================
- Coverage   85.56%   85.56%   -0.01%     
==========================================
  Files         164      164              
  Lines       12475    12494      +19     
==========================================
+ Hits        10674    10690      +16     
- Misses       1800     1803       +3     
  Partials        1        1              
Flag Coverage Δ
unit-tests 85.56% <100.00%> (-0.01%) ⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

Comment thread pkg/adapter/adapter_test.go Outdated
Comment thread pkg/adapter/adapter.go Outdated
@zakisk
zakisk force-pushed the SRVKP-14040-add-time-taken-by-webhook branch 2 times, most recently from f872888 to 610b13c Compare September 4, 2026 11:07

@chmouel chmouel left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the update — the flaky test assertion (comment 1) is fixed 👍

However the nil-logger panic (comment 2) is still present. The logger variable initialized at the top of handleEvent gets overwritten on lines 248/250:

gitProvider, logger, err = l.processIncoming(event, targettedRepo)
// or
gitProvider, logger, err = l.detectProvider(request, string(payload))

Both can return (nil, nil, err), which sets logger = nil. Then line 256 does logger.Infof(...) unconditionally → nil dereference panic.

Suggestion: introduce a separate variable for the event-scoped logger (e.g. eventLogger) at the top, and use a single defer for the timing log:

eventLogger := l.logger.With("event-id", eventID)
start := time.Now().UnixMilli()
defer func() {
    eventLogger.Infof("controller responded to event %s in %dms", eventID, time.Now().UnixMilli()-start)
}()

This way:

  1. The timing log is immune to logger being reassigned to nil by processIncoming/detectProvider
  2. You don't need to copy-paste the timing log at every return point (currently 8 times)

@theakshaypant theakshaypant left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Agree with Chmouel's comment, defer seems like a better option to calculate/log total time taken to process the event.

@zakisk
zakisk force-pushed the SRVKP-14040-add-time-taken-by-webhook branch from 610b13c to d0ccf1b Compare September 7, 2026 13:18
Log the duration from when a webhook request is received until the
controller responds, and separately the async event processing time.
The event ID is extracted from provider-specific headers (GitHub,
GitLab, Gitea, Bitbucket Cloud/DC) for log correlation.

https://redhat.atlassian.net/browse/SRVKP-14040

Signed-off-by: Zaki Shaikh <zashaikh@redhat.com>
@zakisk
zakisk force-pushed the SRVKP-14040-add-time-taken-by-webhook branch from d0ccf1b to 9fb1886 Compare September 8, 2026 09:26
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants