PR Diff View takes a very long time to load: failed to run attr-check: context deadline exceeded

[engaltori]

Description

Hello,

Since the update from 1.21.11 to 1.22.1 I have a problem displaying the differences of commits/PRs.
It takes several minutes for the pages to appear at all.

On the Stacktrace Page of Gitea i see that Gitea stuck on these commands:

• /usr/bin/git cat-file --batch-check [repo_path: /data/git/repositories/test/test.git] (modules/gitrepo/gitrepo.go:31)
• /usr/bin/git cat-file --batch [repo_path: /data/git/repositories/test/test.git] (modules/gitrepo/gitrepo.go:31)
• git(dir:/data/git/repositories/test/test.git): /usr/bin/git -c protocol.version=2 -c credential.helper= -c filter.lfs.required= -c filter.lfs.smudge= -c filter.lfs.clean= check-attr --stdin -z --cached linguist-vendored linguist-generated linguist-documentation linguist-detectable linguist-language gitlab-language

All these Git processes are in sleep state according to the system.

The Full log of Gitea is in the Gist. The Git check-attr Command start on line 17421 and Ends on Line 53584 with a Error : failed to run attr-check. Error: context deadline exceeded

I cannot reproduce this issue in other Repos. The Issue is only in some PRs of this Repo (Mostly the ones with many files (>50)). The Repo has more than 9909 Commit with currently 280 Branches with a Size of 360 MiB (Git 152 MiB, LFS: 208 MiB).

Other Fact: When i run strace on the Gitea Process with all Childs, then this Issue does not occur.

Gitea Version

1.22.1

Can you reproduce the bug on the Gitea demo site?

No

Log Gist

https://gist.github.com/andre-bergemann/580e08a7a4fdb44b67b3a1664375c6d7

Screenshots

No response

Git Version

2.45.2

Operating System

Ubuntu

How are you running Gitea?

Custom Container (For Gitea Config Changes) of the Gitea Docker Image (gitea/gitea:1.22.1) on Ubuntu 22.04.2 VM with Docker Engine 23.0.1

Database

PostgreSQL

[juanpablo-santos]

Hi,

we're experiencing the same issue, also after migrating to 1.22.1. We're also using a custom docker image, based on the official one, with a mysql database

[phyr0s]

Same error here!

[techknowlogick]

@juanpablo-santos are you able to post your customizations?

[juanpablo-santos]

Hi,

on the Dockerfile side, we copy some certificates, some gitea customizations (labels, license, hooks, README) and we set up GPG, asciidoctor and python, so we can render asciidoc files, upyter notebooks and restructuredtext. So, nothing fancy.

Our app.ini file is more or less this:

APP_NAME = XYZ Gitea: Git with a cup of tea
RUN_MODE = prod
RUN_USER = git
WORK_PATH = /data/gitea

[admin]
DISABLE_REGULAR_ORG_CREATION = false

[api]
MAX_RESPONSE_ITEMS = 500
DEFAULT_PAGING_NUM = 300

[attachment]
PATH = /data/gitea/attachments

; Cleanup hook_task table
[cron.cleanup_hook_task_table]
; Whether to enable the job
ENABLED = true
; Whether to always run at start up time (if ENABLED)
RUN_AT_START = false
; Time interval for job to run
SCHEDULE = @midnight
; OlderThan or PerWebhook. How the records are removed, either by age (i.e. how long ago hook_task record was delivered) or by the number to keep per webhook (i.e. keep most recent x deliveries per webhook).
CLEANUP_TYPE = PerWebhook
; If CLEANUP_TYPE is set to OlderThan, then any delivered hook_task records older than this expression will be deleted.
OLDER_THAN = 168h
; If CLEANUP_TYPE is set to PerWebhook, this is number of hook_task records to keep for a webhook (i.e. keep the most recent x deliveries).
NUMBER_TO_KEEP = 10

[cron.delete_old_actions]
; Whether to enable the job
ENABLED = true
; Whether to always run at start up time (if ENABLED)
RUN_AT_START = false
; Time interval for job to run
SCHEDULE = @weekly
; If CLEANUP_TYPE is set to OlderThan, then any delivered hook_task records older than this expression will be deleted.
OLDER_THAN = 2160h

[cron.delete_old_system_notices]
; Whether to enable the job
ENABLED = true
; Whether to always run at start up time (if ENABLED)
RUN_AT_START = false
; Time interval for job to run
SCHEDULE = @midnight
; If CLEANUP_TYPE is set to OlderThan, then any delivered hook_task records older than this expression will be deleted.
OLDER_THAN = 168h

[database]
PATH = /data/gitea/gitea.db
DB_TYPE = mysql
HOST = db:3306
NAME = gitea
USER = XXXXXXXXX
PASSWD = XXXXXXXXX
SSL_MODE = disable

[indexer]
ISSUE_INDEXER_PATH = indexers/issues.bleve
; repo indexer by default disabled, since it uses a lot of disk space
REPO_INDEXER_ENABLED = false
REPO_INDEXER_PATH = indexers/repos.bleve
MAX_FILE_SIZE = 1048576

[queue.issue_indexer]
LENGTH = 20

[git]
HOME_PATH = /data/git

[log]
ROOT_PATH = /data/gitea/log
MODE = file
LEVEL = Error

[mailer]
ENABLED = true
FROM = "Gitea CI/CD" <gitea-noreply@cicd.XYZ.XZ>
SMTP_ADDR = mail.XYZ.XZ
SMTP_PORT = 25
USER = XXXXXXXXX
PASSWD = XXXXXXXXX
FORCE_TRUST_SERVER_CERT = true
SUBJECT_PREFIX = [GITEA]

[migrations]
ALLOW_LOCALNETWORKS = true

[openid]
ENABLE_OPENID_SIGNIN = false
ENABLE_OPENID_SIGNUP = false

[picture]
AVATAR_UPLOAD_PATH = /data/gitea/avatars
DISABLE_GRAVATAR = true
ENABLE_FEDERATED_AVATAR = false

[repository]
ROOT = /data/git/repositories
DEFAULT_BRANCH = master

[repository.pull-request]
WORK_IN_PROGRESS_PREFIXES = WIP:,[WIP]:,WIP,[WIP]

[repository.signing]
# SIGNING_KEY     = default
SIGNING_KEY = XXXXXXXXX
SIGNING_NAME = XXXXXXXXX
SIGNING_EMAIL = XXXXXXXXX@XYZ.XZ
INITIAL_COMMIT = always
CRUD_ACTIONS = always
WIKI = always
MERGES = always

[repository.upload]
TEMP_PATH = /data/gitea/uploads

[security]
DISABLE_GIT_HOOKS = false
INSTALL_LOCK = true
INTERNAL_TOKEN = XXXXXXXXX
SECRET_KEY = XXXXXXXXX

[service]
AUTO_WATCH_NEW_REPOS = false
REGISTER_EMAIL_CONFIRM = false
ENABLE_NOTIFY_MAIL = true
DISABLE_REGISTRATION = true
ENABLE_CAPTCHA = false
REQUIRE_SIGNIN_VIEW = true
DEFAULT_KEEP_EMAIL_PRIVATE = false
DEFAULT_ALLOW_CREATE_ORGANIZATION = false
DEFAULT_ENABLE_TIMETRACKING = true
NO_REPLY_ADDRESS = noreply.XYZ.XZ
ENABLE_USER_HEATMAP = true

[server]
APP_DATA_PATH = /data/gitea
SSH_DOMAIN = ssh.XYZ.XZ
HTTP_PORT = 3000
ROOT_URL = https://XXXXXXXXX/git/
DISABLE_SSH = false
SSH_PORT = 22
DOMAIN = XXXXXXXXX
OFFLINE_MODE = false
LFS_START_SERVER = true
LFS_JWT_SECRET = XXXXXXXXX

[lfs]
PATH = /data/gitea/lfs

[session]
PROVIDER_CONFIG = /data/gitea/sessions
PROVIDER = file

[metrics]
ENABLED = true
ENABLED_ISSUE_BY_REPOSITORY = true

[markup.asciidoc]
ENABLED = true
FILE_EXTENSIONS = .adoc,.asciidoc
RENDER_COMMAND = asciidoctor --out-file=- -
; Input is not a standard input but a file
IS_INPUT_FILE = false

[markup.jupyter]
ENABLED = true
FILE_EXTENSIONS = .ipynb
RENDER_COMMAND = jupyter nbconvert --stdout --to html --template basic
IS_INPUT_FILE = true

[markup.restructuredtext]
ENABLED = true
FILE_EXTENSIONS = .rst
RENDER_COMMAND = rst2html.py
IS_INPUT_FILE = false

[oauth2]
JWT_SECRET = XXXXXXXXX

[webhook]
ALLOWED_HOST_LIST = *
SKIP_TLS_VERIFY = true
DELIVER_TIMEOUT = 15

[ui.notification]
MIN_TIMEOUT = 0s

[juanpablo-santos]

Hi,

we've noticed that having a high amount of branches might be involved on the long time to load. In our case one of the "usual" repos that suffers from this issue contains:

• +25000 commits
• +6600 closed PRs
• 224MB
• 192 tags, 33 releases
• 127 branches, aprox. 90% of them closed or merged, the oldest ones being from 2 years ago

Proceeded to delete oldest merged / closed branches, so the repo is up to 73 branches now, we've noticed an increase in performance; it's still slow, but now is manageable

HTH,

[juanpablo-santos]

Hi,

we've noticed that when we hit this issue, also going to the PR's commits also results in waiting a long time before they show up, so may be the diff view takes to long b/c of waiting a lot on retrieving the commits info? Some times all the commits of the PR take a long time, some times some commits involved in the PR take a long time to load. When loading those commits, at the Stacktrace Page of Gitea, I see that Gitea stuck on these commands:

code.gitea.io/gitea/modules/git.CatFileBatchCheck.func2 graceful-lifecycle with-hammer
  runtime.gopark
  /usr/local/go/src/runtime/proc.go:402
  runtime.chanrecv
  /usr/local/go/src/runtime/chan.go:583
  runtime.chanrecv1
  /usr/local/go/src/runtime/chan.go:442
  code.gitea.io/gitea/modules/git.CatFileBatchCheck.func2
  /go/src/code.gitea.io/gitea/modules/git/batch_reader.go:61
code.gitea.io/gitea/modules/git.CatFileBatch.func2 graceful-lifecycle with-hammer
  runtime.gopark
  /usr/local/go/src/runtime/proc.go:402
  runtime.chanrecv
  /usr/local/go/src/runtime/chan.go:583
  runtime.chanrecv1
  /usr/local/go/src/runtime/chan.go:442
  code.gitea.io/gitea/modules/git.CatFileBatch.func2
  /go/src/code.gitea.io/gitea/modules/git/batch_reader.go:113
code.gitea.io/gitea/modules/web.toHandlerProvider.func1.1 graceful-lifecycle with-hammer
  runtime.gopark
  /usr/local/go/src/runtime/proc.go:402
  runtime.netpollblock
  /usr/local/go/src/runtime/netpoll.go:573
  internal/poll.runtime_pollWait
  /usr/local/go/src/runtime/netpoll.go:345
  internal/poll.(*pollDesc).wait
  /usr/local/go/src/internal/poll/fd_poll_runtime.go:84
  internal/poll.(*pollDesc).waitRead
  /usr/local/go/src/internal/poll/fd_poll_runtime.go:89
  internal/poll.(*FD).Read
  /usr/local/go/src/internal/poll/fd_unix.go:164
  net.(*netFD).Read
  /usr/local/go/src/net/fd_posix.go:55
  net.(*conn).Read
  /usr/local/go/src/net/net.go:185
  github.com/go-sql-driver/mysql.(*buffer).fill
  /go/pkg/mod/github.com/go-sql-driver/mysql@v1.8.0/buffer.go:90
  github.com/go-sql-driver/mysql.(*buffer).readNext
  /go/pkg/mod/github.com/go-sql-driver/mysql@v1.8.0/buffer.go:119
  github.com/go-sql-driver/mysql.(*mysqlConn).readPacket
  /go/pkg/mod/github.com/go-sql-driver/mysql@v1.8.0/packets.go:32
  github.com/go-sql-driver/mysql.(*okHandler).readResultSetHeaderPacket
  /go/pkg/mod/github.com/go-sql-driver/mysql@v1.8.0/packets.go:531
  github.com/go-sql-driver/mysql.(*mysqlStmt).query
  /go/pkg/mod/github.com/go-sql-driver/mysql@v1.8.0/statement.go:111
  github.com/go-sql-driver/mysql.(*mysqlStmt).QueryContext
  /go/pkg/mod/github.com/go-sql-driver/mysql@v1.8.0/connection.go:564
  database/sql.ctxDriverStmtQuery
  /usr/local/go/src/database/sql/ctxutil.go:82
  database/sql.rowsiFromStatement
  /usr/local/go/src/database/sql/sql.go:2836
  database/sql.(*DB).queryDC
  /usr/local/go/src/database/sql/sql.go:1806
  database/sql.(*DB).query
  /usr/local/go/src/database/sql/sql.go:1754
  database/sql.(*DB).QueryContext.func1
  /usr/local/go/src/database/sql/sql.go:1732
  database/sql.(*DB).retry
  /usr/local/go/src/database/sql/sql.go:1566
  database/sql.(*DB).QueryContext
  /usr/local/go/src/database/sql/sql.go:1731
  xorm.io/xorm/core.(*DB).QueryContext
  /go/pkg/mod/xorm.io/xorm@v1.3.8/core/db.go:151
  xorm.io/xorm.(*Session).queryRows
  /go/pkg/mod/xorm.io/xorm@v1.3.8/session_raw.go:52
  xorm.io/xorm.(*Session).noCacheFind
  /go/pkg/mod/xorm.io/xorm@v1.3.8/session_find.go:235
  xorm.io/xorm.(*Session).find
  /go/pkg/mod/xorm.io/xorm@v1.3.8/session_find.go:163
  xorm.io/xorm.(*Session).Find
  /go/pkg/mod/xorm.io/xorm@v1.3.8/session_find.go:33
  code.gitea.io/gitea/models/repo.GetRepoAssignees
  /go/src/code.gitea.io/gitea/models/repo/user_repo.go:109
  code.gitea.io/gitea/routers/web/repo.viewPullFiles
  /go/src/code.gitea.io/gitea/routers/web/repo/pull.go:811
  code.gitea.io/gitea/routers/web/repo.ViewPullFilesForSingleCommit
  /go/src/code.gitea.io/gitea/routers/web/repo/pull.go:889
  reflect.Value.call
  /usr/local/go/src/reflect/value.go:596
  reflect.Value.Call
  /usr/local/go/src/reflect/value.go:380
code.gitea.io/gitea/modules/web.toHandlerProvider.func1.1
  github.com/go-sql-driver/mysql.(*mysqlConn).startWatcher.func1 graceful-lifecycle with-hammer
  runtime.gopark
  /usr/local/go/src/runtime/proc.go:402
  runtime.selectgo
  /usr/local/go/src/runtime/select.go:327
  github.com/go-sql-driver/mysql.(*mysqlConn).startWatcher.func1
  /go/pkg/mod/github.com/go-sql-driver/mysql@v1.8.0/connection.go:626

we've updated to 1.22.2 to see if #31754 would help, but long times still persist

[lunny]

#31754 just delays the cat file commands invocation to avoid unnecessary usage of that command.

[juanpablo-santos]

Hi,

issue doesn't seem related to big repos, we've just experienced the same issue on a PR of a repo with:

• +6200 commits
• +1200 closed PRs
• 315MB
• 131 tags, 14 releases
• 16 branches, the oldest ones being from 4 years ago, the rest updated between 5 days and 4 months ago, 6 of them open

The PR experiencing this issue had 6 commits, 3 of them taking a really long time to render.

Oh, and one last note, the files' rendering seems to always take around six minutes?

[juanpablo-santos]

One more update, as the six minutes waiting seem to be the git default timeout, we've set

[git.timeout]
DEFAULT = 60

after that, we wait, hit one minute, and the diff of the PR/commit appears. Not sure anything is missing, everything seems in place :-?

[lschwahn]

@juanpablo-santos thanks for the hint. We’ve been encountering the same error with some PRs/diffs since version 1.22. Reducing the git.timeout seems to be a workaround.