Skip to content

Commit 31cb3b0

Browse files
committed
HttpServerConnection: Log noticable CPU semaphore wait time
1 parent 9a8620d commit 31cb3b0

File tree

1 file changed

+13
-4
lines changed

1 file changed

+13
-4
lines changed

lib/remote/httpserverconnection.cpp

Lines changed: 13 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -428,13 +428,17 @@ bool ProcessRequest(
428428
boost::beast::http::response<boost::beast::http::string_body>& response,
429429
HttpServerConnection& server,
430430
bool& hasStartedStreaming,
431+
std::chrono::steady_clock::duration& cpuBoundWorkTime,
431432
boost::asio::yield_context& yc
432433
)
433434
{
434435
namespace http = boost::beast::http;
435436

436437
try {
438+
// Cache the elapsed time to acquire a CPU semaphore used to detect extremely heavy workloads.
439+
auto start (std::chrono::steady_clock::now());
437440
CpuBoundWork handlingRequest (yc);
441+
cpuBoundWorkTime = std::chrono::steady_clock::now() - start;
438442

439443
HttpHandler::ProcessRequest(stream, authenticatedUser, request, response, yc, server);
440444
} catch (const std::exception& ex) {
@@ -525,9 +529,14 @@ void HttpServerConnection::ProcessMessages(boost::asio::yield_context yc)
525529
<< ", user: " << (authenticatedUser ? authenticatedUser->GetName() : "<unauthenticated>")
526530
<< ", agent: " << request[http::field::user_agent]; //operator[] - Returns the value for a field, or "" if it does not exist.
527531

528-
Defer addRespCode ([&response, start, &logMsg]() {
529-
logMsg << ", status: " << response.result() << ") took "
530-
<< ch::duration_cast<ch::milliseconds>(ch::steady_clock::now() - start).count() << "ms.";
532+
ch::steady_clock::duration cpuBoundWorkTime(0);
533+
Defer addRespCode ([&response, start, &logMsg, &cpuBoundWorkTime]() {
534+
logMsg << ", status: " << response.result() << ")";
535+
if (cpuBoundWorkTime >= ch::seconds(1)) {
536+
logMsg << " waited " << ch::duration_cast<ch::milliseconds>(cpuBoundWorkTime).count() << "ms on semaphore and";
537+
}
538+
539+
logMsg << " took total " << ch::duration_cast<ch::milliseconds>(ch::steady_clock::now() - start).count() << "ms.";
531540
});
532541

533542
if (!HandleAccessControl(*m_Stream, request, response, yc)) {
@@ -548,7 +557,7 @@ void HttpServerConnection::ProcessMessages(boost::asio::yield_context yc)
548557

549558
m_Seen = std::numeric_limits<decltype(m_Seen)>::max();
550559

551-
if (!ProcessRequest(*m_Stream, request, authenticatedUser, response, *this, m_HasStartedStreaming, yc)) {
560+
if (!ProcessRequest(*m_Stream, request, authenticatedUser, response, *this, m_HasStartedStreaming, cpuBoundWorkTime, yc)) {
552561
break;
553562
}
554563

0 commit comments

Comments
 (0)