peci_cmds: Add request-to-response latency measurement
To help in validation of the peci interface, this patch adds capability
in peci_cmds utility to measure request to response delays. A new
swith -t option provides this capability and it is designed to work
with other switches like verbose mode and command loop mode.
The desired behaviour of the -t switch is as follows:
1) -t switch used in isolation will measure the latency of only the
single command under execution.
2) -t switch with -l (loop) mode will measure the total latency and
provides average per command execution time.
3) -t switch with -l (loop) and -v (verbose) mode will capture total
latency, overall average as well as per command execution times.
Tested:
Case 1)
root# peci_cmds ping -t
Succeeded
Total time taken = 0.000212 seconds
Case 2)
root# peci_cmds ping -t -l 10
Succeeded
Total time taken = 0.001365 seconds
Average time taken per command = 0.000137 seconds
Case 3)
root# peci_cmds ping -t -l 6 -v
Time taken in iteration 1 = 0.000121 s
Succeeded
Time taken in iteration 2 = 0.000122 s
Succeeded
Time taken in iteration 3 = 0.000141 s
Succeeded
Time taken in iteration 4 = 0.000138 s
Succeeded
Time taken in iteration 5 = 0.000143 s
Succeeded
Time taken in iteration 6 = 0.000112 s
Succeeded
Total time taken = 0.000777 seconds
Average time taken per command = 0.000129 seconds
Change-Id: Idde67a6aed05367d91a7bdc807ae1fbfe2a81104
Signed-off-by: Sumanth Bhat <sumanth.bhat@linux.intel.com>
diff --git a/peci_cmds.c b/peci_cmds.c
index 797d2b1..ca4f469 100644
--- a/peci_cmds.c
+++ b/peci_cmds.c
@@ -21,6 +21,7 @@
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
+#include <time.h>
#include <unistd.h>
#ifndef ABS
#define ABS(_v_) (((_v_) > 0) ? (_v_) : -(_v_))
@@ -30,16 +31,33 @@
extern EPECIStatus peci_GetDIB(uint8_t target, uint64_t* dib);
+double getTimeDifference(const struct timespec begin)
+{
+ double timeDiff = 0.0;
+ struct timespec end;
+ long seconds = 0;
+ long nanoseconds = 0;
+
+ clock_gettime(CLOCK_REALTIME, &end);
+ seconds = end.tv_sec - begin.tv_sec;
+ nanoseconds = end.tv_nsec - begin.tv_nsec;
+ timeDiff = (double)seconds + (double)nanoseconds * 1e-9;
+
+ return timeDiff;
+}
+
void Usage(char* progname)
{
printf("Usage:\n");
- printf("%s [-h] [-v] [-a <addr>] [-i <domain id>] [-s <size>] [-l <count>] "
+ printf("%s [-h] [-v] [-t] [-a <addr>] [-i <domain id>] [-s <size>] [-l "
+ "<count>] "
"<command> [parameters]\n",
progname);
printf("Options:\n");
printf("\t%-12s%s\n", "-h", "Display this help information");
printf("\t%-12s%s\n", "-v",
"Display additional information about the command");
+ printf("\t%-12s%s\n", "-t", "Measure request-to-response time");
printf("\t%-12s%s %lu\n", "-l <count>",
"Loop the command the given number of times. <count> is in the "
"range 1 to",
@@ -126,15 +144,20 @@
uint64_t dib;
int index = 0;
uint8_t cc = 0;
+ bool measureTime = false;
bool verbose = false;
bool looped = false;
uint32_t loops = 1;
+ uint32_t loopCount = 1;
uint32_t ccCounts[CC_COUNT] = {0};
+ struct timespec begin;
+ double timeSpent = 0.0;
+ double totalTimeSpent = 0.0;
//
// Parse arguments.
//
- while (-1 != (c = getopt(argc, argv, "hvl:a:i:s:d:")))
+ while (-1 != (c = getopt(argc, argv, "hvtl:a:i:s:d:")))
{
switch (c)
{
@@ -147,6 +170,10 @@
verbose = true;
break;
+ case 't':
+ measureTime = true;
+ break;
+
case 'l':
looped = true;
errno = 0;
@@ -159,6 +186,8 @@
perror("");
goto ErrorExit;
}
+ loopCount =
+ loops; // Preserve a copy for average time measurement
break;
case 'a':
@@ -226,6 +255,17 @@
{
printf("PECI target[0x%x]: ", address);
}
+
+ if (measureTime)
+ {
+ if (verbose && (loopCount > 1))
+ {
+ printf("Warning: Request-response time measurement with verbose "
+ "mode can affect the time between consecutive commands in "
+ "looped mode!\n");
+ }
+ }
+
if (strcmp(cmd, "ping") == 0)
{
if (verbose)
@@ -234,7 +274,16 @@
}
while (loops--)
{
+ clock_gettime(CLOCK_REALTIME, &begin);
ret = peci_Ping(address);
+ timeSpent = getTimeDifference(begin);
+ if (verbose && measureTime)
+ {
+ printf("\nTime taken in iteration %d = %lf s\n",
+ (loopCount - loops), timeSpent);
+ }
+ totalTimeSpent += timeSpent;
+
if (verbose || loops == 0)
{
if (0 != ret)
@@ -256,7 +305,16 @@
}
while (loops--)
{
+ clock_gettime(CLOCK_REALTIME, &begin);
ret = peci_GetDIB(address, &dib);
+ timeSpent = getTimeDifference(begin);
+ if (verbose && measureTime)
+ {
+ printf("\nTime taken in iteration %d = %lf s\n",
+ (loopCount - loops), timeSpent);
+ }
+ totalTimeSpent += timeSpent;
+
if (verbose || loops == 0)
{
if (0 != ret)
@@ -279,7 +337,16 @@
}
while (loops--)
{
+ clock_gettime(CLOCK_REALTIME, &begin);
ret = peci_GetTemp(address, &temperature);
+ timeSpent = getTimeDifference(begin);
+ if (verbose && measureTime)
+ {
+ printf("\nTime taken in iteration %d = %lf s\n",
+ (loopCount - loops), timeSpent);
+ }
+ totalTimeSpent += timeSpent;
+
if (verbose || loops == 0)
{
if (0 != ret)
@@ -320,9 +387,18 @@
}
while (loops--)
{
+ clock_gettime(CLOCK_REALTIME, &begin);
ret =
peci_RdPkgConfig_dom(address, domainId, u8PkgIndex, u16PkgParam,
u8Size, (uint8_t*)&u32PkgValue, &cc);
+ timeSpent = getTimeDifference(begin);
+ if (verbose && measureTime)
+ {
+ printf("\nTime taken in iteration %d = %lf s\n",
+ (loopCount - loops), timeSpent);
+ }
+ totalTimeSpent += timeSpent;
+
ccCounts[cc]++;
if (verbose || loops == 0)
@@ -366,8 +442,17 @@
}
while (loops--)
{
+ clock_gettime(CLOCK_REALTIME, &begin);
ret = peci_WrPkgConfig_dom(address, domainId, u8PkgIndex,
u16PkgParam, u32PkgValue, u8Size, &cc);
+ timeSpent = getTimeDifference(begin);
+ if (verbose && measureTime)
+ {
+ printf("\nTime taken in iteration %d = %lf s\n",
+ (loopCount - loops), timeSpent);
+ }
+ totalTimeSpent += timeSpent;
+
ccCounts[cc]++;
if (verbose || loops == 0)
@@ -405,8 +490,17 @@
}
while (loops--)
{
+ clock_gettime(CLOCK_REALTIME, &begin);
ret = peci_RdIAMSR_dom(address, domainId, u8MsrThread, u16MsrAddr,
&u64MsrVal, &cc);
+ timeSpent = getTimeDifference(begin);
+ if (verbose && measureTime)
+ {
+ printf("\nTime taken in iteration %d = %lf s\n",
+ (loopCount - loops), timeSpent);
+ }
+ totalTimeSpent += timeSpent;
+
ccCounts[cc]++;
if (verbose || loops == 0)
@@ -457,9 +551,18 @@
}
while (loops--)
{
+ clock_gettime(CLOCK_REALTIME, &begin);
ret = peci_RdPCIConfig_dom(address, domainId, u8PciBus, u8PciDev,
u8PciFunc, u16PciReg,
(uint8_t*)&u32PciReadVal, &cc);
+ timeSpent = getTimeDifference(begin);
+ if (verbose && measureTime)
+ {
+ printf("\nTime taken in iteration %d = %lf s\n",
+ (loopCount - loops), timeSpent);
+ }
+ totalTimeSpent += timeSpent;
+
ccCounts[cc]++;
if (verbose || loops == 0)
@@ -510,10 +613,18 @@
}
while (loops--)
{
+ clock_gettime(CLOCK_REALTIME, &begin);
ret = peci_RdPCIConfigLocal_dom(
address, domainId, u8PciBus, u8PciDev, u8PciFunc, u16PciReg,
u8Size, (uint8_t*)&u32PciReadVal, &cc);
ccCounts[cc]++;
+ timeSpent = getTimeDifference(begin);
+ if (verbose && measureTime)
+ {
+ printf("\nTime taken in iteration %d = %lf s\n",
+ (loopCount - loops), timeSpent);
+ }
+ totalTimeSpent += timeSpent;
if (verbose || loops == 0)
{
@@ -565,9 +676,18 @@
}
while (loops--)
{
+ clock_gettime(CLOCK_REALTIME, &begin);
ret = peci_WrPCIConfigLocal_dom(address, domainId, u8PciBus,
u8PciDev, u8PciFunc, u16PciReg,
u8Size, u32PciWriteVal, &cc);
+ timeSpent = getTimeDifference(begin);
+ if (verbose && measureTime)
+ {
+ printf("\nTime taken in iteration %d = %lf s\n",
+ (loopCount - loops), timeSpent);
+ }
+ totalTimeSpent += timeSpent;
+
ccCounts[cc]++;
if (verbose || loops == 0)
@@ -610,9 +730,18 @@
}
while (loops--)
{
+ clock_gettime(CLOCK_REALTIME, &begin);
ret = peci_RdEndPointConfigPciLocal_dom(
address, domainId, u8Seg, u8PciBus, u8PciDev, u8PciFunc,
u16PciReg, u8Size, (uint8_t*)&u32PciReadVal, &cc);
+ timeSpent = getTimeDifference(begin);
+ if (verbose && measureTime)
+ {
+ printf("\nTime taken in iteration %d = %lf s\n",
+ (loopCount - loops), timeSpent);
+ }
+ totalTimeSpent += timeSpent;
+
ccCounts[cc]++;
if (verbose || loops == 0)
@@ -662,9 +791,18 @@
}
while (loops--)
{
+ clock_gettime(CLOCK_REALTIME, &begin);
ret = peci_WrEndPointPCIConfigLocal_dom(
address, domainId, u8Seg, u8PciBus, u8PciDev, u8PciFunc,
u16PciReg, u8Size, u32PciWriteVal, &cc);
+ timeSpent = getTimeDifference(begin);
+ if (verbose && measureTime)
+ {
+ printf("\nTime taken in iteration %d = %lf s\n",
+ (loopCount - loops), timeSpent);
+ }
+ totalTimeSpent += timeSpent;
+
ccCounts[cc]++;
if (verbose || loops == 0)
@@ -705,9 +843,18 @@
}
while (loops--)
{
+ clock_gettime(CLOCK_REALTIME, &begin);
ret = peci_RdEndPointConfigPci_dom(
address, domainId, u8Seg, u8PciBus, u8PciDev, u8PciFunc,
u16PciReg, u8Size, (uint8_t*)&u32PciReadVal, &cc);
+ timeSpent = getTimeDifference(begin);
+ if (verbose && measureTime)
+ {
+ printf("\nTime taken in iteration %d = %lf s\n",
+ (loopCount - loops), timeSpent);
+ }
+ totalTimeSpent += timeSpent;
+
ccCounts[cc]++;
if (verbose || loops == 0)
@@ -756,9 +903,18 @@
}
while (loops--)
{
+ clock_gettime(CLOCK_REALTIME, &begin);
ret = peci_WrEndPointPCIConfig_dom(
address, domainId, u8Seg, u8PciBus, u8PciDev, u8PciFunc,
u16PciReg, u8Size, u32PciWriteVal, &cc);
+ timeSpent = getTimeDifference(begin);
+ if (verbose && measureTime)
+ {
+ printf("\nTime taken in iteration %d = %lf s\n",
+ (loopCount - loops), timeSpent);
+ }
+ totalTimeSpent += timeSpent;
+
ccCounts[cc]++;
if (verbose || loops == 0)
@@ -803,9 +959,18 @@
}
while (loops--)
{
+ clock_gettime(CLOCK_REALTIME, &begin);
ret = peci_RdEndPointConfigMmio_dom(
address, domainId, u8Seg, u8PciBus, u8PciDev, u8PciFunc, u8Bar,
u8AddrType, u64Offset, u8Size, (uint8_t*)&u32PciReadVal, &cc);
+ timeSpent = getTimeDifference(begin);
+ if (verbose && measureTime)
+ {
+ printf("\nTime taken in iteration %d = %lf s\n",
+ (loopCount - loops), timeSpent);
+ }
+ totalTimeSpent += timeSpent;
+
ccCounts[cc]++;
if (verbose || loops == 0)
@@ -857,9 +1022,18 @@
}
while (loops--)
{
+ clock_gettime(CLOCK_REALTIME, &begin);
ret = peci_WrEndPointConfigMmio_dom(
address, domainId, u8Seg, u8PciBus, u8PciDev, u8PciFunc, u8Bar,
u8AddrType, u64Offset, u8Size, u64MmioWriteVal, &cc);
+ timeSpent = getTimeDifference(begin);
+ if (verbose && measureTime)
+ {
+ printf("\nTime taken in iteration %d = %lf s\n",
+ (loopCount - loops), timeSpent);
+ }
+ totalTimeSpent += timeSpent;
+
ccCounts[cc]++;
if (verbose || loops == 0)
@@ -929,8 +1103,17 @@
}
while (loops--)
{
+ clock_gettime(CLOCK_REALTIME, &begin);
ret = peci_raw(rawAddr, readLength, rawCmd, writeLength, rawResp,
readLength);
+ timeSpent = getTimeDifference(begin);
+ if (verbose && measureTime)
+ {
+ printf("\nTime taken in iteration %d = %lf s\n",
+ (loopCount - loops), timeSpent);
+ }
+ totalTimeSpent += timeSpent;
+
if (verbose)
{
printf(" ");
@@ -970,6 +1153,16 @@
goto ErrorExit;
}
+ if (measureTime)
+ {
+ printf("Total time taken = %lf seconds\n", totalTimeSpent);
+ if (loopCount > 1)
+ {
+ printf("Average time taken per command = %lf seconds\n",
+ totalTimeSpent / loopCount);
+ }
+ }
+
return 0;
ErrorExit: