Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add DTRACE points to measure request timings. #11245

Merged
merged 18 commits into from
Mar 20, 2020
Merged
Show file tree
Hide file tree
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Prev Previous commit
move most stuff into dtrace-wrapper.h
  • Loading branch information
jsteemann committed Mar 20, 2020
commit 331de3086d1b4efb98135a543e464bf02d984e7a
14 changes: 1 addition & 13 deletions arangod/GeneralServer/CommTask.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -30,9 +30,7 @@
#include "Basics/HybridLogicalClock.h"
#include "Basics/StaticStrings.h"
#include "Basics/compile-time-strlen.h"
#ifdef USE_DTRACE
#include "Basics/sdt.h"
#endif
#include "Basics/dtrace-wrapper.h"
#include "Cluster/ServerState.h"
#include "GeneralServer/AsyncJobManager.h"
#include "GeneralServer/AuthenticationFeature.h"
Expand Down Expand Up @@ -153,10 +151,7 @@ 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()) {
Expand Down Expand Up @@ -332,10 +327,7 @@ 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);
Expand Down Expand Up @@ -528,11 +520,7 @@ 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();
Expand Down
19 changes: 8 additions & 11 deletions arangod/GeneralServer/H2CommTask.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -25,9 +25,7 @@
#include "Basics/Exceptions.h"
#include "Basics/ScopeGuard.h"
#include "Basics/asio_ns.h"
#ifdef USE_DTRACE
#include "Basics/sdt.h"
#endif
#include "Basics/dtrace-wrapper.h"
#include "Cluster/ServerState.h"
#include "GeneralServer/GeneralServer.h"
#include "GeneralServer/GeneralServerFeature.h"
Expand Down Expand Up @@ -397,14 +395,14 @@ bool H2CommTask<T>::readCallback(asio_ns::error_code ec) {
static void __attribute__ ((noinline)) DTraceH2CommTaskProcessStream(size_t th) {
DTRACE_PROBE1(arangod, H2CommTaskProcessStream, th);
}
#else
static void DTraceH2CommTaskProcessStream(size_t) {}
#endif

template <SocketType T>
void H2CommTask<T>::processStream(H2CommTask<T>::Stream* stream) {

#ifdef USE_DTRACE
DTraceH2CommTaskProcessStream((size_t) this);
#endif

TRI_ASSERT(stream);

Expand Down Expand Up @@ -483,15 +481,15 @@ bool expectResponseBody(int status_code) {
static void __attribute__ ((noinline)) DTraceH2CommTaskSendResponse(size_t th) {
DTRACE_PROBE1(arangod, H2CommTaskSendResponse, th);
}
#else
static void DTraceH2CommTaskSendResponse(size_t) {}
#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);
Expand Down Expand Up @@ -664,6 +662,9 @@ static void __attribute__ ((noinline)) DTraceH2CommTaskBeforeAsyncWrite(size_t t
static void __attribute__ ((noinline)) DTraceH2CommTaskAfterAsyncWrite(size_t th) {
DTRACE_PROBE1(arangod, H2CommTaskAfterAsyncWrite, th);
}
#else
static void DTraceH2CommTaskBeforeAsyncWrite(size_t) {}
static void DTraceH2CommTaskAfterAsyncWrite(size_t) {}
#endif

// called on IO context thread
Expand Down Expand Up @@ -721,9 +722,7 @@ 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,
Expand All @@ -735,9 +734,7 @@ void H2CommTask<T>::doWrite() {
return;
}

#ifdef USE_DTRACE
DTraceH2CommTaskAfterAsyncWrite((size_t) self.get());
#endif

me.doWrite();
});
Expand Down
19 changes: 8 additions & 11 deletions arangod/GeneralServer/HttpCommTask.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -25,9 +25,7 @@

#include "Basics/ScopeGuard.h"
#include "Basics/asio_ns.h"
#ifdef USE_DTRACE
#include "Basics/sdt.h"
#endif
#include "Basics/dtrace-wrapper.h"
#include "Cluster/ServerState.h"
#include "GeneralServer/GeneralServer.h"
#include "GeneralServer/GeneralServerFeature.h"
Expand Down Expand Up @@ -344,14 +342,14 @@ void HttpCommTask<T>::checkVSTPrefix() {
static void __attribute__ ((noinline)) DTraceHttpCommTaskProcessRequest(size_t th) {
DTRACE_PROBE1(arangod, HttpCommTaskProcessRequest, th);
}
#else
static void DTraceHttpCommTaskProcessRequest(size_t) {}
#endif

template <SocketType T>
void HttpCommTask<T>::processRequest() {

#ifdef USE_DTRACE
DTraceHttpCommTaskProcessRequest((size_t) this);
#endif

TRI_ASSERT(_request);
this->_protocol->timer.cancel();
Expand Down Expand Up @@ -434,15 +432,15 @@ void HttpCommTask<T>::processRequest() {
static void __attribute__ ((noinline)) DTraceHttpCommTaskSendResponse(size_t th) {
DTRACE_PROBE1(arangod, HttpCommTaskSendResponse, th);
}
#else
static void DTraceHttpCommTaskSendResponse(size_t) {}
#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;
Expand Down Expand Up @@ -569,15 +567,16 @@ static void __attribute__ ((noinline)) DTraceHttpCommTaskWriteResponse(size_t th
static void __attribute__ ((noinline)) DTraceHttpCommTaskResponseWritten(size_t th) {
DTRACE_PROBE1(arangod, HttpCommTaskResponseWritten, th);
}
#else
static void DTraceHttpCommTaskWriteResponse(size_t) {}
static void DTraceHttpCommTaskResponseWritten(size_t) {}
#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());

Expand All @@ -594,9 +593,7 @@ void HttpCommTask<T>::writeResponse(RequestStatistics* stat) {
[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);
Expand Down
8 changes: 1 addition & 7 deletions arangod/GeneralServer/RestHandler.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -29,9 +29,7 @@
#include "ApplicationFeatures/ApplicationServer.h"
#include "Basics/RecursiveLocker.h"
#include "Basics/StringUtils.h"
#ifdef USE_DTRACE
#include "Basics/sdt.h"
#endif
#include "Basics/dtrace-wrapper.h"
#include "Cluster/ClusterFeature.h"
#include "Cluster/ClusterInfo.h"
#include "Cluster/ClusterMethods.h"
Expand Down Expand Up @@ -401,11 +399,7 @@ 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);

Expand Down
21 changes: 9 additions & 12 deletions arangod/GeneralServer/VstCommTask.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -28,9 +28,7 @@
#include "Basics/Result.h"
#include "Basics/ScopeGuard.h"
#include "Basics/VelocyPackHelper.h"
#ifdef USE_DTRACE
#include "Basics/sdt.h"
#endif
#include "Basics/dtrace-wrapper.h"
#include "Basics/tryEmplaceHelper.h"
#include "Cluster/ServerState.h"
#include "GeneralServer/AuthenticationFeature.h"
Expand Down Expand Up @@ -199,6 +197,8 @@ bool VstCommTask<T>::processChunk(fuerte::vst::Chunk const& chunk) {
static void __attribute__ ((noinline)) DTraceVstCommTaskProcessMessage(size_t th) {
DTRACE_PROBE1(arangod, VstCommTaskProcessMessage, th);
}
#else
static void DTraceVstCommTaskProcessMessage(size_t) {}
#endif

/// process a VST message
Expand All @@ -207,9 +207,7 @@ bool VstCommTask<T>::processMessage(velocypack::Buffer<uint8_t> buffer,
uint64_t messageId) {
using namespace fuerte;

#ifdef USE_DTRACE
DTraceVstCommTaskProcessMessage((size_t) this);
#endif

auto ptr = buffer.data();
auto len = buffer.byteSize();
Expand Down Expand Up @@ -291,15 +289,15 @@ bool VstCommTask<T>::processMessage(velocypack::Buffer<uint8_t> buffer,
static void __attribute__ ((noinline)) DTraceVstCommTaskSendResponse(size_t th) {
DTRACE_PROBE1(arangod, VstCommTaskSendResponse, th);
}
#else
static void DTraceVstCommTaskSendResponse(size_t) {}
#endif

template<SocketType T>
void VstCommTask<T>::sendResponse(std::unique_ptr<GeneralResponse> baseRes, RequestStatistics* stat) {
using namespace fuerte;

#ifdef USE_DTRACE
DTraceVstCommTaskSendResponse((size_t) this);
#endif

if (this->_stopped.load(std::memory_order_acquire)) {
return;
Expand Down Expand Up @@ -370,6 +368,9 @@ static void __attribute__ ((noinline)) DTraceVstCommTaskBeforeAsyncWrite(size_t
static void __attribute__ ((noinline)) DTraceVstCommTaskAfterAsyncWrite(size_t th) {
DTRACE_PROBE1(arangod, VstCommTaskAfterAsyncWrite, th);
}
#else
static void DTraceVstCommTaskBeforeAsyncWrite(size_t) {}
static void DTraceVstCommTaskAfterAsyncWrite(size_t) {}
#endif

template<SocketType T>
Expand Down Expand Up @@ -397,20 +398,16 @@ void VstCommTask<T>::doWrite() {
TRI_ASSERT(tmp != nullptr);
std::unique_ptr<ResponseItem> item(tmp);

#ifdef USE_DTRACE
DTraceVstCommTaskBeforeAsyncWrite((size_t) this);
#endif

auto& buffers = item->buffers;
asio_ns::async_write(this->_protocol->socket, buffers,
[self(CommTask::shared_from_this()), rsp(std::move(item))]
(asio_ns::error_code const& ec, size_t) {

#ifdef USE_DTRACE
DTraceVstCommTaskAfterAsyncWrite((size_t) self.get());
#endif

auto* me = static_cast<VstCommTask<T>*>(self.get());
auto* me = static_cast<VstCommTask<T>*>(self.get());
RequestStatistics::SET_WRITE_END(rsp->stat);
RequestStatistics::ADD_SENT_BYTES(rsp->stat, rsp->buffers[0].size() + rsp->buffers[1].size());
if (ec) {
Expand Down
37 changes: 37 additions & 0 deletions lib/Basics/dtrace-wrapper.h
Original file line number Diff line number Diff line change
@@ -0,0 +1,37 @@
////////////////////////////////////////////////////////////////////////////////
/// DISCLAIMER
///
/// Copyright 2016 ArangoDB GmbH, Cologne, Germany
///
/// Licensed under the Apache License, Version 2.0 (the "License");
/// you may not use this file except in compliance with the License.
/// You may obtain a copy of the License at
///
/// http://www.apache.org/licenses/LICENSE-2.0
///
/// Unless required by applicable law or agreed to in writing, software
/// distributed under the License is distributed on an "AS IS" BASIS,
/// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
/// See the License for the specific language governing permissions and
/// limitations under the License.
///
/// Copyright holder is ArangoDB GmbH, Cologne, Germany
///
/// @author Jan Steemann
////////////////////////////////////////////////////////////////////////////////

#ifndef ARANGODB_DTRACE_WRAPPER_H
#define ARANGODB_DTRACE_WRAPPER_H 1

#ifdef USE_DTRACE

#include "Basics/sdt.h"

#else

#define DTRACE_PROBE1(a, b, c) do { } while (0);
#define DTRACE_PROBE2(a, b, c, d) do { } while (0);

#endif

#endif