github-starred/gitea
2
0
Fork 0
mirror of https://github.com/go-gitea/gitea.git synced 2026-03-22 14:34:54 -05:00
Code Issues 2.6k Packages Projects Releases 100 Wiki Activity

Index page incredibly slow after update to 1.21.8 #12638

New Issue
Closed
opened 2025-11-02 10:16:41 -06:00 by GiteaMirror · 44 comments
GiteaMirror commented 2025-11-02 10:16:41 -06:00
Owner
Copy Link

Originally created by @SoulSeekkor on GitHub (Mar 13, 2024).

Description

Updated from 1.21.7 to 1.21.8 and now the index page takes almost 10 seconds to load, it's insanely slow now... seems to be the heat map that is holding everything up?

Gitea Version

1.21.8

Can you reproduce the bug on the Gitea demo site?

No

Log Gist

No response

Screenshots

image

Git Version

2.42.0, Wire Protocol Version 2 Enabled

Operating System

Windows Server 2019

How are you running Gitea?

As a Windows service using the provided binary.

Database

MSSQL

Originally created by @SoulSeekkor on GitHub (Mar 13, 2024). ### Description Updated from 1.21.7 to 1.21.8 and now the index page takes almost 10 seconds to load, it's insanely slow now... seems to be the heat map that is holding everything up? ### Gitea Version 1.21.8 ### Can you reproduce the bug on the Gitea demo site? No ### Log Gist _No response_ ### Screenshots ![image](https://github.com/go-gitea/gitea/assets/16005426/1d9e6970-2a90-4923-9e86-0cb75e9efa2b) ### Git Version 2.42.0, Wire Protocol Version 2 Enabled ### Operating System Windows Server 2019 ### How are you running Gitea? As a Windows service using the provided binary. ### Database MSSQL
GiteaMirror added the performance/speedissue/needs-feedbacktype/bug labels 2025-11-02 10:16:41 -06:00
GiteaMirror commented 2025-11-02 10:16:42 -06:00
Author
Owner
Copy Link

@lunny commented on GitHub (Mar 13, 2024):

Can you force-reload this page and try again?

@lunny commented on GitHub (Mar 13, 2024): Can you force-reload this page and try again?
GiteaMirror commented 2025-11-02 10:16:43 -06:00
Author
Owner
Copy Link

@SoulSeekkor commented on GitHub (Mar 13, 2024):

Force reload (in Chrome) and it didn't have any effect. Also loaded in Firefox (which I don't use for anything except testing so it's never hit the site before) and it had the same performance problem.

@SoulSeekkor commented on GitHub (Mar 13, 2024): Force reload (in Chrome) and it didn't have any effect. Also loaded in Firefox (which I don't use for anything except testing so it's never hit the site before) and it had the same performance problem.
GiteaMirror commented 2025-11-02 10:16:43 -06:00
Author
Owner
Copy Link

@SoulSeekkor commented on GitHub (Mar 13, 2024):

Quick update, my coworker appears to not have this issue even after hard refreshes. I STILL have the issue however, even after hitting it locally on the server itself with Edge. I have a feeling this is specific to administrative users.

@SoulSeekkor commented on GitHub (Mar 13, 2024): Quick update, my coworker appears to not have this issue even after hard refreshes. I STILL have the issue however, even after hitting it locally on the server itself with Edge. I have a feeling this is specific to administrative users.
GiteaMirror commented 2025-11-02 10:16:43 -06:00
Author
Owner
Copy Link

@lunny commented on GitHub (Mar 13, 2024):

Can you provide some backend logs and web browser console -> network screenshots?

@lunny commented on GitHub (Mar 13, 2024): Can you provide some backend logs and web browser console -> network screenshots?
GiteaMirror commented 2025-11-02 10:16:43 -06:00
Author
Owner
Copy Link

@SoulSeekkor commented on GitHub (Mar 13, 2024):

Sure, here is the contents of the log after clearing it and refreshing the main page a few times:

2024/03/13 11:51:10 ...es/setting/mailer.go:203:loadMailerFrom() [W] connecting over insecure SMTP protocol to non-local address is not recommended
2024/03/13 11:51:10 cmd/web.go:194:serveInstalled() [W] Table system_setting Column version db default is , struct default is 1
2024/03/13 11:51:10 cmd/web.go:194:serveInstalled() [W] Table attachment column uuid db type is NVARCHAR(40), struct type is VARCHAR(40)
2024/03/13 11:51:10 cmd/web.go:194:serveInstalled() [W] Table upload column uuid db type is NVARCHAR(40), struct type is VARCHAR(40)
2024/03/13 11:51:10 cmd/web.go:194:serveInstalled() [W] Table project column card_type db type is INT, struct type is BIGINT
2024/03/13 11:51:10 cmd/web.go:194:serveInstalled() [W] Table project Column card_type db default is 0, struct default is
2024/03/13 11:51:10 cmd/web.go:194:serveInstalled() [W] Table project Column card_type db nullable is false, struct nullable is true
2024/03/13 11:51:10 cmd/web.go:194:serveInstalled() [W] Table hook_task has column repo_id but struct has not related field
2024/03/13 11:51:38 ...eb/routing/logger.go:68:func1() [W] router: slow GET / for 10.5.4.131:63770, elapsed 3866.0ms @ web/home.go:32(web.Home)
2024/03/13 11:52:02 ...eb/routing/logger.go:68:func1() [W] router: slow GET / for 10.5.4.131:63770, elapsed 3799.7ms @ web/home.go:32(web.Home)
2024/03/13 11:52:23 ...eb/routing/logger.go:68:func1() [W] router: slow GET / for 10.5.4.131:63770, elapsed 3310.2ms @ web/home.go:32(web.Home)

@SoulSeekkor commented on GitHub (Mar 13, 2024): Sure, here is the contents of the log after clearing it and refreshing the main page a few times: > 2024/03/13 11:51:10 ...es/setting/mailer.go:203:loadMailerFrom() [W] connecting over insecure SMTP protocol to non-local address is not recommended > 2024/03/13 11:51:10 cmd/web.go:194:serveInstalled() [W] Table system_setting Column version db default is , struct default is 1 > 2024/03/13 11:51:10 cmd/web.go:194:serveInstalled() [W] Table attachment column uuid db type is NVARCHAR(40), struct type is VARCHAR(40) > 2024/03/13 11:51:10 cmd/web.go:194:serveInstalled() [W] Table upload column uuid db type is NVARCHAR(40), struct type is VARCHAR(40) > 2024/03/13 11:51:10 cmd/web.go:194:serveInstalled() [W] Table project column card_type db type is INT, struct type is BIGINT > 2024/03/13 11:51:10 cmd/web.go:194:serveInstalled() [W] Table project Column card_type db default is 0, struct default is > 2024/03/13 11:51:10 cmd/web.go:194:serveInstalled() [W] Table project Column card_type db nullable is false, struct nullable is true > 2024/03/13 11:51:10 cmd/web.go:194:serveInstalled() [W] Table hook_task has column repo_id but struct has not related field > 2024/03/13 11:51:38 ...eb/routing/logger.go:68:func1() [W] router: slow GET / for 10.5.4.131:63770, elapsed 3866.0ms @ web/home.go:32(web.Home) > 2024/03/13 11:52:02 ...eb/routing/logger.go:68:func1() [W] router: slow GET / for 10.5.4.131:63770, elapsed 3799.7ms @ web/home.go:32(web.Home) > 2024/03/13 11:52:23 ...eb/routing/logger.go:68:func1() [W] router: slow GET / for 10.5.4.131:63770, elapsed 3310.2ms @ web/home.go:32(web.Home)
GiteaMirror commented 2025-11-02 10:16:43 -06:00
Author
Owner
Copy Link

@SoulSeekkor commented on GitHub (Mar 13, 2024):

Here are the screenshots.
waterfall3
waterfall1
waterfall2

@SoulSeekkor commented on GitHub (Mar 13, 2024): Here are the screenshots. ![waterfall3](https://github.com/go-gitea/gitea/assets/16005426/93a1d8a8-c5c3-45d6-bce9-b160558f6901) ![waterfall1](https://github.com/go-gitea/gitea/assets/16005426/f2e700be-00fe-4f1b-9cc7-dc197eff2f8b) ![waterfall2](https://github.com/go-gitea/gitea/assets/16005426/d9ccb0cc-ddf9-46b9-97aa-026d3401d5e8)
GiteaMirror commented 2025-11-02 10:16:43 -06:00
Author
Owner
Copy Link

@rwalravens commented on GitHub (Mar 14, 2024):

We're experiencing the same, although for some users it already started in 1.21.1
We suspect it has something to do with the action table.
After launching the cron 'Delete all old actions from database', the performance is much better (for our company, the table shrunk from ~2 million to 500k rows).
Of course this bypasses the cause, but it can help while waiting for a fix.

@rwalravens commented on GitHub (Mar 14, 2024): We're experiencing the same, although for some users it already started in 1.21.1 We suspect it has something to do with the action table. After launching the cron 'Delete all old actions from database', the performance is much better (for our company, the table shrunk from ~2 million to 500k rows). Of course this bypasses the cause, but it can help while waiting for a fix.
GiteaMirror commented 2025-11-02 10:16:44 -06:00
Author
Owner
Copy Link

@SoulSeekkor commented on GitHub (Mar 14, 2024):

I know in one particular older version (not sure if it was 1.21.1 off hand), the main page performance dropped drastically but I believe it was the org/repos listing that took forever at that time.

@SoulSeekkor commented on GitHub (Mar 14, 2024): I know in one particular older version (not sure if it was 1.21.1 off hand), the main page performance dropped drastically but I believe it was the org/repos listing that took forever at that time.
GiteaMirror commented 2025-11-02 10:16:44 -06:00
Author
Owner
Copy Link

@lunny commented on GitHub (Mar 20, 2024):

#29905 & #29932 maybe helpful.

@lunny commented on GitHub (Mar 20, 2024): #29905 & #29932 maybe helpful.
GiteaMirror commented 2025-11-02 10:16:44 -06:00
Author
Owner
Copy Link

@SoulSeekkor commented on GitHub (Mar 20, 2024):

Looks promising!

@SoulSeekkor commented on GitHub (Mar 20, 2024): Looks promising!
GiteaMirror commented 2025-11-02 10:16:44 -06:00
Author
Owner
Copy Link

@SoulSeekkor commented on GitHub (Mar 22, 2024):

Just noting that after updating to 1.21.9 this morning, it didn't make any difference on this page load issue for me.

@SoulSeekkor commented on GitHub (Mar 22, 2024): Just noting that after updating to 1.21.9 this morning, it didn't make any difference on this page load issue for me.
GiteaMirror commented 2025-11-02 10:16:45 -06:00
Author
Owner
Copy Link

@yp05327 commented on GitHub (Mar 26, 2024):

If heatmap is related, maybe this issue is related: #21045

@yp05327 commented on GitHub (Mar 26, 2024): If heatmap is related, maybe this issue is related: #21045
GiteaMirror commented 2025-11-02 10:16:45 -06:00
Author
Owner
Copy Link

@SoulSeekkor commented on GitHub (Mar 26, 2024):

Possibly but I doubt it, the heatmap (despite a fair number of repos on our instance) wasn't an issue before until 1.21.8, something changed in that (and seems to be only affecting admins) that absolutely made the main page almost unusable at this point. Also noting (probably expected) that the latest 1.21.10 version performance is unchanged.

@SoulSeekkor commented on GitHub (Mar 26, 2024): Possibly but I doubt it, the heatmap (despite a fair number of repos on our instance) wasn't an issue before until 1.21.8, something changed in that (and seems to be only affecting admins) that absolutely made the main page almost unusable at this point. Also noting (probably expected) that the latest 1.21.10 version performance is unchanged.
GiteaMirror commented 2025-11-02 10:16:45 -06:00
Author
Owner
Copy Link

@yp05327 commented on GitHub (Mar 27, 2024):

maybe we need a trace level log to detect where takes long time to handle the request.

@yp05327 commented on GitHub (Mar 27, 2024): maybe we need a trace level log to detect where takes long time to handle the request.
GiteaMirror commented 2025-11-02 10:16:45 -06:00
Author
Owner
Copy Link

@SoulSeekkor commented on GitHub (Mar 27, 2024):

I stopped the service, cleared the log, set to trace level, and after starting the service refreshed the main page and stopped it again. Hopefully this helps!

@SoulSeekkor commented on GitHub (Mar 27, 2024): I stopped the service, cleared the log, set to trace level, and after starting the service refreshed the main page and stopped it again. Hopefully this helps!
GiteaMirror commented 2025-11-02 10:16:45 -06:00
Author
Owner
Copy Link

@lunny commented on GitHub (Mar 27, 2024):

Thank you. It's very helpful.

@lunny commented on GitHub (Mar 27, 2024): Thank you. It's very helpful.
GiteaMirror commented 2025-11-02 10:16:46 -06:00
Author
Owner
Copy Link

@SoulSeekkor commented on GitHub (May 28, 2024):

Just a quick update on this, I've updated our instance to 1.22.0 and this is still an issue. Before the update I also converted the entirety of the database collation to the recommended Latin1_General_CS_AS as well (to no effect).

@SoulSeekkor commented on GitHub (May 28, 2024): Just a quick update on this, I've updated our instance to 1.22.0 and this is still an issue. Before the update I also converted the entirety of the database collation to the recommended Latin1_General_CS_AS as well (to no effect).
GiteaMirror commented 2025-11-02 10:16:46 -06:00
Author
Owner
Copy Link

@lunny commented on GitHub (May 29, 2024):

Can you post the backend logs when you visit the dashboard after enable database logs? https://docs.gitea.com/next/administration/logging-config?_highlight=log_sql#the-xorm-logger

And if yo can visit the database, please do a count on action table, so that we know how many records there.

@lunny commented on GitHub (May 29, 2024): Can you post the backend logs when you visit the dashboard after enable database logs? https://docs.gitea.com/next/administration/logging-config?_highlight=log_sql#the-xorm-logger And if yo can visit the database, please do a count on `action` table, so that we know how many records there.
GiteaMirror commented 2025-11-02 10:16:46 -06:00
Author
Owner
Copy Link

@SoulSeekkor commented on GitHub (May 29, 2024):

I've attached the requested log, cleared it first followed by service start, refreshed dashboard, stopped service. The count of the action table is 139,460.

gitea.log

@SoulSeekkor commented on GitHub (May 29, 2024): I've attached the requested log, cleared it first followed by service start, refreshed dashboard, stopped service. The count of the action table is 139,460. [gitea.log](https://github.com/go-gitea/gitea/files/15485399/gitea.log)
GiteaMirror commented 2025-11-02 10:16:46 -06:00
Author
Owner
Copy Link

@SoulSeekkor commented on GitHub (Jun 14, 2024):

Interesting bit to add to this, I noticed yesterday when I had filled the entire feed with commits that were only mine that the index page loaded in a second or two (normal). Today now that the feed has other commits (synced commits for mirrors in orgs) it's back to being super super slow again to refresh.

@SoulSeekkor commented on GitHub (Jun 14, 2024): Interesting bit to add to this, I noticed yesterday when I had filled the entire feed with commits that were only mine that the index page loaded in a second or two (normal). Today now that the feed has other commits (synced commits for mirrors in orgs) it's back to being super super slow again to refresh.
GiteaMirror commented 2025-11-02 10:16:46 -06:00
Author
Owner
Copy Link

@hawkbee commented on GitHub (Jul 5, 2024):

The slow dashboard happened on gitea 1.21.9, some logs may be usefull.

mysql  Ver 14.14 Distrib 5.7.42
gitea 当前版本: 1.21.9 页面:1868ms 模板:150ms

2024/07/05 11:27:37 ...eb/routing/logger.go:68:func1() [W] router: slow      GET /org/test/dashboard for 192.168.100.120:50062, elapsed 3439.9ms @ user/home.go:73(user.Dashboard)
2024/07/05 11:27:47 ...eb/routing/logger.go:102:func1() [I] router: completed GET /avatars/527798c2fac472a9aa2877e4ea29f5b0?size=56 for 192.168.100.120:50074, 200 OK in 47.5ms @ web/base.go:22(avatars)
2024/07/05 11:27:47 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:47 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:47 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:47 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:47 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:47 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:47 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:47 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:47 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:47 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:47 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:47 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:47 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:47 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:48 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:48 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:48 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:48 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false}
2024/07/05 11:27:49 ...eb/routing/logger.go:102:func1() [I] router: completed GET /org/test/dashboard for 192.168.100.120:50062, 200 OK in 15709.9ms @ user/home.go:73(user.Dashboard)
2
@hawkbee commented on GitHub (Jul 5, 2024): The slow dashboard happened on gitea 1.21.9, some logs may be usefull. ``` mysql Ver 14.14 Distrib 5.7.42 gitea 当前版本: 1.21.9 页面:1868ms 模板:150ms ``` ``` 2024/07/05 11:27:37 ...eb/routing/logger.go:68:func1() [W] router: slow GET /org/test/dashboard for 192.168.100.120:50062, elapsed 3439.9ms @ user/home.go:73(user.Dashboard) 2024/07/05 11:27:47 ...eb/routing/logger.go:102:func1() [I] router: completed GET /avatars/527798c2fac472a9aa2877e4ea29f5b0?size=56 for 192.168.100.120:50074, 200 OK in 47.5ms @ web/base.go:22(avatars) 2024/07/05 11:27:47 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:47 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:47 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:47 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:47 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:47 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:47 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:47 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:47 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:47 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:47 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:47 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:47 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:47 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:48 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:48 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:48 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:48 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13950453902916295058 6316367925459460 0x6735640} false} 2024/07/05 11:27:49 ...eb/routing/logger.go:102:func1() [I] router: completed GET /org/test/dashboard for 192.168.100.120:50062, 200 OK in 15709.9ms @ user/home.go:73(user.Dashboard) 2 ```
GiteaMirror commented 2025-11-02 10:16:47 -06:00
Author
Owner
Copy Link

@SoulSeekkor commented on GitHub (Jul 8, 2024):

Just adding that this is still an issue with 1.22.1.

@SoulSeekkor commented on GitHub (Jul 8, 2024): Just adding that this is still an issue with 1.22.1.
GiteaMirror commented 2025-11-02 10:16:47 -06:00
Author
Owner
Copy Link

@somera commented on GitHub (Aug 1, 2024):

I see this

2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}
2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false}

to in my gitea 1.22.1 on ubuntu with PostgreSQL.

@somera commented on GitHub (Aug 1, 2024): I see this ``` 2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:57 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:57 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} 2024/08/01 22:36:58 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13953025034712252310 18263062709511 0x6a1a080} false} ``` to in my gitea 1.22.1 on ubuntu with PostgreSQL.
GiteaMirror commented 2025-11-02 10:16:47 -06:00
Author
Owner
Copy Link

@somera commented on GitHub (Aug 1, 2024):

The "cache context is expired, may be misused..." log entry I see in #31752.

@somera commented on GitHub (Aug 1, 2024): The "cache context is expired, may be misused..." log entry I see in #31752.
GiteaMirror commented 2025-11-02 10:16:47 -06:00
Author
Owner
Copy Link

@lixfel commented on GitHub (Aug 12, 2024):

I have the same issue with the slow home page / user page on my gitea instance. Due to the suspected heatmap, I tested the performance with ENABLE_USER_HEATMAP = false. This resulted in no noticable change in performance. Due to this I suspect not the heatmap but the user/home/activity feed as the culprit.

@lixfel commented on GitHub (Aug 12, 2024): I have the same issue with the slow home page / user page on my gitea instance. Due to the suspected heatmap, I tested the performance with `ENABLE_USER_HEATMAP = false`. This resulted in no noticable change in performance. Due to this I suspect not the heatmap but the user/home/activity feed as the culprit.
GiteaMirror commented 2025-11-02 10:16:47 -06:00
Author
Owner
Copy Link

@somera commented on GitHub (Aug 12, 2024):

@lixfel do you see slow queries in gitea.log?

@somera commented on GitHub (Aug 12, 2024): @lixfel do you see slow queries in gitea.log?
GiteaMirror commented 2025-11-02 10:16:47 -06:00
Author
Owner
Copy Link

@lixfel commented on GitHub (Aug 12, 2024):

Yes (MariaDB backend). Time of the query roughly matches reported page load time for (logged in) / and /user?tab=activity page:

2024/08/12 16:11:31 ...activities/action.go:461:GetFeeds() [W] [Slow SQL Query] SELECT `action`.* FROM `action` INNER JOIN `repository` ON `repository`.id = `action`.repo_id WHERE user_id=? AND act_user_id=? AND is_deleted=? ORDER BY `action`.`created_unix` DESC LIMIT 5 [13 13 false] - 33.760273009s

I have also found these queries (just once, not for every slow page load):

2024/08/12 11:45:58 ...activities/action.go:461:GetFeeds() [W] [Slow SQL Query] SELECT `action`.* FROM `action` INNER JOIN `repository` ON `repository`.id = `action`.repo_id WHERE act_user_id IN (SELECT `user`.id FROM `user` WHERE keep_activity_private=? AND visibility=?) AND repo_id IN (SELECT id FROM repository WHERE (`repository`.is_private=? AND `repository`.owner_id NOT IN (SELECT id FROM `user` WHERE type=? AND visibility IN (?,?)))) AND user_id=? AND act_user_id=? AND `action`.is_private=? AND is_deleted=? ORDER BY `action`.`created_unix` DESC LIMIT 5 [false public false 1 private limited 13 13 false false] - 34.155154395s
2024/08/12 11:46:30 ...activities/action.go:461:GetFeeds() [W] [Slow SQL Query] SELECT count(*) FROM `action` INNER JOIN `repository` ON `repository`.id = `action`.repo_id WHERE act_user_id IN (SELECT `user`.id FROM `user` WHERE keep_activity_private=? AND visibility=?) AND repo_id IN (SELECT id FROM repository WHERE (`repository`.is_private=? AND `repository`.owner_id NOT IN (SELECT id FROM `user` WHERE type=? AND visibility IN (?,?)))) AND user_id=? AND act_user_id=? AND `action`.is_private=? AND is_deleted=? [false public false 1 private limited 13 13 false false] - 31.342845667s
@lixfel commented on GitHub (Aug 12, 2024): Yes (MariaDB backend). Time of the query roughly matches reported page load time for (logged in) `/` and `/user?tab=activity` page: ``` 2024/08/12 16:11:31 ...activities/action.go:461:GetFeeds() [W] [Slow SQL Query] SELECT `action`.* FROM `action` INNER JOIN `repository` ON `repository`.id = `action`.repo_id WHERE user_id=? AND act_user_id=? AND is_deleted=? ORDER BY `action`.`created_unix` DESC LIMIT 5 [13 13 false] - 33.760273009s ``` I have also found these queries (just once, not for every slow page load): ``` 2024/08/12 11:45:58 ...activities/action.go:461:GetFeeds() [W] [Slow SQL Query] SELECT `action`.* FROM `action` INNER JOIN `repository` ON `repository`.id = `action`.repo_id WHERE act_user_id IN (SELECT `user`.id FROM `user` WHERE keep_activity_private=? AND visibility=?) AND repo_id IN (SELECT id FROM repository WHERE (`repository`.is_private=? AND `repository`.owner_id NOT IN (SELECT id FROM `user` WHERE type=? AND visibility IN (?,?)))) AND user_id=? AND act_user_id=? AND `action`.is_private=? AND is_deleted=? ORDER BY `action`.`created_unix` DESC LIMIT 5 [false public false 1 private limited 13 13 false false] - 34.155154395s 2024/08/12 11:46:30 ...activities/action.go:461:GetFeeds() [W] [Slow SQL Query] SELECT count(*) FROM `action` INNER JOIN `repository` ON `repository`.id = `action`.repo_id WHERE act_user_id IN (SELECT `user`.id FROM `user` WHERE keep_activity_private=? AND visibility=?) AND repo_id IN (SELECT id FROM repository WHERE (`repository`.is_private=? AND `repository`.owner_id NOT IN (SELECT id FROM `user` WHERE type=? AND visibility IN (?,?)))) AND user_id=? AND act_user_id=? AND `action`.is_private=? AND is_deleted=? [false public false 1 private limited 13 13 false false] - 31.342845667s ```
GiteaMirror commented 2025-11-02 10:16:48 -06:00
Author
Owner
Copy Link

@somera commented on GitHub (Aug 12, 2024):

I'm using Gitea with PostgreSQL. I can't check the statements on my setup.

Just try to analyse the statements with ANALYSE (https://mariadb.com/kb/en/analyze-statement/). And post the output here.

@somera commented on GitHub (Aug 12, 2024): I'm using Gitea with PostgreSQL. I can't check the statements on my setup. Just try to analyse the statements with ANALYSE (https://mariadb.com/kb/en/analyze-statement/). And post the output here.
GiteaMirror commented 2025-11-02 10:16:48 -06:00
Author
Owner
Copy Link

@lixfel commented on GitHub (Aug 12, 2024):

Context: ~122k Actions (I have in the meantime set the recommended old action cleanup up, therefore slightly shorter times).

1. Statement 
{
  "query_optimization": {
    "r_total_time_ms": 0.224562772
  },
  "query_block": {
    "select_id": 1,
    "r_loops": 1,
    "r_total_time_ms": 14692.04853,
    "filesort": {
      "sort_key": "`action`.created_unix desc",
      "r_loops": 1,
      "r_total_time_ms": 0.310724109,
      "r_limit": 5,
      "r_used_priority_queue": true,
      "r_output_rows": 6,
      "r_sort_mode": "sort_key,rowid",
      "temporary_table": {
        "nested_loop": [
          {
            "table": {
              "table_name": "repository",
              "access_type": "index",
              "possible_keys": ["PRIMARY"],
              "key": "IDX_repository_is_fork",
              "key_length": "1",
              "used_key_parts": ["is_fork"],
              "r_loops": 1,
              "rows": 101,
              "r_rows": 101,
              "r_table_time_ms": 0.128251931,
              "r_other_time_ms": 0.164203069,
              "r_engine_stats": {
                "pages_accessed": 1
              },
              "filtered": 100,
              "r_filtered": 100,
              "using_index": true
            }
          },
          {
            "table": {
              "table_name": "action",
              "access_type": "ref",
              "possible_keys": [
                "IDX_action_user_id",
                "IDX_action_au_r_c_u_d",
                "IDX_action_r_u_d"
              ],
              "key": "IDX_action_r_u_d",
              "key_length": "19",
              "used_key_parts": ["repo_id", "user_id", "is_deleted"],
              "ref": ["gitea.repository.id", "const", "const"],
              "r_loops": 101,
              "rows": 129,
              "r_rows": 258.2079208,
              "r_table_time_ms": 14677.53835,
              "r_other_time_ms": 12.82903396,
              "r_engine_stats": {
                "pages_accessed": 78573,
                "pages_read_count": 8730,
                "pages_read_time_ms": 49065154.15
              },
              "filtered": 27.69502831,
              "r_filtered": 4.022393497,
              "attached_condition": "`action`.act_user_id = 1"
            }
          }
        ]
      }
    }
  }
}
2. Statement 
{
  "query_optimization": {
    "r_total_time_ms": 0.46650906
  },
  "query_block": {
    "select_id": 1,
    "r_loops": 1,
    "r_total_time_ms": 15869.32961,
    "filesort": {
      "sort_key": "`action`.created_unix desc",
      "r_loops": 1,
      "r_total_time_ms": 0.49666901,
      "r_limit": 5,
      "r_used_priority_queue": true,
      "r_output_rows": 6,
      "r_sort_mode": "sort_key,rowid",
      "temporary_table": {
        "nested_loop": [
          {
            "table": {
              "table_name": "user",
              "access_type": "const",
              "possible_keys": ["PRIMARY"],
              "key": "PRIMARY",
              "key_length": "8",
              "used_key_parts": ["id"],
              "ref": ["const"],
              "r_loops": 0,
              "rows": 1,
              "r_rows": null,
              "r_engine_stats": {
                "pages_accessed": 1
              },
              "filtered": 100,
              "r_filtered": null
            }
          },
          {
            "table": {
              "table_name": "repository",
              "access_type": "range",
              "possible_keys": ["PRIMARY", "IDX_repository_is_private"],
              "key": "IDX_repository_is_private",
              "key_length": "2",
              "used_key_parts": ["is_private"],
              "r_loops": 1,
              "rows": 67,
              "r_rows": 67,
              "r_table_time_ms": 0.365640891,
              "r_other_time_ms": 0.387999654,
              "r_engine_stats": {
                "pages_accessed": 135
              },
              "filtered": 100,
              "r_filtered": 76.11940299,
              "index_condition": "repository.is_private = 0",
              "attached_condition": "!<in_optimizer>(repository.owner_id,repository.owner_id in (subquery#4))"
            }
          },
          {
            "table": {
              "table_name": "repository",
              "access_type": "eq_ref",
              "possible_keys": ["PRIMARY"],
              "key": "PRIMARY",
              "key_length": "8",
              "used_key_parts": ["id"],
              "ref": ["gitea.repository.id"],
              "r_loops": 51,
              "rows": 1,
              "r_rows": 1,
              "r_table_time_ms": 0.300514901,
              "r_other_time_ms": 0.032468465,
              "r_engine_stats": {
                "pages_accessed": 104
              },
              "filtered": 100,
              "r_filtered": 100,
              "using_index": true
            }
          },
          {
            "table": {
              "table_name": "action",
              "access_type": "ref",
              "possible_keys": [
                "IDX_action_user_id",
                "IDX_action_au_r_c_u_d",
                "IDX_action_r_u_d"
              ],
              "key": "IDX_action_r_u_d",
              "key_length": "19",
              "used_key_parts": ["repo_id", "user_id", "is_deleted"],
              "ref": ["gitea.repository.id", "const", "const"],
              "r_loops": 51,
              "rows": 129,
              "r_rows": 507.8627451,
              "r_table_time_ms": 15852.30487,
              "r_other_time_ms": 13.85372599,
              "r_engine_stats": {
                "pages_accessed": 77944,
                "pages_read_count": 9094,
                "pages_read_time_ms": 53190293.67
              },
              "filtered": 100,
              "r_filtered": 3.899463341,
              "attached_condition": "`action`.act_user_id = 1 and `action`.is_private = 0"
            }
          }
        ],
        "subqueries": [
          {
            "query_block": {
              "select_id": 4,
              "r_loops": 1,
              "r_total_time_ms": 0.055215297,
              "nested_loop": [
                {
                  "table": {
                    "table_name": "user",
                    "access_type": "ALL",
                    "possible_keys": ["PRIMARY"],
                    "r_loops": 1,
                    "rows": 31,
                    "r_rows": 31,
                    "r_table_time_ms": 0.028239505,
                    "r_other_time_ms": 0.019582574,
                    "r_engine_stats": {
                      "pages_accessed": 1
                    },
                    "filtered": 100,
                    "r_filtered": 87.09677419,
                    "attached_condition": "`user`.`type` = 0 and `user`.visibility in (0,2)"
                  }
                }
              ]
            }
          }
        ]
      }
    }
  }
}
3. Statement 
{
  "query_optimization": {
    "r_total_time_ms": 0.382885099
  },
  "query_block": {
    "select_id": 1,
    "r_loops": 1,
    "r_total_time_ms": 15281.56887,
    "nested_loop": [
      {
        "table": {
          "table_name": "user",
          "access_type": "const",
          "possible_keys": ["PRIMARY"],
          "key": "PRIMARY",
          "key_length": "8",
          "used_key_parts": ["id"],
          "ref": ["const"],
          "r_loops": 0,
          "rows": 1,
          "r_rows": null,
          "r_engine_stats": {
            "pages_accessed": 1
          },
          "filtered": 100,
          "r_filtered": null
        }
      },
      {
        "table": {
          "table_name": "repository",
          "access_type": "ALL",
          "possible_keys": ["PRIMARY", "IDX_repository_is_private"],
          "r_loops": 1,
          "rows": 101,
          "r_rows": 101,
          "r_table_time_ms": 0.149008663,
          "r_other_time_ms": 0.449722574,
          "r_engine_stats": {
            "pages_accessed": 4
          },
          "filtered": 66.33663177,
          "r_filtered": 50.4950495,
          "attached_condition": "repository.is_private = 0 and !<in_optimizer>(repository.owner_id,repository.owner_id in (subquery#4))"
        }
      },
      {
        "table": {
          "table_name": "repository",
          "access_type": "eq_ref",
          "possible_keys": ["PRIMARY"],
          "key": "PRIMARY",
          "key_length": "8",
          "used_key_parts": ["id"],
          "ref": ["gitea.repository.id"],
          "r_loops": 51,
          "rows": 1,
          "r_rows": 1,
          "r_table_time_ms": 0.315848614,
          "r_other_time_ms": 0.031174901,
          "r_engine_stats": {
            "pages_accessed": 104
          },
          "filtered": 100,
          "r_filtered": 100,
          "using_index": true
        }
      },
      {
        "table": {
          "table_name": "action",
          "access_type": "ref",
          "possible_keys": [
            "IDX_action_user_id",
            "IDX_action_au_r_c_u_d",
            "IDX_action_r_u_d"
          ],
          "key": "IDX_action_r_u_d",
          "key_length": "19",
          "used_key_parts": ["repo_id", "user_id", "is_deleted"],
          "ref": ["gitea.repository.id", "const", "const"],
          "r_loops": 51,
          "rows": 129,
          "r_rows": 507.8627451,
          "r_table_time_ms": 15273.24721,
          "r_other_time_ms": 7.312031735,
          "r_engine_stats": {
            "pages_accessed": 77933,
            "pages_read_count": 8640,
            "pages_read_time_ms": 51436849.48
          },
          "filtered": 100,
          "r_filtered": 3.899463341,
          "attached_condition": "`action`.act_user_id = 1 and `action`.is_private = 0"
        }
      }
    ],
    "subqueries": [
      {
        "query_block": {
          "select_id": 4,
          "r_loops": 1,
          "r_total_time_ms": 0.049603218,
          "nested_loop": [
            {
              "table": {
                "table_name": "user",
                "access_type": "ALL",
                "possible_keys": ["PRIMARY"],
                "r_loops": 1,
                "rows": 31,
                "r_rows": 31,
                "r_table_time_ms": 0.025692178,
                "r_other_time_ms": 0.020458218,
                "r_engine_stats": {
                  "pages_accessed": 1
                },
                "filtered": 100,
                "r_filtered": 83.87096774,
                "attached_condition": "`user`.`type` = 0 and `user`.visibility in (0,1)"
              }
            }
          ]
        }
      }
    ]
  }
}
Keys in the action table

image

@lixfel commented on GitHub (Aug 12, 2024): Context: ~122k Actions (I have in the meantime set the recommended old action cleanup up, therefore slightly shorter times). <details> <summary>1. Statement</summary> ```json { "query_optimization": { "r_total_time_ms": 0.224562772 }, "query_block": { "select_id": 1, "r_loops": 1, "r_total_time_ms": 14692.04853, "filesort": { "sort_key": "`action`.created_unix desc", "r_loops": 1, "r_total_time_ms": 0.310724109, "r_limit": 5, "r_used_priority_queue": true, "r_output_rows": 6, "r_sort_mode": "sort_key,rowid", "temporary_table": { "nested_loop": [ { "table": { "table_name": "repository", "access_type": "index", "possible_keys": ["PRIMARY"], "key": "IDX_repository_is_fork", "key_length": "1", "used_key_parts": ["is_fork"], "r_loops": 1, "rows": 101, "r_rows": 101, "r_table_time_ms": 0.128251931, "r_other_time_ms": 0.164203069, "r_engine_stats": { "pages_accessed": 1 }, "filtered": 100, "r_filtered": 100, "using_index": true } }, { "table": { "table_name": "action", "access_type": "ref", "possible_keys": [ "IDX_action_user_id", "IDX_action_au_r_c_u_d", "IDX_action_r_u_d" ], "key": "IDX_action_r_u_d", "key_length": "19", "used_key_parts": ["repo_id", "user_id", "is_deleted"], "ref": ["gitea.repository.id", "const", "const"], "r_loops": 101, "rows": 129, "r_rows": 258.2079208, "r_table_time_ms": 14677.53835, "r_other_time_ms": 12.82903396, "r_engine_stats": { "pages_accessed": 78573, "pages_read_count": 8730, "pages_read_time_ms": 49065154.15 }, "filtered": 27.69502831, "r_filtered": 4.022393497, "attached_condition": "`action`.act_user_id = 1" } } ] } } } } ``` </details> <details> <summary>2. Statement</summary> ```json { "query_optimization": { "r_total_time_ms": 0.46650906 }, "query_block": { "select_id": 1, "r_loops": 1, "r_total_time_ms": 15869.32961, "filesort": { "sort_key": "`action`.created_unix desc", "r_loops": 1, "r_total_time_ms": 0.49666901, "r_limit": 5, "r_used_priority_queue": true, "r_output_rows": 6, "r_sort_mode": "sort_key,rowid", "temporary_table": { "nested_loop": [ { "table": { "table_name": "user", "access_type": "const", "possible_keys": ["PRIMARY"], "key": "PRIMARY", "key_length": "8", "used_key_parts": ["id"], "ref": ["const"], "r_loops": 0, "rows": 1, "r_rows": null, "r_engine_stats": { "pages_accessed": 1 }, "filtered": 100, "r_filtered": null } }, { "table": { "table_name": "repository", "access_type": "range", "possible_keys": ["PRIMARY", "IDX_repository_is_private"], "key": "IDX_repository_is_private", "key_length": "2", "used_key_parts": ["is_private"], "r_loops": 1, "rows": 67, "r_rows": 67, "r_table_time_ms": 0.365640891, "r_other_time_ms": 0.387999654, "r_engine_stats": { "pages_accessed": 135 }, "filtered": 100, "r_filtered": 76.11940299, "index_condition": "repository.is_private = 0", "attached_condition": "!<in_optimizer>(repository.owner_id,repository.owner_id in (subquery#4))" } }, { "table": { "table_name": "repository", "access_type": "eq_ref", "possible_keys": ["PRIMARY"], "key": "PRIMARY", "key_length": "8", "used_key_parts": ["id"], "ref": ["gitea.repository.id"], "r_loops": 51, "rows": 1, "r_rows": 1, "r_table_time_ms": 0.300514901, "r_other_time_ms": 0.032468465, "r_engine_stats": { "pages_accessed": 104 }, "filtered": 100, "r_filtered": 100, "using_index": true } }, { "table": { "table_name": "action", "access_type": "ref", "possible_keys": [ "IDX_action_user_id", "IDX_action_au_r_c_u_d", "IDX_action_r_u_d" ], "key": "IDX_action_r_u_d", "key_length": "19", "used_key_parts": ["repo_id", "user_id", "is_deleted"], "ref": ["gitea.repository.id", "const", "const"], "r_loops": 51, "rows": 129, "r_rows": 507.8627451, "r_table_time_ms": 15852.30487, "r_other_time_ms": 13.85372599, "r_engine_stats": { "pages_accessed": 77944, "pages_read_count": 9094, "pages_read_time_ms": 53190293.67 }, "filtered": 100, "r_filtered": 3.899463341, "attached_condition": "`action`.act_user_id = 1 and `action`.is_private = 0" } } ], "subqueries": [ { "query_block": { "select_id": 4, "r_loops": 1, "r_total_time_ms": 0.055215297, "nested_loop": [ { "table": { "table_name": "user", "access_type": "ALL", "possible_keys": ["PRIMARY"], "r_loops": 1, "rows": 31, "r_rows": 31, "r_table_time_ms": 0.028239505, "r_other_time_ms": 0.019582574, "r_engine_stats": { "pages_accessed": 1 }, "filtered": 100, "r_filtered": 87.09677419, "attached_condition": "`user`.`type` = 0 and `user`.visibility in (0,2)" } } ] } } ] } } } } ``` </details> <details> <summary>3. Statement</summary> ```json { "query_optimization": { "r_total_time_ms": 0.382885099 }, "query_block": { "select_id": 1, "r_loops": 1, "r_total_time_ms": 15281.56887, "nested_loop": [ { "table": { "table_name": "user", "access_type": "const", "possible_keys": ["PRIMARY"], "key": "PRIMARY", "key_length": "8", "used_key_parts": ["id"], "ref": ["const"], "r_loops": 0, "rows": 1, "r_rows": null, "r_engine_stats": { "pages_accessed": 1 }, "filtered": 100, "r_filtered": null } }, { "table": { "table_name": "repository", "access_type": "ALL", "possible_keys": ["PRIMARY", "IDX_repository_is_private"], "r_loops": 1, "rows": 101, "r_rows": 101, "r_table_time_ms": 0.149008663, "r_other_time_ms": 0.449722574, "r_engine_stats": { "pages_accessed": 4 }, "filtered": 66.33663177, "r_filtered": 50.4950495, "attached_condition": "repository.is_private = 0 and !<in_optimizer>(repository.owner_id,repository.owner_id in (subquery#4))" } }, { "table": { "table_name": "repository", "access_type": "eq_ref", "possible_keys": ["PRIMARY"], "key": "PRIMARY", "key_length": "8", "used_key_parts": ["id"], "ref": ["gitea.repository.id"], "r_loops": 51, "rows": 1, "r_rows": 1, "r_table_time_ms": 0.315848614, "r_other_time_ms": 0.031174901, "r_engine_stats": { "pages_accessed": 104 }, "filtered": 100, "r_filtered": 100, "using_index": true } }, { "table": { "table_name": "action", "access_type": "ref", "possible_keys": [ "IDX_action_user_id", "IDX_action_au_r_c_u_d", "IDX_action_r_u_d" ], "key": "IDX_action_r_u_d", "key_length": "19", "used_key_parts": ["repo_id", "user_id", "is_deleted"], "ref": ["gitea.repository.id", "const", "const"], "r_loops": 51, "rows": 129, "r_rows": 507.8627451, "r_table_time_ms": 15273.24721, "r_other_time_ms": 7.312031735, "r_engine_stats": { "pages_accessed": 77933, "pages_read_count": 8640, "pages_read_time_ms": 51436849.48 }, "filtered": 100, "r_filtered": 3.899463341, "attached_condition": "`action`.act_user_id = 1 and `action`.is_private = 0" } } ], "subqueries": [ { "query_block": { "select_id": 4, "r_loops": 1, "r_total_time_ms": 0.049603218, "nested_loop": [ { "table": { "table_name": "user", "access_type": "ALL", "possible_keys": ["PRIMARY"], "r_loops": 1, "rows": 31, "r_rows": 31, "r_table_time_ms": 0.025692178, "r_other_time_ms": 0.020458218, "r_engine_stats": { "pages_accessed": 1 }, "filtered": 100, "r_filtered": 83.87096774, "attached_condition": "`user`.`type` = 0 and `user`.visibility in (0,1)" } } ] } } ] } } ``` </details> <details> <summary>Keys in the action table</summary> ![image](https://github.com/user-attachments/assets/c1967c46-87c6-4975-bbf5-4bb4bd8e4902) </details>
GiteaMirror commented 2025-11-02 10:16:48 -06:00
Author
Owner
Copy Link

@KimonHoffmann commented on GitHub (Sep 13, 2024):

We're running a relatively small instance in Docker, backed by SQLite and are also observing periodic, extremely long delays for quite some time (I don't remember the exact version, but I do remember it was the one where the GoGit was replaced in favor of the git binary, which is why back then I chalked the added delay up to further optimizations being necessary in interacting with the git binary).

Having enabled trace logging now, on 1.22.2 I can confirm the pattern observed by others above.

Please note that the following log entries are complete and have only been annotated with comments and anonymized.
They implicitly show that while this is going on the whole instance is blocked, as indicated by the upload-pack pack requests suffering as a result of this. What is common is that there always is a Dashboard request in the mix, either explicitly in the form of a GET / request, or implicitly in the form of a GET /user/login request, which appear to be the requests actually causing the delays/slowdowns.

# Client A reported to be slow
Sep 13 10:08:14 ANONYMIZED docker[3878067]: 2024/09/13 08:08:14 ...eb/routing/logger.go:68:func1() [W] router: slow      GET /ANONYMIZED.git/info/refs?service=git-upload-pack for AAA.AAA.AAA.AAA:35204, elapsed 3469.3ms @ web/web.go:118(web.Routes.webAuth)
# Client B reported to be slow
Sep 13 10:08:15 ANONYMIZED docker[3878067]: 2024/09/13 08:08:15 ...eb/routing/logger.go:68:func1() [W] router: slow      GET /ANONYMIZED.git/info/refs?service=git-upload-pack for BBB.BBB.BBB.BBB:58500, elapsed 3875.2ms @ web/web.go:118(web.Routes.webAuth)
# Client C reported to be slow
Sep 13 10:08:15 ANONYMIZED docker[3878067]: 2024/09/13 08:08:15 ...eb/routing/logger.go:68:func1() [W] router: slow      GET /ANONYMIZED.git/info/refs?service=git-upload-pack for CCC.CCC.CCC.CCC:53622, elapsed 3875.5ms @ web/web.go:118(web.Routes.webAuth)
# Client D reported to be slow
Sep 13 10:08:42 ANONYMIZED docker[3878067]: 2024/09/13 08:08:42 ...eb/routing/logger.go:68:func1() [W] router: slow      GET /user/login for DDD.DDD.DDD.DDD:40112, elapsed 3260.5ms @ auth/auth.go:164(auth.SignIn)
# Client E reported to be slow
Sep 13 10:08:43 ANONYMIZED docker[3878067]: 2024/09/13 08:08:43 ...eb/routing/logger.go:68:func1() [W] router: slow      GET /ANONYMIZED.git/info/refs?service=git-upload-pack for EEE.EEE.EEE.EEE:60660, elapsed 3516.4ms @ web/web.go:118(web.Routes.webAuth)
# Client F reported to be slow
Sep 13 10:08:44 ANONYMIZED docker[3878067]: 2024/09/13 08:08:44 ...eb/routing/logger.go:68:func1() [W] router: slow      GET /ANONYMIZED.git/info/refs?service=git-upload-pack for FFF.FFF.FFF.FFF:43522, elapsed 3770.4ms @ web/web.go:118(web.Routes.webAuth)
# Client G reported to be slow
Sep 13 10:08:44 ANONYMIZED docker[3878067]: 2024/09/13 08:08:44 ...eb/routing/logger.go:68:func1() [W] router: slow      GET /ANONYMIZED.git/info/refs?service=git-upload-pack for GGG.GGG.GGG.GGG:33844, elapsed 3770.4ms @ web/web.go:118(web.Routes.webAuth)

# Multiple reports of slow SQL queries
Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...auth/access_token.go:174:GetAccessTokenBySHA() [W] [Slow SQL Query] SELECT `id`, `uid`, `name`, `token_hash`, `token_salt`, `token_last_eight`, `scope`, `created_unix`, `updated_unix` FROM `access_token` WHERE (token_last_eight = ?) [d4b41293] - 37.408652439s
Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...auth/access_token.go:174:GetAccessTokenBySHA() [W] [Slow SQL Query] SELECT `id`, `uid`, `name`, `token_hash`, `token_salt`, `token_last_eight`, `scope`, `created_unix`, `updated_unix` FROM `access_token` WHERE (token_last_eight = ?) [d4b41293] - 37.40420057s
Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...auth/access_token.go:174:GetAccessTokenBySHA() [W] [Slow SQL Query] SELECT `id`, `uid`, `name`, `token_hash`, `token_salt`, `token_last_eight`, `scope`, `created_unix`, `updated_unix` FROM `access_token` WHERE (token_last_eight = ?) [d4b41293] - 37.40442079s
Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...ers/web/auth/auth.go:56:autoSignIn() [W] [Slow SQL Query] DELETE FROM `auth_token` WHERE expires_unix<? [1726214920] - 9.408882468s

# Client D's request completes
Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...eb/routing/logger.go:102:func1() [I] router: completed GET /user/login for DDD.DDD.DDD.DDD:40112, 200 OK in 9793.4ms @ auth/auth.go:164(auth.SignIn)

# Multiple reports of slow SQL queries
Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...auth/access_token.go:174:GetAccessTokenBySHA() [W] [Slow SQL Query] SELECT `id`, `uid`, `name`, `token_hash`, `token_salt`, `token_last_eight`, `scope`, `created_unix`, `updated_unix` FROM `access_token` WHERE (token_last_eight = ?) [d4b41293] - 8.372552405s
Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...auth/access_token.go:174:GetAccessTokenBySHA() [W] [Slow SQL Query] SELECT `id`, `uid`, `name`, `token_hash`, `token_salt`, `token_last_eight`, `scope`, `created_unix`, `updated_unix` FROM `access_token` WHERE (token_last_eight = ?) [d4b41293] - 8.372577691s
Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...ties/notification.go:296:GetUIDsAndNotificationCounts() [W] [Slow SQL Query] SELECT user_id, sum(case when status= ? then 1 else 0 end) AS count FROM notification WHERE user_id IN (SELECT user_id FROM notification WHERE updated_unix >= ? AND updated_unix < ?) GROUP BY user_id [1 1726214886 1726214896] - 31.028956563s
Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...auth/access_token.go:174:GetAccessTokenBySHA() [W] [Slow SQL Query] SELECT `id`, `uid`, `name`, `token_hash`, `token_salt`, `token_last_eight`, `scope`, `created_unix`, `updated_unix` FROM `access_token` WHERE (token_last_eight = ?) [d4b41293] - 9.120132387s

# Client A's request completes
Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...eb/routing/logger.go:102:func1() [I] router: completed GET /ANONYMIZED.git/info/refs?service=git-upload-pack for AAA.AAA.AAA.AAA:35204, 200 OK in 38096.4ms @ repo/githttp.go:517(repo.GetInfoRefs)
# Client E's request completes
Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...eb/routing/logger.go:102:func1() [I] router: completed GET /ANONYMIZED.git/info/refs?service=git-upload-pack for EEE.EEE.EEE.EEE:60660, 200 OK in 9143.2ms @ repo/githttp.go:517(repo.GetInfoRefs)
# Client F's request completes
Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...eb/routing/logger.go:102:func1() [I] router: completed GET /ANONYMIZED.git/info/refs?service=git-upload-pack for FFF.FFF.FFF.FFF:43522, 200 OK in 8396.9ms @ repo/githttp.go:517(repo.GetInfoRefs)
# Client C's request completes
Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...eb/routing/logger.go:102:func1() [I] router: completed GET /ANONYMIZED.git/info/refs?service=git-upload-pack for CCC.CCC.CCC.CCC:53622, 200 OK in 37502.3ms @ repo/githttp.go:517(repo.GetInfoRefs)
# Client B's request completes
Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...eb/routing/logger.go:102:func1() [I] router: completed GET /ANONYMIZED.git/info/refs?service=git-upload-pack for BBB.BBB.BBB.BBB:58500, 200 OK in 37506.9ms @ repo/githttp.go:517(repo.GetInfoRefs)
# Client G's request completes
Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...eb/routing/logger.go:102:func1() [I] router: completed GET /ANONYMIZED.git/info/refs?service=git-upload-pack for GGG.GGG.GGG.GGG:33844, 200 OK in 8402.5ms @ repo/githttp.go:517(repo.GetInfoRefs)

# Followed by a slew of these
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false}
@KimonHoffmann commented on GitHub (Sep 13, 2024): We're running a relatively small instance **in Docker**, backed by **SQLite** and are also observing periodic, extremely long delays for quite some time (I don't remember the exact version, but I do remember it was the one where the GoGit was replaced in favor of the git binary, which is why back then I chalked the added delay up to further optimizations being necessary in interacting with the git binary). Having enabled trace logging now, on **1.22.2** I can confirm the pattern observed by others above. Please note that the following log entries are complete and have only been annotated with comments and anonymized. They implicitly show that while this is going on the *whole instance* is blocked, as indicated by the `upload-pack` pack requests suffering as a result of this. What is common is that there always is a *Dashboard* request in the mix, either explicitly in the form of a `GET /` request, or implicitly in the form of a `GET /user/login` request, which appear to be the requests actually causing the delays/slowdowns. ``` # Client A reported to be slow Sep 13 10:08:14 ANONYMIZED docker[3878067]: 2024/09/13 08:08:14 ...eb/routing/logger.go:68:func1() [W] router: slow GET /ANONYMIZED.git/info/refs?service=git-upload-pack for AAA.AAA.AAA.AAA:35204, elapsed 3469.3ms @ web/web.go:118(web.Routes.webAuth) # Client B reported to be slow Sep 13 10:08:15 ANONYMIZED docker[3878067]: 2024/09/13 08:08:15 ...eb/routing/logger.go:68:func1() [W] router: slow GET /ANONYMIZED.git/info/refs?service=git-upload-pack for BBB.BBB.BBB.BBB:58500, elapsed 3875.2ms @ web/web.go:118(web.Routes.webAuth) # Client C reported to be slow Sep 13 10:08:15 ANONYMIZED docker[3878067]: 2024/09/13 08:08:15 ...eb/routing/logger.go:68:func1() [W] router: slow GET /ANONYMIZED.git/info/refs?service=git-upload-pack for CCC.CCC.CCC.CCC:53622, elapsed 3875.5ms @ web/web.go:118(web.Routes.webAuth) # Client D reported to be slow Sep 13 10:08:42 ANONYMIZED docker[3878067]: 2024/09/13 08:08:42 ...eb/routing/logger.go:68:func1() [W] router: slow GET /user/login for DDD.DDD.DDD.DDD:40112, elapsed 3260.5ms @ auth/auth.go:164(auth.SignIn) # Client E reported to be slow Sep 13 10:08:43 ANONYMIZED docker[3878067]: 2024/09/13 08:08:43 ...eb/routing/logger.go:68:func1() [W] router: slow GET /ANONYMIZED.git/info/refs?service=git-upload-pack for EEE.EEE.EEE.EEE:60660, elapsed 3516.4ms @ web/web.go:118(web.Routes.webAuth) # Client F reported to be slow Sep 13 10:08:44 ANONYMIZED docker[3878067]: 2024/09/13 08:08:44 ...eb/routing/logger.go:68:func1() [W] router: slow GET /ANONYMIZED.git/info/refs?service=git-upload-pack for FFF.FFF.FFF.FFF:43522, elapsed 3770.4ms @ web/web.go:118(web.Routes.webAuth) # Client G reported to be slow Sep 13 10:08:44 ANONYMIZED docker[3878067]: 2024/09/13 08:08:44 ...eb/routing/logger.go:68:func1() [W] router: slow GET /ANONYMIZED.git/info/refs?service=git-upload-pack for GGG.GGG.GGG.GGG:33844, elapsed 3770.4ms @ web/web.go:118(web.Routes.webAuth) # Multiple reports of slow SQL queries Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...auth/access_token.go:174:GetAccessTokenBySHA() [W] [Slow SQL Query] SELECT `id`, `uid`, `name`, `token_hash`, `token_salt`, `token_last_eight`, `scope`, `created_unix`, `updated_unix` FROM `access_token` WHERE (token_last_eight = ?) [d4b41293] - 37.408652439s Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...auth/access_token.go:174:GetAccessTokenBySHA() [W] [Slow SQL Query] SELECT `id`, `uid`, `name`, `token_hash`, `token_salt`, `token_last_eight`, `scope`, `created_unix`, `updated_unix` FROM `access_token` WHERE (token_last_eight = ?) [d4b41293] - 37.40420057s Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...auth/access_token.go:174:GetAccessTokenBySHA() [W] [Slow SQL Query] SELECT `id`, `uid`, `name`, `token_hash`, `token_salt`, `token_last_eight`, `scope`, `created_unix`, `updated_unix` FROM `access_token` WHERE (token_last_eight = ?) [d4b41293] - 37.40442079s Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...ers/web/auth/auth.go:56:autoSignIn() [W] [Slow SQL Query] DELETE FROM `auth_token` WHERE expires_unix<? [1726214920] - 9.408882468s # Client D's request completes Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...eb/routing/logger.go:102:func1() [I] router: completed GET /user/login for DDD.DDD.DDD.DDD:40112, 200 OK in 9793.4ms @ auth/auth.go:164(auth.SignIn) # Multiple reports of slow SQL queries Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...auth/access_token.go:174:GetAccessTokenBySHA() [W] [Slow SQL Query] SELECT `id`, `uid`, `name`, `token_hash`, `token_salt`, `token_last_eight`, `scope`, `created_unix`, `updated_unix` FROM `access_token` WHERE (token_last_eight = ?) [d4b41293] - 8.372552405s Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...auth/access_token.go:174:GetAccessTokenBySHA() [W] [Slow SQL Query] SELECT `id`, `uid`, `name`, `token_hash`, `token_salt`, `token_last_eight`, `scope`, `created_unix`, `updated_unix` FROM `access_token` WHERE (token_last_eight = ?) [d4b41293] - 8.372577691s Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...ties/notification.go:296:GetUIDsAndNotificationCounts() [W] [Slow SQL Query] SELECT user_id, sum(case when status= ? then 1 else 0 end) AS count FROM notification WHERE user_id IN (SELECT user_id FROM notification WHERE updated_unix >= ? AND updated_unix < ?) GROUP BY user_id [1 1726214886 1726214896] - 31.028956563s Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...auth/access_token.go:174:GetAccessTokenBySHA() [W] [Slow SQL Query] SELECT `id`, `uid`, `name`, `token_hash`, `token_salt`, `token_last_eight`, `scope`, `created_unix`, `updated_unix` FROM `access_token` WHERE (token_last_eight = ?) [d4b41293] - 9.120132387s # Client A's request completes Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...eb/routing/logger.go:102:func1() [I] router: completed GET /ANONYMIZED.git/info/refs?service=git-upload-pack for AAA.AAA.AAA.AAA:35204, 200 OK in 38096.4ms @ repo/githttp.go:517(repo.GetInfoRefs) # Client E's request completes Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...eb/routing/logger.go:102:func1() [I] router: completed GET /ANONYMIZED.git/info/refs?service=git-upload-pack for EEE.EEE.EEE.EEE:60660, 200 OK in 9143.2ms @ repo/githttp.go:517(repo.GetInfoRefs) # Client F's request completes Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...eb/routing/logger.go:102:func1() [I] router: completed GET /ANONYMIZED.git/info/refs?service=git-upload-pack for FFF.FFF.FFF.FFF:43522, 200 OK in 8396.9ms @ repo/githttp.go:517(repo.GetInfoRefs) # Client C's request completes Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...eb/routing/logger.go:102:func1() [I] router: completed GET /ANONYMIZED.git/info/refs?service=git-upload-pack for CCC.CCC.CCC.CCC:53622, 200 OK in 37502.3ms @ repo/githttp.go:517(repo.GetInfoRefs) # Client B's request completes Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...eb/routing/logger.go:102:func1() [I] router: completed GET /ANONYMIZED.git/info/refs?service=git-upload-pack for BBB.BBB.BBB.BBB:58500, 200 OK in 37506.9ms @ repo/githttp.go:517(repo.GetInfoRefs) # Client G's request completes Sep 13 10:08:49 ANONYMIZED docker[3878067]: 2024/09/13 08:08:49 ...eb/routing/logger.go:102:func1() [I] router: completed GET /ANONYMIZED.git/info/refs?service=git-upload-pack for GGG.GGG.GGG.GGG:33844, 200 OK in 8402.5ms @ repo/githttp.go:517(repo.GetInfoRefs) # Followed by a slew of these Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:134:GetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} Sep 13 10:08:51 ANONYMIZED docker[3878067]: 2024/09/13 08:08:51 ...les/cache/context.go:147:SetContextData() [W] cache context is expired, may be misused for long-life tasks: &{map[] {{0 0} 0 0 {{} 0} {{} 0}} {13956965971883172490 69352623855275 0x69a7300} false} ```
GiteaMirror commented 2025-11-02 10:16:48 -06:00
Author
Owner
Copy Link

@KimonHoffmann commented on GitHub (Sep 25, 2024):

One more data point to add to this:

Due to my gut feeling telling me that the SQL queries themselves are probably not slow as such (because the same behavior is consistently reported by many people in this discussion spanning a variety of DB backends), but rather are themselves the "victims" of some other activity slowing down the instance (maybe such as e.g. filesystem access to update some recently changed aspects of the git repositories, when showing the dashboard) I tried massively increasing the RAM allocated to the VM running Gitea and I can report that I have not observed slowdowns as bad as before since then.

Before the increase the VM had 16GB of RAM to work with with never more than 2GB active and the rest used as FS cache. With this configuration we had regular delays exceeding 35 seconds, sometimes even exceeding 1 minute(!).

Now the VM has 64GB of RAM to work with. The active size remains at less than 2GB and the rest used FS cache. With this configuration we've only have very few reports of slowness in general and those that were reported normally remained below 10 seconds only a select few (3 to be exact) took longer and not a single one exceeded 13 seconds.

@KimonHoffmann commented on GitHub (Sep 25, 2024): One more data point to add to this: Due to my gut feeling telling me that the SQL queries themselves are probably not slow as such (because the same behavior is consistently reported by many people in this discussion spanning a variety of DB backends), but rather are themselves the "victims" of some other activity slowing down the instance (maybe such as e.g. filesystem access to update some recently changed aspects of the git repositories, when showing the dashboard) I tried *massively* increasing the RAM allocated to the VM running Gitea and I can report that I have *not* observed slowdowns as bad as before since then. Before the increase the VM had 16GB of RAM to work with with never more than 2GB active and the rest used as FS cache. With this configuration we had regular delays exceeding 35 seconds, sometimes even exceeding 1 minute(!). Now the VM has 64GB of RAM to work with. The active size remains at less than 2GB and the rest used FS cache. With this configuration we've only have very few reports of slowness in general and those that were reported normally remained below 10 seconds only a select few (3 to be exact) took longer and not a single one exceeded 13 seconds.
GiteaMirror commented 2025-11-02 10:16:49 -06:00
Author
Owner
Copy Link

@somera commented on GitHub (Sep 25, 2024):

Now the VM has 64GB of RAM to work with.

But in this case you can switch to PostgreSQL. Will be better when gitea is used concurrently.

@somera commented on GitHub (Sep 25, 2024): > Now the VM has 64GB of RAM to work with. But in this case you can switch to PostgreSQL. Will be better when gitea is used concurrently.
GiteaMirror commented 2025-11-02 10:16:49 -06:00
Author
Owner
Copy Link

@KimonHoffmann commented on GitHub (Sep 25, 2024):

Now the VM has 64GB of RAM to work with.

But in this case you can switch to PostgreSQL. Will be better when gitea is used concurrently.

True, but I doubt it would make a difference in the context of this specific issue, as others who have reported the same behavior are using PostgresSQL.

This is one of the reasons why I suspect the root cause of this issue to be something else than the DB backend. The behavior change with extra FS cache alone partially supports this assumption.

@KimonHoffmann commented on GitHub (Sep 25, 2024): > > Now the VM has 64GB of RAM to work with. > > But in this case you can switch to PostgreSQL. Will be better when gitea is used concurrently. True, but I doubt it would make a difference in the context of this specific issue, as others who have reported the same behavior *are* using PostgresSQL. This is one of the reasons why I suspect the root cause of this issue to be something else than the DB backend. The behavior change with extra FS cache alone partially supports this assumption.
GiteaMirror commented 2025-11-02 10:16:49 -06:00
Author
Owner
Copy Link

@lixfel commented on GitHub (Sep 25, 2024):

Due to my gut feeling telling me that the SQL queries themselves are probably not slow as such (because the same behavior is consistently reported by many people in this discussion spanning a variety of DB backends), but rather are themselves the "victims" of some other activity slowing down the instance (maybe such as e.g. filesystem access to update some recently changed aspects of the git repositories, when showing the dashboard) I tried massively increasing the RAM allocated to the VM running Gitea and I can report that I have not observed slowdowns as bad as before since then.

I come to a different conclusion than you: The data presented supports the hypothesis that the SQL queries themselves are the problem. My reports on this issue were on a dedicated server with typically 16+GiB free/file cache memory with the slow times persisting after multiple page loads (when all data should be in the file system cache; the database is significantly smaller). A single page load of a frequently displayed page should never require the loading of multiple Gigabytes of data.

Edit: I suspect the reduction in slow page load times after the memory increase might have more to do with larger caches (due to more available memory) in the database software.

@lixfel commented on GitHub (Sep 25, 2024): > Due to my gut feeling telling me that the SQL queries themselves are probably not slow as such (because the same behavior is consistently reported by many people in this discussion spanning a variety of DB backends), but rather are themselves the "victims" of some other activity slowing down the instance (maybe such as e.g. filesystem access to update some recently changed aspects of the git repositories, when showing the dashboard) I tried _massively_ increasing the RAM allocated to the VM running Gitea and I can report that I have _not_ observed slowdowns as bad as before since then. I come to a different conclusion than you: The data presented supports the hypothesis that the SQL queries themselves are the problem. My reports on this issue were on a dedicated server with typically 16+GiB free/file cache memory with the slow times persisting after multiple page loads (when all data should be in the file system cache; the database is significantly smaller). A single page load of a frequently displayed page should never require the loading of multiple Gigabytes of data. Edit: I suspect the reduction in slow page load times after the memory increase might have more to do with larger caches (due to more available memory) in the database software.
GiteaMirror commented 2025-11-02 10:16:49 -06:00
Author
Owner
Copy Link

@KimonHoffmann commented on GitHub (Sep 25, 2024):

I come to a different conclusion than you: The data presented supports the hypothesis that the SQL queries themselves are the problem. My reports on this issue were on a dedicated server with typically 16+GiB free/file cache memory with the slow times persisting after multiple page loads (when all data should be in the file system cache; the database is significantly smaller).

And this is major difference to the situation I observed, which is why I came to a different conclusion.
In our case the slowdowns were regular, but reloading the dashboard immediately after a slow load did not yield any slowdowns at all (page times in the low millisecond range). The correlation appeared to be with the amount of updates to various repositories that have accumulated since the last view of the dashboard.

Edit: But it could of course very well be that we are actually observing two different issues that just happen to surface under similar circumstances.

@KimonHoffmann commented on GitHub (Sep 25, 2024): > I come to a different conclusion than you: The data presented supports the hypothesis that the SQL queries themselves are the problem. My reports on this issue were on a dedicated server with typically 16+GiB free/file cache memory with the slow times persisting after multiple page loads (when all data should be in the file system cache; the database is significantly smaller). And this is major difference to the situation I observed, which is why I came to a different conclusion. In our case the slowdowns were regular, but reloading the dashboard immediately after a slow load did not yield any slowdowns at all (page times in the low millisecond range). The correlation *appeared* to be with the amount of updates to various repositories that have accumulated since the last view of the dashboard. Edit: But it could of course very well be that we are actually observing two different issues that just happen to surface under similar circumstances.
GiteaMirror commented 2025-11-02 10:16:50 -06:00
Author
Owner
Copy Link

@SoulSeekkor commented on GitHub (Sep 25, 2024):

In our case it made no difference reloading immediately after the slow dashboard load, it ALWAYS loaded incredibly slow. The frustrating part now is that after many months of problematic dashboard loading at least all of this year out of nowhere the slow dashboard loading seems to have stopped happening. This was a week or two before upgrading to 1.22.2 when that came out, so I don't have a way to repo this now unfortunately.

@SoulSeekkor commented on GitHub (Sep 25, 2024): In our case it made no difference reloading immediately after the slow dashboard load, it ALWAYS loaded incredibly slow. The frustrating part now is that after many months of problematic dashboard loading at least all of this year out of nowhere the slow dashboard loading seems to have stopped happening. This was a week or two before upgrading to 1.22.2 when that came out, so I don't have a way to repo this now unfortunately.
GiteaMirror commented 2025-11-02 10:16:50 -06:00
Author
Owner
Copy Link

@lunny commented on GitHub (Sep 25, 2024):

#32127 should be a step to resolve the problem.

@lunny commented on GitHub (Sep 25, 2024): #32127 should be a step to resolve the problem.
GiteaMirror commented 2025-11-02 10:16:50 -06:00
Author
Owner
Copy Link

@yp05327 commented on GitHub (Dec 3, 2024):

Any updates?
#32127 and the backport has been merged and released.

@yp05327 commented on GitHub (Dec 3, 2024): Any updates? #32127 and the backport has been merged and released.
GiteaMirror commented 2025-11-02 10:16:51 -06:00
Author
Owner
Copy Link

@lixfel commented on GitHub (Dec 3, 2024):

Updated to 1.22.4. Its better but not perfect yet with a 4.4 s page load time instead of 15 s.

@lixfel commented on GitHub (Dec 3, 2024): Updated to 1.22.4. Its better but not perfect yet with a 4.4 s page load time instead of 15 s.
GiteaMirror commented 2025-11-02 10:16:51 -06:00
Author
Owner
Copy Link

@lunny commented on GitHub (Dec 3, 2024):

Updated to 1.22.4. Its better but not perfect yet with a 4.4 s page load time instead of 15 s.

Please upload some logs and Pprof diagnose reports.

@lunny commented on GitHub (Dec 3, 2024): > Updated to 1.22.4. Its better but not perfect yet with a 4.4 s page load time instead of 15 s. Please upload some logs and Pprof diagnose reports.
GiteaMirror commented 2025-11-02 10:16:51 -06:00
Author
Owner
Copy Link

@lixfel commented on GitHub (Dec 26, 2024):

I did not manage to get pprof running (the port 6060 used by ENABLE_PPROF just returned 404 to me), but got a relevant log excerpt:

2024/12/26 11:15:51 ...eb/routing/logger.go:68:func1() [W] router: slow      GET / for 93.224.168.78:0, elapsed 3584.9ms @ web/home.go:32(web.Home)
2024/12/26 11:15:54 ...activities/action.go:465:GetFeeds() [W] [Slow SQL Query] SELECT count(*) FROM `action` WHERE user_id=? AND is_deleted=? [1 false] - 6.459664284s

Context: 108k Actions total, 29.5k Undeleted actions from my user

Using analyze select on the query:

ANALYZE SELECT COUNT(*) FROM `action` WHERE user_id = 1 AND is_deleted = 0;
1	SIMPLE	action	ref	IDX_action_user_id	IDX_action_user_id	9	const	53944	29553.00	100.00	100.00	Using where

Removing the is_deleted clause accelerates the query to instantaneous.

@lixfel commented on GitHub (Dec 26, 2024): I did not manage to get pprof running (the port 6060 used by ENABLE_PPROF just returned 404 to me), but got a relevant log excerpt: ``` 2024/12/26 11:15:51 ...eb/routing/logger.go:68:func1() [W] router: slow GET / for 93.224.168.78:0, elapsed 3584.9ms @ web/home.go:32(web.Home) 2024/12/26 11:15:54 ...activities/action.go:465:GetFeeds() [W] [Slow SQL Query] SELECT count(*) FROM `action` WHERE user_id=? AND is_deleted=? [1 false] - 6.459664284s ``` Context: 108k Actions total, 29.5k Undeleted actions from my user Using analyze select on the query: ``` ANALYZE SELECT COUNT(*) FROM `action` WHERE user_id = 1 AND is_deleted = 0; 1 SIMPLE action ref IDX_action_user_id IDX_action_user_id 9 const 53944 29553.00 100.00 100.00 Using where ``` Removing the `is_deleted` clause accelerates the query to instantaneous.
GiteaMirror commented 2025-11-02 10:16:51 -06:00
Author
Owner
Copy Link

@lunny commented on GitHub (Dec 26, 2024):

This problem should be fixed by #31821 and will be released on v1.23

@lunny commented on GitHub (Dec 26, 2024): This problem should be fixed by #31821 and will be released on v1.23
GiteaMirror commented 2025-11-02 10:16:51 -06:00
Author
Owner
Copy Link

@SoulSeekkor commented on GitHub (Jan 10, 2025):

Can confirm that the issue seems to be resolved all around for me.

@SoulSeekkor commented on GitHub (Jan 10, 2025): Can confirm that the issue seems to be resolved all around for me.
GiteaMirror commented 2025-11-02 10:16:52 -06:00
Author
Owner
Copy Link

@lunny commented on GitHub (Jan 10, 2025):

Closed at the moment. Please fire a new issue if a similar problem occurs.

@lunny commented on GitHub (Jan 10, 2025): Closed at the moment. Please fire a new issue if a similar problem occurs.
Sign in to join this conversation.
No Branch/Tag Specified
Branches Tags
Labels
Clear labels
$20
$250
$50
$500
backport/done
💎 Bounty
docs-update-needed
good first issue
hacktoberfest
issue/bounty
issue/confirmed
issue/critical
issue/duplicate
issue/needs-feedback
issue/not-a-bug
issue/regression
issue/stale
issue/workaround
lgtm/need 2
modifies/api
modifies/translation
outdated/backport/v1.18
outdated/theme/markdown
outdated/theme/timetracker
performance/bigrepo
performance/cpu
performance/memory
performance/speed
pr/breaking
proposal/accepted
proposal/rejected
pr/wip
pull-request
Mirrored from GitHub Pull Request
 reviewed/wontfix
💰 Rewarded
skip-changelog
status/blocked
topic/accessibility
topic/api
topic/authentication
topic/build
topic/code-linting
topic/commit-signing
topic/content-rendering
topic/deployment
topic/distribution
topic/federation
topic/gitea-actions
topic/issues
topic/lfs
topic/mobile
topic/moderation
topic/packages
topic/pr
topic/projects
topic/repo
topic/repo-migration
topic/security
topic/theme
topic/ui
topic/ui-interaction
topic/ux
topic/webhooks
topic/wiki
type/bug
type/deprecation
type/docs
type/enhancement
type/feature
type/miscellaneous
type/proposal
type/question
type/refactoring
type/summary
type/testing
type/upstream
No Label issue/needs-feedback performance/speed type/bug
Milestone
No items
No Milestone
Projects
Clear projects
No project
Assignees
Clear assignees
GiteaMirror ninjasurge
No Assignees
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: github-starred/gitea#12638
Delete Branch "%!s()"

Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?