[toolsdb] 2026-08-18 Transaction History Length growing too much
Closed, ResolvedPublic
Actions

Assigned To

Authored By

	fnegri
	Aug 18 2026, 3:40 PM

Project Tags

Referenced Files

	F100058046: Screenshot 2026-08-25 at 18.15.53.png
	Aug 25 2026, 4:16 PM

	F99854970: Screenshot 2026-08-24 at 16.48.18.png
	Aug 24 2026, 3:09 PM

	F99854815: Screenshot 2026-08-24 at 16.46.52.png
	Aug 24 2026, 3:09 PM

	F99229323: Screenshot 2026-08-20 at 14.54.34.png
	Aug 20 2026, 12:55 PM

	F98992178: Screenshot 2026-08-18 at 17.36.05.png
	Aug 18 2026, 3:40 PM

Subscribers

Description

Similar to T428139: [toolsdb] Transaction History Length growing too much, but this time it seems to be caused by different tools (although mix-n-match is still in the list, cc @Magnus).

Screenshot 2026-08-18 at 17.36.05.png (1,238×620 px, 70 KB)

Debugging dashboard: https://grafana.wmcloud.org/d/5968f014-0a22-4f48-b6dc-6d1c46636f80/toolsdb-debugging

Current long transactions (on tools-db-6):

MariaDB [(none)]> SELECT trx_id, trx_started, TIMESTAMPDIFF(SECOND, trx_started, NOW()) AS age_sec, trx_state, trx_mysql_thread_id, user, command, state FROM information_schema.innodb_trx JOIN information_schema.processlist p ON trx_mysql_thread_id = p.id HAVING age_sec > 60 ORDER BY trx_started ASC;
+--------+---------------------+---------+-----------+---------------------+--------+---------+--------------+
| trx_id | trx_started         | age_sec | trx_state | trx_mysql_thread_id | user   | command | state        |
+--------+---------------------+---------+-----------+---------------------+--------+---------+--------------+
|      0 | 2026-08-18 15:17:49 |     959 | RUNNING   |          1117430951 | s51434 | Execute | Sending data |
|      0 | 2026-08-18 15:18:39 |     909 | RUNNING   |          1117452121 | s53685 | Query   | Sending data |
|      0 | 2026-08-18 15:26:58 |     410 | RUNNING   |          1117488855 | s54874 | Query   | Sending data |
|      0 | 2026-08-18 15:29:33 |     255 | RUNNING   |          1117500766 | s53952 | Query   | Sending data |
|      0 | 2026-08-18 15:30:18 |     210 | RUNNING   |          1117504085 | s53952 | Query   | Sending data |
|      0 | 2026-08-18 15:31:32 |     136 | RUNNING   |          1117508889 | s51434 | Execute | Sending data |
|      0 | 2026-08-18 15:32:18 |      90 | RUNNING   |          1117512254 | s53952 | Query   | Sending data |
+--------+---------------------+---------+-----------+---------------------+--------+---------+--------------+
7 rows in set (0.005 sec)

Tools are:

s51434 (tools.mix-n-match)
s53685 (tools.editgroups)
s54874 (tools.editgroups-commons)
s53952 (tools.freebase)

Related Objects

Mentioned In: T438504: [toolsdb] 2026-09-18 Transaction History Length growing too much
T428139: [toolsdb] Transaction History Length growing too much
Mentioned Here: T350862: [toolsdb] Migrate mixnmatch db to Trove
T428139: [toolsdb] Transaction History Length growing too much

Event Timeline

fnegri created this task.Aug 18 2026, 3:40 PM

Restricted Application added a project: tools-platform-team. · View Herald TranscriptAug 18 2026, 3:40 PM

Restricted Application added a subscriber: Aklapper. · View Herald Transcript

fnegri mentioned this in T428139: [toolsdb] Transaction History Length growing too much.Aug 18 2026, 3:41 PM

fnegri updated the task description. (Show Details)

fnegri triaged this task as High priority.Aug 19 2026, 2:06 PM

fnegri moved this task from Backlog to Todos on the tools-platform-team board.

I think this is caused by mix-n-match like in T428139: [toolsdb] Transaction History Length growing too much. In that task, I manually scaled the deployment of rustbot to zero, but I see that the pod is now running again:

tools.mix-n-match@tools-bastion-15:~$ kubectl get all
NAME                               READY   STATUS    RESTARTS     AGE
pod/mix-n-match-68cc889765-4b68x   1/1     Running   0            4d6h
pod/rustbot-687f45dbcd-ztglm       1/1     Running   8 (8h ago)   4d6h

I have stopped it again with:

tools.mix-n-match@tools-bastion-15:~$ kubectl scale --replicas=0 deployment.apps/rustbot
Warning: spec.template.spec.containers[0].resources.limits[memory]: fractional byte value "3670049554432m" is invalid, must be an integer
Warning: spec.template.spec.containers[0].resources.requests[memory]: fractional byte value "1835024777.216" is invalid, must be an integer
deployment.apps/rustbot scaled

The problematic queries generated by rustbot are like the following ones:

| 1124805200 | 1325 | Execute | Sending data            | 172.16.1.214:52663 | SET STATEMENT max_statement_time=3600 FOR (SELECT /* automatch_by_search_fetch_page_unmatched */ `id`,`ext_name`,`type` FROM `entry` FORCE INDEX (PRIMARY) WHERE `id`>71124435 AND `catalog`=2261 AND `q` IS NULL ORDER BY `id` LIMIT 1000) UNION ALL (SELECT /* automatch_by_search_fetch_page_autoq */ `id`,`ext_name`,`type` FROM `entry` WHERE `catalog`=2261 AND `id`>71124435 AND `q`>0 AND `user`=0 ORDER BY `id` LIMIT 1000) ORDER BY `id` LIMIT 1000 |
| 1124780951 | 1441 | Execute | Sending data            | 172.16.1.214:54989 | SET STATEMENT max_statement_time=1800 FOR (SELECT /* automatch_by_search_fetch_page_unmatched */ `id`,`ext_name`,`type` FROM `entry` FORCE INDEX (PRIMARY) WHERE `id`>0 AND `catalog`=6197 AND `q` IS NULL ORDER BY `id` LIMIT 1000) UNION ALL (SELECT /* automatch_by_search_fetch_page_autoq */ `id`,`ext_name`,`type` FROM `entry` WHERE `catalog`=6197 AND `id`>0 AND `q`>0 AND `user`=0 ORDER BY `id` LIMIT 1000) ORDER BY `id` LIMIT 1000               |

They are too slow, and the effect on ToolsDB is compounded by the fact that multiple queries are running in parallel, so the server never manages to clean up the history, and InnoDB history length grows out of control.

Cc-ing all the mixnmatch maintainers: @Edoardolenzi, @Hjfocs, @IagoQnsi, @Magnus, @MaxFrax96

fnegri changed the task status from Open to In Progress.Aug 19 2026, 4:45 PM

fnegri moved this task from Todos to In progress on the tools-platform-team board.

The impact on the ToolsDB disk metrics is also very visible when rustbot is running (from 2026-08-15 to 2026-08-19):

Screenshot 2026-08-20 at 14.54.34.png (1,794×544 px, 294 KB)

I have deployed some fixes, let me know if it makes a difference

@magnusmanske thank you! Yes things are a bit better, the history length is still growing, but it seems to be growing slower, let's see after a few days:

Screenshot 2026-08-24 at 16.46.52.png (1,084×622 px, 74 KB)

The other good sign is that since 2026-08-19, there were no queries from mixnmatch reaching the 1-hour timeout and getting killed automatically (there were many between 2026-08-14 and 2026-08-19).

I'm a bit concerned about the impact to disk which is quite heavy: read latency, throughput and IOPS all went up significantly after you restarted rustbot:

Screenshot 2026-08-24 at 16.48.18.png (2,166×558 px, 317 KB)

Is the current load the expected daily load, or is it currently running some sort of back fill that will eventually stop when completed?

I think ToolsDB can sustain this kind of load for a few days, but not indefinitely. If you need it longer term, I can push to get the Trove migration prioritized: T350862: [toolsdb] Migrate mixnmatch db to Trove.

You can find the graphs above at:

Current growth rate:

Screenshot 2026-08-25 at 18.15.53.png (1,236×620 px, 65 KB)

I have fixed some queries using the wrong FORCE INDEX, that should help. I am backfilling some backlog tasks, the current load is not indicitative of long-term behaviour.

I am backfilling some backlog tasks, the current load is not indicitative of long-term behaviour.

Thanks, that's great! I'll mark this as resolved for now, if the db history length grows past 50 million again, we'll get an alert and I'll reopen this.

fnegri mentioned this in T438504: [toolsdb] 2026-09-18 Transaction History Length growing too much.Fri, Sep 18, 3:57 PM

[toolsdb] 2026-08-18 Transaction History Length growing too muchClosed, ResolvedPublicActions

Description

Related Objects

Event Timeline

[toolsdb] 2026-08-18 Transaction History Length growing too much
Closed, ResolvedPublic
Actions