0

We have a mariadb instance hosted on Ubuntu 22.04. We are regularly seeing some threads getting stalled on relatively high activity tables(although the tables are not huge ones). Once stuck, it never recovers. Other threads wanting to run queries on the same table wait for stuck thread to release lock. Eventually all threads of mariadb get stuck denying any more connections. The stuck thread doesn't respond to kill from mariadb's console. Stopping the service doesn't work as the service waits for the hung thread to finish. I have to kill the process which probably restarts mariadb (happens too fast to find out).

Mariadb version: 10.6.16-MariaDB-0ubuntu0.22.04.1

The hangs occur for different tables across databases, but I can confirm that most of the times it happens on relatively larger tables/more frequently updated tables (350000+) records.

Can someone give more hints to look for? I saw a similar post and a reply but in my case the hang is unrecoverable so posting a separate question.

CPU, Memory and IO looks completely normal. There's just a spike in Context Switches/Interrupts count.

Update 1: Added System Details CPU - 2 vCPUs of AMD EPYC 3rd Gen CPU RAM - 8 GB Disk- 40GB Virtual HDD running on RAID 5 cluster of 4 x 1TB SAS Disks (10K RPM) Host - VMWare ESXI 7

Update 2: Addition context based on Rick's questions:

  • There are 8-10 DBs and this is an ERP Product hence the number of tables. - We've had similar number of tables elsewhere also without issues.
  • The issue has been found on only two instances running mariadb 10.6.16. Other VMs on this Host and in cloud run other versions of mariadb and don't show this behavior.

Update 3: Right now I see high number of CTXT on one the threads. strace shows below with loads of clock_nanosleep calls. SHOW PROCESSLIST; returns no running queries. Previously I noticed this on the thread that got stuck on a query. I now suspect that this may not be related to a specific query/table and the hanging of query could be consequence of this abnormality (I'm not an expert just guessing).

Trace of process 4110982 - /usr/sbin/mariadbd

strace: Process 4110982 attached
05:52:13.926759 restart_syscall(<... resuming interrupted read ...>) = 0 <0.000024>
05:52:13.927361 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=100000}, 0x7f86a39e85d0) = 0 <0.000238>
05:52:13.927641 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=100000}, 0x7f86a39e85d0) = 0 <0.000238>
05:52:13.927919 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=100000}, 0x7f86a39e85d0) = 0 <0.000240>
05:52:13.928199 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=100000}, 0x7f86a39e85d0) = 0 <0.000245>
05:52:13.928483 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=100000}, 0x7f86a39e85d0) = 0 <0.000247>
05:52:13.928768 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=100000}, 0x7f86a39e85d0) = 0 <0.000247>
...
2
  • How much RAM? Use the SlowLog .
    – Rick James
    Feb 9 at 18:36
  • Updated system specs in question and enabled slowlog. Will share the results.
    – vamyip
    Feb 10 at 15:31

3 Answers 3

1

We've upgraded Mariadb to version 10.6.17 5 days ago and haven't seen the issue again. Although we're still monitoring, its most likely resolved.

0

These indexes might help:

`tabGL Entry`:  INDEX(company, docstatus, party_type, party,  -- in any order
                      account_currency)  -- last
tabDefaultValue:  INDEX(defkey, parent)  -- in any order)

For more discussion please provide SHOW CREATE TABLE for any tables mentioned in SHOW ENGINE INNODB STATUS.

0

(Nothing jumps out as being helpful for the problem at hand.)

Analysis of GLOBAL STATUS and VARIABLES:
 

Observations:

  • Version: 10.6.16-MariaDB-0ubuntu0.22.04.1
  • 8 GB of RAM -- my assumption
  • Uptime = 3d 06:48:17
  • 10.9 QPS

The More Important Issues:

There seem to be lots of tables; please explain.

Suggested changes to settings:

table_open_cache = 5000  -- Lots of table activity
key_buffer_size = 20M    -- Save a little RAM

Why are SHOW CREATE TABLE, etc being used so often? (I don't know if thisis part of the problem.)

Do you have any FULLTEXT indexes on InnoDB tables?

Turn on the slowlog with long_query_time = 1; see SlowLog. This is likely to provide some extra clues.

Details and other observations:

( Key_blocks_used * 1024 / key_buffer_size ) = 5,218 * 1024 / 128M = 4.0% -- Percent of key_buffer used. High-water-mark. -- Lower key_buffer_size (now 134217728) to avoid unnecessary memory usage.

( Opened_table_definitions ) = 404169 / 283697 = 1.4 /sec -- Frequency of opening .frm files -- Increase table_definition_cache (now 400) and/or table_open_cache (now 2000).

( Table_open_cache_overflows ) = 385248 / 283697 = 1.4 /sec -- May need to increase table_open_cache (now 2000)

( Table_open_cache_misses ) = 4876114 / 283697 = 17 /sec -- May need to increase table_open_cache (now 2000)

( Table_open_cache_misses / (Table_open_cache_hits + Table_open_cache_misses) ) = 4,876,114 / (2398700 + 4876114) = 67.0% -- Effectiveness of table_open_cache. -- Increase table_open_cache (now 2000) and check table_open_cache_instances (now 8).

( 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_io_capacity ) = 200 -- When flushing, use this many IOPs. -- Reads could be slugghish or spiky. Use 2000 if using SSD drive.

( Innodb_buffer_pool_pages_old / Innodb_buffer_pool_pages_total ) = 110,190 / 194688 = 56.6% -- Pct of buffer_pool that is "old".

( innodb_io_capacity_max / innodb_io_capacity ) = 2,000 / 200 = 10 -- Capacity: max/plain -- Recommend 2. Max should be about equal to the IOPs your I/O subsystem can handle. (If the drive type is unknown 2000/200 may be a reasonable pair.)

( Innodb_buffer_pool_read_ahead_evicted / Innodb_buffer_pool_read_ahead ) = 31,051 / 76567 = 40.6% -- Utility of read_ahead. -- Turn off innodb_random_read_ahead (now OFF).

( Innodb_dblwr_pages_written/Innodb_pages_written ) = 12,945/14467 = 89.5% -- Seems like these values should be equal?

( Uptime / 60 * innodb_log_file_size / Innodb_os_log_written ) = 283,697 / 60 * 96M / 123828736 = 3,843 -- Minutes between InnoDB log rotations Beginning with 5.6.8, innodb_log_file_size can be changed dynamically; I don't know about MariaDB. Be sure to also change my.cnf -- (The recommendation of 60 minutes between rotations is somewhat arbitrary.) Adjust innodb_log_file_size (now 100663296). (Cannot change in AWS.)

( Innodb_history_list_length ) = 8,448 -- See innodb_change_buffering (now none)?

( Innodb_row_lock_time_avg ) = 42,857 -- Avg time to lock a row (millisec) -- Possibly conflicting queries; possibly table scans.

( Innodb_row_lock_time_max ) = 50,000 -- Max time to lock a row (millisec) -- Possibly conflicting queries; possibly table scans.

( innodb_flush_neighbors ) = innodb_flush_neighbors = 1 -- A minor optimization when writing blocks to disk. -- Use 0 for SSD drives; 1 for HDD.

( 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. Limits write IO requests per second (IOPS). -- For starters: HDD: 200; SSD: 2000.

( innodb_flush_log_at_trx_commit ) = 1 -- 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.

( innodb_ft_result_cache_limit ) = 2,000,000,000 / 8192M = 23.3% -- Byte limit on FULLTEXT resultset. (It grows as needed.) -- Lower the setting.

( (Com_show_create_table + Com_show_fields) / Questions ) = (20644 + 103091) / 3103150 = 4.0% -- Naughty framework -- spending a lot of effort rediscovering the schema. -- Complain to the 3rd party vendor.

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

( Created_tmp_disk_tables / Questions ) = 125,309 / 3103150 = 4.0% -- Pct of queries that needed on-disk tmp table. -- Better indexes / No blobs / etc.

( Created_tmp_disk_tables / Created_tmp_tables ) = 125,309 / 154502 = 81.1% -- Percent of temp tables that spilled to disk -- Maybe increase tmp_table_size (now 16777216) and max_heap_table_size (now 16777216); improve indexes; avoid blobs, etc.

( Com_rollback / (Com_commit + Com_rollback) ) = 13,767 / (141262 + 13767) = 8.9% -- Rollback : Commit ratio -- Rollbacks are costly; change app logic

( (Com_insert + Com_update + Com_delete + Com_replace) / Com_commit ) = (56334 + 32370 + 34366 + 0) / 141262 = 0.871 -- Statements per Commit (assuming all InnoDB) -- Low: Might help to group queries together in transactions; High: long transactions strain various things.

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

( 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

( back_log ) = 80 -- (Autosized as of 5.6.6; based on max_connections) -- Raising to min(150, max_connections (now 151)) may help when doing lots of connections.

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

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

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

You have the Query Cache half-off. You should set both query_cache_type = OFF and query_cache_size = 0 . There is (according to a rumor) a 'bug' in the QC code that leaves some code on unless you turn off both of those settings.

Abnormally small:

Com_show_status = 0.038 /HR
Handler_read_next / Handler_read_key = 0.631
Handler_write = 0.22 /sec
Innodb_background_log_sync = 0.66 /sec
Innodb_log_write_requests = 0.047 /sec

Abnormally large:

Com_release_savepoint = 0.51 /HR
Com_rollback_to_savepoint = 0.072 /sec
Com_savepoint = 0.51 /HR
Handler_savepoint = 0.51 /HR
Handler_savepoint_rollback = 0.072 /sec
Innodb_buffer_pool_pages_lru_flushed = 5,634
Innodb_buffer_pool_pages_lru_freed = 129,456
Innodb_dblwr_pages_written / Innodb_dblwr_writes = 73.6
Innodb_deadlocks / Com_commit = 0.00%
Innodb_log_writes / Innodb_log_write_requests = 363.9%
Memory_used = 42.3%
Memory_used_initial = 3,365.7MB
Open_streams = 4
Threads_running = 20
innodb_lru_scan_depth / innodb_io_capacity = 7.68
innodb_purge_batch_size = 1,000
performance_schema_max_statement_classes = 222

Abnormal strings:

Innodb_have_snappy = ON
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 = + -><()~*:"&
innodb_fast_shutdown = 1
innodb_use_native_aio = OFF
old_alter_table = DEFAULT
old_mode = UTF8_IS_UTF8MB3
optimizer_trace = enabled=off

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

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