⬢ DragonFlyBSD Kernel Audit
DF-4529 / nvslow.c
← back to finding ↓ download raw
/* nvslow.c -- instrumented NVMEIOCGETLOG prober: records latency of EVERY
 * call (success AND error, incl. errno), prints slow-call lines, and final
 * histogram-ish stats. */
#include <sys/ioccom.h>
#include <sys/types.h>
#include <sys/errno.h>
#include <stdint.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <fcntl.h>
#include <unistd.h>
#include <signal.h>
#include <time.h>

typedef struct { unsigned char pad[4096]; } nvme_admin_data_t;
typedef struct nvme_getlog_ioctl {
	uint8_t  lid, reserved01;
	uint16_t status;
	uint32_t ret_size, beg_offset;
	nvme_admin_data_t info;
} nvme_getlog_ioctl_t;
#define NVMEIOCGETLOG _IOWR('O', 0, struct nvme_getlog_ioctl)

static volatile sig_atomic_t stop;
static void onsig(int s) { stop = 1; }

static double now(void) {
	struct timespec ts;
	clock_gettime(CLOCK_MONOTONIC, &ts);
	return (double)ts.tv_sec + (double)ts.tv_nsec / 1e9;
}

int
main(int argc, char **argv)
{
	nvme_getlog_ioctl_t ioc;
	double t0, t1, maxlat = 0, sum = 0;
	long n = 0, errs = 0, slow1 = 0, slow3 = 0;
	double limit = argc > 2 ? atof(argv[2]) : 60.0;
	double start, thresh = argc > 3 ? atof(argv[3]) : 0.05;
	int fd;
	char errbuf[64];
	long errcount[16];

	memset(errcount, 0, sizeof(errcount));
	signal(SIGINT, onsig);
	signal(SIGTERM, onsig);
	setvbuf(stdout, NULL, _IOLBF, 0);

	fd = open(argv[1], O_RDONLY);
	if (fd < 0) { perror(argv[1]); return 1; }

	start = now();
	while (!stop && now() - start < limit) {
		int rc;
		memset(&ioc, 0, sizeof(ioc));
		ioc.lid = 1;
		ioc.ret_size = 4096;
		t0 = now();
		rc = ioctl(fd, NVMEIOCGETLOG, &ioc);
		t1 = now();
		if (rc < 0) {
			int e = errno;
			errs++;
			errbuf[0] = 0;
			strerror_r(e, errbuf, sizeof(errbuf));
			if (e < 16) errcount[e]++;
			if (t1 - t0 > thresh)
				printf("SLOWERR %.4fs errno=%d(%s)\n",
				    t1 - t0, e, errbuf);
		} else {
			if (t1 - t0 > maxlat) maxlat = t1 - t0;
			sum += t1 - t0;
			if (t1 - t0 > 1.0) slow1++;
			if (t1 - t0 > 3.0) slow3++;
			if (t1 - t0 > thresh)
				printf("SLOW %.4fs status=%u\n",
				    t1 - t0, ioc.status);
		}
		n++;
	}
	printf("DONE n=%ld ok=%ld errs=%ld maxlat=%.4f avg=%.6f "
	    "slow>1s=%ld slow>3s=%ld\n", n, n - errs, errs, maxlat,
	    n - errs ? sum / (n - errs) : 0, slow1, slow3);
	for (int i = 0; i < 16; i++)
		if (errcount[i])
			printf("  errno %d: %ld\n", i, errcount[i]);
	return 0;
}