GC is not working properly, space cannot be released

Note:
This topic has been translated from a Chinese forum by GPT and might contain errors.

Original topic: GC无法正常工作,空间无法释放

| username: ddmasato

[TiDB Usage Environment] Production Environment
[TiDB Version] v3.1.2
[Reproduction Path]

Followed the documentation to adjust region-cache-ttl = 86400, but it was ineffective

Restarted tikv, tidb, pd nodes

April 13, 2023, 17:14:29

tmp.log (94.8 KB)

Adjusted gc life time

Enabled empty region merge

config show configuration as follows

{
  "replication": {
    "enable-placement-rules": "false",
    "location-labels": "host",
    "max-replicas": 3,
    "strictly-match-label": "false"
  },
  "schedule": {
    "enable-cross-table-merge": "false",
    "enable-debug-metrics": "false",
    "enable-location-replacement": "true",
    "enable-make-up-replica": "true",
    "enable-one-way-merge": "false",
    "enable-remove-down-replica": "true",
    "enable-remove-extra-replica": "true",
    "enable-replace-offline-replica": "true",
    "high-space-ratio": 0.6,
    "hot-region-cache-hits-threshold": 3,
    "hot-region-schedule-limit": 8,
    "leader-schedule-limit": 10,
    "leader-schedule-policy": "count",
    "low-space-ratio": 0.8,
    "max-merge-region-keys": 500000,
    "max-merge-region-size": 100,
    "max-pending-peer-count": 64,
    "max-snapshot-count": 3,
    "max-store-down-time": "30m0s",
    "merge-schedule-limit": 8,
    "patrol-region-interval": "100ms",
    "region-schedule-limit": 10,
    "replica-schedule-limit": 6,
    "scheduler-max-waiting-operator": 3,
    "schedulers-payload": {
      "balance-hot-region-scheduler": "null",
      "balance-leader-scheduler": "{\"name\":\"balance-leader-scheduler\",\"ranges\":[{\"start-key\":\"\",\"end-key\":\"\"}]}",
      "balance-region-scheduler": "{\"name\":\"balance-region-scheduler\",\"ranges\":[{\"start-key\":\"\",\"end-key\":\"\"}]}",
      "label-scheduler": "{\"name\":\"label-scheduler\",\"ranges\":[{\"start-key\":\"\",\"end-key\":\"\"}]}"
    },
    "schedulers-v2": [
      {
        "args": null,
        "args-payload": "",
        "disable": false,
        "type": "balance-region"
      },
      {
        "args": null,
        "args-payload": "",
        "disable": false,
        "type": "balance-leader"
      },
      {
        "args": null,
        "args-payload": "",
        "disable": false,
        "type": "hot-region"
      },
      {
        "args": null,
        "args-payload": "",
        "disable": false,
        "type": "label"
      }
    ],
    "split-merge-interval": "1h0m0s",
    "store-balance-rate": 15,
    "store-limit-mode": "manual",
    "tolerant-size-ratio": 2.5
  }
}

[Encountered Problem: Problem Phenomenon and Impact]
After executing delete on the data table, space cannot be released

[Resource Configuration]

[Attachments: Screenshots/Logs/Monitoring]

[2023/04/11 21:15:13.227 +08:00] [INFO] [gc_worker.go:274] ["[gc worker] starts the whole job"] [uuid=61dbd8fad1c001c] [safePoint=440721293418692608] [concurrency=20]
[2023/04/11 21:15:13.227 +08:00] [INFO] [gc_worker.go:818] ["[gc worker] start resolve locks"] [uuid=61dbd8fad1c001c] [safePoint=440721293418692608] [concurrency=20]
[2023/04/11 21:16:12.957 +08:00] [INFO] [gc_worker.go:243] ["[gc worker] there's already a gc job running, skipped"] ["leaderTick on"=61dbd8fad1c001c]
[2023/04/11 21:17:12.931 +08:00] [INFO] [gc_worker.go:243] ["[gc worker] there's already a gc job running, skipped"] ["leaderTick on"=61dbd8fad1c001c]
[2023/04/11 21:18:12.906 +08:00] [INFO] [gc_worker.go:243] ["[gc worker] there's already a gc job running, skipped"] ["leaderTick on"=61dbd8fad1c001c]
[2023/04/11 21:19:13.010 +08:00] [INFO] [gc_worker.go:243] ["[gc worker] there's already a gc job running, skipped"] ["leaderTick on"=61dbd8fad1c001c]
[2023/04/11 21:20:13.038 +08:00] [INFO] [gc_worker.go:243] ["[gc worker] there's already a gc job running, skipped"] ["leaderTick on"=61dbd8fad1c001c]
[2023/04/11 21:21:12.884 +08:00] [INFO] [gc_worker.go:243] ["[gc worker] there's already a gc job running, skipped"] ["leaderTick on"=61dbd8fad1c001c]
[2023/04/11 21:22:12.912 +08:00] [INFO] [gc_worker.go:243] ["[gc worker] there's already a gc job running, skipped"] ["leaderTick on"=61dbd8fad1c001c]
[2023/04/11 21:23:12.836 +08:00] [INFO] [gc_worker.go:243] ["[gc worker] there's already a gc job running, skipped"] ["leaderTick on"=61dbd8fad1c001c]
[2023/04/11 21:23:25.030 +08:00] [ERROR] [gc_worker.go:832] ["[gc worker] resolve locks failed"] [uuid=61dbd8fad1c001c] [safePoint=440721293418692608] [error="loadRegion from PD failed, key: \"t\\x80\\x00\\x00\\x00\\x00\\x02\\x13q_i\\x80\\x00\\x00\\x00\\x00\\x00\\x00\\x03\\x01{       \\xff        \\xff  apiVer\\xffsionCode\\xff:4251,  \\xff        \\xff       p\\xffackageNa\\xffme:com.b\\xffyted.pan\\xffgle,    \\xff        \\xff     min\\xffPluginVe\\xffrsion:42\\xff51,     \\xff        \\xff    inte\\xffrnalPath\\xff:6644354\\xff0,      \\xff        \\xff   inter\\xffnalVersi\\xffonCode:4\\xff251,    \\xff        \\xff     sig\\xffnature:'\\xffMIIDfTCC\\xffAmWgAwIB\\xffAgIEfRwY\\xffPjANBgkq\\xffhkiG9w0B\\xffAQsFADBv\\xffMQswCQYD\\xffVQQGEwJD\\xffTjEQMA4G\\xffA1UECBMH\\xffQmVpamlu\\xffZzEQMA4G\\xffA1UEBxMH\\xffQmVpamlu\\xffZzESMBAG\\xffA1UEChMJ\\xffQnl0ZURh\\xffbmNlMQ8w\\xffDQYDVQQL\\xffEwZQYW5n\\xffbGUxFzAV\\xffBgNVBAMT\\xffDkNodWFu\\xffIFNoYW4g\\xffSmlhMB4X\\xffDTIxMTEw\\xffODA2MjQz\\xffOVoXDTQ2\\xffMTEwMjA2\\xffMjQzOVow\\xffbzELMAkG\\xffA1UEBhMC\\xffQ04xEDAO\\xffBgNVBAgT\\xffB0JlaWpp\\xffbmcxEDAO\\xffBgNVBAcT\\xffB0JlaWpp\\xffbmcxEjAQ\\xffBgNVBAoT\\xffCUJ5dGVE\\xffYW5jZTEP\\xffMA0GA1UE\\xffCxMGUGFu\\xffZ2xlMRcw\\xffFQYDVQQD\\xffEw5DaHVh\\xffbiBTaGFu\\xffIEppYTCC\\xffASIwDQYJ\\xffKoZIhvcN\\xffAQEBBQAD\\xffggEPADCC\\xffAQoCggEB\\xffAIBKeRL+\\xff4mfCn1SL\\xffYv6Oemfw\\xffwItkjlLP\\xffyqOEugkV\\xff6lanFTcZ\\xffgLwEl5LI\\xffkL0y28Un\\xffcPtMX1Mi\\xffi6DzCdJ/\\xffplw7S9+R\\xffT/hYDneu\\xff339IK...\\xff\\x00\\x00\\x00\\x00\\x00\\x00\\x00\\x00\\xf7\\x03\\x80\\x00\\x00\\x00\\xd9\\x03\\xc4\\x00\", err: rpc error: code = Canceled desc = context canceled"]
[2023/04/11 21:23:25.030 +08:00] [ERROR] [gc_worker.go:492] ["[gc worker] resolve locks returns an error"] [uuid=61dbd8fad1c001c] [error="loadRegion from PD failed, key: \"t\\x80\\x00\\x00\\x00\\x00\\x02\\x13q_i\\x80\\x00\\x00\\x00\\x00\\x00\\x00\\x03\\x01{       \\xff        \\xff  apiVer\\xffsionCode\\xff:4251,  \\xff        \\xff       p\\xffackageNa\\xffme:com.b\\xffyted.pan\\xffgle,    \\xff        \\xff     min\\xffPluginVe\\xffrsion:42\\xff51,     \\xff        \\xff    inte\\xffrnalPath\\xff:6644354\\xff0,      \\xff        \\xff   inter\\xffnalVersi\\xffonCode:4\\xff251,    \\xff        \\xff     sig\\xffnature:'\\xffMIIDfTCC\\xffAmWgAwIB\\xffAgIEfRwY\\xffPjANBgkq\\xffhkiG9w0B\\xffAQsFADBv\\xffMQswCQYD\\xffVQQGEwJD\\xffTjEQMA4G\\xffA1UECBMH\\xffQmVpamlu\\xffZzEQMA4G\\xffA1UEBxMH\\xffQmVpamlu\\xffZzESMBAG\\xffA1UEChMJ\\xffQnl0ZURh\\xffbmNlMQ8w\\xffDQYDVQQL\\xffEwZQYW5n\\xffbGUxFzAV\\xffBgNVBAMT\\xffDkNodWFu\\xffIFNoYW4g\\xffSmlhMB4X\\xffDTIxMTEw\\xffODA2MjQz\\xffOVoXDTQ2\\xffMTEwMjA2\\xffMjQzOVow\\xffbzELMAkG\\xffA1UEBhMC\\xffQ04xEDAO\\xffBgNVBAgT\\xffB0JlaWpp\\xffbmcxEDAO\\xffBgNVBAcT\\xffB0JlaWpp\\xffbmcxEjAQ\\xffBgNVBAoT\\xffCUJ5dGVE\\xffYW5jZTEP\\xffMA0GA1UE\\xffCxMGUGFu\\xffZ2xlMRcw\\xffFQYDVQQD\\xffEw5DaHVh\\xffbiBTaGFu\\xffIEppYTCC\\xffASIwDQYJ\\xffKoZIhvcN\\xffAQEBBQAD\\xffggEPADCC\\xffAQoCggEB\\xffAIBKeRL+\\xff4mfCn1SL\\xffYv6Oemfw\\xffwItkjlLP\\xffyqOEugkV\\xff6lanFTcZ\\xffgLwEl5LI\\xffkL0y28Un\\xffcPtMX1Mi\\xffi6DzCdJ/\\xffplw7S9+R\\xffT/hYDneu\\xff339IK...\\xff\\x00\\x00\\x00\\x00\\x00\\x00\\x00\\x00\\xf7\\x03\\x80\\x00\\x00\\x00\\xd9\\x03\\xc4\\x00\", err: rpc error: code = Canceled desc = context canceled"]
[2023/04/11 21:23:25.031 +08:00] [ERROR] [gc_worker.go:180] ["[gc worker] runGCJob"] [error="loadRegion from PD failed, key: \"t\\x80\\x00\\x00\\x00\\x00\\x02\\x13q_i\\x80\\x00\\x00\\x00\\x00\\x00\\x00\\x03\\x01{       \\xff        \\xff  apiVer\\xffsionCode\\xff:4251,  \\xff        \\xff       p\\xffackageNa\\xffme:com.b\\xffyted.pan\\xffgle,    \\xff        \\xff     min\\xffPluginVe\\xffrsion:42\\xff51,     \\xff        \\xff    inte\\xffrnalPath\\xff:6644354\\xff0,      \\xff        \\xff   inter\\xffnalVersi\\xffonCode:4\\xff251,    \\xff        \\xff     sig\\xffnature:'\\xffMIIDfTCC\\xffAmWgAwIB\\xffAgIEfRwY\\xffPjANBgkq\\xffhkiG9w0B\\xffAQsFADBv\\xffMQswCQYD\\xffVQQGEwJD\\xffTjEQMA4G\\xffA1UECBMH\\xffQmVpamlu\\xffZzEQMA4G\\xffA1UEBxMH\\xffQmVpamlu\\xffZzESMBAG\\xffA1UEChMJ\\xffQnl0ZURh\\xffbmNlMQ8w\\xffDQYDVQQL\\xffEwZQYW5n\\xffbGUxFzAV\\xffBgNVBAMT\\xffDkNodWFu\\xffIFNoYW4g\\xffSmlhMB4X\\xffDTIxMTEw\\xffODA2MjQz\\xffOVoXDTQ2\\xffMTEwMjA2\\xffMjQzOVow\\xffbzELMAkG\\xffA1UEBhMC\\xffQ04xEDAO\\xffBgNVBAgT\\xffB0JlaWpp\\xffbmcxEDAO\\xffBgNVBAcT\\xffB0JlaWpp\\xffbmcxEjAQ\\xffBgNVBAoT\\xffCUJ5dGVE\\xffYW5jZTEP\\xffMA0GA1UE\\xffCxMGUGFu\\xffZ2xlMRcw\\xffFQYDVQQD\\xffEw5DaHVh\\xffbiBTaGFu\\xffIEppYTCC\\xffASIwDQYJ\\xffKoZIhvcN\\xffAQEBBQAD\\xffggEPADCC\\xffAQoCggEB\\xffAIBKeRL+\\xff4mfCn1SL\\xffYv6Oemfw\\xffwItkjlLP\\xffyqOEugkV\\xff6lanFTcZ\\xffgLwEl5LI\\xffkL0y28Un\\xffcPtMX1Mi\\xffi6DzCdJ/\\xffplw7S9+R\\xffT/hYDneu\\xff339IK...\\xff\\x00\\x00\\x00\\x00\\x00\\x00\\x00\\x00\\xf7\\x03\\x80\\x00\\x00\\x00\\xd9\\x03\\xc4\\x00\", err: rpc error: code = Canceled desc = context canceled"]

gc monitoring chart

Mainly don’t know how to locate the data causing loadRegion from PD failed. If this can be found, it should be resolved, right?

Supplementary log on April 12, 10:32

[2023/04/12 10:26:06.973 +08:00] [INFO] [range_task.go:254] ["canceling range
| username: TiDBer_jYQINSnf | Original post link

Merging empty regions might reduce the space usage.

| username: TiDBer_jYQINSnf | Original post link

Is the region merge in this version still not perfect? I haven’t maintained the 3.x version, let’s wait for others to take a look.

| username: ddmasato | Original post link

It’s not a merge issue, it’s that the GC didn’t run.
We are planning to gradually upgrade to 4.x-5.x this quarter, but then this problem occurred… Sigh.

| username: Jellybean | Original post link

Your cluster’s Region merge configuration parameters are a bit high. You can reduce them to the official recommended values and see if it helps. This operation will accelerate the merging of empty regions.

  • The size of the Region is smaller than the value of the configuration item max-merge-region-size (default 20 MiB)
  • The number of keys in the Region is smaller than the value of the configuration item max-merge-region-keys (default 200000)
| username: Jellybean | Original post link

The reason why space cannot be released may be influenced by several factors:

  • Besides the empty region issue mentioned above,
  • It could also be that the GC is running a bit slow. According to the logs [gc worker] there’s already a gc job running, skipped, we can see that the GC is triggered and running normally, but the background GC speed is relatively slow. If it hasn’t finished the current GC within 10 minutes and the next GC task comes, the system detects that there is a running task and skips the latest GC task.

How many TiKV nodes does your cluster have approximately?
Because I see the tikv_gc_concurrency configuration parameter is set to 4, if the number of TiKV nodes exceeds 4, you can appropriately increase this concurrency.

| username: Jellybean | Original post link

There is another big issue: TiDB 3.x versions have not been maintained for a long time. Our production environment has been upgraded to version 6.1, and it has been stable and reliable for more than half a year.

I strongly recommend that you evaluate an upgrade. From our production experience, in terms of performance improvement, cluster stability, bug fixes, and feature enhancements, the new version of the TiDB cluster has seen qualitative improvements.

To give an inappropriate example for understanding, if the 3.x version is like the knowledge level of a high school student, the 6.x version can be compared to the level of a master’s or doctoral degree.

| username: ddmasato | Original post link

The cluster has 20 TiKV nodes and 7 physical machines, with multiple instances deployed. Based on recommendations, it has been adjusted to 10.

However, there are errors in the GC logs:
"[gc worker] runGCJob"] [error="loadRegion from PD failed

According to the documentation I referenced, this is due to some abnormal regions, causing repeated loops of resolve locks and preventing the next step. Currently, it is not possible to determine which region is causing the issue.

| username: ddmasato | Original post link

Indeed, it was in preparation for the upgrade, so space was cleared at the beginning of March to prepare for the upgrade. As a result, it was discovered that GC could not run normally… so it was not advisable to force the upgrade.

| username: ddmasato | Original post link

I used to have too many empty regions, which caused the space to not be released, so I increased the size. However, I found that increasing the size did not reduce the space. I can see that the number of regions is decreasing, but the space usage is still increasing.

| username: 大鱼海棠 | Original post link

Refer to this: https://docs.pingcap.com/zh/tidb/stable/pd-control#region-key---formatrawencodehex-key
Find the region based on the key, then find the corresponding table information.
But it looks like a region cache issue, try it first.

| username: TiDBer_jYQINSnf | Original post link

It’s about merging. Once the empty regions are merged, the space usage goes down.

| username: Jiawei | Original post link

Why does it feel like the GC is not working properly because it failed when cleaning up locks?

| username: ddmasato | Original post link

Thank you! I’ll give it a try! If I find the corresponding table, what should I do next?

| username: ddmasato | Original post link

Yes, yes, based on the content of the referenced article, I feel the same way. Do you have any ideas on how to solve it?

| username: Jellybean | Original post link

If you increase it, the number of regions that meet the conditions will increase, and it will merge more regions. Larger regions usually involve more data migration, sorting, etc., which may be slower.

Our goal is to merge empty or relatively small regions as quickly as possible. Empty or relatively small regions usually merge faster and release space more quickly. Therefore, those relatively larger regions will not be included in the merge operation for now. Following this logic, it makes sense to adjust the parameter smaller. You can try this first.

| username: ddmasato | Original post link

Thank you, I just enabled cross-table empty region merging, hope it helps.

| username: dbaspace | Original post link

First, adjust the lowspace store alert to make it green. This value will affect the overall scheduling speed of the cluster.