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

ircd::ctx: Sample rdtsc to complement profile warning output.

This commit is contained in:
Jason Volk 2018-02-05 10:47:46 -08:00
parent 7b48bc9f40
commit 3ba527079b
2 changed files with 28 additions and 10 deletions

View file

@ -452,6 +452,9 @@ RB_CHK_SYSHEADER(winsock2.h, [WINSOCK2_H])
RB_CHK_SYSHEADER(ws2tcpip.h, [WS2TCPIP_H]) RB_CHK_SYSHEADER(ws2tcpip.h, [WS2TCPIP_H])
RB_CHK_SYSHEADER(iphlpapi.h, [IPHLPAPI_H]) RB_CHK_SYSHEADER(iphlpapi.h, [IPHLPAPI_H])
dnl x86 platform
RB_CHK_SYSHEADER(x86intrin.h, [X86INTRIN_H])
dnl experimental dnl experimental
RB_CHK_SYSHEADER(experimental/string_view, [EXPERIMENTAL_STRING_VIEW]) RB_CHK_SYSHEADER(experimental/string_view, [EXPERIMENTAL_STRING_VIEW])
RB_CHK_SYSHEADER(experimental/optional, [EXPERIMENTAL_OPTIONAL]) RB_CHK_SYSHEADER(experimental/optional, [EXPERIMENTAL_OPTIONAL])

View file

@ -8,6 +8,7 @@
// copyright notice and this permission notice is present in all copies. The // copyright notice and this permission notice is present in all copies. The
// full license for this software is available in the LICENSE file. // full license for this software is available in the LICENSE file.
#include <RB_INC_X86INTRIN_H
#include <ircd/asio.h> #include <ircd/asio.h>
/// Internal context implementation /// Internal context implementation
@ -798,6 +799,7 @@ ircd::ctx::debug_stats(const pool &pool)
namespace ircd::ctx::prof namespace ircd::ctx::prof
{ {
time_point cur_slice_start; // Time slice state time_point cur_slice_start; // Time slice state
uint64_t cur_slice_rdtsc; // Time slice state
void check_stack(); void check_stack();
void check_slice(); void check_slice();
@ -860,32 +862,45 @@ ircd::ctx::prof::handle_cur_continue()
void void
ircd::ctx::prof::slice_start() ircd::ctx::prof::slice_start()
{ {
cur_slice_rdtsc = __rdtsc();
cur_slice_start = steady_clock::now(); cur_slice_start = steady_clock::now();
} }
void void
ircd::ctx::prof::check_slice() ircd::ctx::prof::check_slice()
{ {
auto &c(cur()); const uint64_t now_rdtsc(__rdtsc());
const uint64_t rdtsc_usage(now_rdtsc - cur_slice_rdtsc);
const auto time_usage(steady_clock::now() - cur_slice_start); const auto now_sc(steady_clock::now());
const auto time_usage(now_sc - cur_slice_start);
auto &c(cur());
c.awake += duration_cast<microseconds>(time_usage); c.awake += duration_cast<microseconds>(time_usage);
if(unlikely(settings.slice_warning > 0us && time_usage >= settings.slice_warning)) if(unlikely(settings.slice_warning > 0us && time_usage >= settings.slice_warning))
{ {
log::warning("context timeslice exceeded (%p) '%s' last: %06ld$us total: %06ld$us", log::warning
(const void *)&c, {
c.name, "context timeslice exceeded '%s' (%lu) total: %06ld$us last: %lu$ns %lu$tsc",
duration_cast<microseconds>(time_usage).count(), name(c),
c.awake.count()); id(c),
c.awake.count(),
duration_cast<nanoseconds>(time_usage).count(),
rdtsc_usage
};
assert(settings.slice_assertion == 0us || time_usage < settings.slice_assertion); assert(settings.slice_assertion == 0us || time_usage < settings.slice_assertion);
} }
if(unlikely(settings.slice_interrupt > 0us && time_usage >= settings.slice_interrupt)) if(unlikely(settings.slice_interrupt > 0us && time_usage >= settings.slice_interrupt))
throw interrupted("ctx(%p): Time slice exceeded (last: %06ld microseconds)", throw interrupted
(const void *)&c, {
duration_cast<microseconds>(time_usage).count()); "Time slice exceeded '%s' (%lu) (last: %06ld microseconds)",
name(c),
id(c),
duration_cast<microseconds>(time_usage).count()
};
} }
void void