mirror of
https://github.com/matrix-construct/construct
synced 2024-09-25 18:08:52 +02:00
ircd::db: Use if constexpr for verbose seek debug log.
This commit is contained in:
Jason Volk
parent
671120415f
commit
6fd08ba0a3
2 changed files with 121 additions and 128 deletions
243
ircd/db.cc
243
ircd/db.cc
|
|
@ -781,20 +781,19 @@ 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",
|
||||||
ticker->rejects,
|
ticker->rejects,
|
||||||
ticker->request,
|
ticker->request,
|
||||||
ticker->handles,
|
ticker->handles,
|
||||||
ticker->fetches,
|
ticker->fetches,
|
||||||
ticker->directs,
|
ticker->directs,
|
||||||
ticker->cancels,
|
ticker->cancels,
|
||||||
queue.size(),
|
queue.size(),
|
||||||
this->request_workers,
|
this->request_workers,
|
||||||
};
|
};
|
||||||
#endif
|
|
||||||
}
|
}
|
||||||
|
|
||||||
size_t
|
size_t
|
||||||
|
|
@ -844,23 +843,23 @@ 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];
|
||||||
log::debug
|
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",
|
{
|
||||||
name(*request.d),
|
log, "[%s][%s] completed prefetch "
|
||||||
name(column),
|
"len:%zu lte:%b k:%zu v:%zu snd-req:%s req-fin:%s snd-fin:%s queue:%zu",
|
||||||
size(key),
|
name(*request.d),
|
||||||
lte,
|
name(column),
|
||||||
lte? size(it->key()) : 0UL,
|
size(key),
|
||||||
lte? size(it->value()) : 0UL,
|
lte,
|
||||||
pretty(pbuf[0], request.req - request.snd, 1),
|
lte? size(it->key()) : 0UL,
|
||||||
pretty(pbuf[1], request.fin - request.req, 1),
|
lte? size(it->value()) : 0UL,
|
||||||
pretty(pbuf[2], request.fin - request.snd, 1),
|
pretty(pbuf[0], request.req - request.snd, 1),
|
||||||
queue.size(),
|
pretty(pbuf[1], request.fin - request.req, 1),
|
||||||
};
|
pretty(pbuf[2], request.fin - request.snd, 1),
|
||||||
#endif
|
queue.size(),
|
||||||
|
};
|
||||||
}
|
}
|
||||||
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,26 +1814,25 @@ 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 database &d(c);
|
|
||||||
thread_local char tmbuf[32];
|
|
||||||
log::debug
|
|
||||||
{
|
{
|
||||||
log, "'%s' SEEK ROW seq:%lu:%-10lu cnt:%-2zu req:%-2zu ret:%-2zu in %s %s",
|
const column &c(r[0]);
|
||||||
name(d),
|
const database &d(c);
|
||||||
sequence(d),
|
thread_local char tmbuf[32];
|
||||||
sequence(opts.snapshot),
|
log::debug
|
||||||
r.size(),
|
{
|
||||||
submits,
|
log, "'%s' SEEK ROW seq:%lu:%-10lu cnt:%-2zu req:%-2zu ret:%-2zu in %s %s",
|
||||||
ret,
|
name(d),
|
||||||
pretty(tmbuf, timer.at<microseconds>(), true),
|
sequence(d),
|
||||||
what(eptr)
|
sequence(opts.snapshot),
|
||||||
};
|
r.size(),
|
||||||
}
|
submits,
|
||||||
#endif
|
ret,
|
||||||
|
pretty(tmbuf, timer.at<microseconds>(), true),
|
||||||
|
what(eptr)
|
||||||
|
};
|
||||||
|
}
|
||||||
|
|
||||||
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,28 +4785,27 @@ 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",
|
||||||
name(d),
|
name(d),
|
||||||
sequence(d),
|
sequence(d),
|
||||||
sequence(ropts.snapshot),
|
sequence(ropts.snapshot),
|
||||||
ret.size(),
|
ret.size(),
|
||||||
std::count_if(begin(ret), end(ret), [](auto&& s) { return s.ok(); }),
|
std::count_if(begin(ret), end(ret), [](auto&& s) { return s.ok(); }),
|
||||||
std::count_if(begin(ret), end(ret), [](auto&& s) { return s.IsNotFound(); }),
|
std::count_if(begin(ret), end(ret), [](auto&& s) { return s.IsNotFound(); }),
|
||||||
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,26 +4863,25 @@ 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);
|
||||||
log::debug
|
if constexpr(RB_DEBUG_DB_SEEK)
|
||||||
{
|
log::debug
|
||||||
log, "[%s] %lu:%lu SEEK %s %s in %ld$us '%s'",
|
{
|
||||||
name(d),
|
log, "[%s] %lu:%lu SEEK %s %s in %ld$us '%s'",
|
||||||
sequence(d),
|
name(d),
|
||||||
sequence(opts.snapshot),
|
sequence(d),
|
||||||
valid(it)? "VALID" : "INVALID",
|
sequence(opts.snapshot),
|
||||||
it.status().ToString(),
|
valid(it)? "VALID" : "INVALID",
|
||||||
timer.at<microseconds>().count(),
|
it.status().ok()? "OK"s: it.status().ToString(),
|
||||||
name(c)
|
timer.at<microseconds>().count(),
|
||||||
};
|
name(c)
|
||||||
#endif
|
};
|
||||||
|
|
||||||
return valid(it);
|
return valid(it);
|
||||||
}
|
}
|
||||||
|
|
@ -4916,31 +4910,30 @@ 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);
|
||||||
log::debug
|
if constexpr(RB_DEBUG_DB_SEEK)
|
||||||
{
|
log::debug
|
||||||
log, "[%s] %lu:%lu SEEK[%s] %s -> %s in %ld$us '%s'",
|
{
|
||||||
name(d),
|
log, "[%s] %lu:%lu SEEK[%s] %s -> %s in %ld$us '%s'",
|
||||||
sequence(d),
|
name(d),
|
||||||
sequence(opts.snapshot),
|
sequence(d),
|
||||||
reflect(p),
|
sequence(opts.snapshot),
|
||||||
valid_it? "VALID" : "INVALID",
|
reflect(p),
|
||||||
it.status().ToString(),
|
valid_it? "VALID" : "INVALID",
|
||||||
timer.at<microseconds>().count(),
|
it.status().ok()? "OK"s: it.status().ToString(),
|
||||||
name(c)
|
timer.at<microseconds>().count(),
|
||||||
};
|
name(c)
|
||||||
#endif
|
};
|
||||||
|
|
||||||
return valid(it);
|
return valid(it);
|
||||||
}
|
}
|
||||||
|
|
|
||||||
|
|
@ -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
|
||||||
|
|
|
||||||
Loading…
Reference in a new issue