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

mysqldump -uroot unusable for multi-database operations, checks all databases and tables when dumping a single DB

    Details

      Description

      When using mysqldump -uroot, this initiates a very, very resource intensive recursive check of every single database and table on the system.

      On a system with some 12k databases and 540k .frm files, this takes a long, long time.

      (The following output has substituted "censored" for the real username.)

      Using mysqldump -ucensored takes next to no time at all, and does not last for long enough that I can even see the query running.

      The issue does not appear to be present in MySQL 5.5.36 server as delivered by Oracle, but it occurs also when using mysqldump from that version, and therefore seems like it is in the server code, not the client code.

      Someone else have asked this as a question on serverfault.com also, so I'm not the only one experiencing the issue:

      http://serverfault.com/questions/574646/mariadb-10-0-slow-work-mysqldump

      Here is the relevant excerpt from SHOW FULL PROCESSLIST for my use case:

      | 292 | root | localhost | NULL | Query   |  265 | Opening tables | SELECT LOGFILE_GROUP_NAME, FILE_NAME, TOTAL_EXTENTS, INITIAL_SIZE, ENGINE, EXTRA FROM INFORMATION_SCHEMA.FILES WHERE FILE_TYPE = 'UNDO LOG' AND FILE_NAME IS NOT NULL AND LOGFILE_GROUP_NAME IN (SELECT DISTINCT LOGFILE_GROUP_NAME FROM INFORMATION_SCHEMA.FILES WHERE FILE_TYPE = 'DATAFILE' AND TABLESPACE_NAME IN (SELECT DISTINCT TABLESPACE_NAME FROM INFORMATION_SCHEMA.PARTITIONS WHERE TABLE_SCHEMA IN ('censored'))) GROUP BY LOGFILE_GROUP_NAME, FILE_NAME, ENGINE ORDER BY LOGFILE_GROUP_NAME |    0.000 |
      

      And here is some sample output from strace, showing what's going on:

      [pid 37289] getcwd("/var/lib/mysql", 4096) = 15
      [pid 37289] lstat("/var/lib/mysql/CENSORED", {st_mode=S_IFDIR|0700, st_size=8192, ...}) = 0
      [pid 37289] read(1449, "\376\1\n\f\22\0V\0\1\0\37\10\0\0\371\0010\3\0\0\0\0\0\0\0\0\0\2!\0\t\0"..., 64) = 64
      [pid 37289] read(1449, "\0\20\2539\2215\232.\21\343\217\221\270\312:d\362\200\217\5\0\0\1\1\0\0\n\0\0\0\4\0"..., 2015) = 2015
      [pid 37289] close(1449)                 = 0
      [pid 37289] time(NULL)                  = 1393234684
      [pid 37289] access("./CENSORED/flabber_updates.TRG", F_OK) = -1 ENOENT (No such file or directory)
      [pid 37289] stat("./CENSORED/flabber_updates.frm", {st_mode=S_IFREG|0660, st_size=2079, ...}) = 0
      [pid 37289] open("./CENSORED/flabber_user_notes.frm", O_RDONLY) = 1449
      [pid 37289] getcwd("/var/lib/mysql", 4096) = 15
      [pid 37289] lstat("/var/lib/mysql/CENSORED", {st_mode=S_IFDIR|0700, st_size=8192, ...}) = 0
      [pid 37289] read(1449, "\376\1\n\f\22\0V\0\1\0t\n\0\0\313\5\201\1\0\0\0\0\0\0\0\0\0\2_\0\t\0"..., 64) = 64
      [pid 37289] read(1449, "\0\20\253B\364\376\232.\21\343\217\221\270\312:d\362\200\262\7\0\0\3\3\0\0&\0\0\0\4\0"..., 2612) = 2612
      [pid 37289] close(1449)                 = 0
      [pid 37289] time(NULL)                  = 1393234684
      [pid 37289] access("./CENSORED/flabber_user_notes.TRG", F_OK) = -1 ENOENT (No such file or directory)
      [pid 37289] stat("./CENSORED/flabber_user_notes.frm", {st_mode=S_IFREG|0660, st_size=2676, ...}) = 0
      [pid 37289] open("./CENSORED/flabber_user_profiles.frm", O_RDONLY) = 1449
      

        Gliffy Diagrams

          Attachments

            Activity

            Hide
            psergey Sergei Petrunia added a comment -

            Committed a patch that makes MariaDB 10.0 be as fast as MariaDB 5.5. It will not scan unneeded databases anymore.

            Show
            psergey Sergei Petrunia added a comment - Committed a patch that makes MariaDB 10.0 be as fast as MariaDB 5.5. It will not scan unneeded databases anymore.
            Hide
            psergey Sergei Petrunia added a comment -

            Did investigation of optimizer behavior:

            1. Old optimizer (before semi-join subquery optimizations)
            The query ran instantly on older versions, because they only supported top-to-bottom execution. The top-level select is "SELECT ... FROM INFORMATION_SCHEMA.FILES", which typically produces no rows and the subquery is never invoked (I_S tables are populated in JOIN::exec(), see get_schema_tables_result() call)

            2. Semi-join optimizer, MariaDB
            Semi-join optimizer merges the subquery into top-level query. The decision to use SJ-Materialization is essentially a random choice: I_S tables provide bogus data to the optimizer (each I_S table has 2 rows, table->scan_time() =2).
            The problem is that JOIN::exec()/get_schema_tables_result() will attempt to populate all tables before executing the join. Populating I_S.PARTITIONS table will cause all tables in the database of interest to be opened.

            3. Semi-join optimizer, MySQL 5.6
            They have MySQL BUG# 71914 . They never populate I_S.PARTITIONS which causes them to run fast.

            Show
            psergey Sergei Petrunia added a comment - Did investigation of optimizer behavior: 1. Old optimizer (before semi-join subquery optimizations) The query ran instantly on older versions, because they only supported top-to-bottom execution. The top-level select is "SELECT ... FROM INFORMATION_SCHEMA.FILES", which typically produces no rows and the subquery is never invoked (I_S tables are populated in JOIN::exec(), see get_schema_tables_result() call) 2. Semi-join optimizer, MariaDB Semi-join optimizer merges the subquery into top-level query. The decision to use SJ-Materialization is essentially a random choice: I_S tables provide bogus data to the optimizer (each I_S table has 2 rows, table->scan_time() =2). The problem is that JOIN::exec()/get_schema_tables_result() will attempt to populate all tables before executing the join. Populating I_S.PARTITIONS table will cause all tables in the database of interest to be opened. 3. Semi-join optimizer, MySQL 5.6 They have MySQL BUG# 71914 . They never populate I_S.PARTITIONS which causes them to run fast.
            Hide
            psergey Sergei Petrunia added a comment -

            Fixing I_S tables to provide sane data to the optimizer is a big project.

            For now, we will:

            • Fix MariaDB 10.0 to only open tables/databases of interest (already committed)
            • To get a bit of extra performance, fix mysqldump in 5.5/10.0 to run the query with 'semijoin=off' to speed it up.
            Show
            psergey Sergei Petrunia added a comment - Fixing I_S tables to provide sane data to the optimizer is a big project. For now, we will: Fix MariaDB 10.0 to only open tables/databases of interest (already committed) To get a bit of extra performance, fix mysqldump in 5.5/10.0 to run the query with 'semijoin=off' to speed it up.
            Hide
            psergey Sergei Petrunia added a comment -

            Fixed as described in the previous comment.

            Jan Ingvoldstad, thanks alot for taking time to report this issue. We really appreciate such input.

            Show
            psergey Sergei Petrunia added a comment - Fixed as described in the previous comment. Jan Ingvoldstad , thanks alot for taking time to report this issue. We really appreciate such input.
            Hide
            frettled Jan Ingvoldstad added a comment -

            And thank you very much, Elena Stepanova and Sergei Petrunia , for the detailed analysis and, as far as I can tell from following the comments, exactly the correct fix for the problem!

            Show
            frettled Jan Ingvoldstad added a comment - And thank you very much, Elena Stepanova and Sergei Petrunia , for the detailed analysis and, as far as I can tell from following the comments, exactly the correct fix for the problem!

              People

              • Assignee:
                psergey Sergei Petrunia
                Reporter:
                frettled Jan Ingvoldstad
              • Votes:
                0 Vote for this issue
                Watchers:
                4 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: