Change KAIO latency metrics to use LatencySample for easier usability. Rename a SQLite-specific knob to indicate it is specific to SQLite.

This commit is contained in:
Steve Atherton 2022-09-15 13:27:23 -07:00
parent c7924c9fb3
commit 2bf90ca5ec
4 changed files with 30 additions and 39 deletions

View File

@ -38,7 +38,7 @@
#include <sys/syscall.h>
#include "fdbrpc/linux_kaio.h"
#include "flow/Knobs.h"
#include "flow/Histogram.h"
#include "fdbrpc/Stats.h"
#include "flow/UnitTest.h"
#include "crc32/crc32c.h"
#include "flow/genericactors.actor.h"
@ -48,14 +48,6 @@
// /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
@ -66,6 +58,25 @@ DESCR struct SlowAioSubmit {
class AsyncFileKAIO final : public IAsyncFile, public ReferenceCounted<AsyncFileKAIO> {
public:
struct AsyncFileKAIOMetrics {
LatencySample readLatencySample = { "AsyncFileKAIOReadLatency",
UID(),
FLOW_KNOBS->KAIO_LATENCY_LOGGING_INTERVAL,
FLOW_KNOBS->KAIO_LATENCY_SAMPLE_SIZE };
LatencySample writeLatencySample = { "AsyncFileKAIOWriteLatency",
UID(),
FLOW_KNOBS->KAIO_LATENCY_LOGGING_INTERVAL,
FLOW_KNOBS->KAIO_LATENCY_SAMPLE_SIZE };
LatencySample syncLatencySample = { "AsyncFileKAIOSyncLatency",
UID(),
FLOW_KNOBS->KAIO_LATENCY_LOGGING_INTERVAL,
FLOW_KNOBS->KAIO_LATENCY_SAMPLE_SIZE };
};
static AsyncFileKAIOMetrics& getMetrics() {
static AsyncFileKAIOMetrics metrics;
return metrics;
}
#if KAIO_LOGGING
private:
@ -365,7 +376,7 @@ public:
fsync = map(fsync, [=](Void r) mutable {
KAIOLogEvent(logFile, id, OpLogEntry::SYNC, OpLogEntry::COMPLETE);
g_asyncFileKAIOMetrics.syncLatencyDist->sampleSeconds(now() - start_time);
getMetrics().syncLatencySample.addMeasurement(now() - start_time);
return r;
});
@ -640,16 +651,6 @@ 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(FLOW_KNOBS->DISK_METRIC_LOGGING_INTERVAL);
}
}
#if KAIO_LOGGING
@ -769,13 +770,12 @@ private:
ctx.removeFromRequestList(iob);
}
auto& metrics = g_asyncFileKAIOMetrics;
switch (iob->aio_lio_opcode) {
case IO_CMD_PREAD:
metrics.readLatencyDist->sampleSeconds(now() - iob->startTime);
getMetrics().readLatencySample.addMeasurement(now() - iob->startTime);
break;
case IO_CMD_PWRITE:
metrics.writeLatencyDist->sampleSeconds(now() - iob->startTime);
getMetrics().writeLatencySample.addMeasurement(now() - iob->startTime);
break;
}
@ -783,19 +783,6 @@ private:
}
}
}
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

View File

@ -1996,7 +1996,7 @@ private:
state int64_t lastReadsComplete = 0;
state int64_t lastWritesComplete = 0;
loop {
wait(delay(FLOW_KNOBS->DISK_METRIC_LOGGING_INTERVAL));
wait(delay(FLOW_KNOBS->SQLITE_DISK_METRIC_LOGGING_INTERVAL));
int64_t rc = self->readsComplete, wc = self->writesComplete;
TraceEvent("DiskMetrics", self->logID)

View File

@ -163,7 +163,9 @@ void FlowKnobs::initialize(Randomize randomize, IsSimulated isSimulated) {
//AsyncFileKAIO
init( MAX_OUTSTANDING, 64 );
init( MIN_SUBMIT, 10 );
init( DISK_METRIC_LOGGING_INTERVAL, 5.0 );
init( SQLITE_DISK_METRIC_LOGGING_INTERVAL, 5.0 );
init( KAIO_LATENCY_LOGGING_INTERVAL, 30.0 );
init( KAIO_LATENCY_SAMPLE_SIZE, 30000 );
init( PAGE_WRITE_CHECKSUM_HISTORY, 0 ); if( randomize && BUGGIFY ) PAGE_WRITE_CHECKSUM_HISTORY = 10000000;
init( DISABLE_POSIX_KERNEL_AIO, 0 );

View File

@ -227,7 +227,9 @@ public:
// AsyncFileKAIO
int MAX_OUTSTANDING;
int MIN_SUBMIT;
double DISK_METRIC_LOGGING_INTERVAL;
double SQLITE_DISK_METRIC_LOGGING_INTERVAL;
double KAIO_LATENCY_LOGGING_INTERVAL;
int KAIO_LATENCY_SAMPLE_SIZE;
int PAGE_WRITE_CHECKSUM_HISTORY;
int DISABLE_POSIX_KERNEL_AIO;