Description:
Runing a lot of simple insert sqls,and then MYSQL is hanging。
Description:
--------------
ROW OPERATIONS
--------------
24 queries inside InnoDB, 58 queries in queue
1 read views open inside InnoDB
Process ID=126551, Main thread ID=139833817495296 , state=checking free log space
Number of rows inserted 1575843000, updated 501103163, deleted 116790809, read 1138692422190
14.83 inserts/s, 0.00 updates/s, 0.00 deletes/s, 14.83 reads/s
Number of system rows inserted 28800147, updated 44950661, deleted 28797213, read 230297788
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 4.67 reads/s
innodb_thread_concurrency was set by 24.
and I tried to runing such sql: select * from sys.innodb_lock_waits
it did not respond.
show engine innodb status\G
---TRANSACTION 966692238, ACTIVE 4180 sec inserting, thread declared inside InnoDB 5000
mysql tables in use 1, locked 1
1 lock struct(s), heap size 1136, 0 row lock(s)
MySQL thread id 13481570, OS thread handle 139831199725312, query id 2267557526 10.35.86.154 datayes update
INSERT INTO `bond` (`ID`,`BOND_ID`,`SEC_FULL_NAME`,`PARTY_ID`,`ISSUER`,`ISSUER_EQU_ID`,`TOTAL_SIZE`,`COUPON_TYPE_CD`,`CPN_FREQ_CD`,`PAYMENT_CD`,`COUPON`,`PAR`,`CURRENCY_CD`,`HYBRID_CD`,`PUBLISH_DATE`,`LIST_DATE`,`DELIST_DATE`,`ACT_MATURITY_DATE`,`FIRST_ACCR_DATE`,`MATURITY_DATE`,`MATURITY`,`FIRST_REDEMP_DATE`,`MIN_COUPON`,`FRN_REF_RATE_CD`,`FRN_CURR_BMK_RATE`,`FRN_MARGIN`,`PRIV_PLACEM_FLAG`,`ISSUE_INV_NUM`,`PRIV_INV_NUM`,`ABS_ISSUER_ID`,`ABS_ISSUER`,`ABS_LEVEL_CD`,`ABS_LEVEL_RATIO`,`ABS_COUPON_CAP`,`QA_ACTIVE_FLG`,`CREATE_TIME`,`UPDATE_TIME`,`TMSTAMP`,`BOND_FORM_CD`,`CPN_MEMO`,`COUPON_BASE_CD`
---TRANSACTION 966692237, ACTIVE 4180 sec inserting, thread declared inside InnoDB 5000
mysql tables in use 1, locked 1
1 lock struct(s), heap size 1136, 0 row lock(s)
MySQL thread id 13481567, OS thread handle 139827202356992, query id 2267557519 10.35.86.154 datayes update
INSERT INTO `fund_anno_security` (`ANNO_SECURITY_ID`,`ANNO_ID`,`TICKER_SYMBOL`,`SECURITY_ID`,`FUND_ID`,`SEC_SHORT_NAME`,`PARTY_ID`,`PARTY_SHORT_NAME`,`QA_ACTIVE_FLG`,`CREATE_TIME`,`UPDATE_TIME`,`TMSTAMP`) VALUES ('8870743', '6563af069a723736cbcb3723', '019667', '10027928', '15927', 'XXXX-C', '26932', 'XXXX', 1, '2023-11-27 04:48:06.787', '2023-11-27 04:48:06.787', '190132001040') ON DUPLICATE KEY UPDATE `ANNO_SECURITY_ID` = '8870743',`ANNO_ID` = '6563af069a723736cbcb3723',`TICKER_SYMBOL` = '019667',`SECURITY_ID` = '10027928',`FUND_ID` = '15927',`SE
---TRANSACTION 966692236, ACTIVE 4180 sec inserting, thread declared inside InnoDB 5000
mysql tables in use 1, locked 1
1 lock struct(s), heap size 1136, 0 row lock(s)
MySQL thread id 13481568, OS thread handle 139830527129344, query id 2267557514 10.35.86.154 datayes update
INSERT INTO `vnews_nondupbd_flash` (`NEWS_ID`,`UPDATE_TIME`,`NEWS_ORIGIN_SOURCE`,`NEWS_AUTHOR`,`NEWS_URL`,`NEWS_TITLE`,`NEWS_PUBLISH_SITE`,`NEWS_PUBLISH_TIME`,`EFFECTIVE_TIME`) VALUES ('157364031', '2023-11-27 04:11:32', null, null, 'https://flash.jin10.com/detail/20231127040758564800';, 'xxxx：xxx', 'xx', '2023-11-27 04:07:58', '2023-11-27 04:11:25') ON DUPLICATE KEY UPDATE `NEWS_ID` = '157364031',`UPDATE_TIME` = '2023-11-27 04:11:32',`NEWS_ORIGIN_SOURCE` = null,`NEWS_AUTHOR` = null,`NEWS_URL` = 'https://flash.jin10.com/d
---TRANSACTION 966692222, ACTIVE 4907 sec updating or deleting, thread declared inside InnoDB 1233
mysql tables in use 1, locked 1
2426 lock struct(s), heap size 286928, 1 row lock(s)
MySQL thread id 13481617, OS thread handle 139831231411968, query id 2267555754 10.35.86.53 fundwrite updating
UPDATE md_security
SET fund_id = 13407
, SEC_SHORT_NAME = 'XXXX'
, SEC_FULL_NAME = 'XXXXX'
, LIST_DATE = '2013-05-13 00:00:00'
, update_time = '2023-11-26 04:23:46'
, tmstamp = 14462985698
, source = 'XXXX'
, DELIST_DATE = '2021-07-19 00:00:00'
, TICKER_SYMBOL = 'ZYYX13407'
, DYID = 'ZYYX13407.CNFP'
, CREATE_TIME = '2013-05-02 16:44:47'
WHERE ( ( fund_id = 13407 ) ) AND ( ( source = 'XXX' ) )
...
all of the 24 threads are simple inserts.
here is the callstack information about those threads:
Thread 332 (Thread 0x7f2cd56f7700 (LWP 88884)):
#0 0x00007f321981be9d in nanosleep () from /lib64/libpthread.so.0
#1 0x00000000021e376c in log_free_check_wait(log_t&) ()
#2 0x0000000002283165 in row_ins_clust_index_entry(dict_index_t*, dtuple_t*, que_thr_t*, bool) ()
#3 0x0000000002283e51 in row_ins_step(que_thr_t*) ()
#4 0x0000000002296d14 in row_insert_for_mysql_using_ins_graph(unsigned char const*, row_prebuilt_t*) ()
#5 0x00000000021627b7 in ha_innobase::write_row(unsigned char*) ()
#6 0x00000000011618b8 in handler::ha_write_row(unsigned char*) ()
#7 0x0000000001379b35 in write_record(THD*, TABLE*, COPY_INFO*, COPY_INFO*) ()
#8 0x000000000137b059 in Sql_cmd_insert_values::execute_inner(THD*) ()
#9 0x0000000000f85098 in Sql_cmd_dml::execute(THD*) ()
#10 0x0000000000f279b8 in mysql_execute_command(THD*, bool) ()
#11 0x0000000000f2c1b8 in dispatch_sql_command(THD*, Parser_state*) ()
#12 0x0000000000f2dd01 in dispatch_command(THD*, COM_DATA const*, enum_server_command) ()
#13 0x0000000000f2f324 in do_command(THD*) ()
#14 0x0000000001052f88 in handle_connection ()
#15 0x00000000025aed2c in pfs_spawn_thread ()
#16 0x00007f3219814ea5 in start_thread () from /lib64/libpthread.so.0
#17 0x00007f32178f996d in clone () from /lib64/libc.so.6
Thread 175 (Thread 0x7f2cb76ff700 (LWP 153619)):
#0 0x00007f321981be9d in nanosleep () from /lib64/libpthread.so.0
#1 0x00000000021e376c in log_free_check_wait(log_t&) ()
#2 0x0000000002283165 in row_ins_clust_index_entry(dict_index_t*, dtuple_t*, que_thr_t*, bool) ()
#3 0x0000000002283e51 in row_ins_step(que_thr_t*) ()
#4 0x0000000002296d14 in row_insert_for_mysql_using_ins_graph(unsigned char const*, row_prebuilt_t*) ()
#5 0x00000000021627b7 in ha_innobase::write_row(unsigned char*) ()
#6 0x00000000011618b8 in handler::ha_write_row(unsigned char*) ()
#7 0x0000000001379b35 in write_record(THD*, TABLE*, COPY_INFO*, COPY_INFO*) ()
#8 0x000000000137b059 in Sql_cmd_insert_values::execute_inner(THD*) ()
#9 0x0000000000f85098 in Sql_cmd_dml::execute(THD*) ()
#10 0x0000000000f279b8 in mysql_execute_command(THD*, bool) ()
#11 0x0000000000f2c1b8 in dispatch_sql_command(THD*, Parser_state*) ()
#12 0x0000000000f2dd01 in dispatch_command(THD*, COM_DATA const*, enum_server_command) ()
#13 0x0000000000f2f324 in do_command(THD*) ()
#14 0x0000000001052f88 in handle_connection ()
#15 0x00000000025aed2c in pfs_spawn_thread ()
#16 0x00007f3219814ea5 in start_thread () from /lib64/libpthread.so.0
#17 0x00007f32178f996d in clone () from /lib64/libc.so.6
....
and log sequence number:
---
LOG
---
Log sequence number 3885613322062
Log buffer assigned up to 3885613322062
Log buffer completed up to 3885613322062
Log written up to 3885613322062
Log flushed up to 3885613322062
Added dirty pages up to 3885613322062
Pages flushed up to 3881772289742
Last checkpoint at 3881772289742
1122855950 log i/o's done, 0.00 log i/o's/second
innodb_log_file_size = 2G、innodb_log_files_in_group = 2
How to repeat:
It happens every almost two months.
Description: Runing a lot of simple insert sqls,and then MYSQL is hanging。 Description: -------------- ROW OPERATIONS -------------- 24 queries inside InnoDB, 58 queries in queue 1 read views open inside InnoDB Process ID=126551, Main thread ID=139833817495296 , state=checking free log space Number of rows inserted 1575843000, updated 501103163, deleted 116790809, read 1138692422190 14.83 inserts/s, 0.00 updates/s, 0.00 deletes/s, 14.83 reads/s Number of system rows inserted 28800147, updated 44950661, deleted 28797213, read 230297788 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 4.67 reads/s innodb_thread_concurrency was set by 24. and I tried to runing such sql: select * from sys.innodb_lock_waits it did not respond. show engine innodb status\G ---TRANSACTION 966692238, ACTIVE 4180 sec inserting, thread declared inside InnoDB 5000 mysql tables in use 1, locked 1 1 lock struct(s), heap size 1136, 0 row lock(s) MySQL thread id 13481570, OS thread handle 139831199725312, query id 2267557526 10.35.86.154 datayes update INSERT INTO `bond` (`ID`,`BOND_ID`,`SEC_FULL_NAME`,`PARTY_ID`,`ISSUER`,`ISSUER_EQU_ID`,`TOTAL_SIZE`,`COUPON_TYPE_CD`,`CPN_FREQ_CD`,`PAYMENT_CD`,`COUPON`,`PAR`,`CURRENCY_CD`,`HYBRID_CD`,`PUBLISH_DATE`,`LIST_DATE`,`DELIST_DATE`,`ACT_MATURITY_DATE`,`FIRST_ACCR_DATE`,`MATURITY_DATE`,`MATURITY`,`FIRST_REDEMP_DATE`,`MIN_COUPON`,`FRN_REF_RATE_CD`,`FRN_CURR_BMK_RATE`,`FRN_MARGIN`,`PRIV_PLACEM_FLAG`,`ISSUE_INV_NUM`,`PRIV_INV_NUM`,`ABS_ISSUER_ID`,`ABS_ISSUER`,`ABS_LEVEL_CD`,`ABS_LEVEL_RATIO`,`ABS_COUPON_CAP`,`QA_ACTIVE_FLG`,`CREATE_TIME`,`UPDATE_TIME`,`TMSTAMP`,`BOND_FORM_CD`,`CPN_MEMO`,`COUPON_BASE_CD` ---TRANSACTION 966692237, ACTIVE 4180 sec inserting, thread declared inside InnoDB 5000 mysql tables in use 1, locked 1 1 lock struct(s), heap size 1136, 0 row lock(s) MySQL thread id 13481567, OS thread handle 139827202356992, query id 2267557519 10.35.86.154 datayes update INSERT INTO `fund_anno_security` (`ANNO_SECURITY_ID`,`ANNO_ID`,`TICKER_SYMBOL`,`SECURITY_ID`,`FUND_ID`,`SEC_SHORT_NAME`,`PARTY_ID`,`PARTY_SHORT_NAME`,`QA_ACTIVE_FLG`,`CREATE_TIME`,`UPDATE_TIME`,`TMSTAMP`) VALUES ('8870743', '6563af069a723736cbcb3723', '019667', '10027928', '15927', 'XXXX-C', '26932', 'XXXX', 1, '2023-11-27 04:48:06.787', '2023-11-27 04:48:06.787', '190132001040') ON DUPLICATE KEY UPDATE `ANNO_SECURITY_ID` = '8870743',`ANNO_ID` = '6563af069a723736cbcb3723',`TICKER_SYMBOL` = '019667',`SECURITY_ID` = '10027928',`FUND_ID` = '15927',`SE ---TRANSACTION 966692236, ACTIVE 4180 sec inserting, thread declared inside InnoDB 5000 mysql tables in use 1, locked 1 1 lock struct(s), heap size 1136, 0 row lock(s) MySQL thread id 13481568, OS thread handle 139830527129344, query id 2267557514 10.35.86.154 datayes update INSERT INTO `vnews_nondupbd_flash` (`NEWS_ID`,`UPDATE_TIME`,`NEWS_ORIGIN_SOURCE`,`NEWS_AUTHOR`,`NEWS_URL`,`NEWS_TITLE`,`NEWS_PUBLISH_SITE`,`NEWS_PUBLISH_TIME`,`EFFECTIVE_TIME`) VALUES ('157364031', '2023-11-27 04:11:32', null, null, 'https://flash.jin10.com/detail/20231127040758564800';, 'xxxx：xxx', 'xx', '2023-11-27 04:07:58', '2023-11-27 04:11:25') ON DUPLICATE KEY UPDATE `NEWS_ID` = '157364031',`UPDATE_TIME` = '2023-11-27 04:11:32',`NEWS_ORIGIN_SOURCE` = null,`NEWS_AUTHOR` = null,`NEWS_URL` = 'https://flash.jin10.com/d ---TRANSACTION 966692222, ACTIVE 4907 sec updating or deleting, thread declared inside InnoDB 1233 mysql tables in use 1, locked 1 2426 lock struct(s), heap size 286928, 1 row lock(s) MySQL thread id 13481617, OS thread handle 139831231411968, query id 2267555754 10.35.86.53 fundwrite updating UPDATE md_security SET fund_id = 13407 , SEC_SHORT_NAME = 'XXXX' , SEC_FULL_NAME = 'XXXXX' , LIST_DATE = '2013-05-13 00:00:00' , update_time = '2023-11-26 04:23:46' , tmstamp = 14462985698 , source = 'XXXX' , DELIST_DATE = '2021-07-19 00:00:00' , TICKER_SYMBOL = 'ZYYX13407' , DYID = 'ZYYX13407.CNFP' , CREATE_TIME = '2013-05-02 16:44:47' WHERE ( ( fund_id = 13407 ) ) AND ( ( source = 'XXX' ) ) ... all of the 24 threads are simple inserts. here is the callstack information about those threads: Thread 332 (Thread 0x7f2cd56f7700 (LWP 88884)): #0 0x00007f321981be9d in nanosleep () from /lib64/libpthread.so.0 #1 0x00000000021e376c in log_free_check_wait(log_t&) () #2 0x0000000002283165 in row_ins_clust_index_entry(dict_index_t*, dtuple_t*, que_thr_t*, bool) () #3 0x0000000002283e51 in row_ins_step(que_thr_t*) () #4 0x0000000002296d14 in row_insert_for_mysql_using_ins_graph(unsigned char const*, row_prebuilt_t*) () #5 0x00000000021627b7 in ha_innobase::write_row(unsigned char*) () #6 0x00000000011618b8 in handler::ha_write_row(unsigned char*) () #7 0x0000000001379b35 in write_record(THD*, TABLE*, COPY_INFO*, COPY_INFO*) () #8 0x000000000137b059 in Sql_cmd_insert_values::execute_inner(THD*) () #9 0x0000000000f85098 in Sql_cmd_dml::execute(THD*) () #10 0x0000000000f279b8 in mysql_execute_command(THD*, bool) () #11 0x0000000000f2c1b8 in dispatch_sql_command(THD*, Parser_state*) () #12 0x0000000000f2dd01 in dispatch_command(THD*, COM_DATA const*, enum_server_command) () #13 0x0000000000f2f324 in do_command(THD*) () #14 0x0000000001052f88 in handle_connection () #15 0x00000000025aed2c in pfs_spawn_thread () #16 0x00007f3219814ea5 in start_thread () from /lib64/libpthread.so.0 #17 0x00007f32178f996d in clone () from /lib64/libc.so.6 Thread 175 (Thread 0x7f2cb76ff700 (LWP 153619)): #0 0x00007f321981be9d in nanosleep () from /lib64/libpthread.so.0 #1 0x00000000021e376c in log_free_check_wait(log_t&) () #2 0x0000000002283165 in row_ins_clust_index_entry(dict_index_t*, dtuple_t*, que_thr_t*, bool) () #3 0x0000000002283e51 in row_ins_step(que_thr_t*) () #4 0x0000000002296d14 in row_insert_for_mysql_using_ins_graph(unsigned char const*, row_prebuilt_t*) () #5 0x00000000021627b7 in ha_innobase::write_row(unsigned char*) () #6 0x00000000011618b8 in handler::ha_write_row(unsigned char*) () #7 0x0000000001379b35 in write_record(THD*, TABLE*, COPY_INFO*, COPY_INFO*) () #8 0x000000000137b059 in Sql_cmd_insert_values::execute_inner(THD*) () #9 0x0000000000f85098 in Sql_cmd_dml::execute(THD*) () #10 0x0000000000f279b8 in mysql_execute_command(THD*, bool) () #11 0x0000000000f2c1b8 in dispatch_sql_command(THD*, Parser_state*) () #12 0x0000000000f2dd01 in dispatch_command(THD*, COM_DATA const*, enum_server_command) () #13 0x0000000000f2f324 in do_command(THD*) () #14 0x0000000001052f88 in handle_connection () #15 0x00000000025aed2c in pfs_spawn_thread () #16 0x00007f3219814ea5 in start_thread () from /lib64/libpthread.so.0 #17 0x00007f32178f996d in clone () from /lib64/libc.so.6 .... and log sequence number: --- LOG --- Log sequence number 3885613322062 Log buffer assigned up to 3885613322062 Log buffer completed up to 3885613322062 Log written up to 3885613322062 Log flushed up to 3885613322062 Added dirty pages up to 3885613322062 Pages flushed up to 3881772289742 Last checkpoint at 3881772289742 1122855950 log i/o's done, 0.00 log i/o's/second innodb_log_file_size = 2G、innodb_log_files_in_group = 2 How to repeat: It happens every almost two months.