Merge pull request #6724 from sfc-gh-yiwu/file_latency

AsyncFileKAIO: add latency histograms
This commit is contained in:
Steve Atherton 2022-03-30 19:17:34 -07:00 committed by GitHub
commit 26e34a947f
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
1 changed files with 47 additions and 3 deletions

View File

@ -30,14 +30,17 @@
#define FLOW_ASYNCFILEKAIO_ACTOR_H
#include "fdbrpc/IAsyncFile.h"
#include <stdio.h>
#include <fcntl.h>
#include <sys/stat.h>
#include <sys/eventfd.h>
#include <sys/syscall.h>
#include "fdbrpc/linux_kaio.h"
#include "fdbserver/Knobs.h"
#include "flow/Knobs.h"
#include "flow/Histogram.h"
#include "flow/UnitTest.h"
#include <stdio.h>
#include "flow/crc32c.h"
#include "flow/genericactors.actor.h"
#include "flow/actorcompiler.h" // This must be the last #include.
@ -46,6 +49,14 @@
// /data/v7/fdb/
#define KAIO_LOGGING 0
struct AsyncFileKAIOMetrics {
Reference<Histogram> readLatencyDist;
Reference<Histogram> writeLatencyDist;
Reference<Histogram> syncLatencyDist;
} g_asyncFileKAIOMetrics;
Future<Void> g_asyncFileKAIOHistogramLogger;
DESCR struct SlowAioSubmit {
int64_t submitDuration; // ns
int64_t truncateDuration; // ns
@ -343,6 +354,7 @@ public:
#endif
KAIOLogEvent(logFile, id, OpLogEntry::SYNC, OpLogEntry::START);
double start_time = now();
Future<Void> fsync = throwErrorIfFailed(
Reference<AsyncFileKAIO>::addRef(this),
@ -352,12 +364,11 @@ public:
submit(io, "write");
fsync=success(io->result.getFuture());*/
#if KAIO_LOGGING
fsync = map(fsync, [=](Void r) mutable {
KAIOLogEvent(logFile, id, OpLogEntry::SYNC, OpLogEntry::COMPLETE);
g_asyncFileKAIOMetrics.syncLatencyDist->sampleSeconds(now() - start_time);
return r;
});
#endif
if (flags & OPEN_ATOMIC_WRITE_AND_CREATE) {
flags &= ~OPEN_ATOMIC_WRITE_AND_CREATE;
@ -630,6 +641,16 @@ private:
countFileLogicalReads.init(LiteralStringRef("AsyncFile.CountFileLogicalReads"), filename);
countLogicalWrites.init(LiteralStringRef("AsyncFile.CountLogicalWrites"));
countLogicalReads.init(LiteralStringRef("AsyncFile.CountLogicalReads"));
if (!g_asyncFileKAIOHistogramLogger.isValid()) {
auto& metrics = g_asyncFileKAIOMetrics;
metrics.readLatencyDist = Reference<Histogram>(new Histogram(
Reference<HistogramRegistry>(), "AsyncFileKAIO", "ReadLatency", Histogram::Unit::microseconds));
metrics.writeLatencyDist = Reference<Histogram>(new Histogram(
Reference<HistogramRegistry>(), "AsyncFileKAIO", "WriteLatency", Histogram::Unit::microseconds));
metrics.syncLatencyDist = Reference<Histogram>(new Histogram(
Reference<HistogramRegistry>(), "AsyncFileKAIO", "SyncLatency", Histogram::Unit::microseconds));
g_asyncFileKAIOHistogramLogger = histogramLogger(SERVER_KNOBS->DISK_METRIC_LOGGING_INTERVAL);
}
}
#if KAIO_LOGGING
@ -749,10 +770,33 @@ private:
ctx.removeFromRequestList(iob);
}
auto& metrics = g_asyncFileKAIOMetrics;
switch (iob->aio_lio_opcode) {
case IO_CMD_PREAD:
metrics.readLatencyDist->sampleSeconds(now() - iob->startTime);
break;
case IO_CMD_PWRITE:
metrics.writeLatencyDist->sampleSeconds(now() - iob->startTime);
break;
}
iob->setResult(ev[i].result);
}
}
}
ACTOR static Future<Void> histogramLogger(double interval) {
state double currentTime;
loop {
currentTime = now();
wait(delay(interval));
double elapsed = now() - currentTime;
auto& metrics = g_asyncFileKAIOMetrics;
metrics.readLatencyDist->writeToLog(elapsed);
metrics.writeLatencyDist->writeToLog(elapsed);
metrics.syncLatencyDist->writeToLog(elapsed);
}
}
};
#if KAIO_LOGGING