Bug #46525 5.1.36: innodb: updates / alter table exremley slow
Submitted: 3 Aug 12:16 Modified: 19 Nov 17:26
Reporter: Harald Reindl
Status: Open
Category:Server: InnoDB Severity:S5 (Performance)
Version: OS:Linux
Assigned to: Target Version:

[3 Aug 12:16] Harald Reindl
Description:
The following query runs since 1611 seconds
I am nearly sure that this performance-gains exists since upgrade to mysql 5.1
Few weeks ago with 5.0.83 i made an alter table on a innodb-table with 30 GB data and it
was fast and used the whole disk-performance 

"update dbmail_messages set status=3 where deleted_flag=1 and status!=3"

Also a null-alter-table on innodb-tables with mysql 5.1 to reduce filesize does take a
very long time even if the table is > 100 MB, there is no real disk-io and no cpu-usage
this time and so i wonder what mysql does the whole time 

I do not think it's our configuration but at the end i post the content of my.cnf from
the machine which has 7.5 GB RAM and could write nearly 100 MB/Sec. to disk

mysql> select count(*) from dbmail_messages;
+----------+
| count(*) |
+----------+
|    99080 |
+----------+

CREATE TABLE `dbmail_messages` (
  `message_idnr` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
  `mailbox_idnr` bigint(10) unsigned NOT NULL DEFAULT '0',
  `physmessage_id` bigint(20) unsigned NOT NULL DEFAULT '0',
  `seen_flag` tinyint(3) unsigned NOT NULL DEFAULT '0',
  `answered_flag` tinyint(3) unsigned NOT NULL DEFAULT '0',
  `deleted_flag` tinyint(3) unsigned NOT NULL DEFAULT '0',
  `flagged_flag` tinyint(3) unsigned NOT NULL DEFAULT '0',
  `recent_flag` tinyint(3) unsigned NOT NULL DEFAULT '0',
  `draft_flag` tinyint(3) unsigned NOT NULL DEFAULT '0',
  `unique_id` varchar(70) NOT NULL DEFAULT '',
  `status` tinyint(3) unsigned zerofill NOT NULL DEFAULT '000',
  PRIMARY KEY (`message_idnr`),
  KEY `physmessage_id_index` (`physmessage_id`),
  KEY `mailbox_idnr_index` (`mailbox_idnr`),
  KEY `seen_flag_index` (`seen_flag`),
  KEY `unique_id_index` (`unique_id`),
  KEY `status_index` (`status`),
  KEY `mailbox_status` (`mailbox_idnr`,`status`),
  CONSTRAINT `dbmail_messages_ibfk_1` FOREIGN KEY (`physmessage_id`) REFERENCES
`dbmail_physmessage` (`id`) ON DELETE CASCADE ON UPDATE CASCADE,
  CONSTRAINT `dbmail_messages_ibfk_2` FOREIGN KEY (`mailbox_idnr`) REFERENCES
`dbmail_mailboxes` (`mailbox_idnr`) ON DELETE CASCADE ON UPDATE CASCADE
) ENGINE=InnoDB AUTO_INCREMENT=214199 DEFAULT CHARSET=utf8;

[mysqld]
language                   = /usr/share/mysql/german
socket                     = /var/lib/mysql/mysql.sock
datadir                    = /Volumes/dune/mysql_data
pid-file                   = /Volumes/dune/mysql_data/mysql.pid
tmpdir                     = /tmp
default-character-set      = utf8
default-collation          = utf8_general_ci
character-set-server       = utf8
collation-server           = utf8_general_ci
default-storage-engine     = innodb
lower_case_table_names     = 1
port                       = 3306
old_passwords              = 1
local-infile               = 0
thread_concurrency         = 5

max_allowed_packet         = 250M
max_connections            = 500
max_tmp_tables             = 150
max_connect_errors         = 200
max_delayed_threads        = 20

flush_time                 = 0
query_cache_limit          = 50K
query_cache_size           = 600M
query_cache_type           = 1
table_cache                = 512
thread_cache               = 512
tmp_table_size             = 768M
max_heap_table_size        = 768M

key_buffer                 = 650M
sort_buffer_size           = 1M
sort_buffer                = 1M
read_rnd_buffer_size       = 1M
read_rnd_buffer            = 1M
join_buffer_size           = 256K
read_buffer                = 128K
read_buffer_size           = 128K
record_buffer              = 128K
preload_buffer             = 256K
myisam_sort_buffer_size    = 256K

innodb_buffer_pool_size    = 1536M
innodb_log_file_size       = 512M
innodb_log_buffer_size     = 128M
innodb_thread_concurrency  = 5
innodb_flush_log_at_trx_commit = 2
innodb_support_xa          = 0
innodb_lock_wait_timeout   = 50
innodb_flush_method        = O_DIRECT
innodb_max_purge_lag       = 1

low-priority-updates
skip-symbolic-links
skip-mrg_myisam
safe-user-create
safe-show-database
slave_compressed_protocol
innodb_file_per_table
large-pages
memlock

How to repeat:
I can reproduce this even if i have a samll table with 200 records
"update table set field=1" takes a long time for few KB data
"update table set field=1 where field=0" is much faster

remember: 
this happens with small data and few records and needs up to 20 seconds the website hangs
[3 Aug 12:37] Valeriy Kravchuk
Thank you for the problem report. Please, send the result of:

explain select * from dbmail_messages where deleted_flag=1 and status!=3;

Also please run your slow update and send the results of

SHOW INNODB STATUS\G

immediately after that.
[3 Aug 13:06] Harald Reindl
explain, innodb status, mysqltuner....

Attachment: bug_summary.txt (text/plain), 10.72 KiB.

[17 Aug 10:50] Susanne Ebrecht
How did you upgrade?

Did you re-create all indexes on your InnoDB tables?
[17 Aug 11:01] Harald Reindl
I used "mysql_upgrade -u root -p" twice, the scond time with force
But this also affects tables which are dropped and created new because we were in
dbmail-evaluation and wanted to get rid of the test data

We are using innodb_per_table, so i think after drop-create there should be no problems
with old data-formats
[4 Sep 14:10] Harald Reindl
Same with 5.1.38 and innodb-Plugin instead of builtin
I try to compress some inno-tables on the backup-machine (replication-slave) and see that
there are locks which are the real problem, if the table would not be locked while alter
this would not hurt so much because it could compress a week in background

How comes with "innodb_table_locks = 0"?

6866 | Locked | INSERT INTO dbmail_datefield (physmessage_id, datefield)....
773 | copy to tmp table | alter table dbmail_datefield ROW_FORMAT=COMPRESSED
[19 Nov 8:16] Valeriy Kravchuk
Please, send the results of:

show create table dbmail_messages\G
show table status like 'dbmail_messages'\G

I see that update scans entire table (and lock every row as a result)...
[19 Nov 17:24] Harald Reindl
Thank you for your reply
Here the two outputs from our backup-machine (vmware machine)
This one has a small innodb_buffer_pool, but even with bigger or uncompressed tables it's
all the same

mysql> show table status like 'dbmail_messages';
+-----------------+--------+---------+------------+--------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-----------------+----------+-----------------------+---------+
| Name            | Engine | Version | Row_format | Rows   | Avg_row_length | Data_length
| Max_data_length | Index_length | Data_free | Auto_increment | Create_time         |
Update_time | Check_time | Collation       | Checksum | Create_options        | Comment
|
+-----------------+--------+---------+------------+--------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-----------------+----------+-----------------------+---------+
| dbmail_messages | InnoDB |      10 | Compressed | 101924 |            125 |    12812288
|               0 |     29720576 |   2097152 |         762415 | 2009-09-13 05:22:16 | NULL
       | NULL       | utf8_general_ci |     NULL | row_format=COMPRESSED |         |
+-----------------+--------+---------+------------+--------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-----------------+----------+-----------------------+---------+
1 row in set (1.27 sec)

dbmail_messages | CREATE TABLE `dbmail_messages` (                                       
       
  `message_idnr` bigint(20) unsigned NOT NULL AUTO_INCREMENT,                            
         
  `mailbox_idnr` bigint(10) unsigned NOT NULL DEFAULT '0',                               
         
  `physmessage_id` bigint(20) unsigned NOT NULL DEFAULT '0',                             
         
  `seen_flag` tinyint(3) unsigned NOT NULL DEFAULT '0',                                  
         
  `answered_flag` tinyint(3) unsigned NOT NULL DEFAULT '0',                              
         
  `deleted_flag` tinyint(3) unsigned NOT NULL DEFAULT '0',                               
         
  `flagged_flag` tinyint(3) unsigned NOT NULL DEFAULT '0',                               
         
  `recent_flag` tinyint(3) unsigned NOT NULL DEFAULT '0',                                
         
  `draft_flag` tinyint(3) unsigned NOT NULL DEFAULT '0',                                 
         
  `unique_id` varchar(70) NOT NULL DEFAULT '',                                           
         
  `status` tinyint(3) unsigned NOT NULL DEFAULT '0',                                     
         
  PRIMARY KEY (`message_idnr`),                                                          
         
  KEY `physmessage_id_index` (`physmessage_id`),                                         
         
  KEY `mailbox_idnr_index` (`mailbox_idnr`),                                             
         
  KEY `seen_flag_index` (`seen_flag`),                                                   
         
  KEY `unique_id_index` (`unique_id`),
  KEY `status_index` (`status`),
  KEY `mailbox_status` (`mailbox_idnr`,`status`),
  KEY `deleted_flag_index` (`deleted_flag`),
  CONSTRAINT `dbmail_messages_ibfk_1` FOREIGN KEY (`physmessage_id`) REFERENCES
`dbmail_physmessage` (`id`) ON DELETE CASCADE ON UPDATE CASCADE,
  CONSTRAINT `dbmail_messages_ibfk_2` FOREIGN KEY (`mailbox_idnr`) REFERENCES
`dbmail_mailboxes` (`mailbox_idnr`) ON DELETE CASCADE ON UPDATE CASCADE
) ENGINE=InnoDB AUTO_INCREMENT=762415 DEFAULT CHARSET=utf8 ROW_FORMAT=COMPRESSED
[19 Nov 17:26] Harald Reindl
Thats the result after the query has finsihed

Database changed
mysql> update `dbmail_messages` set status=3 where deleted_flag=1 and status!=3;
Query OK, 227 rows affected (1 min 14.66 sec)
Datensätze gefunden: 227  Geändert: 227  Warnungen: 0