Merge with 3.23.51

Fixed wrong usage of sprintf() in ha_innodb.cc

1 files changed, 214 insertions, 110 deletions

diff --git a/innobase/srv/srv0srv.c b/innobase/srv/srv0srv.c
index 39f3566eac8..3efb82eb8eb 100644
--- a/innobase/srv/srv0srv.c
+++ b/innobase/srv/srv0srv.c
@@ -61,7 +61,7 @@ ulint	srv_activity_count	= 0;
 ibool	srv_lock_timeout_and_monitor_active = FALSE;
 ibool	srv_error_monitor_active = FALSE;
 
-char*	srv_main_thread_op_info = (char *) "";
+char*	srv_main_thread_op_info = (char*) "";
 
 /* Server parameters which are read from the initfile */
 
@@ -238,15 +238,14 @@ ulint	srv_n_rows_updated_old		= 0;
 ulint	srv_n_rows_deleted_old		= 0;
 ulint	srv_n_rows_read_old		= 0;
 
-ibool	srv_print_innodb_monitor	= FALSE;
-ibool   srv_print_innodb_lock_monitor   = FALSE;
-ibool   srv_print_innodb_tablespace_monitor = FALSE;
-
 /*
   Set the following to 0 if you want InnoDB to write messages on
   stderr on startup/shutdown
 */
 ibool	srv_print_verbose_log		= TRUE;
+ibool	srv_print_innodb_monitor	= FALSE;
+ibool   srv_print_innodb_lock_monitor   = FALSE;
+ibool   srv_print_innodb_tablespace_monitor = FALSE;
 ibool   srv_print_innodb_table_monitor = FALSE;
 
 /* The parameters below are obsolete: */
@@ -278,6 +277,10 @@ i/o handler thread */
 
 char* srv_io_thread_op_info[SRV_MAX_N_IO_THREADS];
 
+time_t	srv_last_monitor_time;
+
+mutex_t srv_innodb_monitor_mutex;
+
 /*
 	IMPLEMENTATION OF THE SERVER MAIN PROGRAM
 	=========================================
@@ -645,7 +648,7 @@ srv_release_threads(
 	
 		slot = srv_table_get_nth_slot(i);
 
-		if ((slot->type == type) && slot->suspended) {
+		if (slot->in_use && slot->type == type && slot->suspended) {
 			
 			slot->suspended = FALSE;
 
@@ -987,7 +990,6 @@ srv_communication_init(
 	
 /*************************************************************************
 Implements the recovery utility. */
-#ifdef NOT_USED
 static
 ulint
 srv_recovery_thread(
@@ -1025,7 +1027,7 @@ srv_recovery_thread(
 
 	return(0);
 }
-#endif
+
 /*************************************************************************
 Implements the purge utility. */
 
@@ -1077,7 +1079,6 @@ srv_create_utility_threads(void)
 
 /*************************************************************************
 Implements the communication threads. */
-#ifdef NOT_USED
 static
 ulint
 srv_com_thread(
@@ -1125,7 +1126,7 @@ srv_com_thread(
 
 	return(0);
 }
-#endif
+
 /*************************************************************************
 Creates the communication threads. */
 
@@ -1147,7 +1148,6 @@ srv_create_com_threads(void)
 
 /*************************************************************************
 Implements the worker threads. */
-#ifdef NOT_USED
 static
 ulint
 srv_worker_thread(
@@ -1190,7 +1190,7 @@ srv_worker_thread(
 
 	return(0);
 }
-#endif
+
 /*************************************************************************
 Creates the worker threads. */
 
@@ -1625,13 +1625,16 @@ srv_init(void)
 	kernel_mutex_temp = mem_alloc(sizeof(mutex_t));
 	mutex_create(&kernel_mutex);
 	mutex_set_level(&kernel_mutex, SYNC_KERNEL);
+
+	mutex_create(&srv_innodb_monitor_mutex);
+	mutex_set_level(&srv_innodb_monitor_mutex, SYNC_NO_ORDER_CHECK);
 	
 	srv_sys->threads = mem_alloc(OS_THREAD_MAX_N * sizeof(srv_slot_t));
 
 	for (i = 0; i < OS_THREAD_MAX_N; i++) {
 		slot = srv_table_get_nth_slot(i);
 		slot->in_use = FALSE;
-		slot->type=0;			/* Avoid purify errors */
+                slot->type=0;	/* Avoid purify errors */
 		slot->event = os_event_create(NULL);
 		ut_a(slot->event);
 	}
@@ -1641,6 +1644,7 @@ srv_init(void)
 	for (i = 0; i < OS_THREAD_MAX_N; i++) {
 		slot = srv_mysql_table + i;
 		slot->in_use = FALSE;
+		slot->type = 0;
 		slot->event = os_event_create(NULL);
 		ut_a(slot->event);
 	}
@@ -1900,7 +1904,6 @@ srv_conc_exit_innodb(
 	trx_t*	trx)	/* in: transaction object associated with the
 			thread */
 {
-
 	if (srv_thread_concurrency >= 500) {
 	
 		return;
@@ -2004,7 +2007,31 @@ srv_table_reserve_slot_for_mysql(void)
 
 	while (slot->in_use) {
 		i++;
-		ut_a(i < OS_THREAD_MAX_N);
+
+		if (i >= OS_THREAD_MAX_N) {
+
+		        ut_print_timestamp(stderr);
+
+		        fprintf(stderr,
+"  InnoDB: There appear to be %lu MySQL threads currently waiting\n"
+"InnoDB: inside InnoDB, which is the upper limit. Cannot continue operation.\n"
+"InnoDB: We intentionally generate a seg fault to print a stack trace\n"
+"InnoDB: on Linux. But first we print a list of waiting threads.\n", i);
+
+			for (i = 0; i < OS_THREAD_MAX_N; i++) {
+
+			        slot = srv_mysql_table + i;
+
+			        fprintf(stderr,
+"Slot %lu: thread id %lu, type %lu, in use %lu, susp %lu, time %lu\n",
+				  i, (ulint)(slot->id),
+				  slot->type, slot->in_use,
+				  slot->suspended,
+			  (ulint)difftime(ut_time(), slot->suspend_time));
+			}
+
+		        ut_a(0);
+		}
 		
 		slot = srv_mysql_table + i;
 	}
@@ -2141,104 +2168,113 @@ srv_release_mysql_thread_if_suspended(
 	/* not found */
 }
 
-/*************************************************************************
-A thread which wakes up threads whose lock wait may have lasted too long.
-This also prints the info output by various InnoDB monitors. */
+/**********************************************************************
+Sprintfs to a buffer the output of the InnoDB Monitor. */
 
-#ifndef __WIN__
-void*
-#else
-ulint
-#endif
-srv_lock_timeout_and_monitor_thread(
-/*================================*/
-			/* out: a dummy parameter */
-	void*	arg)	/* in: a dummy parameter required by
-			os_thread_create */
+void
+srv_sprintf_innodb_monitor(
+/*=======================*/
+	char*	buf,	/* in/out: buffer which must be at least 4 kB */
+	ulint	len)	/* in: length of the buffer */
 {
-	srv_slot_t*	slot;
-	double		time_elapsed;
-	time_t          current_time;
-	time_t          last_monitor_time;
-	time_t          last_table_monitor_time;
-	ibool		some_waits;
-	double		wait_time;
-	ulint		i;
-
-	UT_NOT_USED(arg);
-	last_monitor_time = time(NULL);
-	last_table_monitor_time = time(NULL);
-loop:
-	srv_lock_timeout_and_monitor_active = TRUE;
+	char*	buf_end	= buf + len - 2000;
+	double	time_elapsed;
+	time_t	current_time;
 
-	/* When someone is waiting for a lock, we wake up every second
-	and check if a timeout has passed for a lock wait */
+	mutex_enter(&srv_innodb_monitor_mutex);
 
-	os_thread_sleep(1000000);		
+	current_time = time(NULL);
 
-	/* In case mutex_exit is not a memory barrier, it is
-	theoretically possible some threads are left waiting though
-	the semaphore is already released. Wake up those threads: */
+	/* We add 0.001 seconds to time_elapsed to prevent division
+	by zero if two users happen to call SHOW INNODB STATUS at the same
+	time */
 	
-	sync_arr_wake_threads_if_sema_free();
+	time_elapsed = difftime(current_time, srv_last_monitor_time)
+			+ 0.001;
 
-	current_time = time(NULL);
+	srv_last_monitor_time = time(NULL);
 
-	time_elapsed = difftime(current_time, last_monitor_time);
-	
-	if (time_elapsed > 15) {
+	ut_a(len >= 4096);	
 
-	    if (srv_print_innodb_monitor) {
+	buf += sprintf(buf, "\n=====================================\n");
 
-	    	last_monitor_time = time(NULL);
-	
-	        printf("=====================================\n");
-		ut_print_timestamp(stdout);
+	ut_sprintf_timestamp(buf);
+	buf = buf + strlen(buf);
 	
-		printf(" INNODB MONITOR OUTPUT\n"
+	buf += sprintf(buf, " INNODB MONITOR OUTPUT\n"
 	       	       "=====================================\n");
-		printf("----------\n"
+
+	buf += sprintf(buf,
+"Per second values calculated from the last %lu seconds\n",
+					(ulint)time_elapsed);
+	       	       
+	buf += sprintf(buf, "----------\n"
 		       "SEMAPHORES\n"
 		       "----------\n");
-		sync_print();
-		printf("------------\n"
+	sync_print(buf, buf_end);
+
+	buf = buf + strlen(buf);
+
+	buf += sprintf(buf, "------------\n"
 		       "TRANSACTIONS\n"
 		       "------------\n");
-		lock_print_info();
-		printf("--------\n"
+	lock_print_info(buf, buf_end);
+	buf = buf + strlen(buf);
+
+	buf += sprintf(buf, "--------\n"
 		       "FILE I/O\n"
 		       "--------\n");
-		os_aio_print();
-		printf("-------------\n"
-		       "INSERT BUFFER\n"
-		       "-------------\n");
-		ibuf_print();
-		printf("---\n"
+	os_aio_print(buf, buf_end);
+	buf = buf + strlen(buf);
+
+	buf += sprintf(buf, "-------------------------------------\n"
+		       "INSERT BUFFER AND ADAPTIVE HASH INDEX\n"
+		       "-------------------------------------\n");
+	ibuf_print(buf, buf_end);
+	buf = buf + strlen(buf);
+
+	ha_print_info(buf, buf_end, btr_search_sys->hash_index);
+	buf = buf + strlen(buf);
+
+	buf += sprintf(buf,
+		"%.2f hash searches/s, %.2f non-hash searches/s\n",
+			(btr_cur_n_sea - btr_cur_n_sea_old)
+						/ time_elapsed,
+			(btr_cur_n_non_sea - btr_cur_n_non_sea_old)
+						/ time_elapsed);
+			btr_cur_n_sea_old = btr_cur_n_sea;
+			btr_cur_n_non_sea_old = btr_cur_n_non_sea;
+
+	buf += sprintf(buf,"---\n"
 		       "LOG\n"
 		       "---\n");
-		log_print();
-		printf("----------------------\n"
+	log_print(buf, buf_end);
+	buf = buf + strlen(buf);
+	
+	buf += sprintf(buf, "----------------------\n"
 		       "BUFFER POOL AND MEMORY\n"
 		       "----------------------\n");
-		printf(
+	buf += sprintf(buf,
 	"Total memory allocated %lu; in additional pool allocated %lu\n",
 				ut_total_allocated_memory,
 				mem_pool_get_reserved(mem_comm_pool));
-		buf_print_io();
-		printf("--------------\n"
+	buf_print_io(buf, buf_end);
+	buf = buf + strlen(buf);
+
+	buf += sprintf(buf, "--------------\n"
 		       "ROW OPERATIONS\n"
 		       "--------------\n");
-		printf(
+	buf += sprintf(buf,
 	"%ld queries inside InnoDB, %ld queries in queue; main thread: %s\n",
 			srv_conc_n_threads, srv_conc_n_waiting_threads,
 			srv_main_thread_op_info);
-		printf(
+	buf += sprintf(buf,
 	"Number of rows inserted %lu, updated %lu, deleted %lu, read %lu\n",
 			srv_n_rows_inserted, 
 			srv_n_rows_updated, 
 			srv_n_rows_deleted, 
 			srv_n_rows_read);
-		printf(
+	buf += sprintf(buf,
 	"%.2f inserts/s, %.2f updates/s, %.2f deletes/s, %.2f reads/s\n",
 			(srv_n_rows_inserted - srv_n_rows_inserted_old)
 						/ time_elapsed,
@@ -2254,9 +2290,71 @@ loop:
 		srv_n_rows_deleted_old = srv_n_rows_deleted;
 		srv_n_rows_read_old = srv_n_rows_read;
 
-		printf("----------------------------\n"
+	buf += sprintf(buf, "----------------------------\n"
 		       "END OF INNODB MONITOR OUTPUT\n"
 		       "============================\n");
+	mutex_exit(&srv_innodb_monitor_mutex);
+}
+
+/*************************************************************************
+A thread which wakes up threads whose lock wait may have lasted too long.
+This also prints the info output by various InnoDB monitors. */
+
+#ifndef __WIN__
+void*
+#else
+ulint
+#endif
+srv_lock_timeout_and_monitor_thread(
+/*================================*/
+			/* out: a dummy parameter */
+	void*	arg)	/* in: a dummy parameter required by
+			os_thread_create */
+{
+	srv_slot_t*	slot;
+	double		time_elapsed;
+	time_t          current_time;
+	time_t		last_table_monitor_time;
+	time_t		last_monitor_time;
+	ibool		some_waits;
+	double		wait_time;
+	char*		buf;
+	ulint		i;
+
+	UT_NOT_USED(arg);
+	srv_last_monitor_time = time(NULL);
+	last_table_monitor_time = time(NULL);
+	last_monitor_time = time(NULL);
+loop:
+	srv_lock_timeout_and_monitor_active = TRUE;
+
+	/* When someone is waiting for a lock, we wake up every second
+	and check if a timeout has passed for a lock wait */
+
+	os_thread_sleep(1000000);		
+
+	/* In case mutex_exit is not a memory barrier, it is
+	theoretically possible some threads are left waiting though
+	the semaphore is already released. Wake up those threads: */
+	
+	sync_arr_wake_threads_if_sema_free();
+
+	current_time = time(NULL);
+
+	time_elapsed = difftime(current_time, last_monitor_time);
+	
+	if (time_elapsed > 15) {
+	    last_monitor_time = time(NULL);
+
+	    if (srv_print_innodb_monitor) {
+
+	    	buf = mem_alloc(100000);
+
+	    	srv_sprintf_innodb_monitor(buf, 100000);
+
+	    	printf("%s", buf);
+
+	    	mem_free(buf);
             }
 
             if (srv_print_innodb_tablespace_monitor
@@ -2491,7 +2589,7 @@ srv_master_thread(
 
 	os_event_set(srv_sys->operational);
 loop:
-	srv_main_thread_op_info = (char *) "reserving kernel mutex";
+	srv_main_thread_op_info = (char*) "reserving kernel mutex";
 
 	n_ios_very_old = log_sys->n_log_ios + buf_pool->n_pages_read
 						+ buf_pool->n_pages_written;
@@ -2507,18 +2605,19 @@ loop:
 	for (i = 0; i < 10; i++) {
 		n_ios_old = log_sys->n_log_ios + buf_pool->n_pages_read
 						+ buf_pool->n_pages_written;
-		srv_main_thread_op_info = (char *) "sleeping";
+		srv_main_thread_op_info = (char*)"sleeping";
 		os_thread_sleep(1000000);
 
 		/* ALTER TABLE in MySQL requires on Unix that the table handler
 		can drop tables lazily after there no longer are SELECT
 		queries to them. */
 
-		srv_main_thread_op_info = (char*) "doing background drop tables";
+		srv_main_thread_op_info =
+					(char*)"doing background drop tables";
 
 		row_drop_tables_for_mysql_in_background();
 
-		srv_main_thread_op_info = (char*) "";
+		srv_main_thread_op_info = (char*)"";
 
 		if (srv_force_recovery >= SRV_FORCE_NO_BACKGROUND) {
 
@@ -2529,8 +2628,9 @@ loop:
 		is issued or the we have specified in my.cnf no flush
 		at transaction commit */
 
-		srv_main_thread_op_info = (char *) "flushing log";
+		srv_main_thread_op_info = (char*)"flushing log";
 		log_flush_up_to(ut_dulint_max, LOG_WAIT_ONE_GROUP);
+		log_flush_to_disk();
 
 		/* If there were less than 10 i/os during the
 		one second sleep, we assume that there is free
@@ -2543,11 +2643,13 @@ loop:
 						+ buf_pool->n_pages_written;
 		if (n_pend_ios < 3 && (n_ios - n_ios_old < 10)) {
 			srv_main_thread_op_info =
-			  (char *) "doing insert buffer merge";
+					(char*)"doing insert buffer merge";
 			ibuf_contract_for_n_pages(TRUE, 5);
 
-			srv_main_thread_op_info = (char *) "flushing log";
+			srv_main_thread_op_info =
+						(char*)"flushing log";
 			log_flush_up_to(ut_dulint_max, LOG_WAIT_ONE_GROUP);
+			log_flush_to_disk();
 		}
 		
 		if (srv_fast_shutdown && srv_shutdown_state > 0) {
@@ -2583,21 +2685,23 @@ loop:
 						+ buf_pool->n_pages_written;
 	if (n_pend_ios < 3 && (n_ios - n_ios_very_old < 200)) {
 
-		srv_main_thread_op_info =(char *) "flushing buffer pool pages";
+		srv_main_thread_op_info = (char*) "flushing buffer pool pages";
 		buf_flush_batch(BUF_FLUSH_LIST, 50, ut_dulint_max);
 
-		srv_main_thread_op_info = (char *) "flushing log";
+		srv_main_thread_op_info = (char*) "flushing log";
 		log_flush_up_to(ut_dulint_max, LOG_WAIT_ONE_GROUP);
+		log_flush_to_disk();
 	}
 
 	/* We run a batch of insert buffer merge every 10 seconds,
 	even if the server were active */
 
-	srv_main_thread_op_info = (char *) "doing insert buffer merge";
+	srv_main_thread_op_info = (char*)"doing insert buffer merge";
 	ibuf_contract_for_n_pages(TRUE, 5);
 
-	srv_main_thread_op_info = (char *) "flushing log";
+	srv_main_thread_op_info = (char*)"flushing log";
 	log_flush_up_to(ut_dulint_max, LOG_WAIT_ONE_GROUP);
+	log_flush_to_disk();
 
 	/* We run a full purge every 10 seconds, even if the server
 	were active */
@@ -2613,15 +2717,16 @@ loop:
 			goto background_loop;
 		}
 
-		srv_main_thread_op_info = (char *) "purging";
+		srv_main_thread_op_info = (char*)"purging";
 		n_pages_purged = trx_purge();
 
 		current_time = time(NULL);
 
 		if (difftime(current_time, last_flush_time) > 1) {
-			srv_main_thread_op_info = (char *) "flushing log";
+			srv_main_thread_op_info = (char*) "flushing log";
 
 		        log_flush_up_to(ut_dulint_max, LOG_WAIT_ONE_GROUP);
+			log_flush_to_disk();
 			last_flush_time = current_time;
 		}
 	}
@@ -2630,25 +2735,25 @@ background_loop:
 	/* In this loop we run background operations when the server
 	is quiet and we also come here about once in 10 seconds */
 
-	srv_main_thread_op_info = (char*) "doing background drop tables";
+	srv_main_thread_op_info = (char*)"doing background drop tables";
 
 	n_tables_to_drop = row_drop_tables_for_mysql_in_background();
 
-	srv_main_thread_op_info = (char*) "";
+	srv_main_thread_op_info = (char*)"";
 	
-	srv_main_thread_op_info = (char*) "flushing buffer pool pages";
+	srv_main_thread_op_info = (char*)"flushing buffer pool pages";
 
 	/* Flush a few oldest pages to make the checkpoint younger */
 
 	n_pages_flushed = buf_flush_batch(BUF_FLUSH_LIST, 10, ut_dulint_max);
 
-	srv_main_thread_op_info = (char*) "making checkpoint";
+	srv_main_thread_op_info = (char*)"making checkpoint";
 
 	/* Make a new checkpoint about once in 10 seconds */
 
 	log_checkpoint(TRUE, FALSE);
 
-	srv_main_thread_op_info = (char *) "reserving kernel mutex";
+	srv_main_thread_op_info = (char*)"reserving kernel mutex";
 
 	mutex_enter(&kernel_mutex);
 	if (srv_activity_count != old_activity_count) {
@@ -2661,11 +2766,11 @@ background_loop:
 	/* The server has been quiet for a while: start running background
 	operations */
 		
-	srv_main_thread_op_info = (char *) "purging";
+	srv_main_thread_op_info = (char*)"purging";
 
 	n_pages_purged = trx_purge();
 
-	srv_main_thread_op_info = (char *) "reserving kernel mutex";
+	srv_main_thread_op_info = (char*)"reserving kernel mutex";
 
 	mutex_enter(&kernel_mutex);
 	if (srv_activity_count != old_activity_count) {
@@ -2674,10 +2779,10 @@ background_loop:
 	}
 	mutex_exit(&kernel_mutex);
 
-	srv_main_thread_op_info = (char *) "doing insert buffer merge";
+	srv_main_thread_op_info = (char*)"doing insert buffer merge";
 	n_bytes_merged = ibuf_contract_for_n_pages(TRUE, 20);
 
-	srv_main_thread_op_info = (char *) "reserving kernel mutex";
+	srv_main_thread_op_info = (char*)"reserving kernel mutex";
 
 	mutex_enter(&kernel_mutex);
 	if (srv_activity_count != old_activity_count) {
@@ -2686,10 +2791,10 @@ background_loop:
 	}
 	mutex_exit(&kernel_mutex);
 	
-	srv_main_thread_op_info = (char *) "flushing buffer pool pages";
+	srv_main_thread_op_info = (char*)"flushing buffer pool pages";
 	n_pages_flushed = buf_flush_batch(BUF_FLUSH_LIST, 100, ut_dulint_max);
 
-	srv_main_thread_op_info = (char *) "reserving kernel mutex";
+	srv_main_thread_op_info = (char*)"reserving kernel mutex";
 
 	mutex_enter(&kernel_mutex);
 	if (srv_activity_count != old_activity_count) {
@@ -2698,15 +2803,14 @@ background_loop:
 	}
 	mutex_exit(&kernel_mutex);
 	
-	srv_main_thread_op_info =
-	  (char *) "waiting for buffer pool flush to end";
+	srv_main_thread_op_info = (char*) "waiting for buffer pool flush to end";
 	buf_flush_wait_batch_end(BUF_FLUSH_LIST);
 
-	srv_main_thread_op_info = (char *) "making checkpoint";
+	srv_main_thread_op_info = (char*)"making checkpoint";
 
 	log_checkpoint(TRUE, FALSE);
 
-	srv_main_thread_op_info = (char *) "reserving kernel mutex";
+	srv_main_thread_op_info = (char*)"reserving kernel mutex";
 
 	mutex_enter(&kernel_mutex);
 	if (srv_activity_count != old_activity_count) {
@@ -2716,7 +2820,7 @@ background_loop:
 	mutex_exit(&kernel_mutex);
 
 	srv_main_thread_op_info =
-	  (char *) "archiving log (if log archive is on)";
+				(char*)"archiving log (if log archive is on)";
 	
 	log_archive_do(FALSE, &n_bytes_archived);
 
@@ -2742,7 +2846,7 @@ background_loop:
 	master thread to wait for more server activity */
 	
 suspend_thread:
-	srv_main_thread_op_info = (char *) "suspending";
+	srv_main_thread_op_info = (char*)"suspending";
 
 	mutex_enter(&kernel_mutex);
 
@@ -2756,7 +2860,7 @@ suspend_thread:
 
 	mutex_exit(&kernel_mutex);
 
-	srv_main_thread_op_info = (char *) "waiting for server activity";
+	srv_main_thread_op_info = (char*)"waiting for server activity";
 
 	os_event_wait(event);