Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Improve][Manager] MySQL deadlocked when operating stream source #3264

Closed
2 tasks done
kipshi opened this issue Mar 21, 2022 · 0 comments · Fixed by #3265
Closed
2 tasks done

[Improve][Manager] MySQL deadlocked when operating stream source #3264

kipshi opened this issue Mar 21, 2022 · 0 comments · Fixed by #3265
Assignees
Milestone

Comments

@kipshi
Copy link
Contributor

kipshi commented Mar 21, 2022

Description

Log of dead lock:


=====================================
2022-03-20 19:55:33 0x7f649e9ff700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 1 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 87222 srv_active, 0 srv_shutdown, 259493 srv_idle
srv_master_thread log flush and writes: 346708
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 29654
OS WAIT ARRAY INFO: signal count 28482
RW-shared spins 0, rounds 50034, OS waits 24972
RW-excl spins 0, rounds 10180, OS waits 38
RW-sx spins 37, rounds 330, OS waits 6
Spin rounds per wait: 50034.00 RW-shared, 10180.00 RW-excl, 8.92 RW-sx
------------------------
LATEST DETECTED DEADLOCK
------------------------
2022-03-18 17:56:26 0x7f64a7afe700
*** (1) TRANSACTION:
TRANSACTION 177164, ACTIVE 27 sec fetching rows
mysql tables in use 1, locked 1
LOCK WAIT 7 lock struct(s), heap size 1136, 77 row lock(s)
MySQL thread id 55437, OS thread handle 140070349686528, query id 1321523 172.17.6.186 root Sending data
select
         
        id, inlong_group_id, inlong_stream_id, source_type, source_name, agent_ip, uuid,
        server_id, server_name, cluster_id, cluster_name, snapshot, report_time, ext_params,
        status, previous_status, is_deleted, creator, modifier, create_time, modify_time
     
        from stream_source
         WHERE is_deleted = 0
            and status in
            (
                200
            ,
                205
            )
            limit 2 for update
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 48 page no 9 n bits 88 index PRIMARY of table `apache_inlong_manager`.`stream_source` trx id 177164 lock_mode X waiting
Record lock, heap no 7 PHYSICAL RECORD: n_fields 23; compact format; info bits 0
 0: len 4; hex 80000049; asc    I;;
 1: len 6; hex 00000002b3b4; asc       ;;
 2: len 7; hex b90000012e0110; asc     .  ;;
 3: len 30; hex 625f32303230316533632d626636342d343736662d386365632d65373766; asc b_20201e3c-bf64-476f-8cec-e77f; (total 38 bytes);
 4: len 30; hex 625f32303230316533632d626636342d343736662d386365632d65373766; asc b_20201e3c-bf64-476f-8cec-e77f; (total 50 bytes);
 5: len 30; hex 62313763336566652d663362622d343332332d383738662d396363643937; asc b17c3efe-f3bb-4323-878f-9ccd97; (total 36 bytes);
 6: len 6; hex 42494e4c4f47; asc BINLOG;;
 7: SQL NULL;
 8: SQL NULL;
 9: SQL NULL;
 10: SQL NULL;
 11: SQL NULL;
 12: SQL NULL;
 13: SQL NULL;
 14: len 4; hex 6234571e; asc b4W ;;
 15: len 30; hex 7b2275736572223a22726f6f74222c2270617373776f7264223a22426967; asc {"user":"root","password":"Big; (total 338 bytes);
 16: len 4; hex 8000006e; asc    n;;
 17: SQL NULL;
 18: len 4; hex 80000000; asc     ;;
 19: len 5; hex 61646d696e; asc admin;;
 20: len 5; hex 61646d696e; asc admin;;
 21: len 4; hex 6234571e; asc b4W ;;
 22: len 4; hex 6234571e; asc b4W ;;

*** (2) TRANSACTION:
TRANSACTION 177086, ACTIVE 43 sec starting index read
mysql tables in use 1, locked 1
21 lock struct(s), heap size 1136, 26 row lock(s), undo log entries 15
MySQL thread id 55476, OS thread handle 140070286780160, query id 1321734 172.17.6.186 root updating
update stream_source
        set previous_status = status,
        status = 200,
        modify_time = modify_time
         WHERE inlong_group_id = 'b_20201e3c-bf64-476f-8cec-e77f8f2db725'
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 48 page no 9 n bits 88 index PRIMARY of table `apache_inlong_manager`.`stream_source` trx id 177086 lock_mode X locks rec but not gap
Record lock, heap no 7 PHYSICAL RECORD: n_fields 23; compact format; info bits 0
 0: len 4; hex 80000049; asc    I;;
 1: len 6; hex 00000002b3b4; asc       ;;
 2: len 7; hex b90000012e0110; asc     .  ;;
 3: len 30; hex 625f32303230316533632d626636342d343736662d386365632d65373766; asc b_20201e3c-bf64-476f-8cec-e77f; (total 38 bytes);
 4: len 30; hex 625f32303230316533632d626636342d343736662d386365632d65373766; asc b_20201e3c-bf64-476f-8cec-e77f; (total 50 bytes);
 5: len 30; hex 62313763336566652d663362622d343332332d383738662d396363643937; asc b17c3efe-f3bb-4323-878f-9ccd97; (total 36 bytes);
 6: len 6; hex 42494e4c4f47; asc BINLOG;;
 7: SQL NULL;
 8: SQL NULL;
 9: SQL NULL;
 10: SQL NULL;
 11: SQL NULL;
 12: SQL NULL;
 13: SQL NULL;
 14: len 4; hex 6234571e; asc b4W ;;
 15: len 30; hex 7b2275736572223a22726f6f74222c2270617373776f7264223a22426967; asc {"user":"root","password":"Big; (total 338 bytes);
 16: len 4; hex 8000006e; asc    n;;
 17: SQL NULL;
 18: len 4; hex 80000000; asc     ;;
 19: len 5; hex 61646d696e; asc admin;;
 20: len 5; hex 61646d696e; asc admin;;
 21: len 4; hex 6234571e; asc b4W ;;
 22: len 4; hex 6234571e; asc b4W ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 48 page no 9 n bits 88 index PRIMARY of table `apache_inlong_manager`.`stream_source` trx id 177086 lock_mode X locks rec but not gap waiting
Record lock, heap no 19 PHYSICAL RECORD: n_fields 23; compact format; info bits 0
 0: len 4; hex 8000003e; asc    >;;
 1: len 6; hex 00000002b3ff; asc       ;;
 2: len 7; hex 65000001f92a4a; asc e    *J;;
 3: len 30; hex 625f32303230316533632d626636342d343736662d386365632d65373766; asc b_20201e3c-bf64-476f-8cec-e77f; (total 38 bytes);
 4: len 30; hex 625f32303230316533632d626636342d343736662d386365632d65373766; asc b_20201e3c-bf64-476f-8cec-e77f; (total 50 bytes);
 5: len 30; hex 61313438636265332d316165312d346561322d393737362d326164343364; asc a148cbe3-1ae1-4ea2-9776-2ad43d; (total 36 bytes);
 6: len 6; hex 42494e4c4f47; asc BINLOG;;
 7: len 0; hex ; asc ;;
 8: len 0; hex ; asc ;;
 9: SQL NULL;
 10: SQL NULL;
 11: SQL NULL;
 12: SQL NULL;
 13: len 30; hex 724f304142584e794142467159585a684c6e5630615777755347467a6145; asc rO0ABXNyABFqYXZhLnV0aWwuSGFzaE; (total 456 bytes);
 14: len 4; hex 6233e6a3; asc b3  ;;
 15: len 30; hex 7b2275736572223a22726f6f74222c2270617373776f7264223a22426967; asc {"user":"root","password":"Big; (total 338 bytes);
 16: len 4; hex 800000c8; asc     ;;
 17: len 4; hex 800000c9; asc     ;;
 18: len 4; hex 8000003e; asc    >;;
 19: len 5; hex 61646d696e; asc admin;;
 20: len 5; hex 61646d696e; asc admin;;
 21: len 4; hex 6233fafe; asc b3  ;;
 22: len 4; hex 6234422e; asc b4B.;;

*** WE ROLL BACK TRANSACTION (1)
------------
TRANSACTIONS
------------
Trx id counter 676451
Purge done for trx's n:o < 676451 undo n:o < 0 state: running but idle
History list length 27
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421552864628896, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421552864626864, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421552864627880, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421552864625848, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421552864624832, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421552864622800, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 675657, ACTIVE 240 sec
5 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 3
MySQL thread id 113816, OS thread handle 140070278919936, query id 2836040 172.17.6.186 root
--------
FILE I/O
--------
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
I/O thread 1 state: waiting for completed aio requests (log thread)
I/O thread 2 state: waiting for completed aio requests (read thread)
I/O thread 3 state: waiting for completed aio requests (read thread)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (write thread)
I/O thread 7 state: waiting for completed aio requests (write thread)
I/O thread 8 state: waiting for completed aio requests (write thread)
I/O thread 9 state: waiting for completed aio requests (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
 ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 0
279 OS file reads, 1667294 OS file writes, 499746 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 0 merges
merged operations:
 insert 0, delete mark 0, delete 0
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 1593833, node heap has 0 buffer(s)
Hash table size 1593833, node heap has 0 buffer(s)
Hash table size 1593833, node heap has 0 buffer(s)
Hash table size 1593833, node heap has 0 buffer(s)
Hash table size 1593833, node heap has 0 buffer(s)
Hash table size 1593833, node heap has 0 buffer(s)
Hash table size 1593833, node heap has 0 buffer(s)
Hash table size 1593833, node heap has 0 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 176589846
Log flushed up to   176589846
Pages flushed up to 176589846
Last checkpoint at  176589837
0 pending log flushes, 0 pending chkp writes
394669 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 6606028800
Dictionary memory allocated 474326
Buffer pool size   393216
Free buffers       392244
Database pages     972
Old database pages 0
Modified db pages  4
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 247, created 725, written 1223866
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: 972, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
----------------------
INDIVIDUAL BUFFER POOL INFO
----------------------
---BUFFER POOL 0
Buffer pool size   98304
Free buffers       98038
Database pages     266
Old database pages 0
Modified db pages  4
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 123, created 143, written 481420
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: 266, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 1
Buffer pool size   98304
Free buffers       98090
Database pages     214
Old database pages 0
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 16, created 198, written 18185
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 214, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 2
Buffer pool size   98304
Free buffers       98095
Database pages     209
Old database pages 0
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 19, created 190, written 218874
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 209, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 3
Buffer pool size   98304
Free buffers       98021
Database pages     283
Old database pages 0
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 89, created 194, written 505387
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: 283, unzip_LRU len: 0
I/O sum[0]: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=352088, Main thread ID=140070502213376, state: sleeping
Number of rows inserted 3500584, updated 329046, deleted 114, read 32554350
66.93 inserts/s, 0.00 updates/s, 0.00 deletes/s, 69.93 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

InLong Component

InLong Manager

Are you willing to submit PR?

  • Yes, I am willing to submit a PR!

Code of Conduct

@dockerzhang dockerzhang added this to the 1.1.0 milestone Mar 21, 2022
@healchow healchow changed the title [Improve] Fix dead lock of mysql when operate streamSource [Improve][Manager] MySQL deadlocked when operating stream source Mar 21, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants