Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Incomplete
-
10.11.2, 11.0.1, 10.6.12, 10.8.7, 10.9.5, 10.7
-
Ubuntu 22.04 LTS
Ubuntu 23.04
Description
Edit: This seems resolved in 11.1.0 Alpha.
MariaDB 11 under load will after a few minutes skip max_* checks, fill up the processlist and no longer accept any new connections.
MySQL 8 does not suffer from the issue.
Stress testing with: ./hey_linux_amd64 -z 1000s -c 2500 http://127.0.0.1/mysql.php
MariaDB 11.0.1-MariaDB source revision 158a58245813b1959d6ee912d77734620c7cf3ba
Edit, tested a bunch of versions:
✅ 11.1.0 Alpha does not suffer from this issue.
❌ 11.0.1 is affected.
❌ 10.11.2 is affected.
❌ 10.9.5 is affected.
❌ 10.8.7 is affected.
❌ 10.7.8 is affected.
❌ 10.6.12 is affected.
✅ 10.5.19 does not suffer from this issue.
...
✅ 10.3.38 does not suffer from this issue.
This bug was introduced sometime between version ✅ 10.5.19 and ❌ 10.6.12
my.cnf
[mysqld]
max_connections = 8000
innodb_buffer_pool_size = 40G
thread_handling=pool-of-threads
max_heap_table_size=6G
tmp_table_size=256M
innodb_log_file_size = 30G
innodb_log_buffer_size = 512M
wait_timeout=10
interactive_timeout=10
max_statement_time=10
show processlist;
Notice how the `time` column eventually goes up to 367 seconds when it should be prevented by `wait_timeout=10` `interactive_timeout=10` `max_execution_time=10` `max_statement_time=10`
Normally the `time` column never reaches this high, only after a few minutes of stress testing.
Typical output from mariadbd...
bin/mariadbd --datadir=./data --basedir=./ --user=$USER --bind-address=127.0.0.1 --socket=mariadb
2023-03-17 7:07:27 0 [Note] Starting MariaDB 11.0.1-MariaDB source revision 158a58245813b1959d6ee912d77734620c7cf3ba as process 1718874
2023-03-17 7:07:27 0 [Note] InnoDB: Compressed tables use zlib 1.2.12
2023-03-17 7:07:27 0 [Note] InnoDB: Number of transaction pools: 1
2023-03-17 7:07:27 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions
2023-03-17 7:07:27 0 [Note] InnoDB: Using Linux native AIO
2023-03-17 7:07:27 0 [Note] InnoDB: Initializing buffer pool, total size = 40.000GiB, chunk size = 0.625GiB
2023-03-17 7:07:28 0 [Note] InnoDB: Completed initialization of buffer pool
2023-03-17 7:07:28 0 [Note] InnoDB: File system buffers for log disabled (block size=512 bytes)
2023-03-17 7:07:28 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=4285051021
2023-03-17 7:07:42 0 [Note] InnoDB: Read redo log up to LSN=6432526751
2023-03-17 7:07:59 0 [Note] InnoDB: Read redo log up to LSN=8580003219
2023-03-17 7:08:15 0 [Note] InnoDB: Read redo log up to LSN=6432526751
2023-03-17 7:08:33 0 [Note] InnoDB: Read redo log up to LSN=9653744008
2023-03-17 7:08:45 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 1 row operations to undo
2023-03-17 7:08:45 0 [Note] InnoDB: Trx id counter is 84322562
2023-03-17 7:08:45 0 [Note] InnoDB: Starting final batch to recover 207227 pages from redo log.
2023-03-17 7:08:48 0 [Note] InnoDB: To recover: 116587 pages from log
2023-03-17 7:08:55 0 [Note] InnoDB: Opened 3 undo tablespaces
2023-03-17 7:08:55 0 [Note] InnoDB: 128 rollback segments in 3 undo tablespaces are active.
2023-03-17 7:08:55 0 [Note] InnoDB: Removed temporary tablespace data file: "./ibtmp1"
2023-03-17 7:08:55 0 [Note] InnoDB: Setting file './ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ...
2023-03-17 7:08:55 0 [Note] InnoDB: File './ibtmp1' size is now 12.000MiB.
2023-03-17 7:08:55 0 [Note] InnoDB: log sequence number 10373960574; transaction id 84322563
2023-03-17 7:08:55 0 [Note] InnoDB: Starting in background the rollback of recovered transactions
2023-03-17 7:08:55 0 [Note] InnoDB: Loading buffer pool(s) from /home/serve/Desktop/mariadb/data/ib_buffer_pool
2023-03-17 7:08:55 0 [Note] Plugin 'FEEDBACK' is disabled.
2023-03-17 7:08:55 0 [Note] InnoDB: Rolled back recovered transaction 84321801
2023-03-17 7:08:55 0 [Note] InnoDB: Rollback of non-prepared transactions completed
2023-03-17 7:08:55 0 [Note] Plugin 'wsrep-provider' is disabled.
2023-03-17 7:08:55 0 [Note] Server socket created on IP: '127.0.0.1'.
2023-03-17 7:08:55 0 [Note] InnoDB: Buffer pool(s) load completed at 230317 7:08:55
2023-03-17 7:08:55 0 [Note] bin/mariadbd: ready for connections.
Version: '11.0.1-MariaDB' socket: 'mariadb' port: 3306 MariaDB Server
2023-03-17 7:09:27 3 [Warning] Access denied for user 'root'@'localhost'
2023-03-17 7:09:44 4 [Warning] Aborted connection 4 to db: 'unconnected' user: 'root' host: 'localhost' (Got timeout reading communication packets)
2023-03-17 7:10:22 505 [Warning] Aborted connection 505 to db: 'unconnected' user: 'root' host: 'localhost' (Got timeout reading communication packets)
2023-03-17 7:10:47 506 [Warning] Aborted connection 506 to db: 'unconnected' user: 'root' host: 'localhost' (Got timeout reading communication packets)
2023-03-17 7:11:25 507 [Warning] Aborted connection 507 to db: 'unconnected' user: 'root' host: 'localhost' (Got timeout reading communication packets)
2023-03-17 7:11:48 508 [Warning] Aborted connection 508 to db: 'unconnected' user: 'root' host: 'localhost' (Got timeout reading communication packets)
2023-03-17 7:12:54 509 [Warning] Aborted connection 509 to db: 'unconnected' user: 'root' host: 'localhost' (Got timeout reading communication packets)
2023-03-17 7:13:40 510 [Warning] Aborted connection 510 to db: 'unconnected' user: 'root' host: 'localhost' (Got timeout reading communication packets)
2023-03-17 7:15:12 511 [Warning] Aborted connection 511 to db: 'unconnected' user: 'root' host: 'localhost' (Got timeout reading communication packets)
Originally reported here: https://github.com/MariaDB/mariadb-docker/issues/500