InnoDB: send diagnostic output to stderr or files

instead of stdout or fixed-size memory buffers

4 files changed, 123 insertions, 160 deletions

diff --git a/innobase/buf/buf0buf.c b/innobase/buf/buf0buf.c
index e2661725912..b744430a76e 100644
--- a/innobase/buf/buf0buf.c
+++ b/innobase/buf/buf0buf.c
@@ -348,19 +348,12 @@ buf_page_print(
 	dict_index_t*	index;
 	ulint		checksum;
 	ulint		old_checksum;
-	char*		buf;
-	
-	buf = mem_alloc(4 * UNIV_PAGE_SIZE);
-
-	ut_sprintf_buf(buf, read_buf, UNIV_PAGE_SIZE);
 
 	ut_print_timestamp(stderr);
-	fprintf(stderr,
-	"  InnoDB: Page dump in ascii and hex (%lu bytes):\n%s",
-					(ulint)UNIV_PAGE_SIZE, buf);
-	fprintf(stderr, "InnoDB: End of page dump\n");
-
-	mem_free(buf);
+	fprintf(stderr, "  InnoDB: Page dump in ascii and hex (%lu bytes):\n",
+		(ulint)UNIV_PAGE_SIZE);
+	ut_print_buf(stderr, read_buf, UNIV_PAGE_SIZE);
+	fputs("InnoDB: End of page dump\n", stderr);
 
 	checksum = buf_calc_page_new_checksum(read_buf);
 	old_checksum = buf_calc_page_old_checksum(read_buf);
@@ -407,18 +400,17 @@ buf_page_print(
 		        index = dict_index_find_on_id_low(
 					btr_page_get_index_id(read_buf));
 		        if (index) {
-			        fprintf(stderr,
-					"InnoDB: and table %s index %s\n",
-						index->table_name,
-						index->name);
+				fputs("InnoDB: (", stderr);
+				dict_index_name_print(stderr, index);
+				fputs(")\n", stderr);
 			}
 		}
 	  
 	} else if (fil_page_get_type(read_buf) == FIL_PAGE_INODE) {
-		fprintf(stderr, "InnoDB: Page may be an 'inode' page\n");
+		fputs("InnoDB: Page may be an 'inode' page\n", stderr);
 	} else if (fil_page_get_type(read_buf) == FIL_PAGE_IBUF_FREE_LIST) {
-		fprintf(stderr,
-		"InnoDB: Page may be an insert buffer free list page\n");
+		fputs("InnoDB: Page may be an insert buffer free list page\n",
+			stderr);
 	}
 }
 
@@ -1464,8 +1456,8 @@ buf_page_create(
 	/* If we get here, the page was not in buf_pool: init it there */
 
 	if (buf_debug_prints) {
-		printf("Creating space %lu page %lu to buffer\n", space,
-								offset);
+		fprintf(stderr, "Creating space %lu page %lu to buffer\n",
+			space, offset);
 	}
 
 	block = free_block;
@@ -1519,8 +1511,6 @@ buf_page_io_complete(
 /*=================*/
 	buf_block_t*	block)	/* in: pointer to the block in question */
 {
-	dict_index_t*	index;
-	dulint		id;
 	ulint		io_type;
 	ulint		read_page_no;
 	
@@ -1551,17 +1541,17 @@ buf_page_io_complete(
 		"InnoDB: Database page corruption on disk or a failed\n"
 		"InnoDB: file read of page %lu.\n", block->offset);
 			  
-		  	fprintf(stderr,
-		"InnoDB: You may have to recover from a backup.\n");
+			fputs(
+		"InnoDB: You may have to recover from a backup.\n", stderr);
 
 			buf_page_print(block->frame);
 
 		  	fprintf(stderr,
 		"InnoDB: Database page corruption on disk or a failed\n"
 		"InnoDB: file read of page %lu.\n", block->offset);
-		  	fprintf(stderr,
-		"InnoDB: You may have to recover from a backup.\n");
-			fprintf(stderr,
+			fputs(
+		"InnoDB: You may have to recover from a backup.\n", stderr);
+			fputs(
 		"InnoDB: It is also possible that your operating\n"
 		"InnoDB: system has corrupted its own file cache\n"
 		"InnoDB: and rebooting your computer removes the\n"
@@ -1572,12 +1562,13 @@ buf_page_io_complete(
 		"InnoDB: the corrupt table. You can use CHECK\n"
 		"InnoDB: TABLE to scan your table for corruption.\n"
 		"InnoDB: Look also at section 6.1 of\n"
-		"InnoDB: http://www.innodb.com/ibman.html about\n"
-		"InnoDB: forcing recovery.\n");
+		"InnoDB: http://www.innodb.com/ibman.php about\n"
+		"InnoDB: forcing recovery.\n", stderr);
 			  
 			if (srv_force_recovery < SRV_FORCE_IGNORE_CORRUPT) {
-				fprintf(stderr,
-	"InnoDB: Ending processing because of a corrupt database page.\n");
+				fputs(
+	"InnoDB: Ending processing because of a corrupt database page.\n",
+					stderr);
 		  		exit(1);
 		  	}
 		}
@@ -1619,7 +1610,7 @@ buf_page_io_complete(
 		rw_lock_x_unlock_gen(&(block->read_lock), BUF_IO_READ);
 
 		if (buf_debug_prints) {
-			printf("Has read ");
+			fputs("Has read ", stderr);
 		}
 	} else {
 		ut_ad(io_type == BUF_IO_WRITE);
@@ -1634,29 +1625,15 @@ buf_page_io_complete(
 		buf_pool->n_pages_written++;
 
 		if (buf_debug_prints) {
-			printf("Has written ");
+			fputs("Has written ", stderr);
 		}
 	}
 	
 	mutex_exit(&(buf_pool->mutex));
 
 	if (buf_debug_prints) {
-		printf("page space %lu page no %lu", block->space,
-								block->offset);
-		id = btr_page_get_index_id(block->frame);
-
-		index = NULL;
-		/* The following can cause deadlocks if used: */
-		/*
-		index = dict_index_get_if_in_cache(id);
-
-  		if (index) {
-			printf(" index name %s table %s", index->name,
-							index->table->name);
-		}
-		*/
-
-		printf("\n");
+		fprintf(stderr, "page space %lu page no %lu\n",
+			block->space, block->offset);
 	}
 }
 
@@ -1757,14 +1734,14 @@ buf_validate(void)
  	}
 
 	if (n_lru + n_free > buf_pool->curr_size) {
-		printf("n LRU %lu, n free %lu\n", n_lru, n_free);
+		fprintf(stderr, "n LRU %lu, n free %lu\n", n_lru, n_free);
 		ut_error;
 	}
 
 	ut_a(UT_LIST_GET_LEN(buf_pool->LRU) == n_lru);
 	if (UT_LIST_GET_LEN(buf_pool->free) != n_free) {
-		printf("Free list len %lu, free blocks %lu\n",
-		    UT_LIST_GET_LEN(buf_pool->free), n_free);
+		fprintf(stderr, "Free list len %lu, free blocks %lu\n",
+			UT_LIST_GET_LEN(buf_pool->free), n_free);
 		ut_error;
 	}
 	ut_a(UT_LIST_GET_LEN(buf_pool->flush_list) == n_flush);
@@ -1807,22 +1784,24 @@ buf_print(void)
 
 	mutex_enter(&(buf_pool->mutex));
 	
-	printf("buf_pool size %lu \n", size);
-	printf("database pages %lu \n", UT_LIST_GET_LEN(buf_pool->LRU));
-	printf("free pages %lu \n", UT_LIST_GET_LEN(buf_pool->free));
-	printf("modified database pages %lu \n",
-				UT_LIST_GET_LEN(buf_pool->flush_list));
-
-	printf("n pending reads %lu \n", buf_pool->n_pend_reads);
-
-	printf("n pending flush LRU %lu list %lu single page %lu\n",
+	fprintf(stderr,
+		"buf_pool size %lu \n"
+		"database pages %lu \n"
+		"free pages %lu \n"
+		"modified database pages %lu \n"
+		"n pending reads %lu \n"
+		"n pending flush LRU %lu list %lu single page %lu\n"
+		"pages read %lu, created %lu, written %lu\n",
+		size,
+		UT_LIST_GET_LEN(buf_pool->LRU),
+		UT_LIST_GET_LEN(buf_pool->free),
+		UT_LIST_GET_LEN(buf_pool->flush_list),
+		buf_pool->n_pend_reads,
 		buf_pool->n_flush[BUF_FLUSH_LRU],
 		buf_pool->n_flush[BUF_FLUSH_LIST],
-		buf_pool->n_flush[BUF_FLUSH_SINGLE_PAGE]);
-
-	printf("pages read %lu, created %lu, written %lu\n",
-			buf_pool->n_pages_read, buf_pool->n_pages_created,
-						buf_pool->n_pages_written);
+		buf_pool->n_flush[BUF_FLUSH_SINGLE_PAGE],
+		buf_pool->n_pages_read, buf_pool->n_pages_created,
+		buf_pool->n_pages_written);
 
 	/* Count the number of blocks belonging to each index in the buffer */
 	
@@ -1865,15 +1844,16 @@ buf_print(void)
 	for (i = 0; i < n_found; i++) {
 		index = dict_index_get_if_in_cache(index_ids[i]);
 
-		printf("Block count for index %lu in buffer is about %lu",
+		fprintf(stderr,
+			"Block count for index %lu in buffer is about %lu",
 			ut_dulint_get_low(index_ids[i]), counts[i]);
 
 		if (index) {
-			printf(" index name %s table %s", index->name,
-				index->table->name);
+			putc(' ', stderr);
+			dict_index_name_print(stderr, index);
 		}
 
-		printf("\n");
+		putc('\n', stderr);
 	}
 	
 	mem_free(index_ids);
@@ -1924,44 +1904,29 @@ Prints info of the buffer i/o. */
 void
 buf_print_io(
 /*=========*/
-	char*	buf,	/* in/out: buffer where to print */
-	char*	buf_end)/* in: buffer end */
+	FILE*	file)	/* in/out: buffer where to print */
 {
 	time_t	current_time;
 	double	time_elapsed;
 	ulint	size;
 	
 	ut_ad(buf_pool);
-
-	if (buf_end - buf < 400) {
-
-		return;
-	}
-
 	size = buf_pool_get_curr_size() / UNIV_PAGE_SIZE;
 
 	mutex_enter(&(buf_pool->mutex));
 	
-	buf += sprintf(buf,
-		"Buffer pool size   %lu\n", size);
-	buf += sprintf(buf,
-		"Free buffers       %lu\n", UT_LIST_GET_LEN(buf_pool->free));
-	buf += sprintf(buf,
-		"Database pages     %lu\n", UT_LIST_GET_LEN(buf_pool->LRU));
-/*
-	buf += sprintf(buf,
-		"Lock heap buffers  %lu\n", buf_pool->n_lock_heap_pages);
-	buf += sprintf(buf,
-		"Hash index buffers %lu\n", buf_pool->n_adaptive_hash_pages);
-*/
-	buf += sprintf(buf,
-		"Modified db pages  %lu\n",
-				UT_LIST_GET_LEN(buf_pool->flush_list));
-
-	buf += sprintf(buf, "Pending reads %lu \n", buf_pool->n_pend_reads);
-
-	buf += sprintf(buf,
+	fprintf(file,
+		"Buffer pool size   %lu\n"
+		"Free buffers       %lu\n"
+		"Database pages     %lu\n"
+		"Modified db pages  %lu\n"
+		"Pending reads %lu \n"
 		"Pending writes: LRU %lu, flush list %lu, single page %lu\n",
+		size,
+		UT_LIST_GET_LEN(buf_pool->free),
+		UT_LIST_GET_LEN(buf_pool->LRU),
+		UT_LIST_GET_LEN(buf_pool->flush_list),
+		buf_pool->n_pend_reads,
 		buf_pool->n_flush[BUF_FLUSH_LRU]
 				+ buf_pool->init_flush[BUF_FLUSH_LRU],
 		buf_pool->n_flush[BUF_FLUSH_LIST]
@@ -1973,10 +1938,11 @@ buf_print_io(
 						buf_pool->last_printout_time);
 	buf_pool->last_printout_time = current_time;
 
-	buf += sprintf(buf, "Pages read %lu, created %lu, written %lu\n",
-			buf_pool->n_pages_read, buf_pool->n_pages_created,
-						buf_pool->n_pages_written);
-	buf += sprintf(buf, "%.2f reads/s, %.2f creates/s, %.2f writes/s\n",
+	fprintf(file,
+		"Pages read %lu, created %lu, written %lu\n"
+		"%.2f reads/s, %.2f creates/s, %.2f writes/s\n",
+		buf_pool->n_pages_read, buf_pool->n_pages_created,
+		buf_pool->n_pages_written,
 		(buf_pool->n_pages_read - buf_pool->n_pages_read_old)
 		/ time_elapsed,
 		(buf_pool->n_pages_created - buf_pool->n_pages_created_old)
@@ -1985,14 +1951,14 @@ buf_print_io(
 		/ time_elapsed);
 
 	if (buf_pool->n_page_gets > buf_pool->n_page_gets_old) {
-		buf += sprintf(buf, "Buffer pool hit rate %lu / 1000\n",
+		fprintf(file, "Buffer pool hit rate %lu / 1000\n",
 		1000
 		- ((1000 *
 		    (buf_pool->n_pages_read - buf_pool->n_pages_read_old))
 		/ (buf_pool->n_page_gets - buf_pool->n_page_gets_old)));
 	} else {
-		buf += sprintf(buf,
-			"No buffer pool page gets since the last printout\n");
+		fputs("No buffer pool page gets since the last printout\n",
+			file);
 	}
 
 	buf_pool->n_page_gets_old = buf_pool->n_page_gets;
@@ -2039,8 +2005,9 @@ buf_all_freed(void)
 
 			if (!buf_flush_ready_for_replace(block)) {
 
-			    	/* printf("Page %lu %lu still fixed or dirty\n",
-			    		block->space, block->offset); */
+				fprintf(stderr,
+					"Page %lu %lu still fixed or dirty\n",
+					block->space, block->offset);
 			    	ut_error;
 			}
 		}
diff --git a/innobase/buf/buf0flu.c b/innobase/buf/buf0flu.c
index 66c9bb605dc..7456e5d6f61 100644
--- a/innobase/buf/buf0flu.c
+++ b/innobase/buf/buf0flu.c
@@ -189,7 +189,7 @@ buf_flush_write_complete(
 		buf_pool->LRU_flush_ended++;
 	}
 
-	/* 	printf("n pending flush %lu\n",
+	/* fprintf(stderr, "n pending flush %lu\n",
 		buf_pool->n_flush[block->flush_type]); */
 
 	if ((buf_pool->n_flush[block->flush_type] == 0)
@@ -411,8 +411,8 @@ buf_flush_write_block_low(
 	ut_ad(!ut_dulint_is_zero(block->newest_modification));
 
 #ifdef UNIV_LOG_DEBUG
-	printf(
-	"Warning: cannot force log to disk in the log debug version!\n");
+	fputs("Warning: cannot force log to disk in the log debug version!\n",
+		stderr);
 #else
 	/* Force the log to the disk before writing the modified block */
 	log_write_up_to(block->newest_modification, LOG_WAIT_ALL_GROUPS, TRUE);
@@ -489,8 +489,9 @@ buf_flush_try_page(
 		}
 
 		if (buf_debug_prints) {
-			printf("Flushing page space %lu, page no %lu \n",
-					block->space, block->offset);
+			fprintf(stderr,
+				"Flushing page space %lu, page no %lu \n",
+				block->space, block->offset);
 		}
 
 		buf_flush_write_block_low(block);
@@ -548,7 +549,7 @@ buf_flush_try_page(
 		rw_lock_s_lock_gen(&(block->lock), BUF_IO_WRITE);
 
 		if (buf_debug_prints) {
-			printf(
+			fprintf(stderr,
 			"Flushing single page space %lu, page no %lu \n",
 						block->space, block->offset);
 		}
@@ -592,7 +593,7 @@ buf_flush_try_neighbors(
 		high = offset + 1;
 	}
 
-	/* printf("Flush area: low %lu high %lu\n", low, high); */
+	/* fprintf(stderr, "Flush area: low %lu high %lu\n", low, high); */
 	
 	if (high > fil_space_get_size(space)) {
 		high = fil_space_get_size(space);
@@ -739,7 +740,7 @@ buf_flush_batch(
 				page_count +=
 					buf_flush_try_neighbors(space, offset,
 								flush_type);
-				/* printf(
+				/* fprintf(stderr,
 				"Flush type %lu, page no %lu, neighb %lu\n",
 				flush_type, offset,
 				page_count - old_page_count); */
@@ -779,15 +780,12 @@ buf_flush_batch(
 	buf_flush_buffered_writes();
 
 	if (buf_debug_prints && page_count > 0) {
-		if (flush_type == BUF_FLUSH_LRU) {
-			printf("Flushed %lu pages in LRU flush\n",
-						page_count);
-		} else if (flush_type == BUF_FLUSH_LIST) {
-			printf("Flushed %lu pages in flush list flush\n",
-						page_count);
-		} else {
-			ut_error;
-		}
+		ut_a(flush_type == BUF_FLUSH_LRU
+			|| flush_type == BUF_FLUSH_LIST);
+		fprintf(stderr, flush_type == BUF_FLUSH_LRU
+			? "Flushed %lu pages in LRU flush\n"
+			: "Flushed %lu pages in flush list flush\n",
+			page_count);
 	}
 	
 	return(page_count);
diff --git a/innobase/buf/buf0lru.c b/innobase/buf/buf0lru.c
index 0128ee87871..0ced7e23abe 100644
--- a/innobase/buf/buf0lru.c
+++ b/innobase/buf/buf0lru.c
@@ -126,7 +126,7 @@ buf_LRU_search_and_free_block(
 		if (buf_flush_ready_for_replace(block)) {
 
 			if (buf_debug_prints) {
-				printf(
+				fprintf(stderr,
 				"Putting space %lu page %lu to free list\n",
 					block->space, block->offset);
 			}
@@ -301,26 +301,20 @@ loop:
 		fprintf(stderr,
 		"InnoDB: Warning: difficult to find free blocks from\n"
 		"InnoDB: the buffer pool (%lu search iterations)! Consider\n"
-		"InnoDB: increasing the buffer pool size.\n",
-						n_iterations);
-		fprintf(stderr,
+		"InnoDB: increasing the buffer pool size.\n"
 		"InnoDB: It is also possible that in your Unix version\n"
 		"InnoDB: fsync is very slow, or completely frozen inside\n"
 		"InnoDB: the OS kernel. Then upgrading to a newer version\n"
 		"InnoDB: of your operating system may help. Look at the\n"
-		"InnoDB: number of fsyncs in diagnostic info below.\n");
-
-		fprintf(stderr,
-		"InnoDB: Pending flushes (fsync) log: %lu; buffer pool: %lu\n",
-	       			fil_n_pending_log_flushes,
-				fil_n_pending_tablespace_flushes);
-		fprintf(stderr,
-	"InnoDB: %lu OS file reads, %lu OS file writes, %lu OS fsyncs\n",
-			os_n_file_reads, os_n_file_writes, os_n_fsyncs);
-
-		fprintf(stderr,
+		"InnoDB: number of fsyncs in diagnostic info below.\n"
+		"InnoDB: Pending flushes (fsync) log: %lu; buffer pool: %lu\n"
+		"InnoDB: %lu OS file reads, %lu OS file writes, %lu OS fsyncs\n"
 		"InnoDB: Starting InnoDB Monitor to print further\n"
-		"InnoDB: diagnostics to the standard output.\n");
+		"InnoDB: diagnostics to the standard output.\n",
+			n_iterations,
+			fil_n_pending_log_flushes,
+			fil_n_pending_tablespace_flushes,
+			os_n_file_reads, os_n_file_writes, os_n_fsyncs);
 
 		mon_value_was = srv_print_innodb_monitor;
 		started_monitor = TRUE;
@@ -797,7 +791,7 @@ buf_LRU_print(void)
 	ut_ad(buf_pool);
 	mutex_enter(&(buf_pool->mutex));
 
-	printf("Pool ulint clock %lu\n", buf_pool->ulint_clock);
+	fprintf(stderr, "Pool ulint clock %lu\n", buf_pool->ulint_clock);
 
 	block = UT_LIST_GET_FIRST(buf_pool->LRU);
 
@@ -805,37 +799,37 @@ buf_LRU_print(void)
 
 	while (block != NULL) {
 
-		printf("BLOCK %lu ", block->offset);
+		fprintf(stderr, "BLOCK %lu ", block->offset);
 
 		if (block->old) {
-			printf("old ");
+			fputs("old ", stderr);
 		}
 
 		if (block->buf_fix_count) {
-			printf("buffix count %lu ", block->buf_fix_count);
+			fprintf(stderr, "buffix count %lu ",
+				block->buf_fix_count);
 		}
 
 		if (block->io_fix) {
-			printf("io_fix %lu ", block->io_fix);
+			fprintf(stderr, "io_fix %lu ", block->io_fix);
 		}
 
 		if (ut_dulint_cmp(block->oldest_modification,
 				ut_dulint_zero) > 0) {
-			printf("modif. ");
+			fputs("modif. ", stderr);
 		}
 
-		printf("LRU pos %lu ", block->LRU_position);
-		
 		frame = buf_block_get_frame(block);
 
-		printf("type %lu ", fil_page_get_type(frame));
-		printf("index id %lu ", ut_dulint_get_low(
-					btr_page_get_index_id(frame)));
+		fprintf(stderr, "LRU pos %lu type %lu index id %lu ",
+			block->LRU_position,
+			fil_page_get_type(frame),
+			ut_dulint_get_low(btr_page_get_index_id(frame)));
 
 		block = UT_LIST_GET_NEXT(LRU, block);
-		len++;
-		if (len % 10 == 0) {
-			printf("\n");
+		if (++len == 10) {
+			len = 0;
+			putc('\n', stderr);
 		}
 	}
 
diff --git a/innobase/buf/buf0rea.c b/innobase/buf/buf0rea.c
index 475a5bd9cbd..83397c9c7fa 100644
--- a/innobase/buf/buf0rea.c
+++ b/innobase/buf/buf0rea.c
@@ -81,7 +81,8 @@ buf_read_page_low(
 		log mutex: the read must be handled before other reads
 		which might incur ibuf operations and thus write to the log */
 
-		printf("Log debug: reading replicate page in sync mode\n");
+		fputs("Log debug: reading replicate page in sync mode\n",
+			stderr);
 
 		sync = TRUE;
 	}
@@ -101,7 +102,8 @@ buf_read_page_low(
 
 	if (block != NULL) {
 		if (buf_debug_prints) {
-			printf("Posting read request for page %lu, sync %lu\n",
+			fprintf(stderr,
+			"Posting read request for page %lu, sync %lu\n",
 				offset, sync);
 		}
 
@@ -241,8 +243,8 @@ buf_read_ahead_random(
 	os_aio_simulated_wake_handler_threads();
 
 	if (buf_debug_prints && (count > 0)) {
-	
-		printf("Random read-ahead space %lu offset %lu pages %lu\n",
+		fprintf(stderr,
+			"Random read-ahead space %lu offset %lu pages %lu\n",
 						space, offset, count);
 	}
 
@@ -499,7 +501,7 @@ buf_read_ahead_linear(
 	buf_flush_free_margin();
 
 	if (buf_debug_prints && (count > 0)) {
-		printf(
+		fprintf(stderr,
 		"LINEAR read-ahead space %lu offset %lu pages %lu\n",
 		space, offset, count);
 	}
@@ -548,7 +550,8 @@ buf_read_ibuf_merge_pages(
 	buf_flush_free_margin();
 
 	if (buf_debug_prints) {
-		printf("Ibuf merge read-ahead space %lu pages %lu\n",
+		fprintf(stderr,
+			"Ibuf merge read-ahead space %lu pages %lu\n",
 							space, n_stored);
 	}
 }
@@ -611,6 +614,7 @@ buf_read_recv_pages(
 	buf_flush_free_margin();
 
 	if (buf_debug_prints) {
-		printf("Recovery applies read-ahead pages %lu\n", n_stored);
+		fprintf(stderr,
+			"Recovery applies read-ahead pages %lu\n", n_stored);
 	}
 }