Merge pull request #5245 from sfc-gh-satherton/redwood-io-priority

Valgrind fixes in Redwood metrics, as well as metric accuracy fixes and output refactoring
This commit is contained in:
Steve Atherton 2021-07-21 14:34:42 -07:00 committed by GitHub
commit 31c63cb4e4
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
2 changed files with 94 additions and 125 deletions

View File

@ -42,31 +42,31 @@ typedef uint32_t QueueID;
// Pager Events
enum class PagerEvents { CacheLookup = 0, CacheHit, CacheMiss, PageWrite, MAXEVENTS };
static const std::string PagerEventsStrings[] = { "Lookup", "Hit", "Miss", "Write", "Unknown" };
static const char* const PagerEventsStrings[] = { "Lookup", "Hit", "Miss", "Write", "Unknown" };
// Reasons for page level events.
enum class PagerEventReasons { PointRead = 0, RangeRead, RangePrefetch, Commit, LazyClear, MetaData, MAXEVENTREASONS };
static const std::string PagerEventReasonsStrings[] = { "Get", "GetR", "GetRPF", "Commit", "LazyClr", "Meta", "Unknown" };
static const char* const PagerEventReasonsStrings[] = {
"Get", "GetR", "GetRPF", "Commit", "LazyClr", "Meta", "Unknown"
};
static const int nonBtreeLevel = 0;
static const std::pair<PagerEvents, PagerEventReasons> possibleEventReasonPairs[] = {
static const std::vector<std::pair<PagerEvents, PagerEventReasons>> possibleEventReasonPairs = {
{ PagerEvents::CacheLookup, PagerEventReasons::Commit },
{ PagerEvents::CacheLookup, PagerEventReasons::LazyClear },
{ PagerEvents::CacheLookup, PagerEventReasons::PointRead },
{ PagerEvents::CacheLookup, PagerEventReasons::RangeRead },
{ PagerEvents::CacheLookup, PagerEventReasons::LazyClear },
{ PagerEvents::CacheLookup, PagerEventReasons::MetaData },
{ PagerEvents::CacheHit, PagerEventReasons::Commit },
{ PagerEvents::CacheHit, PagerEventReasons::LazyClear },
{ PagerEvents::CacheHit, PagerEventReasons::PointRead },
{ PagerEvents::CacheHit, PagerEventReasons::RangeRead },
{ PagerEvents::CacheHit, PagerEventReasons::LazyClear },
{ PagerEvents::CacheHit, PagerEventReasons::MetaData },
{ PagerEvents::CacheHit, PagerEventReasons::Commit },
{ PagerEvents::CacheMiss, PagerEventReasons::Commit },
{ PagerEvents::CacheMiss, PagerEventReasons::LazyClear },
{ PagerEvents::CacheMiss, PagerEventReasons::PointRead },
{ PagerEvents::CacheMiss, PagerEventReasons::RangeRead },
{ PagerEvents::CacheMiss, PagerEventReasons::LazyClear },
{ PagerEvents::CacheMiss, PagerEventReasons::MetaData },
{ PagerEvents::CacheMiss, PagerEventReasons::Commit },
{ PagerEvents::PageWrite, PagerEventReasons::MetaData },
{ PagerEvents::PageWrite, PagerEventReasons::Commit },
{ PagerEvents::PageWrite, PagerEventReasons::LazyClear },
};
static const std::pair<PagerEvents, PagerEventReasons> L0PossibleEventReasonPairs[] = {
static const std::vector<std::pair<PagerEvents, PagerEventReasons>> L0PossibleEventReasonPairs = {
{ PagerEvents::CacheLookup, PagerEventReasons::RangePrefetch },
{ PagerEvents::CacheLookup, PagerEventReasons::MetaData },
{ PagerEvents::CacheHit, PagerEventReasons::RangePrefetch },

View File

@ -1447,85 +1447,59 @@ int nextPowerOf2(uint32_t x) {
}
struct RedwoodMetrics {
static constexpr int btreeLevels = 5;
static constexpr unsigned int btreeLevels = 5;
static int maxRecordCount;
struct EventReasonsArray {
unsigned int eventReasons[(size_t)PagerEvents::MAXEVENTS][(size_t)PagerEventReasons::MAXEVENTREASONS];
EventReasonsArray() { clear(); }
void clear() {
for (size_t i = 0; i < (size_t)PagerEvents::MAXEVENTS; i++) {
for (size_t j = 0; j < (size_t)PagerEventReasons::MAXEVENTREASONS; j++) {
eventReasons[i][j] = 0;
}
}
}
void clear() { memset(eventReasons, 0, sizeof(eventReasons)); }
void addEventReason(PagerEvents event, PagerEventReasons reason) {
eventReasons[(size_t)event][(size_t)reason] += 1;
}
const unsigned int& getEventReason(PagerEvents event, PagerEventReasons reason) {
unsigned int getEventReason(PagerEvents event, PagerEventReasons reason) const {
return eventReasons[(size_t)event][(size_t)reason];
}
std::string ouputSummary(int currLevel) {
std::string result = "";
PagerEvents prevEvent = PagerEvents::MAXEVENTS;
if (currLevel == 0) {
for (const auto& ER : L0PossibleEventReasonPairs) {
if (prevEvent != ER.first) {
result += "\n";
result += PagerEventsStrings[(size_t)ER.first];
result += "\n\t";
prevEvent = ER.first;
}
std::string num = std::to_string(eventReasons[(size_t)ER.first][(size_t)ER.second]);
result += PagerEventReasonsStrings[(size_t)ER.second];
result.append(16 - PagerEventReasonsStrings[(size_t)ER.second].length(), ' ');
result.append(8 - num.length(), ' ');
result += num;
result.append(13, ' ');
}
} else {
for (const auto& ER : possibleEventReasonPairs) {
if (prevEvent != ER.first) {
result += "\n";
result += PagerEventsStrings[(size_t)ER.first];
result += "\n\t";
prevEvent = ER.first;
}
std::string num = std::to_string(eventReasons[(size_t)ER.first][(size_t)ER.second]);
result += PagerEventReasonsStrings[(size_t)ER.second];
result.append(16 - PagerEventReasonsStrings[(size_t)ER.second].length(), ' ');
result.append(8 - num.length(), ' ');
result += num;
result.append(13, ' ');
std::string toString(int level, double elapsed) const {
std::string result;
const auto& pairs = (level == 0 ? L0PossibleEventReasonPairs : possibleEventReasonPairs);
PagerEvents prevEvent = pairs.front().first;
std::string lineStart = (level == 0) ? "" : "\t";
for (const auto& p : pairs) {
if (p.first != prevEvent) {
result += "\n";
result += lineStart;
}
std::string name =
format("%s%s", PagerEventsStrings[(int)p.first], PagerEventReasonsStrings[(int)p.second]);
int count = getEventReason(p.first, p.second);
result += format("%-15s %8u %8u/s ", name.c_str(), count, int(count / elapsed));
prevEvent = p.first;
}
return result;
}
void reportTrace(TraceEvent* t, int h) {
if (h == 0) {
for (const auto& ER : L0PossibleEventReasonPairs) {
t->detail(
format("L%d%s",
h,
(PagerEventsStrings[(size_t)ER.first] + PagerEventReasonsStrings[(size_t)ER.second])
.c_str()),
eventReasons[(size_t)ER.first][(size_t)ER.second]);
}
} else {
for (const auto& ER : possibleEventReasonPairs) {
t->detail(
format("L%d%s",
h,
(PagerEventsStrings[(size_t)ER.first] + PagerEventReasonsStrings[(size_t)ER.second])
.c_str()),
eventReasons[(size_t)ER.first][(size_t)ER.second]);
}
void toTraceEvent(TraceEvent* t, int level) const {
const auto& pairs = (level == 0 ? L0PossibleEventReasonPairs : possibleEventReasonPairs);
for (const auto& p : pairs) {
std::string name =
format(level == 0 ? "" : "L%d", level) +
format("%s%s", PagerEventsStrings[(int)p.first], PagerEventReasonsStrings[(int)p.second]);
int count = getEventReason(p.first, p.second);
t->detail(std::move(name), count);
}
}
};
// Metrics by level
struct Level {
struct Counters {
@ -1542,7 +1516,7 @@ struct RedwoodMetrics {
unsigned int lazyClearFreeExt;
unsigned int forceUpdate;
unsigned int detachChild;
EventReasonsArray eventReasons;
EventReasonsArray events;
};
Counters metrics;
Reference<Histogram> buildFillPctSketch;
@ -1554,37 +1528,33 @@ struct RedwoodMetrics {
Level() { clear(); }
void clear(int levelCounter = -1) {
void clear(int level = 0) {
metrics = {};
if (!buildFillPctSketch.isValid() ||
buildFillPctSketch->name() != ("buildFillPct:" + std::to_string(levelCounter))) {
std::string levelCounterStr = std::to_string(levelCounter);
buildFillPctSketch = Histogram::getHistogram(
LiteralStringRef("buildFillPct"), StringRef(levelCounterStr), Histogram::Unit::percentage);
modifyFillPctSketch = Histogram::getHistogram(
LiteralStringRef("modifyFillPct"), StringRef(levelCounterStr), Histogram::Unit::percentage);
buildStoredPctSketch = Histogram::getHistogram(
LiteralStringRef("buildStoredPct"), StringRef(levelCounterStr), Histogram::Unit::percentage);
modifyStoredPctSketch = Histogram::getHistogram(
LiteralStringRef("modifyStoredPct"), StringRef(levelCounterStr), Histogram::Unit::percentage);
buildItemCountSketch = Histogram::getHistogram(LiteralStringRef("buildItemCount"),
StringRef(levelCounterStr),
Histogram::Unit::count,
0,
maxRecordCount);
modifyItemCountSketch = Histogram::getHistogram(LiteralStringRef("modifyItemCount"),
StringRef(levelCounterStr),
Histogram::Unit::count,
0,
maxRecordCount);
if (level > 0) {
if (!buildFillPctSketch) {
std::string levelString = format("L%d", level);
buildFillPctSketch = Histogram::getHistogram(
LiteralStringRef("buildFillPct"), levelString, Histogram::Unit::percentage);
modifyFillPctSketch = Histogram::getHistogram(
LiteralStringRef("modifyFillPct"), levelString, Histogram::Unit::percentage);
buildStoredPctSketch = Histogram::getHistogram(
LiteralStringRef("buildStoredPct"), levelString, Histogram::Unit::percentage);
modifyStoredPctSketch = Histogram::getHistogram(
LiteralStringRef("modifyStoredPct"), levelString, Histogram::Unit::percentage);
buildItemCountSketch = Histogram::getHistogram(
LiteralStringRef("buildItemCount"), levelString, Histogram::Unit::count, 0, maxRecordCount);
modifyItemCountSketch = Histogram::getHistogram(
LiteralStringRef("modifyItemCount"), levelString, Histogram::Unit::count, 0, maxRecordCount);
}
buildFillPctSketch->clear();
modifyFillPctSketch->clear();
buildStoredPctSketch->clear();
modifyStoredPctSketch->clear();
buildItemCountSketch->clear();
modifyItemCountSketch->clear();
}
metrics.eventReasons.clear();
buildFillPctSketch->clear();
modifyFillPctSketch->clear();
buildStoredPctSketch->clear();
modifyStoredPctSketch->clear();
buildItemCountSketch->clear();
modifyItemCountSketch->clear();
}
};
@ -1652,18 +1622,17 @@ struct RedwoodMetrics {
}
Level& level(unsigned int level) {
static Level outOfBound;
// Valid levels are from 0 - btreeLevels
if (level < 0 || level > btreeLevels) {
return outOfBound;
}
return levels[level];
// Level 0 is for operations that are not BTree level specific, as many of the metrics are the same
// Level 0 - btreeLevels correspond to BTree node height, however heights above btreeLevels are combined
// into the level at btreeLevels
return levels[std::min(level, btreeLevels)];
}
void updateMaxRecordCount(int maxRecords) {
if (maxRecordCount != maxRecords) {
maxRecordCount = maxRecords;
for (int i = 0; i < btreeLevels + 1; ++i) {
for (int i = 1; i <= btreeLevels; ++i) {
auto& level = levels[i];
level.buildItemCountSketch->updateUpperBound(maxRecordCount);
level.modifyItemCountSketch->updateUpperBound(maxRecordCount);
@ -1699,8 +1668,8 @@ struct RedwoodMetrics {
{ "", 0 },
{ "PagerRemapFree", metric.pagerRemapFree },
{ "PagerRemapCopy", metric.pagerRemapCopy },
{ "PagerRemapSkip", metric.pagerRemapSkip } };
GetHistogramRegistry().logReport();
{ "PagerRemapSkip", metric.pagerRemapSkip },
{ "", 0 } };
double elapsed = now() - startTime;
@ -1711,6 +1680,7 @@ struct RedwoodMetrics {
e->detail(m.first, m.second);
}
}
levels[0].metrics.events.toTraceEvent(e, 0);
}
if (s != nullptr) {
@ -1721,10 +1691,10 @@ struct RedwoodMetrics {
*s += format("%-15s %-8u %8" PRId64 "/s ", m.first, m.second, int64_t(m.second / elapsed));
}
}
*s += "\n";
*s += levels[0].metrics.events.toString(0, elapsed);
}
for (int i = 0; i < btreeLevels + 1; ++i) {
for (int i = 1; i < btreeLevels + 1; ++i) {
auto& metric = levels[i].metrics;
std::pair<const char*, unsigned int> metrics[] = {
@ -1754,7 +1724,7 @@ struct RedwoodMetrics {
e->detail(format("L%d%s", i + 1, m.first + (c == '-' ? 1 : 0)), m.second);
}
}
metric.eventReasons.reportTrace(e, i);
metric.events.toTraceEvent(e, i);
}
if (s != nullptr) {
@ -1774,8 +1744,7 @@ struct RedwoodMetrics {
*s += format("%-15s %8u %8u/s ", name, m.second, rate ? int(m.second / elapsed) : 0);
}
}
*s += '\n';
*s += metric.eventReasons.ouputSummary(i);
*s += metric.events.toString(i, elapsed);
}
}
}
@ -2516,7 +2485,7 @@ public:
state PriorityMultiLock::Lock lock = wait(self->ioLock.lock(header ? ioMaxPriority : ioMinPriority));
++g_redwoodMetrics.metric.pagerDiskWrite;
g_redwoodMetrics.level(level).metrics.eventReasons.addEventReason(PagerEvents::PageWrite, reason);
g_redwoodMetrics.level(level).metrics.events.addEventReason(PagerEvents::PageWrite, reason);
if (self->memoryOnly) {
return Void();
@ -2792,7 +2761,7 @@ public:
bool noHit) override {
// Use cached page if present, without triggering a cache hit.
// Otherwise, read the page and return it but don't add it to the cache
auto& eventReasons = g_redwoodMetrics.level(level).metrics.eventReasons;
auto& eventReasons = g_redwoodMetrics.level(level).metrics.events;
eventReasons.addEventReason(PagerEvents::CacheLookup, reason);
if (!cacheable) {
debug_printf("DWALPager(%s) op=readUncached %s\n", filename.c_str(), toString(pageID).c_str());
@ -2950,7 +2919,7 @@ public:
Future<Reference<ArenaPage>> readExtent(LogicalPageID pageID) override {
debug_printf("DWALPager(%s) op=readExtent %s\n", filename.c_str(), toString(pageID).c_str());
PageCacheEntry* pCacheEntry = extentCache.getIfExists(pageID);
auto& eventReasons = g_redwoodMetrics.level(0).metrics.eventReasons;
auto& eventReasons = g_redwoodMetrics.level(0).metrics.events;
if (pCacheEntry != nullptr) {
eventReasons.addEventReason(PagerEvents::CacheLookup, PagerEventReasons::MetaData);
debug_printf("DWALPager(%s) Cache Entry exists for %s\n", filename.c_str(), toString(pageID).c_str());
@ -5412,8 +5381,8 @@ private:
}
debug_printf("readPage() op=readComplete %s @%" PRId64 " \n", toString(id).c_str(), snapshot->getVersion());
const BTreePage* pTreePage = (const BTreePage*)page->begin();
auto& metrics = g_redwoodMetrics.level(pTreePage->height).metrics;
const BTreePage* btPage = (const BTreePage*)page->begin();
auto& metrics = g_redwoodMetrics.level(btPage->height).metrics;
metrics.pageRead += 1;
metrics.pageReadExt += (id.size() - 1);
@ -6674,7 +6643,7 @@ public:
std::string toString() const {
std::string r = format("{ptr=%p reason=%s %s ",
this,
PagerEventsStrings[(int)reason].c_str(),
PagerEventsStrings[(int)reason],
::toString(pager->getVersion()).c_str());
for (int i = 0; i < path.size(); ++i) {
std::string id = "<debugOnly>";
@ -6738,11 +6707,11 @@ public:
// Initialize or reinitialize cursor
Future<Void> init(VersionedBTree* btree_in,
PagerEventReasons reason,
PagerEventReasons reason_in,
Reference<IPagerSnapshot> pager_in,
BTreePageIDRef root) {
btree = btree_in;
reason = reason;
reason = reason_in;
pager = pager_in;
path.clear();
path.reserve(6);
@ -9056,7 +9025,7 @@ TEST_CASE("/redwood/correctness/btree") {
mutationBytesThisCommit >= mutationBytesTargetThisCommit) {
// Wait for previous commit to finish
wait(commit);
printf("Last commit complete. Next commit %d bytes, %" PRId64 " bytes committed so far.",
printf("Commit complete. Next commit %d bytes, %" PRId64 " bytes committed so far.",
mutationBytesThisCommit,
mutationBytes.get() - mutationBytesThisCommit);
printf(" Stats: Insert %.2f MB/s ClearedKeys %.2f MB/s Total %.2f\n",