Mysql: Deadlock found when trying to get lock; try restarting transaction

Hello team,

On VMware VM was installed single morpheus on Ubuntu 22.04 ( up to date )

dpgk in next: morpheus-appliance_7.0.6-2_amd64.deb
 Static hostname: morpheus
       Icon name: computer-vm
         Chassis: vm
      Machine ID: fe55a737f53b49b88e2017ff9de49f4e
         Boot ID: 26ae100de11f4c1cb554972bac6c2014
  Virtualization: vmware
Operating System: Ubuntu 22.04.5 LTS
          Kernel: Linux 5.15.0-124-generic
    Architecture: x86-64
 Hardware Vendor: VMware, Inc.
  Hardware Model: VMware Virtual Platform

with community license.

in UI: Administration → health → Morpheus logs I see many errors:

ERROR
11/02/2024 11:29:03 AM	appliance	[RxCachedThreadScheduler-64] Deadlock found when trying to get lock; try restarting transaction
ERROR
11/02/2024 11:29:03 AM	appliance	[RxCachedThreadScheduler-46] Deadlock found when trying to get lock; try restarting transaction
ERROR
11/02/2024 11:29:03 AM	appliance	[RxCachedThreadScheduler-29] Deadlock found when trying to get lock; try restarting transaction
ERROR
11/02/2024 11:27:58 AM	appliance	[RxCachedThreadScheduler-62] Deadlock found when trying to get lock; try restarting transaction
ERROR
11/02/2024 11:27:58 AM	appliance	[RxCachedThreadScheduler-7] Deadlock found when trying to get lock; try restarting transaction
ERROR
11/02/2024 11:27:58 AM	appliance	[RxCachedThreadScheduler-39] Deadlock found when trying to get lock; try restarting transaction
ERROR
11/02/2024 11:27:58 AM	appliance	[RxCachedThreadScheduler-65] Deadlock found when trying to get lock; try restarting transaction
ERROR
11/02/2024 11:27:58 AM	appliance	[RxCachedThreadScheduler-60] Deadlock found when trying to get lock; try restarting transaction
ERROR
11/02/2024 11:27:58 AM	appliance	[RxCachedThreadScheduler-30] Deadlock found when trying to get lock; try restarting transaction

I didnt changed any configuration of mysql or installed any external packages

[client]
default-character-set          = utf8mb4
port                           = 3306
socket                         = /var/run/morpheus/mysqld/mysqld.sock

[mysql]
default-character-set          = utf8mb4

[mysqld]
default_time_zone              = "+00:00"
user                           = mysql-morpheus
pid-file                       = /var/run/morpheus/mysqld/mysqld.pid
socket                         = /var/run/morpheus/mysqld/mysqld.sock
bind-address                   = 127.0.0.1
port                           = 3306
datadir                        = /var/opt/morpheus/mysql/data
tmpdir                         = /var/run/morpheus/mysqld
lc-messages-dir                = /opt/morpheus/embedded/mysql/share
log-error                      = /var/log/morpheus/mysql/mysql_error.log
character-set-server           = utf8mb4
collation-server               = utf8mb4_0900_ai_ci
max_allowed_packet             = 67108864
max_connections                = 151
!includedir /opt/morpheus/embedded/mysql/conf.d
skip-log-bin

[mysqld_safe]
socket                         = /var/run/morpheus/mysqld/mysqld.sock

morpheus.rb

## Url on which Morpheus will be reachable.
## For more details on configuring appliance_url see:
## https://docs.morpheusdata.com
appliance_url 'https://morpheus.local.lab'
mysql> SHOW ENGINE INNODB STATUS \G
*************************** 1. row ***************************
  Type: InnoDB
  Name:
Status:
=====================================
2024-11-02 09:51:34 140233880344128 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 2 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 13182 srv_active, 0 srv_shutdown, 55428 srv_idle
srv_master_thread log flush and writes: 0
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 48502
OS WAIT ARRAY INFO: signal count 39310
RW-shared spins 0, rounds 0, OS waits 0
RW-excl spins 0, rounds 0, OS waits 0
RW-sx spins 0, rounds 0, OS waits 0
Spin rounds per wait: 0.00 RW-shared, 0.00 RW-excl, 0.00 RW-sx
------------------------
LATEST DETECTED DEADLOCK
------------------------
2024-11-02 09:49:37 140234293478976
*** (1) TRANSACTION:
TRANSACTION 538956, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1128, 2 row lock(s)
MySQL thread id 5038, OS thread handle 140234982528576, query id 804159 localhost 127.0.0.1 morpheus updating
delete from distributed_lock where name='morpheus-ui.server.status.cleanup' and timeout<1730540977187

*** (1) HOLDS THE LOCK(S):
RECORD LOCKS space id 299 page no 6 n bits 72 index distributed_lock_timeout_idx of table `morpheus`.`distributed_lock` trx id 538956 lock_mode X locks rec but not gap
Record lock, heap no 2 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 8; hex 80000192ec4c4e98; asc      LN ;;
 1: len 8; hex 80000000000101ee; asc         ;;


*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 299 page no 4 n bits 80 index PRIMARY of table `morpheus`.`distributed_lock` trx id 538956 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 6; compact format; info bits 32
 0: len 8; hex 80000000000101ee; asc         ;;
 1: len 6; hex 00000008394b; asc     9K;;
 2: len 7; hex 02000001ad216a; asc      !j;;
 3: len 30; hex 6d6f7270686575732d75692e6d6f6e69746f722e636865636b2e65787069; asc morpheus-ui.monitor.check.expi; (total 32 bytes);
 4: len 30; hex 38373239353733342d323865382d343339322d393437342d656632633966; asc 87295734-28e8-4392-9474-ef2c9f; (total 36 bytes);
 5: len 8; hex 80000192ec4c4e98; asc      LN ;;


*** (2) TRANSACTION:
TRANSACTION 538955, ACTIVE 0 sec updating or deleting
mysql tables in use 1, locked 1
LOCK WAIT 4 lock struct(s), heap size 1128, 3 row lock(s), undo log entries 1
MySQL thread id 5030, OS thread handle 140234980415040, query id 804157 localhost 127.0.0.1 morpheus updating
delete from distributed_lock where name='morpheus-ui.monitor.check.expire' and value='87295734-28e8-4392-9474-ef2c9f3b2e2d'

*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 299 page no 4 n bits 80 index PRIMARY of table `morpheus`.`distributed_lock` trx id 538955 lock_mode X locks rec but not gap
Record lock, heap no 2 PHYSICAL RECORD: n_fields 6; compact format; info bits 32
 0: len 8; hex 80000000000101ee; asc         ;;
 1: len 6; hex 00000008394b; asc     9K;;
 2: len 7; hex 02000001ad216a; asc      !j;;
 3: len 30; hex 6d6f7270686575732d75692e6d6f6e69746f722e636865636b2e65787069; asc morpheus-ui.monitor.check.expi; (total 32 bytes);
 4: len 30; hex 38373239353733342d323865382d343339322d393437342d656632633966; asc 87295734-28e8-4392-9474-ef2c9f; (total 36 bytes);
 5: len 8; hex 80000192ec4c4e98; asc      LN ;;


*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 299 page no 6 n bits 80 index distributed_lock_timeout_idx of table `morpheus`.`distributed_lock` trx id 538955 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 8; hex 80000192ec4c4e98; asc      LN ;;
 1: len 8; hex 80000000000101ee; asc         ;;

*** WE ROLL BACK TRANSACTION (1)
------------
TRANSACTIONS
------------
Trx id counter 539209
Purge done for trx's n:o < 539209 undo n:o < 0 state: running but idle
History list length 34
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421710371182912, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421710371182104, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421710371181296, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421710371179680, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421710371178872, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421710371177256, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421710371176448, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421710371175640, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421710371180488, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421710371178064, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421710371185336, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421710371174832, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421710371174024, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request ((null))
I/O thread 1 state: waiting for i/o request (insert buffer thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (read thread)
I/O thread 4 state: waiting for i/o request (read thread)
I/O thread 5 state: waiting for i/o request (read thread)
I/O thread 6 state: waiting for i/o request (write thread)
I/O thread 7 state: waiting for i/o request (write thread)
I/O thread 8 state: waiting for i/o request (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
 ibuf aio reads:
Pending flushes (fsync) log: 0; buffer pool: 0
8943 OS file reads, 608527 OS file writes, 364154 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.50 writes/s, 0.99 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 5 merges
merged operations:
 insert 6, delete mark 0, delete 0
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 34679, node heap has 23 buffer(s)
Hash table size 34679, node heap has 9 buffer(s)
Hash table size 34679, node heap has 13 buffer(s)
Hash table size 34679, node heap has 6 buffer(s)
Hash table size 34679, node heap has 11 buffer(s)
Hash table size 34679, node heap has 4 buffer(s)
Hash table size 34679, node heap has 5 buffer(s)
Hash table size 34679, node heap has 6 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number          677589605
Log buffer assigned up to    677589605
Log buffer completed up to   677589605
Log written up to            677589605
Log flushed up to            677589605
Added dirty pages up to      677589605
Pages flushed up to          677589605
Last checkpoint at           677589605
Log minimum file id is       204
Log maximum file id is       206
198777 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 0
Dictionary memory allocated 11680128
Buffer pool size   8192
Free buffers       1024
Database pages     7091
Old database pages 2597
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 1008, not young 12345
0.00 youngs/s, 0.00 non-youngs/s
Pages read 7278, created 966, written 311756
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 7091, unzip_LRU len: 0
I/O sum[125]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Process ID=123820, Main thread ID=140234251519552 , state=sleeping
Number of rows inserted 22766, updated 25813, deleted 20477, read 8296379
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 5.00 reads/s
Number of system rows inserted 8, updated 332, deleted 8, read 5891517
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

1 row in set (0.00 sec)

How I can fix this error?

What size VM is this provisioned on? Any snapshots or backup software that targets the server? apparmor running?


By default standard morpheus backup is configured and no other tools.
size ov VM: 8CPU, 32 RAM, 400GB storage - here is ok

Apparmor was enabled… systemctl disable --now apparmor.service was implemented and restarted VM.

Now still facing this error.

Maybe reconfigure after disabling apparmor?

yes I would reconfigure after. I know apparmor and selinux provide oddities when in enforcing.

Hi,

Unfortunately still face this issue in log. Even upgrade to 7.0.7 didn’t help. I guest that its related to MySQL configuration…

Because after sometimes “HOLDS THE LOCK(S)” is empty…