Skip to content
New issue
Jump to bottom

ERROR: mx_mysql_do_statement(): Deadlock found when trying to get lock; try restarting transaction #161

Closed
donald opened this issue Aug 26, 2024 · 3 comments · Fixed by #164
Closed

ERROR: mx_mysql_do_statement(): Deadlock found when trying to get lock; try restarting transaction #161

donald opened this issue Aug 26, 2024 · 3 comments · Fixed by #164

Comments

@donald
Copy link
Contributor

donald commented Aug 26, 2024

http://afk.molgen.mpg.de/mxq/mxq/job/52017245

2024-08-26 11:35:09 +0200 mxqd[150090]: job finished (via fspool) : job 52017245 pid 67386 status 0
2024-08-26 11:35:09 +0200 mxqd[150090]: WARNING: mx_mysql_do_statement() failed: Invalid exchange
2024-08-26 11:35:09 +0200 mxqd[150090]: ERROR: mx_mysql_do_statement(): Deadlock found when trying to get lock; try restarting transaction
2024-08-26 11:35:09 +0200 mxqd[150090]: Main loop freed 14 slots.
2024-08-26 11:35:09 +0200 mxqd[150090]:   group=arndt(8099):566348 slots_to_start=18 slots_per_job=14 :: trying to start job for group.
2024-08-26 11:35:09 +0200 mxqd[150090]: WARNING:   group_id=566348 :: mxq_assign_job_from_group_to_daemon(): No matching job found - maybe another server was a bit faster. ;)
2024-08-26 11:35:09 +0200 mxqd[150090]:   group=arndt(8099):566348 slots_to_start=18 slots_per_job=14 :: trying to start job for group.
@donald
Copy link
Contributor Author

donald commented Aug 26, 2024 

mxqprj@macheteinfach:~> mysql -u root -p
mysql> show engine innodb status;
[...]
=====================================
2024-08-26 12:41:15 7ff1b7e736c0 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 11 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 18938929 srv_active, 0 srv_shutdown, 1255450 srv_idle
srv_master_thread log flush and writes: 20194377
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 265196072
OS WAIT ARRAY INFO: signal count 265628773
Mutex spin waits 527019005, rounds 6176338098, OS waits 30313815
RW-shared spins 712964354, rounds 8105822838, OS waits 218730580
RW-excl spins 5054403, rounds 53124335, OS waits 118538
Spin rounds per wait: 11.72 mutex, 11.37 RW-shared, 10.51 RW-excl
------------------------
LATEST DETECTED DEADLOCK
------------------------
2024-08-26 11:35:09 7ff1b7e736c0
*** (1) TRANSACTION:
TRANSACTION 3408599826, ACTIVE 0 sec starting index read
mysql tables in use 2, locked 2
LOCK WAIT 4 lock struct(s), heap size 1248, 2 row lock(s)
MySQL thread id 10149229, OS thread handle 0x7ff2242756c0, query id 667599828 dugong.molgen.mpg.de 141.14.19.142 mxqprj updating
UPDATE mxq_group SET
                    group_slots_running = group_slots_running - OLD.host_slots,
                    group_jobs_running  = group_jobs_running  - 1,
                    group_jobs_finished = group_jobs_finished + 1,
                    stats_max_sumrss    = GREATEST(stats_max_sumrss,    NEW.stats_max_sumrss),
                    stats_max_maxrss    = GREATEST(stats_max_maxrss,    NEW.stats_maxrss),
                    stats_max_utime_sec = GREATEST(stats_max_utime_sec, NEW.stats_utime_sec),
                    stats_max_stime_sec = GREATEST(stats_max_stime_sec, NEW.stats_stime_sec),
                    stats_max_real_sec  = GREATEST(stats_max_real_sec,  NEW.stats_real_sec),
                    stats_total_utime_sec = stats_total_utime_sec + NEW.stats_utime_sec,
                    stats_total_stime_sec = stats_total_stime_sec + NEW.stats_stime_sec,
              
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 229 page no 16507 n bits 80 index `PRIMARY` of table `mxq`.`mxq_group` trx id 3408599826 lock_mode X locks rec but not gap waiting
Record lock, heap no 7 PHYSICAL RECORD: n_fields 51; compact format; info bits 0
 0: len 8; hex 000000000008a44c; asc        L;;
 1: len 6; hex 0000cb2b1b08; asc    +  ;;
 2: len 7; hex 190000013214ae; asc     2  ;;
 3: len 12; hex 5057432d4d6f6e2d31313037; asc PWC-Mon-1107;;
 4: len 1; hex 00; asc  ;;
 5: len 8; hex 0000000000000000; asc         ;;
 6: len 2; hex 007f; asc   ;;
 7: len 30; hex 636173736f7761727920666c7566667962757474206b6f616c61206b7265; asc cassowary fluffybutt koala kre; (total 58 bytes);
 8: len 0; hex ; asc ;;
 9: len 5; hex 7373736533; asc ssse3;;
 10: len 0; hex ; asc ;;
 11: len 4; hex 00001fa3; asc     ;;
 12: len 5; hex 61726e6474; asc arndt;;
 13: len 4; hex 00001fa3; asc     ;;
 14: len 5; hex 61726e6474; asc arndt;;
 15: len 30; hex 2f70726f6a6563742f65766f67656e2d636f6d707574696e672f71756575; asc /project/evogen-computing/queu; (total 54 bytes);
 16: len 2; hex 0001; asc   ;;
 17: len 8; hex 000000000000c800; asc         ;;
 18: len 4; hex 000000f0; asc     ;;
 19: len 4; hex 00000064; asc    d;;
 20: len 2; hex 0000; asc   ;;
 21: len 2; hex 0000; asc   ;;
 22: len 8; hex 0000000000000fa0; asc         ;;
 23: len 8; hex 0000000000000ce3; asc         ;;
 24: len 8; hex 00000000000002af; asc         ;;
 25: len 8; hex 000000000000000e; asc         ;;
 26: len 8; hex 0000000000000000; asc         ;;
 27: len 8; hex 0000000000000000; asc         ;;
 28: len 8; hex 0000000000000000; asc         ;;
 29: len 8; hex 0000000000002173; asc       !s;;
 30: len 8; hex 0000000000000000; asc         ;;
 31: len 4; hex 66cc4c4d; asc f LM;;
 32: len 4; hex 00000000; asc     ;;
 33: len 8; hex 00000000008f8928; asc        (;;
 34: len 8; hex 0000000001007e84; asc       ~ ;;
 35: len 8; hex 00000000000000bc; asc         ;;
 36: len 8; hex 0000000000000010; asc         ;;
 37: len 8; hex 000000000000066b; asc        k;;
 38: len 8; hex 00000000000001e8; asc         ;;
 39: len 8; hex 000000000000003d; asc        =;;
 40: len 8; hex 00000000000059a9; asc       Y ;;
 41: len 8; hex 0000000000000000; asc         ;;
 42: len 8; hex 0000000000000000; asc         ;;
 43: len 8; hex 0000000000000672; asc        r;;
 44: len 8; hex 0000000000000000; asc         ;;
 45: len 8; hex 00000000000001e8; asc         ;;
 46: len 8; hex 000000000000003d; asc        =;;
 47: len 8; hex 00000000000059a9; asc       Y ;;
 48: len 8; hex 0000000000000000; asc         ;;
 49: SQL NULL;
 50: SQL NULL;

*** (2) TRANSACTION:
TRANSACTION 3408599824, ACTIVE 0 sec fetching rows
mysql tables in use 3, locked 3
102 lock struct(s), heap size 14776, 6727 row lock(s), undo log entries 3343
MySQL thread id 13056889, OS thread handle 0x7ff1b7e736c0, query id 667599813 likearollingstone.molgen.mpg.de 141.14.18.5 mxqprj Sending data
INSERT INTO j(job_id)  SELECT mxq_job.job_id FROM mxq_job,mxq_group  WHERE mxq_job.group_id = mxq_group.group_id  AND user_uid = ?  AND job_status IN (0,100,150,200  )
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 229 page no 16507 n bits 80 index `PRIMARY` of table `mxq`.`mxq_group` trx id 3408599824 lock mode S locks rec but not gap
Record lock, heap no 4 PHYSICAL RECORD: n_fields 51; compact format; info bits 0
 0: len 8; hex 000000000008a449; asc        I;;
 1: len 6; hex 0000cb2a37b1; asc    *7 ;;
 2: len 7; hex 73000001b415b0; asc s      ;;
 3: len 7; hex 64656661756c74; asc default;;
 4: len 1; hex 00; asc  ;;
 5: len 8; hex 0000000000000000; asc         ;;
 6: len 2; hex 007f; asc   ;;
 7: len 0; hex ; asc ;;
 8: len 0; hex ; asc ;;
 9: len 0; hex ; asc ;;
 10: len 0; hex ; asc ;;
 11: len 4; hex 00001e4a; asc    J;;
 12: len 8; hex 6b6f6c637a796e73; asc kolczyns;;
 13: len 4; hex 00001e4a; asc    J;;
 14: len 8; hex 6b6f6c637a796e73; asc kolczyns;;
 15: len 11; hex 527363726970742d342e32; asc Rscript-4.2;;
 16: len 2; hex 0010; asc   ;;
 17: len 8; hex 0000000000010000; asc         ;;
 18: len 4; hex 00000bb8; asc     ;;
 19: len 4; hex 0000000a; asc     ;;
 20: len 2; hex 0000; asc   ;;
 21: len 2; hex 0000; asc   ;;
 22: len 8; hex 0000000000000001; asc         ;;
 23: len 8; hex 0000000000000000; asc         ;;
 24: len 8; hex 0000000000000001; asc         ;;
 25: len 8; hex 0000000000000000; asc         ;;
 26: len 8; hex 0000000000000000; asc         ;;
 27: len 8; hex 0000000000000000; asc         ;;
 28: len 8; hex 0000000000000000; asc         ;;
 29: len 8; hex 0000000000000010; asc         ;;
 30: len 8; hex 0000000000000000; asc         ;;
 31: len 4; hex 66cc3e5c; asc f >\;;
 32: len 4; hex 00000000; asc     ;;
 33: len 8; hex 0000000000000000; asc         ;;
 34: len 8; hex 0000000000000000; asc         ;;
 35: len 8; hex 0000000000000000; asc         ;;
 36: len 8; hex 0000000000000000; asc         ;;
 37: len 8; hex 0000000000000000; asc         ;;
 38: len 8; hex 0000000000000000; asc         ;;
 39: len 8; hex 0000000000000000; asc         ;;
 40: len 8; hex 0000000000000000; asc         ;;
 41: len 8; hex 0000000000000000; asc         ;;
 42: len 8; hex 0000000000000000; asc         ;;
 43: len 8; hex 0000000000000002; asc         ;;
 44: len 8; hex 0000000000000000; asc         ;;
 45: len 8; hex 0000000000000000; asc         ;;
 46: len 8; hex 0000000000000000; asc         ;;
 47: len 8; hex 0000000000000000; asc         ;;
 48: len 8; hex 0000000000000000; asc         ;;
 49: SQL NULL;
 50: SQL NULL;

Record lock, heap no 5 PHYSICAL RECORD: n_fields 51; compact format; info bits 0
 0: len 8; hex 000000000008a44a; asc        J;;
 1: len 6; hex 0000cb2a4812; asc    *H ;;
 2: len 7; hex 4c000080170672; asc L     r;;
 3: len 4; hex 4d585149; asc MXQI;;
 4: len 1; hex 00; asc  ;;
 5: len 8; hex 0000000000000000; asc         ;;
 6: len 2; hex 007f; asc   ;;
 7: len 0; hex ; asc ;;
 8: len 0; hex ; asc ;;
 9: len 0; hex ; asc ;;
 10: len 4; hex 6d787169; asc mxqi;;
 11: len 4; hex 00002177; asc   !w;;
 12: len 8; hex 7374656e74656c6c; asc stentell;;
 13: len 4; hex 00002177; asc   !w;;
 14: len 8; hex 7374656e74656c6c; asc stentell;;
 15: len 9; hex 2f62696e2f6d787169; asc /bin/mxqi;;
 16: len 2; hex 0040; asc  @;;
 17: len 8; hex 000000000000a000; asc         ;;
 18: len 4; hex 00000258; asc    X;;
 19: len 4; hex 00000064; asc    d;;
 20: len 2; hex 0000; asc   ;;
 21: len 2; hex 0000; asc   ;;
 22: len 8; hex 0000000000000001; asc         ;;
 23: len 8; hex 0000000000000000; asc         ;;
 24: len 8; hex 0000000000000001; asc         ;;
 25: len 8; hex 0000000000000000; asc         ;;
 26: len 8; hex 0000000000000000; asc         ;;
 27: len 8; hex 0000000000000000; asc         ;;
 28: len 8; hex 0000000000000000; asc         ;;
 29: len 8; hex 0000000000000040; asc        @;;
 30: len 8; hex 0000000000000000; asc         ;;
 31: len 4; hex 66cc4123; asc f A#;;
 32: len 4; hex 00000000; asc     ;;
 33: len 8; hex 0000000000000000; asc         ;;
 34: len 8; hex 0000000000000000; asc         ;;
 35: len 8; hex 0000000000000000; asc         ;;
 36: len 8; hex 0000000000000000; asc         ;;
 37: len 8; hex 0000000000000000; asc         ;;
 38: len 8; hex 0000000000000000; asc         ;;
 39: len 8; hex 0000000000000000; asc         ;;
 40: len 8; hex 0000000000000000; asc         ;;
 41: len 8; hex 0000000000000000; asc         ;;
 42: len 8; hex 000000000000000e; asc         ;;
 43: len 8; hex 0000000000000001; asc         ;;
 44: len 8; hex 0000000000000000; asc         ;;
 45: len 8; hex 0000000000000000; asc         ;;
 46: len 8; hex 0000000000000000; asc         ;;
 47: len 8; hex 0000000000000000; asc         ;;
 48: len 8; hex 0000000000000000; asc         ;;
 49: SQL NULL;
 50: SQL NULL;

Record lock, heap no 7 PHYSICAL RECORD: n_fields 51; compact format; info bits 0
 0: len 8; hex 000000000008a44c; asc        L;;
 1: len 6; hex 0000cb2b1b08; asc    +  ;;
 2: len 7; hex 190000013214ae; asc     2  ;;
 3: len 12; hex 5057432d4d6f6e2d31313037; asc PWC-Mon-1107;;
 4: len 1; hex 00; asc  ;;
 5: len 8; hex 0000000000000000; asc         ;;
 6: len 2; hex 007f; asc   ;;
 7: len 30; hex 636173736f7761727920666c7566667962757474206b6f616c61206b7265; asc cassowary fluffybutt koala kre; (total 58 bytes);
 8: len 0; hex ; asc ;;
 9: len 5; hex 7373736533; asc ssse3;;
 10: len 0; hex ; asc ;;
 11: len 4; hex 00001fa3; asc     ;;
 12: len 5; hex 61726e6474; asc arndt;;
 13: len 4; hex 00001fa3; asc     ;;
 14: len 5; hex 61726e6474; asc arndt;;
 15: len 30; hex 2f70726f6a6563742f65766f67656e2d636f6d707574696e672f71756575; asc /project/evogen-computing/queu; (total 54 bytes);
 16: len 2; hex 0001; asc   ;;
 17: len 8; hex 000000000000c800; asc         ;;
 18: len 4; hex 000000f0; asc     ;;
 19: len 4; hex 00000064; asc    d;;
 20: len 2; hex 0000; asc   ;;
 21: len 2; hex 0000; asc   ;;
 22: len 8; hex 0000000000000fa0; asc         ;;
 23: len 8; hex 0000000000000ce3; asc         ;;
 24: len 8; hex 00000000000002af; asc         ;;
 25: len 8; hex 000000000000000e; asc         ;;
 26: len 8; hex 0000000000000000; asc         ;;
 27: len 8; hex 0000000000000000; asc         ;;
 28: len 8; hex 0000000000000000; asc         ;;
 29: len 8; hex 0000000000002173; asc       !s;;
 30: len 8; hex 0000000000000000; asc         ;;
 31: len 4; hex 66cc4c4d; asc f LM;;
 32: len 4; hex 00000000; asc     ;;
 33: len 8; hex 00000000008f8928; asc        (;;
 34: len 8; hex 0000000001007e84; asc       ~ ;;
 35: len 8; hex 00000000000000bc; asc         ;;
 36: len 8; hex 0000000000000010; asc         ;;
 37: len 8; hex 000000000000066b; asc        k;;
 38: len 8; hex 00000000000001e8; asc         ;;
 39: len 8; hex 000000000000003d; asc        =;;
 40: len 8; hex 00000000000059a9; asc       Y ;;
 41: len 8; hex 0000000000000000; asc         ;;
 42: len 8; hex 0000000000000000; asc         ;;
 43: len 8; hex 0000000000000672; asc        r;;
 44: len 8; hex 0000000000000000; asc         ;;
 45: len 8; hex 00000000000001e8; asc         ;;
 46: len 8; hex 000000000000003d; asc        =;;
 47: len 8; hex 00000000000059a9; asc       Y ;;
 48: len 8; hex 0000000000000000; asc         ;;
 49: SQL NULL;
 50: SQL NULL;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 228 page no 2232740 n bits 112 index `PRIMARY` of table `mxq`.`mxq_job` trx id 3408599824 lock mode S locks rec but not gap waiting
Record lock, heap no 18 PHYSICAL RECORD: n_fields 40; compact format; info bits 0
 0: len 8; hex 000000000319b85d; asc        ];;
 1: len 6; hex 0000cb2aa8aa; asc    *  ;;
 2: len 7; hex 2c0000c00b2d57; asc ,    -W;;
 3: len 2; hex 00c8; asc   ;;
 4: len 2; hex 007f; asc   ;;
 5: len 1; hex 80; asc  ;;
 6: len 8; hex 000000000008a44c; asc        L;;
 7: len 24; hex 2f70726f6a6563742f506f7053696d2f686f7473706f7473; asc /project/PopSim/hotspots;;
 8: len 4; hex 00000002; asc     ;;
 9: len 30; hex 2f70726f6a6563742f65766f67656e2d636f6d707574696e672f71756575; asc /project/evogen-computing/queu; (total 120 bytes);
 10: len 9; hex 2f6465762f6e756c6c; asc /dev/null;;
 11: len 9; hex 2f6465762f6e756c6c; asc /dev/null;;
 12: len 4; hex 80000007; asc     ;;
 13: len 29; hex 676f6473617665746865717565656e2e6d6f6c67656e2e6d70672e6465; asc godsavethequeen.molgen.mpg.de;;
 14: len 4; hex 6d61696e; asc main;;
 15: len 5; hex 3132363739; asc 12679;;
 16: len 4; hex 00003187; asc   1 ;;
 17: len 20; hex 6475676f6e672e6d6f6c67656e2e6d70672e6465; asc dugong.molgen.mpg.de;;
 18: len 4; hex 0001073a; asc    :;;
 19: len 4; hex 0000000e; asc     ;;
 20: len 7; hex 3230302d323133; asc 200-213;;
 21: len 4; hex 66cc45dc; asc f E ;;
 22: len 4; hex 66cc45df; asc f E ;;
 23: len 4; hex 00000000; asc     ;;
 24: len 8; hex 0000000000000000; asc         ;;
 25: len 4; hex 00000000; asc     ;;
 26: len 8; hex 0000000000000000; asc         ;;
 27: len 4; hex 00000000; asc     ;;
 28: len 8; hex 0000000000000000; asc         ;;
 29: len 4; hex 00000000; asc     ;;
 30: len 8; hex 0000000000000000; asc         ;;
 31: len 4; hex 00000000; asc     ;;
 32: len 8; hex 8000000000000000; asc         ;;
 33: len 8; hex 8000000000000000; asc         ;;
 34: len 8; hex 8000000000000000; asc         ;;
 35: len 8; hex 8000000000000000; asc         ;;
 36: len 8; hex 8000000000000000; asc         ;;
 37: len 8; hex 8000000000000000; asc         ;;
 38: len 8; hex 8000000000000000; asc         ;;
 39: len 8; hex 8000000000000000; asc         ;;

*** WE ROLL BACK TRANSACTION (1)
------------
TRANSACTIONS
------------
Trx id counter 3408657486
Purge done for trx's n:o < 3408657448 undo n:o < 0 state: running but idle
History list length 1971
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 13059754, OS thread handle 0x7ff1b7e736c0, query id 667893775 localhost root init
show engine innodb status
---TRANSACTION 3408657429, not started
MySQL thread id 12956644, OS thread handle 0x7ff1b718f6c0, query id 667893578 nomnomnom.molgen.mpg.de 141.14.25.255 mxqprj cleaning up
---TRANSACTION 3408657400, not started
MySQL thread id 12660404, OS thread handle 0x7ff2290a56c0, query id 667893475 dirtyfork.molgen.mpg.de 141.14.19.27 mxqprj cleaning up
---TRANSACTION 3408657472, not started
MySQL thread id 12631402, OS thread handle 0x7ff1b7ca56c0, query id 667893727 jabberwocky.molgen.mpg.de 141.14.19.35 mxqprj cleaning up
---TRANSACTION 3408657431, not started
MySQL thread id 12629163, OS thread handle 0x7ff2240656c0, query id 667893585 bandersnatch.molgen.mpg.de 141.14.19.34 mxqprj cleaning up
---TRANSACTION 3408657451, not started
MySQL thread id 12621901, OS thread handle 0x7ff1b78c76c0, query id 667893652 theredqueen.molgen.mpg.de 141.14.19.36 mxqprj cleaning up
---TRANSACTION 3408657435, not started
MySQL thread id 12580004, OS thread handle 0x7ff228e536c0, query id 667893599 whiterabbit.molgen.mpg.de 141.14.19.37 mxqprj cleaning up
---TRANSACTION 3408657415, not started
MySQL thread id 11183492, OS thread handle 0x7ff2242b76c0, query id 667893529 greentreefrog.molgen.mpg.de 141.14.19.180 mxqprj cleaning up
---TRANSACTION 3408657456, not started
MySQL thread id 10305726, OS thread handle 0x7ff1b79cf6c0, query id 667893670 magpie.molgen.mpg.de 141.14.19.155 mxqprj cleaning up
---TRANSACTION 3408657386, not started
MySQL thread id 10149848, OS thread handle 0x7ff1b7fbd6c0, query id 667893426 hotelcalifornia.molgen.mpg.de 141.14.16.151 mxqprj cleaning up
---TRANSACTION 3408657485, not started
MySQL thread id 10149815, OS thread handle 0x7ff1b798d6c0, query id 667893774 stairwaytoheaven.molgen.mpg.de 141.14.16.150 mxqprj cleaning up
---TRANSACTION 3408657413, not started
MySQL thread id 10149289, OS thread handle 0x7ff1b77bf6c0, query id 667893522 wombat.molgen.mpg.de 141.14.19.205 mxqprj cleaning up
---TRANSACTION 3408657481, not started
MySQL thread id 10149287, OS thread handle 0x7ff1b7a116c0, query id 667893760 wedgetaileagle.molgen.mpg.de 141.14.19.204 mxqprj cleaning up
---TRANSACTION 3408657462, not started
MySQL thread id 10149285, OS thread handle 0x7ff2240e96c0, query id 667893690 wallaby.molgen.mpg.de 141.14.19.202 mxqprj cleaning up
---TRANSACTION 3408657384, not started
MySQL thread id 10149284, OS thread handle 0x7ff1b7dad6c0, query id 667893419 thornydevil.molgen.mpg.de 141.14.19.201 mxqprj cleaning up
---TRANSACTION 3408657407, not started
MySQL thread id 10149281, OS thread handle 0x7ff1b78016c0, query id 667893499 theclusterbeforetime.molgen.mpg.de 141.14.18.222 mxqprj cleaning up
---TRANSACTION 3408657479, not started
MySQL thread id 10149280, OS thread handle 0x7ff1b7a536c0, query id 667893753 thebiglebowserver.molgen.mpg.de 141.14.18.224 mxqprj cleaning up
---TRANSACTION 3408657449, not started
MySQL thread id 10149278, OS thread handle 0x7ff1b7d296c0, query id 667893645 tasmaniandevil.molgen.mpg.de 141.14.19.200 mxqprj cleaning up
---TRANSACTION 3408657380, not started
MySQL thread id 10149277, OS thread handle 0x7ff1b76b76c0, query id 667893405 taipan.molgen.mpg.de 141.14.19.198 mxqprj cleaning up
---TRANSACTION 3408657402, not started
MySQL thread id 10149275, OS thread handle 0x7ff2241af6c0, query id 667893482 sugarglider.molgen.mpg.de 141.14.19.196 mxqprj cleaning up
---TRANSACTION 3408657441, not started
MySQL thread id 10149274, OS thread handle 0x7ff228e116c0, query id 667893620 stonegirl.molgen.mpg.de 141.14.19.115 mxqprj cleaning up
---TRANSACTION 3408657396, not started
MySQL thread id 10149272, OS thread handle 0x7ff1b76336c0, query id 667893461 stonefish.molgen.mpg.de 141.14.19.193 mxqprj cleaning up
---TRANSACTION 3408657457, not started
MySQL thread id 10149270, OS thread handle 0x7ff1b7ad76c0, query id 667893673 seadragon.molgen.mpg.de 141.14.19.189 mxqprj cleaning up
---TRANSACTION 3408657425, not started
MySQL thread id 10149268, OS thread handle 0x7ff1b76f96c0, query id 667893565 saltwatercrocodile.molgen.mpg.de 141.14.19.186 mxqprj cleaning up
---TRANSACTION 3408657474, not started
MySQL thread id 10149267, OS thread handle 0x7ff22916b6c0, query id 667893734 quokka.molgen.mpg.de 141.14.19.185 mxqprj cleaning up
---TRANSACTION 3408657460, not started
MySQL thread id 10149265, OS thread handle 0x7ff2290216c0, query id 667893683 platypus.molgen.mpg.de 141.14.19.184 mxqprj cleaning up
---TRANSACTION 3408657426, not started
MySQL thread id 10149264, OS thread handle 0x7ff1b773b6c0, query id 667893568 parakeet.molgen.mpg.de 141.14.19.182 mxqprj cleaning up
---TRANSACTION 3408657448, not started
MySQL thread id 10149262, OS thread handle 0x7ff2240a76c0, query id 667893642 otherland.molgen.mpg.de 141.14.19.109 mxqprj cleaning up
---TRANSACTION 3408657382, not started
MySQL thread id 10149261, OS thread handle 0x7ff1b7c636c0, query id 667893412 okeanos.molgen.mpg.de 141.14.18.24 mxqprj cleaning up
---TRANSACTION 3408657468, not started
MySQL thread id 10149258, OS thread handle 0x7ff1b76756c0, query id 667893713 mehrlametta.molgen.mpg.de 141.14.19.38 mxqprj cleaning up
---TRANSACTION 3408657411, not started
MySQL thread id 10149255, OS thread handle 0x7ff1b7a956c0, query id 667893515 kronos.molgen.mpg.de 141.14.18.10 mxqprj cleaning up
---TRANSACTION 3408657477, not started
MySQL thread id 10149254, OS thread handle 0x7ff1b78436c0, query id 667893744 kreios.molgen.mpg.de 141.14.18.26 mxqprj cleaning up
---TRANSACTION 3408657375, not started
MySQL thread id 10149253, OS thread handle 0x7ff1b7b196c0, query id 667893385 koala.molgen.mpg.de 141.14.19.156 mxqprj cleaning up
---TRANSACTION 3408657404, not started
MySQL thread id 10149251, OS thread handle 0x7ff1b7fff6c0, query id 667893489 kangaroo.molgen.mpg.de 141.14.19.181 mxqprj cleaning up
---TRANSACTION 3408657464, not started
MySQL thread id 10149248, OS thread handle 0x7ff1b7b9d6c0, query id 667893699 hotshotsthemotherofallservers.molgen.mpg.de 141.14.18.223 mxqprj cleaning up
---TRANSACTION 3408657392, not started
MySQL thread id 10149244, OS thread handle 0x7ff2242336c0, query id 667893447 greatwhiteshark.molgen.mpg.de 141.14.19.153 mxqprj cleaning up
---TRANSACTION 3408657427, not started
MySQL thread id 10149243, OS thread handle 0x7ff22412b6c0, query id 667893571 goanna.molgen.mpg.de 141.14.19.150 mxqprj cleaning up
---TRANSACTION 3408657453, not started
MySQL thread id 10149241, OS thread handle 0x7ff2291296c0, query id 667893659 galah.molgen.mpg.de 141.14.19.146 mxqprj cleaning up
---TRANSACTION 3408657395, not started
MySQL thread id 10149240, OS thread handle 0x7ff228e956c0, query id 667893458 frillneckedlizard.molgen.mpg.de 141.14.19.144 mxqprj cleaning up
---TRANSACTION 3408657388, not started
MySQL thread id 10149238, OS thread handle 0x7ff1b794b6c0, query id 667893433 freshwatercrocodile.molgen.mpg.de 141.14.19.145 mxqprj cleaning up
---TRANSACTION 3408657421, not started
MySQL thread id 10149236, OS thread handle 0x7ff228ed76c0, query id 667893550 fluffybutt.molgen.mpg.de 141.14.17.243 mxqprj cleaning up
---TRANSACTION 3408657484, not started
MySQL thread id 10149234, OS thread handle 0x7ff1b7d6b6c0, query id 667893771 einklavier.molgen.mpg.de 141.14.17.177 mxqprj cleaning up
---TRANSACTION 3408657417, not started
MySQL thread id 10149231, OS thread handle 0x7ff22416d6c0, query id 667893536 echidna.molgen.mpg.de 141.14.19.143 mxqprj cleaning up
---TRANSACTION 3408657410, not started
MySQL thread id 10149229, OS thread handle 0x7ff2242756c0, query id 667893512 dugong.molgen.mpg.de 141.14.19.142 mxqprj cleaning up
---TRANSACTION 3408657470, not started
MySQL thread id 10149223, OS thread handle 0x7ff2242f96c0, query id 667893720 dingo.molgen.mpg.de 141.14.19.141 mxqprj cleaning up
---TRANSACTION 3408657377, not started
MySQL thread id 10149220, OS thread handle 0x7ff1b7f7b6c0, query id 667893392 crunkbunny.molgen.mpg.de 141.14.18.190 mxqprj cleaning up
---TRANSACTION 3408657398, not started
MySQL thread id 10149218, OS thread handle 0x7ff1b7def6c0, query id 667893468 crunchyfrog.molgen.mpg.de 141.14.19.28 mxqprj cleaning up
---TRANSACTION 3408657390, not started
MySQL thread id 10149216, OS thread handle 0x7ff2290e76c0, query id 667893440 cassowary.molgen.mpg.de 141.14.19.139 mxqprj cleaning up
---TRANSACTION 3408657446, not started
MySQL thread id 10149213, OS thread handle 0x7ff1b7c216c0, query id 667893639 boxjellyfish.molgen.mpg.de 141.14.19.138 mxqprj cleaning up
---TRANSACTION 3408657433, not started
MySQL thread id 10149211, OS thread handle 0x7ff1b7e316c0, query id 667893592 bluetonguelizard.molgen.mpg.de 141.14.19.137 mxqprj cleaning up
---TRANSACTION 3408657466, not started
MySQL thread id 10149208, OS thread handle 0x7ff2290636c0, query id 667893706 blueringoctopus.molgen.mpg.de 141.14.17.173 mxqprj cleaning up
---TRANSACTION 3408657439, not started
MySQL thread id 10149206, OS thread handle 0x7ff1b7b5b6c0, query id 667893613 bilby.molgen.mpg.de 141.14.19.3 mxqprj cleaning up
---TRANSACTION 3408657437, not started
MySQL thread id 10149205, OS thread handle 0x7ff1b7ce76c0, query id 667893606 barramundi.molgen.mpg.de 141.14.19.117 mxqprj cleaning up
---TRANSACTION 3408657419, not started
MySQL thread id 10149202, OS thread handle 0x7ff2241f16c0, query id 667893543 bandicoot.molgen.mpg.de 141.14.19.116 mxqprj cleaning up
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log 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)
I/O thread 9 state: waiting for i/o request (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
 ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
13411875230 OS file reads, 54616899 OS file writes, 31282641 OS fsyncs
745.39 reads/s, 34957 avg bytes/read, 0.73 writes/s, 0.64 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 1821, seg size 1823, 1901675 merges
merged operations:
 insert 2319363, delete mark 398737, delete 16079
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 276671, node heap has 228 buffer(s)
1916.37 hash searches/s, 128.90 non-hash searches/s
---
LOG
---
Log sequence number 572304990096
Log flushed up to   572304990096
Pages flushed up to 572304990096
Last checkpoint at  572304990096
0 pending log writes, 0 pending chkp writes
21452192 log i/o's done, 0.18 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 137363456; in additional pool allocated 0
Dictionary memory allocated 93971
Buffer pool size   8191
Free buffers       1024
Database pages     6939
Old database pages 2541
Modified db pages  0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 14655440777, not young 156453235868
883.56 youngs/s, 8881.65 non-youngs/s
Pages read 26359873260, created 630700, written 40859224
1590.40 reads/s, 0.00 creates/s, 0.36 writes/s
Buffer pool hit rate 930 / 1000, young-making rate 39 / 1000 not 396 / 1000
Pages read ahead 878.65/s, evicted without access 0.73/s, Random read ahead 0.00/s
LRU len: 6939, unzip_LRU len: 0
I/O sum[39951]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Main thread process no. 15069, id 140678016267968, state: sleeping
Number of rows inserted 2166260, updated 22505560, deleted 0, read 1856520730556
0.00 inserts/s, 0.09 updates/s, 0.00 deletes/s, 109601.85 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

@donald
Copy link
Contributor Author

donald commented Aug 26, 2024 •
edited

Transaction 1 from dugong (UPDATE mxq_group SET ...) is the trigger after the job has finished. Transaction 2 from likearollingstone (INSERT INTO j(job_id) SELECT mxq_job.job_id FROM mxq_job,mxq_group WHERE mxq_job.group_id = mxq_group.group_id AND user_uid = ? AND job_status IN (0,100,150,200)) is from myqkill -A when building the temporary table with jobs to be cancelled. Looks like the temporary table doesn't really resolve the conflict with the triggers.

@donald
Copy link
Contributor Author

donald commented Aug 26, 2024 •
edited

mx__mysql_stmt_execute should return EAGAIN for ER_LOCK_DEADLOCK so that mx_mysql_do_statement_retry_on_fail would retry the statement. But we should still try to avoid the deadlock.

Call chain:

static int job_has_finished(struct mxq_server *server, struct mxq_group *group, struct mxq_job_list *jlist)
{
    ...
    mxq_set_job_status_exited(server->mysql, job);
    ...

int mxq_set_job_status_exited(struct mx_mysql *mysql, struct mxq_job *job)
{
    ...
    res = mx_mysql_do_statement_noresult_retry_on_fail(mysql, query, &param);
    if (res < 0) {
        mx_log_err("mx_mysql_do_statement(): %s", mx_mysql_error());    # Deadlock found when trying to get lock; try restarting transaction
        return res;
    }

    job->job_status = newstatus;
    ...

#define mx_mysql_do_statement_noresult_retry_on_fail(m
, q, p) \
        mx_mysql_do_statement_retry_on_fail(m, q, p, NULL, NULL, NULL, 0)

int mx_mysql_do_statement_retry_on_fail(struct mx_mysql *mysql, char *query, struct mx_mysql_bind *param, struct mx_mysql_bind *result, void *from, void **to, size_t size)
{
    int res;

    while (1) {
        res = mx_mysql_do_statement_no_bind_cleanup(mysql, query, param, result, from, to, size);

        if (res >= 0)
            break;

        mx_mysql_assert_usage_ok(res);

        mx_log_warning("mx_mysql_do_statement() failed: %s", strerror(-res));

        if (res != -EAGAIN)
            break;

        mx_mysql_ping_forever(mysql);
    }
    mx_mysql_bind_cleanup(param);
    mx_mysql_bind_cleanup(result);

    return res;
}

static int mx_mysql_do_statement_no_bind_cleanup(struct mx_mysql *mysql, char *query, struct mx_mysql_bind *param, struct mx_mysql_bind *result, void *from, void **to, size_t size)
{
    return _mx_mysql_do_statement(mysql, query, param, result, from, to, size, 0);
}

static int _mx_mysql_do_statement(struct mx_mysql *mysql, char *query, struct mx_mysql_bind *param, struct mx_mysql_bind *result, void *from, void **to, size_t size, char cleanup)
{
    ...
    res = mx_mysql_statement_execute(stmt, &num_rows);
    if (res < 0) {
        if (cleanup)
            mx_mysql_statement_close(&stmt);
        else
            mx_mysql_statement_close_no_bind_cleanup(&stmt);
        return res;
    }

int mx_mysql_statement_execute(struct mx_mysql_stmt *stmt, unsigned long long *count)
{
    ...
    res = mx__mysql_stmt_execute(stmt);
    if (res < 0) {
        mx_log_debug("ERROR: mx__mysql_stmt_execute: %s", strerror(-res));
        return res;
    }


static int mx__mysql_stmt_execute(struct mx_mysql_stmt *stmt)
{
    ...
    res = mysql_stmt_execute(stmt->stmt);
    if (res == 0)
        return 0;

    mx_mysql_save_error(mysql_stmt_error(stmt->stmt));

    switch (mysql_stmt_errno(stmt->stmt)) {
        case CR_COMMANDS_OUT_OF_SYNC:
            return -EPROTO;

        case CR_OUT_OF_MEMORY:
            return -ENOMEM;

        case CR_SERVER_GONE_ERROR:
        case CR_SERVER_LOST:
            return -EAGAIN;

        case CR_UNKNOWN_ERROR:
            return -EIO;
    }
    return -EBADE;
}

This was referenced Aug 26, 2024
Closed
Merged
Sign in to join this conversation on GitHub.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Next mariux64/mxq
1 participant
@donald