implement simulate latency use RDTSC instruction

Author: trdtnguyen

build_mysql.sh

@@ -5,13 +5,18 @@ MYSQL_HOME=/home/vldb/mysql-plnvm
 IS_DEBUG=0
 #IS_DEBUG=1
 
+#Next paper configs PL-NVM ##############################
 #BUILD_NAME="-DUNIV_TRACE_RECOVERY_TIME"
 #BUILD_NAME="-DUNIV_TRACE_FLUSH_TIME -DUNIV_SKIPLOG"
 #BUILD_NAME="-DUNIV_PMEMOBJ_WAL -DUNIV_TRACE_FLUSH_TIME"
 #BUILD_NAME="-DUNIV_PMEMOBJ_WAL -DUNIV_PMEMOBJ_WAL_ELR -DUNIV_TRACE_FLUSH_TIME"
 #BUILD_NAME="-DUNIV_NVM_LOG -DUNIV_PMEMOBJ_WAL -DUNIV_TRACE_FLUSH_TIME"
-BUILD_NAME="-DUNIV_PMEMOBJ_PPL_STAT -DUNIV_PMEMOBJ_PAGE_LOG -DUNIV_PMEMOBJ_PART_PL -DUNIV_PMEMOBJ_PL -DUNIV_TRACE_RECOVERY_TIME"
+#BUILD_NAME="-DUNIV_PMEMOBJ_PPL_STAT -DUNIV_PMEMOBJ_PAGE_LOG -DUNIV_PMEMOBJ_PART_PL -DUNIV_PMEMOBJ_PL -DUNIV_TRACE_RECOVERY_TIME"
 #BUILD_NAME="-DUNIV_PMEMOBJ_PPL_STAT -DUNIV_PMEMOBJ_PAGE_LOG -DUNIV_PMEMOBJ_PART_PL -DUNIV_PMEMOBJ_PART_PL_DEBUG -DUNIV_PMEMOBJ_PL -DUNIV_TRACE_FLUSH_TIME"
+#######################################
+
+##### Simulate latency
+BUILD_NAME="-DUNIV_SIM_LATENCY -DUNIV_OPENMP -DUNIV_PMEMOBJ_BLOOM -DUNIV_PMEMOBJ_BUF -DUNIV_PMEMOBJ_BUF_PARTITION -DUNIV_PMEMOBJ_BUF_FLUSHER -DUNIV_PMEMOBJ_BUF_RECOVERY -DUNIV_TRACE_FLUSH_TIME"
 
 ####debug with valid mtr
 #BUILD_NAME="-DUNIV_PMEMOBJ_VALID_MTR -DUNIV_PMEMOBJ_PPL_STAT -DUNIV_PMEMOBJ_PAGE_LOG -DUNIV_PMEMOBJ_PART_PL -DUNIV_PMEMOBJ_PL -DUNIV_TRACE_RECOVERY_TIME"

storage/innobase/handler/ha_innodb.cc

@@ -3769,6 +3769,11 @@ innobase_init(
 		srv_ppl_log_files_per_bucket = 1;
 	}
 #endif
+#if defined (UNIV_PMEM_SIM_LATENCY)
+	if (!srv_pmem_sim_latency) {
+		srv_pmem_sim_latency = 1000 ; //1000 ns
+	}
+#endif
 
 #if defined(UNIV_PMEMOBJ_BUF) 
 	if (!srv_pmem_buf_bucket_size) {
@@ -19623,6 +19628,13 @@ static MYSQL_SYSVAR_DOUBLE(pmem_bloom_fpr, srv_pmem_bloom_fpr,
   NULL, NULL, 0.001, 0, 1,0);
 #endif
 
+#if defined (UNIV_PMEM_SIM_LATENCY)
+static MYSQL_SYSVAR_ULONG(pmem_sim_latency, srv_pmem_sim_latency,
+  PLUGIN_VAR_RQCMDARG | PLUGIN_VAR_READONLY,
+  "Additional latency , from 1 ns to 10000000, default 1000.",
+  NULL, NULL, 1000, 1, 10000000,0);
+#endif
+
 #if defined (UNIV_PMEMOBJ_BUF) || defined (UNIV_PMEMOBJ_DBW) || defined (UNIV_PMEMOBJ_LOG) || defined (UNIV_PMEMOBJ_WAL) || defined (UNIV_PMEMOBJ_PART_PL)
 static MYSQL_SYSVAR_STR(pmem_home_dir, srv_pmem_home_dir,
   PLUGIN_VAR_RQCMDARG | PLUGIN_VAR_READONLY,
@@ -20536,6 +20548,9 @@ static struct st_mysql_sys_var* innobase_system_variables[]= {
   MYSQL_SYSVAR(pmem_n_flush_threads),
   MYSQL_SYSVAR(pmem_flush_threshold),
 #endif 
+#if defined (UNIV_PMEM_SIM_LATENCY)
+  MYSQL_SYSVAR(pmem_sim_latency),
+#endif
 #if defined (UNIV_PMEMOBJ_BUF_PARTITION)
   MYSQL_SYSVAR(pmem_n_space_bits),
   MYSQL_SYSVAR(pmem_page_per_bucket_bits),

storage/innobase/include/my_pmemobj.h

@@ -312,6 +312,9 @@ struct __pmem_wrapper {
 
 #if defined (UNIV_PMEMOBJ_LSB)
 	PMEM_LSB* plsb;
+#endif
+#if defined (UNIV_PMEM_SIM_LATENCY)
+	uint64_t PMEM_SIM_CPU_CYCLES; //used in simulate latency
 #endif
 	bool is_new;
 };
@@ -332,7 +335,15 @@ pm_wrapper_free(PMEM_WRAPPER* pmw);
 PMEMoid pm_pop_alloc_bytes(PMEMobjpool* pop, size_t size);
 void pm_pop_free(PMEMobjpool* pop);
 
-
+#if defined (UNIV_PMEM_SIM_LATENCY)
+#define PMEM_DELAY(start, end, t) do {\
+	start = my_timer_cycles();\
+	end = start;\
+	while( (end - start) < t){\
+		end = my_timer_cycles();\
+	}\
+} while(0)
+#endif
 //////////////////// PARTITIONED-LOG 2018.11.2/////////////
 
 #if defined (UNIV_PMEMOBJ_PL)

storage/innobase/include/srv0srv.h

@@ -286,6 +286,11 @@ extern ulong	srv_pmem_page_per_bucket_bits;
 extern ulong	srv_pmem_bloom_n_elements;
 extern double	srv_pmem_bloom_fpr;
 #endif
+
+#if defined (UNIV_PMEM_SIM_LATENCY)
+extern ulong	srv_pmem_sim_latency;
+#endif
+
 #if defined(UNIV_PMEMOBJ_BUF) || defined (UNIV_PMEMOBJ_DBW) || defined (UNIV_PMEMOBJ_LOG) || defined(UNIV_PMEMOBJ_WAL) || defined (UNIV_PMEMOBJ_PART_PL)
 extern char*	srv_pmem_home_dir;
 extern ulong	srv_pmem_pool_size;

storage/innobase/pmem/pmem0buf.cc

@@ -23,6 +23,12 @@
 #include "buf0dblwr.h"
 
 
+#if defined (UNIV_PMEM_SIM_LATENCY)
+static uint64_t PMEM_SIM_LATENCY = 1000;
+static float PMEM_CPU_FREQ = 2.2;
+static uint64_t PMEM_SIM_CPU_CYCLES = PMEM_SIM_LATENCY * PMEM_CPU_FREQ;
+#endif //UNIV_PMEM_SIM_LATENCY
+
 #if defined (UNIV_PMEMOBJ_BUF)
 /*
   There are two types of structure need to be allocated: structures in NVM that non-volatile after shutdown server or power-off and D-RAM structures that only need when the server is running. 
@@ -733,6 +739,11 @@ TX_BEGIN(pop) {
 			//pspec_block->file_handle = node->handle;
 			strcpy(pspec_block->file_name, node->name);
 
+#if defined (UNIV_PMEM_SIM_LATENCY)
+			/*5 times write to NVM*/
+			PMEM_DELAY(start_cycle, end_cycle, 5 * pmw->PMEM_SIM_CPU_CYCLES);
+#endif
+
 #if defined (UNIV_PMEMOBJ_NO_PERSIST)
 			pmemobj_memcpy_persist(pop, pdata + pspec_block->pmemaddr, src_data, page_size); 
 			//memcpy(pdata + pspec_block->pmemaddr, src_data, page_size); 
@@ -830,6 +841,10 @@ TX_BEGIN(pop) {
 					}
 				}
 				pfree_block->sync = sync;
+#if defined (UNIV_PMEM_SIM_LATENCY)
+			/*3 times write to NVM*/
+			PMEM_DELAY(start_cycle, end_cycle, 3 * pmw->PMEM_SIM_CPU_CYCLES);
+#endif
 #if defined (UNIV_PMEMOBJ_NO_PERSIST)
 				pmemobj_memcpy_persist(pop, pdata + pfree_block->pmemaddr, src_data, page_size); 
 				//memcpy(pdata + pfree_block->pmemaddr, src_data, page_size); 
@@ -923,6 +938,10 @@ TX_BEGIN(pop) {
 	else
 		++(phashlist->n_sio_pending);		
 
+#if defined (UNIV_PMEM_SIM_LATENCY)
+	/*7 times write to NVM*/
+	PMEM_DELAY(start_cycle, end_cycle, 7 * pmw->PMEM_SIM_CPU_CYCLES);
+#endif
 // HANDLE FULL LIST ////////////////////////////////////////////////////////////
 	if (phashlist->cur_pages >= phashlist->max_pages * PMEM_BUF_FLUSH_PCT) {
 		//(3) The hashlist is (nearly) full, flush it and assign a free list 
@@ -1303,6 +1322,10 @@ pm_handle_finished_block(
 		for (i = 0; i < pflush_list->max_pages; i++) {
 			D_RW(D_RW(pflush_list->arr)[i])->state = PMEM_FREE_BLOCK;
 			D_RW(D_RW(pflush_list->arr)[i])->sync = false;
+#if defined (UNIV_PMEM_SIM_LATENCY)
+			/*2 times write to NVM*/
+			PMEM_DELAY(start_cycle, end_cycle, 2 * pmw->PMEM_SIM_CPU_CYCLES);
+#endif
 		}
 
 		pflush_list->cur_pages = 0;
@@ -1336,11 +1359,20 @@ pm_handle_finished_block(
 		PMEM_BUF_FREE_POOL* pfree_pool;
 		pfree_pool = D_RW(buf->free_pool);
 
+#if defined (UNIV_PMEM_SIM_LATENCY)
+		/*7 times write to NVM*/
+		PMEM_DELAY(start_cycle, end_cycle, 7 * pmw->PMEM_SIM_CPU_CYCLES);
+#endif
+
 		//printf("PMEM_DEBUG: in fil_aio_wait(), try to lock free_pool list id: %zd, cur_lists in free_pool= %zd \n", pflush_list->list_id, pfree_pool->cur_lists);
 		pmemobj_rwlock_wrlock(pop, &pfree_pool->lock);
 
 		POBJ_LIST_INSERT_TAIL(pop, &pfree_pool->head, flush_list, list_entries);
 		pfree_pool->cur_lists++;
+#if defined (UNIV_PMEM_SIM_LATENCY)
+		/*2 times write to NVM*/
+		PMEM_DELAY(start_cycle, end_cycle, 2 * pmw->PMEM_SIM_CPU_CYCLES);
+#endif
 		//wakeup who is waitting for free_pool available
 		os_event_set(buf->free_pool_event);
 
@@ -1583,7 +1615,7 @@ pm_buf_read(
 
 #if defined (UNIV_PMEMOBJ_BLOOM)
 				if (bloom_ret == BLOOM_MAY_EXIST){
-					printf("++++> BLOOM false positive fold %zu \n", page_id.fold());
+					//printf("++++> BLOOM false positive fold %zu \n", page_id.fold());
 					buf->cbf->n_false_pos_reads++;
 				}
 #endif

storage/innobase/pmem/pmem0log.cc

@@ -71,6 +71,9 @@ static bool USE_BIT_ARRAY = true;
 //static bool USE_BIT_ARRAY = false;
 static uint64_t BIT_BLOCK_SIZE = sizeof(long long);
 
+/*call pmemobj_persist() at every log record write*/
+static bool PERSIST_AT_WRITE = true;
+
 #endif //UNIV_PMEMOBJ_PL
 //////////////// NEW PMEM PARTITION LOG /////////////
 
@@ -1710,6 +1713,9 @@ pm_ppl_write_rec(
 #endif	
 		//move the diskaddr on the line ahead, the written size should be aligned with 512B for DIRECT_IO works
 		pline->diskaddr += plogbuf->size;
+		if (PERSIST_AT_WRITE){
+			pmemobj_persist(pop, &pline->diskaddr, sizeof(pline->diskaddr));
+		}
 
 		// (1.4) write log rec on new buf
 		D_RW(free_buf)->hashed_id = pline->hashed_id; 
@@ -1778,15 +1784,28 @@ pm_ppl_write_rec(
 			//update the oldest
 			if (pline->oldest_block_off == UINT32_MAX) {
 				pline->oldest_block_off = item->block_off;
+				if (PERSIST_AT_WRITE){
+					pmemobj_persist(pop, &pline->oldest_block_off, sizeof(pline->oldest_block_off));
+				}
 			}
 			//test
 			/*insert the pair (offset, bid) into the set*/
 			write_off = plog_block->start_diskaddr + plog_block->start_off;
 			pline->offset_map->insert( std::make_pair(write_off, item->block_off));
 
+			if (PERSIST_AT_WRITE){
+				pmemobj_persist(pop, plog_block, sizeof(PMEM_PAGE_LOG_BLOCK));
+			}
+
 		}
 		plog_block->lastLSN = rec_lsn;
 
+		/*persist the plogblock*/
+		if (PERSIST_AT_WRITE){
+			pmemobj_persist(pop, D_RW(free_buf), sizeof(PMEM_PAGE_LOG_BUF));
+			pmemobj_persist(pop, plogbuf, sizeof(PMEM_PAGE_LOG_BUF));
+		}
+
 
 		// (1.6) assign a pointer in the flusher to the full log buf, this function return immediately 
 		pm_log_buf_assign_flusher(ppl, plogbuf);
@@ -1814,6 +1833,9 @@ pm_ppl_write_rec(
 
 		old_off = plogbuf->cur_off;
 		plogbuf->cur_off += rec_size;
+		if (PERSIST_AT_WRITE){
+			pmemobj_persist(pop, &plogbuf->cur_off, sizeof(plogbuf->cur_off));
+		}
 
 		if (!pline->is_req_checkpoint){
 			/*comment this line to disable checkpoint (for debugging)*/
@@ -1850,13 +1872,21 @@ pm_ppl_write_rec(
 			//update the oldest
 			if (pline->oldest_block_off == UINT32_MAX) {
 				pline->oldest_block_off = item->block_off;
+				if (PERSIST_AT_WRITE){
+					pmemobj_persist(pop, &pline->oldest_block_off, sizeof(pline->oldest_block_off));
+				}
 			}
 			//test
 			/*insert the pair (offset, bid) into the set*/
 			write_off = plog_block->start_diskaddr + plog_block->start_off;
+
 			pmemobj_rwlock_wrlock(pop, &pline->meta_lock);
 			pline->offset_map->insert( std::make_pair(write_off, item->block_off));
 			pmemobj_rwlock_unlock(pop, &pline->meta_lock);
+
+			if (PERSIST_AT_WRITE){
+				pmemobj_persist(pop, plog_block, sizeof(PMEM_PAGE_LOG_BLOCK));
+			}
 		}
 
 		plog_block->lastLSN = rec_lsn;
@@ -2397,6 +2427,7 @@ pm_ppl_check_for_ckpt(
 
 		//Method 1
 		pline->ckpt_lsn = oldest_lsn + delta;
+		//pmemobj_persist(pop, &pline->ckpt_lsn, sizeof(pline->ckpt_lsn));
 
 		//Method 2 => no ckpt call
 		//pline->ckpt_lsn = oldest_lsn + 1000000 ;
@@ -2408,6 +2439,7 @@ pm_ppl_check_for_ckpt(
 		pmemobj_rwlock_wrlock(pop, &ppl->ckpt_lock);
 		if (ppl->max_oldest_lsn < pline->ckpt_lsn){
 			ppl->max_oldest_lsn = pline->ckpt_lsn;
+			//pmemobj_persist(pop, &ppl->max_oldest_lsn, sizeof(ppl->max_oldest_lsn));
 		}
 
 		//printf("SET is_req_checkpoint to true pline %zu \n", pline->hashed_id);

storage/innobase/srv/srv0srv.cc

@@ -229,6 +229,10 @@ ulong	srv_pmem_bloom_n_elements	= 10000000;
 double	srv_pmem_bloom_fpr			= 0.01;
 #endif
 
+#if defined (UNIV_PMEM_SIM_LATENCY)
+ulong	srv_pmem_sim_latency			= 1000;
+#endif
+
 #if defined(UNIV_PMEMOBJ_BUF) || defined (UNIV_PMEMOBJ_DBW) || defined (UNIV_PMEMOBJ_LOG) || defined (UNIV_PMEMOBJ_WAL) || defined (UNIV_PMEMOBJ_PART_PL)
 char*	srv_pmem_home_dir			= NULL;
 ulong	srv_pmem_pool_size			= 8 * 1024;

storage/innobase/srv/srv0start.cc

@@ -1809,6 +1809,9 @@ innobase_start_or_create_for_mysql(void)
 	#ifdef UNIV_PMEMOBJ_WAL
 		ib::info() << "======= Hello PMEMOBJ WAL from VLDB lab ========\n";
 	#endif 
+	#if defined (UNIV_PMEM_SIM_LATENCY)
+		ib::info() << "======= Simulate addtional latency %zu ns ========\n", srv_pmem_sim_latency;
+	#endif
 	#ifdef UNIV_PMEOBJ_BUF
 	ib::info() << "======== pool_size =" << srv_pmem_pool_size << 
 		"MB; srv_pmem_buf_size= " << srv_pmem_buf_size << "MB; " <<
@@ -1973,6 +1976,12 @@ innobase_start_or_create_for_mysql(void)
 	fsp_init();
 	log_init();
 
+#if defined (UNIV_PMEM_SIM_LATENCY)
+	PMEM_SIM_LATENCY = srv_pmem_sim_latency;
+	PMEM_SIM_CPU_CYCLES = PMEM_SIM_LATENCY * 1.0 * PMEM_CPU_FREQ;
+	pmw->PMEM_SIM_CPU_CYCLES = PMEM_SIM_CPU_CYCLES;
+#endif
+
 #if defined (UNIV_PMEMOBJ_BUF)
 	size_t buf_size = srv_pmem_buf_size * 1024 * 1024;
 #if defined (UNIV_PMEMOBJ_LSB)