From ac42d4df13225ac466cfc733ca0954953cf5b6bc Mon Sep 17 00:00:00 2001
From: Jason Volk <jason@zemos.net>
Date: Sun, 24 May 2020 16:43:56 -0700
Subject: [PATCH] ircd::ctx: Measure and report epoch span for
 slice_usage_warning.

---
 include/ircd/ctx/slice_usage_warning.h |  1 +
 ircd/ctx.cc                            | 16 +++++++++++++++-
 2 files changed, 16 insertions(+), 1 deletion(-)

diff --git a/include/ircd/ctx/slice_usage_warning.h b/include/ircd/ctx/slice_usage_warning.h
index 1fec3919c..4b8266cc9 100644
--- a/include/ircd/ctx/slice_usage_warning.h
+++ b/include/ircd/ctx/slice_usage_warning.h
@@ -22,6 +22,7 @@ struct ircd::ctx::this_ctx::slice_usage_warning
 {
 	string_view fmt;
 	va_rtti ap;
+	ulong epoch;
 	ulong start;
 
 	template<class... args>
diff --git a/ircd/ctx.cc b/ircd/ctx.cc
index c218a598b..82149fedf 100644
--- a/ircd/ctx.cc
+++ b/ircd/ctx.cc
@@ -917,6 +917,12 @@ ircd::ctx::this_ctx::slice_usage_warning::slice_usage_warning(const string_view
 {
 	std::move(ap)
 }
+,epoch
+{
+	current?
+		ircd::ctx::epoch(cur()):
+		ircd::ctx::epoch()
+}
 ,start
 {
 	// Set the start value to the total number of cycles accrued by this
@@ -956,6 +962,13 @@ noexcept
 	if(likely(!prof::slice_exceeded_warning(total)))
 		return;
 
+	const auto span
+	{
+		current?
+			ircd::ctx::epoch(cur()) - this->epoch:
+			ircd::ctx::epoch() - this->epoch
+	};
+
 	thread_local char buf[256];
 	const string_view reason{fmt::vsprintf
 	{
@@ -965,12 +978,13 @@ noexcept
 	const ulong &threshold{prof::settings::slice_warning};
 	log::dwarning
 	{
-		log, "[%s] context id:%lu watchdog :timeslice excessive; lim:%lu this:%lu pct:%.2lf :%s",
+		log, "[%s] context id:%lu watchdog :timeslice excessive; lim:%lu this:%lu pct:%.2lf span:%lu :%s",
 		current? name(cur()) : ""_sv,
 		current? id(cur()) : 0,
 		threshold,
 		total,
 		(double(total) / double(threshold)) * 100.0,
+		span,
 		reason
 	};
 }