x86_64, Rocky Linux release 8.8 (Green Obsidian)

I can confirm this as described, on /dev/shm (RAM disk). I executed perf record -p $(pgrep mariadbd) while the statement on tbl2 was executing. Here is what perf report told me:

  33,75%  mariadbd       mariadbd             [.] bitmap_get_next_set

  18,20%  mariadbd       mariadbd             [.] ha_innobase::extra

   9,70%  mariadbd       mariadbd             [.] ha_partition::extra

   7,50%  mariadbd       mariadbd             [.] innobase_trx_init

   3,61%  mariadbd       mariadbd             [.] mysql_sys_var_int

   2,72%  mariadbd       libc.so.6            [.] __GI___pthread_mutex_unlock_u

   1,87%  mariadbd       mariadbd             [.] thd_get_ha_data

   1,50%  mariadbd       mariadbd             [.] thd_test_options

   1,24%  mariadbd       mariadbd             [.] wsrep_on

   1,23%  mariadbd       mariadbd             [.] buf_page_get_low

   1,20%  mariadbd       mariadbd             [.] handler::ha_thd

   1,15%  mariadbd       mariadbd             [.] rec_get_offsets_func

   0,85%  mariadbd       mariadbd             [.] page_cur_search_with_match

   0,76%  mariadbd       mariadbd             [.] cmp_data

   0,68%  mariadbd       mariadbd             [.] cmp_dtuple_rec_with_match_low

   0,46%  mariadbd       mariadbd             [.] READ_INFO::read_field

   0,43%  mariadbd       mariadbd             [.] btr_cur_t::search_leaf

   0,41%  mariadbd       mariadbd             [.] rec_init_offsets_comp_ordinary

   0,41%  mariadbd       libc.so.6            [.] __memcmp_avx2_movbe_rtm

   0,39%  mariadbd       mariadbd             [.] mysql_load

   0,31%  mariadbd       libc.so.6            [.] __tzfile_compute

Based on this, there is an excessive amount of calls to ha_innobase::extra() as well as innobase_trx_init(). It is as if each row were inserted in a separate transaction.

I set breakpoints on these two functions to see what is going on. I see that ha_partition::open_read_partitions() is invoking handler::ha_open() on each partition, apparently with a different THD, because the parameter that is being passed to check_trx_exists() is changing. This forces InnoDB to constantly allocate new transaction objects.

mtr case (thanks to marko for helping with the reprod)

--source include/have_innodb.inc

--source include/have_partition.inc

DROP TABLE IF EXISTS `tbl0`;

CREATE TABLE `tbl0` (

  `id` int(11) NOT NULL,

  `tm` timestamp NOT NULL DEFAULT '0000-00-00 00:00:00',

  `v` varchar(15) DEFAULT NULL,

  PRIMARY KEY (`tm`,`id`)

) ENGINE=InnoDB DEFAULT CHARSET=utf8mb3 COLLATE=utf8mb3_bin

;

DROP TABLE IF EXISTS `tbl1`;

CREATE TABLE `tbl1` (

  `id` int(11) NOT NULL,

  `tm` timestamp NOT NULL DEFAULT '0000-00-00 00:00:00',

  `v` varchar(15) DEFAULT NULL,

  PRIMARY KEY (`tm`,`id`)

) ENGINE=InnoDB DEFAULT CHARSET=utf8mb3 COLLATE=utf8mb3_bin

 PARTITION BY RANGE (unix_timestamp(`tm`))

(PARTITION `p2023080123` VALUES LESS THAN (1690927200) ENGINE = InnoDB);

DROP TABLE IF EXISTS `tbl2`;

CREATE TABLE `tbl2` (

  `id` int(11) NOT NULL,

  `tm` timestamp NOT NULL DEFAULT '0000-00-00 00:00:00',

  `v` varchar(15) DEFAULT NULL,

  PRIMARY KEY (`tm`,`id`)

) ENGINE=InnoDB DEFAULT CHARSET=utf8mb3 COLLATE=utf8mb3_bin

 PARTITION BY RANGE (unix_timestamp(`tm`))

(PARTITION `p2023062900` VALUES LESS THAN (1687993200) ENGINE = InnoDB,

... # omit ~800 lines from tables.sql

 PARTITION `p2023080123` VALUES LESS THAN (1690927200) ENGINE = InnoDB);

--let $TMP_DIR=`select @@tmpdir`

--let inf=$TMP_DIR/inf

perl;

my $file="$ENV{inf}";

open(FH, ">", $file) or die $!;

print FH "$_\t2023-07-25\t1234567890ABCD\n" for (1..2e5);

close FH or die "close";

EOF

SET profiling = 1;

eval load data infile '$inf' ignore into table tbl0;

eval load data infile '$inf' ignore into table tbl1;

eval load data infile '$inf' ignore into table tbl2;

show profiles;

drop table tbl0, tbl1, tbl2;

Running this case, at 10.5.21 bed70468ea08c2820647f5e3ac006a9ff88144ac
I get

Query_ID	Duration	Query

1	0.91881544	load data infile '/home/ycp/source/mariadb-server/10.5/build/mysql-test/var/tmp/mysqld.1/inf' ignore into table tbl0

2	0.86368869	load data infile '/home/ycp/source/mariadb-server/10.5/build/mysql-test/var/tmp/mysqld.1/inf' ignore into table tbl1

3	0.86235132	load data infile '/home/ycp/source/mariadb-server/10.5/build/mysql-test/var/tmp/mysqld.1/inf' ignore into table tbl2

at 10.6 d28d636f57bb8c197c7bd9f35ecfe2a972bf31ab I get

Query_ID	Duration	Query

1	0.76890261	load data infile '/home/ycp/source/mariadb-server/10.6/build/mysql-test/var/tmp/mysqld.1/inf' ignore into table tbl0

2	0.96452144	load data infile '/home/ycp/source/mariadb-server/10.6/build/mysql-test/var/tmp/mysqld.1/inf' ignore into table tbl1

3	2.72212813	load data infile '/home/ycp/source/mariadb-server/10.6/build/mysql-test/var/tmp/mysqld.1/inf' ignore into table tbl2

I had -march=native and CMAKE_BUILD_TYPE=Release
(Debug may not work in showing the correct scale of regression).

Running outside mtr with the time command produced similar
results.

Git bisect result is in:

3cef4f8f0fc88ae5bfae4603d8d600ec84cc70a9 is the first bad commit

commit 3cef4f8f0fc88ae5bfae4603d8d600ec84cc70a9

Author: Marko Mäkelä <marko.makela@mariadb.com>

Date:   Mon Jan 25 18:41:27 2021 +0200

    MDEV-515 Reduce InnoDB undo logging for insert into empty table

Undoing the change to ha_partition.cc in this commit fixes the test:

Hmm, I don't know why the test passed locally earlier on the following
commit Undoing the change to ha_partition.cc in the above commit.
Obviously it should fall through the case and fail an assertion, as it does
now:

(based on 11.0)
https://github.com/MariaDB/server/commit/5bfe3e24785

Here's a better one (hopefully):
https://github.com/MariaDB/server/commit/a744a9ce2fb

Initial debugging shows that in the load data query for tbl1 and tbl2,
each row causes one call to ha_partition::extra with
operation=HA_EXTRA_IGNORE_INSERT (introduced in the bad commit),
and each such call makes a number calls to ha_innobase::extra
equal to the number of partitions, i.e. 1 call for tbl1 (200k calls in
total) and 816 calls for tbl2 (163.2 mil calls in total), the high
number of calls in the query for tbl2 could be the cause of the
performance issue.

trace for tbl0:

ha_innobase::extra > write_record > read_sep_field > mysql_load > mysql_execute_command > mysql_parse > dispatch_command > do_command > do_handle_one_connection > handle_one_connection > pfs_spawn_thread

trace for tbl1 and tbl2:

ha_innobase::extra > extra_cb > ha_partition::loop_partitions > ha_partition::extra > write_record > read_sep_field > mysql_load > mysql_execute_command > mysql_parse > dispatch_command > do_command > do_handle_one_connection > handle_one_connection > pfs_spawn_thread

Thank you for the analysis. I think that we must remove the call table->file->extra(HA_EXTRA_IGNORE_INSERT) from write_row() and move it to each (grand)caller of write_row() where IGNORE semantics may be needed, right before the loop that would insert the records. It seems to me that the LOAD statement is implemented by mysql_load(). Is it being invoked with the parameter bool ignore=true in the test case?

• at commit bb924273f3b8700d85827e65663e0b6fbca99f92[1] insert_into_empty,4k,debug,innodb fails. It seems to be caused by trx.bulk_insert being flipped back to true inside ha_write_row(). I suppose this is why extra(HA_EXTRA_IGNORE_INSERT) was called towards the end in write_record(), after the call to ha_write_row(). Here's what happens:
  • extra(HA_EXTRA_IGNORE_INSERT) sets trx.bulk_insert to false: ha_innobase::extra > mysql_insert > mysql_execute_command > mysql_parse > dispatch_command > do_command > do_handle_one_connection > handle_one_connection > pfs_spawn_thread
  • ha_write_row() flips it back to true: row_ins_clust_index_entry_low > row_ins_clust_index_entry > row_ins_index_entry > row_ins_index_entry_step > row_ins > row_ins_step > row_insert_for_mysql > ha_innobase::write_row > handler::ha_write_row > write_record > mysql_insert > mysql_execute_command > mysql_parse > dispatch_command > do_command > do_handle_one_connection > handle_one_connection > pfs_spawn_thread
  • trx.bulk_insert == true causes a call to trx->bulk_insert_apply() which causes an assertion failure: __assert_fail > rec_offs_data_size > row_merge_read_rec > row_merge_blocks > row_merge > row_merge_sort > row_merge_bulk_t::write_to_index > row_merge_bulk_t::write_to_table > trx_mod_table_time_t::write_bulk > trx_t::bulk_insert_apply_low > trx_t::bulk_insert_apply > ha_innobase::extra > mysql_insert > mysql_execute_command > mysql_parse > dispatch_command > do_command > do_handle_one_connection > handle_one_connection > pfs_spawn_thread

[1] https://github.com/MariaDB/server/commit/bb924273f3b8700d85827e65663e0b6fbca99f92

How did you generate the LESS THAN clauses? I wonder whether all the data went into one partition or was evenly spread across partitions. Please rerun and display the sizes of each partition (or at least the first and last partition).

(Meanwhile, thanks for the test case demonstrating that lots of partitions can be slow. I have long suspected such.)

> How did you generate the LESS THAN clauses?

It is in the attached tables.sql file.

> I wonder whether all the data went into one partition or was evenly spread across partitions.

They are all in one partition, because tm has the same value (2023-07-25) for all rows:

perl -e 'print "$_\t2023-07-25\t1234567890ABCD\n" for (1..2e5)' > $FILE

See also the select output in the result file[1] in the commit:

select count(*) from tbl2 where unix_timestamp(`tm`) = 1690207200;

count(*)

200000

https://github.com/MariaDB/server/commit/bb924273f3b8700d85827e65663e0b6fbca99f92#diff-84653f5b4fbf870463ee396603fac266ac3dd4f451da4bf4a3f8676a27ace339R860-R862

Given each call to ha_innobase::write_row() resets
trx->bulk_insert to true which could cause the problem, one way to fix
it is to re-reset bulk_insert to false before or after each call. The
issue is that by the time a call is made to ha_innobase::write_row(),
the info is not necessary available, because the call could be made
from ha_partition. So one idea is to do something in a back channel,
maybe in ha_innobase::extra(), to mark a flag so that
ha::innobase::write_row() will reset trx->bulk_insert. This is
what I did in <https://github.com/MariaDB/server/commit/144e91f1dc5>,
which passes all existing tests. The failure in buildbot is the new
test I added (main.mdev_31835), which passes locally, so it could be
something to do with the filesystem or other inconsequential issues.

Anyway, following up on discussions on #spider, I have transferred
this ticket to the innodb team.

I think that we should try to avoid introducing conditional branches in frequently invoked low-level code, such as write_record() or handler::write_row(). Conditional branches may cause pipeline stalls and can incur a huge overhead on superscalar processors. It would be better to inform the storage engine only once per statement (rather than once per written row) that the bulk insert interface cannot be used due to an IGNORE keyword.

Thank you both. It would be really great if we can simply remove the HA_EXTRA_IGNORE_INSERT without any bad effects. thiru, can you please find out which later change in 10.6 made the flag unnecessary? Was it perhaps MDEV-24818? I think that we need to fully understand this. For 10.10 (the earliest currently supported major version which contains MDEV-24621), I see that some additional changes are necessary, to apply any earlier bulk INSERT before the first INSERT IGNORE statement will cause a switch to row-level undo logging.

mleich, I think that we need extra comparison runs to ensure that LOAD…IGNORE and INSERT IGNORE behave exactly the same way as they would before this change. Ideally, we should compare both the 10.6 and the 10.10 versions of the fix to unfixed 10.6 and 10.10 servers.

How insert operation works under bulk insert operation:

begin;

insert into t1 values(1);

insert into t1 values(2);

insert into t1 values(2);

ERROR 23000: Duplicate entry '2' for key 'PRIMARY'

commit;

select * from t1;

f1

Since we have only one table level undo log for the table, we clear the table itself incase of partial rollback or complete rollback.

We can follow the same for insert..ignore under bulk insert operation too. There is no need to end bulk insert when we encounter insert..ignore stmt.
Given patch does remove the extra call of HA_EXTRA_IGNORE_INSERT

thiru, as far as I understand, you are trying to say that SET foreign_key_checks=0, unique_checks=0 is already changing the way how a multi-statement INSERT transactions work. Before MDEV-515 and MDEV-24818 were implemented, the outcome of your example

begin;

insert into t1 values(1);

insert into t1 values(2);

--error ER_DUP_ENTRY

insert into t1 values(2);

commit;

would always be that we would have the records (1),(2) in the table. With MDEV-515 and MDEV-24818, if the table is empty and the bulk insert is enabled, we would end up with an empty table.

I now see that even without this fix, we will ignore the IGNORE in the following example, and end up with an empty table in MariaDB Server 10.6.15:

--source include/have_innodb.inc

SET foreign_key_checks=0, unique_checks=0;

CREATE TABLE t1 (a INT UNIQUE) ENGINE=InnoDB;

BEGIN;

INSERT INTO t1 VALUES(1),(2);

INSERT IGNORE INTO t1 VALUES(2);

COMMIT;

SELECT * FROM t1;

DROP TABLE t1;

Only if the COMMIT is moved before the INSERT IGNORE, then we will end up with the result that I would expect: (1),(2).

I think that it would be helpful issue a warning "ignoring IGNORE" on the SQL layer if LOAD…IGNORE or INSERT…IGNORE will be ignored if it is being executed on an InnoDB table while unique_checks=0,foreign_key_checks=0 are in effect. serg, what do you think?

I tracked down the change that causes the above test to return an empty table. MDEV-24818 in MariaDB Server 10.6.0 would make the HA_EXTRA_IGNORE_INSERT redundant and basically cause the IGNORE clause to be ignored in bulk insert mode.

SET foreign_key_checks=0, unique_checks=0;

CREATE TABLE t (a INT UNIQUE) ENGINE=InnoDB;

BEGIN;

INSERT INTO t VALUES(1),(2);

INSERT IGNORE INTO t VALUES(2);

Warnings:

Warning	1062	Duplicate entry '2' for key 'a'

COMMIT;

SELECT * FROM t;

a

DROP TABLE t;

SET foreign_key_checks=0, unique_checks=0;

CREATE TABLE t (a INT UNIQUE) ENGINE=InnoDB;

BEGIN;

INSERT INTO t VALUES(1),(2);

INSERT IGNORE INTO t VALUES(2);

Warnings:

Warning	1062	Duplicate entry '2' for key 'a'

COMMIT;

SELECT * FROM t;

a

DROP TABLE t;

In other words, the HA_EXTRA_IGNORE_INSERT can be safely removed. It could be worth filing a separate bug for issuing a warning that the IGNORE clause of INSERT or LOAD statements will be ignored in bulk insert mode.

Please mention in the commit message that the second commit of MDEV-24818 made the HA_EXTRA_IGNORE_INSERT redundant.

commit 8ea923f55b7666a359ac2c54f6c10e8609d16846

Author: Marko Mäkelä <marko.makela@mariadb.com>

Date:   Tue Mar 16 15:21:34 2021 +0200

    MDEV-24818: Optimize multi-statement INSERT into an empty table

    If the user "opts in" (as in the parent

    commit 92b2a911e516ded986945d5d3dc6326f5575a21a),

    we can optimize multiple INSERT statements to use table-level locking

    and undo logging.

    There will be a change of behavior:

        CREATE TABLE t(a PRIMARY KEY) ENGINE=InnoDB;

        SET foreign_key_checks=0, unique_checks=0;

        BEGIN; INSERT INTO t SET a=1; INSERT INTO t SET a=1; COMMIT;

    will end up with an empty table, because in case of an error,

    the entire transaction will be rolled back, instead of rolling

    back the failing statement. Previously, the second INSERT statement

    would have been logged row by row, and only that second statement

    would have been rolled back, leaving the first INSERT intact.

    lock_table_x_unlock(), trx_mod_table_time_t::WAS_BULK: Remove.

    Because we cannot really support statement rollback in this

    optimized mode, we will not optimize the locking. The exclusive

    table lock will be held until the end of the transaction.

Above commit has made the HA_EXTRA_IGNORE_INSERT redundant.

marko

I think that it would be helpful issue a warning "ignoring IGNORE" on the SQL layer if LOAD…IGNORE or INSERT…IGNORE will be ignored if it is being executed on an InnoDB table while unique_checks=0,foreign_key_checks=0 are in effect.

No, I don't think it should be a warning. You don't execute the command that user wanted, but do something different, this produces incorrect (according to the semantics of the user issued command) result. So I am sure this should be an error — if you cannot do what user wants, you should not proceed doing something else instead.

Come to think of it, IGNORE doesn't make much sense when unique_checks=0, perhaps the server can error out early and don't even pass it to the engine?

serg, thank you. I have filed MDEV-31985 for the missing error handling.

unique_checks may only disable checking of UNIQUE .. HASH.
Primary keys in all engines I know of are always checked!
This means that IGNORE is still relevant even if unique_checks=0