Parse external request id from request headers, and print it in access log by sillyguodong · Pull Request #22906 · go-gitea/gitea

sillyguodong · 2023-02-14T07:15:22Z

Configure in .ini file:

[log]
REQUEST_ID_HEADERS = X-Request-ID, X-Trace-Id

Params in Request Header

X-Trace-ID: trace-id-1q2w3e4r

Log output:

wxiaoguang · 2023-02-14T07:19:51Z

Maybe these headers could be added to access log, but not the routing log. Although in most cases you see the routing logs and treat them as access logs, but the routing logs are mainly for debug purpose, and are always subjected to be changed.

sillyguodong · 2023-02-14T07:27:29Z

Maybe these headers could be added to access log, but not the routing log. Although in most cases you see the routing logs and treat them as access logs, but the routing logs are mainly for debug purpose, and are always subjected to be changed.

I think you're right. i will put it into access log. thank you for your suggestion!

sillyguodong · 2023-02-14T09:32:20Z

Now, if user specify the location of the RequestID in ACCESS_LOG_TEMPLATE like this:

We can see it in access.log:

zeripath · 2023-02-14T14:24:04Z

linting is failing I'm afraid

sillyguodong · 2023-02-14T14:47:48Z

linting is failing I'm afraid

It should be ok now.

pboguslawski · 2023-02-14T15:32:31Z

BTW: chi router uses value from X-Request-ID request header as request ID instead of own generated request ID.

sillyguodong · 2023-02-14T16:06:51Z

BTW: chi router uses value from X-Request-ID request header as request ID instead of own generated request ID.

hi.
i don't find it that we use RequestID middleware in gitea's web router.
So, i think it won't be conflict?

pboguslawski · 2023-02-14T16:11:17Z

So, i think it won't be conflict?

Agree. Just pointed to chi solution in case gitea will need reqid in the future in other places also not just for logging (passing reqid with context sounds good).

techknowlogick · 2023-02-14T17:35:56Z

Thanks for this PR :)

I wonder if it should only accept overrides from the trusted reverse proxy setting to prevent an end user being able to set the request ID (same protections we have in place for accepting forwarded IPs)

pboguslawski · 2023-02-14T17:39:28Z

I wonder if it should only accept overrides from the trusted reverse proxy

Fetching reqid from header should be disabled by default and enabled only if admin knows what they are doing. Don't know giteas forwarded IPs protections and if they are suitable here.

wolfogre · 2023-02-15T02:28:50Z

... to prevent an end user being able to set the request ID ...

That's incorrect, unlike X-Forwarded-For, X-Request-ID is designed for an end user, they should be able to set it and use it to trace requests. It doesn't make sense if the ID has been overrided by reverse proxy.

However, you reminded me, we should have some protection, maybe length limitation is enough, to prevent printing a huge request id in log.

sillyguodong · 2023-02-15T05:48:30Z

now, if length of X-Request-ID (or other header) is more than 256 bits, the id will be printed like this:

pboguslawski · 2023-02-15T06:49:20Z

now, if length of X-Request-ID (or other header) is more than 256 bits, the id will be printed like this

Consider limiting to 36 or 40 bytes for UUID not to be truncated in logs.

pboguslawski · 2023-02-15T06:53:04Z

It doesn't make sense if the ID has been overrided by reverse proxy

It makes sense if someone wants to trace request flow between many internal systems and sets such header on front proxy (replacing any value provided by client).

wolfogre · 2023-02-16T02:48:17Z

It doesn't make sense if the ID has been overrided by reverse proxy

It makes sense if someone wants to trace request flow between many internal systems and sets such header on front proxy (replacing any value provided by client).

I understand, as you said, "only if admin knows what they are doing".

wxiaoguang · 2023-02-16T02:58:45Z

Fetching reqid from header should be disabled by default

It doesn't make sense if the ID has been overrided by reverse proxy

It makes sense if someone wants to trace request flow between many internal systems and sets such header on front proxy (replacing any value provided by client).

In this case, the header is always set by the front proxy, still no need to disable it if it doesn't come from "trusted-ip".

IMO this request header is just like host oruser-agent, it could just be passed as it is, and it can be set by reverse proxies, since it's not related to security logic (that's different from X-Real-Ip)

enabled only if admin knows what they are doing.

Admins could just use access logs without the RequestID field if they do not want to see or trust the RequestID.

At least, this header shouldn't be mixed with trusted reverse proxy which is dedicated for X-Real-Ip related headers.

lafriks · 2023-02-20T12:28:18Z

What about X-Correlation-Id and Correlation-Id?

wxiaoguang · 2023-02-20T12:34:38Z

+;; * E.g:
+;; * In reuqest Header:         X-Request-ID: test-id-123
+;; * Configuration in app.ini:  REQUEST_ID_HEADERS = X-Request-ID
+;; * Print in log:              127.0.0.1:58384 - - [14/Feb/2023:16:33:51 &#43;0800] "test-id-123"


Oh wait, the + should be +. There is no HTML, do not use HTML entity.

(And below, many +)

emmm...
It seems that template.Execute() escapes the + to the HTML entity.
I will try to fix it

Oh wait, the + should be +. There is no HTML, do not use HTML entity.

(And below, many +)

I solved the problem.
Use "text/template" instead of "html/template" and no escaping will occur~
But this PR have been passed, do I keep pushing on my own branch？

Sorry, I don't understand why you need text/template or html/template. Aren't these just some comments? Feel free to ignore my comment if that's done by purpose.

In the image, upper part is the output of "html/template", + is indeed escaped.
The comment in app.example.ini was copied from access.log directly. But I did not find this problem at the time.

This may be a previous bug? Need to create a new PR?

gitea/modules/context/access_log.go

Line 9 in 36d1d5f

"html/template"

gitea/modules/context/access_log.go

Line 30 in 36d1d5f

logTemplate, _ := template.New("log").Parse(setting.Log.AccessLogTemplate)

gitea/modules/context/access_log.go

Line 41 in 36d1d5f

err := logTemplate.Execute(buf, routerLoggerOptions{

The bug was introduced by #14475 . Before, it used text/template as my expectation. But #14475 used the incorrect html/template ...... since then, nobody ever found this bug because the logger is rarely used .....

This may be a previous bug? Need to create a new PR?

It depends. If I was the PR author, I would fix the bug together to save maintainer's time.

okey, I get it~thx

@sillyguodong Could you also merge #23013 into this PR?

sillyguodong · 2023-02-20T12:43:15Z

What about X-Correlation-Id and Correlation-Id?

Hi, you can configure it in app.ini file like this:
REQUEST_ID_HEADERS = X-Correlation-Id
The key of the specific request header can be fully customized...

Fix #22906 (comment)

Fix go-gitea#22906 (comment)

# Conflicts: # modules/context/access_log.go

Backport #23013 Fix #22906 (comment) Co-authored-by: Lunny Xiao <xiaolunwen@gmail.com>

…o-gitea#23025) Backport go-gitea#23013 Fix go-gitea#22906 (comment) Co-authored-by: Lunny Xiao <xiaolunwen@gmail.com> (cherry picked from commit 8fa62be)

wxiaoguang · 2023-03-09T20:28:14Z

+;; * E.g:
+;; * In reuqest Header:         X-Trace-ID: trace-id-1q2w3e4r
+;; * Configuration in app.ini:  REQUEST_ID_HEADERS = X-Request-ID, X-Trace-ID, X-Req-ID
+;; * Print in log:              127.0.0.1:58384 - - [14/Feb/2023:16:33:51 &#43;0800] "trace-id-1q2w3e4r"


The + should be fixed.

codecov-commenter · 2023-03-09T21:08:42Z

Codecov Report

Merging #22906 (29283b1) into main (e6df743) will decrease coverage by 0.03%.
The diff coverage is 5.88%.

❗ Current head 29283b1 differs from pull request most recent head b387a1e. Consider uploading reports for the commit b387a1e to get more accurate results

📣 This organization is not using Codecov’s GitHub App Integration. We recommend you install it so Codecov can continue to function properly for your repositories. Learn more

@@            Coverage Diff             @@
##             main   #22906      +/-   ##
==========================================
- Coverage   47.61%   47.58%   -0.03%     
==========================================
  Files        1147     1147              
  Lines      151196   151213      +17     
==========================================
- Hits        71985    71950      -35     
- Misses      70700    70761      +61     
+ Partials     8511     8502       -9

Impacted Files	Coverage Δ
modules/context/access_log.go	`0.00% <0.00%> (ø)`
modules/setting/log.go	`58.42% <100.00%> (+0.15%)`	⬆️

... and 11 files with indirect coverage changes

Help us with your feedback. Take ten seconds to tell us how you rate us. Have a feature suggestion? Share it here.

jolheiser · 2023-03-10T15:54:10Z

🎺 🤖

* giteaofficial/main: Scoped label display and documentation tweaks (go-gitea#23430) Deduplicate template code for label selection menu (go-gitea#23431) Show edit/close/delete button on organization wide repositories (go-gitea#23388) Sync the class change of Edit Column Button to JS code (go-gitea#23400) Preserve file size when creating attachments (go-gitea#23406) [skip ci] Updated translations via Crowdin Use buildkit for docker builds (go-gitea#23415) Refactor branch/tag selector dropdown (first step) (go-gitea#23394) [skip ci] Updated translations via Crowdin Hide target selector if tag exists when creating new release (go-gitea#23171) Parse external request id from request headers, and print it in access log (go-gitea#22906) Add missing tabs to org projects page (go-gitea#22705) Add user webhooks (go-gitea#21563) Handle OpenID discovery URL errors a little nicer when creating/editing sources (go-gitea#23397) Split CI pipelines (go-gitea#23385)

sillyguodong added 3 commits February 14, 2023 11:53

log reuqest id that parsed from request header

3ef5609

fix

e23a9f6

update example and config cheat sheet

bca651f

GiteaBot added the lgtm/need 2 This PR needs two approvals by maintainers to be considered for merging. label Feb 14, 2023

sillyguodong changed the title ~~Parse external request id from request headers, and print it in router log~~ Parse external request id from request headers, and print it in access log Feb 14, 2023

wolfogre reviewed Feb 14, 2023

View reviewed changes

Comment thread docs/content/doc/advanced/config-cheat-sheet.en-us.md Outdated

Comment thread docs/content/doc/advanced/config-cheat-sheet.zh-cn.md

put request id into access log

68ae309

delete useless character

248ca3c

fix lint

f15ce89

set the maximum length of request id to 256 bits

e040fa8

sillyguodong added 4 commits February 15, 2023 15:10

fix markdown

55c2779

lint markdown

c5a5442

set maxRequestIDBtyeLength to 40

ec0d6c0

fix comment misspelling

0c47e3f

wxiaoguang reviewed Feb 20, 2023

View reviewed changes

lunny mentioned this pull request Feb 20, 2023

Render access log template as text instead of HTML #23013

Merged

lunny closed this in #23013 Feb 21, 2023

lunny added a commit that referenced this pull request Feb 21, 2023

Render access log template as text instead of HTML (#23013)

34ae184

Fix #22906 (comment)

yardenshoham mentioned this pull request Feb 21, 2023

Render access log template as text instead of HTML (#23013) #23025

Merged

yardenshoham pushed a commit to yardenshoham/gitea that referenced this pull request Feb 21, 2023

Render access log template as text instead of HTML (go-gitea#23013)

0de6167

Fix go-gitea#22906 (comment)

sillyguodong added 2 commits February 21, 2023 10:25

fix example

fc843f0

Merge branch 'main' into feature/issue_22890

37d578c

# Conflicts: # modules/context/access_log.go

wolfogre reopened this Feb 21, 2023

lunny added a commit that referenced this pull request Feb 21, 2023

Render access log template as text instead of HTML (#23013) (#23025)

8fa62be

Backport #23013 Fix #22906 (comment) Co-authored-by: Lunny Xiao <xiaolunwen@gmail.com>

lunny added the reviewed/wait-merge This pull request is part of the merge queue. It will be merged soon. label Mar 9, 2023

lunny and others added 3 commits March 9, 2023 10:49

Merge branch 'main' into feature/issue_22890

16d2d01

Merge branch 'main' into feature/issue_22890

031f83e

Merge branch 'main' into feature/issue_22890

29283b1

zeripath reviewed Mar 9, 2023

View reviewed changes

Comment thread custom/conf/app.example.ini Outdated

wxiaoguang reviewed Mar 9, 2023

View reviewed changes

Update custom/conf/app.example.ini

b387a1e

sillyguodong and others added 2 commits March 10, 2023 09:39

fix eample

f231c64

Merge branch 'main' into feature/issue_22890

a812d1d

jolheiser merged commit 5155ec3 into go-gitea:main Mar 10, 2023

jolheiser removed the reviewed/wait-merge This pull request is part of the merge queue. It will be merged soon. label Mar 10, 2023

go-gitea locked and limited conversation to collaborators May 3, 2023

sillyguodong deleted the feature/issue_22890 branch February 29, 2024 03:31

Uh oh!

Conversation

sillyguodong commented Feb 14, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Configure in .ini file:

Params in Request Header

Log output:

Uh oh!

wxiaoguang commented Feb 14, 2023

Uh oh!

sillyguodong commented Feb 14, 2023

Uh oh!

Uh oh!

Uh oh!

sillyguodong commented Feb 14, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

zeripath commented Feb 14, 2023

Uh oh!

sillyguodong commented Feb 14, 2023

Uh oh!

pboguslawski commented Feb 14, 2023

Uh oh!

sillyguodong commented Feb 14, 2023

Uh oh!

pboguslawski commented Feb 14, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

techknowlogick commented Feb 14, 2023

Uh oh!

pboguslawski commented Feb 14, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

wolfogre commented Feb 15, 2023

Uh oh!

sillyguodong commented Feb 15, 2023

Uh oh!

pboguslawski commented Feb 15, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

pboguslawski commented Feb 15, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

wolfogre commented Feb 16, 2023

Uh oh!

wxiaoguang commented Feb 16, 2023

Uh oh!

lafriks commented Feb 20, 2023

Uh oh!

wxiaoguang Feb 20, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

sillyguodong commented Feb 20, 2023

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

codecov-commenter commented Mar 9, 2023

Codecov Report

Uh oh!

jolheiser commented Mar 10, 2023

sillyguodong commented Feb 14, 2023 •

edited

Loading

sillyguodong commented Feb 14, 2023 •

edited

Loading

pboguslawski commented Feb 14, 2023 •

edited

Loading

pboguslawski commented Feb 14, 2023 •

edited

Loading

pboguslawski commented Feb 15, 2023 •

edited

Loading

pboguslawski commented Feb 15, 2023 •

edited

Loading

wxiaoguang Feb 20, 2023 •

edited

Loading