MariaDB 10.6 issue with blocked queries that can't be killed

Question

We have AWS RDS database, MariaDB 10.6.8, and we are facing some issues with queries being blocked, the main issue is that queries would lock the table and this would cause more blocked queries:

show open tables where in_use > 0 ;

Database	Table	In_use	Name_locked
x	x	156	0

We started seeing this issue after upgrading from MariaDB 10.2 to 10.6

Even after killing the queries, the query would still appear in "show full process list" (only the state would change to KILLED), this would create a lot of open connections and only restarting the database would reset everything back to normal.

This is the default variable that we have "SHOW VARIABLES;" : https://pastebin.com/SHeBZ4RW

We have changed a lot of variables like connect_timeout, innodb_roolback_on_timeout, idle_transaction_timeout but nothing seemed to help.

We have doubts that 2 queries would block each other and this would block the entire table.

This is the output we get with "show engine innodb status;": https://pastebin.com/yjZnCeAC

This is the output we get with "show global status;": https://pastebin.com/E6Vhb7w3

This issue would increase the number of connections to the database and sometime the database itself would stop responding, we would have to restart the DB again to make it working again but most of the time we restart the DB to unblock the tables and make the workflow we have running again

Restarting the database would take 20 min and we can't keep doing it each time.

The blocked queries could be because of the running transaction but nothing would be return when we run the following queries:

SELECT * FROM information_schema.INNODB_LOCKs;

SELECT * FROM information_schema.INNODB_LOCK_waits;

This issue is getting annoying and we can't seem to solve it

Thanks

Answer 1

Are the "amazon%" tables yours? Or AWS's?

The slowlog could help you identify the slowest queries; analyzing them may lead to improvements that prevent the problem.

Meanwhile, here are some crude comments on some of the queries that were slow enough to be captured by the INNODB STATUS:

SELECT  *
    FROM  adjustment_processes
    WHERE  (sp_keywords_adjusted != ''2022-08-24''
              AND  sp_keywords_enabled = 1
           )
      OR  (sb_keywords_adjusted != ''2022-08-24''
              AND  sb_keywords_enabled = 1
          )
      OR  (sp_targets_adjusted != ''2022-08-24''
              AND  sp_targets_enabled = 1
          )
      OR  (sb_targets_adjusted != ''2022-08-24''
              AND  sb_targets_enabled = 1
          )
      OR  (sd_targets_adjusted != ''2022-08-24''
              AND  sd_targets_enabled = 1
          )
    ORDER BY  RAND()
    LIMIT  1

It may be possible to speed that up by using UNION instead of OR. Also, here are some RAND() tricks (that may or may not help): http://mysql.rjweb.org/doc.php/random

update  `amazon_prepared_target_performance_data`
    set `update_adjustment` = ''20220824''
    where  `target_id` = 78682371592585 

Is there an INDEX(target_id) ?

select  `campaign_id`, SUM(impressions) as impressions, SUM(clicks) as clicks,
        SUM(cost) as cost, SUM(conversions_7d) as conversions,
        SUM(sales_7d) as sales
    from  `amazon_campaign_performance_data`
    where  `campaign_id` in (100490644238876, 79703517421422,
                254432794562076, 242368355219340, 211750405271747, 16269064883056,
                97105174682211, 79790903133152, 140744679864595, 77849018300231,

The end of that is not showing, but if it doing a date range and/or group by, then a Summary Table may speed it up considerably.

        SELECT  `id`
            from  `company_countries`
            where  `profile_id` = 1694427117928582

Hopefully, there is an index starting with profile_id?

select  SUM(amazon_order_items.quantity_ordered *
            amazon_mws_costs.total_price) as SUM
    from  `amazon_order_items`
    inner join  `amazon_orders`
        ON `amazon_orders`.`id` = `amazon_order_items`.`amazon_order_id`
    left join  `amazon_mws_costs`
        ON `amazon_mws_costs`.`cid` = `amazon_order_items`.`cid`
    where  `amazon_order_items`.`asin` in (''B08PFNWDTQ'')
      and  `amazon_orders`.`company_countries_id` in (
        SELECT  `id`
            from  `company_countries`
            where  `profile_id` = 1694427117928582
                          )
      and  `amazon_orders`.`purchase_date`
               between ''2022-06-25 00:00''
                   AND ''2022-08-24 23:59''

I would like to see the rest of it, plus EXPLAIN SELECT ...; there are some likely index suggestions.

Answer 2

Analysis of GLOBAL STATUS and VARIABLES:

Observations:

• Version: 10.6.8-MariaDB-log
• 256 GB of RAM (assumed size)
• Uptime = 05:48:07; some GLOBAL STATUS values may not be meaningful yet.
• 2.12e+4 Queries/sec : 7.2e+3 Questions/sec

The More Important Issues:

Suggested changes:

innodb_io_capacity = 3000
innodb_lru_scan_depth = 512
innodb_lock_wait_timeout = 50  -- more below
thread_pool_size = 128
connect_timeout = 120
tx_isolation = REPEATABLE-READ  -- more below

You might experiment with innodb_change_buffering = all. 10.7 changed the default to "none". However, in doing so, updates to non-UNIQUE secondary index is slowed down by a small amount (for the sake of safety). I don't know enough about the change nor about your app to give a solid recommendataion. See https://mariadb.com/kb/en/innodb-change-buffering/

innodb_lock_wait_timeout is set to 12 minutes. This can lead to transactions hanging around a long time when it is possibly better for them to be aborted and retried.

Max_statement_time_exceeded about ever 4 minutes -- This is a clue of something. Maybe you have set the limit too high; maybe some queries need better indexes and/or reformulating.

`Created_tmp_disk_tables = 412 /sec Better indexes and reformulation of queries are likely to help.

Update_scan = 13 /sec -- This seems high. Check index usage on UPDATEs.

tx_isolation = READ-COMMITTED -- This is abnormal; was it a deliberate decision?

How is the RAM utilization? I can't definitively tell whether it RAM is too big or too small. How much data?

Details and other observations:

( Key_reads + Key_writes + Innodb_pages_read + Innodb_pages_written + Innodb_dblwr_writes + Innodb_buffer_pool_pages_flushed ) = (0 + 0 + 41438449 + 7258170 + 55053 + 7258170) / 20887 = 2681 /sec -- IOPs? -- If the hardware can handle it, set innodb_io_capacity (now 2000) to about this value.

( ( Key_reads + Key_writes + Innodb_pages_read + Innodb_pages_written + Innodb_dblwr_writes + Innodb_buffer_pool_pages_flushed ) / innodb_io_capacity / Uptime ) = ( 0 + 0 + 41438449 + 7258170 + 55053 + 7258170 ) / 2000 / 20887 = 134.1% -- This may be a metric indicating what innodb_io_capacity is set reasonably. -- Increase innodb_io_capacity (now 2000) if the hardware can handle it.

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

( innodb_lru_scan_depth ) = 1,536 -- innodb_lru_scan_depth is a very poorly named variable. A better name would be innodb_free_page_target_per_buffer_pool. It is a number of pages InnoDB tries to keep free in each buffer pool instance to speed up read and page creation operations. -- "InnoDB: page_cleaner: 1000ms intended loop took ..." may be fixed by lowering lru_scan_depth

( Innodb_buffer_pool_reads ) = (0 + 0 + 41438449 + 7258170 + 55053 + 7258170) / 20887 = 1972 /sec -- Cache misses in the buffer_pool. -- Increase innodb_buffer_pool_size (now 197568495616)? (~100 is limit for HDD, ~1000 is limit for SSDs.)

( innodb_change_buffering ) = innodb_change_buffering = none -- Pre-5.6.11 / 5.5.31, there was a bug that made ="changes" a safer option.

( Innodb_os_log_written ) = 6139221 /sec -- This is an indicator of how busy InnoDB is. -- Very busy InnoDB.

( Innodb_history_list_length ) = 12,115,447 = 1.21e+7 -- see innodb_change_buffering ?

( default_tmp_storage_engine ) = default_tmp_storage_engine =

( Innodb_row_lock_waits ) = 0.39 /sec -- How often there is a delay in getting a row lock. -- May be caused by complex queries that could be optimized.

( innodb_lock_wait_timeout ) = 7,200 (seconds) -- Two battling InnoDB transactions, but not a deadlock -- one will wait this long (seconds) in hopes of getting the desired locks. -- Fix the cause of timeouts rather than increasing this value.

( ( Innodb_pages_read + Innodb_pages_written ) / Uptime / innodb_io_capacity ) = ( 41438449 + 7258170 ) / 20887 / 2000 = 116.6% -- If > 100%, need more io_capacity. -- Increase innodb_io_capacity (now 2000) if the drives can handle it.

( innodb_strict_mode ) = innodb_strict_mode = OFF -- When ON, this catches some subtle errors earlier. -- OFF leaves some warnings as warnings; ON makes them errors.

( innodb_flush_log_at_trx_commit ) = 0 -- 1 = secure; 2 = faster -- (You decide) Use 1, along with sync_binlog (now 0)=1 for the greatest level of fault tolerance. 0 is best for speed. 2 is a compromise between 0 and 1.

( sync_binlog ) = 0 -- Use 1 for added security, at some cost of I/O =1 may lead to lots of "query end"; =0 may lead to "binlog at impossible position" and lose transactions in a crash, but is faster. 0 is OK for Galera.

( 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.

( max_connections ) = 16,000 -- Maximum number of connections (threads). Impacts various allocations. -- If max_connections (now 16000) is too high and various memory settings are high, you could run out of RAM.

( Max_statement_time_exceeded ) = 18 /HR -- Identify long-running statements that have been aborted.

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

( Questions ) = 7204 /sec -- Queries (outside SP) -- "qps" -- >2000 may be stressing server

( Queries ) = 21226 /sec -- Queries (including inside SP) -- >3000 may be stressing server

( Created_tmp_tables ) = 909 /sec -- Frequency of creating "temp" tables as part of complex SELECTs.

( Created_tmp_disk_tables ) = 412 /sec -- Frequency of creating disk "temp" tables as part of complex SELECTs -- increase tmp_table_size (now 134217728) and max_heap_table_size (now 423054278656). Check the rules for temp tables on when MEMORY is used instead of MyISAM. Perhaps minor schema or query changes can avoid MyISAM. Better indexes and reformulation of queries are more likely to help.

( Created_tmp_disk_tables / Questions ) = 8,620,588 / 150482616 = 5.7% -- Pct of queries that needed on-disk tmp table. -- Better indexes / No blobs / etc.

( Created_tmp_disk_tables / Created_tmp_tables ) = 8,620,588 / 18993077 = 45.4% -- Percent of temp tables that spilled to disk -- Maybe increase tmp_table_size (now 134217728) and max_heap_table_size (now 423054278656); improve indexes; avoid blobs, etc.

( Handler_read_rnd_next ) = 2,848,315 /sec -- High if lots of table scans -- possibly inadequate keys

( Com_insert + Com_delete + Com_delete_multi + Com_replace + Com_update + Com_update_multi ) = (1109546 + 84807 + 3 + 5250 + 23866165 + 422) / 20887 = 1200 /sec -- writes/sec -- Lots of writes

( Com__biggest ) = Com__biggest = Com_stmt_execute -- Which of the "Com_" metrics is biggest. -- Normally it is Com_select (now 122516652).

( binlog_format ) = binlog_format = MIXED -- STATEMENT/ROW/MIXED. -- ROW is preferred by 5.7 / 10.3

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

( Max_used_connections / max_connections ) = 672 / 16000 = 4.2% -- Peak % of connections -- Since several memory factors can expand based on max_connections (now 16000), it is good not to have that setting too high.

( Max_used_connections ) = 672 -- High-water mark for connections -- Lots of inactive connections is OK; over 100 active connections is likely to be a problem. Max_used_connections (now 672) does not distinguish them; Threads_running (now 158) is instantaneous.

( Connections ) = (1109546 + 84807 + 3 + 5250 + 23866165 + 422) / 20887 = 63 /sec -- Connections -- Increase wait_timeout (now 7200); use pooling?

( Threads_running - 1 ) = 158 - 1 = 157 -- Active threads (concurrency when data collected) -- Optimize queries and/or schema A value of more than, say, twice the number of CPU cores is likely to indicate overloading.

( thread_pool_size ) = 64 -- Number of 'thread groups'. Limits how many treads can be executing at once. Probably should not be much bigger than the number of CPUs. -- Don't set much higher than the number of CPU cores.

( thread_pool_max_threads ) = 65,536 -- One of many settings for MariaDB's thread pooling -- Lower the value.

( connect_timeout ) = 7,200 -- DOS attack vulnerability if too large

Abnormally small:

Innodb_adaptive_hash_non_hash_searches = 0
Innodb_log_writes / Innodb_log_write_requests = 0.04%
Innodb_master_thread_active_loops = 0
Memory_used = 0.10%
Memory_used_initial = 15.7MB
binlog_expire_logs_seconds = 0
deadlock_timeout_long = 7,200
lock_wait_timeout = 7,200
query_cache_limit = 0
table_open_cache / max_connections = 0.375

Abnormally large:

( Innodb_pages_read + Innodb_pages_written ) / Uptime = 2,331
Acl_column_grants = 6
Acl_table_grants = 37
Aria_pagecache_read_requests = 74872 /sec
Aria_pagecache_write_requests = 15618 /sec
Aria_pagecache_writes = 160 /sec
Binlog_bytes_written = 959376 /sec
Binlog_cache_use = 579 /sec
Binlog_commits = 579 /sec
Binlog_group_commits = 578 /sec
Busy_time = 445,998
Bytes_received = 3730067 /sec
Bytes_sent = 21791837 /sec
Com_begin = 33 /sec
Com_kill = 0.86 /HR
Com_purge = 12 /HR
Com_select = 5865 /sec
Com_show_charsets = 7.6 /HR
Com_show_open_tables = 0.52 /HR
Com_show_storage_engines = 0.86 /HR
Com_stmt_close = 7010 /sec
Com_stmt_execute = 7012 /sec
Com_stmt_prepare = 7010 /sec
Com_stmt_send_long_data = 6.9 /HR
Com_update = 1142 /sec
Cpu_time = 387,362
Created_tmp_files = 0.49 /sec
Feature_check_constraint = 0.17 /HR
Feature_subquery = 49 /sec
Feature_timezone = 19295 /sec
Feature_window_functions = 62 /HR
Handler_commit = 7622 /sec
Handler_discover = 0.69 /HR
Handler_icp_attempts = 1985623 /sec
Handler_icp_match = 1000573 /sec
Handler_prepare = 1183 /sec
Handler_read_key = 210017 /sec
Handler_read_next = 3688326 /sec
Handler_read_retry = 0.24 /sec
Handler_read_rnd = 33992 /sec
Handler_read_rnd_deleted = 27 /sec
Handler_tmp_update = 50706 /sec
Handler_tmp_write = 236195 /sec
Handler_update = 1946 /sec
Innodb_buffer_pool_pages_data = 1.75e+7
Innodb_buffer_pool_pages_dirty = 240,866
Innodb_buffer_pool_pages_lru_flushed = 203
Innodb_buffer_pool_pages_made_not_young = 68043 /sec
Innodb_buffer_pool_pages_made_young = 2090 /sec
Innodb_buffer_pool_pages_misc = 1.84e+19
Innodb_buffer_pool_pages_misc * 16384 / innodb_buffer_pool_size = 152975530820962.7%
Innodb_buffer_pool_pages_old = 6.47e+6
Innodb_buffer_pool_pages_total = 1.19e+7
Innodb_buffer_pool_read_requests = 9282510 /sec
Innodb_buffer_pool_write_requests = 58711 /sec
Innodb_buffer_pool_write_requests / Innodb_buffer_pool_pages_flushed = 168
Innodb_checkpoint_age = 2.83e+9
Innodb_data_read = 18933360 /sec
Innodb_data_reads = 1992 /sec
Innodb_data_writes - Innodb_log_writes - Innodb_dblwr_writes = 347 /sec
Innodb_dblwr_pages_written = 323 /sec
Innodb_dblwr_pages_written / Innodb_dblwr_writes = 122
Innodb_ibuf_free_list = 2.53e+6
Innodb_ibuf_segment_size = 2.53e+6
Innodb_log_write_requests = 3901 /sec
Innodb_mem_dictionary = 1,119.3MB
Innodb_pages_created = 24 /sec
Innodb_pages_read = 1983 /sec
Innodb_pages_read + Innodb_pages_written = 2331 /sec
Innodb_pages_written = 347 /sec
Innodb_rows_read = 6384955 /sec
Innodb_rows_updated = 1897 /sec
Innodb_secondary_index_triggered_cluster_reads = 1613699 /sec
Open_streams = 4
Opened_plugin_libraries = 0.17 /HR
Prepared_stmt_count = 167
Rows_tmp_read = 286948 /sec
Select_full_range_join = 0.77 /sec
Select_range = 94 /sec
Sort_priority_queue_sorts = 281 /sec
Sort_range = 48 /sec
Sort_rows = 12703 /sec
Sort_scan = 782 /sec
Ssl_accepts = 713
Ssl_default_timeout = 7,200
Ssl_finished_accepts = 713
Ssl_verify_depth = 1.84e+19
Ssl_verify_mode = 5
Subquery_cache_hit = 5273 /sec
Table_open_cache_hits = 18785 /sec
Threads_cached = 210
Threads_connected = 358
Threads_running = 158
Update_scan = 269,330
host_cache_size = 1,403
idle_readonly_transaction_timeout = 1,800
idle_transaction_timeout = 1,800
idle_write_transaction_timeout = 1,800
max_heap_table_size = 403456MB
max_statement_time = 7,200
net_read_timeout = 120
net_write_timeout = 120
performance_schema_max_statement_classes = 222

Abnormal strings:

Slave_heartbeat_period = 0
Slave_received_heartbeats = 0
aria_recover_options = BACKUP,QUICK
character_set_system = utf8mb3
disconnect_on_expired_password = OFF
ft_boolean_syntax = + -><()~*:&
ignore_db_dirs = #rocksdb
innodb_data_home_dir = /rdsdbdata/db/innodb
log_bin_trust_function_creators = ON
log_slow_verbosity = innodb,query_plan,explain
myisam_stats_method = NULLS_UNEQUAL
old_alter_table = DEFAULT
old_mode = UTF8_IS_UTF8MB3
optimizer_trace = enabled=off
relay_log_recovery = ON
replicate_ignore_table = mysql.rds_sysinfo, mysql.rds_configuration, mysql.rds_replication_status, mysql.rds_history
slave_parallel_mode = optimistic
sql_slave_skip_counter = 0
time_zone = UTC
tx_isolation = READ-COMMITTED
userstat = ON