The latency of liblightnvm is a bit long.

[ChaosD]

Hello~ I do a simple test about the latency of liblightnvm. Then compare with the posix interface.
This is what I do:

1. Open nvm dev with nvm_dev_open
2. Write a string into this dev
3. Calculate the latency of such a write op.

I find the latency is a bit long, around 1ms. Do I use the interface with wrong?
And I repeat this test with posix interface. I'm not sure the result is correct or not but the latency is obviously shorter, about 60us. I use femu in white-box-SSD mode to emulate OCSSD . Do you have any idea or advice about my problem? Shall I pull this issue in femu project?

Thanks for your watching!

This is my test and result:

Code:

#include <stdio.h>
#include <liblightnvm.h>
#include <string.h>
#include <unistd.h>
#include <sys/time.h>
#include <fcntl.h>


int main(int argc, char **argv)
{

	struct nvm_dev *dev = nvm_dev_open("/dev/nvme0n1");
	if (!dev) {
		perror("nvm_dev_open");
		return 1;
	}
	nvm_dev_pr(dev);

	const struct nvm_geo* geo = nvm_dev_get_geo(dev);
	nvm_geo_pr(geo);

	// fetch the ws_opt and bytes/sector
	size_t ws_opt = nvm_dev_get_ws_opt(dev);
	printf("ws_opt: %ld\n", ws_opt);
	size_t ws_min = nvm_dev_get_ws_min(dev);
	printf("ws_min: %ld\n", ws_min);

	char read_buffer[ws_opt * geo->g.sector_nbytes], write_buffer[ws_opt * geo->g.sector_nbytes];
	strcpy(write_buffer, "Hello, world!");

	// start timing.
	struct timeval start, middle, end;

	struct nvm_addr addr[ws_opt];
	for(int i = 0; i < ws_opt; i++)
		addr[i].val = nvm_addr_off2gen(dev, 0 + i * geo->g.sector_nbytes).val;

	printf("######################### liblightnvm interface ############################ \n");

	// get write latency.
	gettimeofday(&start, NULL);
	nvm_cmd_write(dev, addr, ws_opt, write_buffer, nullptr, 0x0, nullptr);

	gettimeofday(&middle, NULL);
	uint64_t t_cur_ltcy = (middle.tv_sec-start.tv_sec)*1000000+(middle.tv_usec-start.tv_usec);//Microsecond
	printf("lightNVM Write latency: %luus\n", t_cur_ltcy);		

	// get the read latency.
	nvm_cmd_read(dev, addr, ws_opt, read_buffer, nullptr, 0x0, nullptr);
	gettimeofday(&end, NULL);
	t_cur_ltcy = (end.tv_sec-middle.tv_sec)*1000000+(end.tv_usec-middle.tv_usec);//Microsecond
	printf("lightNVM Read latency: %luus\n", t_cur_ltcy);		

	printf("%s\n", read_buffer);

	nvm_dev_close(dev);

	// clear read buffer.
	memset(read_buffer, 0, ws_opt * geo->g.sector_nbytes);

	printf("######################### Posix interface ############################ \n");
 	// open by posix interface.
	int fd = open("/dev/nvme0n1", O_RDWR);
	gettimeofday(&start, NULL);

	write(fd, write_buffer, ws_opt * geo->g.sector_nbytes);	
	gettimeofday(&middle, NULL);
	t_cur_ltcy = (middle.tv_sec-start.tv_sec)*1000000+(middle.tv_usec-start.tv_usec);//Microsecond
	printf("Posix Write latency: %luus\n", t_cur_ltcy);		

	lseek(fd, 0, SEEK_SET);
	read(fd, read_buffer, ws_opt * geo->g.sector_nbytes);	
	gettimeofday(&end, NULL);
	t_cur_ltcy = (end.tv_sec-middle.tv_sec)*1000000+(end.tv_usec-middle.tv_usec);//Microsecond
	printf("Posix Read latency: %luus\n", t_cur_ltcy);		

	printf("%s\n", read_buffer);
	return 0;
}

Output:

...
geo:
  verid: 0x01
  nchannels: 2
  nluns: 8
  nplanes: 2
  nblocks: 4
  npages: 512
  nsectors: 4
  page_nbytes: 16384
  sector_nbytes: 4096
  meta_nbytes: 16
  tbytes: 1073741824
  tmbytes: 1024
ws_opt: 8
ws_min: 4
######################### liblightnvm interface ############################ 
lightNVM Write latency: 1085us
lightNVM Read latency: 292us
Hello, world!
######################### Posix interface ############################ 
Posix Write latency: 61us
Posix Read latency: 19us
Hello, world!

[safl]

Hi @ChaosD,
I apologize, did not see this. You are seeing this difference for two reasons:

1. liblightnvm when opening with "/dev/nvme0n1" is using the NVMe Driver IOCTL interface for sending the command, thus in this way it blocks until the NVMe command is completed, so the time measured should be close the the round-trip-time it takes femu to process and complete a command + overhead of the ioctl() syscall and the in-kernel handling of the command.
2. The posix write/read you do here is opening the device with open("/dev/nvme0n1", O_RDWR);, since this is not using O_DIRECT what you are really measuring is how long it takes to utilize the Linux page cache.