MirrorHub/construct
0
0
Fork 0
mirror of https://github.com/matrix-construct/construct synced 2024-11-12 13:01:07 +01:00
Code Issues Releases Wiki Activity

ircd::db: Use if constexpr for verbose seek debug log.

Browse source
This commit is contained in:
Jason Volk 2022-06-15 13:46:38 -07:00
parent 671120415f
commit 6fd08ba0a3
2 changed files with 121 additions and 128 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

73
ircd/db.cc
View file

@ -781,7 +781,7 @@ ircd::db::prefetcher::request_worker()
assert(request->fin != steady_point::min()); assert(request->fin != steady_point::min());
ticker->fetched++; ticker->fetched++;
#ifdef IRCD_DB_DEBUG_PREFETCH if constexpr(RB_DEBUG_DB_PREFETCH)
log::debug log::debug
{ {
log, "prefetcher reject:%zu request:%zu handle:%zu fetch:%zu direct:%zu cancel:%zu queue:%zu rw:%zu", log, "prefetcher reject:%zu request:%zu handle:%zu fetch:%zu direct:%zu cancel:%zu queue:%zu rw:%zu",
@ -794,7 +794,6 @@ ircd::db::prefetcher::request_worker()
queue.size(), queue.size(),
this->request_workers, this->request_workers,
}; };
#endif
} }
size_t size_t
@ -844,11 +843,12 @@ try
ticker->fetched_bytes_val += size(it->value()); ticker->fetched_bytes_val += size(it->value());
} }
#ifdef IRCD_DB_DEBUG_PREFETCH
char pbuf[3][32]; char pbuf[3][32];
if constexpr(RB_DEBUG_DB_PREFETCH)
log::debug log::debug
{ {
log, "[%s][%s] completed prefetch len:%zu lte:%b k:%zu v:%zu snd-req:%s req-fin:%s snd-fin:%s queue:%zu", log, "[%s][%s] completed prefetch "
"len:%zu lte:%b k:%zu v:%zu snd-req:%s req-fin:%s snd-fin:%s queue:%zu",
name(*request.d), name(*request.d),
name(column), name(column),
size(key), size(key),
@ -860,7 +860,6 @@ try
pretty(pbuf[2], request.fin - request.snd, 1), pretty(pbuf[2], request.fin - request.snd, 1),
queue.size(), queue.size(),
}; };
#endif
} }
catch(const std::exception &e) catch(const std::exception &e)
{ {
@ -1774,10 +1773,10 @@ ircd::db::seek(row &r,
latch.count_down(); latch.count_down();
}}; }};
#ifdef RB_DEBUG_DB_SEEK_ROW
const ircd::timer timer;
size_t submits{0}; size_t submits{0};
#endif util::timer timer{util::timer::nostart};
if constexpr(RB_DEBUG_DB_SEEK_ROW)
timer = util::timer{};
// Submit all the requests // Submit all the requests
for(auto &cell : r) for(auto &cell : r)
@ -1802,9 +1801,8 @@ ircd::db::seek(row &r,
!db::cached(column, key, opts) !db::cached(column, key, opts)
}; };
#ifdef RB_DEBUG_DB_SEEK_ROW if constexpr(RB_DEBUG_DB_SEEK_ROW)
submits += submit; submits += submit;
#endif
if(submit) if(submit)
request(reclosure); request(reclosure);
@ -1816,7 +1814,7 @@ ircd::db::seek(row &r,
latch.wait(); latch.wait();
assert(ret <= r.size()); assert(ret <= r.size());
#ifdef RB_DEBUG_DB_SEEK_ROW if constexpr(RB_DEBUG_DB_SEEK_ROW)
if(likely(!r.empty())) if(likely(!r.empty()))
{ {
const column &c(r[0]); const column &c(r[0]);
@ -1835,7 +1833,6 @@ ircd::db::seek(row &r,
what(eptr) what(eptr)
}; };
} }
#endif
if(eptr && !test(opts, get::NO_THROW)) if(eptr && !test(opts, get::NO_THROW))
std::rethrow_exception(eptr); std::rethrow_exception(eptr);
@ -4644,27 +4641,26 @@ ircd::db::_seek(database::column &c,
rocksdb::ColumnFamilyHandle *const &cf(c); rocksdb::ColumnFamilyHandle *const &cf(c);
database &d(*c.d); database &d(*c.d);
#ifdef RB_DEBUG_DB_SEEK util::timer timer{util::timer::nostart};
const ircd::timer timer; if constexpr(RB_DEBUG_DB_SEEK)
#endif timer = {};
const rocksdb::Status ret const rocksdb::Status ret
{ {
d.d->Get(ropts, cf, slice(key), &s) d.d->Get(ropts, cf, slice(key), &s)
}; };
#ifdef RB_DEBUG_DB_SEEK if constexpr(RB_DEBUG_DB_SEEK)
log::debug log::debug
{ {
log, "[%s] %lu:%lu SEEK %s in %ld$us '%s'", log, "[%s] %lu:%lu SEEK %s in %ld$us '%s'",
name(d), name(d),
sequence(d), sequence(d),
sequence(ropts.snapshot), sequence(ropts.snapshot),
ret.ToString(), ret.ok()? "OK"s: ret.ToString(),
timer.at<microseconds>().count(), timer.at<microseconds>().count(),
name(c) name(c)
}; };
#endif
return ret; return ret;
} }
@ -4789,15 +4785,15 @@ ircd::db::_seek(const vector_view<_read_op> &op,
return static_cast<rocksdb::ColumnFamilyHandle *>(c); return static_cast<rocksdb::ColumnFamilyHandle *>(c);
}); });
#ifdef RB_DEBUG_DB_SEEK util::timer timer{util::timer::nostart};
const ircd::timer timer; if constexpr(RB_DEBUG_DB_SEEK)
#endif timer = {};
#ifdef IRCD_DB_HAS_MULTIGET_BATCHED #ifdef IRCD_DB_HAS_MULTIGET_BATCHED
d.d->MultiGet(ropts, num, cf, key, val.data(), ret.data()); d.d->MultiGet(ropts, num, cf, key, val.data(), ret.data());
#endif #endif
#ifdef RB_DEBUG_DB_SEEK if constexpr(RB_DEBUG_DB_SEEK)
log::debug log::debug
{ {
log, "[%s] %lu:%lu SEEK parallel:%zu ok:%zu nf:%zu inc:%zu in %ld$us", log, "[%s] %lu:%lu SEEK parallel:%zu ok:%zu nf:%zu inc:%zu in %ld$us",
@ -4810,7 +4806,6 @@ ircd::db::_seek(const vector_view<_read_op> &op,
std::count_if(begin(ret), end(ret), [](auto&& s) { return s.IsIncomplete(); }), std::count_if(begin(ret), end(ret), [](auto&& s) { return s.IsIncomplete(); }),
timer.at<microseconds>().count(), timer.at<microseconds>().count(),
}; };
#endif
} }
// //
@ -4868,14 +4863,14 @@ try
{ {
const ctx::uninterruptible ui; const ctx::uninterruptible ui;
#ifdef RB_DEBUG_DB_SEEK util::timer timer{util::timer::nostart};
database &d(*c.d); if constexpr(RB_DEBUG_DB_SEEK_ROW)
const ircd::timer timer; timer = util::timer{};
#endif
_seek_(it, p); _seek_(it, p);
#ifdef RB_DEBUG_DB_SEEK database &d(*c.d);
if constexpr(RB_DEBUG_DB_SEEK)
log::debug log::debug
{ {
log, "[%s] %lu:%lu SEEK %s %s in %ld$us '%s'", log, "[%s] %lu:%lu SEEK %s %s in %ld$us '%s'",
@ -4883,11 +4878,10 @@ try
sequence(d), sequence(d),
sequence(opts.snapshot), sequence(opts.snapshot),
valid(it)? "VALID" : "INVALID", valid(it)? "VALID" : "INVALID",
it.status().ToString(), it.status().ok()? "OK"s: it.status().ToString(),
timer.at<microseconds>().count(), timer.at<microseconds>().count(),
name(c) name(c)
}; };
#endif
return valid(it); return valid(it);
} }
@ -4916,18 +4910,18 @@ try
{ {
const ctx::stack_usage_assertion sua; const ctx::stack_usage_assertion sua;
#ifdef RB_DEBUG_DB_SEEK bool valid_it;
database &d(*c.d); util::timer timer{util::timer::nostart};
const ircd::timer timer; if constexpr(RB_DEBUG_DB_SEEK_ROW)
const bool valid_it
{ {
valid(it) valid_it = valid(it);
}; timer = util::timer{};
#endif }
_seek_(it, p); _seek_(it, p);
#ifdef RB_DEBUG_DB_SEEK database &d(*c.d);
if constexpr(RB_DEBUG_DB_SEEK)
log::debug log::debug
{ {
log, "[%s] %lu:%lu SEEK[%s] %s -> %s in %ld$us '%s'", log, "[%s] %lu:%lu SEEK[%s] %s -> %s in %ld$us '%s'",
@ -4936,11 +4930,10 @@ try
sequence(opts.snapshot), sequence(opts.snapshot),
reflect(p), reflect(p),
valid_it? "VALID" : "INVALID", valid_it? "VALID" : "INVALID",
it.status().ToString(), it.status().ok()? "OK"s: it.status().ToString(),
timer.at<microseconds>().count(), timer.at<microseconds>().count(),
name(c) name(c)
}; };
#endif
return valid(it); return valid(it);
} }

6
ircd/db.h
View file

@ -21,9 +21,9 @@
/// It is still so verbose that it goes beyond what is tolerable and generally /// It is still so verbose that it goes beyond what is tolerable and generally
/// useful even in debug-mode builds, thus the manual #define being required. /// useful even in debug-mode builds, thus the manual #define being required.
/// ///
//#define RB_DEBUG_DB_SEEK #define RB_DEBUG_DB_SEEK 0
//#define RB_DEBUG_DB_SEEK_ROW #define RB_DEBUG_DB_SEEK_ROW 0
//#define IRCD_DB_DEBUG_PREFETCH #define RB_DEBUG_DB_PREFETCH 0
/// Set this #define to 1 or 2 to enable extensive log messages for the /// Set this #define to 1 or 2 to enable extensive log messages for the
/// experimental db environment-port implementation. This is only useful /// experimental db environment-port implementation. This is only useful