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.

Sign up for GitHub

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

Add DTRACE points to measure request timings. #11245

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
18 commits
Select commit Hold shift + click to select a range
47bacf7
Add DTRACE probes for request infrastructure timing.
neunhoef Mar 3, 2020
213263d
DTrace working.
neunhoef Mar 4, 2020
8363264
Merge remote-tracking branch 'origin/devel' into feature/dtrace
neunhoef Mar 4, 2020
d85e7ca
Include sdt.h with source.
neunhoef Mar 5, 2020
5e6d6d4
Merge branch 'feature/dtrace' of ssh://github.com/arangodb/arangodb i…
neunhoef Mar 5, 2020
60c620b
Merge remote-tracking branch 'origin/devel' into feature/dtrace
neunhoef Mar 5, 2020
89dc1a7
Do VstCommTask, too.
neunhoef Mar 5, 2020
d088e52
Add example files for bpftrace.
neunhoef Mar 5, 2020
ea70ab9
Comments for examples.
neunhoef Mar 5, 2020
1da7311
Fix compilation and script.
neunhoef Mar 5, 2020
d4c0ce6
Bugfixes.
neunhoef Mar 5, 2020
a21303a
Merge remote-tracking branch 'origin/devel' into feature/dtrace
neunhoef Mar 10, 2020
e50a20c
Merge remote-tracking branch 'origin/devel' into feature/dtrace
neunhoef Mar 11, 2020
b99c41b
Merge remote-tracking branch 'origin/devel' into feature/dtrace
neunhoef Mar 12, 2020
5935be4
Merge remote-tracking branch 'origin/devel' into feature/dtrace
neunhoef Mar 13, 2020
b56ee2b
Fix HTTP/2 server side switching.
neunhoef Mar 13, 2020
3ffaa4c
Merge branch 'devel' of github.com:arangodb/arangodb into feature/dtrace
jsteemann Mar 20, 2020
331de30
move most stuff into dtrace-wrapper.h
jsteemann Mar 20, 2020
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
Next Next commit
Add example files for bpftrace.
  • Loading branch information
@neunhoef
neunhoef committed Mar 5, 2020
commit d088e52019b84decf6795f3a7e8dd94e7668ac55
135 changes: 135 additions & 0 deletions scripts/measureRequestLife.bt
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,135 @@
#!/usr/bin/env bpftrace

BEGIN {
@START = nsecs;
@ProcessRequest = 0;
@ProcessStream = 0;
@ProcessMessage = 0;
printf("Measuring timings for requests in arangod...\n");
printf("Values are (in this order per line):\n");
printf(" Absolute time since script start (all times in nanoseconds)\n");
printf(" CommTask::processRequest -> CommTask::prepareExecution\n");
printf(" CommTask::prepareExecution -> CommTask::executeRequest\n");
printf(" CommTask::executeRequest -> CommTask::handleRequestSync\n");
printf(" CommTask::handleRequestSync -> RestHandler::executeEngine\n");
printf(" RestHandler::executeEngine -> CommTask::sendResponse\n");
printf(" CommTask::sendResponse -> CommTask::writeResponse\n");
printf(" CommTask::writeResponse -> CommTask::responseWritten\n");
printf(" Total time for request until response written\n");
}

usdt:build/bin/arangod:arangod:HttpCommTaskProcess* {
@ProcessRequest = nsecs;
}

usdt:build/bin/arangod:arangod:CommTaskPrepareExecution {
@PrepareExecution = nsecs;
}

usdt:build/bin/arangod:arangod:CommTaskExecuteRequest {
@ExecuteRequest = nsecs;
}

usdt:build/bin/arangod:arangod:CommTaskHandleRequestSync {
@HandleRequestSync = nsecs;
}

usdt:build/bin/arangod:arangod:RestHandlerExecuteEngine {
@ExecuteEngine = nsecs;
}

usdt:build/bin/arangod:arangod:HttpCommTaskSendResponse* {
@SendResponse = nsecs;
}

usdt:build/bin/arangod:arangod:HttpCommTaskWriteResponse* {
@WriteResponse = nsecs;
}

usdt:build/bin/arangod:arangod:HttpCommTaskResponseWritten* {
$t = nsecs;
if (@ProcessRequest != 0) {
printf("%lld %lld %lld %lld %lld %lld ",
$t - @START,
@PrepareExecution - @ProcessRequest,
@ExecuteRequest - @PrepareExecution,
@HandleRequestSync - @ExecuteRequest,
@ExecuteEngine - @HandleRequestSync,
@SendResponse - @ExecuteEngine);
printf("%lld %lld %lld\n",
@WriteResponse - @SendResponse,
$t - @WriteResponse,
$t - @ProcessRequest);
@Total = hist($t - @ProcessRequest);
} else {
printf("%lld ResponseWritten\n", $t - @START);
}
@ProcessRequest = 0;
}

usdt:build/bin/arangod:arangod:H2CommTaskProcessStream* {
@ProcessStream = nsecs;
}

usdt:build/bin/arangod:arangod:H2CommTaskSendResponse* {
@SendResponse = nsecs;
}

usdt:build/bin/arangod:arangod:H2CommTaskBeforeAsyncWrite* {
@BeforeAsyncWrite = nsecs;
}

usdt:build/bin/arangod:arangod:H2CommTaskAfterAsyncWrite* {
$t = nsecs;
if (@ProcessStream != 0) {
printf("%lld %lld %lld %lld %lld %lld ",
$t - @START,
@PrepareExecution - @ProcessStream,
@ExecuteRequest - @PrepareExecution,
@HandleRequestSync - @ExecuteRequest,
@ExecuteEngine - @HandleRequestSync,
@SendResponse - @ExecuteEngine);
printf("%lld %lld %lld\n",
@BeforeAsyncWrite - @SendResponse,
$t - @BeforeAsyncWrite,
$t - @ProcessStream);
@Total = hist($t - @ProcessStream);
} else {
printf("%lld AfterAsyncWrite\n", $t - @START);
}
@ProcessStream = 0;
}

usdt:build/bin/arangod:arangod:VstCommTaskProcessMessage* {
@ProcessMessage = nsecs;
}

usdt:build/bin/arangod:arangod:VstCommTaskSendResponse* {
@SendResponse = nsecs;
}

usdt:build/bin/arangod:arangod:VstCommTaskBeforeAsyncWrite* {
@BeforeAsyncWrite = nsecs;
}

usdt:build/bin/arangod:arangod:VstCommTaskAfterAsyncWrite* {
$t = nsecs;
if (@ProcessMessage != 0) {
printf("%lld %lld %lld %lld %lld %lld ",
$t - @START,
@PrepareExecution - @ProcessMessage,
@ExecuteRequest - @PrepareExecution,
@HandleRequestSync - @ExecuteRequest,
@ExecuteEngine - @HandleRequestSync,
@SendResponse - @ExecuteEngine);
printf("%lld %lld %lld\n",
@BeforeAsyncWrite - @SendResponse,
$t - @BeforeAsyncWrite,
$t - @ProcessMessage);
@Total = hist($t - @ProcessMessage);
} else {
printf("%lld AfterAsyncWrite\n", $t - @START);
}
@ProcessMessage = 0;
}

87 changes: 87 additions & 0 deletions scripts/showRequestLife.bt
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,87 @@
#!/usr/bin/env bpftrace

BEGIN {
@START = nsecs;
printf("Tracing timings for requests in arangod...\n");
}

usdt:build/bin/arangod:arangod:HttpCommTaskProcess* {
printf("%llu HttpCommTask::processRequest this=%llx\n", (nsecs-@START)/1000,
arg0);
}

usdt:build/bin/arangod:arangod:CommTaskPrepareExecution {
printf("%llu CommTask::prepareExecution this=%llx\n", (nsecs-@START)/1000,
arg0);
}

usdt:build/bin/arangod:arangod:CommTaskExecuteRequest {
printf("%llu CommTask::executeRequest this=%llx\n", (nsecs-@START)/1000,
arg0);
}

usdt:build/bin/arangod:arangod:CommTaskHandleRequestSync {
printf("%llu CommTask::handleRequestSync commtask=%llx handler=%llx\n",
(nsecs-@START)/1000, arg0, arg1);
}

usdt:build/bin/arangod:arangod:RestHandlerExecuteEngine {
printf("%llu RestHandler::executeEngine this=%llx\n", (nsecs-@START)/1000,
arg0);
}

usdt:build/bin/arangod:arangod:HttpCommTaskSendResponse* {
printf("%llu HttpCommTask::sendResponse this=%llx\n",
(nsecs-@START)/1000, arg0);
}

usdt:build/bin/arangod:arangod:HttpCommTaskWriteResponse* {
printf("%llu HttpCommTask::writeResponse this=%llx\n",
(nsecs-@START)/1000, arg0);
}

usdt:build/bin/arangod:arangod:HttpCommTaskResponseWritten* {
printf("%llu HttpCommTask::ResponseWritten this=%llx\n",
(nsecs-@START)/1000, arg0);
}

usdt:build/bin/arangod:arangod:H2CommTaskProcessStream* {
printf("%llu H2CommTask::processStream this=%llx\n", (nsecs-@START)/1000,
arg0);
}

usdt:build/bin/arangod:arangod:H2CommTaskSendResponse* {
printf("%llu H2CommTask::sendResponse this=%llx\n",
(nsecs-@START)/1000, arg0);
}

usdt:build/bin/arangod:arangod:H2CommTaskBeforeAsyncWrite* {
printf("%llu H2CommTask::BeforeAsyncWrite this=%llx\n",
(nsecs-@START)/1000, arg0);
}

usdt:build/bin/arangod:arangod:H2CommTaskAfterAsyncWrite* {
printf("%llu H2CommTask::AfterAsyncWritten this=%llx\n",
(nsecs-@START)/1000, arg0);
}

usdt:build/bin/arangod:arangod:VstCommTaskProcess* {
printf("%llu VstCommTask::processMessage this=%llx\n", (nsecs-@START)/1000,
arg0);
}

usdt:build/bin/arangod:arangod:VstCommTaskSendResponse* {
printf("%llu H2CommTask::sendResponse this=%llx\n",
(nsecs-@START)/1000, arg0);
}

usdt:build/bin/arangod:arangod:VstCommTaskBeforeAsyncWrite* {
printf("%llu VstCommTask::BeforeAsyncWrite this=%llx\n",
(nsecs-@START)/1000, arg0);
}

usdt:build/bin/arangod:arangod:VstCommTaskAfterAsyncWrite* {
printf("%llu VstCommTask::AfterAsyncWritten this=%llx\n",
(nsecs-@START)/1000, arg0);
}