0
0
Fork 0
mirror of https://github.com/matrix-construct/construct synced 2024-11-12 13:01:07 +01:00

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

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

View file

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

View file

@ -21,9 +21,9 @@
/// 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.
///
//#define RB_DEBUG_DB_SEEK
//#define RB_DEBUG_DB_SEEK_ROW
//#define IRCD_DB_DEBUG_PREFETCH
#define RB_DEBUG_DB_SEEK 0
#define RB_DEBUG_DB_SEEK_ROW 0
#define RB_DEBUG_DB_PREFETCH 0
/// Set this #define to 1 or 2 to enable extensive log messages for the
/// experimental db environment-port implementation. This is only useful