Details
-
Bug
-
Status: Open (View Workflow)
-
Major
-
Resolution: Unresolved
-
10.1.31, 10.3.10, 10.4.1
-
fc29 x86_64 + debian x86_64 jessie container
Description
Starting mariadb from start and ran mysqldump to fully populate the innodb_buffer_pool. No other concurrenct activity on this database:
MariaDB [test]> shutdown;
|
Query OK, 0 rows affected (0.000 sec)
|
|
MariaDB [test]> Bye
|
|
$ sudo systemctl start mariadb.service
|
|
$ mysqldump -u root test > /dev/null
|
|
$ ps -uax -q 28797
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 53.2 0.9 1381316 320828 ? Ssl 14:15 1:39 /usr/libexec/mysqld --basedir=/usr
|
[dan@volution systemd]$ mysql -u root -A test
|
Welcome to the MariaDB monitor. Commands end with ; or \g.
|
Your MariaDB connection id is 9
|
Server version: 10.3.10-MariaDB MariaDB Server
|
|
Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.
|
|
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
|
|
MariaDB [test]> show global status like 'innodb_buffer_pool_pages%';
|
+----------------------------------+-------+
|
| Variable_name | Value |
|
+----------------------------------+-------+
|
| Innodb_buffer_pool_pages_data | 7899 |
|
| Innodb_buffer_pool_pages_dirty | 0 |
|
| Innodb_buffer_pool_pages_flushed | 131 |
|
| Innodb_buffer_pool_pages_free | 0 |
|
| Innodb_buffer_pool_pages_misc | 293 |
|
| Innodb_buffer_pool_pages_total | 8192 |
|
+----------------------------------+-------+
|
6 rows in set (0.002 sec)
|
|
MariaDB [test]>
|
MariaDB [test]> ANALYZE TABLE cost PERSISTENT FOR ALL;
|
+-----------+---------+----------+-----------------------------------------+
|
| Table | Op | Msg_type | Msg_text |
|
+-----------+---------+----------+-----------------------------------------+
|
| test.cost | analyze | status | Engine-independent statistics collected |
|
| test.cost | analyze | status | OK |
|
+-----------+---------+----------+-----------------------------------------+
|
2 rows in set (35.188 sec)
|
Before the previous `ANALYZE TABLE` table was run the below script was run to monitor memory usage.
$ while [ 1 ]; do ps -uax -q 28797 ; sleep 1; done
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 43.6 0.9 1381316 321180 ? Ssl 14:15 1:39 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 43.4 0.9 1381316 321180 ? Ssl 14:15 1:39 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 43.2 0.9 1381316 321180 ? Ssl 14:15 1:39 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 43.0 0.9 1381316 321180 ? Ssl 14:15 1:39 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 42.9 0.9 1381316 321180 ? Ssl 14:15 1:39 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 42.7 0.9 1381316 321180 ? Ssl 14:15 1:39 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 42.5 0.9 1381316 321180 ? Ssl 14:15 1:39 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 42.3 0.9 1381316 321180 ? Ssl 14:15 1:39 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 42.1 0.9 1381316 321180 ? Ssl 14:15 1:39 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 41.9 0.9 1381316 321180 ? Ssl 14:15 1:39 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 41.8 0.9 1381316 321180 ? Ssl 14:15 1:39 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 41.6 0.9 1381316 321180 ? Ssl 14:15 1:39 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 41.4 0.9 1381316 321180 ? Ssl 14:15 1:39 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 41.2 0.9 1381316 321180 ? Ssl 14:15 1:39 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 41.2 1.0 1421252 342032 ? Ssl 14:15 1:39 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 41.5 1.0 1435588 353672 ? Ssl 14:15 1:40 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 41.7 1.0 1447876 358688 ? Ssl 14:15 1:41 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 41.9 1.1 1447876 359744 ? Ssl 14:15 1:42 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 42.2 1.1 1447876 363968 ? Ssl 14:15 1:43 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 42.4 1.1 1447876 363968 ? Ssl 14:15 1:44 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 42.7 1.1 1447876 366080 ? Ssl 14:15 1:45 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 42.9 1.1 1447876 366080 ? Ssl 14:15 1:46 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 43.1 1.1 1447876 366080 ? Ssl 14:15 1:47 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 43.4 1.1 1447876 366080 ? Ssl 14:15 1:49 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 43.6 1.1 1447876 366080 ? Ssl 14:15 1:50 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 43.8 1.1 1447876 366080 ? Ssl 14:15 1:51 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 44.1 1.0 1447876 357888 ? Ssl 14:15 1:52 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 44.3 1.0 1447876 357888 ? Ssl 14:15 1:53 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 44.5 1.1 1447876 362636 ? Ssl 14:15 1:54 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 44.8 1.1 1447876 362900 ? Ssl 14:15 1:55 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 45.0 1.1 1447876 362900 ? Ssl 14:15 1:56 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 45.2 1.1 1447876 363956 ? Ssl 14:15 1:57 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 45.4 1.1 1447876 363956 ? Ssl 14:15 1:58 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 45.6 1.0 1447876 348716 ? Ssl 14:15 1:59 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 45.8 1.1 1447876 360856 ? Ssl 14:15 2:00 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 46.0 1.1 1447876 361912 ? Ssl 14:15 2:01 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 46.2 1.1 1447876 361912 ? Ssl 14:15 2:02 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 28762 46.4 1.1 1472452 378280 ? Ssl 14:15 2:03 /usr/libexec/mysqld --basedir=/usr
|
memory usage raised from 321M to 378M (57M)
MariaDB [test]> show create table cost;
|
+-------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|
| Table | Create Table |
|
+-------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|
| cost | CREATE TABLE `cost` (
|
`id` varchar(40) NOT NULL,
|
`snapshotActive` int(11) DEFAULT NULL,
|
`billingAccountName` varchar(255) DEFAULT NULL,
|
`period` int(11) NOT NULL,
|
`cost` decimal(40,25) DEFAULT 0.0000000000000000000000000,
|
PRIMARY KEY (`id`),
|
KEY `periodActiveBillingCost` (`period`,`snapshotActive`,`billingAccountName`,`cost`),
|
KEY `periodBillingCostActive` (`period`,`billingAccountName`,`cost`,`snapshotActive`)
|
) ENGINE=InnoDB DEFAULT CHARSET=utf8 |
|
+-------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|
1 row in set (0.001 sec)
|
|
MariaDB [test]> select count(*) from cost;
|
sele+----------+
|
| count(*) |
|
+----------+
|
| 15678912 |
|
+----------+
|
1 row in set (2.639 sec)
|
|
MariaDB [test]> select version();
|
+-----------------+
|
| version() |
|
+-----------------+
|
| 10.3.10-MariaDB |
|
+-----------------+
|
1 row in set (0.000 sec)
|
Halving the number of entries:
MariaDB [test]> shutdown;
|
Query OK, 0 rows affected (0.000 sec)
|
|
MariaDB [test]> Bye
|
|
$ sudo systemctl start mariadb.service
|
|
|
$ mysqldump -u root test > /dev/null
|
|
|
^C
|
[dan@volution systemd]$ mysql -u root -A test
|
Welcome to the MariaDB monitor. Commands end with ; or \g.
|
Your MariaDB connection id is 9
|
Server version: 10.3.10-MariaDB MariaDB Server
|
|
Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.
|
|
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
|
|
MariaDB [test]> show global status like 'innodb_buffer_pool_pages%';
|
+----------------------------------+--------+
|
| Variable_name | Value |
|
+----------------------------------+--------+
|
| Innodb_buffer_pool_pages_data | 8142 |
|
| Innodb_buffer_pool_pages_dirty | 3593 |
|
| Innodb_buffer_pool_pages_flushed | 140761 |
|
| Innodb_buffer_pool_pages_free | 0 |
|
| Innodb_buffer_pool_pages_misc | 50 |
|
| Innodb_buffer_pool_pages_total | 8192 |
|
+----------------------------------+--------+
|
6 rows in set (0.002 sec)
|
|
MariaDB [test]> ANALYZE TABLE cost PERSISTENT FOR ALL;
|
|
^CCtrl-C -- query killed. Continuing normally.
|
+-----------+---------+----------+------------------+
|
| Table | Op | Msg_type | Msg_text |
|
+-----------+---------+----------+------------------+
|
+-----------+---------+----------+------------------+
|
1 row in set (27 min 29.657 sec)
|
The memory usage of ANALYZE TABLE from before it started
while [ 1 ]; do ps -uax -q 29338 ; sleep 1; done
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 29338 36.7 0.9 1414084 316468 ? Ssl 14:49 4:25 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 29338 36.7 0.9 1414084 316468 ? Ssl 14:49 4:26 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 29338 36.7 0.9 1414084 316468 ? Ssl 14:49 4:26 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 29338 36.7 0.9 1414084 316468 ? Ssl 14:49 4:26 /usr/libexec/mysqld --basedir=/usr
|
..
|
..
|
..
|
(23 minutes later)
|
..
|
..
|
..
|
mysql 29338 32.9 1.1 1490884 360872 ? Ssl 14:49 10:10 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 29338 32.9 1.1 1490884 360872 ? Ssl 14:49 10:10 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 29338 32.9 1.1 1490884 360872 ? Ssl 14:49 10:10 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 29338 32.9 1.1 1490884 360872 ? Ssl 14:49 10:11 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 29338 32.9 1.1 1490884 360872 ? Ssl 14:49 10:11 /usr/libexec/mysqld --basedir=/usr
|
...
|
..
|
..
|
5 minutes later:
|
..
|
..
|
..
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 29338 32.5 1.1 1515460 389004 ? Ssl 14:49 11:24 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 29338 32.5 1.1 1515460 389004 ? Ssl 14:49 11:25 /usr/libexec/mysqld --basedir=/usr
|
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
|
mysql 29338 32.5 1.1 1515460 389004 ? Ssl 14:49 11:25 /usr/libexec/mysqld --basedir=/usr
|
ANALYZE TABLE continued to run after 30minutes and failed to finish despite finishing in 30 seconds previously.
Memory use continued to over time.
Quote from coworker on 10.1.31-MariaDB-1~jessie running in x86-64 64G container:
run the `alter table xxx persistent for all` on dev-3 — runs for hours against a large table, and eventually mariadb just crashes / restarts without writing the stats. Frustrating to get these stats collected to see if it helps the query plan.
the container is getting killed after it exhausts its memory limits:
```"lastState": {
"terminated": { bq. "exitCode": 137, bq. "reason": "OOMKilled", bq. "startedAt": "2018-12-12T04:04:41Z", bq. "finishedAt": "2018-12-12T14:43:10Z", bq. "containerID": "docker://cc77db9f947369bfb4d6fb783cce841b30866460d0e57d1b1d3271777ec2beb2" bq. }
},```
must be a serious memory leak in the Analyze for it to use all ~64G of RAM when running the analyze (and no other activity happening in Maria)