fix bugs, modify printf for statistic information

Author: trdtnguyen

storage/innobase/buf/buf0flu.cc

@@ -61,6 +61,9 @@ Created 11/11/1995 Heikki Tuuri
 static const int buf_flush_page_cleaner_priority = -20;
 #endif /* UNIV_LINUX */
 
+#if defined(UNIV_TRACE_FLUSH_TIME)
+extern ulint gb_flush_time;
+#endif
 #if defined(UNIV_PMEMOBJ_BUF)
 #include "my_pmemobj.h"
 #include <libpmemobj.h>
@@ -1187,6 +1190,12 @@ buf_flush_page(
 
 	bool	is_uncompressed;
 
+#if defined(UNIV_TRACE_FLUSH_TIME)
+	ulint start_time;
+	ulint end_time;
+
+	start_time = ut_time_ms();
+#endif
 	is_uncompressed = (buf_page_get_state(bpage) == BUF_BLOCK_FILE_PAGE);
 	ut_ad(is_uncompressed == (block_mutex != &buf_pool->zip_mutex));
 
@@ -1278,6 +1287,11 @@ buf_flush_page(
 		//printf(" END buf_flush_write_block_low ] ");
 	}
 
+#if defined(UNIV_TRACE_FLUSH_TIME)
+	end_time = ut_time_ms();
+    gb_flush_time += (end_time - start_time);
+#endif 
+
 	return(flush);
 }
 
@@ -4109,7 +4123,7 @@ DECLARE_THREAD(pm_flusher_worker)(
 
 	mutex_enter(&flusher->mutex);
 	flusher->n_workers--;
-	printf("close a worker, current open workers %zu, n_requested/size = %zu/%zu/%zu is_running = %d\n", flusher->n_workers, flusher->n_requested, flusher->size, flusher->is_running);
+	//printf("close a worker, current open workers %zu, n_requested/size = %zu/%zu/%zu is_running = %d\n", flusher->n_workers, flusher->n_requested, flusher->size, flusher->is_running);
 	if (flusher->n_workers == 0) {
 		printf("The last worker is closing\n");
 		//os_event_set(flusher->is_all_closed);

storage/innobase/handler/ha_innodb.cc

@@ -3732,6 +3732,9 @@ innobase_init(
 	if (!srv_pmem_n_flush_threads) {
 		srv_pmem_n_flush_threads = 8;
 	}
+	if (!srv_pmem_flush_threshold) {
+		srv_pmem_flush_threshold = srv_pmem_n_flush_threads - 2;
+	}
 #endif 
 #if defined (UNIV_PMEMOBJ_BUF_PARTITION)
 	if (!srv_pmem_n_space_bits) {
@@ -19510,6 +19513,11 @@ static MYSQL_SYSVAR_ULONG(pmem_n_flush_threads, srv_pmem_n_flush_threads,
   "Number of threads in flusher, from 1 to 64, default is 8.",
   NULL, NULL, 8, 1, 64, 0);
 
+static MYSQL_SYSVAR_ULONG(pmem_flush_threshold, srv_pmem_flush_threshold,
+  PLUGIN_VAR_RQCMDARG | PLUGIN_VAR_READONLY,
+  "If the pointer assign in thread flusher larger than this threshold. The batch flush is trigger, from 1 to 64, default is number of flusher threads - 2.",
+  NULL, NULL, 6, 1, 64, 0);
+
 #endif
 
 #if defined (UNIV_PMEMOBJ_BUF_PARTITION)
@@ -20359,6 +20367,7 @@ static struct st_mysql_sys_var* innobase_system_variables[]= {
 #endif
 #if defined (UNIV_PMEMOBJ_BUF_FLUSHER)
   MYSQL_SYSVAR(pmem_n_flush_threads),
+  MYSQL_SYSVAR(pmem_flush_threshold),
 #endif 
 #if defined (UNIV_PMEMOBJ_BUF_PARTITION)
   MYSQL_SYSVAR(pmem_n_space_bits),

storage/innobase/include/my_pmemobj.h

@@ -643,12 +643,15 @@ hash_f1(
 @S			[in]: number of bits present space_no
 @P			[in]: number of bits present max number of pages per space on a bucket, this value is log2(page_per_bucket)
  * */
+//Use this funciton for DEBUG only
 //#define PMEM_LESS_BUCKET_HASH_KEY(hashed, space, page)\
 //   hash_f1(hashed, space, page,\
 //		   	PMEM_N_BUCKETS,\
 //		   	PMEM_N_BUCKET_BITS,\
 //		   	PMEM_N_SPACE_BITS,\
 //		   	PMEM_PAGE_PER_BUCKET_BITS) 
+
+//Use this macro for production build 
 #define PMEM_LESS_BUCKET_HASH_KEY(hashed, space, page)\
    	PARTITION_FUNC1(hashed, space, page,\
 		   	PMEM_N_BUCKETS,\

storage/innobase/include/srv0srv.h

@@ -276,6 +276,7 @@ extern ulong	srv_pmem_buf_bucket_size;
 #endif
 #if defined(UNIV_PMEMOBJ_BUF_FLUSHER)
 extern ulong	srv_pmem_n_flush_threads;
+extern ulong	srv_pmem_flush_threshold;
 #endif
 #if defined (UNIV_PMEMOBJ_BUF_PARTITION)
 extern ulong	srv_pmem_n_space_bits;

storage/innobase/pmem/pmem0buf.cc

@@ -32,16 +32,18 @@ static uint64_t PMEM_N_FLUSH_THREADS;
 //set this to large number to eliminate 
 //static uint64_t PMEM_PAGE_PER_BUCKET_BITS=32;
 
+// 1 < this_value < flusher->size (32)
+//static uint64_t PMEM_FLUSHER_WAKE_THRESHOLD=5;
+static uint64_t PMEM_FLUSHER_WAKE_THRESHOLD=30;
+
+static FILE* debug_file = fopen("part_debug.txt","a");
+
 #if defined (UNIV_PMEMOBJ_BUF_PARTITION)
 //256 buckets => 8 bits, max 32 spaces => 5 bits => need 3 = 8 - 5 bits
 static uint64_t PMEM_N_BUCKET_BITS = 8;
 static uint64_t PMEM_N_SPACE_BITS = 5;
 static uint64_t PMEM_PAGE_PER_BUCKET_BITS=10;
-// 1 < this_value < flusher->size
-//static uint64_t PMEM_FLUSHER_WAKE_THRESHOLD=5;
-static uint64_t PMEM_FLUSHER_WAKE_THRESHOLD=2;
 
-static FILE* debug_file = fopen("part_debug.txt","w");
 
 /*
  * This is the "clear" version of hash function, use it for debugging 
@@ -111,6 +113,7 @@ pm_wrapper_buf_alloc_or_open(
 	PMEM_BUF_FLUSH_PCT = srv_pmem_buf_flush_pct;
 #if defined (UNIV_PMEMOBJ_BUF_FLUSHER)
 	PMEM_N_FLUSH_THREADS= srv_pmem_n_flush_threads;
+	PMEM_FLUSHER_WAKE_THRESHOLD = srv_pmem_flush_threshold;
 #endif
 
 #if defined (UNIV_PMEMOBJ_BUF_PARTITION)
@@ -200,7 +203,7 @@ pm_wrapper_buf_alloc_or_open(
 	pmw->pbuf->cur_free_param = 0; //start with the 0
 
 	//Open file 
-	pmw->pbuf->deb_file = fopen("pmem_debug.txt","w");
+	pmw->pbuf->deb_file = fopen("pmem_debug.txt","a");
 
 //	////test for recovery
 //	printf("========== > Test for recovery\n");
@@ -2310,7 +2313,7 @@ pm_buf_resume_flushing(
 
 	for (i = 0; i < PMEM_N_BUCKETS; i++) {
 #if defined (UNIV_PMEMOBJ_BUF_RECOVERY_DEBUG)
-		printf ("\n====>resuming flush hash %zu\n", i);
+		//printf ("\n====>resuming flush hash %zu\n", i);
 #endif
 		TOID_ASSIGN(cur_list, (D_RW(buf->buckets)[i]).oid);
 		phashlist = D_RW(cur_list);
@@ -2471,7 +2474,12 @@ pm_buf_assign_flusher(
 			//delay calling flush up to a threshold
 			//printf("trigger worker...\n");
 			//if (flusher->n_requested == flusher->size - 2) {
-			if (flusher->n_requested == PMEM_FLUSHER_WAKE_THRESHOLD) {
+			//if (flusher->n_requested == PMEM_FLUSHER_WAKE_THRESHOLD) {
+			if (flusher->n_requested >= PMEM_FLUSHER_WAKE_THRESHOLD) {
+#if defined (UNIV_PMEMOBJ_BUF_RECOVERY_DEBUG)
+			printf("\n in [1.1] try to trigger flusher list_id = %zu\n", phashlist->list_id);
+#endif
+			
 				os_event_set(flusher->is_req_not_empty);
 			}
 
@@ -2560,6 +2568,9 @@ void pm_buf_bucket_stat_init(PMEM_BUF* pbuf) {
 	pbuf->bucket_stats = arr;
 }
 
+/*
+ *Print statistic infomation for all hashed lists
+ * */
 void pm_buf_stat_print_all(PMEM_BUF* pbuf) {
 	ulint i;
 	PMEM_BUCKET_STAT* arr = pbuf->bucket_stats;
@@ -2592,6 +2603,10 @@ void pm_buf_stat_print_all(PMEM_BUF* pbuf) {
 			sumstat.n_writes, sumstat.n_overwrites, sumstat.n_reads, sumstat.n_reads_hit, sumstat.n_reads_flushing, sumstat.max_linked_lists, sumstat.n_flushed_lists);
 	fprintf(pbuf->deb_file, "\n==========\n");
 
+	fprintf(debug_file, "\n==========\n Statistic info:\n n_writes n_overwrites n_reads n_reads_hit n_reads_flushing max_linked_lists n_flushed_lists \n %zu %zu %zu %zu %zu %zu %zu \n",
+			sumstat.n_writes, sumstat.n_overwrites, sumstat.n_reads, sumstat.n_reads_hit, sumstat.n_reads_flushing, sumstat.max_linked_lists, sumstat.n_flushed_lists);
+	fprintf(pbuf->deb_file, "\n==========\n");
+
 }
 
 #endif //UNIV_PMEMOBJ_STAT

storage/innobase/srv/srv0srv.cc

@@ -209,6 +209,7 @@ ulong	srv_pmem_buf_bucket_size	= 256;
 #endif 
 #if defined(UNIV_PMEMOBJ_BUF_FLUSHER)
 ulong	srv_pmem_n_flush_threads	= 8;
+ulong	srv_pmem_flush_threshold	= 6;
 #endif
 #if defined (UNIV_PMEMOBJ_BUF_PARTITION)
 ulong	srv_pmem_n_space_bits	= 5;

storage/innobase/srv/srv0start.cc

@@ -172,6 +172,11 @@ enum srv_shutdown_t	srv_shutdown_state = SRV_SHUTDOWN_NONE;
 
 /** Files comprising the system tablespace */
 static pfs_os_file_t	files[1000];
+
+#if defined (UNIV_TRACE_FLUSH_TIME)
+ulint gb_flush_time = 0;
+FILE* gb_trace_file = fopen("trace_flush.txt","a");
+#endif 
 #ifdef UNIV_NVM_LOG
 //tdnguyen
 /** global PMEM_FILE_COLL object*/
@@ -1775,6 +1780,7 @@ innobase_start_or_create_for_mysql(void)
 	    "; n_buckets=" << srv_pmem_buf_n_buckets <<
 	#ifdef UNIV_PMEMOBJ_BUF_FLUSHER
 	    "; n_flush_threads=" << srv_pmem_n_flush_threads <<
+	    "; flush_threshold=" << srv_pmem_flush_threshold <<
 	#endif
 	    "; n_slots_per_seg=" << srv_aio_n_slots_per_seg <<
 	    "; flush_pct=" << srv_pmem_buf_flush_pct <<
@@ -1972,8 +1978,9 @@ innobase_start_or_create_for_mysql(void)
 	os_thread_create(pm_buf_flush_list_cleaner_coordinator, NULL, NULL);
 #if defined (UNIV_PMEMOBJ_BUF_FLUSHER)
 	//os_thread_create(pm_flusher_coordinator, NULL, NULL);
-	//printf("PMEM_INFO: ========>   create %d worker threads for pm\n", PMEM_N_BUCKETS);
-	for (i = 1; i < srv_n_page_cleaners; ++i) {
+	printf("PMEM_INFO: ========>   create %d worker threads for pm\n", srv_pmem_n_flush_threads);
+	//for (i = 1; i < srv_n_page_cleaners; ++i) {
+	for (i = 0; i < srv_pmem_n_flush_threads; ++i) {
 		os_thread_create(pm_flusher_worker, NULL, NULL);
 	}
 #endif 
@@ -2861,6 +2868,11 @@ innobase_shutdown_for_mysql(void)
 #endif
 	pm_wrapper_free(gb_pmw);
 #endif
+#if defined (UNIV_TRACE_FLUSH_TIME)
+	printf("=== > TRACE FLUSH TIME: total flush time (ms) = %zu\n ", gb_flush_time);
+	fprintf(gb_trace_file, "\n===>TRACE_FLUSH_TIME: total flush time (ms) = %zu", gb_flush_time);
+	fclose(gb_trace_file);
+#endif 
 
 	/* 2. Make all threads created by InnoDB to exit */
 	srv_shutdown_all_bg_threads();