diff options
| -rw-r--r-- | BitKeeper/etc/logging_ok | 1 | ||||
| -rw-r--r-- | innobase/include/que0que.h | 6 | ||||
| -rw-r--r-- | innobase/include/srv0srv.h | 5 | ||||
| -rw-r--r-- | innobase/include/sync0rw.h | 8 | ||||
| -rw-r--r-- | innobase/include/sync0sync.h | 24 | ||||
| -rw-r--r-- | innobase/include/sync0sync.ic | 6 | ||||
| -rw-r--r-- | innobase/include/univ.i | 1 | ||||
| -rw-r--r-- | innobase/que/que0que.c | 1 | ||||
| -rw-r--r-- | innobase/row/row0mysql.c | 7 | ||||
| -rw-r--r-- | innobase/row/row0sel.c | 4 | ||||
| -rw-r--r-- | innobase/srv/srv0srv.c | 50 | ||||
| -rw-r--r-- | innobase/sync/sync0rw.c | 7 | ||||
| -rw-r--r-- | innobase/sync/sync0sync.c | 260 | ||||
| -rw-r--r-- | innobase/ut/ut0ut.c | 15 | ||||
| -rw-r--r-- | mysql-test/r/innodb.result | 15 | ||||
| -rw-r--r-- | mysql-test/r/variables.result | 8 | ||||
| -rw-r--r-- | mysql-test/t/innodb.test | 8 | ||||
| -rw-r--r-- | mysql-test/t/variables.test | 6 | ||||
| -rw-r--r-- | sql/ha_innodb.cc | 107 | ||||
| -rw-r--r-- | sql/ha_innodb.h | 1 | ||||
| -rw-r--r-- | sql/lex.h | 1 | ||||
| -rw-r--r-- | sql/mysql_priv.h | 1 | ||||
| -rw-r--r-- | sql/mysqld.cc | 8 | ||||
| -rw-r--r-- | sql/set_var.cc | 4 | ||||
| -rw-r--r-- | sql/sql_lex.h | 2 | ||||
| -rw-r--r-- | sql/sql_parse.cc | 7 | ||||
| -rw-r--r-- | sql/sql_yacc.yy | 4 |
27 files changed, 444 insertions, 123 deletions
diff --git a/BitKeeper/etc/logging_ok b/BitKeeper/etc/logging_ok index 107e4cadacf..81686ff0163 100644 --- a/BitKeeper/etc/logging_ok +++ b/BitKeeper/etc/logging_ok @@ -230,6 +230,7 @@ ulli@morbus.(none) venu@hundin.mysql.fi venu@myvenu.com venu@work.mysql.com +vtkachenko@intelp4d.mysql.com vva@eagle.mysql.r18.ru vva@genie.(none) vva@mysql.r18.ru diff --git a/innobase/include/que0que.h b/innobase/include/que0que.h index e1874edcaf2..d45ae032ddb 100644 --- a/innobase/include/que0que.h +++ b/innobase/include/que0que.h @@ -359,6 +359,7 @@ struct que_thr_struct{ the control came */ ulint resource; /* resource usage of the query thread thus far */ + ulint lock_state; /* lock state of thread (table or row) */ }; #define QUE_THR_MAGIC_N 8476583 @@ -482,6 +483,11 @@ struct que_fork_struct{ #define QUE_THR_SUSPENDED 7 #define QUE_THR_ERROR 8 +/* Query thread lock states */ +#define QUE_THR_LOCK_NOLOCK 0 +#define QUE_THR_LOCK_ROW 1 +#define QUE_THR_LOCK_TABLE 2 + /* From where the cursor position is counted */ #define QUE_CUR_NOT_DEFINED 1 #define QUE_CUR_START 2 diff --git a/innobase/include/srv0srv.h b/innobase/include/srv0srv.h index 84b7d14ca00..5f752717fcc 100644 --- a/innobase/include/srv0srv.h +++ b/innobase/include/srv0srv.h @@ -525,6 +525,11 @@ struct export_var_struct{ ulint innodb_pages_created; ulint innodb_pages_read; ulint innodb_pages_written; + ulint innodb_row_lock_waits; + ulint innodb_row_lock_current_waits; + ib_longlong innodb_row_lock_time; + ulint innodb_row_lock_time_avg; + ulint innodb_row_lock_time_max; ulint innodb_rows_read; ulint innodb_rows_inserted; ulint innodb_rows_updated; diff --git a/innobase/include/sync0rw.h b/innobase/include/sync0rw.h index 9a988a03e92..6e3a4cf4dc7 100644 --- a/innobase/include/sync0rw.h +++ b/innobase/include/sync0rw.h @@ -61,8 +61,9 @@ Creates, or rather, initializes an rw-lock object in a specified memory location (which must be appropriately aligned). The rw-lock is initialized to the non-locked state. Explicit freeing of the rw-lock with rw_lock_free is necessary only if the memory block containing it is freed. */ - -#define rw_lock_create(L) rw_lock_create_func((L), __FILE__, __LINE__) +#define rw_lock_create(L) rw_lock_create_func(\ + (L), __FILE__, __LINE__, __STRING(L)) + /*=====================*/ /********************************************************************** Creates, or rather, initializes an rw-lock object in a specified memory @@ -75,7 +76,8 @@ rw_lock_create_func( /*================*/ rw_lock_t* lock, /* in: pointer to memory */ const char* cfile_name, /* in: file name where created */ - ulint cline); /* in: file line where created */ + ulint cline, /* in: file line where created */ + const char* cmutex_name); /* in: mutex name */ /********************************************************************** Calling this function is obligatory only if the memory buffer containing the rw-lock is freed. Removes an rw-lock object from the global list. The diff --git a/innobase/include/sync0sync.h b/innobase/include/sync0sync.h index 8e0ec715b12..98d61c129b1 100644 --- a/innobase/include/sync0sync.h +++ b/innobase/include/sync0sync.h @@ -17,6 +17,8 @@ Created 9/5/1995 Heikki Tuuri #include "os0sync.h" #include "sync0arr.h" +extern my_bool timed_mutexes; + /********************************************************************** Initializes the synchronization data structures. */ @@ -35,8 +37,7 @@ location (which must be appropriately aligned). The mutex is initialized in the reset state. Explicit freeing of the mutex with mutex_free is necessary only if the memory block containing it is freed. */ - -#define mutex_create(M) mutex_create_func((M), __FILE__, __LINE__) +#define mutex_create(M) mutex_create_func((M), __FILE__, __LINE__, __STRING(M)) /*===================*/ /********************************************************************** Creates, or rather, initializes a mutex object in a specified memory @@ -49,7 +50,8 @@ mutex_create_func( /*==============*/ mutex_t* mutex, /* in: pointer to memory */ const char* cfile_name, /* in: file name where created */ - ulint cline); /* in: file line where created */ + ulint cline, /* in: file line where created */ + const char* cmutex_name); /* in: mutex name */ /********************************************************************** Calling this function is obligatory only if the memory buffer containing the mutex is freed. Removes a mutex object from the mutex list. The mutex @@ -471,6 +473,15 @@ struct mutex_struct { const char* cfile_name;/* File name where mutex created */ ulint cline; /* Line where created */ ulint magic_n; + ulong count_using; /* count of times mutex used */ + ulong count_spin_loop; /* count of spin loops */ + ulong count_spin_rounds; /* count of spin rounds */ + ulong count_os_wait; /* count of os_wait */ + ulong count_os_yield; /* count of os_wait */ + ulonglong lspent_time; /* mutex os_wait timer msec */ + ulonglong lmax_spent_time; /* mutex os_wait timer msec */ + const char* cmutex_name;/* mutex name */ + ulint mutex_type;/* 0 - usual mutex 1 - rw_lock mutex */ }; #define MUTEX_MAGIC_N (ulint)979585 @@ -504,6 +515,13 @@ extern ibool sync_order_checks_on; /* This variable is set to TRUE when sync_init is called */ extern ibool sync_initialized; +/* Global list of database mutexes (not OS mutexes) created. */ +UT_LIST_BASE_NODE_T(mutex_t) mutex_list; + +/* Mutex protecting the mutex_list variable */ +mutex_t mutex_list_mutex; + + #ifndef UNIV_NONINL #include "sync0sync.ic" #endif diff --git a/innobase/include/sync0sync.ic b/innobase/include/sync0sync.ic index aaf5e1fd9e9..1731b47db58 100644 --- a/innobase/include/sync0sync.ic +++ b/innobase/include/sync0sync.ic @@ -249,8 +249,11 @@ mutex_enter_func( /* Note that we do not peek at the value of lock_word before trying the atomic test_and_set; we could peek, and possibly save time. */ + + mutex->count_using++; - if (!mutex_test_and_set(mutex)) { + if (!mutex_test_and_set(mutex)) + { #ifdef UNIV_SYNC_DEBUG mutex_set_debug_info(mutex, file_name, line); #endif @@ -258,4 +261,5 @@ mutex_enter_func( } mutex_spin_wait(mutex, file_name, line); + } diff --git a/innobase/include/univ.i b/innobase/include/univ.i index be71d4211b3..80024f71992 100644 --- a/innobase/include/univ.i +++ b/innobase/include/univ.i @@ -88,6 +88,7 @@ memory is read outside the allocated blocks. */ #define UNIV_SEARCH_DEBUG #define UNIV_SYNC_PERF_STAT #define UNIV_SEARCH_PERF_STAT +#define UNIV_SRV_PRINT_LATCH_WAITS; */ #define UNIV_LIGHT_MEM_DEBUG diff --git a/innobase/que/que0que.c b/innobase/que/que0que.c index 22878dec27f..a0a6adf9b83 100644 --- a/innobase/que/que0que.c +++ b/innobase/que/que0que.c @@ -163,6 +163,7 @@ que_thr_create( thr->run_node = NULL; thr->resource = 0; + thr->lock_state = QUE_THR_LOCK_NOLOCK; UT_LIST_ADD_LAST(thrs, parent->thrs, thr); diff --git a/innobase/row/row0mysql.c b/innobase/row/row0mysql.c index e959c28f6bb..0a2e9e5eaad 100644 --- a/innobase/row/row0mysql.c +++ b/innobase/row/row0mysql.c @@ -937,9 +937,10 @@ run_again: if (err != DB_SUCCESS) { que_thr_stop_for_mysql(thr); - + thr->lock_state= QUE_THR_LOCK_ROW; was_lock_wait = row_mysql_handle_errors(&err, trx, thr, &savept); + thr->lock_state= QUE_THR_LOCK_NOLOCK; if (was_lock_wait) { goto run_again; } @@ -1171,9 +1172,11 @@ run_again: return((int) err); } - + + thr->lock_state= QUE_THR_LOCK_ROW; was_lock_wait = row_mysql_handle_errors(&err, trx, thr, &savept); + thr->lock_state= QUE_THR_LOCK_NOLOCK;; if (was_lock_wait) { goto run_again; } diff --git a/innobase/row/row0sel.c b/innobase/row/row0sel.c index a3d844d1dac..c079557ca8b 100644 --- a/innobase/row/row0sel.c +++ b/innobase/row/row0sel.c @@ -3791,8 +3791,10 @@ lock_wait_or_error: que_thr_stop_for_mysql(thr); + thr->lock_state= QUE_THR_LOCK_ROW; was_lock_wait = row_mysql_handle_errors(&err, trx, thr, NULL); - + thr->lock_state= QUE_THR_LOCK_NOLOCK; + if (was_lock_wait) { mtr_start(&mtr); diff --git a/innobase/srv/srv0srv.c b/innobase/srv/srv0srv.c index 83d4fb4d39d..aa2a7fa9169 100644 --- a/innobase/srv/srv0srv.c +++ b/innobase/srv/srv0srv.c @@ -346,6 +346,12 @@ static ulint srv_n_rows_updated_old = 0; static ulint srv_n_rows_deleted_old = 0; static ulint srv_n_rows_read_old = 0; +ulint srv_n_lock_wait_count= 0; +ulint srv_n_lock_wait_current_count= 0; +ib_longlong srv_n_lock_wait_time= 0; +ulint srv_n_lock_max_wait_time= 0; + + /* Set the following to 0 if you want InnoDB to write messages on stderr on startup/shutdown @@ -1378,7 +1384,11 @@ srv_suspend_mysql_thread( trx_t* trx; ibool had_dict_lock = FALSE; ibool was_declared_inside_innodb = FALSE; - + ib_longlong start_time, finish_time; + ulint diff_time; + ulint sec; + ulint ms; + #ifdef UNIV_SYNC_DEBUG ut_ad(!mutex_own(&kernel_mutex)); #endif /* UNIV_SYNC_DEBUG */ @@ -1420,7 +1430,15 @@ srv_suspend_mysql_thread( os_event_reset(event); slot->suspend_time = ut_time(); + if (thr->lock_state == QUE_THR_LOCK_ROW) + { + srv_n_lock_wait_count++; + srv_n_lock_wait_current_count++; + + ut_usectime(&sec, &ms); + start_time= (ib_longlong)sec * 1000000 + ms; + } /* Wake the lock timeout monitor thread, if it is suspended */ os_event_set(srv_lock_timeout_thread_event); @@ -1471,7 +1489,22 @@ srv_suspend_mysql_thread( slot->in_use = FALSE; wait_time = ut_difftime(ut_time(), slot->suspend_time); - + + if (thr->lock_state == QUE_THR_LOCK_ROW) + { + ut_usectime(&sec, &ms); + finish_time= (ib_longlong)sec * 1000000 + ms; + + diff_time= finish_time-start_time; + + srv_n_lock_wait_current_count--; + srv_n_lock_wait_time= srv_n_lock_wait_time + diff_time; + if (diff_time > srv_n_lock_max_wait_time) + { + srv_n_lock_max_wait_time= diff_time; + } + } + if (trx->was_chosen_as_deadlock_victim) { trx->error_state = DB_DEADLOCK; @@ -1689,15 +1722,14 @@ srv_printf_innodb_monitor( (srv_n_rows_read - srv_n_rows_read_old) / time_elapsed); - srv_n_rows_inserted_old = srv_n_rows_inserted; + srv_n_rows_inserted_old = srv_n_rows_inserted; srv_n_rows_updated_old = srv_n_rows_updated; srv_n_rows_deleted_old = srv_n_rows_deleted; srv_n_rows_read_old = srv_n_rows_read; - fputs("----------------------------\n" + fputs("----------------------------\n" "END OF INNODB MONITOR OUTPUT\n" "============================\n", file); - mutex_exit(&srv_innodb_monitor_mutex); fflush(file); } @@ -1746,11 +1778,19 @@ srv_export_innodb_status(void) export_vars.innodb_pages_created= buf_pool->n_pages_created; export_vars.innodb_pages_read= buf_pool->n_pages_read; export_vars.innodb_pages_written= buf_pool->n_pages_written; + export_vars.innodb_row_lock_waits= srv_n_lock_wait_count; + export_vars.innodb_row_lock_current_waits= srv_n_lock_wait_current_count; + export_vars.innodb_row_lock_time= srv_n_lock_wait_time / 10000; + export_vars.innodb_row_lock_time_avg= + (srv_n_lock_wait_count > 0) ? + (srv_n_lock_wait_time / 10000 / srv_n_lock_wait_count) : 0; + export_vars.innodb_row_lock_time_max= srv_n_lock_max_wait_time / 10000; export_vars.innodb_rows_read= srv_n_rows_read; export_vars.innodb_rows_inserted= srv_n_rows_inserted; export_vars.innodb_rows_updated= srv_n_rows_updated; export_vars.innodb_rows_deleted= srv_n_rows_deleted; mutex_exit(&srv_innodb_monitor_mutex); + } /************************************************************************* diff --git a/innobase/sync/sync0rw.c b/innobase/sync/sync0rw.c index 77757685208..e57974a375b 100644 --- a/innobase/sync/sync0rw.c +++ b/innobase/sync/sync0rw.c @@ -90,7 +90,8 @@ rw_lock_create_func( /*================*/ rw_lock_t* lock, /* in: pointer to memory */ const char* cfile_name, /* in: file name where created */ - ulint cline) /* in: file line where created */ + ulint cline, /* in: file line where created */ + const char* cmutex_name) /* in: mutex name */ { /* If this is the very first time a synchronization object is created, then the following call initializes @@ -101,7 +102,9 @@ rw_lock_create_func( lock->mutex.cfile_name = cfile_name; lock->mutex.cline = cline; - + lock->mutex.cmutex_name = cmutex_name; + lock->mutex.mutex_type = 1; + rw_lock_set_waiters(lock, 0); rw_lock_set_writer(lock, RW_LOCK_NOT_LOCKED); lock->writer_count = 0; diff --git a/innobase/sync/sync0sync.c b/innobase/sync/sync0sync.c index 86306e49cac..fb46c692830 100644 --- a/innobase/sync/sync0sync.c +++ b/innobase/sync/sync0sync.c @@ -129,11 +129,6 @@ sync_array_t* sync_primary_wait_array; /* This variable is set to TRUE when sync_init is called */ ibool sync_initialized = FALSE; -/* Global list of database mutexes (not OS mutexes) created. */ -UT_LIST_BASE_NODE_T(mutex_t) mutex_list; - -/* Mutex protecting the mutex_list variable */ -mutex_t mutex_list_mutex; typedef struct sync_level_struct sync_level_t; typedef struct sync_thread_struct sync_thread_t; @@ -202,7 +197,8 @@ mutex_create_func( /*==============*/ mutex_t* mutex, /* in: pointer to memory */ const char* cfile_name, /* in: file name where created */ - ulint cline) /* in: file line where created */ + ulint cline, /* in: file line where created */ + const char* cmutex_name) /* in: mutex name */ { #if defined(_WIN32) && defined(UNIV_CAN_USE_X86_ASSEMBLER) mutex_reset_lock_word(mutex); @@ -219,6 +215,16 @@ mutex_create_func( mutex->level = SYNC_LEVEL_NONE; mutex->cfile_name = cfile_name; mutex->cline = cline; + mutex->cmutex_name= cmutex_name; + mutex->count_using= 0; + mutex->mutex_type= 0; + mutex->lspent_time= 0; + mutex->lmax_spent_time= 0; + mutex->count_spin_loop= 0; + mutex->count_spin_rounds= 0; + mutex->count_os_wait= 0; + mutex->count_os_yield= 0; + /* Check that lock_word is aligned; this is important on Intel */ ut_ad(((ulint)(&(mutex->lock_word))) % 4 == 0); @@ -355,135 +361,180 @@ for the mutex before suspending the thread. */ void mutex_spin_wait( /*============*/ - mutex_t* mutex, /* in: pointer to mutex */ - const char* file_name, /* in: file name where - mutex requested */ - ulint line) /* in: line where requested */ + mutex_t* mutex, /* in: pointer to mutex */ + const char* file_name, /* in: file name where + mutex requested */ + ulint line) /* in: line where requested */ { - ulint index; /* index of the reserved wait cell */ - ulint i; /* spin round count */ - - ut_ad(mutex); + ulint index; /* index of the reserved wait cell */ + ulint i; /* spin round count */ + ib_longlong lstart_time, lfinish_time; /* for timing os_wait */ + ulint ltime_diff; + ulint sec; + ulint ms; -mutex_loop: + uint timer_started = 0; - i = 0; + ut_ad(mutex); - /* Spin waiting for the lock word to become zero. Note that we do not - have to assume that the read access to the lock word is atomic, as the - actual locking is always committed with atomic test-and-set. In - reality, however, all processors probably have an atomic read of a - memory word. */ - -spin_loop: - mutex_spin_wait_count++; +mutex_loop: - while (mutex_get_lock_word(mutex) != 0 && i < SYNC_SPIN_ROUNDS) { + i = 0; - if (srv_spin_wait_delay) { - ut_delay(ut_rnd_interval(0, srv_spin_wait_delay)); - } - - i++; - } +/* Spin waiting for the lock word to become zero. Note that we do not + have to assume that the read access to the lock word is atomic, as the + actual locking is always committed with atomic test-and-set. In + reality, however, all processors probably have an atomic read of a + memory word. */ - if (i == SYNC_SPIN_ROUNDS) { - os_thread_yield(); - } +spin_loop: + mutex_spin_wait_count++; + mutex->count_spin_loop++; + + while (mutex_get_lock_word(mutex) != 0 && i < SYNC_SPIN_ROUNDS) + { + if (srv_spin_wait_delay) + { + ut_delay(ut_rnd_interval(0, srv_spin_wait_delay)); + } + + i++; + } + + if (i == SYNC_SPIN_ROUNDS) + { + mutex->count_os_yield++; + if (timed_mutexes == 1 && timer_started==0) + { + ut_usectime(&sec, &ms); + lstart_time= (ib_longlong)sec * 1000000 + ms; + timer_started = 1; + } + os_thread_yield(); + } + +#ifdef UNIV_SRV_PRINT_LATCH_WAITS + fprintf(stderr, + "Thread %lu spin wait mutex at %p cfile %s cline %lu rnds %lu\n", + (ulong) os_thread_pf(os_thread_get_curr_id()), mutex, + mutex->cfile_name, (ulong) mutex->cline, (ulong) i); +#endif - if (srv_print_latch_waits) { - fprintf(stderr, - "Thread %lu spin wait mutex at %p cfile %s cline %lu rnds %lu\n", - (ulong) os_thread_pf(os_thread_get_curr_id()), mutex, - mutex->cfile_name, (ulong) mutex->cline, (ulong) i); - } + mutex_spin_round_count += i; - mutex_spin_round_count += i; + mutex->count_spin_rounds += i; - if (mutex_test_and_set(mutex) == 0) { - /* Succeeded! */ + if (mutex_test_and_set(mutex) == 0) + { + /* Succeeded! */ #ifdef UNIV_SYNC_DEBUG - mutex_set_debug_info(mutex, file_name, line); + mutex_set_debug_info(mutex, file_name, line); #endif - return; - } + goto finish_timing; + } - /* We may end up with a situation where lock_word is - 0 but the OS fast mutex is still reserved. On FreeBSD - the OS does not seem to schedule a thread which is constantly - calling pthread_mutex_trylock (in mutex_test_and_set - implementation). Then we could end up spinning here indefinitely. - The following 'i++' stops this infinite spin. */ + /* We may end up with a situation where lock_word is + 0 but the OS fast mutex is still reserved. On FreeBSD + the OS does not seem to schedule a thread which is constantly + calling pthread_mutex_trylock (in mutex_test_and_set + implementation). Then we could end up spinning here indefinitely. + The following 'i++' stops this infinite spin. */ - i++; - - if (i < SYNC_SPIN_ROUNDS) { + i++; - goto spin_loop; - } + if (i < SYNC_SPIN_ROUNDS) + { + goto spin_loop; + } - sync_array_reserve_cell(sync_primary_wait_array, mutex, - SYNC_MUTEX, - file_name, line, - &index); + sync_array_reserve_cell(sync_primary_wait_array, mutex, + SYNC_MUTEX, file_name, line, &index); - mutex_system_call_count++; + mutex_system_call_count++; - /* The memory order of the array reservation and the change in the - waiters field is important: when we suspend a thread, we first - reserve the cell and then set waiters field to 1. When threads are - released in mutex_exit, the waiters field is first set to zero and - then the event is set to the signaled state. */ - - mutex_set_waiters(mutex, 1); + /* The memory order of the array reservation and the change in the + waiters field is important: when we suspend a thread, we first + reserve the cell and then set waiters field to 1. When threads are + released in mutex_exit, the waiters field is first set to zero and + then the event is set to the signaled state. */ + + mutex_set_waiters(mutex, 1); - /* Try to reserve still a few times */ - for (i = 0; i < 4; i++) { - if (mutex_test_and_set(mutex) == 0) { + /* Try to reserve still a few times */ + for (i = 0; i < 4; i++) + { + if (mutex_test_and_set(mutex) == 0) + { + /* Succeeded! Free the reserved wait cell */ - /* Succeeded! Free the reserved wait cell */ + sync_array_free_cell(sync_primary_wait_array, index); - sync_array_free_cell(sync_primary_wait_array, index); - #ifdef UNIV_SYNC_DEBUG - mutex_set_debug_info(mutex, file_name, line); + mutex_set_debug_info(mutex, file_name, line); #endif - if (srv_print_latch_waits) { - fprintf(stderr, - "Thread %lu spin wait succeeds at 2:" - " mutex at %p\n", - (ulong) os_thread_pf(os_thread_get_curr_id()), - mutex); - } - - return; +#ifdef UNIV_SRV_PRINT_LATCH_WAITS + fprintf(stderr, "Thread %lu spin wait succeeds at 2:" + " mutex at %p\n", + (ulong) os_thread_pf(os_thread_get_curr_id()), + mutex); +#endif - /* Note that in this case we leave the waiters field - set to 1. We cannot reset it to zero, as we do not know - if there are other waiters. */ - } - } + goto finish_timing; - /* Now we know that there has been some thread holding the mutex - after the change in the wait array and the waiters field was made. - Now there is no risk of infinite wait on the event. */ + /* Note that in this case we leave the waiters field + set to 1. We cannot reset it to zero, as we do not know + if there are other waiters. */ + } + } - if (srv_print_latch_waits) { - fprintf(stderr, - "Thread %lu OS wait mutex at %p cfile %s cline %lu rnds %lu\n", - (ulong) os_thread_pf(os_thread_get_curr_id()), mutex, - mutex->cfile_name, (ulong) mutex->cline, (ulong) i); - } - - mutex_system_call_count++; - mutex_os_wait_count++; + /* Now we know that there has been some thread holding the mutex + after the change in the wait array and the waiters field was made. +Now there is no risk of infinite wait on the event. */ - sync_array_wait_event(sync_primary_wait_array, index); +#ifdef UNIV_SRV_PRINT_LATCH_WAITS + fprintf(stderr, + "Thread %lu OS wait mutex at %p cfile %s cline %lu rnds %lu\n", + (ulong) os_thread_pf(os_thread_get_curr_id()), mutex, + mutex->cfile_name, (ulong) mutex->cline, (ulong) i); +#endif - goto mutex_loop; + mutex_system_call_count++; + mutex_os_wait_count++; + + mutex->count_os_wait++; + + /* + !!!!! Sometimes os_wait can be called without os_thread_yield + */ + + if (timed_mutexes == 1 && timer_started==0) + { + ut_usectime(&sec, &ms); + lstart_time= (ib_longlong)sec * 1000000 + ms; + timer_started = 1; + } + + + sync_array_wait_event(sync_primary_wait_array, index); + goto mutex_loop; + +finish_timing: + if (timed_mutexes == 1 && timer_started==1) + { + ut_usectime(&sec, &ms); + lfinish_time= (ib_longlong)sec * 1000000 + ms; + + ltime_diff= lfinish_time - lstart_time; + mutex->lspent_time += ltime_diff; + if (mutex->lmax_spent_time < ltime_diff) + { + mutex->lmax_spent_time= ltime_diff; + } + } + return; } /********************************************************************** @@ -555,6 +606,7 @@ mutex_set_level( mutex->level = level; } + #ifdef UNIV_SYNC_DEBUG /********************************************************************** Checks that the current thread owns the mutex. Works only in the debug diff --git a/innobase/ut/ut0ut.c b/innobase/ut/ut0ut.c index 732380bcb1f..21c2833b6d6 100644 --- a/innobase/ut/ut0ut.c +++ b/innobase/ut/ut0ut.c @@ -74,6 +74,21 @@ ut_time(void) } /************************************************************** +Returns system time. We do not specify the format of the time returned: +the only way to manipulate it is to use the function ut_difftime. */ + +void +ut_usectime(ulint* sec, ulint* ms) +/*=========*/ +{ + struct timeval tv; + gettimeofday(&tv,NULL); + *sec = (ulint) tv.tv_sec; + *ms = (ulint) tv.tv_usec; + return; +} + +/************************************************************** Returns the difference of two times in seconds. */ double diff --git a/mysql-test/r/innodb.result b/mysql-test/r/innodb.result index fe99961f964..06940d65a79 100644 --- a/mysql-test/r/innodb.result +++ b/mysql-test/r/innodb.result @@ -1700,5 +1700,20 @@ Innodb_rows_read 80161 show status like "Innodb_rows_updated"; Variable_name Value Innodb_rows_updated 29530 +show status like "Innodb_row_lock_waits"; +Variable_name Value +Innodb_row_lock_waits 0 +show status like "Innodb_row_lock_current_waits"; +Variable_name Value +Innodb_row_lock_current_waits 0 +show status like "Innodb_row_lock_time"; +Variable_name Value +Innodb_row_lock_time 0 +show status like "Innodb_row_lock_time_max"; +Variable_name Value +Innodb_row_lock_time_max 0 +show status like "Innodb_row_lock_time_avg"; +Variable_name Value +Innodb_row_lock_time_avg 0 create table t1 (v varchar(16384)) engine=innodb; ERROR 42000: Column length too big for column 'v' (max = 255); use BLOB instead diff --git a/mysql-test/r/variables.result b/mysql-test/r/variables.result index b2d58df5798..0612f4b3941 100644 --- a/mysql-test/r/variables.result +++ b/mysql-test/r/variables.result @@ -137,6 +137,14 @@ set global concurrent_insert=DEFAULT; show variables like 'concurrent_insert'; Variable_name Value concurrent_insert ON +set global timed_mutexes=1; +show variables like 'timed_mutexes'; +Variable_name Value +timed_mutexes ON +set global timed_mutexes=0; +show variables like 'timed_mutexes'; +Variable_name Value +timed_mutexes OFF set storage_engine=MYISAM, storage_engine="HEAP", global storage_engine="INNODB"; show local variables like 'storage_engine'; Variable_name Value diff --git a/mysql-test/t/innodb.test b/mysql-test/t/innodb.test index e7f08f11a2d..cee216e9e29 100644 --- a/mysql-test/t/innodb.test +++ b/mysql-test/t/innodb.test @@ -1210,6 +1210,14 @@ show status like "Innodb_rows_deleted"; show status like "Innodb_rows_inserted"; show status like "Innodb_rows_read"; show status like "Innodb_rows_updated"; + +# Test for row locks InnoDB status variables. +show status like "Innodb_row_lock_waits"; +show status like "Innodb_row_lock_current_waits"; +show status like "Innodb_row_lock_time"; +show status like "Innodb_row_lock_time_max"; +show status like "Innodb_row_lock_time_avg"; + # # Test varchar # diff --git a/mysql-test/t/variables.test b/mysql-test/t/variables.test index 6563f7117cd..760a08555ce 100644 --- a/mysql-test/t/variables.test +++ b/mysql-test/t/variables.test @@ -83,6 +83,12 @@ show variables like 'concurrent_insert'; set global concurrent_insert=DEFAULT; show variables like 'concurrent_insert'; +set global timed_mutexes=1; +show variables like 'timed_mutexes'; +set global timed_mutexes=0; +show variables like 'timed_mutexes'; + + set storage_engine=MYISAM, storage_engine="HEAP", global storage_engine="INNODB"; show local variables like 'storage_engine'; show global variables like 'storage_engine'; diff --git a/sql/ha_innodb.cc b/sql/ha_innodb.cc index cb23e31225b..2ae1ff5672d 100644 --- a/sql/ha_innodb.cc +++ b/sql/ha_innodb.cc @@ -231,6 +231,16 @@ struct show_var_st innodb_status_variables[]= { (char*) &export_vars.innodb_pages_read, SHOW_LONG}, {"pages_written", (char*) &export_vars.innodb_pages_written, SHOW_LONG}, + {"row_lock_waits", + (char*) &export_vars.innodb_row_lock_waits, SHOW_LONG}, + {"row_lock_current_waits", + (char*) &export_vars.innodb_row_lock_current_waits, SHOW_LONG}, + {"row_lock_time", + (char*) &export_vars.innodb_row_lock_time, SHOW_LONGLONG}, + {"row_lock_time_max", + (char*) &export_vars.innodb_row_lock_time_max, SHOW_LONG}, + {"row_lock_time_avg", + (char*) &export_vars.innodb_row_lock_time_avg, SHOW_LONG}, {"rows_deleted", (char*) &export_vars.innodb_rows_deleted, SHOW_LONG}, {"rows_inserted", @@ -5506,6 +5516,103 @@ innodb_show_status( } /**************************************************************************** +Implements the SHOW MUTEX STATUS command. . */ + +bool +innodb_mutex_show_status( +/*===============*/ + THD* thd) /* in: the MySQL query thread of the caller */ +{ + Protocol *protocol= thd->protocol; + List<Item> field_list; + mutex_t* mutex; + const char* file_name; + ulint line; + ulint rw_lock_count= 0; + ulint rw_lock_count_spin_loop= 0; + ulint rw_lock_count_spin_rounds= 0; + ulint rw_lock_count_os_wait= 0; + ulint rw_lock_count_os_yield= 0; + ulonglong rw_lock_wait_time= 0; + + DBUG_ENTER("innodb_mutex_show_status"); + + field_list.push_back(new Item_empty_string("Mutex", FN_REFLEN)); + field_list.push_back(new Item_empty_string("Module", FN_REFLEN)); + field_list.push_back(new Item_uint("Count", 21)); + field_list.push_back(new Item_uint("Spin_waits", 21)); + field_list.push_back(new Item_uint("Spin_rounds", 21)); + field_list.push_back(new Item_uint("OS_waits", 21)); + field_list.push_back(new Item_uint("OS_yields", 21)); + field_list.push_back(new Item_uint("OS_waits_time", 21)); + + if (protocol->send_fields(&field_list, + Protocol::SEND_NUM_ROWS | Protocol::SEND_EOF)) + DBUG_RETURN(TRUE); + +// mutex_enter(&mutex_list_mutex); + + mutex = UT_LIST_GET_FIRST(mutex_list); + + while ( mutex != NULL ) + { + if (mutex->mutex_type != 1) + { + if (mutex->count_using > 0) + { + protocol->prepare_for_resend(); + protocol->store(mutex->cmutex_name, system_charset_info); + protocol->store(mutex->cfile_name, system_charset_info); + protocol->store((ulonglong)mutex->count_using); + protocol->store((ulonglong)mutex->count_spin_loop); + protocol->store((ulonglong)mutex->count_spin_rounds); + protocol->store((ulonglong)mutex->count_os_wait); + protocol->store((ulonglong)mutex->count_os_yield); + protocol->store((ulonglong)mutex->lspent_time/1000); + + if (protocol->write()) + { +// mutex_exit(&mutex_list_mutex); + DBUG_RETURN(1); + } + } + } + else + { + rw_lock_count += mutex->count_using; + rw_lock_count_spin_loop += mutex->count_spin_loop; + rw_lock_count_spin_rounds += mutex->count_spin_rounds; + rw_lock_count_os_wait += mutex->count_os_wait; + rw_lock_count_os_yield += mutex->count_os_yield; + rw_lock_wait_time += mutex->lspent_time; + } + + mutex = UT_LIST_GET_NEXT(list, mutex); + } + + protocol->prepare_for_resend(); + protocol->store("rw_lock_mutexes", system_charset_info); + protocol->store("", system_charset_info); + protocol->store((ulonglong)rw_lock_count); + protocol->store((ulonglong)rw_lock_count_spin_loop); + protocol->store((ulonglong)rw_lock_count_spin_rounds); + protocol->store((ulonglong)rw_lock_count_os_wait); + protocol->store((ulonglong)rw_lock_count_os_yield); + protocol->store((ulonglong)rw_lock_wait_time/1000); + + if (protocol->write()) + { +// mutex_exit(&mutex_list_mutex); + DBUG_RETURN(1); + } + + +// mutex_exit(&mutex_list_mutex); + send_eof(thd); + DBUG_RETURN(FALSE); +} + +/**************************************************************************** Handling the shared INNOBASE_SHARE structure that is needed to provide table locking. ****************************************************************************/ diff --git a/sql/ha_innodb.h b/sql/ha_innodb.h index bb8823fd1bb..fcb9165de64 100644 --- a/sql/ha_innodb.h +++ b/sql/ha_innodb.h @@ -242,6 +242,7 @@ int innobase_savepoint( int innobase_close_connection(THD *thd); int innobase_drop_database(char *path); bool innodb_show_status(THD* thd); +bool innodb_mutex_show_status(THD* thd); void innodb_export_status(void); my_bool innobase_query_caching_of_table_permitted(THD* thd, char* full_name, diff --git a/sql/lex.h b/sql/lex.h index cf0059a1397..b052479d413 100644 --- a/sql/lex.h +++ b/sql/lex.h @@ -323,6 +323,7 @@ static SYMBOL symbols[] = { { "MULTILINESTRING", SYM(MULTILINESTRING)}, { "MULTIPOINT", SYM(MULTIPOINT)}, { "MULTIPOLYGON", SYM(MULTIPOLYGON)}, + { "MUTEX", SYM(MUTEX_SYM)}, { "NAME", SYM(NAME_SYM)}, { "NAMES", SYM(NAMES_SYM)}, { "NATIONAL", SYM(NATIONAL_SYM)}, diff --git a/sql/mysql_priv.h b/sql/mysql_priv.h index 2fc82e05f31..3d6e23cceaf 100644 --- a/sql/mysql_priv.h +++ b/sql/mysql_priv.h @@ -998,6 +998,7 @@ extern ulong table_cache_size; extern ulong max_connections,max_connect_errors, connect_timeout; extern ulong slave_net_timeout; extern ulong max_user_connections; +extern my_bool timed_mutexes; extern ulong what_to_log,flush_time; extern ulong query_buff_size, thread_stack,thread_stack_min; extern ulong binlog_cache_size, max_binlog_cache_size, open_files_limit; diff --git a/sql/mysqld.cc b/sql/mysqld.cc index c5698469341..196e7502d25 100644 --- a/sql/mysqld.cc +++ b/sql/mysqld.cc @@ -325,6 +325,7 @@ ulong binlog_cache_use= 0, binlog_cache_disk_use= 0; ulong max_connections,max_used_connections, max_connect_errors, max_user_connections = 0; ulong thread_id=1L,current_pid; +my_bool timed_mutexes= 0; ulong slow_launch_threads = 0, sync_binlog_period; ulong expire_logs_days = 0; ulong rpl_recovery_rank=0; @@ -4200,7 +4201,8 @@ enum options_mysqld OPT_OPTIMIZER_PRUNE_LEVEL, OPT_UPDATABLE_VIEWS_WITH_LIMIT, OPT_AUTO_INCREMENT, OPT_AUTO_INCREMENT_OFFSET, - OPT_ENABLE_LARGE_PAGES + OPT_ENABLE_LARGE_PAGES, + OPT_TIMED_MUTEXES }; @@ -4799,6 +4801,10 @@ log and this option does nothing anymore.", "Using this option will cause most temporary files created to use a small set of names, rather than a unique name for each new file.", (gptr*) &use_temp_pool, (gptr*) &use_temp_pool, 0, GET_BOOL, NO_ARG, 1, 0, 0, 0, 0, 0}, + {"timed_mutexes", OPT_TIMED_MUTEXES, + "Specify whether to time mutexes (only InnoDB mutexes are currently supported)", + (gptr*) &timed_mutexes, (gptr*) &timed_mutexes, 0, GET_BOOL, NO_ARG, 0, + 0, 0, 0, 0, 0}, {"tmpdir", 't', "Path for temporary files. Several paths may be specified, separated by a " #if defined(__WIN__) || defined(OS2) || defined(__NETWARE__) diff --git a/sql/set_var.cc b/sql/set_var.cc index da6341597f1..4e74ad02ea5 100644 --- a/sql/set_var.cc +++ b/sql/set_var.cc @@ -361,6 +361,8 @@ sys_var_thd_enum sys_tx_isolation("tx_isolation", fix_tx_isolation); sys_var_thd_ulong sys_tmp_table_size("tmp_table_size", &SV::tmp_table_size); +sys_var_bool_ptr sys_timed_mutexes("timed_mutexes", + &timed_mutexes); sys_var_thd_ulong sys_net_wait_timeout("wait_timeout", &SV::net_wait_timeout); @@ -635,6 +637,7 @@ sys_var *sys_variables[]= &sys_table_type, &sys_thread_cache_size, &sys_time_format, + &sys_timed_mutexes, &sys_timestamp, &sys_time_zone, &sys_tmp_table_size, @@ -901,6 +904,7 @@ struct show_var_st init_vars[]= { {"thread_stack", (char*) &thread_stack, SHOW_LONG}, {sys_time_format.name, (char*) &sys_time_format, SHOW_SYS}, {"time_zone", (char*) &sys_time_zone, SHOW_SYS}, + {sys_timed_mutexes.name, (char*) &sys_timed_mutexes, SHOW_SYS}, {sys_tmp_table_size.name, (char*) &sys_tmp_table_size, SHOW_SYS}, {"tmpdir", (char*) &opt_mysql_tmpdir, SHOW_CHAR_PTR}, {sys_trans_alloc_block_size.name, (char*) &sys_trans_alloc_block_size, diff --git a/sql/sql_lex.h b/sql/sql_lex.h index 721febab548..ea084b5735f 100644 --- a/sql/sql_lex.h +++ b/sql/sql_lex.h @@ -53,7 +53,7 @@ enum enum_sql_command { SQLCOM_SHOW_DATABASES, SQLCOM_SHOW_TABLES, SQLCOM_SHOW_FIELDS, SQLCOM_SHOW_KEYS, SQLCOM_SHOW_VARIABLES, SQLCOM_SHOW_LOGS, SQLCOM_SHOW_STATUS, - SQLCOM_SHOW_INNODB_STATUS, + SQLCOM_SHOW_INNODB_STATUS, SQLCOM_SHOW_MUTEX_STATUS, SQLCOM_SHOW_PROCESSLIST, SQLCOM_SHOW_MASTER_STAT, SQLCOM_SHOW_SLAVE_STAT, SQLCOM_SHOW_GRANTS, SQLCOM_SHOW_CREATE, SQLCOM_SHOW_CHARSETS, SQLCOM_SHOW_COLLATIONS, SQLCOM_SHOW_CREATE_DB, SQLCOM_SHOW_TABLE_STATUS, diff --git a/sql/sql_parse.cc b/sql/sql_parse.cc index 0dec6e820be..a622568d9dc 100644 --- a/sql/sql_parse.cc +++ b/sql/sql_parse.cc @@ -2488,6 +2488,13 @@ mysql_execute_command(THD *thd) res = innodb_show_status(thd); break; } + case SQLCOM_SHOW_MUTEX_STATUS: + { + if (check_global_access(thd, SUPER_ACL)) + goto error; + res = innodb_mutex_show_status(thd); + break; + } #endif #ifdef HAVE_REPLICATION case SQLCOM_LOAD_MASTER_TABLE: diff --git a/sql/sql_yacc.yy b/sql/sql_yacc.yy index 88cd3daf924..eba3b5298af 100644 --- a/sql/sql_yacc.yy +++ b/sql/sql_yacc.yy @@ -337,6 +337,7 @@ bool my_yyoverflow(short **a, YYSTYPE **b, ulong *yystacksize); %token MAX_UPDATES_PER_HOUR %token MEDIUM_SYM %token MIN_ROWS +%token MUTEX_SYM %token NAMES_SYM %token NAME_SYM %token NATIONAL_SYM @@ -5986,6 +5987,8 @@ show_param: } | INNOBASE_SYM STATUS_SYM { Lex->sql_command = SQLCOM_SHOW_INNODB_STATUS; WARN_DEPRECATED("SHOW INNODB STATUS", "SHOW ENGINE INNODB STATUS"); } + | MUTEX_SYM STATUS_SYM + { Lex->sql_command = SQLCOM_SHOW_MUTEX_STATUS; } | opt_full PROCESSLIST_SYM { Lex->sql_command= SQLCOM_SHOW_PROCESSLIST;} | opt_var_type VARIABLES wild @@ -6987,6 +6990,7 @@ keyword: | MULTILINESTRING {} | MULTIPOINT {} | MULTIPOLYGON {} + | MUTEX_SYM {} | NAME_SYM {} | NAMES_SYM {} | NATIONAL_SYM {} |