Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

repos/pulls api take long time for large repos #31492

Closed
GammaGames opened this issue Jun 25, 2024 · 14 comments · Fixed by #32680
Closed

repos/pulls api take long time for large repos #31492

GammaGames opened this issue Jun 25, 2024 · 14 comments · Fixed by #32680
Assignees
@lunny
Labels
performance/speed performance issues with slow downs topic/api Concerns mainly the API type/bug
Milestone
1.23.0

Comments

@GammaGames
Copy link

Description

I'm working with renovate which makes calls to api/v1/repos/org/repo/pulls?state=all&sort=recentupdate&page=[page]. At pages 8+ the requests take a long time. Looking at htop it's because the git diff command is blocking.
This is likely because my repo had a large restructure, loading the diffs on the gitea web app is also very slow.

/usr/bin/git -c protocol.version=2 -c credential.helper= -c filter.lfs.required= -c filter.lfs.smudge= -c filter.lfs.clean= diff --shortstat [left]...[right]

Is there any way to cache diffs or any config I can use to speed them up? My current workaround is to set the request timeout to 5 min in renovate

Gitea Version

1.22.0

Can you reproduce the bug on the Gitea demo site?

No

Log Gist

https://gist.github.com/GammaGames/b1ae6715c8a66da638ee181ed6f93da1

Screenshots

image

Git Version

No response

Operating System

No response

How are you running Gitea?

Docker compose:

services:
  gitea:
    image: gitea/gitea:1
    container_name: gitea
    environment:
      USER_UID: 1001
      USER_GID: 1001
    restart: unless-stopped
    volumes:
      - ./gitea:/data
    ports:
      - 127.0.0.1:3001:3000
      - 127.0.0.1:2222:22

Database

SQLite
@yp05327 yp05327 added performance/speed performance issues with slow downs topic/api Concerns mainly the API labels Jun 27, 2024
@xoxys
Copy link
Contributor

xoxys commented Jul 30, 2024

Facing the same issue while using Postgres.

@LazyDodo
Copy link
Contributor

another poke, i'm facing the same issue on projects.blenders.org tracker, but rather than a long wait and still giving the data, their server just gives a 504 Gateway Time-out after a bit making this endpoint unusable.

running a git diff --shortstat every time someone queries the open PR's seems a bit fishy, ideally this is cached somewhere when a PR is updated, especially since this is seemingly an expensive operation to execute.

@lunny
Copy link
Member

lunny commented Oct 31, 2024

another poke, i'm facing the same issue on projects.blenders.org tracker, but rather than a long wait and still giving the data, their server just gives a 504 Gateway Time-out after a bit making this endpoint unusable.

running a git diff --shortstat every time someone queries the open PR's seems a bit fishy, ideally this is cached somewhere when a PR is updated, especially since this is seemingly an expensive operation to execute.

Can you post the link?

@LazyDodo
Copy link
Contributor

I'm not entirely sure what you're asking? the link to what?

the fact shortstat somehow runs i got from the opening post in this ticket, the failing call on the blender server you can repro with curl -v "https://projects.blender.org/api/v1/repos/blender/blender/pulls?state=all&sort=oldest"

if it's something else you're looking for happy to help but you're gonna have to be a bit more specific :)

@GammaGames
Copy link
Author

I was curious what these long running commands look like, so I copied a few and ran them locally. I had to run git config diff.renamelimit 999999 first but they all return "13973 files changed, 824628 insertions(+), 75683 deletions(-)" (with different numbers). I think they're comparing old commits against the latest commit on each branch, but it's a little hard to follow

@lunny
Copy link
Member

lunny commented Nov 2, 2024 •
edited
Loading

curl -v "https://projects.blender.org/api/v1/repos/blender/blender/pulls?state=all&sort=oldest"

It's very strange because the web request https://projects.blender.org/blender/blender/pulls is very fast.

If you can provide some logs about this API requests, that's better.

@wxiaoguang
Copy link
Contributor

At pages 8+ the requests take a long time.

If the loading time increases for all "old" pages, it seems to be a SQL index or optimizer problem. In many cases LIMIT 1, 10 is faster than LIMIT 200, 10.

@LazyDodo
Copy link
Contributor

LazyDodo commented Nov 2, 2024

If you can provide some logs about this API requests, that's better

I'm not in control of that server, but i'll prod blender devops, they should be able to dig up whatever you need, could be a few days though, hang tight!

@bartvdbraak
Copy link

The following logging is what I could drum up:

https://projects.blender.org/api/v1/repos/blender/blender/pulls?state=all&sort=oldest

# gitea.log
2024/11/18 12:12:57 ...eb/routing/logger.go:102:func1() [I] router: completed GET /api/v1/repos/blender/blender/pulls?state=all&sort=oldest for <redacted_ip>:0, 500 Internal Server Error in 60024.3ms @ repo/pull.go:46(repo.ListPullRequests)
Stacktrace in /admin/monitor/stacktrace?show=process 
# GET: /api/v1/repos/blender/blender/pulls?state=all&sort=oldest
# 2024-11-18 12:11:57 +01:00
    <> code.gitea.io/gitea/modules/git.CatFileBatchCheck.func2 * 3
    <> 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
      /home/git/builds/gitea/modules/git/batch_reader.go:61
    <> code.gitea.io/gitea/modules/git.CatFileBatch.func2 * 3
    <> 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
      /home/git/builds/gitea/modules/git/batch_reader.go:113
  # /usr/bin/git cat-file --batch [repo_path: /gitea/work_dir/data/gitea-repositories/blender/blender.git] (modules/gitrepo/gitrepo.go:31)
  # 2024-11-18 12:12:34 +01:00
    <> os/exec.(*Cmd).Start.func2 * 2
    <> 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
      os.(*File).read
      /usr/local/go/src/os/file_posix.go:29
      os.(*File).Read
      /usr/local/go/src/os/file.go:118
      io.copyBuffer
      /usr/local/go/src/io/io.go:429
      io.Copy
      /usr/local/go/src/io/io.go:388
      os.genericWriteTo
      /usr/local/go/src/os/file.go:269
      os.(*File).WriteTo
      /usr/local/go/src/os/file.go:247
      io.copyBuffer
      /usr/local/go/src/io/io.go:411
      io.Copy
      /usr/local/go/src/io/io.go:388
      os/exec.(*Cmd).writerDescriptor.func1
      /usr/local/go/src/os/exec/exec.go:577
      os/exec.(*Cmd).Start.func2
      /usr/local/go/src/os/exec/exec.go:724
    <> os/exec.(*Cmd).Start.func2
    <> graceful-lifecycle
    <> with-hammer
      runtime.gopark
      /usr/local/go/src/runtime/proc.go:402
      runtime.selectgo
      /usr/local/go/src/runtime/select.go:327
      io.(*pipe).read
      /usr/local/go/src/io/pipe.go:57
      io.(*PipeReader).Read
      /usr/local/go/src/io/pipe.go:134
      io.copyBuffer
      /usr/local/go/src/io/io.go:429
      io.Copy
      /usr/local/go/src/io/io.go:388
      os.genericReadFrom
      /usr/local/go/src/os/file.go:179
      os.(*File).ReadFrom
      /usr/local/go/src/os/file.go:155
      io.copyBuffer
      /usr/local/go/src/io/io.go:415
      io.Copy
      /usr/local/go/src/io/io.go:388
      os/exec.(*Cmd).childStdin.func1
      /usr/local/go/src/os/exec/exec.go:528
      os/exec.(*Cmd).Start.func2
      /usr/local/go/src/os/exec/exec.go:724
    <> os/exec.(*Cmd).watchCtx
    <> graceful-lifecycle
    <> with-hammer
      runtime.gopark
      /usr/local/go/src/runtime/proc.go:402
      runtime.selectgo
      /usr/local/go/src/runtime/select.go:327
      os/exec.(*Cmd).watchCtx
      /usr/local/go/src/os/exec/exec.go:764
    <> code.gitea.io/gitea/modules/git.CatFileBatch.func3
    <> graceful-lifecycle
    <> with-hammer
      syscall.Syscall6
      /usr/local/go/src/syscall/syscall_linux.go:91
      os.(*Process).blockUntilWaitable
      /usr/local/go/src/os/wait_waitid.go:32
      os.(*Process).wait
      /usr/local/go/src/os/exec_unix.go:22
      os.(*Process).Wait
      /usr/local/go/src/os/exec.go:134
      os/exec.(*Cmd).Wait
      /usr/local/go/src/os/exec/exec.go:897
      code.gitea.io/gitea/modules/git.(*Command).Run
      /home/git/builds/gitea/modules/git/command.go:342
      code.gitea.io/gitea/modules/git.CatFileBatch.func3
      /home/git/builds/gitea/modules/git/batch_reader.go:124
  # /usr/bin/git cat-file --batch-check [repo_path: /gitea/work_dir/data/gitea-repositories/mano-wii/blender.git] (modules/gitrepo/gitrepo.go:31)
  # 2024-11-18 12:12:34 +01:00
    <> os/exec.(*Cmd).Start.func2 * 2
    <> 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
      os.(*File).read
      /usr/local/go/src/os/file_posix.go:29
      os.(*File).Read
      /usr/local/go/src/os/file.go:118
      io.copyBuffer
      /usr/local/go/src/io/io.go:429
      io.Copy
      /usr/local/go/src/io/io.go:388
      os.genericWriteTo
      /usr/local/go/src/os/file.go:269
      os.(*File).WriteTo
      /usr/local/go/src/os/file.go:247
      io.copyBuffer
      /usr/local/go/src/io/io.go:411
      io.Copy
      /usr/local/go/src/io/io.go:388
      os/exec.(*Cmd).writerDescriptor.func1
      /usr/local/go/src/os/exec/exec.go:577
      os/exec.(*Cmd).Start.func2
      /usr/local/go/src/os/exec/exec.go:724
    <> os/exec.(*Cmd).Start.func2
    <> graceful-lifecycle
    <> with-hammer
      runtime.gopark
      /usr/local/go/src/runtime/proc.go:402
      runtime.selectgo
      /usr/local/go/src/runtime/select.go:327
      io.(*pipe).read
      /usr/local/go/src/io/pipe.go:57
      io.(*PipeReader).Read
      /usr/local/go/src/io/pipe.go:134
      io.copyBuffer
      /usr/local/go/src/io/io.go:429
      io.Copy
      /usr/local/go/src/io/io.go:388
      os.genericReadFrom
      /usr/local/go/src/os/file.go:179
      os.(*File).ReadFrom
      /usr/local/go/src/os/file.go:155
      io.copyBuffer
      /usr/local/go/src/io/io.go:415
      io.Copy
      /usr/local/go/src/io/io.go:388
      os/exec.(*Cmd).childStdin.func1
      /usr/local/go/src/os/exec/exec.go:528
      os/exec.(*Cmd).Start.func2
      /usr/local/go/src/os/exec/exec.go:724
    <> os/exec.(*Cmd).watchCtx
    <> graceful-lifecycle
    <> with-hammer
      runtime.gopark
      /usr/local/go/src/runtime/proc.go:402
      runtime.selectgo
      /usr/local/go/src/runtime/select.go:327
      os/exec.(*Cmd).watchCtx
      /usr/local/go/src/os/exec/exec.go:764
    <> code.gitea.io/gitea/modules/git.CatFileBatchCheck.func3
    <> graceful-lifecycle
    <> with-hammer
      syscall.Syscall6
      /usr/local/go/src/syscall/syscall_linux.go:91
      os.(*Process).blockUntilWaitable
      /usr/local/go/src/os/wait_waitid.go:32
      os.(*Process).wait
      /usr/local/go/src/os/exec_unix.go:22
      os.(*Process).Wait
      /usr/local/go/src/os/exec.go:134
      os/exec.(*Cmd).Wait
      /usr/local/go/src/os/exec/exec.go:897
      code.gitea.io/gitea/modules/git.(*Command).Run
      /home/git/builds/gitea/modules/git/command.go:342
      code.gitea.io/gitea/modules/git.CatFileBatchCheck.func3
      /home/git/builds/gitea/modules/git/batch_reader.go:72
  # /usr/bin/git cat-file --batch [repo_path: /gitea/work_dir/data/gitea-repositories/mano-wii/blender.git] (modules/gitrepo/gitrepo.go:31)
  # 2024-11-18 12:12:34 +01:00
    <> os/exec.(*Cmd).Start.func2 * 2
    <> 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
      os.(*File).read
      /usr/local/go/src/os/file_posix.go:29
      os.(*File).Read
      /usr/local/go/src/os/file.go:118
      io.copyBuffer
      /usr/local/go/src/io/io.go:429
      io.Copy
      /usr/local/go/src/io/io.go:388
      os.genericWriteTo
      /usr/local/go/src/os/file.go:269
      os.(*File).WriteTo
      /usr/local/go/src/os/file.go:247
      io.copyBuffer
      /usr/local/go/src/io/io.go:411
      io.Copy
      /usr/local/go/src/io/io.go:388
      os/exec.(*Cmd).writerDescriptor.func1
      /usr/local/go/src/os/exec/exec.go:577
      os/exec.(*Cmd).Start.func2
      /usr/local/go/src/os/exec/exec.go:724
      os/exec.(*Cmd).Start.func2
    <> graceful-lifecycle
    <> with-hammer
    <> runtime.gopark
      /usr/local/go/src/runtime/proc.go:402
      runtime.selectgo
      /usr/local/go/src/runtime/select.go:327
      io.(*pipe).read
      /usr/local/go/src/io/pipe.go:57
      io.(*PipeReader).Read
      /usr/local/go/src/io/pipe.go:134
      io.copyBuffer
      /usr/local/go/src/io/io.go:429
      io.Copy
      /usr/local/go/src/io/io.go:388
      os.genericReadFrom
      /usr/local/go/src/os/file.go:179
      os.(*File).ReadFrom
      /usr/local/go/src/os/file.go:155
      io.copyBuffer
      /usr/local/go/src/io/io.go:415
      io.Copy
      /usr/local/go/src/io/io.go:388
      os/exec.(*Cmd).childStdin.func1
      /usr/local/go/src/os/exec/exec.go:528
      os/exec.(*Cmd).Start.func2
      /usr/local/go/src/os/exec/exec.go:724
    <> os/exec.(*Cmd).watchCtx
    <> graceful-lifecycle
    <> with-hammer
      runtime.gopark
      /usr/local/go/src/runtime/proc.go:402
      runtime.selectgo
      /usr/local/go/src/runtime/select.go:327
      os/exec.(*Cmd).watchCtx
      /usr/local/go/src/os/exec/exec.go:764
    <> code.gitea.io/gitea/modules/git.CatFileBatch.func3
    <> graceful-lifecycle
    <> with-hammer
      syscall.Syscall6
      /usr/local/go/src/syscall/syscall_linux.go:91
      os.(*Process).blockUntilWaitable
      /usr/local/go/src/os/wait_waitid.go:32
      os.(*Process).wait
      /usr/local/go/src/os/exec_unix.go:22
      os.(*Process).Wait
      /usr/local/go/src/os/exec.go:134
      os/exec.(*Cmd).Wait
      /usr/local/go/src/os/exec/exec.go:897
      code.gitea.io/gitea/modules/git.(*Command).Run
      /home/git/builds/gitea/modules/git/command.go:342
      code.gitea.io/gitea/modules/git.CatFileBatch.func3
      /home/git/builds/gitea/modules/git/batch_reader.go:124
  # /usr/bin/git cat-file --batch-check [repo_path: /gitea/work_dir/data/gitea-repositories/blender/blender.git] (modules/gitrepo/gitrepo.go:31)
  # 2024-11-18 12:11:57 +01:00
    <> os/exec.(*Cmd).Start.func2 * 2
    <> 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
      os.(*File).read
      /usr/local/go/src/os/file_posix.go:29
      os.(*File).Read
      /usr/local/go/src/os/file.go:118
      io.copyBuffer
      /usr/local/go/src/io/io.go:429
      io.Copy
      /usr/local/go/src/io/io.go:388
      os.genericWriteTo
      /usr/local/go/src/os/file.go:269
      os.(*File).WriteTo
      /usr/local/go/src/os/file.go:247
      io.copyBuffer
      /usr/local/go/src/io/io.go:411
      io.Copy
      /usr/local/go/src/io/io.go:388
      os/exec.(*Cmd).writerDescriptor.func1
      /usr/local/go/src/os/exec/exec.go:577
      os/exec.(*Cmd).Start.func2
      /usr/local/go/src/os/exec/exec.go:724
    <> os/exec.(*Cmd).Start.func2
    <> graceful-lifecycle
    <> with-hammer
      runtime.gopark
      /usr/local/go/src/runtime/proc.go:402
      runtime.selectgo
      /usr/local/go/src/runtime/select.go:327
      io.(*pipe).read
      /usr/local/go/src/io/pipe.go:57
      io.(*PipeReader).Read
      /usr/local/go/src/io/pipe.go:134
      io.copyBuffer
      /usr/local/go/src/io/io.go:429
      io.Copy
      /usr/local/go/src/io/io.go:388
      os.genericReadFrom
      /usr/local/go/src/os/file.go:179
      os.(*File).ReadFrom
      /usr/local/go/src/os/file.go:155
      io.copyBuffer
      /usr/local/go/src/io/io.go:415
      io.Copy
      /usr/local/go/src/io/io.go:388
      os/exec.(*Cmd).childStdin.func1
      /usr/local/go/src/os/exec/exec.go:528
      os/exec.(*Cmd).Start.func2
      /usr/local/go/src/os/exec/exec.go:724
    <> os/exec.(*Cmd).watchCtx
    <> graceful-lifecycle
    <> with-hammer
      runtime.gopark
      /usr/local/go/src/runtime/proc.go:402
      runtime.selectgo
      /usr/local/go/src/runtime/select.go:327
      os/exec.(*Cmd).watchCtx
      /usr/local/go/src/os/exec/exec.go:764
    <> code.gitea.io/gitea/modules/git.CatFileBatchCheck.func3
    <> graceful-lifecycle
    <> with-hammer
      syscall.Syscall6
      /usr/local/go/src/syscall/syscall_linux.go:91
      os.(*Process).blockUntilWaitable
      /usr/local/go/src/os/wait_waitid.go:32
      os.(*Process).wait
      /usr/local/go/src/os/exec_unix.go:22
      os.(*Process).Wait
      /usr/local/go/src/os/exec.go:134
      os/exec.(*Cmd).Wait
      /usr/local/go/src/os/exec/exec.go:897
      code.gitea.io/gitea/modules/git.(*Command).Run
      /home/git/builds/gitea/modules/git/command.go:342
      code.gitea.io/gitea/modules/git.CatFileBatchCheck.func3
      /home/git/builds/gitea/modules/git/batch_reader.go:72
  # /usr/bin/git cat-file --batch-check [repo_path: /gitea/work_dir/data/gitea-repositories/blender/blender.git] (modules/gitrepo/gitrepo.go:31)
  # 2024-11-18 12:12:34 +01:00
    <> os/exec.(*Cmd).Start.func2 * 2
    <> 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
      os.(*File).read
      /usr/local/go/src/os/file_posix.go:29
      os.(*File).Read
      /usr/local/go/src/os/file.go:118
      io.copyBuffer
      /usr/local/go/src/io/io.go:429
      io.Copy
      /usr/local/go/src/io/io.go:388
      os.genericWriteTo
      /usr/local/go/src/os/file.go:269
      os.(*File).WriteTo
      /usr/local/go/src/os/file.go:247
      io.copyBuffer
      /usr/local/go/src/io/io.go:411
      io.Copy
      /usr/local/go/src/io/io.go:388
      os/exec.(*Cmd).writerDescriptor.func1
      /usr/local/go/src/os/exec/exec.go:577
      os/exec.(*Cmd).Start.func2
      /usr/local/go/src/os/exec/exec.go:724
    <> os/exec.(*Cmd).Start.func2
    <> graceful-lifecycle
    <> with-hammer
      runtime.gopark
      /usr/local/go/src/runtime/proc.go:402
      runtime.selectgo
      /usr/local/go/src/runtime/select.go:327
      io.(*pipe).read
      /usr/local/go/src/io/pipe.go:57
      io.(*PipeReader).Read
      /usr/local/go/src/io/pipe.go:134
      io.copyBuffer
      /usr/local/go/src/io/io.go:429
      io.Copy
      /usr/local/go/src/io/io.go:388
      os.genericReadFrom
      /usr/local/go/src/os/file.go:179
      os.(*File).ReadFrom
      /usr/local/go/src/os/file.go:155
      io.copyBuffer
      /usr/local/go/src/io/io.go:415
      io.Copy
      /usr/local/go/src/io/io.go:388
      os/exec.(*Cmd).childStdin.func1
      /usr/local/go/src/os/exec/exec.go:528
      os/exec.(*Cmd).Start.func2
      /usr/local/go/src/os/exec/exec.go:724
    <> os/exec.(*Cmd).watchCtx
    <> graceful-lifecycle
    <> with-hammer
      runtime.gopark
      /usr/local/go/src/runtime/proc.go:402
      runtime.selectgo
      /usr/local/go/src/runtime/select.go:327
      os/exec.(*Cmd).watchCtx
      /usr/local/go/src/os/exec/exec.go:764
    <> code.gitea.io/gitea/modules/git.CatFileBatchCheck.func3
    <> graceful-lifecycle
    <> with-hammer
      syscall.Syscall6
      /usr/local/go/src/syscall/syscall_linux.go:91
      os.(*Process).blockUntilWaitable
      /usr/local/go/src/os/wait_waitid.go:32
      os.(*Process).wait
      /usr/local/go/src/os/exec_unix.go:22
      os.(*Process).Wait
      /usr/local/go/src/os/exec.go:134
      os/exec.(*Cmd).Wait
      /usr/local/go/src/os/exec/exec.go:897
      code.gitea.io/gitea/modules/git.(*Command).Run
      /home/git/builds/gitea/modules/git/command.go:342
      code.gitea.io/gitea/modules/git.CatFileBatchCheck.func3
      /home/git/builds/gitea/modules/git/batch_reader.go:72
  # /usr/bin/git cat-file --batch [repo_path: /gitea/work_dir/data/gitea-repositories/blender/blender.git] (modules/gitrepo/gitrepo.go:31)
  # 2024-11-18 12:11:57 +01:00
    <> os/exec.(*Cmd).Start.func2 * 2
    <> 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
      os.(*File).read
      /usr/local/go/src/os/file_posix.go:29
      os.(*File).Read
      /usr/local/go/src/os/file.go:118
      io.copyBuffer
      /usr/local/go/src/io/io.go:429
      io.Copy
      /usr/local/go/src/io/io.go:388
      os.genericWriteTo
      /usr/local/go/src/os/file.go:269
      os.(*File).WriteTo
      /usr/local/go/src/os/file.go:247
      io.copyBuffer
      /usr/local/go/src/io/io.go:411
      io.Copy
      /usr/local/go/src/io/io.go:388
      os/exec.(*Cmd).writerDescriptor.func1
      /usr/local/go/src/os/exec/exec.go:577
      os/exec.(*Cmd).Start.func2
    /usr/local/go/src/os/exec/exec.go:724
    <> os/exec.(*Cmd).Start.func2
    <> graceful-lifecycle
    <> with-hammer
      runtime.gopark
      /usr/local/go/src/runtime/proc.go:402
      runtime.selectgo
      /usr/local/go/src/runtime/select.go:327
      io.(*pipe).read
      /usr/local/go/src/io/pipe.go:57
      io.(*PipeReader).Read
      /usr/local/go/src/io/pipe.go:134
      io.copyBuffer
      /usr/local/go/src/io/io.go:429
      io.Copy
      /usr/local/go/src/io/io.go:388
      os.genericReadFrom
      /usr/local/go/src/os/file.go:179
      os.(*File).ReadFrom
      /usr/local/go/src/os/file.go:155
      io.copyBuffer
      /usr/local/go/src/io/io.go:415
      io.Copy
      /usr/local/go/src/io/io.go:388
      os/exec.(*Cmd).childStdin.func1
      /usr/local/go/src/os/exec/exec.go:528
      os/exec.(*Cmd).Start.func2
      /usr/local/go/src/os/exec/exec.go:724
    <> os/exec.(*Cmd).watchCtx
    <> graceful-lifecycle
    <> with-hammer
      runtime.gopark
      /usr/local/go/src/runtime/proc.go:402
      runtime.selectgo
      /usr/local/go/src/runtime/select.go:327
      os/exec.(*Cmd).watchCtx
      /usr/local/go/src/os/exec/exec.go:764
      <> code.gitea.io/gitea/modules/git.CatFileBatch.func3
    <> graceful-lifecycle
    <> with-hammer
      syscall.Syscall6
      /usr/local/go/src/syscall/syscall_linux.go:91
      os.(*Process).blockUntilWaitable
      /usr/local/go/src/os/wait_waitid.go:32
      os.(*Process).wait
      /usr/local/go/src/os/exec_unix.go:22
      os.(*Process).Wait
      /usr/local/go/src/os/exec.go:134
      os/exec.(*Cmd).Wait
      /usr/local/go/src/os/exec/exec.go:897
      code.gitea.io/gitea/modules/git.(*Command).Run
      /home/git/builds/gitea/modules/git/command.go:342
      code.gitea.io/gitea/modules/git.CatFileBatch.func3
      /home/git/builds/gitea/modules/git/batch_reader.go:124
  # git(dir:/gitea/work_dir/data/gitea-repositories/blender/blender.git): /usr/bin/git -c protocol.version=2 -c credential.helper= -c filter.lfs.required= -c filter.lfs.smudge= -c filter.lfs.clean= diff --shortstat d6b9df2737fb32510e872d5680a1c494190dd51c...
  # 2024-11-18 12:12:35 +01:00
    <> os/exec.(*Cmd).Start.func2 * 2
    <> 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
      os.(*File).read
      /usr/local/go/src/os/file_posix.go:29
      os.(*File).Read
      /usr/local/go/src/os/file.go:118
      bytes.(*Buffer).ReadFrom
      /usr/local/go/src/bytes/buffer.go:211
      io.copyBuffer
      /usr/local/go/src/io/io.go:415
      io.Copy
      /usr/local/go/src/io/io.go:388
      os.genericWriteTo
      /usr/local/go/src/os/file.go:269
      os.(*File).WriteTo
      /usr/local/go/src/os/file.go:247
      io.copyBuffer
      /usr/local/go/src/io/io.go:411
      io.Copy
      /usr/local/go/src/io/io.go:388
      os/exec.(*Cmd).writerDescriptor.func1
      /usr/local/go/src/os/exec/exec.go:577
      os/exec.(*Cmd).Start.func2
      /usr/local/go/src/os/exec/exec.go:724
    <> os/exec.(*Cmd).watchCtx
    <> graceful-lifecycle
    <> with-hammer
      runtime.gopark
      /usr/local/go/src/runtime/proc.go:402
      runtime.selectgo
      /usr/local/go/src/runtime/select.go:327
      os/exec.(*Cmd).watchCtx
      /usr/local/go/src/os/exec/exec.go:764
    <> net/http.HandlerFunc.ServeHTTP
    <> graceful-lifecycle
    <> with-hammer
      syscall.Syscall6
      /usr/local/go/src/syscall/syscall_linux.go:91
      os.(*Process).blockUntilWaitable
      /usr/local/go/src/os/wait_waitid.go:32
      os.(*Process).wait
      /usr/local/go/src/os/exec_unix.go:22
      os.(*Process).Wait
      /usr/local/go/src/os/exec.go:134
      os/exec.(*Cmd).Wait
      /usr/local/go/src/os/exec/exec.go:897
      code.gitea.io/gitea/modules/git.(*Command).Run
      /home/git/builds/gitea/modules/git/command.go:342
      code.gitea.io/gitea/modules/git.(*Command).RunStdBytes
      /home/git/builds/gitea/modules/git/command.go:438
      code.gitea.io/gitea/modules/git.(*Command).RunStdString
      /home/git/builds/gitea/modules/git/command.go:404
      code.gitea.io/gitea/modules/git.GetDiffShortStat
      /home/git/builds/gitea/modules/git/repo_compare.go:196
      code.gitea.io/gitea/modules/git.(*Repository).GetDiffShortStat
      /home/git/builds/gitea/modules/git/repo_compare.go:182
      code.gitea.io/gitea/services/convert.ToAPIPullRequest
      /home/git/builds/gitea/services/convert/pull.go:205
      code.gitea.io/gitea/routers/api/v1/repo.ListPullRequests
      /home/git/builds/gitea/routers/api/v1/repo/pull.go:136
      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
      /home/git/builds/gitea/modules/web/handler.go:172
      net/http.HandlerFunc.ServeHTTP
      /usr/local/go/src/net/http/server.go:2166
      net/http.HandlerFunc.ServeHTTP
      /usr/local/go/src/net/http/server.go:2166
      code.gitea.io/gitea/modules/web.toHandlerProvider.func1.1
      /home/git/builds/gitea/modules/web/handler.go:182
      net/http.HandlerFunc.ServeHTTP
      /usr/local/go/src/net/http/server.go:2166
      code.gitea.io/gitea/modules/web.toHandlerProvider.func1.1
      /home/git/builds/gitea/modules/web/handler.go:182
      net/http.HandlerFunc.ServeHTTP
      /usr/local/go/src/net/http/server.go:2166
      code.gitea.io/gitea/modules/web.toHandlerProvider.func1.1
      /home/git/builds/gitea/modules/web/handler.go:182
      net/http.HandlerFunc.ServeHTTP
      /usr/local/go/src/net/http/server.go:2166
      code.gitea.io/gitea/modules/web.toHandlerProvider.func1.1
      /home/git/builds/gitea/modules/web/handler.go:182
      net/http.HandlerFunc.ServeHTTP
      /usr/local/go/src/net/http/server.go:2166
      code.gitea.io/gitea/modules/web.toHandlerProvider.func1.1
      /home/git/builds/gitea/modules/web/handler.go:182
      net/http.HandlerFunc.ServeHTTP
      /usr/local/go/src/net/http/server.go:2166
      code.gitea.io/gitea/modules/web.toHandlerProvider.func1.1
      /home/git/builds/gitea/modules/web/handler.go:182
      net/http.HandlerFunc.ServeHTTP
      /usr/local/go/src/net/http/server.go:2166
      github.com/go-chi/chi/v5.(*ChainHandler).ServeHTTP
      /home/git/builds/gitea/vendor/github.com/go-chi/chi/v5/chain.go:31
      github.com/go-chi/chi/v5.(*Mux).routeHTTP
      /home/git/builds/gitea/vendor/github.com/go-chi/chi/v5/mux.go:459
      net/http.HandlerFunc.ServeHTTP
      /usr/local/go/src/net/http/server.go:2166

https://projects.blender.org/blender/blender/pulls

# gitea.log
2024/11/18 12:17:06 ...eb/routing/logger.go:102:func1() [I] router: completed GET /blender/blender/pulls for <redacted_ip>:0, 200 OK in 617.0ms @ repo/issue.go:500(repo.Issues)

@lunny
Copy link
Member

lunny commented Nov 29, 2024

The following logging is what I could drum up:

https://projects.blender.org/api/v1/repos/blender/blender/pulls?state=all&sort=oldest

# gitea.log
2024/11/18 12:12:57 ...eb/routing/logger.go:102:func1() [I] router: completed GET /api/v1/repos/blender/blender/pulls?state=all&sort=oldest for <redacted_ip>:0, 500 Internal Server Error in 60024.3ms @ repo/pull.go:46(repo.ListPullRequests)

Stacktrace in /admin/monitor/stacktrace?show=process

https://projects.blender.org/blender/blender/pulls

# gitea.log
2024/11/18 12:17:06 ...eb/routing/logger.go:102:func1() [I] router: completed GET /blender/blender/pulls for <redacted_ip>:0, 200 OK in 617.0ms @ repo/issue.go:500(repo.Issues)

Can you also give more context logs of API requests, your previous log lost some details?

@wxiaoguang
Copy link
Contributor

If there is performance problem, maybe you could refer to the diagnosis tool to collect performance profiles.

Steps:

  1. Goto admin -> monitoring -> stackstrace
  2. Beside "Download diagnosis report", set the time to a reasonable value (eg: 30 seconds in your case?)
  3. Click "Download diagnosis report"
  4. Then immediately access the slow API
  5. Then after 30 seconds, you should have downloaded a zip file

@wxiaoguang
Copy link
Contributor

And if the performance is related to SQL, you could enable SQL logs to see what happens: https://docs.gitea.com/help/support (LOG_SQL)

@lunny
Copy link
Member

lunny commented Nov 30, 2024

I'm working on this one.

@lunny lunny self-assigned this Nov 30, 2024
@lunny lunny mentioned this issue Nov 30, 2024
Merged
@lunny lunny added this to the 1.23.0 milestone Dec 4, 2024
@lunny
Copy link
Member

lunny commented Dec 4, 2024

#32680 is ready to review.

@lunny lunny closed this as completed in fbe6d9d Dec 10, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@lunny lunny

Labels
performance/speed performance issues with slow downs topic/api Concerns mainly the API type/bug
Projects
None yet
Milestone
1.23.0
Development

Successfully merging a pull request may close this issue.

Use batch database operations instead of one by one to optimze api pulls lunny/gitea
7 participants
@lunny @LazyDodo @wxiaoguang @xoxys @bartvdbraak @GammaGames @yp05327