Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-17996

ANALYZE TABLE x PERSISTENT FOR ALL - memory usage excessive / fails to complete

    XMLWordPrintable

Details

    • Bug
    • Status: Open (View Workflow)
    • Major
    • Resolution: Unresolved
    • 10.1.31, 10.3.10, 10.4.1
    • 10.4(EOL)
    • Optimizer
    • 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)

      Attachments

        Activity

          People

            psergei Sergei Petrunia
            danblack Daniel Black
            Votes:
            1 Vote for this issue
            Watchers:
            7 Start watching this issue

            Dates

              Created:
              Updated:

              Git Integration

                Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.