Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-24322

Assertion failure in file /home/buildbot/buildbot/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_P REFIX/mariadb-10.5.6/storage/innobase/trx/trx0trx.cc line 1329

Details

    Description

      See below error dump & attached core dump, happens sporadically resulting in dropping of all connections and evacuation of cache taking around 20 seconds to recover. In each case it is a random simple select that causes the issue. All tables are innodb and have been mysqlcheck'd with no issue found. Issue did not occur under 10.4 but coincided with move to 10.5. System is not under excessive load at the time the problems manifests. Problem also was manifest in 10.5.5

      2020-12-01 11:11:36 0x7f474137d700  InnoDB: Assertion failure in file /home/buildbot/buildbot/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX/mariadb-10.5.6/storage/innobase/trx/trx0trx.cc line 1329
      InnoDB: Failing assertion: UT_LIST_GET_LEN(lock.trx_locks) == 0
      InnoDB: We intentionally generate a memory trap.
      InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
      InnoDB: If you get repeated assertion failures or crashes, even
      InnoDB: immediately after the mysqld startup, there may be
      InnoDB: corruption in the InnoDB tablespace. Please refer to
      InnoDB: https://mariadb.com/kb/en/library/innodb-recovery-modes/
      InnoDB: about forcing recovery.
      201201 11:11:36 [ERROR] mysqld got signal 6 ;
      This could be because you hit a bug. It is also possible that this binary
      or one of the libraries it was linked against is corrupt, improperly built,
      or misconfigured. This error can also be caused by malfunctioning hardware.
       
      To report this bug, see https://mariadb.com/kb/en/reporting-bugs
       
      We will try our best to scrape up some info that will hopefully help
      diagnose the problem, but since we have already crashed,
      something is definitely wrong and this may fail.
       
      Server version: 10.5.6-MariaDB-log
      key_buffer_size=67108864
      read_buffer_size=1048576
      max_used_connections=624
      max_threads=1252
      thread_count=462
      It is possible that mysqld could use up to
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2660907 K  bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.
       
      Thread pointer: 0x7f44840b6ef8
      Attempting backtrace. You can use the following information to find out
      where mysqld died. If you see no messages after this, something went
      terribly wrong...
      stack_bottom = 0x7f474137cc90 thread_stack 0x49000
      Can't start addr2line
      /usr/sbin/mariadbd(my_print_stacktrace+0x2e)[0x5581d45b00ae]
      /usr/sbin/mariadbd(handle_fatal_signal+0x307)[0x5581d3fb15d7]
      /lib64/libpthread.so.0(+0xf630)[0x7f7f13604630]
      /lib64/libc.so.6(gsignal+0x37)[0x7f7f1165e387]
      /lib64/libc.so.6(abort+0x148)[0x7f7f1165fa78]
      /usr/sbin/mariadbd(+0x64c5b7)[0x5581d3c8f5b7]
      /usr/sbin/mariadbd(+0xdaa307)[0x5581d43ed307]
      /usr/sbin/mariadbd(+0xdaa433)[0x5581d43ed433]
      /usr/sbin/mariadbd(+0xdaa714)[0x5581d43ed714]
      /usr/sbin/mariadbd(+0xc4c83c)[0x5581d428f83c]
      /usr/sbin/mariadbd(+0xc57893)[0x5581d429a893]
      /usr/sbin/mariadbd(_ZN7handler16ha_external_lockEP3THDi+0x261)[0x5581d3fbd651]
      /usr/sbin/mariadbd(+0xa6ae4a)[0x5581d40ade4a]
      /usr/sbin/mariadbd(_Z24mysql_unlock_read_tablesP3THDP13st_mysql_lock+0x72)[0x5581d40ae6d2]
      /usr/sbin/mariadbd(_ZN4JOIN9join_freeEv+0x169)[0x5581d3debc89]
      /usr/sbin/mariadbd(_ZN4JOIN10exec_innerEv+0xc6c)[0x5581d3e1052c]
      /usr/sbin/mariadbd(_ZN4JOIN4execEv+0x33)[0x5581d3e107e3]
      /usr/sbin/mariadbd(_Z12mysql_selectP3THDP10TABLE_LISTR4ListI4ItemEPS4_jP8st_orderS9_S7_S9_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x186)[0x5581d3e0e9a6]
      /usr/sbin/mariadbd(_Z13handle_selectP3THDP3LEXP13select_resultm+0x1cc)[0x5581d3e0f50c]
      /usr/sbin/mariadbd(+0x63340a)[0x5581d3c7640a]
      /usr/sbin/mariadbd(_Z21mysql_execute_commandP3THD+0x37f5)[0x5581d3db55d5]
      /usr/sbin/mariadbd(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x36a)[0x5581d3db84da]
      /usr/sbin/mariadbd(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0x1bbd)[0x5581d3dba84d]
      /usr/sbin/mariadbd(_Z10do_commandP3THD+0x10b)[0x5581d3dbbfeb]
      /usr/sbin/mariadbd(_Z24do_handle_one_connectionP7CONNECTb+0x1b2)[0x5581d3ea4b02]
      /usr/sbin/mariadbd(handle_one_connection+0x34)[0x5581d3ea4db4]
      /usr/sbin/mariadbd(+0xbb627d)[0x5581d41f927d]
      /lib64/libpthread.so.0(+0x7ea5)[0x7f7f135fcea5]
      /lib64/libc.so.6(clone+0x6d)[0x7f7f117268dd]
       
      Trying to get some variables.
      Some pointers may be invalid and cause the dump to abort.
      Query (0x7f44840e5d90): SELECT * FROM `lookup_permissions_grid` WHERE  `application` IN ('guest')
      Connection ID (thread ID): 8019424
      Status: NOT_KILLED
       
      Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=on,not_null_range_scan=off
       
      The manual page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/ contains
      information that should help you find out what is causing the crash.
      Writing a core file...
      Working directory at /mnt/db/mysql
      Resource Limits:
      Limit                     Soft Limit           Hard Limit           Units
      Max cpu time              unlimited            unlimited            seconds
      Max file size             unlimited            unlimited            bytes
      Max data size             unlimited            unlimited            bytes
      Max stack size            8388608              unlimited            bytes
      Max core file size        unlimited            unlimited            bytes
      Max resident set          unlimited            unlimited            bytes
      Max processes             1030944              1030944              processes
      Max open files            16384                16384                files
      Max locked memory         65536                65536                bytes
      Max address space         unlimited            unlimited            bytes
      Max file locks            unlimited            unlimited            locks
      Max pending signals       1030944              1030944              signals
      Max msgqueue size         819200               819200               bytes
      Max nice priority         0                    0
      Max realtime priority     0                    0
      Max realtime timeout      unlimited            unlimited            us
      Core pattern: core
       
      2020-12-01 11:12:06 0 [Note] mariadbd: Aria engine: starting recovery
      recovered pages: 0% 16% 37% 59% 81% 94% 100% (0.0 seconds); tables to flush: 2 1 0
       (2.5 seconds);
      2020-12-01 11:12:08 0 [Note] mariadbd: Aria engine: recovery done
      2020-12-01 11:12:08 0 [Warning] The parameter innodb_buffer_pool_instances is deprecated and has no effect.
      2020-12-01 11:12:08 0 [Note] InnoDB: Using Linux native AIO
      2020-12-01 11:12:08 0 [Note] InnoDB: Uses event mutexes
      2020-12-01 11:12:08 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
      2020-12-01 11:12:08 0 [Note] InnoDB: Number of pools: 1
      2020-12-01 11:12:08 0 [Note] InnoDB: Using SSE4.2 crc32 instructions
      2020-12-01 11:12:08 0 [Note] InnoDB: Initializing buffer pool, total size = 235149459456, chunk size = 134217728
      2020-12-01 11:12:15 0 [Note] InnoDB: Completed initialization of buffer pool
      2020-12-01 11:12:15 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
      2020-12-01 11:12:15 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=41701133623035
      2020-12-01 11:12:16 0 [Note] InnoDB: 13 transaction(s) which must be rolled back or cleaned up in total 1710 row operations to undo
      2020-12-01 11:12:16 0 [Note] InnoDB: Trx id counter is 128600878351
      2020-12-01 11:12:16 0 [Note] InnoDB: Starting final batch to recover 6393 pages from redo log.
      2020-12-01 11:12:17 0 [Note] InnoDB: Last binlog file '/mnt/db/mysqllogs/bin-log.016476', position 903131623
      2020-12-01 11:12:17 0 [Note] InnoDB: 128 rollback segments are active.
      2020-12-01 11:12:17 0 [Note] InnoDB: Starting in background the rollback of recovered transactions
      2020-12-01 11:12:17 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
      2020-12-01 11:12:17 0 [Note] InnoDB: Creating shared tablespace for temporary tables
      2020-12-01 11:12:17 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
      2020-12-01 11:12:17 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
      2020-12-01 11:12:17 0 [Note] InnoDB: 10.5.6 started; log sequence number 41701133722664; transaction id 128600878353
      2020-12-01 11:12:17 0 [Note] InnoDB: Loading buffer pool(s) from /mnt/db/mysql/ib_buffer_pool
      2020-12-01 11:12:17 0 [Note] Plugin 'FEEDBACK' is disabled.
      2020-12-01 11:12:17 0 [Note] Recovering after a crash using /mnt/db/mysqllogs/bin-log
      2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600878319
      2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600873770
      2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600878248
      2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600878283
      2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600878247
      2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600874989
      2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600876172
      2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600863931
      2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600878174
      2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600878294
      2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600878322
      2020-12-01 11:12:18 0 [Note] InnoDB: Rolled back recovered transaction 128600877747
      2020-12-01 11:12:18 0 [Note] InnoDB: Rolled back recovered transaction 128600878337
      2020-12-01 11:12:18 0 [Note] InnoDB: Rollback of non-prepared transactions completed
      2020-12-01 11:12:20 0 [Note] Starting crash recovery...
      2020-12-01 11:12:20 0 [Note] Crash recovery finished.
      2020-12-01 11:12:20 0 [Note] Server socket created on IP: '::'.
      2020-12-01 11:12:20 0 [Note] Reading of all Master_info entries succeeded
      2020-12-01 11:12:20 0 [Note] Added new Master_info '' to hash table
      2020-12-01 11:12:20 0 [Note] /usr/sbin/mariadbd: ready for connections.
      Version: '10.5.6-MariaDB-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MariaDB Server
      2020-12-01 11:12:20 131 [Warning] IP address '10.0.1.58' could not be resolved: Name or service not known
      2020-12-01 11:12:22 715 [Warning] IP address '10.0.1.56' could not be resolved: Name or service not known
      2020-12-01 11:13:00 23979 [Note] Start binlog_dump to slave_server(2), pos(bin-log.016476, 903133807), using_gtid(1), gtid('1-1-15145546826')
      2020-12-01 11:13:00 23982 [Note] Start binlog_dump to slave_server(11), pos(bin-log.016476, 903133807), using_gtid(1), gtid('1-1-15145546826,2-1-3532097557')
      

      mysqld --print-defaults
      mysqld would have been started with the following arguments:
      --datadir=/mnt/db/mysql --tmpdir=/var/lib/mysqltmp --sql-mode=STRICT_TRANS_TABLES,NO_ENGINE_SUBSTITUTION --userstat=1 --log_warnings=2 --thread_handling=one-thread-per-connection --thread-cache-size=16 --table-open-cache=4096 --table-definition-cache=2048 --query-cache-type=0 --sort-buffer-size=1M --read-buffer-size=1M --read-rnd-buffer-size=1M --join-buffer-size=1M --tmp-table-size=128M --max-heap-table-size=128M --back-log=100 --max-connections=1250 --max-connect-errors=10000 --max-allowed-packet=16M --interactive-timeout=28800 --wait-timeout=28800 --default-storage-engine=InnoDB --innodb=FORCE --key-buffer-size=64M --myisam-sort-buffer-size=128M --innodb-buffer-pool-size=224256M --innodb-log-file-size=100M --innodb-file-per-table=1 --innodb-open-files=4096 --innodb_flush_log_at_trx_commit=0 --innodb_buffer_pool_instances=16 --innodb_flush_method=O_DIRECT --log-output=FILE --slow-query-log=1 --slow-query-log-file=/mnt/db/mysql_slow.log --long-query-time=1 --character-set-server=utf8 --group_concat_max_len=40960 --log-error=/mnt/db/mysqld.log --open-files-limit=65535 --server-id=1 --gtid-domain-id=1 --log-bin=/mnt/db/mysqllogs/bin-log --relay-log-space-limit=16G --expire-logs-days=2 --sync-binlog=0 --core_file --innodb_io_capacity=2000 --innodb_thread_concurrency=0
      

      Attachments

        1. gdb-core.11003.txt
          6.30 MB
        2. mariadb_srv1.log
          39 kB
        3. mariadb_srv2.log
          80 kB
        4. mariadb_srv3.log
          51 kB

        Issue Links

          Activity

            stephane@skysql.com VAROQUI Stephane added a comment - - edited

            Hi,

            Get similar trace on last 10.3

            RECORD LOCKS space id 329029 page no 3 n bits 160 index PRIMARY of table `wpmixrgen`.`msg_conversation_user` trx id 35135650 lock_mode X locks rec but not gap waiting
            Record lock, heap no 43 PHYSICAL RECORD: n_fields 18; compact format; info bits 0
             0: len 8; hex 000000000000002a; asc        *;;
             1: len 6; hex 000000000000; asc       ;;
             2: len 7; hex 80000000000000; asc        ;;
             3: len 8; hex 000000000000000d; asc         ;;
             4: len 8; hex 0000000000003649; asc       6I;;
             5: len 8; hex 000000000000030b; asc         ;;
             6: len 8; hex 000000000000002a; asc        *;;
             7: len 1; hex 81; asc  ;;
             8: len 5; hex 99ab6ae70e; asc   j  ;;
             9: len 5; hex 8000000000; asc      ;;
             10: len 5; hex 99ab6c971a; asc   l  ;;
             11: len 5; hex 99ab7aa733; asc   z 3;;
             12: len 5; hex 99ab7aa733; asc   z 3;;
             13: len 5; hex 99ab7aa733; asc   z 3;;
             14: len 8; hex 0000000000000000; asc         ;;
             15: len 5; hex 8000000000; asc      ;;
             16: len 5; hex 8000000000; asc      ;;
             17: len 5; hex 8000000000; asc      ;;
             
            2021-12-29 11:29:52 733720 [Note] InnoDB: *** WE ROLL BACK TRANSACTION (1)
             
            2021-12-29 11:29:52 0x7f7b05310700  InnoDB: Assertion failure in file /home/buildbot/buildbot/build/mariadb-10.3.32/storage/innobase/trx/trx0trx.cc line 1301
            InnoDB: Failing assertion: UT_LIST_GET_LEN(trx->lock.trx_locks) == 0
            InnoDB: We intentionally generate a memory trap.
            InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
            InnoDB: If you get repeated assertion failures or crashes, even
            InnoDB: immediately after the mysqld startup, there may be
            InnoDB: corruption in the InnoDB tablespace. Please refer to
            InnoDB: https://mariadb.com/kb/en/library/innodb-recovery-modes/
            InnoDB: about forcing recovery.
            211229 11:29:52 [ERROR] mysqld got signal 6 ;
            This could be because you hit a bug. It is also possible that this binary
            or one of the libraries it was linked against is corrupt, improperly built,
            or misconfigured. This error can also be caused by malfunctioning hardware.
             
            To report this bug, see https://mariadb.com/kb/en/reporting-bugs
             
            We will try our best to scrape up some info that will hopefully help
            diagnose the problem, but since we have already crashed,
            something is definitely wrong and this may fail.
             
            Server version: 10.3.32-MariaDB-1:10.3.32+maria~focal-log
            key_buffer_size=213909504
            read_buffer_size=262144
            max_used_connections=46
            max_threads=65546
            thread_count=36
            It is possible that mysqld could use up to
            key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 84130556 K  bytes of memory
            Hope that's ok; if not, decrease some variables in the equation.
             
            Thread pointer: 0x7f7a90036368
            Attempting backtrace. You can use the following information to find out
            where mysqld died. If you see no messages after this, something went
            terribly wrong...
            stack_bottom = 0x7f7b0530fcf0 thread_stack 0x49000
            mysqld(my_print_stacktrace+0x32)[0x555d2bcf4c32]
            

            table definition

            CREATE TABLE `msg_conversation_user` (
              `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
              `id_msg_conversation` bigint(20) unsigned NOT NULL,
              `id_user` bigint(20) unsigned NOT NULL,
              `id_workplace` bigint(20) unsigned NOT NULL,
              `id_msg_conversation_user_name` bigint(20) unsigned NOT NULL,
              `is_conversation_admin` tinyint(4) NOT NULL DEFAULT 0,
              `added_at` datetime NOT NULL DEFAULT '0000-00-00 00:00:00',
              `renamed_at` datetime NOT NULL DEFAULT '0000-00-00 00:00:00',
              `admin_role_udpated_at` datetime NOT NULL DEFAULT '0000-00-00 00:00:00',
              `check_updates_at` datetime NOT NULL DEFAULT '0000-00-00 00:00:00',
              `received_at` datetime NOT NULL DEFAULT '0000-00-00 00:00:00',
              `opened_at` datetime NOT NULL DEFAULT '0000-00-00 00:00:00',
              `id_user_removed_by` bigint(20) unsigned NOT NULL DEFAULT 0,
              `removed_at` datetime NOT NULL DEFAULT '0000-00-00 00:00:00',
              `hidden_at` datetime NOT NULL DEFAULT '0000-00-00 00:00:00',
              `muted_at` datetime NOT NULL DEFAULT '0000-00-00 00:00:00',
              PRIMARY KEY (`id`),
              KEY `id_user` (`id_user`),
              KEY `added_at` (`added_at`),
              KEY `received_at` (`received_at`),
              KEY `opened_at` (`opened_at`),
              KEY `removed_at` (`removed_at`),
              KEY `id_msg_conversation` (`id_msg_conversation`),
              KEY `renamed_at` (`renamed_at`),
              KEY `admin_role_udpated_at` (`admin_role_udpated_at`),
              KEY `check_updates_at` (`check_updates_at`),
              KEY `muted_at` (`muted_at`),
              KEY `hidden_at` (`hidden_at`),
              KEY `id_user_removed_by` (`id_user_removed_by`),
              KEY `id_workplace` (`id_workplace`)
            ) ENGINE=InnoDB AUTO_INCREMENT=96 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci 
            

            This is a dev server upgraded in release form 2 weeks ago and those tables and workload are new code

            cat /proc/version
            Linux version 5.4.0-91-generic (buildd@lcy01-amd64-017) (gcc version 9.3.0 (Ubuntu 9.3.0-17ubuntu1~20.04)) #102-Ubuntu SMP Fri Nov 5 16:31:28 UTC 2021

            config disable adaptive hash and change buffer it run on a pretty unoptimized ZFS on slow sata raid disques Kernel

            +---------------------------------------------+-------------------------------------+
            | Variable_name                               | Value                               |
            +---------------------------------------------+-------------------------------------+
            | innodb_adaptive_flushing                    | ON                                  |
            | innodb_adaptive_flushing_lwm                | 10.000000                           |
            | innodb_adaptive_hash_index                  | OFF                                 |
            | innodb_adaptive_hash_index_parts            | 8                                   |
            | innodb_adaptive_max_sleep_delay             | 150000                              |
            | innodb_autoextend_increment                 | 64                                  |
            | innodb_autoinc_lock_mode                    | 2                                   |
            | innodb_background_scrub_data_check_interval | 3600                                |
            | innodb_background_scrub_data_compressed     | OFF                                 |
            | innodb_background_scrub_data_interval       | 604800                              |
            | innodb_background_scrub_data_uncompressed   | OFF                                 |
            | innodb_buf_dump_status_frequency            | 0                                   |
            | innodb_buffer_pool_chunk_size               | 134217728                           |
            | innodb_buffer_pool_dump_at_shutdown         | ON                                  |
            | innodb_buffer_pool_dump_now                 | OFF                                 |
            | innodb_buffer_pool_dump_pct                 | 25                                  |
            | innodb_buffer_pool_filename                 | ib_buffer_pool                      |
            | innodb_buffer_pool_instances                | 1                                   |
            | innodb_buffer_pool_load_abort               | OFF                                 |
            | innodb_buffer_pool_load_at_startup          | ON                                  |
            | innodb_buffer_pool_load_now                 | OFF                                 |
            | innodb_buffer_pool_size                     | 1342177280                          |
            | innodb_change_buffer_max_size               | 25                                  |
            | innodb_change_buffering                     | none                                |
            | innodb_checksum_algorithm                   | none                                |
            | innodb_checksums                            | ON                                  |
            | innodb_cmp_per_index_enabled                | OFF                                 |
            | innodb_commit_concurrency                   | 0                                   |
            | innodb_compression_algorithm                | zlib                                |
            | innodb_compression_default                  | OFF                                 |
            | innodb_compression_failure_threshold_pct    | 5                                   |
            | innodb_compression_level                    | 6                                   |
            | innodb_compression_pad_pct_max              | 50                                  |
            | innodb_concurrency_tickets                  | 5000                                |
            | innodb_data_file_path                       | ibdata1:12M:autoextend              |
            | innodb_data_home_dir                        | /var/lib/mysql/.system/innodb       |
            | innodb_deadlock_detect                      | ON                                  |
            | innodb_default_encryption_key_id            | 1                                   |
            | innodb_default_row_format                   | dynamic                             |
            | innodb_defragment                           | OFF                                 |
            | innodb_defragment_fill_factor               | 0.900000                            |
            | innodb_defragment_fill_factor_n_recs        | 20                                  |
            | innodb_defragment_frequency                 | 40                                  |
            | innodb_defragment_n_pages                   | 7                                   |
            | innodb_defragment_stats_accuracy            | 0                                   |
            | innodb_disable_sort_file_cache              | OFF                                 |
            | innodb_disallow_writes                      | OFF                                 |
            | innodb_doublewrite                          | OFF                                 |
            | innodb_encrypt_log                          | OFF                                 |
            | innodb_encrypt_tables                       | OFF                                 |
            | innodb_encrypt_temporary_tables             | OFF                                 |
            | innodb_encryption_rotate_key_age            | 1                                   |
            | innodb_encryption_rotation_iops             | 100                                 |
            | innodb_encryption_threads                   | 0                                   |
            | innodb_fast_shutdown                        | 1                                   |
            | innodb_fatal_semaphore_wait_threshold       | 600                                 |
            | innodb_file_format                          |                                     |
            | innodb_file_per_table                       | ON                                  |
            | innodb_fill_factor                          | 100                                 |
            | innodb_flush_log_at_timeout                 | 1                                   |
            | innodb_flush_log_at_trx_commit              | 1                                   |
            | innodb_flush_method                         | O_DSYNC                             |
            | innodb_flush_neighbors                      | 0                                   |
            | innodb_flush_sync                           | ON                                  |
            | innodb_flushing_avg_loops                   | 30                                  |
            | innodb_force_load_corrupted                 | OFF                                 |
            | innodb_force_primary_key                    | ON                                  |
            | innodb_force_recovery                       | 0                                   |
            | innodb_ft_aux_table                         |                                     |
            | innodb_ft_cache_size                        | 8000000                             |
            | innodb_ft_enable_diag_print                 | OFF                                 |
            | innodb_ft_enable_stopword                   | ON                                  |
            | innodb_ft_max_token_size                    | 84                                  |
            | innodb_ft_min_token_size                    | 3                                   |
            | innodb_ft_num_word_optimize                 | 2000                                |
            | innodb_ft_result_cache_limit                | 2000000000                          |
            | innodb_ft_server_stopword_table             |                                     |
            | innodb_ft_sort_pll_degree                   | 2                                   |
            | innodb_ft_total_cache_size                  | 640000000                           |
            | innodb_ft_user_stopword_table               |                                     |
            | innodb_idle_flush_pct                       | 100                                 |
            | innodb_immediate_scrub_data_uncompressed    | OFF                                 |
            | innodb_instant_alter_column_allowed         | add_last                            |
            | innodb_io_capacity                          | 100                                 |
            | innodb_io_capacity_max                      | 300                                 |
            | innodb_large_prefix                         |                                     |
            | innodb_lock_schedule_algorithm              | fcfs                                |
            | innodb_lock_wait_timeout                    | 50                                  |
            | innodb_locks_unsafe_for_binlog              | OFF                                 |
            | innodb_log_buffer_size                      | 16777216                            |
            | innodb_log_checksums                        | ON                                  |
            | innodb_log_compressed_pages                 | ON                                  |
            | innodb_log_file_size                        | 1073741824                          |
            | innodb_log_files_in_group                   | 1                                   |
            | innodb_log_group_home_dir                   | /var/lib/mysql/.system/innodb/redo  |
            | innodb_log_optimize_ddl                     | OFF                                 |
            | innodb_log_write_ahead_size                 | 8192                                |
            | innodb_lru_scan_depth                       | 1024                                |
            | innodb_max_dirty_pages_pct                  | 40.000000                           |
            | innodb_max_dirty_pages_pct_lwm              | 20.000000                           |
            | innodb_max_purge_lag                        | 0                                   |
            | innodb_max_purge_lag_delay                  | 0                                   |
            | innodb_max_purge_lag_wait                   | 4294967295                          |
            | innodb_max_undo_log_size                    | 10485760                            |
            | innodb_monitor_disable                      |                                     |
            | innodb_monitor_enable                       |                                     |
            | innodb_monitor_reset                        |                                     |
            | innodb_monitor_reset_all                    |                                     |
            | innodb_old_blocks_pct                       | 37                                  |
            | innodb_old_blocks_time                      | 1000                                |
            | innodb_online_alter_log_max_size            | 134217728                           |
            | innodb_open_files                           | 16384                               |
            | innodb_optimize_fulltext_only               | OFF                                 |
            | innodb_page_cleaners                        | 1                                   |
            | innodb_page_size                            | 16384                               |
            | innodb_prefix_index_cluster_optimization    | OFF                                 |
            | innodb_print_all_deadlocks                  | ON                                  |
            | innodb_purge_batch_size                     | 300                                 |
            | innodb_purge_rseg_truncate_frequency        | 128                                 |
            | innodb_purge_threads                        | 4                                   |
            | innodb_random_read_ahead                    | OFF                                 |
            | innodb_read_ahead_threshold                 | 56                                  |
            | innodb_read_io_threads                      | 1                                   |
            | innodb_read_only                            | OFF                                 |
            | innodb_replication_delay                    | 0                                   |
            | innodb_rollback_on_timeout                  | ON                                  |
            | innodb_rollback_segments                    | 128                                 |
            | innodb_scrub_log                            | OFF                                 |
            | innodb_scrub_log_speed                      | 256                                 |
            | innodb_sort_buffer_size                     | 1048576                             |
            | innodb_spin_wait_delay                      | 4                                   |
            | innodb_stats_auto_recalc                    | ON                                  |
            | innodb_stats_include_delete_marked          | OFF                                 |
            | innodb_stats_method                         | nulls_equal                         |
            | innodb_stats_modified_counter               | 0                                   |
            | innodb_stats_on_metadata                    | OFF                                 |
            | innodb_stats_persistent                     | ON                                  |
            | innodb_stats_persistent_sample_pages        | 20                                  |
            | innodb_stats_sample_pages                   | 8                                   |
            | innodb_stats_traditional                    | ON                                  |
            | innodb_stats_transient_sample_pages         | 8                                   |
            | innodb_status_output                        | OFF                                 |
            | innodb_status_output_locks                  | OFF                                 |
            | innodb_strict_mode                          | ON                                  |
            | innodb_sync_array_size                      | 1                                   |
            | innodb_sync_spin_loops                      | 30                                  |
            | innodb_table_locks                          | ON                                  |
            | innodb_temp_data_file_path                  | ibtmp1:12M:autoextend               |
            | innodb_thread_concurrency                   | 0                                   |
            | innodb_thread_sleep_delay                   | 10000                               |
            | innodb_tmpdir                               |                                     |
            | innodb_undo_directory                       | //var/lib/mysql/.system/innodb/undo |
            | innodb_undo_log_truncate                    | OFF                                 |
            | innodb_undo_logs                            | 128                                 |
            | innodb_undo_tablespaces                     | 0                                   |
            | innodb_use_atomic_writes                    | ON                                  |
            | innodb_use_native_aio                       | OFF                                 |
            | innodb_version                              | 10.3.32                             |
            | innodb_write_io_threads                     | 1                                   |
            +---------------------------------------------+-------------------------------------+
            

            Syslog

            Dec 29 11:28:25 mixr-fr-1 dockerd[2583]: time="2021-12-29T11:28:25.997972509+01:00" level=error msg="stream copy error: read /proc/self/fd/227: file already closed"
            Dec 29 11:29:54 mixr-fr-1 kernel: [748575.988934] traps: mysqld[1261883] general protection fault ip:7f7ba4e1d941 sp:7f7b0530c7c0 error:0 in libc-2.31.so[7f7ba4e1d000+178000]
            

            and dmesg

            [Wed Dec 22 18:11:12 2021] obr_mixrnet: port 4(vethab23a5d6) entered blocking state
            [Wed Dec 22 18:11:12 2021] obr_mixrnet: port 4(vethab23a5d6) entered forwarding state
            [Wed Dec 29 11:30:03 2021] traps: mysqld[1261883] general protection fault ip:7f7ba4e1d941 sp:7f7b0530c7c0 error:0 in libc-2.31.so[7f7ba4e1d000+178000]
            [Wed Dec 29 11:35:29 2021] obr_mixrnet: port 4(vethab23a5d6) entered disabled state
            [Wed Dec 29 11:35:29 2021] device vethab23a5d6 left promiscuous mode
            

            Note that the crash occured in between 2 network issues that does not show up constantly on the server

            stephane@skysql.com VAROQUI Stephane added a comment - - edited Hi, Get similar trace on last 10.3 RECORD LOCKS space id 329029 page no 3 n bits 160 index PRIMARY of table `wpmixrgen`.`msg_conversation_user` trx id 35135650 lock_mode X locks rec but not gap waiting Record lock, heap no 43 PHYSICAL RECORD: n_fields 18; compact format; info bits 0 0: len 8; hex 000000000000002a; asc *;; 1: len 6; hex 000000000000; asc ;; 2: len 7; hex 80000000000000; asc ;; 3: len 8; hex 000000000000000d; asc ;; 4: len 8; hex 0000000000003649; asc 6I;; 5: len 8; hex 000000000000030b; asc ;; 6: len 8; hex 000000000000002a; asc *;; 7: len 1; hex 81; asc ;; 8: len 5; hex 99ab6ae70e; asc j ;; 9: len 5; hex 8000000000; asc ;; 10: len 5; hex 99ab6c971a; asc l ;; 11: len 5; hex 99ab7aa733; asc z 3;; 12: len 5; hex 99ab7aa733; asc z 3;; 13: len 5; hex 99ab7aa733; asc z 3;; 14: len 8; hex 0000000000000000; asc ;; 15: len 5; hex 8000000000; asc ;; 16: len 5; hex 8000000000; asc ;; 17: len 5; hex 8000000000; asc ;;   2021-12-29 11:29:52 733720 [Note] InnoDB: *** WE ROLL BACK TRANSACTION (1)   2021-12-29 11:29:52 0x7f7b05310700 InnoDB: Assertion failure in file /home/buildbot/buildbot/build/mariadb-10.3.32/storage/innobase/trx/trx0trx.cc line 1301 InnoDB: Failing assertion: UT_LIST_GET_LEN(trx->lock.trx_locks) == 0 InnoDB: We intentionally generate a memory trap. InnoDB: Submit a detailed bug report to https://jira.mariadb.org/ InnoDB: If you get repeated assertion failures or crashes, even InnoDB: immediately after the mysqld startup, there may be InnoDB: corruption in the InnoDB tablespace. Please refer to InnoDB: https://mariadb.com/kb/en/library/innodb-recovery-modes/ InnoDB: about forcing recovery. 211229 11:29:52 [ERROR] mysqld got signal 6 ; This could be because you hit a bug. It is also possible that this binary or one of the libraries it was linked against is corrupt, improperly built, or misconfigured. This error can also be caused by malfunctioning hardware.   To report this bug, see https://mariadb.com/kb/en/reporting-bugs   We will try our best to scrape up some info that will hopefully help diagnose the problem, but since we have already crashed, something is definitely wrong and this may fail.   Server version: 10.3.32-MariaDB-1:10.3.32+maria~focal-log key_buffer_size=213909504 read_buffer_size=262144 max_used_connections=46 max_threads=65546 thread_count=36 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 84130556 K bytes of memory Hope that's ok; if not, decrease some variables in the equation.   Thread pointer: 0x7f7a90036368 Attempting backtrace. You can use the following information to find out where mysqld died. If you see no messages after this, something went terribly wrong... stack_bottom = 0x7f7b0530fcf0 thread_stack 0x49000 mysqld(my_print_stacktrace+0x32)[0x555d2bcf4c32] table definition CREATE TABLE `msg_conversation_user` ( `id` bigint (20) unsigned NOT NULL AUTO_INCREMENT, `id_msg_conversation` bigint (20) unsigned NOT NULL , `id_user` bigint (20) unsigned NOT NULL , `id_workplace` bigint (20) unsigned NOT NULL , `id_msg_conversation_user_name` bigint (20) unsigned NOT NULL , `is_conversation_admin` tinyint(4) NOT NULL DEFAULT 0, `added_at` datetime NOT NULL DEFAULT '0000-00-00 00:00:00' , `renamed_at` datetime NOT NULL DEFAULT '0000-00-00 00:00:00' , `admin_role_udpated_at` datetime NOT NULL DEFAULT '0000-00-00 00:00:00' , `check_updates_at` datetime NOT NULL DEFAULT '0000-00-00 00:00:00' , `received_at` datetime NOT NULL DEFAULT '0000-00-00 00:00:00' , `opened_at` datetime NOT NULL DEFAULT '0000-00-00 00:00:00' , `id_user_removed_by` bigint (20) unsigned NOT NULL DEFAULT 0, `removed_at` datetime NOT NULL DEFAULT '0000-00-00 00:00:00' , `hidden_at` datetime NOT NULL DEFAULT '0000-00-00 00:00:00' , `muted_at` datetime NOT NULL DEFAULT '0000-00-00 00:00:00' , PRIMARY KEY (`id`), KEY `id_user` (`id_user`), KEY `added_at` (`added_at`), KEY `received_at` (`received_at`), KEY `opened_at` (`opened_at`), KEY `removed_at` (`removed_at`), KEY `id_msg_conversation` (`id_msg_conversation`), KEY `renamed_at` (`renamed_at`), KEY `admin_role_udpated_at` (`admin_role_udpated_at`), KEY `check_updates_at` (`check_updates_at`), KEY `muted_at` (`muted_at`), KEY `hidden_at` (`hidden_at`), KEY `id_user_removed_by` (`id_user_removed_by`), KEY `id_workplace` (`id_workplace`) ) ENGINE=InnoDB AUTO_INCREMENT=96 DEFAULT CHARSET=utf8mb4 COLLATE =utf8mb4_unicode_ci This is a dev server upgraded in release form 2 weeks ago and those tables and workload are new code cat /proc/version Linux version 5.4.0-91-generic (buildd@lcy01-amd64-017) (gcc version 9.3.0 (Ubuntu 9.3.0-17ubuntu1~20.04)) #102-Ubuntu SMP Fri Nov 5 16:31:28 UTC 2021 config disable adaptive hash and change buffer it run on a pretty unoptimized ZFS on slow sata raid disques Kernel +---------------------------------------------+-------------------------------------+ | Variable_name | Value | +---------------------------------------------+-------------------------------------+ | innodb_adaptive_flushing | ON | | innodb_adaptive_flushing_lwm | 10.000000 | | innodb_adaptive_hash_index | OFF | | innodb_adaptive_hash_index_parts | 8 | | innodb_adaptive_max_sleep_delay | 150000 | | innodb_autoextend_increment | 64 | | innodb_autoinc_lock_mode | 2 | | innodb_background_scrub_data_check_interval | 3600 | | innodb_background_scrub_data_compressed | OFF | | innodb_background_scrub_data_interval | 604800 | | innodb_background_scrub_data_uncompressed | OFF | | innodb_buf_dump_status_frequency | 0 | | innodb_buffer_pool_chunk_size | 134217728 | | innodb_buffer_pool_dump_at_shutdown | ON | | innodb_buffer_pool_dump_now | OFF | | innodb_buffer_pool_dump_pct | 25 | | innodb_buffer_pool_filename | ib_buffer_pool | | innodb_buffer_pool_instances | 1 | | innodb_buffer_pool_load_abort | OFF | | innodb_buffer_pool_load_at_startup | ON | | innodb_buffer_pool_load_now | OFF | | innodb_buffer_pool_size | 1342177280 | | innodb_change_buffer_max_size | 25 | | innodb_change_buffering | none | | innodb_checksum_algorithm | none | | innodb_checksums | ON | | innodb_cmp_per_index_enabled | OFF | | innodb_commit_concurrency | 0 | | innodb_compression_algorithm | zlib | | innodb_compression_default | OFF | | innodb_compression_failure_threshold_pct | 5 | | innodb_compression_level | 6 | | innodb_compression_pad_pct_max | 50 | | innodb_concurrency_tickets | 5000 | | innodb_data_file_path | ibdata1:12M:autoextend | | innodb_data_home_dir | /var/lib/mysql/.system/innodb | | innodb_deadlock_detect | ON | | innodb_default_encryption_key_id | 1 | | innodb_default_row_format | dynamic | | innodb_defragment | OFF | | innodb_defragment_fill_factor | 0.900000 | | innodb_defragment_fill_factor_n_recs | 20 | | innodb_defragment_frequency | 40 | | innodb_defragment_n_pages | 7 | | innodb_defragment_stats_accuracy | 0 | | innodb_disable_sort_file_cache | OFF | | innodb_disallow_writes | OFF | | innodb_doublewrite | OFF | | innodb_encrypt_log | OFF | | innodb_encrypt_tables | OFF | | innodb_encrypt_temporary_tables | OFF | | innodb_encryption_rotate_key_age | 1 | | innodb_encryption_rotation_iops | 100 | | innodb_encryption_threads | 0 | | innodb_fast_shutdown | 1 | | innodb_fatal_semaphore_wait_threshold | 600 | | innodb_file_format | | | innodb_file_per_table | ON | | innodb_fill_factor | 100 | | innodb_flush_log_at_timeout | 1 | | innodb_flush_log_at_trx_commit | 1 | | innodb_flush_method | O_DSYNC | | innodb_flush_neighbors | 0 | | innodb_flush_sync | ON | | innodb_flushing_avg_loops | 30 | | innodb_force_load_corrupted | OFF | | innodb_force_primary_key | ON | | innodb_force_recovery | 0 | | innodb_ft_aux_table | | | innodb_ft_cache_size | 8000000 | | innodb_ft_enable_diag_print | OFF | | innodb_ft_enable_stopword | ON | | innodb_ft_max_token_size | 84 | | innodb_ft_min_token_size | 3 | | innodb_ft_num_word_optimize | 2000 | | innodb_ft_result_cache_limit | 2000000000 | | innodb_ft_server_stopword_table | | | innodb_ft_sort_pll_degree | 2 | | innodb_ft_total_cache_size | 640000000 | | innodb_ft_user_stopword_table | | | innodb_idle_flush_pct | 100 | | innodb_immediate_scrub_data_uncompressed | OFF | | innodb_instant_alter_column_allowed | add_last | | innodb_io_capacity | 100 | | innodb_io_capacity_max | 300 | | innodb_large_prefix | | | innodb_lock_schedule_algorithm | fcfs | | innodb_lock_wait_timeout | 50 | | innodb_locks_unsafe_for_binlog | OFF | | innodb_log_buffer_size | 16777216 | | innodb_log_checksums | ON | | innodb_log_compressed_pages | ON | | innodb_log_file_size | 1073741824 | | innodb_log_files_in_group | 1 | | innodb_log_group_home_dir | /var/lib/mysql/.system/innodb/redo | | innodb_log_optimize_ddl | OFF | | innodb_log_write_ahead_size | 8192 | | innodb_lru_scan_depth | 1024 | | innodb_max_dirty_pages_pct | 40.000000 | | innodb_max_dirty_pages_pct_lwm | 20.000000 | | innodb_max_purge_lag | 0 | | innodb_max_purge_lag_delay | 0 | | innodb_max_purge_lag_wait | 4294967295 | | innodb_max_undo_log_size | 10485760 | | innodb_monitor_disable | | | innodb_monitor_enable | | | innodb_monitor_reset | | | innodb_monitor_reset_all | | | innodb_old_blocks_pct | 37 | | innodb_old_blocks_time | 1000 | | innodb_online_alter_log_max_size | 134217728 | | innodb_open_files | 16384 | | innodb_optimize_fulltext_only | OFF | | innodb_page_cleaners | 1 | | innodb_page_size | 16384 | | innodb_prefix_index_cluster_optimization | OFF | | innodb_print_all_deadlocks | ON | | innodb_purge_batch_size | 300 | | innodb_purge_rseg_truncate_frequency | 128 | | innodb_purge_threads | 4 | | innodb_random_read_ahead | OFF | | innodb_read_ahead_threshold | 56 | | innodb_read_io_threads | 1 | | innodb_read_only | OFF | | innodb_replication_delay | 0 | | innodb_rollback_on_timeout | ON | | innodb_rollback_segments | 128 | | innodb_scrub_log | OFF | | innodb_scrub_log_speed | 256 | | innodb_sort_buffer_size | 1048576 | | innodb_spin_wait_delay | 4 | | innodb_stats_auto_recalc | ON | | innodb_stats_include_delete_marked | OFF | | innodb_stats_method | nulls_equal | | innodb_stats_modified_counter | 0 | | innodb_stats_on_metadata | OFF | | innodb_stats_persistent | ON | | innodb_stats_persistent_sample_pages | 20 | | innodb_stats_sample_pages | 8 | | innodb_stats_traditional | ON | | innodb_stats_transient_sample_pages | 8 | | innodb_status_output | OFF | | innodb_status_output_locks | OFF | | innodb_strict_mode | ON | | innodb_sync_array_size | 1 | | innodb_sync_spin_loops | 30 | | innodb_table_locks | ON | | innodb_temp_data_file_path | ibtmp1:12M:autoextend | | innodb_thread_concurrency | 0 | | innodb_thread_sleep_delay | 10000 | | innodb_tmpdir | | | innodb_undo_directory | //var/lib/mysql/.system/innodb/undo | | innodb_undo_log_truncate | OFF | | innodb_undo_logs | 128 | | innodb_undo_tablespaces | 0 | | innodb_use_atomic_writes | ON | | innodb_use_native_aio | OFF | | innodb_version | 10.3.32 | | innodb_write_io_threads | 1 | +---------------------------------------------+-------------------------------------+ Syslog Dec 29 11:28:25 mixr-fr-1 dockerd[2583]: time="2021-12-29T11:28:25.997972509+01:00" level=error msg="stream copy error: read /proc/self/fd/227: file already closed" Dec 29 11:29:54 mixr-fr-1 kernel: [748575.988934] traps: mysqld[1261883] general protection fault ip:7f7ba4e1d941 sp:7f7b0530c7c0 error:0 in libc-2.31.so[7f7ba4e1d000+178000] and dmesg [Wed Dec 22 18:11:12 2021] obr_mixrnet: port 4(vethab23a5d6) entered blocking state [Wed Dec 22 18:11:12 2021] obr_mixrnet: port 4(vethab23a5d6) entered forwarding state [Wed Dec 29 11:30:03 2021] traps: mysqld[1261883] general protection fault ip:7f7ba4e1d941 sp:7f7b0530c7c0 error:0 in libc-2.31.so[7f7ba4e1d000+178000] [Wed Dec 29 11:35:29 2021] obr_mixrnet: port 4(vethab23a5d6) entered disabled state [Wed Dec 29 11:35:29 2021] device vethab23a5d6 left promiscuous mode Note that the crash occured in between 2 network issues that does not show up constantly on the server
            stephane@skysql.com VAROQUI Stephane added a comment - - edited

            The last slow query reported before the cash was a drop table and the workoad is doing this every minute in a process of rebuilding a table
            I will activate general log and report if it crash again

            # # Time: 211224 10:18:38
            # User@Host: root[root] @  [10.48.48.146]
            # Thread_id: 305282  Schema: wpmixrgen  QC_hit: No
            # Query_time: 2.768105  Lock_time: 0.000069  Rows_sent: 0  Rows_examined: 0
            # Rows_affected: 0  Bytes_sent: 11
            SET timestamp=1640337518;
            drop table if exists geo_filter_old;
            mysqld, Version: 10.3.32-MariaDB-1:10.3.32+maria~focal-log (mariadb.org binary distribution). started with:
            Tcp port: 3306  Unix socket: (null)
            Time		    Id Command	Argument
            # Time: 211229 11:55:34
            

            the client code is under constant deadlock on this table

            explain update `msg_conversation_user` set `check_updates_at` = '2021-12-29 14:35:50' where `id` in (92, 65, 40, 30, 27, 1);
            +------+-------------+-----------------------+-------+---------------+---------+---------+------+------+-------------+
            | id   | select_type | table                 | type  | possible_keys | key     | key_len | ref  | rows | Extra       |
            +------+-------------+-----------------------+-------+---------------+---------+---------+------+------+-------------+
            |    1 | SIMPLE      | msg_conversation_user | range | PRIMARY       | PRIMARY | 8       | NULL |    6 | Using where |
            +------+-------------+-----------------------+-------+---------------+---------+---------+------+------+-------------+ 
            

            and

            analyze SELECT     mc.id                     AS id,            0                         AS is_new_conversation,            mc.id_user                AS id_user,            mc.id_workplace           AS id_workplace,            mc.id_organization        AS id_organization,            mc.is_group_conversation  AS is_group_conversation,            mcun.conversation_name    AS user_conversation_name,            mcu.is_conversation_admin AS user_is_conversation_admin,            mcu.added_at              AS user_added_at,            mcu.received_at           AS user_received_at,            mcu.opened_at             AS user_opened_at,            mcu.id_user_removed_by    AS user_removed_by_id_user,            mcu.removed_at            AS user_removed_at,            mcu.muted_at              AS user_muted_at,            mc.created_at             AS created_at,            mc.updated_at             AS updated_at,            mc.deleted_at             AS deleted_at FROM       `msg_conversation`        AS `mc` INNER JOIN `msg_conversation_user`   AS `mcu` ON         `mc`.`id` = `mcu`.`id_msg_conversation` INNER JOIN `msg_conversation_user_name` AS `mcun` ON         `mcu`.`id_msg_conversation_user_name` = `mcun`.`id` WHERE      `mc`.`id` = 14 AND        `mcu`.`id_user` = 13137 ORDER BY   `user_added_at` DESC LIMIT      1 FOR UPDATE\G
            *************************** 1. row ***************************
                       id: 1
              select_type: SIMPLE
                    table: mc
                     type: const
            possible_keys: PRIMARY
                      key: PRIMARY
                  key_len: 8
                      ref: const
                     rows: 1
                   r_rows: NULL
                 filtered: 100.00
               r_filtered: NULL
                    Extra: Using temporary; Using filesort
            *************************** 2. row ***************************
                       id: 1
              select_type: SIMPLE
                    table: mcu
                     type: index_merge
            possible_keys: id_user,id_msg_conversation
                      key: id_user,id_msg_conversation
                  key_len: 8,8
                      ref: NULL
                     rows: 1
                   r_rows: 1.00
                 filtered: 100.00
               r_filtered: 100.00
                    Extra: Using intersect(id_user,id_msg_conversation); Using where
            *************************** 3. row ***************************
                       id: 1
              select_type: SIMPLE
                    table: mcun
                     type: eq_ref
            possible_keys: PRIMARY
                      key: PRIMARY
                  key_len: 8
                      ref: wpmixrgen.mcu.id_msg_conversation_user_name
                     rows: 1
                   r_rows: 1.00
                 filtered: 100.00
               r_filtered: 100.00
                    Extra: Using join buffer (flat, BKA join); Key-ordered scan
            

            stephane@skysql.com VAROQUI Stephane added a comment - - edited The last slow query reported before the cash was a drop table and the workoad is doing this every minute in a process of rebuilding a table I will activate general log and report if it crash again # # Time: 211224 10 : 18 : 38 # User @Host : root[root] @ [ 10.48 . 48.146 ] # Thread_id: 305282 Schema: wpmixrgen QC_hit: No # Query_time: 2.768105 Lock_time: 0.000069 Rows_sent: 0 Rows_examined: 0 # Rows_affected: 0 Bytes_sent: 11 SET timestamp= 1640337518 ; drop table if exists geo_filter_old; mysqld, Version: 10.3 . 32 -MariaDB- 1 : 10.3 . 32 +maria~focal-log (mariadb.org binary distribution). started with: Tcp port: 3306 Unix socket: ( null ) Time Id Command Argument # Time: 211229 11 : 55 : 34 the client code is under constant deadlock on this table explain update `msg_conversation_user` set `check_updates_at` = '2021-12-29 14:35:50' where `id` in (92, 65, 40, 30, 27, 1); +------+-------------+-----------------------+-------+---------------+---------+---------+------+------+-------------+ | id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra | +------+-------------+-----------------------+-------+---------------+---------+---------+------+------+-------------+ | 1 | SIMPLE | msg_conversation_user | range | PRIMARY | PRIMARY | 8 | NULL | 6 | Using where | +------+-------------+-----------------------+-------+---------------+---------+---------+------+------+-------------+ and analyze SELECT mc.id AS id, 0 AS is_new_conversation, mc.id_user AS id_user, mc.id_workplace AS id_workplace, mc.id_organization AS id_organization, mc.is_group_conversation AS is_group_conversation, mcun.conversation_name AS user_conversation_name, mcu.is_conversation_admin AS user_is_conversation_admin, mcu.added_at AS user_added_at, mcu.received_at AS user_received_at, mcu.opened_at AS user_opened_at, mcu.id_user_removed_by AS user_removed_by_id_user, mcu.removed_at AS user_removed_at, mcu.muted_at AS user_muted_at, mc.created_at AS created_at, mc.updated_at AS updated_at, mc.deleted_at AS deleted_at FROM `msg_conversation` AS `mc` INNER JOIN `msg_conversation_user` AS `mcu` ON `mc`.`id` = `mcu`.`id_msg_conversation` INNER JOIN `msg_conversation_user_name` AS `mcun` ON `mcu`.`id_msg_conversation_user_name` = `mcun`.`id` WHERE `mc`.`id` = 14 AND `mcu`.`id_user` = 13137 ORDER BY `user_added_at` DESC LIMIT 1 FOR UPDATE\G *************************** 1. row *************************** id: 1 select_type: SIMPLE table: mc type: const possible_keys: PRIMARY key: PRIMARY key_len: 8 ref: const rows: 1 r_rows: NULL filtered: 100.00 r_filtered: NULL Extra: Using temporary; Using filesort *************************** 2. row *************************** id: 1 select_type: SIMPLE table: mcu type: index_merge possible_keys: id_user,id_msg_conversation key: id_user,id_msg_conversation key_len: 8,8 ref: NULL rows: 1 r_rows: 1.00 filtered: 100.00 r_filtered: 100.00 Extra: Using intersect(id_user,id_msg_conversation); Using where *************************** 3. row *************************** id: 1 select_type: SIMPLE table: mcun type: eq_ref possible_keys: PRIMARY key: PRIMARY key_len: 8 ref: wpmixrgen.mcu.id_msg_conversation_user_name rows: 1 r_rows: 1.00 filtered: 100.00 r_filtered: 100.00 Extra: Using join buffer (flat, BKA join); Key-ordered scan

            jplindst, can you please identify the supposed fix of this bug? Note that this affects users who do not use Galera replication. I will reopen MDEV-24035 to keep track of the non-Galera case.

            marko Marko Mäkelä added a comment - jplindst , can you please identify the supposed fix of this bug? Note that this affects users who do not use Galera replication. I will reopen MDEV-24035 to keep track of the non-Galera case.

            marko My understanding is that Galera problem was fixed on 47ba5523. That fix does not effect only foreign keys as it effects how write set column values are stored. If I remember correctly the actual customer problem we could not reproduce.

            jplindst Jan Lindström (Inactive) added a comment - marko My understanding is that Galera problem was fixed on 47ba5523. That fix does not effect only foreign keys as it effects how write set column values are stored. If I remember correctly the actual customer problem we could not reproduce.

            If this is reproducible we would need more information. For example query log, show create table for table effected, full stack trace from all threads. Is that select inside a transaction and does that transaction contain UPDATE/DELETE-clauses. We could also when we hit that problematic assertion print more information what those locks are (this requires code changes). Clear is based on reports both standalone InnoDB and Galera cluster are effected. In Galera cluster case in testing environment run using --wsrep-debug=1 (requires debug packages). Is it possible that transaction was already killed or aborted but this fact was ignored on upper layer and execution was continued?

            jplindst Jan Lindström (Inactive) added a comment - If this is reproducible we would need more information. For example query log, show create table for table effected, full stack trace from all threads. Is that select inside a transaction and does that transaction contain UPDATE/DELETE-clauses. We could also when we hit that problematic assertion print more information what those locks are (this requires code changes). Clear is based on reports both standalone InnoDB and Galera cluster are effected. In Galera cluster case in testing environment run using --wsrep-debug=1 (requires debug packages). Is it possible that transaction was already killed or aborted but this fact was ignored on upper layer and execution was continued?

            People

              jplindst Jan Lindström (Inactive)
              marnixgb Martin Nix (Inactive)
              Votes:
              3 Vote for this issue
              Watchers:
              17 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.