ircd::ios: Add constexpr verbose debug; add inline enqueue(); reorg.

ircd::ios: Simplify fault handler; reuse leave() codepath.

include/ircd/ios.h

@@ -43,6 +43,9 @@ namespace ircd::ios
 	struct defer;
 	struct post;
 
+	constexpr bool profile_history {false};
+	constexpr bool profile_logging {false};
+
 	extern log::log log;
 	extern std::thread::id main_thread_id;
 	extern asio::executor user;
@@ -148,6 +151,7 @@ struct ircd::ios::handler
 	static thread_local handler *current;
 	static thread_local uint64_t epoch;
 
+	static void enqueue(handler *const &) noexcept;
 	static void *allocate(handler *const &, const size_t &);
 	static void deallocate(handler *const &, void *const &, const size_t &) noexcept;
 	static bool continuation(handler *const &) noexcept;
@@ -168,9 +172,10 @@ struct ircd::ios::handle
 	template<class... args>
 	void operator()(args&&... a) const;
 
-	handle(ios::descriptor &, function);
+	handle(ios::descriptor &, function) noexcept;
 };
 
+// boost handlers
 namespace ircd::ios
 {
 	template<class function>
@@ -187,31 +192,9 @@ namespace ircd::ios
 	void asio_handler_invoke(callable &f, handle<function> *);
 }
 
-template<class function>
-ircd::ios::handle<function>::handle(ios::descriptor &d,
-                                    function f)
-:handler{&d, prof::cycles()}
-,f{std::move(f)}
-{
-	assert(d.stats);
-	d.stats->queued++;
-}
-
-template<class function>
-template<class... args>
-void
-ircd::ios::handle<function>::operator()(args&&... a)
-const
-{
-	assert(descriptor && descriptor->stats);
-	assert(descriptor->stats->queued > 0);
-	descriptor->stats->queued--;
-	f(std::forward<args>(a)...);
-}
-
 template<class callable,
          class function>
-void
+inline void
 ircd::ios::asio_handler_invoke(callable &f,
                                handle<function> *const h)
 try
@@ -229,14 +212,14 @@ catch(...)
 }
 
 template<class function>
-bool
+inline bool
 ircd::ios::asio_handler_is_continuation(handle<function> *const h)
 {
 	return handler::continuation(h);
 }
 
 template<class function>
-void *
+inline void *
 __attribute__((malloc, returns_nonnull, warn_unused_result, alloc_size(1)))
 ircd::ios::asio_handler_allocate(size_t size,
                                  handle<function> *const h)
@@ -245,7 +228,7 @@ ircd::ios::asio_handler_allocate(size_t size,
 }
 
 template<class function>
-void
+inline void
 ircd::ios::asio_handler_deallocate(void *const ptr,
                                    size_t size,
                                    handle<function> *const h)
@@ -253,6 +236,74 @@ ircd::ios::asio_handler_deallocate(void *const ptr,
 	handler::deallocate(h, ptr, size);
 }
 
+//
+// ircd::ios::handle
+//
+
+template<class function>
+inline
+ircd::ios::handle<function>::handle(ios::descriptor &d,
+                                    function f)
+noexcept
+:handler{&d, prof::cycles()}
+,f(std::move(f))
+{
+	handler::enqueue(this);
+}
+
+template<class function>
+template<class... args>
+inline void
+ircd::ios::handle<function>::operator()(args&&... a)
+const
+{
+	assert(descriptor && descriptor->stats);
+	assert(descriptor->stats->queued > 0);
+	descriptor->stats->queued--;
+	f(std::forward<args>(a)...);
+}
+
+//
+// ircd::ios::handler
+//
+
+inline void
+ircd::ios::handler::enqueue(handler *const &handler)
+noexcept
+{
+	assert(handler && handler->descriptor);
+	auto &descriptor(*handler->descriptor);
+
+	assert(descriptor.stats);
+	auto &stats(*descriptor.stats);
+	++stats.queued;
+
+	if constexpr(profile_logging)
+		log::logf
+		{
+			log, log::level::DEBUG,
+			"QUEUE %5u %-20s [%11lu] ------[%9lu] q:%-4lu",
+			descriptor.id,
+			trunc(descriptor.name, 20),
+			stats.calls,
+			0UL,
+			stats.queued,
+		};
+}
+
+inline bool
+ircd::ios::handler::continuation(handler *const &handler)
+noexcept
+{
+	assert(handler && handler->descriptor);
+	auto &descriptor(*handler->descriptor);
+	return descriptor.continuation;
+}
+
+//
+// ircd::ios
+//
+
 inline const ircd::string_view &
 ircd::ios::name(const handler &handler)
 {

ircd/ios.cc

@@ -187,11 +187,6 @@ ircd::ios::descriptor::stats::operator+=(const stats &o)
 // handler
 //
 
-namespace ircd::ios
-{
-	constexpr bool profile_history {false};
-}
-
 decltype(ircd::ios::handler::current)
 thread_local
 ircd::ios::handler::current;
@@ -212,23 +207,27 @@ noexcept
 	auto &stats(*descriptor.stats);
 	++stats.faults;
 
-	bool ret(false);
+	bool ret
-	// leave() isn't called if we return false so the tsc counter
-	// needs to be tied off here instead.
-	if(!ret)
 	{
-		const auto last_ts
+		false
-		{
-			std::exchange(handler->ts, cycles())
 	};
 
-		assert(handler->ts >= last_ts);
+	if constexpr(profile_logging)
-		stats.slice_last = handler->ts - last_ts;
+		log::logf
-		stats.slice_total += stats.slice_last;
+		{
+			log, log::level::DEBUG,
+			"FAULT %5u %-20s [%11lu] faults[%9lu] q:%-4lu",
+			descriptor.id,
+			trunc(descriptor.name, 20),
+			stats.calls,
+			stats.faults,
+			stats.queued,
+		};
 
-		assert(handler::current == handler);
+	// Our API sez if this function returns true, caller is responsible for
-		handler::current = nullptr;
+	// calling leave(), otherwise they must not call leave().
-	}
+	if(likely(!ret))
+		leave(handler);
 
 	return ret;
 }
@@ -263,6 +262,18 @@ noexcept
 		++descriptor.history_pos;
 	}
 
+	if constexpr(profile_logging)
+		log::logf
+		{
+			log, log::level::DEBUG,
+			"LEAVE %5u %-20s [%11lu] cycles[%9lu] q:%-4lu",
+			descriptor.id,
+			trunc(descriptor.name, 20),
+			stats.calls,
+			stats.slice_last,
+			stats.queued,
+		};
+
 	assert(handler::current == handler);
 	handler::current = nullptr;
 }
@@ -290,16 +301,18 @@ noexcept
 
 	stats.latency_last = handler->ts - last_ts;
 	stats.latency_total += stats.latency_last;
-}
 
-[[gnu::hot]]
+	if constexpr(profile_logging)
-bool
+		log::logf
-ircd::ios::handler::continuation(handler *const &handler)
-noexcept
 		{
-	assert(handler && handler->descriptor);
+			log, log::level::DEBUG,
-	auto &descriptor(*handler->descriptor);
+			"ENTER %5u %-20s [%11lu] latent[%9lu] q:%-4lu",
-	return descriptor.continuation;
+			descriptor.id,
+			trunc(descriptor.name, 20),
+			stats.calls,
+			stats.latency_last,
+			stats.queued,
+		};
 }
 
 [[gnu::hot]]