0

I am having this problem in a recurrent way, in different projects, and different databases.

MySQL version

SHOW VARIABLES LIKE "%version%";

Variable_name   Value
immediate_server_version    999999
innodb_version  8.0.15
original_server_version 999999
protocol_version    10
slave_type_conversions  
tls_version TLSv1,TLSv1.1,TLSv1.2
version 8.0.15
version_comment Source distribution
version_compile_machine x86_64
version_compile_os  Linux
version_compile_zlib    1.2.11

(It is an AWS RDS instance)

I have this table:

CREATE TABLE `my_table` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
  `field_X` int(11) DEFAULT NULL,
  `field_X` varchar(255) COLLATE utf8_unicode_ci DEFAULT NULL,
  `field_X` varchar(255) COLLATE utf8_unicode_ci DEFAULT NULL,
  `field_X` varchar(255) COLLATE utf8_unicode_ci DEFAULT NULL,
  `field_X` varchar(255) COLLATE utf8_unicode_ci DEFAULT NULL,
  `field_X` int(11) DEFAULT NULL,
  `field_X` varchar(255) COLLATE utf8_unicode_ci DEFAULT NULL,
  `field_X` int(11) DEFAULT NULL,
  `field_X` decimal(8,4) NOT NULL,
  `field_X` int(11) DEFAULT NULL,
  `field_X` int(11) DEFAULT NULL,
  `field_X` int(11) DEFAULT NULL,
  `field_X` int(11) DEFAULT NULL,
  `field_X` tinyint(1) DEFAULT NULL,
  `field_X` tinyint(1) DEFAULT NULL,
  `field_X` tinyint(1) DEFAULT NULL,
  `field_X` varchar(255) COLLATE utf8_unicode_ci DEFAULT NULL,
  `field_X` varchar(255) COLLATE utf8_unicode_ci DEFAULT NULL,
  `field_X` longtext COLLATE utf8_unicode_ci,
  `field_X` longtext COLLATE utf8_unicode_ci,
  `field_X` longtext COLLATE utf8_unicode_ci,
  `field_X` longtext COLLATE utf8_unicode_ci,
  `field_X` varchar(255) COLLATE utf8_unicode_ci DEFAULT NULL,
  `field_X` mediumtext COLLATE utf8_unicode_ci,
  `field_X` longtext COLLATE utf8_unicode_ci,
  `field_X` mediumtext COLLATE utf8_unicode_ci,
  `field_X` datetime DEFAULT NULL,
  `field_X` datetime DEFAULT NULL,
  `field_X` datetime DEFAULT NULL,
  `field_X` datetime DEFAULT NULL,
  `field_X` datetime DEFAULT NULL,
  `field_X` int(11) DEFAULT '0',
  `field_X` int(11) DEFAULT NULL,
  PRIMARY KEY (`id`),
  UNIQUE KEY `index_surveys_on_offer_uuid` (`field_X`),
  KEY `index_surveys_on_survey_id` (`field_X`),
  KEY `index_surveys_on_api_synch_state` (`field_X`),
  KEY `index_survey_sync_flags` (`field_X`,`field_X`,`field_X`,`field_X`),
  KEY `index_surveys_on_created_at` (`field_X`)
) ENGINE=InnoDB AUTO_INCREMENT=154046 DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci;

(Field names anonymised, hope they are not needed to provide with solutions or suggestions)

It is a big table with ~2M records (can be cases where there are more, or less that this)

My intention is to delete old data from this table and I start doing this queries:

delete from my_table where created_at < date_sub(now(), interval 6 month) limit 10000;
  • The first run takes 12 seconds
  • The second run takes 1 minute
  • The third run takes 12 minutes

The table starts to not be responsible. It takes a moment that I can not even run a query like this:

select * from my_table limit 1;

I don't see any process blocked when I check show full processlist;

Desperately I try to reboot the MySQL server but after rebooting the table is still stuck.

After a while (~2 hours), though, the table becomes responsive again.

Here there are some information extraction from the time the table was stuck:

show engine innodb status
SELECT * FROM information_schema.innodb_trx

This information was added days latter, when the table is not longer stuck:

SHOW INDEX FROM my_table;
SHOW GLOBAL VARIABLES
SHOW GLOBAL STATUS

What is the reason of this behaviour? how can I avoid it?

  • 1
    Game time is over. For assistance, post TEXT results of A) SHOW CREATE TABLE tbl_name; B) SHOW INDEX FROM tbl_name; Your 'show engine innodb status' last page indicates you are reading over 40,000 rows per second. With this information, we should be able to help you. – Wilson Hauck Sep 28 at 22:17
  • 1
    Please also post TEXT results of A) SHOW CREATE TABLE surveys; B) SHOW INDEX FROM surveys; Also your 'history list length' is over 400,000 indicating significant delays are plaguing your instance. Do you have SSD or NVME data storage? Please post to pastebin.com (to avoid storage limit) TEXT results of SHOW GLOBAL VARIABLES; and SHOW GLOBAL STATUS; for workload analysis and suggestions. – Wilson Hauck Sep 28 at 22:31
  • 2
    @JesusUzcanga - date_sub(now(), interval 6 month) is a "constant" expression. It will be evaluated into a constant (such as "2019-04-08 00:29:00"). – Rick James Oct 8 at 0:29
  • 2
    OPTIMIZE TABLE will probably take so long that it is not worth doing. – Rick James Oct 8 at 0:30
  • 2
    @WilsonHauck - Number of cores is unlikely to matter since this DELETE (or OPTIMIZE or ...) will use only one core. – Rick James Oct 8 at 0:31
5

Don't delete more than 1000 at a time. All the rows being deleted are saved in case of a crash (or reboot) so that they can be restored. (cf Atomicity.) This also explains why the table was non-responsive after the reboot.

Index updates are delayed (cf Change Buffering). This may explain why subsequent deletes got slower -- the updates to the indexes were backlogged and needed flushing.

UUIDs are terrible for performance because of how random they are.

I would expect created_at (what you are deleting on) to closely track id (which is AUTO_INCREMENT), thereby meaning that each of your DELETEs deleting the "first" 10K rows of the table. But, if not, then see this for how to walk through the table much more efficiently: http://mysql.rjweb.org/doc.php/deletebig#deleting_in_chunks

If you are deleting "a lot" of the table, it is much faster to copy over the rows to keep. Details: http://mysql.rjweb.org/doc.php/deletebig#deleting_more_than_half_a_table

Having an index starting with created_at would help. But it would take a long time to add such an index.

If this deletion task needs to be done regularly, then see this for using partitioning to make the task almost instantaneous: http://mysql.rjweb.org/doc.php/partitionmaint

Meanwhile, one of the queries mentioned in InnoDB Status may benefit from INDEX(historizable_id, historizable_type) -- in either order.

  • Thanks a lot also for these comments, it helps a lot to receive educated suggestions. – fguillen Oct 10 at 11:52
  • @fguillen - "big deletes" is a common problem, so I wrote that page on various ways to improve on it. And your use case is one of the very few real uses for partitioning, hence that other blog. – Rick James Oct 10 at 15:21
2

Analysis of VARIABLEs and STATUS:

Observations:

  • Version: 8.0.15
  • 16 GB of RAM
  • Uptime = 61d 02:53:06
  • Are you sure this was a SHOW GLOBAL STATUS ?
  • You are not running on Windows.
  • Running 64-bit version
  • You appear to be running entirely (or mostly) InnoDB.

The More Important Issues:

How much RAM? (This analysis assumes 16G.)

Your machine is generally quite busy. I can't tell if you are pushing the limits of the hardware you are using. Increasing RAM may help.

Raising innodb_log_file_size to 1G (from 128M) may help. However, depending on the version, etc, it may be complicated to make the change.

Raise innodb_io_capacity to 1000 (from 200), especially if you have SSDs.

Where practical, combine multiple queries into a single transaction. (Currently it seems that each query is its own transaction.)

Details and other observations:

( Innodb_buffer_pool_pages_flushed ) = 712,703,856 / 5280786 = 134 /sec -- Writes (flushes) -- check innodb_buffer_pool_size (now 11811160064)

( table_open_cache ) = 4,000 -- Number of table descriptors to cache -- Several hundred is usually good.

( innodb_lru_scan_depth * innodb_page_cleaners ) = 1,024 * 4 = 4,096 -- Amount of work for page cleaners every second. -- "InnoDB: page_cleaner: 1000ms intended loop took ..." may be fixable by lowering lru_scan_depth: Consider 1000 / innodb_page_cleaners (now 4)

( innodb_page_cleaners / innodb_buffer_pool_instances ) = 4 / 8 = 0.5 -- innodb_page_cleaners -- Recommend setting innodb_page_cleaners (now 4) to innodb_buffer_pool_instances (now 8)

( innodb_lru_scan_depth ) = 1,024 -- "InnoDB: page_cleaner: 1000ms intended loop took ..." may be fixed by lowering lru_scan_depth

( (Innodb_buffer_pool_reads + Innodb_buffer_pool_pages_flushed) ) = ((78842623 + 712703856) ) / 5280786 = 149 /sec -- InnoDB I/O -- Increase innodb_buffer_pool_size (now 11811160064)?

( Innodb_pages_written/Innodb_data_writes ) = 712,703,870/4159979444 = 17.1% -- Seems like these values should be equal?

( Innodb_os_log_written ) = 4,582,891,422,720 / 5280786 = 867842 /sec -- This is an indicator of how busy InnoDB is. -- Very idle or very busy InnoDB.

( Innodb_log_writes ) = 3,370,974,466 / 5280786 = 638 /sec

( Innodb_os_log_written / (Uptime / 3600) / innodb_log_files_in_group / innodb_log_file_size ) = 4,582,891,422,720 / (5280786 / 3600) / 2 / 128M = 11.6 -- Ratio -- (see minutes)

( Uptime / 60 * innodb_log_file_size / Innodb_os_log_written ) = 5,280,786 / 60 * 128M / 4582891422720 = 2.58 -- Minutes between InnoDB log rotations Beginning with 5.6.8, this can be changed dynamically; be sure to also change my.cnf. -- (The recommendation of 60 minutes between rotations is somewhat arbitrary.) Adjust innodb_log_file_size (now 134217728). (Cannot change in AWS.)

( Innodb_dblwr_writes ) = 69,857,937 / 5280786 = 13 /sec -- "Doublewrite buffer" writes to disk. "Doublewrites" are a reliability feature. Some newer versions / configurations don't need them. -- (Symptom of other issues)

( innodb_io_capacity ) = 200 -- I/O ops per second capable on disk . 100 for slow drives; 200 for spinning drives; 1000-2000 for SSDs; multiply by RAID factor.

( innodb_print_all_deadlocks ) = innodb_print_all_deadlocks = OFF -- Whether to log all Deadlocks. -- If you are plagued with Deadlocks, turn this on. Caution: If you have lots of deadlocks, this may write a lot to disk.

( join_buffer_size / _ram ) = 262,144 / 16384M = 0.00% -- 0-N per thread. May speed up JOINs (better to fix queries/indexes) (all engines) Used for index scan, range index scan, full table scan, each full JOIN, etc. -- If large, decrease join_buffer_size (now 262144) to avoid memory pressure. Suggest less than 1% of RAM. If small, increase to 0.01% of RAM to improve some queries.

( net_buffer_length / max_allowed_packet ) = 16,384 / 64M = 0.02%

( local_infile ) = local_infile = ON -- local_infile (now ON) = ON is a potential security issue

( (Queries-Questions)/Queries ) = (2072796273-3665450)/2072796273 = 99.8% -- Fraction of queries that are inside Stored Routines. -- (Not bad if high; but it impacts the validity of some other conclusions.)

( (Com_insert + Com_update + Com_delete + Com_replace) / Com_commit ) = (9395934 + 1028486573 + 66454 + 0) / 1031172250 = 1.01 -- Statements per Commit (assuming all InnoDB) -- Low: Might help to group queries together in transactions; High: long transactions strain various things.

( Select_scan / Com_select ) = 828,881 / 3499461 = 23.7% -- % of selects doing full table scan. (May be fooled by Stored Routines.) -- Add indexes / optimize queries

( Com_insert + Com_delete + Com_delete_multi + Com_replace + Com_update + Com_update_multi ) = (9395934 + 66454 + 0 + 0 + 1028486573 + 0) / 5280786 = 196 /sec -- writes/sec -- 50 writes/sec + log flushes will probably max out I/O write capacity of normal drives

( expire_logs_days ) = 0 -- How soon to automatically purge binlog (after this many days) -- Too large (or zero) = consumes disk space; too small = need to respond quickly to network/machine crash. (Not relevant if log_bin (now OFF) = OFF)

( slave_pending_jobs_size_max / max_allowed_packet ) = 128M / 64M = 2 -- For parallel slave threads -- slave_pending_jobs_size_max (now 134217728) must not be less than max_allowed_packet (now 67108864)

( slow_query_log ) = slow_query_log = OFF -- Whether to log slow queries. (5.1.12)

( long_query_time ) = 10 -- Cutoff (Seconds) for defining a "slow" query. -- Suggest 2

( thread_cache_size / max_connections ) = 20 / 1282 = 1.6% -- (0 for Windows)

( thread_cache_size / Max_used_connections ) = 20 / 8 = 250.0% -- There is no advantage in having the thread cache bigger than your likely number of connections. Wasting space is the disadvantage.

Abnormally small:

Com_set_option = 0.62 /HR
Created_tmp_files = 0.0041 /HR
Handler_read_next / Handler_read_key = 0.0155
Handler_read_rnd_next / Handler_read_rnd = 0.64
Table_locks_immediate = 12 /HR
gtid_executed_compression_period = 0.68 /HR
range_optimizer_max_mem_size = 0

Abnormally large:

Bytes_received = 12895796 /sec
Com_begin = 195 /sec
Com_commit = 195 /sec
Com_commit + Com_rollback = 195 /sec
Com_flush = 12 /HR
Com_repair = 0.00068 /HR
Com_show_slave_status = 60 /HR
Com_slave_start = 0.033 /HR
Com_slave_stop = 0.012 /HR
Com_update = 194 /sec
Innodb_data_fsyncs = 369 /sec
Innodb_data_pending_fsyncs = 0.21 /HR
Innodb_data_writes = 787 /sec
Innodb_data_writes - Innodb_log_writes - Innodb_dblwr_writes = 136 /sec
Innodb_data_written = 5734842 /sec
Innodb_dblwr_pages_written = 134 /sec
Innodb_log_write_requests = 1986 /sec
Innodb_os_log_fsyncs = 335 /sec
Innodb_os_log_pending_fsyncs = 1
Innodb_os_log_written / (Uptime / 3600) / innodb_log_files_in_group = 1,489.8MB
Innodb_pages_written = 134 /sec
Innodb_rows_updated = 390 /sec
Ssl_accepts = 29a
Ssl_finished_accepts = 29
Ssl_used_session_cache_entries = 3
back_log / max_connections = 100.0%
innodb_max_dirty_pages_pct_lwm = 10
innodb_undo_tablespaces = 2
max_error_count = 1,024
max_length_for_sort_data = 4,096
optimizer_trace_max_mem_size = 1.05e+6
slave_pending_jobs_size_max = 128MB

Abnormal strings:

event_scheduler = ON
gtid_mode = OFF_PERMISSIVE
innodb_data_home_dir = /rdsdbdata/db/innodb
innodb_fast_shutdown = 1
innodb_undo_log_truncate = ON
log_output = TABLE
log_statements_unsafe_for_binlog = OFF
optimizer_trace = enabled=off,one_line=off
optimizer_trace_features = greedy_search=on, range_optimizer=on, dynamic_range=on, repeated_subselect=on
read_only = ON
relay_log_recovery = ON
session_track_system_variables = time_zone, autocommit, character_set_client, character_set_results, character_set_connection
slave_exec_mode = IDEMPOTENT
slave_rows_search_algorithms = INDEX_SCAN,HASH_SCAN
time_zone = UTC
transaction_write_set_extraction = XXHASH64
  • I don't know how express all the appreciation I am feeling. Your effort will be properly used, I am learning a lot of things reading your comment. As a start I see how desperately we need to check the basic configuration of our servers. Would be great to have someone as you in our team ;) – fguillen Oct 10 at 8:30
  • @fguillen - Thanks. But, for most systems, one only needs to make sure that innodb_buffer_pool_size is correct, leaving everything else at default values. Running an in-depth analysis like this can point out a very busy system (like yours) may benefit from some other tweaks. – Rick James Oct 10 at 15:19

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.