504 on /admin after Gitea upgrade because of large action table

[tsunamaru]

Gitea Version

1.15.6 (was: 1.11.1)

Git Version

N/A

Operating System

Amazon Linux 2 (EKS)

How are you running Gitea?

AWS EKS, version 1.17.7

Deployment:

apiVersion: apps/v1
kind: Deployment
metadata:
  name: gitea
  namespace: default
spec:
  replicas: 1
  selector:
    matchLabels:
      app: gitea
  strategy:
    type: Recreate
  template:
    metadata:
      labels:
        app: gitea
    spec:
      containers:
        - name: gitea-app
          image: gitea/gitea:1.15.6
          ports:
            - name: ssh
              containerPort: 10022
            - name: http
              containerPort: 3000
          volumeMounts:
            - name: data
              mountPath: /data
              subPath: repositories
          resources:
            limits:
              memory: 4000Mi
              cpu: 3500m
      volumes:
        - name: data
          persistentVolumeClaim:
            claimName: gitea-data
            readOnly: false

Database

MySQL

Can you reproduce the bug on the Gitea demo site?

No

Log Gist

No response

Description

After Gitea upgrade from 1.11.1 to 1.15.6 /admin page doesn't load anymore. Everything other works okay.
We are using AWS NLB behind Gitea, but connecting directly (kubectl port-forward) makes no difference, page still doesn't load.

This is extensively used Gitea instance so logs on debug level very huge (>10Mb for few minutes online), I can't attach them at this moment.
From what I can see, GET request to /admin is started but never completed, causing 504 Gateway timeout after 5 minutes.
If you can, please guide me how I can filter logs output to track down this specific issue with /admin.

Screenshots

No response

[tsunamaru]

app.ini:

APP_NAME = <redacted>
RUN_MODE = prod
RUN_USER = git

[repository]
ROOT = /data/git/repositories

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

[server]
APP_DATA_PATH    = /data/gitea
PROTOCOL         = http
HTTP_PORT        = 3000
DOMAIN           = <redacted>
ROOT_URL         = <redacted>
DISABLE_SSH      = false
SSH_PORT         = 10222
SSH_LISTEN_PORT  = 10022
SSH_DOMAIN       = <redacted>
START_SSH_SERVER = true
LFS_START_SERVER = false
OFFLINE_MODE     = false

[database]
DB_TYPE  = mysql
HOST     = <redacted>
NAME     = gitea
USER     = gitea
PASSWD   = gitea
SSL_MODE = disable

[indexer]
REPO_INDEXER_ENABLED = true
REPO_INDEXER_PATH = /data/gitea/indexers/repos.bleve
UPDATE_BUFFER_LEN = 20
MAX_FILE_SIZE = 1048576
REPO_INDEXER_INCLUDE =
REPO_INDEXER_EXCLUDE = resources/bin/**


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

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

[attachment]
PATH = /data/gitea/attachments

[log]
ROOT_PATH = /data/gitea/log
MODE      = file
; MODE      = console
LEVEL     = Warn

[security]
INSTALL_LOCK   = true
SECRET_KEY     = <redacted>
INTERNAL_TOKEN = <redacted>

[mailer]
ENABLED     = true
HOST        = <redacted>
FROM        = <redacted>
USER        = <redacted>
PASSWD      = <redacted>
SKIP_VERIFY = true

[service]
REGISTER_EMAIL_CONFIRM            = true
ENABLE_NOTIFY_MAIL                = false
DISABLE_REGISTRATION              = true
ENABLE_CAPTCHA                    = false
REQUIRE_SIGNIN_VIEW               = true
DEFAULT_KEEP_EMAIL_PRIVATE        = false
DEFAULT_ALLOW_CREATE_ORGANIZATION = true
DEFAULT_ENABLE_TIMETRACKING       = true
NO_REPLY_ADDRESS                  = <redacted>

[openid]
ENABLE_OPENID_SIGNIN = false
ENABLE_OPENID_SIGNUP = false

[oauth2]
JWT_SECRET = <redacted>

[wxiaoguang]

The best methods:

1. https://github.com/go-gitea/gitea/issues/17138#issuecomment-926457731 , find the blocking go-routine.

   1. Set app.ini:

   [server]
   ENABLE_PPROF = true
   

   2. Restart Gitea

   3. Try to trigger the bug, when the requests get stuck for a while, use curl or browser to visit: http://127.0.0.1:6060/debug/pprof/goroutine?debug=1

   4. Report the output stack trace here (the stack trace doesn't contain sensitive data).

2. In MySQL SHOW FULL PROCESSLIST to see whehther there is any slow query.

[tsunamaru]

Thanks for quick response @wxiaoguang, really appreciate it!

1. I tried to add ENABLE_PPROF = true to [server] block as you suggested and restarted gitea, but when I trying to access /debug/pprof/goroutine?debug=1 it returns me 404 page not found.
2. I can see several queries SELECT count(*) FROM `action` are taking a long time. What should I do with it? Looks like some of them are still executing even after several Gitea restarts -- you can notice IP change below, this is where Gitea deployment is restarted and new IP from cluster assigning.

MySQL [gitea]> SHOW FULL PROCESSLIST;
+------+-----------------+--------------------+-------+---------+-------+------------------------+-------------------------------+
| Id   | User            | Host               | db    | Command | Time  | State                  | Info                          |
+------+-----------------+--------------------+-------+---------+-------+------------------------+-------------------------------+
|    5 | event_scheduler | localhost          | NULL  | Daemon  | 13772 | Waiting on empty queue | NULL                          |
|   12 | rdsadmin        | localhost:20024    | NULL  | Sleep   |     7 |                        | NULL                          |
|   13 | rdsadmin        | localhost          | NULL  | Sleep   |     1 |                        | NULL                          |
|  971 | gitea           | 10.10.27.67:36136  | gitea | Query   | 10756 | executing              | SELECT count(*) FROM `action` |
|  997 | gitea           | 10.10.27.67:36394  | gitea | Query   | 10696 | executing              | SELECT count(*) FROM `action` |
| 1180 | gitea           | 10.10.27.67:37922  | gitea | Query   | 10401 | executing              | SELECT count(*) FROM `action` |
| 1206 | gitea           | 10.10.27.67:38190  | gitea | Query   | 10341 | executing              | SELECT count(*) FROM `action` |
| 1256 | gitea           | 10.10.27.67:38582  | gitea | Query   | 10281 | executing              | SELECT count(*) FROM `action` |
| 1360 | gitea           | 10.10.27.67:39588  | gitea | Query   | 10053 | executing              | SELECT count(*) FROM `action` |
| 1462 | gitea           | 10.10.27.67:41464  | gitea | Query   |  9642 | executing              | SELECT count(*) FROM `action` |
| 1669 | gitea           | 10.10.27.99:53992  | gitea | Query   |  8866 | executing              | SELECT count(*) FROM `action` |
| 1781 | gitea           | 10.10.27.99:55266  | gitea | Query   |  8601 | executing              | SELECT count(*) FROM `action` |
| 3055 | gitea           | 10.10.27.137:56048 | gitea | Query   |  6008 | executing              | SELECT count(*) FROM `action` |
| 3237 | gitea           | 10.10.27.137:56878 | gitea | Query   |  5910 | executing              | SELECT count(*) FROM `action` |
| 4735 | gitea           | 10.10.27.101:48394 | gitea | Query   |  4155 | executing              | SELECT count(*) FROM `action` |
| 6402 | gitea           | 10.10.27.143:57312 | gitea | Query   |  2326 | executing              | SELECT count(*) FROM `action` |
| 6548 | gitea           | 10.10.27.143:59308 | gitea | Query   |  1939 | executing              | SELECT count(*) FROM `action` |
| 6557 | gitea           | 10.10.27.143:59450 | gitea | Query   |  1921 | executing              | SELECT count(*) FROM `action` |
| 7036 | gitea           | 10.10.27.112:48806 | gitea | Query   |   692 | executing              | SELECT count(*) FROM `action` |
| 7047 | gitea           | 10.10.27.112:49062 | gitea | Query   |   642 | executing              | SELECT count(*) FROM `action` |
| 7247 | admin           | 10.10.27.112:51616 | gitea | Query   |     0 | init                   | SHOW FULL PROCESSLIST         |
| 7320 | gitea           | 10.10.27.112:52564 | gitea | Sleep   |     2 |                        | NULL                          |
+------+-----------------+--------------------+-------+---------+-------+------------------------+-------------------------------+
22 rows in set (0.001 sec)

[wxiaoguang]

1. That's impossible. Make sure you are using http://127.0.0.1:6060/debug/pprof/goroutine?debug=1 , you can only do this inside the gitea pod
2. I think this is the problem. action table is not that important. You can safely empty it.
   1. stop Gitea
   2. restart MySQL (or just kill these slow queries)
   3. make a database backup (if you do not have confidence about your database operations)
   4. run SQL: RENAME TABLE action TO action_bak; CREATE TABLE action LIKE action_bak;
   5. start Gitea

[tsunamaru]

Thank you very much for your support @wxiaoguang. I have cleared action table and now it works very well.
As for 1st suggestion -- yes, you're right, I ignored :6060 port in your post, thought it was the same as application listen port. On :6060 I can see actual stack, but now this is not needed, as the issue is resolved.

Thanks again!

[wxiaoguang]

This seems to be a flaw in Gitea, we should prevent counting on the large action table. I will open a new issue and hope it can be fixed in future.

• Improve admin dashboard summary display to prevent timeout #17506

[tsunamaru]

Just for your information, here is database insigts from RDS console:

Action table contained 8539538 rows. Even on io1 storage with 3000 IOPS counting takes almost 2 minutes. Previously DB was running on gp2 volumes with 100 IOPS.

MySQL [gitea]> SELECT count(*) FROM `action_bak`;
+----------+
| count(*) |
+----------+
|  8539538 |
+----------+
1 row in set (1 min 42.996 sec)

[zeripath]

The Actions table should really only contain the actions for the past year as any actions beyond that date will not be shown - although this should be improved.

We need to think a bit more long term about this actions table - it's a monotonically increasing data stream and so we should be able to move data out of it and/or use database features like views to make things more efficient.