[#MDEV-15213] UPDATEs are slow after instant ADD COLUMN

[MDEV-15213] UPDATEs are slow after instant ADD COLUMN Created: 2018-02-05 Updated: 2023-12-14 Resolved: 2018-04-19
Status:	Closed
Project:	MariaDB Server
Component/s:	Data Definition - Alter Table, Data Manipulation - Update
Affects Version/s:	10.3.5
Fix Version/s:	10.3.6

Type:

Bug

Priority:

Major

Reporter:

Valerii Kravchuk

Assignee:

Axel Schwenke

Resolution:

Won't Fix

Votes:

Labels:

regression

Environment:

Ubuntu 14.04, Fedora 27

Attachments:

scaling.png

Issue Links:

Relates
relates to	~~MDEV-15914~~	performance regression for mass update	Closed

Description

Consider the following test case, test_instant_alter.sql (that was created mostly to illustrate how fast instant ADD COLUMN is relative to other statements against the table):

show variables like '%version%';

drop table if exists t;

create table t(id int auto_increment primary key, c1 int);

insert into t(c1) values (0);

insert into t(c1) select rand()*1000 from t;

insert into t(c1) select rand()*1000 from t;

insert into t(c1) select rand()*1000 from t;

insert into t(c1) select rand()*1000 from t;

insert into t(c1) select rand()*1000 from t;

insert into t(c1) select rand()*1000 from t;

insert into t(c1) select rand()*1000 from t;

insert into t(c1) select rand()*1000 from t;

insert into t(c1) select rand()*1000 from t;

insert into t(c1) select rand()*1000 from t;

insert into t(c1) select rand()*1000 from t;

insert into t(c1) select rand()*1000 from t;

insert into t(c1) select rand()*1000 from t;

insert into t(c1) select rand()*1000 from t;

insert into t(c1) select rand()*1000 from t;

insert into t(c1) select rand()*1000 from t;

insert into t(c1) select rand()*1000 from t;

insert into t(c1) select rand()*1000 from t;

insert into t(c1) select rand()*1000 from t;

select count(*) from t;

show table status like 't'\G

analyze table t;

show table status like 't'\G

alter table t add column c2 char(200) default repeat('a',200);

show table status like 't'\G

update t set c2 = 'b'; -- 1

update t set c2 = 'c'; -- 2

update t set c2 = 'd'; -- 3

analyze table t;

show table status like 't'\G

optimize table t;

show table status like 't'\G

show create table t\G

alter table t force;

update t set c2 = 'e'; -- 4

update t set c2 = 'f'; -- 5

analyze table t;

show table status like 't'\G

To prove the point (how fast is instant ALTER TABLE ... ADD COLUMN is and how much it influeces later changes to the rows of the table), I run it under MariaDB 10.3.5, 10.2.12 and Percona Server 5.7.20.

It turned out that while ALTER TABLE itself is indeed instant in 10.3.5, subsequent updates to all rows of the table that set non-default value to newly added column (marked with 1, 2 and 3 in the comments) are executed unexpectedly slow, both comparing to similar updates after full table rebuild (ALTER TABLE t FORCE, marked as 5 and 6 in the comments). Moreover, total time to run the entire test case is much worse on 10.35 comparing to 10.2.12 and other versions the same scenario was tested against.

Results are as follows, for example on my Ubuntu 14.04 netbook:

openxs@ao756:~/dbs/maria10.3$ time bin/mysql -vvv -uroot --socket=/tmp/mariadb.sock test <~/test_instant_alter.sql > ~/instant_1035_new_innodb.txt

real    6m46.066s

user    0m0.022s

sys     0m0.004s

openxs@ao756:~/dbs/maria10.2$ time bin/mysql -vvv -uroot --socket=/tmp/mariadb.sock test <~/test_instant_alter.sql > ~/instant_10212_innodb.txt

real    4m35.802s

user    0m0.014s

sys     0m0.013s

or the following on Fedroa 27 quadcore box:

[openxs@fc23 maria10.3]$ time bin/mysql -vvv -uroot --socket=/tmp/mariadb.sock test <~/test_instant_alter.sql > ~/instant_1035_innodb.txt

real    5m40.820s

user    0m0.009s

sys     0m0.005s

[openxs@fc23 maria10.2]$ time bin/mysql -vvv -uroot --socket=/tmp/mariadb.sock test <~/test_instant_alter.sql > ~/instant_10213_innodb.txt

real    3m46.452s

user    0m0.011s

sys     0m0.003s

In all cases servers where freshly installed and started with --no-defaults, like this:

openxs@ao756:~$ bin/mysqld_safe --no-defaults --port=3308 --socket=/tmp/mariadb.sock &

Relative times of individual statements were as follows, for example:

--------------

alter table t add column c2 char(200) default repeat('a',200)

--------------

Query OK, 0 rows affected (0.035 sec)

Records: 0  Duplicates: 0  Warnings: 0

--------------

show table status like 't'

--------------

*************************** 1. row ***************************

           Name: t

         Engine: InnoDB

        Version: 11

     Row_format: Dynamic

           Rows: 523848

 Avg_row_length: 31

    Data_length: 16269312

Max_data_length: 0

   Index_length: 0

      Data_free: 4194304

 Auto_increment: 786406

    Create_time: 2018-02-05 15:04:54

    Update_time: 2018-02-05 15:04:54

     Check_time: NULL

      Collation: latin1_swedish_ci

       Checksum: NULL

 Create_options:

        Comment:

1 row in set (0.000 sec)

--------------

update t set c2 = 'b'

--------------

Query OK, 524288 rows affected (56.504 sec)

Rows matched: 524288  Changed: 524288  Warnings: 0

--------------

update t set c2 = 'c'

--------------

Query OK, 524288 rows affected (56.892 sec)

Rows matched: 524288  Changed: 524288  Warnings: 0

--------------

update t set c2 = 'd'

--------------

Query OK, 524288 rows affected (1 min 3.755 sec)

Rows matched: 524288  Changed: 524288  Warnings: 0

...

--------------

alter table t force

--------------

Query OK, 0 rows affected (39.913 sec)

Records: 0  Duplicates: 0  Warnings: 0

--------------

update t set c2 = 'e'

--------------

Query OK, 524288 rows affected (27.636 sec)

Rows matched: 524288  Changed: 524288  Warnings: 0

--------------

update t set c2 = 'f'

--------------

Query OK, 524288 rows affected (1 min 35.323 sec)

Rows matched: 524288  Changed: 524288  Warnings: 0

In case of 10.2.12 we see:

--------------

alter table t add column c2 char(200) default repeat('a',200)

--------------

Query OK, 0 rows affected (30.02 sec)

Records: 0  Duplicates: 0  Warnings: 0

--------------

show table status like 't'

--------------

*************************** 1. row ***************************

           Name: t

         Engine: InnoDB

        Version: 11

     Row_format: Dynamic

           Rows: 516360

 Avg_row_length: 289

    Data_length: 149569536

Max_data_length: 0

   Index_length: 0

      Data_free: 5242880

 Auto_increment: 786406

    Create_time: 2018-01-30 19:18:45

    Update_time: NULL

     Check_time: NULL

      Collation: latin1_swedish_ci

       Checksum: NULL

 Create_options:

        Comment:

1 row in set (0.00 sec)

--------------

update t set c2 = 'b'

--------------

Query OK, 524288 rows affected (27.39 sec)

Rows matched: 524288  Changed: 524288  Warnings: 0

--------------

update t set c2 = 'c'

--------------

Query OK, 524288 rows affected (32.87 sec)

Rows matched: 524288  Changed: 524288  Warnings: 0

--------------

update t set c2 = 'd'

--------------

Query OK, 524288 rows affected (32.98 sec)

Rows matched: 524288  Changed: 524288  Warnings: 0

So, on 10.3.5 the time to execute UPDATE varies a lot, but is larger than in 10.2.12 after normal ALTER, and also those executed immediately after ALTER are usually slower.

Comments

Comment by Valerii Kravchuk [ 2018-02-08 ]

This is what I see in perf top when slow updates:

--------------

alter table t add column c2 char(200) default repeat('a',200)

--------------

Query OK, 0 rows affected (0.222 sec)

Records: 0  Duplicates: 0  Warnings: 0

--------------

show table status like 't'

--------------

*************************** 1. row ***************************

           Name: t

         Engine: InnoDB

        Version: 11

     Row_format: Dynamic

           Rows: 523848

 Avg_row_length: 31

    Data_length: 16269312

Max_data_length: 0

   Index_length: 0

      Data_free: 4194304

 Auto_increment: 786406

    Create_time: 2018-02-08 10:50:46

    Update_time: 2018-02-08 10:50:46

     Check_time: NULL

      Collation: latin1_swedish_ci

       Checksum: NULL

 Create_options:

        Comment:

1 row in set (0.000 sec)

--------------

update t set c2 = 'b'

--------------

Query OK, 524288 rows affected (44.923 sec)

Rows matched: 524288  Changed: 524288  Warnings: 0

--------------

update t set c2 = 'c'

--------------

Query OK, 524288 rows affected (1 min 0.146 sec)

Rows matched: 524288  Changed: 524288  Warnings: 0

--------------

update t set c2 = 'd'

--------------

Query OK, 524288 rows affected (1 min 4.180 sec)

Rows matched: 524288  Changed: 524288  Warnings: 0

were running (some samples):

  16.10%  mysqld               [.] ut_delay

  10.00%  mysqld               [.] btr_search_guess_on_hash

   8.85%  mysqld               [.] ha_insert_for_fold_func

   4.17%  mysqld               [.] buf_page_get_gen

   4.00%  mysqld               [.] PolicyMutex<TTASEventMutex<GenericPolicy> >::

   3.26%  mysqld               [.] rec_get_offsets_func

   2.60%  mysqld               [.] btr_cur_search_to_nth_level_func

   2.28%  mysqld               [.] mtr_t::Command::prepare_write

...

  16.40%  mysqld               [.] ut_crc32_sw

   9.07%  [kernel]             [k] copy_user_generic_string

   5.96%  mysqld               [.] ut_delay

   5.77%  mysqld               [.] ha_remove_all_nodes_to_page

   3.61%  mysqld               [.] ha_delete_hash_node

   3.55%  mysqld               [.] btr_search_guess_on_hash

   3.14%  mysqld               [.] ha_insert_for_fold_func

   3.09%  [kernel]             [k] memcpy

...

  12.23%  mysqld               [.] ut_delay

  11.54%  mysqld               [.] ut_crc32_sw

   6.32%  [kernel]             [k] copy_user_generic_string

   4.11%  mysqld               [.] buf_page_get_gen

   3.19%  mysqld               [.] ha_insert_for_fold_func

   2.77%  mysqld               [.] btr_search_guess_on_hash

   2.70%  mysqld               [.] ha_delete_hash_node

   2.55%  mysqld               [.] ha_remove_all_nodes_to_page

   2.39%  mysqld               [.] rec_get_offsets_func

   1.82%  mysqld               [.] PolicyMutex<TTASEventMutex<GenericPolicy> >::

   1.53%  mysqld               [.] rw_lock_x_lock_func

   1.49%  libc-2.26.so         [.] __memcpy_ssse3

   1.43%  mysqld               [.] btr_cur_search_to_nth_level_func

   1.37%  mysqld               [.] mtr_t::Command::execute

   1.33%  mysqld               [.] cmp_dtuple_rec_with_match_low

   1.27%  mysqld               [.] row_purge_step

   1.04%  mysqld               [.] mtr_t::Command::prepare_write

   1.00%  [kernel]             [k] memcpy

...

  14.88%  mysqld               [.] ut_crc32_sw

   8.30%  [kernel]             [k] copy_user_generic_string

   6.37%  mysqld               [.] ut_delay

   3.76%  mysqld               [.] ha_insert_for_fold_func

   3.06%  mysqld               [.] ha_remove_all_nodes_to_page

   3.00%  mysqld               [.] ha_delete_hash_node

   2.81%  mysqld               [.] buf_page_get_gen

   2.46%  mysqld               [.] rec_get_offsets_func

   2.38%  mysqld               [.] btr_search_guess_on_hash

   1.96%  libc-2.26.so         [.] __memcpy_ssse3

   1.64%  mysqld               [.] PolicyMutex<TTASEventMutex<GenericPolicy> >::

   1.51%  mysqld               [.] trx_undo_update_rec_get_update

...

  15.86%  mysqld               [.] ut_crc32_sw

   8.98%  [kernel]             [k] copy_user_generic_string

   3.90%  mysqld               [.] ut_delay

   3.87%  mysqld               [.] ha_insert_for_fold_func

   2.85%  mysqld               [.] buf_page_get_gen

   2.28%  mysqld               [.] btr_search_guess_on_hash

   2.28%  mysqld               [.] ha_delete_hash_node

   2.22%  libc-2.26.so         [.] __memcpy_ssse3

   2.21%  mysqld               [.] rec_get_offsets_func

   1.99%  mysqld               [.] ha_remove_all_nodes_to_page

...

  16.56%  mysqld               [.] ut_crc32_sw

   9.47%  [kernel]             [k] copy_user_generic_string

   4.06%  mysqld               [.] ut_delay

   3.99%  mysqld               [.] ha_delete_hash_node

   3.83%  mysqld               [.] ha_remove_all_nodes_to_page

   3.73%  mysqld               [.] ha_insert_for_fold_func

   2.46%  mysqld               [.] rec_get_offsets_func

   2.24%  mysqld               [.] btr_search_guess_on_hash

   2.10%  libc-2.26.so         [.] __memcpy_ssse3

   1.95%  mysqld               [.] buf_page_get_gen

   1.44%  mysqld               [.] PolicyMutex<TTASEventMutex<GenericPolicy> >::

   1.41%  mysqld               [.] row_purge_step

   1.30%  mysqld               [.] trx_undo_update_rec_get_update

...

Later after table rebuild updates are faster:

--------------

alter table t force

--------------

Query OK, 0 rows affected (22.529 sec)

Records: 0  Duplicates: 0  Warnings: 0

--------------

update t set c2 = 'e'

--------------

Query OK, 524288 rows affected (27.908 sec)

Rows matched: 524288  Changed: 524288  Warnings: 0

--------------

update t set c2 = 'f'

--------------

Query OK, 524288 rows affected (56.873 sec)

Rows matched: 524288  Changed: 524288  Warnings: 0

In perf top I see:

  19.37%  mysqld               [.] ut_crc32_sw

  13.05%  [kernel]             [k] copy_user_generic_string

   3.60%  libc-2.26.so         [.] __memcpy_ssse3

   3.53%  [kernel]             [k] memcpy

   1.84%  mysqld               [.] page_simple_validate_new

   1.06%  [kernel]             [k] syscall_return_via_sysret

   1.05%  [kernel]             [k] _raw_spin_lock_irqsave

   1.03%  mysqld               [.] ut_delay

   0.94%  mysqld               [.] LinuxAIOHandler::find_completed_slot

   0.87%  [kernel]             [k] iov_iter_fault_in_readable

   0.78%  [kernel]             [k] ext4_bio_write_page

   0.76%  [kernel]             [k] find_get_pages_tag

...

  13.52%  mysqld               [.] ut_crc32_sw

   9.30%  mysqld               [.] ut_delay

   8.58%  [kernel]             [k] copy_user_generic_string

   3.73%  mysqld               [.] buf_page_get_gen

   2.23%  mysqld               [.] btr_search_guess_on_hash

   2.15%  mysqld               [.] rec_get_offsets_func

   2.11%  libc-2.26.so         [.] __memcpy_ssse3

   1.80%  mysqld               [.] PolicyMutex<TTASEventMutex<GenericPolicy> >::

   1.64%  mysqld               [.] ha_insert_for_fold_func

   1.63%  mysqld               [.] btr_cur_search_to_nth_level_func

   1.46%  mysqld               [.] cmp_dtuple_rec_with_match_low

   1.34%  mysqld               [.] mtr_t::Command::execute

   1.30%  mysqld               [.] row_purge_step

   1.21%  mysqld               [.] rw_lock_x_lock_func

   1.17%  mysqld               [.] mtr_t::Command::prepare_write

   1.11%  [kernel]             [k] memcpy

   0.98%  mysqld               [.] mtr_t::Command::release_blocks

   0.97%  mysqld               [.] trx_undo_update_rec_get_update

   0.86%  mysqld               [.] page_cur_search_with_match

...

  15.56%  mysqld               [.] ut_crc32_sw

   9.18%  [kernel]             [k] copy_user_generic_string

   3.81%  mysqld               [.] ut_delay

   3.45%  mysqld               [.] ha_delete_hash_node

   3.24%  mysqld               [.] ha_insert_for_fold_func

   3.12%  mysqld               [.] ha_remove_all_nodes_to_page

   2.55%  libc-2.26.so         [.] __memcpy_ssse3

   2.22%  mysqld               [.] rec_get_offsets_func

   2.18%  mysqld               [.] btr_search_guess_on_hash

   2.09%  mysqld               [.] buf_page_get_gen

   1.65%  mysqld               [.] row_purge_step

   1.56%  mysqld               [.] PolicyMutex<TTASEventMutex<GenericPolicy> >::

   1.42%  mysqld               [.] mtr_t::Command::execute

   1.23%  mysqld               [.] trx_undo_update_rec_get_update

   1.09%  mysqld               [.] cmp_dtuple_rec_with_match_low

   0.90%  mysqld               [.] mtr_t::Command::prepare_write

   0.88%  mysqld               [.] page_simple_validate_new

...

Comment by Marko Mäkelä [ 2018-04-08 ]

In the perf top, I do not see any obvious InnoDB functions. The btr_search_guess_on_hash() is for the adaptive hash index. The adaptive hash index is only built on key columns, and instantly added columns have special format in the clustered index only.

I would be interested in call graphs of what got more expensive. That would be perf top -g or preferably perf record --call-graph (for the duration of the UPDATE) followed by some perf report.

Is UPDATE slow when you only update ‘core’ columns (those that were not instantly added)?
Does it make a difference if the updated columns have non-default values for the instantly added columns?
What if you first ADD COLUMN, then separately CREATE INDEX? How do updates of indexed instantly added columns perform compared to the baseline (ADD COLUMN, ADD INDEX, FORCE)?

The benchmark seems to involve UPDATE of an instantly added column from a non-default value to another. The initial update from default value to non-default is faster than an update from non-default to non-default. Did I get that correctly?

Comment by Axel Schwenke [ 2018-04-08 ]

Here some numbers from my tests. I tried first with data on hard disk and small (default) buffers. The numbers were wildly varying. Then I retried with datadir on SSD and a buffer pool large enough to hold the data set. Now the numbers are fairly stable.

I tested 3 cases:

1. create + fill the table with 3 columns, update the third column in all (1 mio) rows.
MariaDB 10.2.14: 1.94 .. 2.23 sec
MariaDB 10.3.5: 2.41 .. 2.73 sec

2. create table with 2 columns, fill it, add third column, update as above.
MariaDB 10.2.14: 1.91 .. 2.05 sec
MariaDB 10.3.5: 11.94 sec (first update), 2.44 .. 2.91 sec (subsequent updates)

3. create table with 2 columns, fill it, add third column, alter table force, update as above.
MariaDB 10.2.14: 1.86 .. 2.13 sec
MariaDB 10.3.5: 2.0 .. 2.85 sec

Conlcusions:

10.3.5 is consistently slower for this workload than 10.2.14
the first UPDATE after instant ADD COLUMN is significantly slower; this is what I expect anyway

I also observe that the UPDATE overhead after instant ADD COLUMN is higher than the time for ALTER TABLE FORCE (or ADD COLUMN in 10.2). The ALTER TABLE takes ~ 2.5 sec. Yet the time for updating all rows grows from 2.5 sec to nearly 12 sec.

Comment by Marko Mäkelä [ 2018-04-08 ]

axel, thank you. There seem to be some noise in your numbers; cases 1 and 3 should be identical in 10.3, and cases 1,2,3 should be identical in 10.2.

Did you test updating the column back to its default value (whatever SELECT would return immediately after the ALTER TABLE…ADD COLUMN?

The time to execute a table-rebuilding ALTER should be proportional to the number of rows, the number of indexes, and the size of the indexed columns, while the time to execute instant ADD COLUMN should be pretty much instantaneous (provided that there is no DML operation that would prevent the instant ALTER from acquiring an exclusive lock). If ~~MDEV-11369~~ instant ADD COLUMN was used, all records of the table will remain in the "instant ALTER" format until the table or partition becomes empty, or until it is truncated or rebuilt.

It looks like we have to find out why the UPDATE in the general case has become slower. Can you post some call graphs from perf, comparing 10.2 and 10.3?

Comment by Valerii Kravchuk [ 2018-04-08 ]

All kinds of noise aside, the first UPDATE to a non-default value for new column added with instant ALTER is unexpectedly slow in all my tests so far.

Comment by Marko Mäkelä [ 2018-04-08 ]

valerii, that the first UPDATE to a non-default value of an instantly added column is slower is a design feature and cannot be addressed. The underlying reason ought to be that pages will have to be split as the records grow bigger. I do not think we can do much about this case. It should be similar to first inserting a number of records with a VARCHAR field being the empty string, and then updating the values to longer strings. Updating back to an empty string (or rolling back the original update) should be faster, because the sparsely filled pages would not be merged immediately. Can you confirm this?

What is not expected is that other forms of UPDATE are slower in MariaDB 10.3 than in 10.2, especially when no instant ADD was used. That we can and should do something about.

Comment by Axel Schwenke [ 2018-04-10 ]

More numbers, this time from 100 executions of the UPDATE.
MariaDB 10.3.5:

+--------------+-----------+-----------+-----------+

| label        | min       | avg       | max       |

+--------------+-----------+-----------+-----------+

| case 1       |  2.503336 |  2.940933 |  3.476728 |

| case 2       |  2.531204 |  2.928061 |  3.930623 |

| case 2 first | 11.588176 | 11.588176 | 11.588176 |

| case 3       |  2.250255 |  2.945323 |  3.235695 |

+--------------+-----------+-----------+-----------+

marko I hope case 1 and 3 are now close enough? I'm also very satisfied that case 2 is just as close (except the first execution of the update, of course).

Here the numbers for MariaDB-10.2.14:

+--------------+----------+----------+----------+

| label        | min      | avg      | max      |

+--------------+----------+----------+----------+

| case 1       |  1.69808 | 2.000246 |  2.30575 |

| case 2       | 1.643595 | 1.928849 | 2.420083 |

| case 2 first | 2.537558 | 2.537558 | 2.537558 |

| case 3       | 1.625349 | 1.958550 | 2.450954 |

+--------------+----------+----------+----------+

Here are the SQL scripts I used.

test.sql:

use test;

\. benchmark.sql

set @iterations=100;

drop table if exists t1;

create table t1 (id serial, c1 int, c2 char(10) default 'foobar');

insert into t1 (c1) values (rand()*1000);

insert into t1 (c1) select rand()*1000 from t1;

... (19 more times)

call xl_benchmark('case 1', 'update t1 set c2="x"', @iterations);

drop table if exists t1;

create table t1 (id serial, c1 int);

insert into t1 (c1) values (rand()*1000);

insert into t1 (c1) select rand()*1000 from t1;

... (19 more times)

alter table t1 add column c2 char(10) default 'foobar';

call xl_benchmark('case 2 first', 'update t1 set c2="x"', 1);

call xl_benchmark('case 2', 'update t1 set c2="x"', @iterations);

drop table if exists t1;

create table t1 (id serial, c1 int);

insert into t1 (c1) values (rand()*1000);

insert into t1 (c1) select rand()*1000 from t1;

... (19 more times)

alter table t1 add column c2 char(10) default 'foobar';

alter table t1 force;

call xl_benchmark('case 3', 'update t1 set c2="x"', @iterations);

select label, min(duration) as min, round(avg(duration),6) as avg,

max(duration) as max from timing group by label;

and the procedure from benchmark.sql:

drop table if exists timing;

create table timing(id serial, label char(20), duration double);

delimiter !!

drop procedure if exists xl_benchmark!!

create procedure xl_benchmark

  in label char(20),

  in workload char(255),

  in repetitions int unsigned

begin

  prepare stmt1 from workload;

  set @counter=0;

  repeat

    set @t1=now(6);

    execute stmt1;

    set @t2=now(6);

    insert into timing (label, duration)

      values (label, unix_timestamp(@t2)-unix_timestamp(@t1));

    set @counter = @counter+1;

  until @counter >= repetitions end repeat;

  deallocate prepare stmt1;

end !!

delimiter ;

Comment by Marko Mäkelä [ 2018-04-16 ]

Thanks. One more thing that could be tested just to validate my hypothesis is:

Create a table with a VARCHAR column.
Insert many rows with an empty VARCHAR value.
Update the rows to a longer VARHCAR value (not too long, so that the columns will remain in-page).
Update the rows back to empty VARCHAR.

I believe that the first update to a longer value will be slower, because it will result in page splits. Later, when the long record values are updated to be shorter again, the pages would not be merged, and subsequent updates (to any value not exceeding the length of the first updated value) should be fast.

Please file a separate ticket for the UPDATE performance regression compared to MariaDB 10.2. I think that analyzing it will require some use of perf record with call graph collection enabled.

Comment by Axel Schwenke [ 2018-04-16 ]

Here you go marko:

+---------------+----------+----------+----------+

| label         | min      | avg      | max      |

+---------------+----------+----------+----------+

| insert empty  | 0.712973 | 0.843348 | 1.003764 |

| insert string | 0.576478 | 0.741412 | 0.923602 |

+---------------+----------+----------+----------+

and this is the test case:

create table t1 (id serial, c1 int, c2 char(10) default '');

insert into t1 (c1) values (rand()*1000);

insert into t1 (c1) select rand()*1000 from t1;

-- repeat last insert 17 times, yields 256K rows

update t1 set c2="foobar";

update t1 set c2="";

I repeated everything 100 times. The unexpected outcome is, that updating the rows to a longer row image (causing page splits) is actually faster than the second update where the row image shrinks.

Comment by Axel Schwenke [ 2018-04-16 ]

Here is another interesting result. Above I mentioned that ALTER TABLE ... FORCE after the instantly added column runs 5x faster than the full table update while both had the same effect of adding the new column to each rows image.

I was curious if that holds for different table sizes, so I cooked a test case where I create the table and fill it with some rows, then INSTANT ADD a column with default "foobar" and measure the time for ALTER TABLE FORCE. Then I do the same, but instead of ALTER TABLE FORCE I do a full table update, setting the new column to "snafu!" (not the default value, but the same number of chars). The second variant I call "expand", the first "force".

Here are the execution times for different table sizes:

scale expand force ratio
-----------------------------
15 0,38 0,24 158%
16 0,83 0,39 216%
17 1,32 1,14 116%
18 2,98 1,38 215%
19 5,95 1,78 335%
20 11,22 2,70 415%
21 23,93 3,70 647%
22 48,36 6,34 763%
23 106,82 12,31 868%
24 242,10 24,67 982%
25 630,39 45,21 1394%

"sacle" is ld(rownum). So the line with scale=20 corresponds to the test case I used before.

Now the funny thing is that ALTER TABLE FORCE scales better than linear where "expand" grows about linear. Execution time for "expand" doubles when the number of rows doubles (scale increases by 1). But "force" is faster than that.

I put both series in a log-log diagram and added a regression line. ALTER TABLE is not exactly on that line, but "expand" very much. See attached image scaling.png.

Comment by Marko Mäkelä [ 2018-04-19 ]

axel, you could also test rebuilding the table with ALTER TABLE t1 ALGORITHM=COPY. That should be slower than ALTER TABLE t1 FORCE (when it is executed by ALGORITHM=INPLACE). The reason is that with MySQL 5.7’s WL#7277 in MariaDB 10.2, the table is being built one page at a time, rather than one row at a time. With ALGORITHM=COPY for large tables, the results may be skewed due to the InnoDB change buffer.

In any case, there is not much that can be done to improve the performance of the UPDATE instantly added columns from the initially default values to something else, and I think that this issue should be closed as "Won’t fix".

The generic UPDATE performance regression in 10.3 will be covered by ~~MDEV-15914~~.

Comment by Axel Schwenke [ 2018-04-19 ]

The observed behavior of the first UPDATE being slow is expected. It's also not slower than expected.

Comment by Marko Mäkelä [ 2023-12-14 ]

~~MDEV-26740~~ has been filed for the fact that the native ALTER TABLE (without ALGORITHM=COPY) is growing the data files quicker.

Generated at Thu Feb 08 08:19:32 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.

[MDEV-15213] UPDATEs are slow after instant ADD COLUMN Created: 2018-02-05 Updated: 2023-12-14 Resolved: 2018-04-19