Performance regression on v1.9+

[issmirnov]

• Gitea version (or commit ref): 1.9.0 (official release)
• Git version: 2.17.1
• Operating system: Ubuntu 18
• Database (use [x]):
  • PostgreSQL
  • MySQL
  • MSSQL
  • SQLite
• Can you reproduce the bug at https://try.gitea.io:
  • Yes (provide example URL)
  • No
  • Not relevant
• Log gist: https://gist.github.com/issmirnov/3d317a552d4d485b15519b4ed17c045a

Description

Hey folks. My server ($5 digital ocean droplet, 1vCPU 1gb RAM) has been really struggling with the latest gitea release. Up to v1.7/1.8 or so it was completely fine. Since installing v1.9, htop and other tools consistently show the gitea web process eating up a combined 80% of my CPU.

Are there any performance regression tests for gitea? These recent changes are having a major impact on my entire server, whereas previously it coexisted fine with about 30 services.

Looking at the logs, I do see tons of runtime errors. Unsure if this is related.

Thanks so much - really love gitea, and would love to see the resource usage become normal again.

Screenshots

[lunny]

Which operations did you do on gitea? And could you give any error log?

[issmirnov]

I've made no changes since installing it pre v1. I generally upgrade the binary 3 days after each release. Full log:
errorlog.tar.gz

Log configuration:

{
  "colorize": false,
  "compress": true,
  "compressionLevel": -1,
  "daily": true,
  "expression": "",
  "filename": "/home/git/gitea/log/error.log/gitea.log",
  "flags": 347,
  "level": "error",
  "maxdays": 7,
  "maxsize": 268435456,
  "prefix": "",
  "rotate": true,
  "stacktraceLevel": "none"
}

Git config:

Migration Timeout: 600 seconds
Mirror Update Timeout: 300 seconds
Clone Operation Timeout: 300 seconds
Pull Operation Timeout: 300 seconds
GC Operation Timeout: 60 seconds

System Notices (5 of the same):

Failed to health check repository (/home/git/gogs-repositories/backups/calibre.git): signal: killed

Thank you so much for looking into this!

[lafriks]

There seems too many gitea processes imho... Can you stop gitea and check if all processes are killed actually

[issmirnov]

Done. Ran systemctl stop gitea followed by pgrep gitea. CPU load instantly falls to my usual idle of about 2%. htop confirms all gitea processes are gone.

My systemd file:

[Unit]
Description=Gitea (Git with a cup of tea)
After=syslog.target
After=network.target
After=mysqld.service

[Service]
# Modify these two values and uncomment them if you have
# repos with lots of files and get an HTTP error 500 because
# of that
###
#LimitMEMLOCK=infinity
#LimitNOFILE=65535
RestartSec=2s
Type=simple
User=git
Group=git
WorkingDirectory=/home/git/gitea
ExecStart=/home/git/gitea/gitea web
Restart=always
Environment=USER=git HOME=/home/git

# security
PrivateTmp=true
ReadWritePaths=/home/git
ProtectSystem=strict

# stop Macaron http logs
StandardOutput=null 

[Install]
WantedBy=multi-user.target

[silverwind]

Do you have the repo indexer enabled? If yes, it could be the cause. After it's done updating the index, CPU should go to idle levels.

[typeless]

Does it happen on a fresh install? ( including the performance regression and the runtime errors)

[issmirnov]

@silverwind I don't have it enabled - I saw the strict warning and decided to use Sourcegraph on a different machine that's more powerful.

@typeless I will try to find time on the weekend to set up a secondary instance and repro. Been using the same config for a while so want to be careful to not nuke the data.

[typeless]

@issmirnov Okay. I am particularly concerned about whether it is related to the state of the database.

[issmirnov]

Whoa. So here's a wild datapoint. I restarted the service 4 days ago, and look at the memory allocation! It's 321GB. There have also been 6 BILLION memory allocations and frees.

Current Memory Usage: 75MB
Total Memory Allocated: 321GB
Memory Obtained: 272MB
Pointer Lookup Times: 0
Memory Allocations: 6824696694
Memory Frees: 6823996775

[lunny]

@issmirnov I think Total Memory Allocated is non-meaningful here. You just need to know Current Memory Usage. For a long term monitoring, maybe you could monitor gitea by Prometheus.

[issmirnov]

@lunny understood, been meaning to set up a prometheus/grafana stack.

I've tried to do some digging this weekend. Haven't had a chance to spin up a fresh install. A few discoveries:

• resource usage spikes during git.fsck cron jobs. This is expected, however, I have some giant mirrors that are killing the node. Specifically, I have a mirror of calibre and qmk_firmware. Would be great to have someone else try out a migration and see if it has a similar effect.
• second disocovery is that the runtime panic is happening here:

  gitea/routers/repo/repo.go

  Line 328 in 171b359

  switch ctx.Params(":action") {

  Error is PANIC:: runtime error: invalid memory address or nil pointer dereference. Earlier in the stack trace I see https://github.com/go-macaron/inject/blob/master/inject.go#L177

Here's the full stack trace:

2019/08/25 00:18:25 ...les/context/panic.go:34:1() [E] PANIC:: runtime error: invalid memory address or nil pointer dereference
	/usr/local/go/src/runtime/panic.go:82 (0x44a620)
	/usr/local/go/src/runtime/signal_unix.go:390 (0x44a44f)
	/go/src/code.gitea.io/gitea/routers/repo/repo.go:329 (0x1387fbb)
	/usr/local/go/src/reflect/value.go:447 (0x48f370)
	/usr/local/go/src/reflect/value.go:308 (0x48edf3)
	/go/src/code.gitea.io/gitea/vendor/github.com/go-macaron/inject/inject.go:177 (0x9854b6)
	/go/src/code.gitea.io/gitea/vendor/github.com/go-macaron/inject/inject.go:137 (0x984dab)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/context.go:121 (0x9b4f29)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/context.go:112 (0x11d2a68)
	/go/src/code.gitea.io/gitea/modules/context/panic.go:38 (0x11d2a5b)
	/usr/local/go/src/reflect/value.go:447 (0x48f370)
	/usr/local/go/src/reflect/value.go:308 (0x48edf3)
	/go/src/code.gitea.io/gitea/vendor/github.com/go-macaron/inject/inject.go:177 (0x9854b6)
	/go/src/code.gitea.io/gitea/vendor/github.com/go-macaron/inject/inject.go:137 (0x984dab)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/context.go:121 (0x9b4f29)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/context.go:112 (0x9e4706)
	/go/src/code.gitea.io/gitea/vendor/github.com/go-macaron/session/session.go:192 (0x9e46f1)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/context.go:79 (0x9b4dd0)
	/go/src/code.gitea.io/gitea/vendor/github.com/go-macaron/inject/inject.go:157 (0x985170)
	/go/src/code.gitea.io/gitea/vendor/github.com/go-macaron/inject/inject.go:135 (0x984e9a)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/context.go:121 (0x9b4f29)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/context.go:112 (0x1449ccf)
	/go/src/code.gitea.io/gitea/modules/gzip/gzip.go:139 (0x1449cc2)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/context.go:79 (0x9b4dd0)
	/go/src/code.gitea.io/gitea/vendor/github.com/go-macaron/inject/inject.go:157 (0x985170)
	/go/src/code.gitea.io/gitea/vendor/github.com/go-macaron/inject/inject.go:135 (0x984e9a)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/context.go:121 (0x9b4f29)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/context.go:112 (0x9c69bf)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/recovery.go:161 (0x9c69ad)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/logger.go:40 (0x9b8bc3)
	/go/src/code.gitea.io/gitea/vendor/github.com/go-macaron/inject/inject.go:157 (0x985170)
	/go/src/code.gitea.io/gitea/vendor/github.com/go-macaron/inject/inject.go:135 (0x984e9a)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/context.go:121 (0x9b4f29)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/context.go:112 (0x9c5ce0)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/logger.go:52 (0x9c5ccb)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/logger.go:40 (0x9b8bc3)
	/go/src/code.gitea.io/gitea/vendor/github.com/go-macaron/inject/inject.go:157 (0x985170)
	/go/src/code.gitea.io/gitea/vendor/github.com/go-macaron/inject/inject.go:135 (0x984e9a)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/context.go:121 (0x9b4f29)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/router.go:187 (0x9c7c06)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/router.go:303 (0x9c1675)
	/go/src/code.gitea.io/gitea/vendor/gopkg.in/macaron.v1/macaron.go:220 (0x9b9f9c)
	/go/src/code.gitea.io/gitea/vendor/github.com/gorilla/context/context.go:141 (0xd18a7a)
	/usr/local/go/src/net/http/server.go:1995 (0x779a53)
	/usr/local/go/src/net/http/server.go:2774 (0x77cd27)
	/usr/local/go/src/net/http/server.go:1878 (0x778a10)
	/usr/local/go/src/runtime/asm_amd64.s:1337 (0x464680)

The reason I bring this up is that I see 4 instances of gitea web running. I'm not familiar with the threading model used for the task runners in gitea, but it could be that the panics in the git.fsck jobs cause new instances of gitea to be launched and thus thrash the system.

[lunny]

If you only have one gitea web site, you should only see ONLY one gitea web process but not 4 instances. That should some scripts configuration error I think.

[guillep2k]

If you only have one gitea web site, you should only see ONLY one gitea web process but not 4 instances. That should some scripts configuration error I think.

One valid case in which 4 instances can happen is when Gitea is executed from a git remote (e.g. ssh) with the serv cmd. Also, git processes will usually spawn gitea hook calls as well.

Of course all of this can happen only if the system is live, with users connecting and making requests, or during a migration process.

Only one instance should be a long time runner, though.

[lunny]

Yes, I mean only one gitea web, NOT gitea hook or gitea serv.

[issmirnov]

I've been digging into this every spare chance that I get, and am unable to track down the root cause. Running gitea standalone also had high CPU usage, but I can't get reliable reproduction.

In the meantime I've scaled my droplet to 2GB ram and 2vCPU, and used systemd to throttle the gitea CPU usage.

[Service]
CPUWeight=80
CPUQuota=85%