Slow to open a repo if there’s many branches in it #6598

GiteaMirror commented

@skyline75489 commented on GitHub (Dec 30, 2020):

So I did a little debugging with Gitea code and found that the reason is the number of branches.

@skyline75489 commented on GitHub (Dec 30, 2020): So I did a little debugging with Gitea code and found that the reason is the number of branches.

GiteaMirror commented

@skyline75489 commented on GitHub (Dec 30, 2020):

The root cause of this seem to be git show-ref used by gitea becomes very slow for a repo like PyTorch which have 4000+ branches

@skyline75489 commented on GitHub (Dec 30, 2020): The root cause of this seem to be `git show-ref` used by gitea becomes very slow for a repo like PyTorch which have 4000+ branches

GiteaMirror commented

@zeripath commented on GitHub (Jan 1, 2021):

Could you use pprof to confirm where the delay is?

@zeripath commented on GitHub (Jan 1, 2021): Could you use pprof to confirm where the delay is?

GiteaMirror commented

@skyline75489 commented on GitHub (Jan 2, 2021):

I’m new to golang. I’ll try pprof later. Based on my debugging using logging, I found most of the time was spent in GetTags & GetBranches in repoAssginment. This is why I filed the show-ref PR.

By the way because repoAssignment is called every time we need to get the repo context, the entire PyTorch repo feels unresponsive. Everything is slow, be it opening issues, opening commits.

@skyline75489 commented on GitHub (Jan 2, 2021): I’m new to golang. I’ll try pprof later. Based on my debugging using logging, I found most of the time was spent in `GetTags` & `GetBranches` in `repoAssginment`. This is why I filed the `show-ref` PR. By the way because `repoAssignment` is called every time we need to get the repo context, the entire PyTorch repo feels unresponsive. Everything is slow, be it opening issues, opening commits.

GiteaMirror commented

@zeripath commented on GitHub (Jan 2, 2021):

Yes. Before I broke my hand this was precisely the kind of thing I was working on.

Ok. pprof can be enabled by setting ENABLE_PPROF=true in [server] in app.ini

Once you have that running on your server you can run:

go tool pprof http://localhost:6060/debug/pprof/profile?seconds=30

Ok. pprof can be enabled by setting ENABLE_PPROF=true in [server] in app.ini

And get a SVG on your browser with: web. top would give some other data.

@zeripath commented on GitHub (Jan 2, 2021): Yes. Before I broke my hand this was precisely the kind of thing I was working on. Ok. pprof can be enabled by setting `ENABLE_PPROF=true` in `[server]` in app.ini Once you have that running on your server you can run: ``` go tool pprof http://localhost:6060/debug/pprof/profile?seconds=30 ``` Ok. pprof can be enabled by setting ENABLE_PPROF=true in [server] in app.ini And get a SVG on your browser with: `web`. `top` would give some other data.

GiteaMirror commented

@zeripath commented on GitHub (Jan 2, 2021):

I've just reread the issue opening comment - please could you try again on current master. You will likely find it much faster

@zeripath commented on GitHub (Jan 2, 2021): I've just reread the issue opening comment - please could you try again on current master. You will likely find it much faster

GiteaMirror commented

@skyline75489 commented on GitHub (Jan 2, 2021):

I was using the latest master on my mac. And it is still not good. I also delibrately tried building it with 'gogit' flag. But changing 'show-ref' to 'branch/tag' without gogit gives me the best performance.

I'm having a hard time setting up a golang dev environment on my Windows machine. But i'll keep trying.

@skyline75489 commented on GitHub (Jan 2, 2021): I was using the latest master on my mac. And it is still not good. I also delibrately tried building it with 'gogit' flag. But changing 'show-ref' to 'branch/tag' without gogit gives me the best performance. I'm having a hard time setting up a golang dev environment on my Windows machine. But i'll keep trying.

GiteaMirror commented

@zeripath commented on GitHub (Jan 2, 2021):

Interestingly I am not able to duplicate the slow down on linux - ah found it

@zeripath commented on GitHub (Jan 2, 2021): Interestingly I am not able to duplicate the slow down on linux - ah found it

GiteaMirror commented

@skyline75489 commented on GitHub (Jan 2, 2021):

On Linux there's buff/cache, which will aggresively cache everything used on the file system. So i think on Linux it should be better. But still, 'show-ref' feels like an unnecessary slow path for me. All the hashes retrieved end up being just ignored. There has to be a better way, right? Even it's not 'branch/tag'.

@skyline75489 commented on GitHub (Jan 2, 2021): On Linux there's buff/cache, which will aggresively cache everything used on the file system. So i think on Linux it should be better. But still, 'show-ref' feels like an unnecessary slow path for me. All the hashes retrieved end up being just ignored. There has to be a better way, right? Even it's not 'branch/tag'.

GiteaMirror commented

@zeripath commented on GitHub (Jan 2, 2021):

is it this path that is the slow down http://localhost/gitea/administrator/pytorch/branches/ ?

@zeripath commented on GitHub (Jan 2, 2021): is it this path that is the slow down http://localhost/gitea/administrator/pytorch/branches/ ?

GiteaMirror commented

@skyline75489 commented on GitHub (Jan 2, 2021):

The one with 4000+ branches on the same page? TBH I never once successfully opened the page until I added pagination myself.

The repo homepage feels considerably slow to me, which is the first thing I noticed.

@skyline75489 commented on GitHub (Jan 2, 2021): The one with 4000+ branches on the same page? TBH I never once successfully opened the page until I added pagination myself. The repo homepage feels considerably slow to me, which is the first thing I noticed.

GiteaMirror commented

@zeripath commented on GitHub (Jan 2, 2021):

OK I've managed to get pprof results.

(pprof) list repo.Branches    
Total: 12.63s
ROUTINE ======================== code.gitea.io/gitea/routers/repo.Branches in /home/andrew/src/go/gitea/routers/repo/branch.go
         0      4.80s (flat, cum) 38.00% of Total
         .          .     50:	ctx.Data["IsMirror"] = ctx.Repo.Repository.IsMirror
         .          .     51:	ctx.Data["CanPull"] = ctx.Repo.CanWrite(models.UnitTypeCode) || (ctx.IsSigned && ctx.User.HasForkedRepo(ctx.Repo.Repository.ID))
         .          .     52:	ctx.Data["PageIsViewCode"] = true
         .          .     53:	ctx.Data["PageIsBranches"] = true
         .          .     54:
         .      2.22s     55:	ctx.Data["Branches"] = loadBranches(ctx)
         .      2.58s     56:	ctx.HTML(200, tplBranch)
         .          .     57:}
         .          .     58:
         .          .     59:// DeleteBranchPost responses for delete merged branch
         .          .     60:func DeleteBranchPost(ctx *context.Context) {
         .          .     61:	defer redirect(ctx)

(pprof) list repo.loadBranches
Total: 12.63s
ROUTINE ======================== code.gitea.io/gitea/routers/repo.loadBranches in /home/andrew/src/go/gitea/routers/repo/branch.go
         0      2.22s (flat, cum) 17.58% of Total
         .          .    195:	repoIDToGitRepo := map[int64]*git.Repository{}
         .          .    196:	repoIDToGitRepo[ctx.Repo.Repository.ID] = ctx.Repo.GitRepo
         .          .    197:
         .          .    198:	branches := make([]*Branch, len(rawBranches))
         .          .    199:	for i := range rawBranches {
         .      640ms    200:		commit, err := rawBranches[i].GetCommit()
         .          .    201:		if err != nil {
         .          .    202:			ctx.ServerError("GetCommit", err)
         .          .    203:			return nil
         .          .    204:		}
         .          .    205:
         .          .    206:		var isProtected bool
         .          .    207:		branchName := rawBranches[i].Name
         .          .    208:		for _, b := range protectedBranches {
         .          .    209:			if b.BranchName == branchName {
         .          .    210:				isProtected = true
         .          .    211:				break
         .          .    212:			}
         .          .    213:		}
         .          .    214:
         .      920ms    215:		divergence, divergenceError := repofiles.CountDivergingCommits(ctx.Repo.Repository, git.BranchPrefix+branchName)
         .          .    216:		if divergenceError != nil {
         .          .    217:			ctx.ServerError("CountDivergingCommits", divergenceError)
         .          .    218:			return nil
         .          .    219:		}
         .          .    220:
         .      660ms    221:		pr, err := models.GetLatestPullRequestByHeadInfo(ctx.Repo.Repository.ID, branchName)
         .          .    222:		if err != nil {
         .          .    223:			ctx.ServerError("GetLatestPullRequestByHeadInfo", err)
         .          .    224:			return nil
         .          .    225:		}
         .          .    226:		headCommit := commit.ID.String()

(pprof) list git.callShowRef
Total: 12.63s
ROUTINE ======================== code.gitea.io/gitea/modules/git.callShowRef in /home/andrew/src/go/gitea/modules/git/repo_branch_nogogit.go
         0       10ms (flat, cum) 0.079% of Total
         .          .     63:		}
         .          .     64:		if err != nil {
         .          .     65:			return nil, err
         .          .     66:		}
         .          .     67:
         .       10ms     68:		branchName, err := bufReader.ReadString('\n')
         .          .     69:		if err == io.EOF {
         .          .     70:			// This shouldn't happen... but we'll tolerate it for the sake of peace
         .          .     71:			return branchNames, nil
         .          .     72:		}
         .          .     73:		if err != nil {

callshowref is not the problem

@zeripath commented on GitHub (Jan 2, 2021): OK I've managed to get pprof results. ``` (pprof) list repo.Branches Total: 12.63s ROUTINE ======================== code.gitea.io/gitea/routers/repo.Branches in /home/andrew/src/go/gitea/routers/repo/branch.go 0 4.80s (flat, cum) 38.00% of Total . . 50: ctx.Data["IsMirror"] = ctx.Repo.Repository.IsMirror . . 51: ctx.Data["CanPull"] = ctx.Repo.CanWrite(models.UnitTypeCode) || (ctx.IsSigned && ctx.User.HasForkedRepo(ctx.Repo.Repository.ID)) . . 52: ctx.Data["PageIsViewCode"] = true . . 53: ctx.Data["PageIsBranches"] = true . . 54: . 2.22s 55: ctx.Data["Branches"] = loadBranches(ctx) . 2.58s 56: ctx.HTML(200, tplBranch) . . 57:} . . 58: . . 59:// DeleteBranchPost responses for delete merged branch . . 60:func DeleteBranchPost(ctx *context.Context) { . . 61: defer redirect(ctx) ``` ``` (pprof) list repo.loadBranches Total: 12.63s ROUTINE ======================== code.gitea.io/gitea/routers/repo.loadBranches in /home/andrew/src/go/gitea/routers/repo/branch.go 0 2.22s (flat, cum) 17.58% of Total . . 195: repoIDToGitRepo := map[int64]*git.Repository{} . . 196: repoIDToGitRepo[ctx.Repo.Repository.ID] = ctx.Repo.GitRepo . . 197: . . 198: branches := make([]*Branch, len(rawBranches)) . . 199: for i := range rawBranches { . 640ms 200: commit, err := rawBranches[i].GetCommit() . . 201: if err != nil { . . 202: ctx.ServerError("GetCommit", err) . . 203: return nil . . 204: } . . 205: . . 206: var isProtected bool . . 207: branchName := rawBranches[i].Name . . 208: for _, b := range protectedBranches { . . 209: if b.BranchName == branchName { . . 210: isProtected = true . . 211: break . . 212: } . . 213: } . . 214: . 920ms 215: divergence, divergenceError := repofiles.CountDivergingCommits(ctx.Repo.Repository, git.BranchPrefix+branchName) . . 216: if divergenceError != nil { . . 217: ctx.ServerError("CountDivergingCommits", divergenceError) . . 218: return nil . . 219: } . . 220: . 660ms 221: pr, err := models.GetLatestPullRequestByHeadInfo(ctx.Repo.Repository.ID, branchName) . . 222: if err != nil { . . 223: ctx.ServerError("GetLatestPullRequestByHeadInfo", err) . . 224: return nil . . 225: } . . 226: headCommit := commit.ID.String() ``` ``` (pprof) list git.callShowRef Total: 12.63s ROUTINE ======================== code.gitea.io/gitea/modules/git.callShowRef in /home/andrew/src/go/gitea/modules/git/repo_branch_nogogit.go 0 10ms (flat, cum) 0.079% of Total . . 63: } . . 64: if err != nil { . . 65: return nil, err . . 66: } . . 67: . 10ms 68: branchName, err := bufReader.ReadString('\n') . . 69: if err == io.EOF { . . 70: // This shouldn't happen... but we'll tolerate it for the sake of peace . . 71: return branchNames, nil . . 72: } . . 73: if err != nil { ``` callshowref is not the problem

GiteaMirror commented

@skyline75489 commented on GitHub (Jan 2, 2021):

Interesting. That explains why using 'branch/tag' still feels slower, comparing to repos that have a smaller size.

Way to go, PyTorch.

@skyline75489 commented on GitHub (Jan 2, 2021): Interesting. That explains why using 'branch/tag' still feels slower, comparing to repos that have a smaller size. Way to go, PyTorch.

GiteaMirror commented

@zeripath commented on GitHub (Jan 2, 2021):

it's Gitea's fault - not pytorches tbh.

@zeripath commented on GitHub (Jan 2, 2021): it's Gitea's fault - not pytorches tbh.

GiteaMirror commented

https://docs.gitea.io/en-us/config-cheat-sheet/#cache---lastcommitcache-settings-cachelast_commit

@zeripath commented on GitHub (Jan 2, 2021):

OK - this means that your PR will definitely be helpful - but if we're doing optimisations we should be guided by what actually takes time.

I'm not quite sure why:

         .      2.58s     56:	ctx.HTML(200, tplBranch)

takes so long - I'd have to check - but it's likely that anything that reduces the number of branches will improve that.

In terms of main repo showing being slow that's likely to do with generating the history for each file. That is unfortunately a slightly difficult problem - and is necessarily slow - we need to ajax getting that info instead of delaying render. However you would likely benefit from enabling the cache:

@zeripath commented on GitHub (Jan 2, 2021): OK - this means that your PR will definitely be helpful - but if we're doing optimisations we should be guided by what actually takes time. I'm not quite sure why: ``` . 2.58s 56: ctx.HTML(200, tplBranch) ``` takes so long - I'd have to check - but it's likely that anything that reduces the number of branches will improve that. --- In terms of main repo showing being slow that's likely to do with generating the history for each file. That is unfortunately a slightly difficult problem - and is necessarily slow - we need to ajax getting that info instead of delaying render. However you would likely benefit from enabling the cache: https://docs.gitea.io/en-us/config-cheat-sheet/#cache---lastcommitcache-settings-cachelast_commit

GiteaMirror commented

@skyline75489 commented on GitHub (Jan 4, 2021):

@zeripath I was joking about PyTorch. I'm glad my findings turned out to be useful to gitea.

@skyline75489 commented on GitHub (Jan 4, 2021): @zeripath I was joking about PyTorch. I'm glad my findings turned out to be useful to gitea.

GiteaMirror commented

@lunny commented on GitHub (Jan 6, 2021):

Last commit cache is only for treepath view page but not branches page ?

@lunny commented on GitHub (Jan 6, 2021): Last commit cache is only for treepath view page but not branches page ?

GiteaMirror commented

@skyline75489 commented on GitHub (Jan 19, 2021):

So I was trying pprof but got something like this:

(pprof) top10
Showing nodes accounting for 1110ms, 70.70% of 1570ms total
Showing top 10 nodes out of 328
      flat  flat%   sum%        cum   cum%
     360ms 22.93% 22.93%      360ms 22.93%  runtime.memclrNoHeapPointers
     170ms 10.83% 33.76%      170ms 10.83%  runtime.pthread_cond_wait
     160ms 10.19% 43.95%      530ms 33.76%  os/exec.(*Cmd).Start
     140ms  8.92% 52.87%      140ms  8.92%  runtime.kevent
      70ms  4.46% 57.32%       70ms  4.46%  runtime.memmove
      70ms  4.46% 61.78%       70ms  4.46%  runtime.nanotime1
      50ms  3.18% 64.97%       60ms  3.82%  runtime.usleep
      40ms  2.55% 67.52%       40ms  2.55%  internal/poll.(*fdMutex).increfAndClose
      30ms  1.91% 69.43%       30ms  1.91%  syscall.syscall
      20ms  1.27% 70.70%       20ms  1.27%  runtime.(*mspan).refillAllocCache
(pprof) list repo.Branches
Total: 1.57s

I don't know what I did wrong. The steps I took is:

Fire gitea
go tool pprof 'http://localhost:6060/debug/pprof/profile?seconds=60
Goto http://localhost:3000/test_gitea/pytorch
Wait for pprof

Anything else I need to do to get the method trace?

@skyline75489 commented on GitHub (Jan 19, 2021): So I was trying pprof but got something like this: ``` (pprof) top10 Showing nodes accounting for 1110ms, 70.70% of 1570ms total Showing top 10 nodes out of 328 flat flat% sum% cum cum% 360ms 22.93% 22.93% 360ms 22.93% runtime.memclrNoHeapPointers 170ms 10.83% 33.76% 170ms 10.83% runtime.pthread_cond_wait 160ms 10.19% 43.95% 530ms 33.76% os/exec.(*Cmd).Start 140ms 8.92% 52.87% 140ms 8.92% runtime.kevent 70ms 4.46% 57.32% 70ms 4.46% runtime.memmove 70ms 4.46% 61.78% 70ms 4.46% runtime.nanotime1 50ms 3.18% 64.97% 60ms 3.82% runtime.usleep 40ms 2.55% 67.52% 40ms 2.55% internal/poll.(*fdMutex).increfAndClose 30ms 1.91% 69.43% 30ms 1.91% syscall.syscall 20ms 1.27% 70.70% 20ms 1.27% runtime.(*mspan).refillAllocCache (pprof) list repo.Branches Total: 1.57s ``` I don't know what I did wrong. The steps I took is: * Fire gitea * go tool pprof 'http://localhost:6060/debug/pprof/profile?seconds=60 * Goto http://localhost:3000/test_gitea/pytorch * Wait for pprof Anything else I need to do to get the method trace?

GiteaMirror commented

@michaelbutler commented on GitHub (Feb 3, 2021):

We will be watching this too. Our repo has 1600+ branches and as we evaluate Gitea we are seeing 8-10 second page load times. Git clones don't seem to be affected.

@michaelbutler commented on GitHub (Feb 3, 2021): We will be watching this too. Our repo has 1600+ branches and as we evaluate Gitea we are seeing 8-10 second page load times. Git clones don't seem to be affected.

GiteaMirror commented

@lunny commented on GitHub (Feb 4, 2021):

The branches list on repo home page should be loaded asynchronously.

@lunny commented on GitHub (Feb 4, 2021): The branches list on repo home page should be loaded asynchronously.

GiteaMirror commented

@sandsenter commented on GitHub (Jan 7, 2022):

any progress for this issue?
We found that for two repositories, one repo is a mirror repository, the other is a normal repository for developing.
Both have hundreds of branches, the mirror repository's page is opened faster than the other one.

@sandsenter commented on GitHub (Jan 7, 2022): any progress for this issue? We found that for two repositories, one repo is a mirror repository, the other is a normal repository for developing. Both have hundreds of branches, the mirror repository's page is opened faster than the other one.

GiteaMirror commented

@zeripath commented on GitHub (Jan 8, 2022):

any progress for this issue? We found that for two repositories, one repo is a mirror repository, the other is a normal repository for developing. Both have hundreds of branches, the mirror repository's page is opened faster than the other one.

When you say progress have you tried main recently? There have been some improvements there.

However, we still need to stop loading all of the branches for every page.

@zeripath commented on GitHub (Jan 8, 2022): > any progress for this issue? We found that for two repositories, one repo is a mirror repository, the other is a normal repository for developing. Both have hundreds of branches, the mirror repository's page is opened faster than the other one. When you say progress have you tried main recently? There have been some improvements there. However, we still need to stop loading all of the branches for every page.

GiteaMirror commented