Skip to content

M
MariaDB
Commit 9e5df967 authored by Marko Mäkelä's avatar Marko Mäkelä
Browse files
Options

Reduce the amount of time(NULL) calls for lock processing 

lock_t::requested_time: Document what the field is used for.

lock_t::wait_time: Document that the field is only used for
diagnostics and may be garbage if the system time is being adjusted.

srv_slot_t::suspend_time: Document that this is duplicating
trx_lock_t::wait_started.

lock_table_print(), lock_rec_print(): Declare in static scope.
Add a parameter for the current time.

lock_deadlock_check_and_resolve(), lock_deadlock_lock_print(),
lock_deadlock_joining_trx_print():
Add a parameter for the current time.
parent 2b5bc761
Hide whitespace changes
Inline Side-by-side
Showing with 284 additions and 294 deletions
storage/innobase/include/lock0lock.h
View file @ 9e5df967
...@@ -615,22 +615,6 @@ lock_report_trx_id_insanity( ...@@ -615,22 +615,6 @@ lock_report_trx_id_insanity(
trx_id_t max_trx_id) /*!< in: trx_sys_get_max_trx_id() */ trx_id_t max_trx_id) /*!< in: trx_sys_get_max_trx_id() */
MY_ATTRIBUTE((nonnull)); MY_ATTRIBUTE((nonnull));
/*********************************************************************//** /*********************************************************************//**
Prints info of a table lock. */
UNIV_INTERN
void
lock_table_print(
/*=============*/
FILE* file, /*!< in: file where to print */
const lock_t* lock); /*!< in: table type lock */
/*********************************************************************//**
Prints info of a record lock. */
UNIV_INTERN
void
lock_rec_print(
/*===========*/
FILE* file, /*!< in: file where to print */
const lock_t* lock); /*!< in: record type lock */
/*********************************************************************//**
Prints info of locks for all transactions. Prints info of locks for all transactions.
@return FALSE if not able to obtain lock mutex and exits without @return FALSE if not able to obtain lock mutex and exits without
printing info */ printing info */
......
storage/innobase/include/lock0priv.h
View file @ 9e5df967
...@@ -74,10 +74,14 @@ struct lock_t { ...@@ -74,10 +74,14 @@ struct lock_t {
lock */ lock */
dict_index_t* index; /*!< index for a record lock */ dict_index_t* index; /*!< index for a record lock */
/* Statistics for how long lock has been held and time /** time(NULL) of the lock request creation.
how long this lock had to be waited before it was granted */ Used for computing wait_time and diagnostics only.
time_t requested_time; /*!< Lock request time */ Note: bogus durations may be reported
ulint wait_time; /*!< Time waited this lock or 0 */ when the system time is adjusted! */
time_t requested_time;
/** Cumulated wait time in seconds.
Note: may be bogus when the system time is adjusted! */
ulint wait_time;
union { union {
lock_table_t tab_lock;/*!< table lock */ lock_table_t tab_lock;/*!< table lock */
......
storage/innobase/include/srv0srv.h
View file @ 9e5df967
...@@ -1078,10 +1078,14 @@ struct srv_slot_t{ ...@@ -1078,10 +1078,14 @@ struct srv_slot_t{
ibool suspended; /*!< TRUE if the thread is ibool suspended; /*!< TRUE if the thread is
waiting for the event of this waiting for the event of this
slot */ slot */
ib_time_t suspend_time; /*!< time when the thread was /** time(NULL) when the thread was suspended.
suspended. Initialized by FIXME: Use my_interval_timer() or similar, to avoid bogus
lock_wait_table_reserve_slot() timeouts in lock_wait_check_and_cancel() or lock_wait_suspend_thread()
for lock wait */ when the system time is adjusted to the past!
FIXME: This is duplicating trx_lock_t::wait_started,
which is being used for diagnostic purposes only. */
time_t suspend_time;
ulong wait_timeout; /*!< wait time that if exceeded ulong wait_timeout; /*!< wait time that if exceeded
the thread will be timed out. the thread will be timed out.
Initialized by Initialized by
......
storage/innobase/include/trx0i_s.h
View file @ 9e5df967
/***************************************************************************** /*****************************************************************************
Copyright (c) 2007, 2011, Oracle and/or its affiliates. All Rights Reserved. Copyright (c) 2007, 2011, Oracle and/or its affiliates. All Rights Reserved.
Copyright (c) 2019, MariaDB Corporation.
This program is free software; you can redistribute it and/or modify it under This program is free software; you can redistribute it and/or modify it under
the terms of the GNU General Public License as published by the Free Software the terms of the GNU General Public License as published by the Free Software
...@@ -133,7 +134,7 @@ struct i_s_trx_row_t { ...@@ -133,7 +134,7 @@ struct i_s_trx_row_t {
/*!< pointer to a row /*!< pointer to a row
in innodb_locks if trx in innodb_locks if trx
is waiting, or NULL */ is waiting, or NULL */
ib_time_t trx_wait_started; /*!< trx_t::wait_started */ time_t trx_wait_started; /*!< trx->lock.wait_started */
ullint trx_weight; /*!< TRX_WEIGHT() */ ullint trx_weight; /*!< TRX_WEIGHT() */
ulint trx_mysql_thread_id; /*!< thd_get_thread_id() */ ulint trx_mysql_thread_id; /*!< thd_get_thread_id() */
const char* trx_query; /*!< MySQL statement being const char* trx_query; /*!< MySQL statement being
......
storage/innobase/lock/lock0lock.cc
View file @ 9e5df967
...@@ -383,6 +383,20 @@ struct lock_stack_t { ...@@ -383,6 +383,20 @@ struct lock_stack_t {
ulint heap_no; /*!< heap number if rec lock */ ulint heap_no; /*!< heap number if rec lock */
}; };
/** Pretty-print a table lock.
@param[in,out] file output stream
@param[in] lock table lock
@param[in] now current time */
static void lock_table_print(FILE* file, const lock_t* lock, time_t now);
/** Pretty-print a record lock.
@param[in,out] file output stream
@param[in] lock record lock
@param[in] now current time
@param[in,out] mtr mini-transaction */
static void lock_rec_print(FILE* file, const lock_t* lock, time_t now,
mtr_t* mtr = NULL);
/*********************************************************************//** /*********************************************************************//**
Checks if a waiting record lock request still has to wait in a queue. Checks if a waiting record lock request still has to wait in a queue.
@return lock that is causing the wait */ @return lock that is causing the wait */
...@@ -466,20 +480,18 @@ UNIV_INTERN ibool lock_deadlock_found = FALSE; ...@@ -466,20 +480,18 @@ UNIV_INTERN ibool lock_deadlock_found = FALSE;
/** Only created if !srv_read_only_mode */ /** Only created if !srv_read_only_mode */
static FILE* lock_latest_err_file; static FILE* lock_latest_err_file;
/********************************************************************//** /** Check if a joining lock request results in a deadlock. If a deadlock is
Checks if a joining lock request results in a deadlock. If a deadlock is
found this function will resolve the dadlock by choosing a victim transaction found this function will resolve the dadlock by choosing a victim transaction
and rolling it back. It will attempt to resolve all deadlocks. The returned and rolling it back. It will attempt to resolve all deadlocks.
transaction id will be the joining transaction id or 0 if some other @param[in] trx joining transaction
transaction was chosen as a victim and rolled back or no deadlock found. @param[in] lock the requested lock
@param[in] now current time
@return id of transaction chosen as victim or 0 */ @return trx->id of the victim transaction
static @retval 0 if some other transaction was chosen as a victim and
trx_id_t rolled back, or no deadlock was found. */
lock_deadlock_check_and_resolve( static trx_id_t lock_deadlock_check_and_resolve(const trx_t* trx,
/*===========================*/ const lock_t* lock,
const lock_t* lock, /*!< in: lock the transaction is requesting */ time_t now);
const trx_t* trx); /*!< in: transaction */
/*********************************************************************//** /*********************************************************************//**
Gets the nth bit of a record lock. Gets the nth bit of a record lock.
...@@ -1135,12 +1147,11 @@ lock_rec_has_to_wait( ...@@ -1135,12 +1147,11 @@ lock_rec_has_to_wait(
thread, we need to look at trx ordering and lock types */ thread, we need to look at trx ordering and lock types */
if (wsrep_thd_is_BF(trx->mysql_thd, FALSE) && if (wsrep_thd_is_BF(trx->mysql_thd, FALSE) &&
wsrep_thd_is_BF(lock2->trx->mysql_thd, TRUE)) { wsrep_thd_is_BF(lock2->trx->mysql_thd, TRUE)) {
if (wsrep_debug) { if (wsrep_debug) {
fprintf(stderr, fprintf(stderr,
"BF-BF lock conflict, locking: %lu\n", "BF-BF lock conflict, locking: %lu\n",
for_locking); for_locking);
lock_rec_print(stderr, lock2); lock_rec_print(stderr, lock2, time(NULL));
} }
if (wsrep_trx_order_before(trx->mysql_thd, if (wsrep_trx_order_before(trx->mysql_thd,
...@@ -1159,7 +1170,8 @@ lock_rec_has_to_wait( ...@@ -1159,7 +1170,8 @@ lock_rec_has_to_wait(
"conflicts states: my %d locked %d\n", "conflicts states: my %d locked %d\n",
wsrep_thd_conflict_state(trx->mysql_thd, FALSE), wsrep_thd_conflict_state(trx->mysql_thd, FALSE),
wsrep_thd_conflict_state(lock2->trx->mysql_thd, FALSE) ); wsrep_thd_conflict_state(lock2->trx->mysql_thd, FALSE) );
lock_rec_print(stderr, lock2); lock_rec_print(stderr, lock2,
time(NULL));
if (for_locking) return FALSE; if (for_locking) return FALSE;
//abort(); //abort();
} }
...@@ -1786,10 +1798,12 @@ wsrep_kill_victim( ...@@ -1786,10 +1798,12 @@ wsrep_kill_victim(
fputs("*** WAITING FOR THIS LOCK TO BE GRANTED:\n", fputs("*** WAITING FOR THIS LOCK TO BE GRANTED:\n",
stderr); stderr);
time_t now = time(NULL);
if (lock_get_type(lock) == LOCK_REC) { if (lock_get_type(lock) == LOCK_REC) {
lock_rec_print(stderr, lock); lock_rec_print(stderr, lock, now);
} else { } else {
lock_table_print(stderr, lock); lock_table_print(stderr, lock, now);
} }
} }
...@@ -2032,16 +2046,20 @@ wsrep_print_wait_locks( ...@@ -2032,16 +2046,20 @@ wsrep_print_wait_locks(
{ {
if (wsrep_debug && c_lock->trx->lock.wait_lock != c_lock) { if (wsrep_debug && c_lock->trx->lock.wait_lock != c_lock) {
fprintf(stderr, "WSREP: c_lock != wait lock\n"); fprintf(stderr, "WSREP: c_lock != wait lock\n");
time_t now = time(NULL);
if (lock_get_type_low(c_lock) & LOCK_TABLE) { if (lock_get_type_low(c_lock) & LOCK_TABLE) {
lock_table_print(stderr, c_lock); lock_table_print(stderr, c_lock, now);
} else { } else {
lock_rec_print(stderr, c_lock); lock_rec_print(stderr, c_lock, now);
} }
if (lock_get_type_low(c_lock->trx->lock.wait_lock) & LOCK_TABLE) { if (lock_get_type_low(c_lock->trx->lock.wait_lock) & LOCK_TABLE) {
lock_table_print(stderr, c_lock->trx->lock.wait_lock); lock_table_print(stderr, c_lock->trx->lock.wait_lock,
now);
} else { } else {
lock_rec_print(stderr, c_lock->trx->lock.wait_lock); lock_rec_print(stderr, c_lock->trx->lock.wait_lock,
now);
} }
} }
} }
...@@ -2477,7 +2495,8 @@ lock_rec_enqueue_waiting( ...@@ -2477,7 +2495,8 @@ lock_rec_enqueue_waiting(
trx_mutex_exit(trx); trx_mutex_exit(trx);
victim_trx_id = lock_deadlock_check_and_resolve(lock, trx); const time_t now = time(NULL);
victim_trx_id = lock_deadlock_check_and_resolve(trx, lock, now);
trx_mutex_enter(trx); trx_mutex_enter(trx);
...@@ -2501,7 +2520,7 @@ lock_rec_enqueue_waiting( ...@@ -2501,7 +2520,7 @@ lock_rec_enqueue_waiting(
trx->lock.que_state = TRX_QUE_LOCK_WAIT; trx->lock.que_state = TRX_QUE_LOCK_WAIT;
trx->lock.was_chosen_as_deadlock_victim = FALSE; trx->lock.was_chosen_as_deadlock_victim = FALSE;
trx->lock.wait_started = ut_time(); trx->lock.wait_started = now;
ut_a(que_thr_stop(thr)); ut_a(que_thr_stop(thr));
...@@ -2642,7 +2661,8 @@ lock_rec_add_to_queue( ...@@ -2642,7 +2661,8 @@ lock_rec_add_to_queue(
"BF skipping wait: " "BF skipping wait: "
TRX_ID_FMT "\n", TRX_ID_FMT "\n",
trx->id); trx->id);
lock_rec_print(stderr, lock); lock_rec_print(stderr, lock,
time(NULL));
} }
} else } else
#endif #endif
...@@ -2958,13 +2978,14 @@ lock_rec_has_to_wait_in_queue( ...@@ -2958,13 +2978,14 @@ lock_rec_has_to_wait_in_queue(
if (wsrep_thd_is_BF(wait_lock->trx->mysql_thd, FALSE) && if (wsrep_thd_is_BF(wait_lock->trx->mysql_thd, FALSE) &&
wsrep_thd_is_BF(lock->trx->mysql_thd, TRUE)) { wsrep_thd_is_BF(lock->trx->mysql_thd, TRUE)) {
if (wsrep_debug) { if (wsrep_debug) {
time_t now = time(NULL);
fprintf(stderr, fprintf(stderr,
"BF-BF lock conflict " TRX_ID_FMT "BF-BF lock conflict " TRX_ID_FMT
" : " TRX_ID_FMT "\n", " : " TRX_ID_FMT "\n",
wait_lock->trx->id, wait_lock->trx->id,
lock->trx->id); lock->trx->id);
lock_rec_print(stderr, wait_lock); lock_rec_print(stderr, wait_lock, now);
lock_rec_print(stderr, lock); lock_rec_print(stderr, lock, now);
} }
/* don't wait for another BF lock */ /* don't wait for another BF lock */
continue; continue;
...@@ -4293,28 +4314,26 @@ lock_deadlock_trx_print( ...@@ -4293,28 +4314,26 @@ lock_deadlock_trx_print(
mutex_exit(&trx_sys->mutex); mutex_exit(&trx_sys->mutex);
} }
/*********************************************************************//** /** Print lock data to the deadlock file and possibly to stderr.
Print lock data to the deadlock file and possibly to stderr. */ @param[in] lock record or table lock
UNIV_INLINE @param[in] now current time */
void static void lock_deadlock_lock_print(const lock_t* lock, time_t now)
lock_deadlock_lock_print(
/*=====================*/
const lock_t* lock) /*!< in: record or table type lock */
{ {
ut_ad(lock_mutex_own()); ut_ad(lock_mutex_own());
ut_ad(!srv_read_only_mode); ut_ad(!srv_read_only_mode);
if (lock_get_type_low(lock) == LOCK_REC) { if (lock_get_type_low(lock) == LOCK_REC) {
lock_rec_print(lock_latest_err_file, lock); mtr_t mtr;
lock_rec_print(lock_latest_err_file, lock, now, &mtr);
if (srv_print_all_deadlocks) { if (srv_print_all_deadlocks) {
lock_rec_print(stderr, lock); lock_rec_print(stderr, lock, now, &mtr);
} }
} else { } else {
lock_table_print(lock_latest_err_file, lock); lock_table_print(lock_latest_err_file, lock, now);
if (srv_print_all_deadlocks) { if (srv_print_all_deadlocks) {
lock_table_print(stderr, lock); lock_table_print(stderr, lock, now);
} }
} }
} }
...@@ -4427,6 +4446,8 @@ lock_deadlock_notify( ...@@ -4427,6 +4446,8 @@ lock_deadlock_notify(
ut_ad(lock_mutex_own()); ut_ad(lock_mutex_own());
ut_ad(!srv_read_only_mode); ut_ad(!srv_read_only_mode);
const time_t now = time(NULL);
lock_deadlock_start_print(); lock_deadlock_start_print();
lock_deadlock_fputs("\n*** (1) TRANSACTION:\n"); lock_deadlock_fputs("\n*** (1) TRANSACTION:\n");
...@@ -4435,7 +4456,7 @@ lock_deadlock_notify( ...@@ -4435,7 +4456,7 @@ lock_deadlock_notify(
lock_deadlock_fputs("*** (1) WAITING FOR THIS LOCK TO BE GRANTED:\n"); lock_deadlock_fputs("*** (1) WAITING FOR THIS LOCK TO BE GRANTED:\n");
lock_deadlock_lock_print(ctx->wait_lock); lock_deadlock_lock_print(ctx->wait_lock, now);
lock_deadlock_fputs("*** (2) TRANSACTION:\n"); lock_deadlock_fputs("*** (2) TRANSACTION:\n");
...@@ -4443,7 +4464,7 @@ lock_deadlock_notify( ...@@ -4443,7 +4464,7 @@ lock_deadlock_notify(
lock_deadlock_fputs("*** (2) HOLDS THE LOCK(S):\n"); lock_deadlock_fputs("*** (2) HOLDS THE LOCK(S):\n");
lock_deadlock_lock_print(lock); lock_deadlock_lock_print(lock, now);
/* It is possible that the joining transaction was granted its /* It is possible that the joining transaction was granted its
lock when we rolled back some other waiting transaction. */ lock when we rolled back some other waiting transaction. */
...@@ -4452,7 +4473,7 @@ lock_deadlock_notify( ...@@ -4452,7 +4473,7 @@ lock_deadlock_notify(
lock_deadlock_fputs( lock_deadlock_fputs(
"*** (2) WAITING FOR THIS LOCK TO BE GRANTED:\n"); "*** (2) WAITING FOR THIS LOCK TO BE GRANTED:\n");
lock_deadlock_lock_print(ctx->start->lock.wait_lock); lock_deadlock_lock_print(ctx->start->lock.wait_lock, now);
} }
#ifdef UNIV_DEBUG #ifdef UNIV_DEBUG
...@@ -4700,14 +4721,12 @@ lock_deadlock_search( ...@@ -4700,14 +4721,12 @@ lock_deadlock_search(
return(0); return(0);
} }
/********************************************************************//** /** Print info about transaction that was rolled back.
Print info about transaction that was rolled back. */ @param[in] trx victim transaction
static @param[in] lock the requested lock
void @param[in] now current time */
lock_deadlock_joining_trx_print( static void lock_deadlock_joining_trx_print(const trx_t* trx,
/*============================*/ const lock_t* lock, time_t now)
const trx_t* trx, /*!< in: transaction rolled back */
const lock_t* lock) /*!< in: lock trx wants */
{ {
ut_ad(lock_mutex_own()); ut_ad(lock_mutex_own());
ut_ad(!srv_read_only_mode); ut_ad(!srv_read_only_mode);
...@@ -4727,7 +4746,7 @@ lock_deadlock_joining_trx_print( ...@@ -4727,7 +4746,7 @@ lock_deadlock_joining_trx_print(
lock_deadlock_fputs("*** WAITING FOR THIS LOCK TO BE GRANTED:\n"); lock_deadlock_fputs("*** WAITING FOR THIS LOCK TO BE GRANTED:\n");
lock_deadlock_lock_print(lock); lock_deadlock_lock_print(lock, now);
} }
/********************************************************************//** /********************************************************************//**
...@@ -4797,20 +4816,17 @@ lock_report_waiters_to_mysql( ...@@ -4797,20 +4816,17 @@ lock_report_waiters_to_mysql(
} }
/********************************************************************//** /** Check if a joining lock request results in a deadlock. If a deadlock is
Checks if a joining lock request results in a deadlock. If a deadlock is
found this function will resolve the dadlock by choosing a victim transaction found this function will resolve the dadlock by choosing a victim transaction
and rolling it back. It will attempt to resolve all deadlocks. The returned and rolling it back. It will attempt to resolve all deadlocks.
transaction id will be the joining transaction id or 0 if some other @param[in] trx joining transaction
transaction was chosen as a victim and rolled back or no deadlock found. @param[in] lock the requested lock
@param[in] now current time
@return id of transaction chosen as victim or 0 */ @return trx->id of the victim transaction
static @retval 0 if some other transaction was chosen as a victim and
trx_id_t rolled back, or no deadlock was found. */
lock_deadlock_check_and_resolve( static trx_id_t lock_deadlock_check_and_resolve(const trx_t* trx,
/*============================*/ const lock_t* lock, time_t now)
const lock_t* lock, /*!< in: lock the transaction is requesting */
const trx_t* trx) /*!< in: transaction */
{ {
trx_id_t victim_trx_id; trx_id_t victim_trx_id;
struct thd_wait_reports waitee_buf; struct thd_wait_reports waitee_buf;
...@@ -4862,17 +4878,12 @@ lock_deadlock_check_and_resolve( ...@@ -4862,17 +4878,12 @@ lock_deadlock_check_and_resolve(
ut_a(victim_trx_id == trx->id); ut_a(victim_trx_id == trx->id);
#ifdef WITH_WSREP #ifdef WITH_WSREP
if (!wsrep_thd_is_BF(ctx.start->mysql_thd, TRUE)) if (!wsrep_thd_is_BF(ctx.start->mysql_thd, TRUE)); else
{
#endif /* WITH_WSREP */ #endif /* WITH_WSREP */
if (!srv_read_only_mode) { if (!srv_read_only_mode) {
lock_deadlock_joining_trx_print(trx, lock); lock_deadlock_joining_trx_print(trx, lock,
} now);
#ifdef WITH_WSREP
} else {
/* BF processor */;
} }
#endif /* WITH_WSREP */
MONITOR_INC(MONITOR_DEADLOCK); MONITOR_INC(MONITOR_DEADLOCK);
...@@ -5218,7 +5229,9 @@ lock_table_enqueue_waiting( ...@@ -5218,7 +5229,9 @@ lock_table_enqueue_waiting(
trx_mutex_exit(trx); trx_mutex_exit(trx);
victim_trx_id = lock_deadlock_check_and_resolve(lock, trx); const time_t now = time(NULL);
victim_trx_id = lock_deadlock_check_and_resolve(trx, lock, now);
trx_mutex_enter(trx); trx_mutex_enter(trx);
...@@ -5240,7 +5253,7 @@ lock_table_enqueue_waiting( ...@@ -5240,7 +5253,7 @@ lock_table_enqueue_waiting(
trx->lock.que_state = TRX_QUE_LOCK_WAIT; trx->lock.que_state = TRX_QUE_LOCK_WAIT;
trx->lock.wait_started = ut_time(); trx->lock.wait_started = now;
trx->lock.was_chosen_as_deadlock_victim = FALSE; trx->lock.was_chosen_as_deadlock_victim = FALSE;
trx->n_table_lock_waits++; trx->n_table_lock_waits++;
...@@ -5984,14 +5997,11 @@ lock_remove_all_on_table( ...@@ -5984,14 +5997,11 @@ lock_remove_all_on_table(
/*===================== VALIDATION AND DEBUGGING ====================*/ /*===================== VALIDATION AND DEBUGGING ====================*/
/*********************************************************************//** /** Pretty-print a table lock.
Prints info of a table lock. */ @param[in,out] file output stream
UNIV_INTERN @param[in] lock table lock
void @param[in] now current time */
lock_table_print( static void lock_table_print(FILE* file, const lock_t* lock, time_t now)
/*=============*/
FILE* file, /*!< in: file where to print */
const lock_t* lock) /*!< in: table type lock */
{ {
ut_ad(lock_mutex_own()); ut_ad(lock_mutex_own());
ut_a(lock_get_type_low(lock) == LOCK_TABLE); ut_a(lock_get_type_low(lock) == LOCK_TABLE);
...@@ -6021,30 +6031,22 @@ lock_table_print( ...@@ -6021,30 +6031,22 @@ lock_table_print(
} }
fprintf(file, " lock hold time %lu wait time before grant %lu ", fprintf(file, " lock hold time %lu wait time before grant %lu ",
(ulint)difftime(ut_time(), lock->requested_time), (ulint)difftime(now, lock->requested_time),
lock->wait_time); lock->wait_time);
putc('\n', file); putc('\n', file);
} }
/*********************************************************************//** /** Pretty-print a record lock.
Prints info of a record lock. */ @param[in,out] file output stream
UNIV_INTERN @param[in] lock record lock
void @param[in] now current time
lock_rec_print( @param[in,out] mtr mini-transaction */
/*===========*/ static void lock_rec_print(FILE* file, const lock_t* lock, time_t now,
FILE* file, /*!< in: file where to print */ mtr_t* mtr)
const lock_t* lock) /*!< in: record type lock */
{ {
const buf_block_t* block;
ulint space; ulint space;
ulint page_no; ulint page_no;
ulint i;
mtr_t mtr;
mem_heap_t* heap = NULL;
ulint offsets_[REC_OFFS_NORMAL_SIZE];
ulint* offsets = offsets_;
rec_offs_init(offsets_);
ut_ad(lock_mutex_own()); ut_ad(lock_mutex_own());
ut_a(lock_get_type_low(lock) == LOCK_REC); ut_a(lock_get_type_low(lock) == LOCK_REC);
...@@ -6089,17 +6091,25 @@ lock_rec_print( ...@@ -6089,17 +6091,25 @@ lock_rec_print(
fputs(" waiting", file); fputs(" waiting", file);
} }
mtr_start(&mtr);
fprintf(file, " lock hold time %lu wait time before grant %lu ", fprintf(file, " lock hold time %lu wait time before grant %lu ",
(ulint)difftime(ut_time(), lock->requested_time), (ulint)difftime(now, lock->requested_time),
lock->wait_time); lock->wait_time);
putc('\n', file); putc('\n', file);
block = buf_page_try_get(space, page_no, &mtr); if (!mtr) {
return;
}
mem_heap_t* heap = NULL;
ulint offsets_[REC_OFFS_NORMAL_SIZE];
ulint* offsets = offsets_;
rec_offs_init(offsets_);
mtr_start(mtr);
const buf_block_t* block = buf_page_try_get(space, page_no, mtr);
for (i = 0; i < lock_rec_get_n_bits(lock); ++i) { for (ulint i = 0; i < lock_rec_get_n_bits(lock); ++i) {
if (!lock_rec_get_nth_bit(lock, i)) { if (!lock_rec_get_nth_bit(lock, i)) {
continue; continue;
...@@ -6124,7 +6134,7 @@ lock_rec_print( ...@@ -6124,7 +6134,7 @@ lock_rec_print(
putc('\n', file); putc('\n', file);
} }
mtr_commit(&mtr); mtr_commit(mtr);
if (UNIV_LIKELY_NULL(heap)) { if (UNIV_LIKELY_NULL(heap)) {
mem_heap_free(heap); mem_heap_free(heap);
} }
...@@ -6280,6 +6290,8 @@ lock_print_info_all_transactions( ...@@ -6280,6 +6290,8 @@ lock_print_info_all_transactions(
ut_ad(lock_mutex_own()); ut_ad(lock_mutex_own());
const time_t now = time(NULL);
mutex_enter(&trx_sys->mutex); mutex_enter(&trx_sys->mutex);
/* First print info on non-active transactions */ /* First print info on non-active transactions */
...@@ -6366,13 +6378,14 @@ lock_print_info_all_transactions( ...@@ -6366,13 +6378,14 @@ lock_print_info_all_transactions(
fprintf(file, fprintf(file,
"------- TRX HAS BEEN WAITING %lu SEC" "------- TRX HAS BEEN WAITING %lu SEC"
" FOR THIS LOCK TO BE GRANTED:\n", " FOR THIS LOCK TO BE GRANTED:\n",
(ulong) difftime(ut_time(), (ulong) difftime(now, trx->lock.wait_started));
trx->lock.wait_started));
if (lock_get_type_low(trx->lock.wait_lock) == LOCK_REC) { if (lock_get_type_low(trx->lock.wait_lock) == LOCK_REC) {
lock_rec_print(file, trx->lock.wait_lock); lock_rec_print(file, trx->lock.wait_lock, now,
&mtr);
} else { } else {
lock_table_print(file, trx->lock.wait_lock); lock_table_print(file, trx->lock.wait_lock,
now);
} }
fputs("------------------\n", file); fputs("------------------\n", file);
...@@ -6457,11 +6470,11 @@ lock_print_info_all_transactions( ...@@ -6457,11 +6470,11 @@ lock_print_info_all_transactions(
} }
print_rec: print_rec:
lock_rec_print(file, lock); lock_rec_print(file, lock, now, &mtr);
} else { } else {
ut_ad(lock_get_type_low(lock) & LOCK_TABLE); ut_ad(lock_get_type_low(lock) & LOCK_TABLE);
lock_table_print(file, lock); lock_table_print(file, lock, now);
} }
load_page_first = TRUE; load_page_first = TRUE;
......
storage/innobase/lock/lock0wait.cc
View file @ 9e5df967
...@@ -226,7 +226,6 @@ lock_wait_suspend_thread( ...@@ -226,7 +226,6 @@ lock_wait_suspend_thread(
user OS thread */ user OS thread */
{ {
srv_slot_t* slot; srv_slot_t* slot;
double wait_time;
trx_t* trx; trx_t* trx;
ulint had_dict_lock; ulint had_dict_lock;
ibool was_declared_inside_innodb; ibool was_declared_inside_innodb;
...@@ -360,7 +359,7 @@ lock_wait_suspend_thread( ...@@ -360,7 +359,7 @@ lock_wait_suspend_thread(
row_mysql_freeze_data_dictionary(trx); row_mysql_freeze_data_dictionary(trx);
} }
wait_time = ut_difftime(ut_time(), slot->suspend_time); double wait_time = difftime(time(NULL), slot->suspend_time);
/* Release the slot for others to use */ /* Release the slot for others to use */
...@@ -451,19 +450,12 @@ lock_wait_check_and_cancel( ...@@ -451,19 +450,12 @@ lock_wait_check_and_cancel(
const srv_slot_t* slot) /*!< in: slot reserved by a user const srv_slot_t* slot) /*!< in: slot reserved by a user
thread when the wait started */ thread when the wait started */
{ {
trx_t* trx;
double wait_time;
ib_time_t suspend_time = slot->suspend_time;
ut_ad(lock_wait_mutex_own()); ut_ad(lock_wait_mutex_own());
ut_ad(slot->in_use); ut_ad(slot->in_use);
ut_ad(slot->suspended); ut_ad(slot->suspended);
wait_time = ut_difftime(ut_time(), suspend_time); double wait_time = difftime(time(NULL), slot->suspend_time);
trx_t* trx = thr_get_trx(slot->thr);
trx = thr_get_trx(slot->thr);
if (trx_is_interrupted(trx) if (trx_is_interrupted(trx)
|| (slot->wait_timeout < 100000000 || (slot->wait_timeout < 100000000
...@@ -497,7 +489,6 @@ lock_wait_check_and_cancel( ...@@ -497,7 +489,6 @@ lock_wait_check_and_cancel(
trx_mutex_exit(trx); trx_mutex_exit(trx);
} }
} }
/*********************************************************************//** /*********************************************************************//**
......
storage/xtradb/include/lock0lock.h
View file @ 9e5df967
...@@ -629,22 +629,6 @@ lock_report_trx_id_insanity( ...@@ -629,22 +629,6 @@ lock_report_trx_id_insanity(
trx_id_t max_trx_id) /*!< in: trx_sys_get_max_trx_id() */ trx_id_t max_trx_id) /*!< in: trx_sys_get_max_trx_id() */
MY_ATTRIBUTE((nonnull)); MY_ATTRIBUTE((nonnull));
/*********************************************************************//** /*********************************************************************//**
Prints info of a table lock. */
UNIV_INTERN
void
lock_table_print(
/*=============*/
FILE* file, /*!< in: file where to print */
const lock_t* lock); /*!< in: table type lock */
/*********************************************************************//**
Prints info of a record lock. */
UNIV_INTERN
void
lock_rec_print(
/*===========*/
FILE* file, /*!< in: file where to print */
const lock_t* lock); /*!< in: record type lock */
/*********************************************************************//**
Prints info of locks for all transactions. Prints info of locks for all transactions.
@return FALSE if not able to obtain lock mutex and exits without @return FALSE if not able to obtain lock mutex and exits without
printing info */ printing info */
......
storage/xtradb/include/lock0priv.h
View file @ 9e5df967
...@@ -74,10 +74,14 @@ struct lock_t { ...@@ -74,10 +74,14 @@ struct lock_t {
lock */ lock */
dict_index_t* index; /*!< index for a record lock */ dict_index_t* index; /*!< index for a record lock */
/* Statistics for how long lock has been held and time /** time(NULL) of the lock request creation.
how long this lock had to be waited before it was granted */ Used for computing wait_time and diagnostics only.
time_t requested_time; /*!< Lock request time */ Note: bogus durations may be reported
ulint wait_time; /*!< Time waited this lock or 0 */ when the system time is adjusted! */
time_t requested_time;
/** Cumulated wait time in seconds.
Note: may be bogus when the system time is adjusted! */
ulint wait_time;
union { union {
lock_table_t tab_lock;/*!< table lock */ lock_table_t tab_lock;/*!< table lock */
......
storage/xtradb/include/srv0srv.h
View file @ 9e5df967
...@@ -1332,7 +1332,10 @@ struct srv_slot_t{ ...@@ -1332,7 +1332,10 @@ struct srv_slot_t{
/** time(NULL) when the thread was suspended. /** time(NULL) when the thread was suspended.
FIXME: Use my_interval_timer() or similar, to avoid bogus FIXME: Use my_interval_timer() or similar, to avoid bogus
timeouts in lock_wait_check_and_cancel() or lock_wait_suspend_thread() timeouts in lock_wait_check_and_cancel() or lock_wait_suspend_thread()
when the system time is adjusted to the past! */ when the system time is adjusted to the past!
FIXME: This is duplicating trx_lock_t::wait_started,
which is being used for diagnostic purposes only. */
time_t suspend_time; time_t suspend_time;
ulong wait_timeout; /*!< wait time that if exceeded ulong wait_timeout; /*!< wait time that if exceeded
the thread will be timed out. the thread will be timed out.
......
storage/xtradb/include/trx0i_s.h
View file @ 9e5df967
/***************************************************************************** /*****************************************************************************
Copyright (c) 2007, 2011, Oracle and/or its affiliates. All Rights Reserved. Copyright (c) 2007, 2011, Oracle and/or its affiliates. All Rights Reserved.
Copyright (c) 2019, MariaDB Corporation.
This program is free software; you can redistribute it and/or modify it under This program is free software; you can redistribute it and/or modify it under
the terms of the GNU General Public License as published by the Free Software the terms of the GNU General Public License as published by the Free Software
...@@ -133,7 +134,7 @@ struct i_s_trx_row_t { ...@@ -133,7 +134,7 @@ struct i_s_trx_row_t {
/*!< pointer to a row /*!< pointer to a row
in innodb_locks if trx in innodb_locks if trx
is waiting, or NULL */ is waiting, or NULL */
ib_time_t trx_wait_started; /*!< trx_t::wait_started */ time_t trx_wait_started; /*!< trx->lock.wait_started */
ullint trx_weight; /*!< TRX_WEIGHT() */ ullint trx_weight; /*!< TRX_WEIGHT() */
ulint trx_mysql_thread_id; /*!< thd_get_thread_id() */ ulint trx_mysql_thread_id; /*!< thd_get_thread_id() */
const char* trx_query; /*!< MySQL statement being const char* trx_query; /*!< MySQL statement being
......
storage/xtradb/lock/lock0lock.cc
View file @ 9e5df967
...@@ -383,6 +383,20 @@ struct lock_stack_t { ...@@ -383,6 +383,20 @@ struct lock_stack_t {
ulint heap_no; /*!< heap number if rec lock */ ulint heap_no; /*!< heap number if rec lock */
}; };
/** Pretty-print a table lock.
@param[in,out] file output stream
@param[in] lock table lock
@param[in] now current time */
static void lock_table_print(FILE* file, const lock_t* lock, time_t now);
/** Pretty-print a record lock.
@param[in,out] file output stream
@param[in] lock record lock
@param[in] now current time
@param[in,out] mtr mini-transaction */
static void lock_rec_print(FILE* file, const lock_t* lock, time_t now,
mtr_t* mtr = NULL);
/*********************************************************************//** /*********************************************************************//**
Checks if a waiting record lock request still has to wait in a queue. Checks if a waiting record lock request still has to wait in a queue.
@return lock that is causing the wait */ @return lock that is causing the wait */
...@@ -466,20 +480,18 @@ UNIV_INTERN ibool lock_deadlock_found = FALSE; ...@@ -466,20 +480,18 @@ UNIV_INTERN ibool lock_deadlock_found = FALSE;
/** Only created if !srv_read_only_mode */ /** Only created if !srv_read_only_mode */
static FILE* lock_latest_err_file; static FILE* lock_latest_err_file;
/********************************************************************//** /** Check if a joining lock request results in a deadlock. If a deadlock is
Checks if a joining lock request results in a deadlock. If a deadlock is
found this function will resolve the dadlock by choosing a victim transaction found this function will resolve the dadlock by choosing a victim transaction
and rolling it back. It will attempt to resolve all deadlocks. The returned and rolling it back. It will attempt to resolve all deadlocks.
transaction id will be the joining transaction id or 0 if some other @param[in] trx joining transaction
transaction was chosen as a victim and rolled back or no deadlock found. @param[in] lock the requested lock
@param[in] now current time
@return id of transaction chosen as victim or 0 */ @return trx->id of the victim transaction
static @retval 0 if some other transaction was chosen as a victim and
trx_id_t rolled back, or no deadlock was found. */
lock_deadlock_check_and_resolve( static trx_id_t lock_deadlock_check_and_resolve(const trx_t* trx,
/*===========================*/ const lock_t* lock,
const lock_t* lock, /*!< in: lock the transaction is requesting */ time_t now);
const trx_t* trx); /*!< in: transaction */
/*********************************************************************//** /*********************************************************************//**
Gets the nth bit of a record lock. Gets the nth bit of a record lock.
...@@ -1147,12 +1159,11 @@ lock_rec_has_to_wait( ...@@ -1147,12 +1159,11 @@ lock_rec_has_to_wait(
thread, we need to look at trx ordering and lock types */ thread, we need to look at trx ordering and lock types */
if (wsrep_thd_is_BF(trx->mysql_thd, FALSE) && if (wsrep_thd_is_BF(trx->mysql_thd, FALSE) &&
wsrep_thd_is_BF(lock2->trx->mysql_thd, TRUE)) { wsrep_thd_is_BF(lock2->trx->mysql_thd, TRUE)) {
if (wsrep_debug) { if (wsrep_debug) {
fprintf(stderr, fprintf(stderr,
"BF-BF lock conflict, locking: %lu\n", "BF-BF lock conflict, locking: %lu\n",
for_locking); for_locking);
lock_rec_print(stderr, lock2); lock_rec_print(stderr, lock2, time(NULL));
} }
if (wsrep_trx_order_before(trx->mysql_thd, if (wsrep_trx_order_before(trx->mysql_thd,
...@@ -1171,7 +1182,8 @@ lock_rec_has_to_wait( ...@@ -1171,7 +1182,8 @@ lock_rec_has_to_wait(
"conflicts states: my %d locked %d\n", "conflicts states: my %d locked %d\n",
wsrep_thd_conflict_state(trx->mysql_thd, FALSE), wsrep_thd_conflict_state(trx->mysql_thd, FALSE),
wsrep_thd_conflict_state(lock2->trx->mysql_thd, FALSE) ); wsrep_thd_conflict_state(lock2->trx->mysql_thd, FALSE) );
lock_rec_print(stderr, lock2); lock_rec_print(stderr, lock2,
time(NULL));
if (for_locking) return FALSE; if (for_locking) return FALSE;
//abort(); //abort();
} }
...@@ -1797,10 +1809,12 @@ wsrep_kill_victim( ...@@ -1797,10 +1809,12 @@ wsrep_kill_victim(
fputs("*** WAITING FOR THIS LOCK TO BE GRANTED:\n", fputs("*** WAITING FOR THIS LOCK TO BE GRANTED:\n",
stderr); stderr);
time_t now = time(NULL);
if (lock_get_type(lock) == LOCK_REC) { if (lock_get_type(lock) == LOCK_REC) {
lock_rec_print(stderr, lock); lock_rec_print(stderr, lock, now);
} else { } else {
lock_table_print(stderr, lock); lock_table_print(stderr, lock, now);
} }
} }
...@@ -2055,16 +2069,20 @@ wsrep_print_wait_locks( ...@@ -2055,16 +2069,20 @@ wsrep_print_wait_locks(
{ {
if (wsrep_debug && c_lock->trx->lock.wait_lock != c_lock) { if (wsrep_debug && c_lock->trx->lock.wait_lock != c_lock) {
fprintf(stderr, "WSREP: c_lock != wait lock\n"); fprintf(stderr, "WSREP: c_lock != wait lock\n");
time_t now = time(NULL);
if (lock_get_type_low(c_lock) & LOCK_TABLE) { if (lock_get_type_low(c_lock) & LOCK_TABLE) {
lock_table_print(stderr, c_lock); lock_table_print(stderr, c_lock, now);
} else { } else {
lock_rec_print(stderr, c_lock); lock_rec_print(stderr, c_lock, now);
} }
if (lock_get_type_low(c_lock->trx->lock.wait_lock) & LOCK_TABLE) { if (lock_get_type_low(c_lock->trx->lock.wait_lock) & LOCK_TABLE) {
lock_table_print(stderr, c_lock->trx->lock.wait_lock); lock_table_print(stderr, c_lock->trx->lock.wait_lock,
now);
} else { } else {
lock_rec_print(stderr, c_lock->trx->lock.wait_lock); lock_rec_print(stderr, c_lock->trx->lock.wait_lock,
now);
} }
} }
} }
...@@ -2503,7 +2521,8 @@ lock_rec_enqueue_waiting( ...@@ -2503,7 +2521,8 @@ lock_rec_enqueue_waiting(
trx_mutex_exit(trx); trx_mutex_exit(trx);
victim_trx_id = lock_deadlock_check_and_resolve(lock, trx); const time_t now = time(NULL);
victim_trx_id = lock_deadlock_check_and_resolve(trx, lock, now);
trx_mutex_enter(trx); trx_mutex_enter(trx);
...@@ -2527,7 +2546,7 @@ lock_rec_enqueue_waiting( ...@@ -2527,7 +2546,7 @@ lock_rec_enqueue_waiting(
trx->lock.que_state = TRX_QUE_LOCK_WAIT; trx->lock.que_state = TRX_QUE_LOCK_WAIT;
trx->lock.was_chosen_as_deadlock_victim = FALSE; trx->lock.was_chosen_as_deadlock_victim = FALSE;
trx->lock.wait_started = ut_time(); trx->lock.wait_started = now;
if (UNIV_UNLIKELY(trx->take_stats)) { if (UNIV_UNLIKELY(trx->take_stats)) {
trx->lock_que_wait_nstarted = my_interval_timer(); trx->lock_que_wait_nstarted = my_interval_timer();
...@@ -2672,7 +2691,8 @@ lock_rec_add_to_queue( ...@@ -2672,7 +2691,8 @@ lock_rec_add_to_queue(
"BF skipping wait: " "BF skipping wait: "
TRX_ID_FMT "\n", TRX_ID_FMT "\n",
trx->id); trx->id);
lock_rec_print(stderr, lock); lock_rec_print(stderr, lock,
time(NULL));
} }
} else } else
#endif #endif
...@@ -2991,13 +3011,14 @@ lock_rec_has_to_wait_in_queue( ...@@ -2991,13 +3011,14 @@ lock_rec_has_to_wait_in_queue(
if (wsrep_thd_is_BF(wait_lock->trx->mysql_thd, FALSE) && if (wsrep_thd_is_BF(wait_lock->trx->mysql_thd, FALSE) &&
wsrep_thd_is_BF(lock->trx->mysql_thd, TRUE)) { wsrep_thd_is_BF(lock->trx->mysql_thd, TRUE)) {
if (wsrep_debug) { if (wsrep_debug) {
time_t now = time(NULL);
fprintf(stderr, fprintf(stderr,
"BF-BF lock conflict " TRX_ID_FMT "BF-BF lock conflict " TRX_ID_FMT
" : " TRX_ID_FMT "\n", " : " TRX_ID_FMT "\n",
wait_lock->trx->id, wait_lock->trx->id,
lock->trx->id); lock->trx->id);
lock_rec_print(stderr, wait_lock); lock_rec_print(stderr, wait_lock, now);
lock_rec_print(stderr, lock); lock_rec_print(stderr, lock, now);
} }
/* don't wait for another BF lock */ /* don't wait for another BF lock */
continue; continue;
...@@ -4328,28 +4349,26 @@ lock_deadlock_trx_print( ...@@ -4328,28 +4349,26 @@ lock_deadlock_trx_print(
mutex_exit(&trx_sys->mutex); mutex_exit(&trx_sys->mutex);
} }
/*********************************************************************//** /** Print lock data to the deadlock file and possibly to stderr.
Print lock data to the deadlock file and possibly to stderr. */ @param[in] lock record or table lock
UNIV_INLINE @param[in] now current time */
void static void lock_deadlock_lock_print(const lock_t* lock, time_t now)
lock_deadlock_lock_print(
/*=====================*/
const lock_t* lock) /*!< in: record or table type lock */
{ {
ut_ad(lock_mutex_own()); ut_ad(lock_mutex_own());
ut_ad(!srv_read_only_mode); ut_ad(!srv_read_only_mode);
if (lock_get_type_low(lock) == LOCK_REC) { if (lock_get_type_low(lock) == LOCK_REC) {
lock_rec_print(lock_latest_err_file, lock); mtr_t mtr;
lock_rec_print(lock_latest_err_file, lock, now, &mtr);
if (srv_print_all_deadlocks) { if (srv_print_all_deadlocks) {
lock_rec_print(stderr, lock); lock_rec_print(stderr, lock, now, &mtr);
} }
} else { } else {
lock_table_print(lock_latest_err_file, lock); lock_table_print(lock_latest_err_file, lock, now);
if (srv_print_all_deadlocks) { if (srv_print_all_deadlocks) {
lock_table_print(stderr, lock); lock_table_print(stderr, lock, now);
} }
} }
} }
...@@ -4462,6 +4481,8 @@ lock_deadlock_notify( ...@@ -4462,6 +4481,8 @@ lock_deadlock_notify(
ut_ad(lock_mutex_own()); ut_ad(lock_mutex_own());
ut_ad(!srv_read_only_mode); ut_ad(!srv_read_only_mode);
const time_t now = time(NULL);
lock_deadlock_start_print(); lock_deadlock_start_print();
lock_deadlock_fputs("\n*** (1) TRANSACTION:\n"); lock_deadlock_fputs("\n*** (1) TRANSACTION:\n");
...@@ -4470,7 +4491,7 @@ lock_deadlock_notify( ...@@ -4470,7 +4491,7 @@ lock_deadlock_notify(
lock_deadlock_fputs("*** (1) WAITING FOR THIS LOCK TO BE GRANTED:\n"); lock_deadlock_fputs("*** (1) WAITING FOR THIS LOCK TO BE GRANTED:\n");
lock_deadlock_lock_print(ctx->wait_lock); lock_deadlock_lock_print(ctx->wait_lock, now);
lock_deadlock_fputs("*** (2) TRANSACTION:\n"); lock_deadlock_fputs("*** (2) TRANSACTION:\n");
...@@ -4478,7 +4499,7 @@ lock_deadlock_notify( ...@@ -4478,7 +4499,7 @@ lock_deadlock_notify(
lock_deadlock_fputs("*** (2) HOLDS THE LOCK(S):\n"); lock_deadlock_fputs("*** (2) HOLDS THE LOCK(S):\n");
lock_deadlock_lock_print(lock); lock_deadlock_lock_print(lock, now);
/* It is possible that the joining transaction was granted its /* It is possible that the joining transaction was granted its
lock when we rolled back some other waiting transaction. */ lock when we rolled back some other waiting transaction. */
...@@ -4487,7 +4508,7 @@ lock_deadlock_notify( ...@@ -4487,7 +4508,7 @@ lock_deadlock_notify(
lock_deadlock_fputs( lock_deadlock_fputs(
"*** (2) WAITING FOR THIS LOCK TO BE GRANTED:\n"); "*** (2) WAITING FOR THIS LOCK TO BE GRANTED:\n");
lock_deadlock_lock_print(ctx->start->lock.wait_lock); lock_deadlock_lock_print(ctx->start->lock.wait_lock, now);
} }
#ifdef UNIV_DEBUG #ifdef UNIV_DEBUG
...@@ -4736,14 +4757,12 @@ lock_deadlock_search( ...@@ -4736,14 +4757,12 @@ lock_deadlock_search(
return(0); return(0);
} }
/********************************************************************//** /** Print info about transaction that was rolled back.
Print info about transaction that was rolled back. */ @param[in] trx victim transaction
static @param[in] lock the requested lock
void @param[in] now current time */
lock_deadlock_joining_trx_print( static void lock_deadlock_joining_trx_print(const trx_t* trx,
/*============================*/ const lock_t* lock, time_t now)
const trx_t* trx, /*!< in: transaction rolled back */
const lock_t* lock) /*!< in: lock trx wants */
{ {
ut_ad(lock_mutex_own()); ut_ad(lock_mutex_own());
ut_ad(!srv_read_only_mode); ut_ad(!srv_read_only_mode);
...@@ -4763,7 +4782,7 @@ lock_deadlock_joining_trx_print( ...@@ -4763,7 +4782,7 @@ lock_deadlock_joining_trx_print(
lock_deadlock_fputs("*** WAITING FOR THIS LOCK TO BE GRANTED:\n"); lock_deadlock_fputs("*** WAITING FOR THIS LOCK TO BE GRANTED:\n");
lock_deadlock_lock_print(lock); lock_deadlock_lock_print(lock, now);
} }
/********************************************************************//** /********************************************************************//**
...@@ -4833,20 +4852,17 @@ lock_report_waiters_to_mysql( ...@@ -4833,20 +4852,17 @@ lock_report_waiters_to_mysql(
} }
/********************************************************************//** /** Check if a joining lock request results in a deadlock. If a deadlock is
Checks if a joining lock request results in a deadlock. If a deadlock is
found this function will resolve the dadlock by choosing a victim transaction found this function will resolve the dadlock by choosing a victim transaction
and rolling it back. It will attempt to resolve all deadlocks. The returned and rolling it back. It will attempt to resolve all deadlocks.
transaction id will be the joining transaction id or 0 if some other @param[in] trx joining transaction
transaction was chosen as a victim and rolled back or no deadlock found. @param[in] lock the requested lock
@param[in] now current time
@return id of transaction chosen as victim or 0 */ @return trx->id of the victim transaction
static @retval 0 if some other transaction was chosen as a victim and
trx_id_t rolled back, or no deadlock was found. */
lock_deadlock_check_and_resolve( static trx_id_t lock_deadlock_check_and_resolve(const trx_t* trx,
/*============================*/ const lock_t* lock, time_t now)
const lock_t* lock, /*!< in: lock the transaction is requesting */
const trx_t* trx) /*!< in: transaction */
{ {
trx_id_t victim_trx_id; trx_id_t victim_trx_id;
struct thd_wait_reports waitee_buf; struct thd_wait_reports waitee_buf;
...@@ -4898,18 +4914,12 @@ lock_deadlock_check_and_resolve( ...@@ -4898,18 +4914,12 @@ lock_deadlock_check_and_resolve(
ut_a(victim_trx_id == trx->id); ut_a(victim_trx_id == trx->id);
#ifdef WITH_WSREP #ifdef WITH_WSREP
if (!wsrep_thd_is_BF(ctx.start->mysql_thd, TRUE)) if (wsrep_thd_is_BF(ctx.start->mysql_thd, TRUE)); else
{
#endif /* WITH_WSREP */ #endif /* WITH_WSREP */
if (!srv_read_only_mode) { if (!srv_read_only_mode) {
lock_deadlock_joining_trx_print(trx, lock); lock_deadlock_joining_trx_print(trx, lock,
} now);
#ifdef WITH_WSREP
} else {
/* BF processor */;
} }
#endif /* WITH_WSREP */
} else if (victim_trx_id != 0 && victim_trx_id != trx->id) { } else if (victim_trx_id != 0 && victim_trx_id != trx->id) {
ut_ad(victim_trx_id == ctx.wait_lock->trx->id); ut_ad(victim_trx_id == ctx.wait_lock->trx->id);
...@@ -5255,7 +5265,9 @@ lock_table_enqueue_waiting( ...@@ -5255,7 +5265,9 @@ lock_table_enqueue_waiting(
trx_mutex_exit(trx); trx_mutex_exit(trx);
victim_trx_id = lock_deadlock_check_and_resolve(lock, trx); const time_t now = time(NULL);
victim_trx_id = lock_deadlock_check_and_resolve(trx, lock, now);
trx_mutex_enter(trx); trx_mutex_enter(trx);
...@@ -5277,7 +5289,7 @@ lock_table_enqueue_waiting( ...@@ -5277,7 +5289,7 @@ lock_table_enqueue_waiting(
trx->lock.que_state = TRX_QUE_LOCK_WAIT; trx->lock.que_state = TRX_QUE_LOCK_WAIT;
trx->lock.wait_started = ut_time(); trx->lock.wait_started = now;
trx->lock.was_chosen_as_deadlock_victim = FALSE; trx->lock.was_chosen_as_deadlock_victim = FALSE;
trx->n_table_lock_waits++; trx->n_table_lock_waits++;
...@@ -6029,14 +6041,11 @@ lock_remove_all_on_table( ...@@ -6029,14 +6041,11 @@ lock_remove_all_on_table(
/*===================== VALIDATION AND DEBUGGING ====================*/ /*===================== VALIDATION AND DEBUGGING ====================*/
/*********************************************************************//** /** Pretty-print a table lock.
Prints info of a table lock. */ @param[in,out] file output stream
UNIV_INTERN @param[in] lock table lock
void @param[in] now current time */
lock_table_print( static void lock_table_print(FILE* file, const lock_t* lock, time_t now)
/*=============*/
FILE* file, /*!< in: file where to print */
const lock_t* lock) /*!< in: table type lock */
{ {
ut_ad(lock_mutex_own()); ut_ad(lock_mutex_own());
ut_a(lock_get_type_low(lock) == LOCK_TABLE); ut_a(lock_get_type_low(lock) == LOCK_TABLE);
...@@ -6066,30 +6075,22 @@ lock_table_print( ...@@ -6066,30 +6075,22 @@ lock_table_print(
} }
fprintf(file, " lock hold time %lu wait time before grant %lu ", fprintf(file, " lock hold time %lu wait time before grant %lu ",
(ulint)difftime(ut_time(), lock->requested_time), (ulint)difftime(now, lock->requested_time),
lock->wait_time); lock->wait_time);
putc('\n', file); putc('\n', file);
} }
/*********************************************************************//** /** Pretty-print a record lock.
Prints info of a record lock. */ @param[in,out] file output stream
UNIV_INTERN @param[in] lock record lock
void @param[in] now current time
lock_rec_print( @param[in,out] mtr mini-transaction */
/*===========*/ static void lock_rec_print(FILE* file, const lock_t* lock, time_t now,
FILE* file, /*!< in: file where to print */ mtr_t* mtr)
const lock_t* lock) /*!< in: record type lock */
{ {
const buf_block_t* block;
ulint space; ulint space;
ulint page_no; ulint page_no;
ulint i;
mtr_t mtr;
mem_heap_t* heap = NULL;
ulint offsets_[REC_OFFS_NORMAL_SIZE];
ulint* offsets = offsets_;
rec_offs_init(offsets_);
ut_ad(lock_mutex_own()); ut_ad(lock_mutex_own());
ut_a(lock_get_type_low(lock) == LOCK_REC); ut_a(lock_get_type_low(lock) == LOCK_REC);
...@@ -6134,18 +6135,25 @@ lock_rec_print( ...@@ -6134,18 +6135,25 @@ lock_rec_print(
fputs(" waiting", file); fputs(" waiting", file);
} }
mtr_start(&mtr);
fprintf(file, " lock hold time %lu wait time before grant %lu ", fprintf(file, " lock hold time %lu wait time before grant %lu ",
(ulint)difftime(ut_time(), lock->requested_time), (ulint)difftime(now, lock->requested_time),
lock->wait_time); lock->wait_time);
putc('\n', file); putc('\n', file);
if ( srv_show_verbose_locks ) { if (!srv_show_verbose_locks || !mtr) {
block = buf_page_try_get(space, page_no, &mtr); return;
}
for (i = 0; i < lock_rec_get_n_bits(lock); ++i) { mem_heap_t* heap = NULL;
ulint offsets_[REC_OFFS_NORMAL_SIZE];
ulint* offsets = offsets_;
rec_offs_init(offsets_);
mtr_start(mtr);
const buf_block_t* block = buf_page_try_get(space, page_no, mtr);
for (ulint i = 0; i < lock_rec_get_n_bits(lock); ++i) {
if (!lock_rec_get_nth_bit(lock, i)) { if (!lock_rec_get_nth_bit(lock, i)) {
continue; continue;
...@@ -6169,9 +6177,8 @@ lock_rec_print( ...@@ -6169,9 +6177,8 @@ lock_rec_print(
putc('\n', file); putc('\n', file);
} }
}
mtr_commit(&mtr); mtr_commit(mtr);
if (UNIV_LIKELY_NULL(heap)) { if (UNIV_LIKELY_NULL(heap)) {
mem_heap_free(heap); mem_heap_free(heap);
} }
...@@ -6327,6 +6334,8 @@ lock_print_info_all_transactions( ...@@ -6327,6 +6334,8 @@ lock_print_info_all_transactions(
ut_ad(lock_mutex_own()); ut_ad(lock_mutex_own());
const time_t now = time(NULL);
mutex_enter(&trx_sys->mutex); mutex_enter(&trx_sys->mutex);
/* First print info on non-active transactions */ /* First print info on non-active transactions */
...@@ -6413,13 +6422,14 @@ lock_print_info_all_transactions( ...@@ -6413,13 +6422,14 @@ lock_print_info_all_transactions(
fprintf(file, fprintf(file,
"------- TRX HAS BEEN WAITING %lu SEC" "------- TRX HAS BEEN WAITING %lu SEC"
" FOR THIS LOCK TO BE GRANTED:\n", " FOR THIS LOCK TO BE GRANTED:\n",
(ulong) difftime(ut_time(), (ulong) difftime(now, trx->lock.wait_started));
trx->lock.wait_started));
if (lock_get_type_low(trx->lock.wait_lock) == LOCK_REC) { if (lock_get_type_low(trx->lock.wait_lock) == LOCK_REC) {
lock_rec_print(file, trx->lock.wait_lock); lock_rec_print(file, trx->lock.wait_lock, now,
&mtr);
} else { } else {
lock_table_print(file, trx->lock.wait_lock); lock_table_print(file, trx->lock.wait_lock,
now);
} }
fputs("------------------\n", file); fputs("------------------\n", file);
...@@ -6508,11 +6518,11 @@ lock_print_info_all_transactions( ...@@ -6508,11 +6518,11 @@ lock_print_info_all_transactions(
} }
print_rec: print_rec:
lock_rec_print(file, lock); lock_rec_print(file, lock, now, &mtr);
} else { } else {
ut_ad(lock_get_type_low(lock) & LOCK_TABLE); ut_ad(lock_get_type_low(lock) & LOCK_TABLE);
lock_table_print(file, lock); lock_table_print(file, lock, now);
} }
load_page_first = TRUE; load_page_first = TRUE;
......
storage/xtradb/lock/lock0wait.cc
View file @ 9e5df967
...@@ -280,7 +280,6 @@ lock_wait_suspend_thread( ...@@ -280,7 +280,6 @@ lock_wait_suspend_thread(
user OS thread */ user OS thread */
{ {
srv_slot_t* slot; srv_slot_t* slot;
double wait_time;
trx_t* trx; trx_t* trx;
ulint had_dict_lock; ulint had_dict_lock;
ibool was_declared_inside_innodb; ibool was_declared_inside_innodb;
...@@ -416,7 +415,7 @@ lock_wait_suspend_thread( ...@@ -416,7 +415,7 @@ lock_wait_suspend_thread(
row_mysql_freeze_data_dictionary(trx); row_mysql_freeze_data_dictionary(trx);
} }
wait_time = ut_difftime(ut_time(), slot->suspend_time); double wait_time = difftime(time(NULL), slot->suspend_time);
/* Release the slot for others to use */ /* Release the slot for others to use */
...@@ -509,19 +508,12 @@ lock_wait_check_and_cancel( ...@@ -509,19 +508,12 @@ lock_wait_check_and_cancel(
const srv_slot_t* slot) /*!< in: slot reserved by a user const srv_slot_t* slot) /*!< in: slot reserved by a user
thread when the wait started */ thread when the wait started */
{ {
trx_t* trx;
double wait_time;
ib_time_t suspend_time = slot->suspend_time;
ut_ad(lock_wait_mutex_own()); ut_ad(lock_wait_mutex_own());
ut_ad(slot->in_use); ut_ad(slot->in_use);
ut_ad(slot->suspended); ut_ad(slot->suspended);
wait_time = ut_difftime(ut_time(), suspend_time); double wait_time = difftime(time(NULL), slot->suspend_time);
trx_t* trx = thr_get_trx(slot->thr);
trx = thr_get_trx(slot->thr);
if (trx_is_interrupted(trx) if (trx_is_interrupted(trx)
|| (slot->wait_timeout < 100000000 || (slot->wait_timeout < 100000000
...@@ -555,7 +547,6 @@ lock_wait_check_and_cancel( ...@@ -555,7 +547,6 @@ lock_wait_check_and_cancel(
trx_mutex_exit(trx); trx_mutex_exit(trx);
} }
} }
/*********************************************************************//** /*********************************************************************//**
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment
GitLab Nexedi Edition | About GitLab | About Nexedi | 沪ICP备2021021310号-2 | 沪ICP备2021021310号-7