arangodb · jsteemann · Mar 20, 2020 · Mar 3, 2020 · Mar 4, 2020 · Mar 4, 2020
diff --git a/CHANGELOG b/CHANGELOG
@@ -1,6 +1,8 @@
 devel
 -----
 
+* Add DTRACE points to track a request through the infrastructure.
+
 * Agency ttl bug fix
 
 * Added the SNI feature for TLS. This means that one can configure multiple

diff --git a/CMakeLists.txt b/CMakeLists.txt
@@ -280,6 +280,12 @@ if (STATIC_EXECUTABLES)
   endif ()
 endif()
 
+# enable dtrace
+option(USE_DTRACE "enable dtrace probes" OFF)
+if (USE_DTRACE)
+  add_definitions("-DUSE_DTRACE=1")
+endif ()
+
 # enable enterprise features
 set(ENTERPRISE_INCLUDE_DIR "enterprise")
 option(USE_ENTERPRISE "enable enterprise build" OFF)

diff --git a/arangod/GeneralServer/CommTask.cpp b/arangod/GeneralServer/CommTask.cpp
@@ -30,6 +30,9 @@
 #include "Basics/HybridLogicalClock.h"
 #include "Basics/StaticStrings.h"
 #include "Basics/compile-time-strlen.h"
+#ifdef USE_DTRACE
+#include "Basics/sdt.h"
+#endif
 #include "Cluster/ServerState.h"
 #include "GeneralServer/AsyncJobManager.h"
 #include "GeneralServer/AuthenticationFeature.h"
@@ -150,6 +153,11 @@ bool resolveRequestContext(GeneralRequest& req) {
 
 CommTask::Flow CommTask::prepareExecution(auth::TokenCache::Entry const& authToken,
                                           GeneralRequest& req) {
+
+#ifdef USE_DTRACE
+  DTRACE_PROBE1(arangod, CommTaskPrepareExecution, this);
+#endif
+
   // Step 1: In the shutdown phase we simply return 503:
   if (_server.server().isStopping()) {
     addErrorResponse(ResponseCode::SERVICE_UNAVAILABLE, req.contentTypeResponse(),
@@ -324,7 +332,11 @@ void CommTask::finishExecution(GeneralResponse& res, std::string const& origin)
 
 void CommTask::executeRequest(std::unique_ptr<GeneralRequest> request,
                               std::unique_ptr<GeneralResponse> response) {
-
+
+#ifdef USE_DTRACE
+  DTRACE_PROBE1(arangod, CommTaskExecuteRequest, this);
+#endif
+
   response->setContentTypeRequested(request->contentTypeResponse());
   response->setGenerateBody(request->requestType() != RequestType::HEAD);
 
@@ -516,6 +528,11 @@ void CommTask::addErrorResponse(rest::ResponseCode code,
 // and scheduled later when the number of used threads decreases
 
 bool CommTask::handleRequestSync(std::shared_ptr<RestHandler> handler) {
+
+#ifdef USE_DTRACE
+  DTRACE_PROBE2(arangod, CommTaskHandleRequestSync, this, handler.get());
+#endif
+
   RequestStatistics::SET_QUEUE_START(handler->statistics(), SchedulerFeature::SCHEDULER->queueStatistics()._queued);
 
   RequestLane lane = handler->getRequestLane();

diff --git a/arangod/GeneralServer/H2CommTask.cpp b/arangod/GeneralServer/H2CommTask.cpp
@@ -25,6 +25,9 @@
 #include "Basics/Exceptions.h"
 #include "Basics/ScopeGuard.h"
 #include "Basics/asio_ns.h"
+#ifdef USE_DTRACE
+#include "Basics/sdt.h"
+#endif
 #include "Cluster/ServerState.h"
 #include "GeneralServer/GeneralServer.h"
 #include "GeneralServer/GeneralServerFeature.h"
@@ -389,8 +392,20 @@ bool H2CommTask<T>::readCallback(asio_ns::error_code ec) {
   return true;  //  continue read lopp
 }
 
+#ifdef USE_DTRACE
+// Moved out to avoid duplication by templates.
+static void __attribute__ ((noinline)) DTraceH2CommTaskProcessStream(size_t th) {
+  DTRACE_PROBE1(arangod, H2CommTaskProcessStream, th);
+}
+#endif
+
 template <SocketType T>
 void H2CommTask<T>::processStream(H2CommTask<T>::Stream* stream) {
+
+#ifdef USE_DTRACE
+  DTraceH2CommTaskProcessStream((size_t) this);
+#endif
+
   TRI_ASSERT(stream);
 
   std::unique_ptr<HttpRequest> req = std::move(stream->request);
@@ -463,10 +478,21 @@ bool expectResponseBody(int status_code) {
 }
 }  // namespace
 
+#ifdef USE_DTRACE
+// Moved out to avoid duplication by templates.
+static void __attribute__ ((noinline)) DTraceH2CommTaskSendResponse(size_t th) {
+  DTRACE_PROBE1(arangod, H2CommTaskSendResponse, th);
+}
+#endif
+
 template <SocketType T>
 void H2CommTask<T>::sendResponse(std::unique_ptr<GeneralResponse> res,
                                  RequestStatistics* stat) {
-
+
+#ifdef USE_DTRACE
+  DTraceH2CommTaskSendResponse((size_t) this);
+#endif
+
   // TODO the statistics are total bogus here
   double const totalTime = RequestStatistics::ELAPSED_SINCE_READ_START(stat);
   if (stat) {
@@ -630,6 +656,16 @@ void H2CommTask<T>::queueHttp2Responses() {
   }
 }
 
+#ifdef USE_DTRACE
+// Moved out to avoid duplication by templates.
+static void __attribute__ ((noinline)) DTraceH2CommTaskBeforeAsyncWrite(size_t th) {
+  DTRACE_PROBE1(arangod, H2CommTaskBeforeAsyncWrite, th);
+}
+static void __attribute__ ((noinline)) DTraceH2CommTaskAfterAsyncWrite(size_t th) {
+  DTRACE_PROBE1(arangod, H2CommTaskAfterAsyncWrite, th);
+}
+#endif
+
 // called on IO context thread
 template <SocketType T>
 void H2CommTask<T>::doWrite() {
@@ -685,6 +721,10 @@ void H2CommTask<T>::doWrite() {
     return;
   }
 
+#ifdef USE_DTRACE
+  DTraceH2CommTaskBeforeAsyncWrite((size_t) this);
+#endif
+
   asio_ns::async_write(this->_protocol->socket, outBuffers,
                        [self = this->shared_from_this()](const asio_ns::error_code& ec,
                                                          std::size_t nwrite) {
@@ -695,6 +735,10 @@ void H2CommTask<T>::doWrite() {
                            return;
                          }
 
+#ifdef USE_DTRACE
+                         DTraceH2CommTaskAfterAsyncWrite((size_t) self.get());
+#endif
+
                          me.doWrite();
                        });
 }

diff --git a/arangod/GeneralServer/HttpCommTask.cpp b/arangod/GeneralServer/HttpCommTask.cpp
@@ -25,6 +25,9 @@
 
 #include "Basics/ScopeGuard.h"
 #include "Basics/asio_ns.h"
+#ifdef USE_DTRACE
+#include "Basics/sdt.h"
+#endif
 #include "Cluster/ServerState.h"
 #include "GeneralServer/GeneralServer.h"
 #include "GeneralServer/GeneralServerFeature.h"
@@ -336,8 +339,20 @@ void HttpCommTask<T>::checkVSTPrefix() {
                       asio_ns::transfer_at_least(11), std::move(cb));
 }
 
+#ifdef USE_DTRACE
+// Moved here to prevent multiplicity by template
+static void __attribute__ ((noinline)) DTraceHttpCommTaskProcessRequest(size_t th) {
+  DTRACE_PROBE1(arangod, HttpCommTaskProcessRequest, th);
+}
+#endif
+
 template <SocketType T>
 void HttpCommTask<T>::processRequest() {
+
+#ifdef USE_DTRACE
+  DTraceHttpCommTaskProcessRequest((size_t) this);
+#endif
+
   TRI_ASSERT(_request);
   this->_protocol->timer.cancel();
 
@@ -414,9 +429,21 @@ void HttpCommTask<T>::processRequest() {
   this->executeRequest(std::move(_request), std::move(resp));
 }
 
+#ifdef USE_DTRACE
+// Moved here to prevent multiplicity by template
+static void __attribute__ ((noinline)) DTraceHttpCommTaskSendResponse(size_t th) {
+  DTRACE_PROBE1(arangod, HttpCommTaskSendResponse, th);
+}
+#endif
+
 template <SocketType T>
 void HttpCommTask<T>::sendResponse(std::unique_ptr<GeneralResponse> baseRes,
                                    RequestStatistics* stat) {
+
+#ifdef USE_DTRACE
+  DTraceHttpCommTaskSendResponse((size_t) this);
+#endif
+
   if (this->_stopped.load(std::memory_order_acquire)) {
     return;
   }
@@ -534,9 +561,24 @@ void HttpCommTask<T>::sendResponse(std::unique_ptr<GeneralResponse> baseRes,
   });
 }
 
+#ifdef USE_DTRACE
+// Moved here to prevent multiplicity by template
+static void __attribute__ ((noinline)) DTraceHttpCommTaskWriteResponse(size_t th) {
+  DTRACE_PROBE1(arangod, HttpCommTaskWriteResponse, th);
+}
+static void __attribute__ ((noinline)) DTraceHttpCommTaskResponseWritten(size_t th) {
+  DTRACE_PROBE1(arangod, HttpCommTaskResponseWritten, th);
+}
+#endif
+
 // called on IO context thread
 template <SocketType T>
 void HttpCommTask<T>::writeResponse(RequestStatistics* stat) {
+
+#ifdef USE_DTRACE
+  DTraceHttpCommTaskWriteResponse((size_t) this);
+#endif
+
   TRI_ASSERT(!_header.empty());
 
   RequestStatistics::SET_WRITE_START(stat);
@@ -551,6 +593,11 @@ void HttpCommTask<T>::writeResponse(RequestStatistics* stat) {
   asio_ns::async_write(this->_protocol->socket, buffers,
                        [self = this->shared_from_this(),
                         stat](asio_ns::error_code ec, size_t nwrite) {
+
+#ifdef USE_DTRACE
+                         DTraceHttpCommTaskResponseWritten((size_t) self.get());
+#endif
+
                          auto* thisPtr = static_cast<HttpCommTask<T>*>(self.get());
                          RequestStatistics::SET_WRITE_END(stat);
                          RequestStatistics::ADD_SENT_BYTES(stat, nwrite);

diff --git a/arangod/GeneralServer/RestHandler.cpp b/arangod/GeneralServer/RestHandler.cpp
@@ -29,6 +29,9 @@
 #include "ApplicationFeatures/ApplicationServer.h"
 #include "Basics/RecursiveLocker.h"
 #include "Basics/StringUtils.h"
+#ifdef USE_DTRACE
+#include "Basics/sdt.h"
+#endif
 #include "Cluster/ClusterFeature.h"
 #include "Cluster/ClusterInfo.h"
 #include "Cluster/ClusterMethods.h"
@@ -398,6 +401,11 @@ bool RestHandler::wakeupHandler() {
 }
 
 void RestHandler::executeEngine(bool isContinue) {
+
+#ifdef USE_DTRACE
+  DTRACE_PROBE1(arangod, RestHandlerExecuteEngine, this);
+#endif
+
   ExecContext* exec = static_cast<ExecContext*>(_request->requestContext());
   ExecContextScope scope(exec);
 

diff --git a/arangod/GeneralServer/SslServerFeature.cpp b/arangod/GeneralServer/SslServerFeature.cpp
@@ -73,7 +73,8 @@ SslServerFeature::SslServerFeature(application_features::ApplicationServer& serv
       _sslProtocol(TLS_GENERIC),
       _sslOptions(asio_ns::ssl::context::default_workarounds |
                   asio_ns::ssl::context::single_dh_use),
-      _ecdhCurve("prime256v1") {
+      _ecdhCurve("prime256v1"),
+      _allowHttpProtocolNegotiation(true) {
   setOptional(true);
   startsAfter<application_features::AqlFeaturePhase>();
 }
@@ -116,6 +117,11 @@ void SslServerFeature::collectOptions(std::shared_ptr<ProgramOptions> options) {
       "--ssl.ecdh-curve",
       "SSL ECDH Curve, see the output of \"openssl ecparam -list_curves\"",
       new StringParameter(&_ecdhCurve));
+
+  options->addOption(
+      "--ssl.allow-http-protocol-negotiation",
+      "Allows that the TLS handshake negotiates the HTTP protocol version",
+      new BooleanParameter(&_allowHttpProtocolNegotiation));
 }
 
 void SslServerFeature::validateOptions(std::shared_ptr<ProgramOptions> options) {
@@ -344,7 +350,9 @@ asio_ns::ssl::context SslServerFeature::createSslContextInternal(
 
     sslContext.set_verify_mode(SSL_VERIFY_NONE);
 
-    SSL_CTX_set_alpn_select_cb(sslContext.native_handle(), alpn_select_proto_cb, NULL);
+    if (_allowHttpProtocolNegotiation) {
+      SSL_CTX_set_alpn_select_cb(sslContext.native_handle(), alpn_select_proto_cb, NULL);
+    }
 
     return sslContext;
   } catch (std::exception const& ex) {

diff --git a/arangod/GeneralServer/SslServerFeature.h b/arangod/GeneralServer/SslServerFeature.h
@@ -90,6 +90,7 @@ class SslServerFeature : public application_features::ApplicationFeature {
   uint64_t _sslProtocol;
   uint64_t _sslOptions;
   std::string _ecdhCurve;
+  bool _allowHttpProtocolNegotiation;
 
  private:
   asio_ns::ssl::context createSslContextInternal(std::string keyfileName,