8000 Add DTRACE points to measure request timings. (#11245) · arangodb/arangodb@15fad6f · GitHub
[go: up one dir, main page]
Skip to content

Commit 15fad6f

Browse files
neunhoefneunhoef
authored
Add DTRACE points to measure request timings. (#11245)
1 parent 1c6a958 commit 15fad6f

14 files changed

+888
-7
lines changed

‎CHANGELOG

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,8 @@
11
devel
22
-----
33

4+
* Add DTRACE points to track a request through the infrastructure.
5+
46
* Fixed issue #11275: indexes backward compatibility broken in 3.5+.
57

68
* Updated snowball dependency to the latest version.

‎CMakeLists.txt

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -280,6 +280,12 @@ if (STATIC_EXECUTABLES)
280280
endif ()
281281
endif()
282282

283+
# enable dtrace
284+
option(USE_DTRACE "enable dtrace probes" OFF)
285+
if (USE_DTRACE)
286+
add_definitions("-DUSE_DTRACE=1")
287+
endif ()
288+
283289
# enable enterprise features
284290
set(ENTERPRISE_INCLUDE_DIR "enterprise")
285291
option(USE_ENTERPRISE "enable enterprise build" OFF)

‎arangod/GeneralServer/CommTask.cpp

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -30,6 +30,7 @@
3030
#include "Basics/HybridLogicalClock.h"
3131
#include "Basics/StaticStrings.h"
3232
#include "Basics/compile-time-strlen.h"
33+
#include "Basics/dtrace-wrapper.h"
3334
#include "Cluster/ServerState.h"
3435
#include "GeneralServer/AsyncJobManager.h"
3536
#include "GeneralServer/AuthenticationFeature.h"
@@ -150,6 +151,8 @@ bool resolveRequestContext(GeneralRequest& req) {
150151

151152
CommTask::Flow CommTask::prepareExecution(auth::TokenCache::Entry const& authToken,
152153
GeneralRequest& req) {
154+
DTRACE_PROBE1(arangod, CommTaskPrepareExecution, this);
155+
153156
// Step 1: In the shutdown phase we simply return 503:
154157
if (_server.server().isStopping()) {
155158
addErrorResponse(ResponseCode::SERVICE_UNAVAILABLE, req.contentTypeResponse(),
@@ -324,7 +327,8 @@ void CommTask::finishExecution(GeneralResponse& res, std::string const& origin)
324327

325328
void CommTask::executeRequest(std::unique_ptr<GeneralRequest> request,
326329
std::unique_ptr<GeneralResponse> response) {
327-
330+
DTRACE_PROBE1(arangod, CommTaskExecuteRequest, this);
331+
328332
response->setContentTypeRequested(request->contentTypeResponse());
329333
response->setGenerateBody(request->requestType() != RequestType::HEAD);
330334

@@ -516,6 +520,7 @@ void CommTask::addErrorResponse(rest::ResponseCode code,
516520
// and scheduled later when the number of used threads decreases
517521

518522
bool CommTask::handleRequestSync(std::shared_ptr<RestHandler> handler) {
523+
DTRACE_PROBE2(arangod, CommTaskHandleRequestSync, this, handler.get());
519524
RequestStatistics::SET_QUEUE_START(handler->statistics(), SchedulerFeature::SCHEDULER->queueStatistics()._queued);
520525

521526
RequestLane lane = handler->getRequestLane();

‎arangod/GeneralServer/H2CommTask.cpp

Lines changed: 42 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -25,6 +25,7 @@
2525
#include "Basics/Exceptions.h"
2626
#include "Basics/ScopeGuard.h"
2727
#include "Basics/asio_ns.h"
28+
#include "Basics/dtrace-wrapper.h"
2829
#include "Cluster/ServerState.h"
2930
#include "GeneralServer/GeneralServer.h"
3031
#include "GeneralServer/GeneralServerFeature.h"
@@ -389,8 +390,20 @@ bool H2CommTask<T>::readCallback(asio_ns::error_code ec) {
389390
return true; // continue read lopp
390391
}
391392

393+
#ifdef USE_DTRACE
394+
// Moved out to avoid duplication by templates.
395+
static void __attribute__ ((noinline)) DTraceH2CommTaskProcessStream(size_t th) {
396+
DTRACE_PROBE1(arangod, H2CommTaskProcessStream, th);
397+
}
398+
#else
399+
static void DTraceH2CommTaskProcessStream(size_t) {}
400+
#endif
401+
392402
template <SocketType T>
393403
void H2CommTask<T>::processStream(H2CommTask<T>::Stream* stream) {
404+
405+
DTraceH2CommTaskProcessStream((size_t) this);
406+
394407
TRI_ASSERT(stream);
395408

396409
std::unique_ptr<HttpRequest> req = std::move(stream->request);
@@ -463,10 +476,21 @@ bool expectResponseBody(int status_code) {
463476
}
464477
} // namespace
465478

479+
#ifdef USE_DTRACE
480+
// Moved out to avoid duplication by templates.
481+
static void __attribute__ ((noinline)) DTraceH2CommTaskSendResponse(size_t th) {
482+
DTRACE_PROBE1(arangod, H2CommTaskSendResponse, th);
483+
}
484+
#else
485+
static void DTraceH2CommTaskSendResponse(size_t) {}
486+
#endif
487+
466488
template <SocketType T>
467489
void H2CommTask<T>::sendResponse(std::unique_ptr<GeneralResponse> res,
468490
RequestStatistics* stat) {
469-
491+
492+
DTraceH2CommTaskSendResponse((size_t) this);
493+
470494
// TODO the statistics are total bogus here
471495
double const totalTime = RequestStatistics::ELAPSED_SINCE_READ_START(stat);
472496
if (stat) {
@@ -630,6 +654,19 @@ void H2CommTask<T>::queueHttp2Responses() {
630654
}
631655
}
632656

657+
#ifdef USE_DTRACE
658+
// Moved out to avoid duplication by templates.
659+
static void __attribute__ ((noinline)) DTraceH2CommTaskBeforeAsyncWrite(size_t th) {
660+
DTRACE_PROBE1(arangod, H2CommTaskBeforeAsyncWrite, th);
661+
}
662+
static void __attribute__ ((noinline)) DTraceH2CommTaskAfterAsyncWrite(size_t th) {
663+
DTRACE_PROBE1(arangod, H2CommTaskAfterAsyncWrite, th);
664+
}
665+
#else
666+
static void DTraceH2CommTaskBeforeAsyncWrite(size_t) {}
667+
static void DTraceH2CommTaskAfterAsyncWrite(size_t) {}
668+
#endif
669+
633670
// called on IO context thread
634671
template <SocketType T>
635672
void H2CommTask<T>::doWrite() {
@@ -685,6 +722,8 @@ void H2CommTask<T>::doWrite() {
685722
return;
686723
}
687724

725+
DTraceH2CommTaskBeforeAsyncWrite((size_t) this);
726+
688727
asio_ns::async_write(this->_protocol->socket, outBuffers,
689728
[self = this->shared_from_this()](const asio_ns::error_code& ec,
690729
std::size_t nwrite) {
@@ -695,6 +734,8 @@ void H2CommTask<T>::doWrite() {
695734
return;
696735
}
697736

737+
DTraceH2CommTaskAfterAsyncWrite((size_t) self.get());
738+
698739
me.doWrite();
699740
});
700741
}

‎arangod/GeneralServer/HttpCommTask.cpp

Lines changed: 44 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -25,6 +25,7 @@
2525

2626
#include "Basics/ScopeGuard.h"
2727
#include "Basics/asio_ns.h"
28+
#include "Basics/dtrace-wrapper.h"
2829
#include "Cluster/ServerState.h"
2930
#include "GeneralServer/GeneralServer.h"
3031
#include "GeneralServer/GeneralServerFeature.h"
@@ -336,8 +337,20 @@ void HttpCommTask<T>::checkVSTPrefix() {
336337
asio_ns::transfer_at_least(11), std::move(cb));
337338
}
338339

340+
#ifdef USE_DTRACE
341+
// Moved here to prevent multiplicity by template
342+
static void __attribute__ ((noinline)) DTraceHttpCommTaskProcessRequest(size_t th) {
343+
DTRACE_PROBE1(arangod, HttpCommTaskProcessRequest, th);
344+
}
345+
#else
346+
static void DTraceHttpCommTaskProcessRequest(size_t) {}
347+
#endif
348+
339349
template <SocketType T>
340350
void HttpCommTask<T>::processRequest() {
351+
352+
DTraceHttpCommTaskProcessRequest((size_t) this);
353+
341354
TRI_ASSERT(_request);
342355
this->_protocol->timer.cancel();
343356

@@ -414,9 +427,21 @@ void HttpCommTask<T>::processRequest() {
414427
this->executeRequest(std::move(_request), std::move(resp));
415428
}
416429

430+
#ifdef USE_DTRACE
431+
// Moved here to prevent multiplicity by template
432+
static void __attribute__ ((noinline)) DTraceHttpCommTaskSendResponse(size_t th) {
433+
DTRACE_PROBE1(arangod, HttpCommTaskSendResponse, th);
434+
}
435+
#else
436+
static void DTraceHttpCommTaskSendResponse(size_t) {}
437+
#endif
438+
417439
template <SocketType T>
418440
void HttpCommTask<T>::sendResponse(std::unique_ptr<GeneralResponse> baseRes,
419441
RequestStatistics* stat) {
442+
443+
DTraceHttpCommTaskSendResponse((size_t) this);
444+
420445
if (this->_stopped.load(std::memory_order_acquire)) {
421446
return;
422447
}
@@ -534,9 +559,25 @@ void HttpCommTask<T>::sendResponse(std::unique_ptr<GeneralResponse> baseRes,
534559
});
535560
}
536561

562+
#ifdef USE_DTRACE
563+
// Moved here to prevent multiplicity by template
564+
static void __attribute__ ((noinline)) DTraceHttpCommTaskWriteResponse(size_t th) {
565+
DTRACE_PROBE1(arangod, HttpCommTaskWriteResponse, th);
566+
}
567+
static void __attribute__ ((noinline)) DTraceHttpCommTaskResponseWritten(size_t th) {
568+
DTRACE_PROBE1(arangod, HttpCommTaskResponseWritten, th);
569+
}
570+
#else
571+
static void DTraceHttpCommTaskWriteResponse(size_t) {}
572+
static void DTraceHttpCommTaskResponseWritten(size_t) {}
573+
#endif
574+
537575
// called on IO context thread
538576
template <SocketType T>
539577
void HttpCommTask<T>::writeResponse(RequestStatistics* stat) {
578+
579+
DTraceHttpCommTaskWriteResponse((size_t) this);
580+
540581
TRI_ASSERT(!_header.empty());
541582

542583
RequestStatistics::SET_WRITE_START(stat);
@@ -551,6 +592,9 @@ void HttpCommTask<T>::writeResponse(RequestStatistics* stat) {
551592
asio_ns::async_write(this->_protocol->socket, buffers,
552593
[self = this->shared_from_this(),
553594
stat](asio_ns::error_code ec, size_t nwrite) {
595+
596+
DTraceHttpCommTaskResponseWritten((size_t) self.get());
597+
554598
auto* thisPtr = static_cast<HttpCommTask<T>*>(self.get());
555599
RequestStatistics::SET_WRITE_END(stat);
556600
RequestStatistics::ADD_SENT_BYTES(stat, nwrite);

‎arangod/GeneralServer/RestHandler.cpp

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -29,6 +29,7 @@
2929
#include "ApplicationFeatures/ApplicationServer.h"
3030
#include "Basics/RecursiveLocker.h"
3131
#include "Basics/StringUtils.h"
32+
#include "Basics/dtrace-wrapper.h"
3233
#include "Cluster/ClusterFeature.h"
3334
#include "Cluster/ClusterInfo.h"
3435
#include "Cluster/ClusterMethods.h"
@@ -398,6 +399,7 @@ bool RestHandler::wakeupHandler() {
398399
}
399400

400401
void RestHandler::executeEngine(bool isContinue) {
402+
DTRACE_PROBE1(arangod, RestHandlerExecuteEngine, this);
401403
ExecContext* exec = static_cast<ExecContext*>(_request->requestContext());
402404
ExecContextScope scope(exec);
403405

‎arangod/GeneralServer/SslServerFeature.cpp

Lines changed: 35 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -73,7 +73,8 @@ SslServerFeature::SslServerFeature(application_features::ApplicationServer& serv
7373
_sslProtocol(TLS_GENERIC),
7474
_sslOptions(asio_ns::ssl::context::default_workarounds |
7575
asio_ns::ssl::context::single_dh_use),
76-
_ecdhCurve("prime256v1") {
76+
_ecdhCurve("prime256v1"),
77+
_preferHttp11InAlpn(false) {
7778
setOptional(true);
7879
startsAfter<application_features::AqlFeaturePhase>();
7980
}
@@ -116,6 +117,10 @@ void SslServerFeature::collectOptions(std::shared_ptr<ProgramOptions> options) {
116117
"--ssl.ecdh-curve",
117118
"SSL ECDH Curve, see the output of \"openssl ecparam -list_curves\"",
118119
new StringParameter(&_ecdhCurve));
120+
121+
options->addOption("--ssl.prefer-http1-in-alpn",
122+
"Allows to let the server prefer HTTP/1.1 over HTTP/2 in ALPN protocol negotiations",
123+
new BooleanParameter(&_preferHttp11InAlpn));
119124
}
120125

121126
void SslServerFeature::validateOptions(std::shared_ptr<ProgramOptions> options) {
@@ -201,12 +206,38 @@ class BIOGuard {
201206
};
202207
} // namespace
203208

209+
static inline bool searchForProtocol(const unsigned char** out, unsigned char* outlen,
210+
const unsigned char* in, unsigned int inlen,
211+
const char* proto) {
212+
size_t len = strlen(proto);
213+
size_t i = 0;
214+
while (i + len <= inlen) {
215+
if (memcmp(in + i, proto, len) == 0) {
216+
*out = (const unsigned char *)(in + i + 1);
217+
*outlen = proto[0];
218+
return true;
219+
}
220+
i += in[i] + 1;
221+
}
222+
return false;
223+
}
224+
204225
static int alpn_select_proto_cb(SSL* ssl, const unsigned char** out,
205226
unsigned char* outlen, const unsigned char* in,
206227
unsigned int inlen, void* arg) {
207-
int rv = nghttp2_select_next_protocol((unsigned char**)out, outlen, in, inlen);
228+
int rv = 0;
229+
bool const* preferHttp11InAlpn = (bool*) arg;
230+
if (*preferHttp11InAlpn) {
231+
if (!searchForProtocol(out, outlen, in, inlen, "\x8http/1.1")) {
232+
if (!searchForProtocol(out, outlen, in, inlen, "\x2h2")) {
233+
rv = -1;
234+
}
235+
}
236+
} else {
237+
rv = nghttp2_select_next_protocol((unsigned char **)out, outlen, in, inlen);
238+
}
208239

209-
if (rv != 1) {
240+
if (rv < 0) {
210241
return SSL_TLSEXT_ERR_NOACK;
211242
}
212243

@@ -344,7 +375,7 @@ asio_ns::ssl::context SslServerFeature::createSslContextInternal(std::string key
344375

345376
sslContext.set_verify_mode(SSL_VERIFY_NONE);
346377

347-
SSL_CTX_set_alpn_select_cb(sslContext.native_handle(), alpn_select_proto_cb, NULL);
378+
SSL_CTX_set_alpn_select_cb(sslContext.native_handle(), alpn_select_proto_cb, (void*) (&_preferHttp11InAlpn));
348379

349380
return sslContext;
350381
} catch (std::exception const& ex) {

‎arangod/GeneralServer/SslServerFeature.h

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -90,6 +90,7 @@ class SslServerFeature : public application_features::ApplicationFeature {
9090
uint64_t _sslProtocol;
9191
uint64_t _sslOptions;
9292
std::string _ecdhCurve;
93+
bool _preferHttp11InAlpn;
9394

9495
private:
9596
asio_ns::ssl::context createSslContextInternal(std::string keyfileName,

0 commit comments

Comments
 (0)
0