Search code examples
mysqldatabasemariadbinnodb

How can I figure out what progress InnoDB is making after a huge INSERT completes?

I'm using MariaDB: mysql Ver 15.1 Distrib 10.3.32-MariaDB. The only configuration option I have changed from Ubuntu's default is that I changed innodb_buffer_pool_size = 1G after having some issues with deleting a large number of rows before. I don't have replication set up.

I just inserted roughly 600 million rows into a table. All my tables are InnoDB except, of course, the system tables. The table (edges) is really simple; two integer columns which form a composite primary key. The insertion process took approximately 4 days and completed successfully (it was an INSERT INTO edges SELECT some, columns FROM a INNER JOIN b ON a.column = b.foreign_key).

During the INSERT, I had an idea of how many rows would be inserted, so to get a rough idea of progress I would start a separate mysql query prompt and run SET SESSION TRANSACTION ISOLATION LEVEL READ UNCOMMITTED followed by SELECT COUNT(*) FROM the_table and find how many rows have been inserted so far. I also ran SHOW PROCESSLIST which just shows how long it's been running. I was able to figure out a rough estimate of how long things were going to take by doing some math: taking the number of seconds the query had been running from SHOW PROCESSLIST and extrapolating that based on the rough number of rows inserted so far and how many rows I thought would result.

Here is where I am a bit lost: Once the prompt where I inserted the rows returned successfully, the load average spiked higher than it was during the INSERT. I see that it's all because of IO from MySQL.

htop output

SHOW PROCESSLIST doesn't really say anything, even though clearly some processes are running on several different threads as indicated by htop.

show processlist

The closest I've gotten to figure out what's going on is SHOW ENGINE INNODB STATUS. Here's some log-related data:

show engine innodb status logs

It seems like the large numbers keep increasing, but I am confused because it says 0 pending log flushes, yet Log flushed up to keeps increasing, and no queries at all are running.

Here is the INSERT BUFFER AND ADAPTIVE HASH INDEX, but

insert buffer and adaptive hash index

Here's the output in gist form: https://gist.github.com/hut8/3508c901e6ebfaab65656b8ae3c32ae3

CREATE TABLE for the table into which insertion is happening:

 CREATE TABLE `edges` (                                                         
    `source_page_id` int(8) unsigned NOT NULL,                                             
    `dest_page_id` int(8) unsigned NOT NULL,                                               
    PRIMARY KEY (`source_page_id`,`dest_page_id`))

The insert statement was:

INSERT INTO edges (source_page_id, dest_page_id)
     SELECT pl.pl_from, v.page_id
       FROM pagelinks pl
 INNER JOIN vertexes v
         ON v.page_title = pl.pl_title;

The two tables that are the source for the data in that join look like:

 CREATE TABLE `pagelinks` ( 
`pl_from` int(8) unsigned NOT NULL DEFAULT 0,      
`pl_namespace` int(11) NOT NULL DEFAULT 0,                 
`pl_title` varbinary(255) NOT NULL DEFAULT '',         
`pl_from_namespace` int(11) NOT NULL DEFAULT 0  
 )ENGINE=InnoDB DEFAULT CHARSET=binary ROW_FORMAT=COMPRESSED;

CREATE TABLE `vertexes` ( 
`page_id` int(8) unsigned NOT NULL DEFAULT 0,                              
`page_title` varbinary(255) NOT NULL DEFAULT '',                         
PRIMARY KEY (`page_id`),  
KEY `page_title_index` (`page_title`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4

There are no indexes on pagelinks as you can see.

MariaDB [wiki]> explain SELECT pl.pl_from, v.page_id
FROM pagelinks pl
INNER JOIN vertexes v
ON v.page_title = pl.pl_title\G
*************************** 1. row *************************** 
id: 1
select_type: SIMPLE
table: pl
type: ALL
possible_keys: NULL
key: NULL 
key_len: NULL
ref: NULL
rows: 676208507 
Extra: 
*************************** 2. row *************************** 
id: 1
select_type: SIMPLE
table: v
type: ref
possible_keys: page_title_index 
key: page_title_index
key_len: 257
ref: wiki.pl.pl_title
rows: 1
Extra: Using index

Basically, I am very confused as to what the server is actually doing, and how long it will take to do it. Can anyone point me in the right direction? Again, I am only wondering about what happens after the INSERT appears to have completed. Many thanks in advance.

Solution

  • InnoDB is designed to postpone costly I/O work in various ways. When you write changes to rows in a transaction, it only modifies pages in RAM -- in the buffer pool. But it also logs the change in the InnoDB redo log on disk, so it can recover if a crash occurs. Then the pages in the buffer pool are flushed to disk some time later.

    But if you are writing 600 million rows, you're certainly going to fill up the redo log over and over. When that happens, InnoDB is forced to flush modified pages from RAM to disk immediately.

    In addition to that, building secondary indexes is postponed further. That's the "Insert buffer" noted in the innodb status. So a transaction is committed, data pages are flushed later, and secondary index pages are "merged" later still.

    Basically, there's a lot of cleanup work to do after you do a lot of inserts/updates. That's why you continue to see I/O load for some time after you think your inserts are done.

    The InnoDB design is sensible if the high write rate is sporadic. It tries to react very quickly, and defer some of the work. Hoping it can "catch up" before you have another surge of writes. But you're trying to do a four-day long surge, so InnoDB ends up falling further and further behind. Once things quiet down, it has to do a great deal of flushing and index merges before it's truly done.

    How can you monitor progress? The means to do that is not developed well. Normally you don't have to monitor it. You can query the innodb metrics this way:

    SELECT * FROM INFORMATION_SCHEMA.INNODB_METRICS WHERE NAME LIKE '%ibuf%';

    But it seems that the insert buffer monitor is disabled by default (all the ibuf-related metrics show status: disabled in my MySQL 8.0 instance). Read https://dev.mysql.com/doc/refman/8.0/en/innodb-information-schema-metrics-table.html to learn how to enable specific innodb monitors.

    Interpreting the results of these innodb metrics is a little mysterious. You can read https://dev.mysql.com/doc/refman/8.0/en/innodb-change-buffer.html but you will have to "read between the lines" quite a bit to understand what the numbers represent. You may even need to read some of the source code of the InnoDB storage engine.