iowait and memory consumption are skyrocketing regularly

[schmittlauch]

• Gitea version (or commit ref): 1.10.0
• Git version: 2.16.4
• Operating system: openSUSE Leap 15.1
• Database (use [x]):
  • PostgreSQL
  • MySQL (MariaDB)
  • MSSQL
  • SQLite
• Can you reproduce the bug at https://try.gitea.io:
  • Yes (provide example URL)
  • No
  • Not relevant
• Log gist:

Description

As written earlier in the Discourse forum, it regularly happens that gitea makes my server's iowait and memory consumption skyrocket, causing issues for all other services running within the same VM. Usually only killing the whole gitea service makes the server recover.
While I couldn't find any direct cause by parsing the logs or the PPROF data, I just discovered in the admin web interface (tab Monitoring) that the GetDiffRange operation seems to be responsible. It seems to get stuck at a single repo of just 138MiB size, clogging IO and making gitea consume more and more memory. iotop shows that gitea creates a lot of I/O, although I'm not sure whether swapping operations are allocated to the process causing them as well.
After this issue first occured, I limited the gitea systemd service to 600MiB and gitea is currently using all of it. But apparently this limit isn't working as the memory+swap usage increased by more than 3GiB during the GetDiffRange operation.

What does this GetDiffRange operation do? I wasn't able to find information on that.

Luckily I was able to allocate an additional 1GiB of memory to my VM, giving me the chance to let the operation run. So far it's running for more than 30 minutes though.

Any ideas about that operation, why it's getting stuck or any additional debug information I could provide?

[schmittlauch]

After ~45min the GetDiffRange operation vanished from the Monitoring web UI, but both memory consumption and IOwait remain equally high. I see myself forced to kill gitea after additional 15 minutes.

[schmittlauch]

Killing the gitea service immediately freed up 4.5GiB of memory.

[lunny]

There is a bug about OpenRepository has been fixed on v1.9.6 or v1.10.0(1?). Could you try v1.10.1?

[schmittlauch]

will do

[zeripath]

I think it's unlikely to be fixed by that - the architecture of GetDiffRange keeps the whole diff in memory. (Probably multiple copies of it too.) If you have a huge diff you're going to break Gitea.

[typeless]

References:
https://github.blog/2016-12-06-how-we-made-diff-pages-3x-faster/
https://github.com/go-gitea/gitea/blob/master/services/pull/merge.go#L504-L545

[lunny]

We can also cache the diff sections to cache server or files.

[schmittlauch]

The issue is still happening regularly even with v1.10.1, but I haven't always seen the "GetDiffRange" operation showing up on the Monitoring page. So GetDiffRange isn't necessarily the cause of this issue.

The gitea logs only show a huge amount of mysql queries and I wasn't able to get anything from the PROF data (I'm not a go developer).
If anyone thinks they can get relevant information from there, I'm willing to pass you the logs and prof data.

[lunny]

So that maybe some cron tasks.

[zeripath]

Hmm excessive Perm checks are a possible cause - see the comments on #8540?

There's another possible issue - testPatch was previously reading the whole patch in to memory. That should stop now.

[schmittlauch]

So that maybe some cron tasks.

Judging from the (non?)periodicty-time the issue appears, is at least **none** of the tasks with a periodicty of 10min or 24h listed in the monitoring tab.

Hmm excessive Perm checks are a possible cause - see the comments on #8540?

I don't have any repos with an excessively large number of owners, which seems to be the precondition for this issue.

There's another possible issue - testPatch was previously reading the whole patch in to memory. That should stop now.

Under which circumstances does `testPatch` get triggered?

[zeripath]

Changes to PRs would cause that

[zeripath]

Do you have repo indexer on? Maybe that could be a cause?

[schmittlauch]

I didn't modify any PRs in the meantime and do not have the indexer enabled (if it's disabled by default). git-lfs is enabled though.
Nevertheless after a while my gitea uses 2GiB of memory:

Server Uptime
9 hours, 34 minutes, 53 seconds
Current Goroutines
29
Current Memory Usage
44MB
Total Memory Allocated
17GB
Memory Obtained
2.8GB
Pointer Lookup Times
0
Memory Allocations
103340464
Memory Frees
102837346
Current Heap Usage
44MB
Heap Memory Obtained
2.7GB
Heap Memory Idle
2.6GB
Heap Memory In Use
52MB
Heap Memory Released
2.6GB
Heap Objects
503118
Bootstrap Stack Usage
928KB
Stack Memory Obtained
928KB
MSpan Structures Usage
678KB
MSpan Structures Obtained
8.2MB
MCache Structures Usage
5.1KB
MCache Structures Obtained
16KB
Profiling Bucket Hash Table Obtained
2.3MB
GC Metadata Obtained
97MB
Other System Allocation Obtained
1.6MB
Next GC Recycle
86MB
Since Last GC Time
19.3s
Total GC Pause
0.2s
Last GC Pause
0.000s
GC Times
382

(taken from the admin dashboard)

[lunny]

I think in fact

Current Memory Usage
44MB

is the memory what go used.

[schmittlauch]

@lunny No, according to htop gitea web uses 54.5% of my 3.86 GiB of RAM.

free gives a difference of 2206128 Bytes (used) after stopping the gitea service, that's 2.1 GiB.

[schmittlauch]

If the PROF files may be useful, I can provide you with those. I was too dumb to analyse them myself.

[schmittlauch]

Any ideas on what I can do to figure out what the memory is even used for?
Maybe taking the memory dump of the gitea process(es) via /proc/ and somehow analysing it?

[zeripath]

OK so on master I recently made a change that means that PR patches are not stored in memory - that could have been to blame.

The other places that are currently poorly written are diff and blame as these both read the whole thing into memory.

I've never used the prof output so I'd be starting from scratch with that.

[schmittlauch]

OK so on master I recently made a change that means that PR patches are not stored in memory - that could have been to blame.

I really doubt that, as my repos have nearly no PRs.

Once I find the time I'll try disabling individual repos, maybe I can pin down the issue to a single repo.

[schmittlauch]

I'd like to disable individual repos to see whether a single certain repo causes this issue.
Is there a convenient way to do this or do I need to delete the repos individually and later re-add them and restore issues + PRs from backup?

[guillep2k]

If you're using Linux, maybe you can try the following command to check what processes are using what repos at a given time:

find /proc -type l -lname '*gitea-repositories*' 2>/dev/null |
egrep '^/proc/[0-9]{1,}/fd/[0-9]{1,}$' |
tr '/' ' ' |
while read dummy1 pid dummy2 fd
do ps -f -p $pid 2>/dev/null ; readlink /proc/$pid/fd/$fd 2>/dev/null
done

The above command requires using root credentials.

With Windows you'd need sysinternals' process monitor (MS official).

[schmittlauch]

I deleted all repositories but one, now the memory issue vanished.
I am going to try to pin down which (single?) repository is causing the issue.

Unfortunately I am inly able to do this on my production instance. So if there is a more convenient way of disabling and restoring repos than gitea dump and restoring all repos afterwards, I'd be glad to hear them.

[stale]

This issue has been automatically marked as stale because it has not had recent activity. I am here to help clear issues left open even if solved or waiting for more insight. This issue will be closed if no further activity occurs during the next 2 weeks. If the issue is still valid just add a comment to keep it alive. Thank you for your contributions.

[schmittlauch]

This is still an issue, but unfortunately I haven't been able to pin it down further.

The current memory stats of my gitea 1.11.5 instance:

According to htop, the gitea web process currently uses 2194MiB of memory (RES) and has 8190MiB allocated virtually (VIRT).

From the admin dashboard:

Server Uptime
3 days, 5 hours, 57 minutes, 4 seconds
Current Goroutines
72
Current Memory Usage
85MB
Total Memory Allocated
275GB
Memory Obtained
5.9GB
Pointer Lookup Times
0
Memory Allocations
914241923
Memory Frees
913578269
Current Heap Usage
85MB
Heap Memory Obtained
5.7GB
Heap Memory Idle
5.6GB
Heap Memory In Use
99MB
Heap Memory Released
5.5GB
Heap Objects
663654
Bootstrap Stack Usage
1.4MB
Stack Memory Obtained
1.4MB
MSpan Structures Usage
882KB
MSpan Structures Obtained
38MB
MCache Structures Usage
5.1KB
MCache Structures Obtained
16KB
Profiling Bucket Hash Table Obtained
6.6MB
GC Metadata Obtained
215MB
Other System Allocation Obtained
4.6MB
Next GC Recycle
129MB
Since Last GC Time
7.3s
Total GC Pause
6.2s
Last GC Pause
0.000s
GC Times
3145

[stale]

This issue has been automatically marked as stale because it has not had recent activity. I am here to help clear issues left open even if solved or waiting for more insight. This issue will be closed if no further activity occurs during the next 2 weeks. If the issue is still valid just add a comment to keep it alive. Thank you for your contributions.

[eikendev]

I think I'm experiencing the same issue. I'm using the Docker image with version 1.13.0+dev-329-gd25f44285.

I see that one of my repositories has some huge diffs, so I'll try remove the repository from Gitea and report back if that changes anything.

Down below you see how I get weird spikes in memory usage, caused by Gitea. When the Docker container is stopped, memory recovers to somewhere between 30% and 35%.

Also note that on this instance, LFS is disabled.

Edit: After about two days the issue has not come back. My conclusion is that repositories with huge diffs are a no-no on Gitea for now.

[schmittlauch]

@eikendev What do you categorise as huge diffs and how can I check whether one of my repos falls into that category?

Gitea is still acting up, eating all my memory and swap:

$ ps auxm |grep gitea
gitea     8630  1.4 82.6 9303548 3336128 ?     -    Jul25  52:16 /nix/store/404wfnlg9dvlzphd955zlqfclsaa31aj-gitea-1.11.8-bin/bin/gitea web
gitea        -  0.1    -      -     - -        Ssl  Jul25   5:26 -
gitea        -  0.2    -      -     - -        Ssl  Jul25   8:56 -
gitea        -  0.0    -      -     - -        Ssl  Jul25   0:00 -
gitea        -  0.1    -      -     - -        Ssl  Jul25   6:26 -
gitea        -  0.0    -      -     - -        Ssl  Jul25   2:42 -
gitea        -  0.0    -      -     - -        Ssl  Jul25   0:00 -
gitea        -  0.0    -      -     - -        Ssl  Jul25   0:00 -
gitea        -  0.2    -      -     - -        Ssl  Jul25   7:14 -
gitea        -  0.0    -      -     - -        Ssl  Jul25   3:24 -
gitea        -  0.1    -      -     - -        Dsl  Jul25   5:38 -
gitea        -  0.2    -      -     - -        Ssl  Jul25   9:07 -
gitea        -  0.0    -      -     - -        Ssl  Jul25   0:20 -
gitea        -  0.1    -      -     - -        Ssl  Jul26   2:19 -
gitea        -  0.6    -      -     - -        Dsl  00:35   0:39 -
gitea    30107  0.2  0.0      0     0 ?        -    00:01   0:20 [git] <defunct>
gitea        -  0.2    -      -     - -        Z    00:01   0:20 -
gitea    30119  0.0  0.0      0     0 ?        -    00:03   0:06 [git] <defunct>
gitea        -  0.0    -      -     - -        Z    00:03   0:06 -

It also leaves broken git processes behind.
There are 13 gitea web threads running which, as I read somewhere, isn't supposed to be the case, right?

Metrics from the admin dashboard, the memory + swap usage seems to be pretty equal with Memory Obtained:

Server Uptime
2 days, 11 hours, 56 minutes, 41 seconds
Current Goroutines
57
Current Memory Usage
4.4GB
Total Memory Allocated
228GB
Memory Obtained
7.3GB
Pointer Lookup Times
0
Memory Allocations
1068826399
Memory Frees
1008293291
Current Heap Usage
4.4GB
Heap Memory Obtained
7.0GB
Heap Memory Idle
2.3GB
Heap Memory In Use
4.7GB
Heap Memory Released
708MB
Heap Objects
60533108
Bootstrap Stack Usage
1.1MB
Stack Memory Obtained
1.1MB
MSpan Structures Usage
28MB
MSpan Structures Obtained
35MB
MCache Structures Usage
5.1KB
MCache Structures Obtained
16KB
Profiling Bucket Hash Table Obtained
6.7MB
GC Metadata Obtained
272MB
Other System Allocation Obtained
4.5MB
Next GC Recycle
8.4GB
Since Last GC Time
79.4s
Total GC Pause
880.7s
Last GC Pause
24.251s
GC Times
2728

[schmittlauch]

For comparison, after a restart, Memory Obtained is back at 137MiB:

$ ps auxm |grep gitea
gitea     1063  2.2  4.8 1550104 194100 ?      -    02:27   0:04 /nix/store/404wfnlg9dvlzphd955zlqfclsaa31aj-gitea-1.11.8-bin/bin/gitea web
gitea        -  0.4    -      -     - -        Ssl  02:27   0:00 -
gitea        -  0.1    -      -     - -        Ssl  02:27   0:00 -
gitea        -  0.0    -      -     - -        Ssl  02:27   0:00 -
gitea        -  0.2    -      -     - -        Ssl  02:27   0:00 -
gitea        -  0.0    -      -     - -        Ssl  02:27   0:00 -
gitea        -  0.0    -      -     - -        Ssl  02:27   0:00 -
gitea        -  0.3    -      -     - -        Ssl  02:27   0:00 -
gitea        -  0.1    -      -     - -        Ssl  02:27   0:00 -
gitea        -  0.3    -      -     - -        Ssl  02:27   0:00 -
gitea        -  0.5    -      -     - -        Ssl  02:28   0:01 -

Server Uptime
2 minutes, 45 seconds
Current Goroutines
50
Current Memory Usage
69MB
Total Memory Allocated
130MB
Memory Obtained
137MB
Pointer Lookup Times
0
Memory Allocations
1494066
Memory Frees
714431
Current Heap Usage
69MB
Heap Memory Obtained
127MB
Heap Memory Idle
52MB
Heap Memory In Use
75MB
Heap Memory Released
42MB
Heap Objects
779635
Bootstrap Stack Usage
864KB
Stack Memory Obtained
864KB
MSpan Structures Usage
843KB
MSpan Structures Obtained
976KB
MCache Structures Usage
5.1KB
MCache Structures Obtained
16KB
Profiling Bucket Hash Table Obtained
1.4MB
GC Metadata Obtained
5.9MB
Other System Allocation Obtained
678KB
Next GC Recycle
112MB
Since Last GC Time
91.7s
Total GC Pause
0.0s
Last GC Pause
0.000s
GC Times
10

gitea-1.11.8

[zeripath]

Hmm... I've got a few ideas here:

1. Our blame code used to potentially fail to close the git process - that should be fixed on 1.13 and I think it was backported to 1.12. So that would be a cause for defunct gits on 1.11.8.

2. Another cause of the defunct git processes could be git gc.

When we run git gc git will attempt to repack things. This process can take a lot of memory and would cause a regular spike.

It's potentially worth running git gc on the command line for the in turn repositories. It may be that we have incorrect options or you need to set the pack configuration options in your global git configuration. If these git gc processes die then they can go defunct - but you should have some information on the processes page when this is happening.

3. I see that huge heap in the process memory - that's interesting because it implies that Gitea has actually read in and required that in one go. It would be really helpful if you could try to reproduce that or point to a public repo that causes Gitea to do that. If I had to guess at a cause it would be a compare page but it would be very helpful to prove it and be able to reproduce it - as then we can work to fix it.

[schmittlauch]

@zeripath

It would be really helpful if you could try to reproduce that or point to a public repo that causes Gitea to do that. If I had to guess at a cause it would be a compare page but it would be very helpful to prove it and be able to reproduce it - as then we can work to fix it.

I've already tried to bisect the repos to find the responsible one, but the process for doing so is quite bothersome:
Due to the lack of repo-level import/export, I always had to backup the whole gitea instance, remove some repos, wait to see the result, and then nuke the whole instance before restoring the whole backup.

Is there any better way?

[eikendev]

@eikendev What do you categorise as huge diffs and how can I check whether one of my repos falls into that category?

It was a repository where a file of over 100MB was added, something that actually belongs into lfs.

I guess my specific case can be detected by looking for large files inside the repository. About the general case, maybe git log --stat helps.

[zeripath]

@eikendev that's bad - do you know if it was when the file was pushed or when someone looked at the diff page?

[zeripath]

oo interesting I just pushed a file with no newlines and memory shot up.

[eikendev]

@eikendev that's bad - do you know if it was when the file was pushed or when someone looked at the diff page?

In the graph I posted earlier I have neither pushed anything nor loaded any huge diff. I looked at the repo at some points, but not the diffs. When memory is freed in the graph, this would indicate I manually restarted the server.

To me this seems more like a product of a scheduled task.

I'm not sure right now if my issue and @schmittlauch's are related.

[lafriks]

Do you see what is exact git command (with arguments) that is left dangling?

[schmittlauch]

@lafriks Currently there is no dangling git command after having restarted gitea.
I'll keep that in mind for the future, but the growth of memory consumption happens independent of dangling git processes being present or not. Right now my 3.5GiB memory are nearly full, the growth will continue into swap the next day.

[zeripath]

OK I think this is going to be related to go-git related issues.

I think therefore I'm going to pull the confirmed from this tag to see if 1.14 still has this issue.

[zeripath]

I think I might have discovered the underlying issue here - if git cat-file is called on a broken git repository it will hang until stdin is closed instead of fatalling immediately. I think therefore #17991 will fix this.

[schmittlauch]

This issue might even be resolved already, but I cannot say for sure as I moved my installation to a new installation, cleaned up some old repos, and thus might have removed such a broken repo coincidentally.

So I suggest to indeed close this once #17991 gets merged, unless some new instance of these symptoms here comes up.