[kudu-CR] KUDU-2996: trace when rpc duration too long ms exceeded
Tim Armstrong has submitted this change and it was merged. ( http://gerrit.cloudera.org:8080/15197 ) Change subject: KUDU-2996: trace when rpc_duration_too_long_ms exceeded .. KUDU-2996: trace when rpc_duration_too_long_ms exceeded Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05 Reviewed-on: http://gerrit.cloudera.org:8080/15197 Tested-by: Alexey Serbin Reviewed-by: Alexey Serbin --- M src/kudu/rpc/rpcz_store.cc 1 file changed, 6 insertions(+), 6 deletions(-) Approvals: Alexey Serbin: Looks good to me, approved; Verified -- To view, visit http://gerrit.cloudera.org:8080/15197 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: kudu Gerrit-Branch: master Gerrit-MessageType: merged Gerrit-Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05 Gerrit-Change-Number: 15197 Gerrit-PatchSet: 5 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Alexey Serbin Gerrit-Reviewer: Kudu Jenkins (120) Gerrit-Reviewer: Tim Armstrong
[kudu-CR] KUDU-2996: trace when rpc duration too long ms exceeded
Alexey Serbin has posted comments on this change. ( http://gerrit.cloudera.org:8080/15197 ) Change subject: KUDU-2996: trace when rpc_duration_too_long_ms exceeded .. Patch Set 4: Code-Review+2 -- To view, visit http://gerrit.cloudera.org:8080/15197 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: kudu Gerrit-Branch: master Gerrit-MessageType: comment Gerrit-Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05 Gerrit-Change-Number: 15197 Gerrit-PatchSet: 4 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Alexey Serbin Gerrit-Reviewer: Kudu Jenkins (120) Gerrit-Reviewer: Tim Armstrong Gerrit-Comment-Date: Tue, 11 Feb 2020 02:05:19 + Gerrit-HasComments: No
[kudu-CR] KUDU-2996: trace when rpc duration too long ms exceeded
Alexey Serbin has posted comments on this change. ( http://gerrit.cloudera.org:8080/15197 ) Change subject: KUDU-2996: trace when rpc_duration_too_long_ms exceeded .. Patch Set 4: Verified+1 unrelated test failure in ToolTest.TestHmsList -- To view, visit http://gerrit.cloudera.org:8080/15197 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: kudu Gerrit-Branch: master Gerrit-MessageType: comment Gerrit-Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05 Gerrit-Change-Number: 15197 Gerrit-PatchSet: 4 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Alexey Serbin Gerrit-Reviewer: Kudu Jenkins (120) Gerrit-Reviewer: Tim Armstrong Gerrit-Comment-Date: Tue, 11 Feb 2020 02:05:17 + Gerrit-HasComments: No
[kudu-CR] KUDU-2996: trace when rpc duration too long ms exceeded
Alexey Serbin has removed a vote on this change. Change subject: KUDU-2996: trace when rpc_duration_too_long_ms exceeded .. Removed Verified-1 by Kudu Jenkins (120) -- To view, visit http://gerrit.cloudera.org:8080/15197 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: kudu Gerrit-Branch: master Gerrit-MessageType: deleteVote Gerrit-Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05 Gerrit-Change-Number: 15197 Gerrit-PatchSet: 4 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Alexey Serbin Gerrit-Reviewer: Kudu Jenkins (120) Gerrit-Reviewer: Tim Armstrong
[kudu-CR] KUDU-2996: trace when rpc duration too long ms exceeded
Hello Alexey Serbin, Kudu Jenkins, I'd like you to reexamine a change. Please visit http://gerrit.cloudera.org:8080/15197 to look at the new patch set (#4). Change subject: KUDU-2996: trace when rpc_duration_too_long_ms exceeded .. KUDU-2996: trace when rpc_duration_too_long_ms exceeded Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05 --- M src/kudu/rpc/rpcz_store.cc 1 file changed, 6 insertions(+), 6 deletions(-) git pull ssh://gerrit.cloudera.org:29418/kudu refs/changes/97/15197/4 -- To view, visit http://gerrit.cloudera.org:8080/15197 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: kudu Gerrit-Branch: master Gerrit-MessageType: newpatchset Gerrit-Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05 Gerrit-Change-Number: 15197 Gerrit-PatchSet: 4 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Alexey Serbin Gerrit-Reviewer: Kudu Jenkins (120) Gerrit-Reviewer: Tim Armstrong
[kudu-CR] KUDU-2996: trace when rpc duration too long ms exceeded
Tim Armstrong has posted comments on this change. (
http://gerrit.cloudera.org:8080/15197 )
Change subject: KUDU-2996: trace when rpc_duration_too_long_ms exceeded
..
Patch Set 3:
(1 comment)
http://gerrit.cloudera.org:8080/#/c/15197/3/src/kudu/rpc/rpcz_store.cc
File src/kudu/rpc/rpcz_store.cc:
http://gerrit.cloudera.org:8080/#/c/15197/3/src/kudu/rpc/rpcz_store.cc@266
PS3, Line 266: if (PREDICT_FALSE(FLAGS_rpc_dump_all_traces)) {
: LOG(INFO) << call->ToString() << " took " << duration_ms <<
"ms. Trace:";
: call->trace()->Dump((INFO), true);
: } else if (duration_ms > FLAGS_rpc_duration_too_long_ms) {
: LOG(INFO) << call->ToString() << " took " << duration_ms <<
"ms.";
: string s = call->trace()->DumpToString();
: if (!s.empty()) {
: LOG(INFO) << "Trace:\n" << s;
: }
: }
> I guess I wanted to say that even if those will result in separate lines if
I looked into how the LOG macro is implemented and it looks like you're right -
the destructor of the LogMessage object is what flushes the log message and
that will only run after Dump() returns. So this makes sense to me.
https://github.com/google/glog/blob/58d7f873dcde8cf0fe6f37817643a7ff4e49e6d4/src/logging.cc#L1457
--
To view, visit http://gerrit.cloudera.org:8080/15197
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings
Gerrit-Project: kudu
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05
Gerrit-Change-Number: 15197
Gerrit-PatchSet: 3
Gerrit-Owner: Tim Armstrong
Gerrit-Reviewer: Alexey Serbin
Gerrit-Reviewer: Kudu Jenkins (120)
Gerrit-Reviewer: Tim Armstrong
Gerrit-Comment-Date: Tue, 11 Feb 2020 00:12:26 +
Gerrit-HasComments: Yes
[kudu-CR] KUDU-2996: trace when rpc duration too long ms exceeded
Alexey Serbin has posted comments on this change. (
http://gerrit.cloudera.org:8080/15197 )
Change subject: KUDU-2996: trace when rpc_duration_too_long_ms exceeded
..
Patch Set 3:
(1 comment)
http://gerrit.cloudera.org:8080/#/c/15197/3/src/kudu/rpc/rpcz_store.cc
File src/kudu/rpc/rpcz_store.cc:
http://gerrit.cloudera.org:8080/#/c/15197/3/src/kudu/rpc/rpcz_store.cc@266
PS3, Line 266: if (PREDICT_FALSE(FLAGS_rpc_dump_all_traces)) {
: LOG(INFO) << call->ToString() << " took " << duration_ms <<
"ms. Trace:";
: call->trace()->Dump((INFO), true);
: } else if (duration_ms > FLAGS_rpc_duration_too_long_ms) {
: LOG(INFO) << call->ToString() << " took " << duration_ms <<
"ms.";
: string s = call->trace()->DumpToString();
: if (!s.empty()) {
: LOG(INFO) << "Trace:\n" << s;
: }
: }
> If I understand correctly, those will not result in separate lines. E.g.,
I guess I wanted to say that even if those will result in separate lines if
using Dump(), using DumpToString() will not be much different since
DumpToString() is implemented via Dump().
--
To view, visit http://gerrit.cloudera.org:8080/15197
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings
Gerrit-Project: kudu
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05
Gerrit-Change-Number: 15197
Gerrit-PatchSet: 3
Gerrit-Owner: Tim Armstrong
Gerrit-Reviewer: Alexey Serbin
Gerrit-Reviewer: Kudu Jenkins (120)
Gerrit-Reviewer: Tim Armstrong
Gerrit-Comment-Date: Tue, 11 Feb 2020 00:03:56 +
Gerrit-HasComments: Yes
[kudu-CR] KUDU-2996: trace when rpc duration too long ms exceeded
Alexey Serbin has posted comments on this change. (
http://gerrit.cloudera.org:8080/15197 )
Change subject: KUDU-2996: trace when rpc_duration_too_long_ms exceeded
..
Patch Set 3:
(1 comment)
http://gerrit.cloudera.org:8080/#/c/15197/3/src/kudu/rpc/rpcz_store.cc
File src/kudu/rpc/rpcz_store.cc:
http://gerrit.cloudera.org:8080/#/c/15197/3/src/kudu/rpc/rpcz_store.cc@266
PS3, Line 266: if (PREDICT_FALSE(FLAGS_rpc_dump_all_traces)) {
: LOG(INFO) << call->ToString() << " took " << duration_ms <<
"ms. Trace:";
: call->trace()->Dump((INFO), true);
: } else if (duration_ms > FLAGS_rpc_duration_too_long_ms) {
: LOG(INFO) << call->ToString() << " took " << duration_ms <<
"ms.";
: string s = call->trace()->DumpToString();
: if (!s.empty()) {
: LOG(INFO) << "Trace:\n" << s;
: }
: }
> I'm not sure about dumping directly to LOG(INFO), won't that result in the
If I understand correctly, those will not result in separate lines. E.g., the
code in line 270 doesn't result in multiple lines. In addition, DumpToString()
is implemented via Dump() anyway:
https://github.com/cloudera/kudu/blob/ccdb6b557d440423843952cace3e7d351a743fa6/src/kudu/util/trace.cc#L190-L194
--
To view, visit http://gerrit.cloudera.org:8080/15197
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings
Gerrit-Project: kudu
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05
Gerrit-Change-Number: 15197
Gerrit-PatchSet: 3
Gerrit-Owner: Tim Armstrong
Gerrit-Reviewer: Alexey Serbin
Gerrit-Reviewer: Kudu Jenkins (120)
Gerrit-Reviewer: Tim Armstrong
Gerrit-Comment-Date: Mon, 10 Feb 2020 23:59:52 +
Gerrit-HasComments: Yes
[kudu-CR] KUDU-2996: trace when rpc duration too long ms exceeded
Tim Armstrong has posted comments on this change. (
http://gerrit.cloudera.org:8080/15197 )
Change subject: KUDU-2996: trace when rpc_duration_too_long_ms exceeded
..
Patch Set 3:
(1 comment)
http://gerrit.cloudera.org:8080/#/c/15197/3/src/kudu/rpc/rpcz_store.cc
File src/kudu/rpc/rpcz_store.cc:
http://gerrit.cloudera.org:8080/#/c/15197/3/src/kudu/rpc/rpcz_store.cc@266
PS3, Line 266: if (PREDICT_FALSE(FLAGS_rpc_dump_all_traces)) {
: LOG(INFO) << call->ToString() << " took " << duration_ms <<
"ms. Trace:";
: call->trace()->Dump((INFO), true);
: } else if (duration_ms > FLAGS_rpc_duration_too_long_ms) {
: LOG(INFO) << call->ToString() << " took " << duration_ms <<
"ms.";
: string s = call->trace()->DumpToString();
: if (!s.empty()) {
: LOG(INFO) << "Trace:\n" << s;
: }
: }
> Only in PS3 I realized the code under those 2 conditional scopes might be u
I'm not sure about dumping directly to LOG(INFO), won't that result in the bit
of the trace being split across many log messages? Not necessarily in a logical
way. My understanding of glog is that each of these statements would result in
a separate log line:
https://github.com/cloudera/kudu/blob/master/src/kudu/util/trace.cc#L163
I was copying the code from l258. Would it make sense for the dump_all_traces
branch to use the DumpToString() approach instead, if we want to unify it?
--
To view, visit http://gerrit.cloudera.org:8080/15197
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings
Gerrit-Project: kudu
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05
Gerrit-Change-Number: 15197
Gerrit-PatchSet: 3
Gerrit-Owner: Tim Armstrong
Gerrit-Reviewer: Alexey Serbin
Gerrit-Reviewer: Kudu Jenkins (120)
Gerrit-Reviewer: Tim Armstrong
Gerrit-Comment-Date: Mon, 10 Feb 2020 21:25:48 +
Gerrit-HasComments: Yes
[kudu-CR] KUDU-2996: trace when rpc duration too long ms exceeded
Alexey Serbin has posted comments on this change. (
http://gerrit.cloudera.org:8080/15197 )
Change subject: KUDU-2996: trace when rpc_duration_too_long_ms exceeded
..
Patch Set 3:
(1 comment)
http://gerrit.cloudera.org:8080/#/c/15197/3/src/kudu/rpc/rpcz_store.cc
File src/kudu/rpc/rpcz_store.cc:
http://gerrit.cloudera.org:8080/#/c/15197/3/src/kudu/rpc/rpcz_store.cc@266
PS3, Line 266: if (PREDICT_FALSE(FLAGS_rpc_dump_all_traces)) {
: LOG(INFO) << call->ToString() << " took " << duration_ms <<
"ms. Trace:";
: call->trace()->Dump((INFO), true);
: } else if (duration_ms > FLAGS_rpc_duration_too_long_ms) {
: LOG(INFO) << call->ToString() << " took " << duration_ms <<
"ms.";
: string s = call->trace()->DumpToString();
: if (!s.empty()) {
: LOG(INFO) << "Trace:\n" << s;
: }
: }
Only in PS3 I realized the code under those 2 conditional scopes might be
unified, something like below:
if (duration_ms > FLAGS_rpc_duration_too_long_ms ||
PREDICT_FALSE(FLAGS_rpc_dump_all_traces)) {
const auto flags = (duration_ms > FLAGS_rpc_duration_too_long_ms)
? INCLUDE_ALL : INCLUDE_TIME_DELTAS;
LOG(INFO) << call->ToString() << " took " << duration_ms << "ms. Trace:";
call->trace()->Dump((INFO), flags);
}
?
--
To view, visit http://gerrit.cloudera.org:8080/15197
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings
Gerrit-Project: kudu
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05
Gerrit-Change-Number: 15197
Gerrit-PatchSet: 3
Gerrit-Owner: Tim Armstrong
Gerrit-Reviewer: Alexey Serbin
Gerrit-Reviewer: Kudu Jenkins (120)
Gerrit-Reviewer: Tim Armstrong
Gerrit-Comment-Date: Mon, 10 Feb 2020 20:10:34 +
Gerrit-HasComments: Yes
[kudu-CR] KUDU-2996: trace when rpc duration too long ms exceeded
Tim Armstrong has posted comments on this change. ( http://gerrit.cloudera.org:8080/15197 ) Change subject: KUDU-2996: trace when rpc_duration_too_long_ms exceeded .. Patch Set 1: (1 comment) Also fixed the IWYU error http://gerrit.cloudera.org:8080/#/c/15197/1/src/kudu/rpc/rpcz_store.cc File src/kudu/rpc/rpcz_store.cc: http://gerrit.cloudera.org:8080/#/c/15197/1/src/kudu/rpc/rpcz_store.cc@270 PS1, Line 270: << "Request Metrics: " << call->trace()->MetricsAsJSON() << "\n"; > If we are dumping both time deltas and metrics below, why do we need to dup I went with the first option. I should've looked more closely at what the functions did - I didn't realise the trace included the metrics. -- To view, visit http://gerrit.cloudera.org:8080/15197 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: kudu Gerrit-Branch: master Gerrit-MessageType: comment Gerrit-Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05 Gerrit-Change-Number: 15197 Gerrit-PatchSet: 1 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Alexey Serbin Gerrit-Reviewer: Kudu Jenkins (120) Gerrit-Reviewer: Tim Armstrong Gerrit-Comment-Date: Mon, 10 Feb 2020 19:09:20 + Gerrit-HasComments: Yes
[kudu-CR] KUDU-2996: trace when rpc duration too long ms exceeded
Hello Alexey Serbin, Kudu Jenkins, I'd like you to reexamine a change. Please visit http://gerrit.cloudera.org:8080/15197 to look at the new patch set (#3). Change subject: KUDU-2996: trace when rpc_duration_too_long_ms exceeded .. KUDU-2996: trace when rpc_duration_too_long_ms exceeded Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05 --- M src/kudu/rpc/rpcz_store.cc 1 file changed, 6 insertions(+), 2 deletions(-) git pull ssh://gerrit.cloudera.org:29418/kudu refs/changes/97/15197/3 -- To view, visit http://gerrit.cloudera.org:8080/15197 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: kudu Gerrit-Branch: master Gerrit-MessageType: newpatchset Gerrit-Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05 Gerrit-Change-Number: 15197 Gerrit-PatchSet: 3 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Alexey Serbin Gerrit-Reviewer: Kudu Jenkins (120)
[kudu-CR] KUDU-2996: trace when rpc duration too long ms exceeded
Hello Alexey Serbin, Kudu Jenkins, I'd like you to reexamine a change. Please visit http://gerrit.cloudera.org:8080/15197 to look at the new patch set (#2). Change subject: KUDU-2996: trace when rpc_duration_too_long_ms exceeded .. KUDU-2996: trace when rpc_duration_too_long_ms exceeded Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05 --- M src/kudu/rpc/rpcz_store.cc 1 file changed, 5 insertions(+), 2 deletions(-) git pull ssh://gerrit.cloudera.org:29418/kudu refs/changes/97/15197/2 -- To view, visit http://gerrit.cloudera.org:8080/15197 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: kudu Gerrit-Branch: master Gerrit-MessageType: newpatchset Gerrit-Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05 Gerrit-Change-Number: 15197 Gerrit-PatchSet: 2 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Alexey Serbin Gerrit-Reviewer: Kudu Jenkins (120)
[kudu-CR] KUDU-2996: trace when rpc duration too long ms exceeded
Alexey Serbin has posted comments on this change. ( http://gerrit.cloudera.org:8080/15197 ) Change subject: KUDU-2996: trace when rpc_duration_too_long_ms exceeded .. Patch Set 1: (1 comment) http://gerrit.cloudera.org:8080/#/c/15197/1/src/kudu/rpc/rpcz_store.cc File src/kudu/rpc/rpcz_store.cc: http://gerrit.cloudera.org:8080/#/c/15197/1/src/kudu/rpc/rpcz_store.cc@270 PS1, Line 270: << "Request Metrics: " << call->trace()->MetricsAsJSON() << "\n"; If we are dumping both time deltas and metrics below, why do we need to duplicate metrics here? Maybe, remove this then or set INCLUDE_TIME_DELTAS for the DumpToString() below? -- To view, visit http://gerrit.cloudera.org:8080/15197 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: kudu Gerrit-Branch: master Gerrit-MessageType: comment Gerrit-Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05 Gerrit-Change-Number: 15197 Gerrit-PatchSet: 1 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Alexey Serbin Gerrit-Reviewer: Kudu Jenkins (120) Gerrit-Comment-Date: Mon, 10 Feb 2020 18:54:52 + Gerrit-HasComments: Yes
[kudu-CR] KUDU-2996: trace when rpc duration too long ms exceeded
Tim Armstrong has uploaded this change for review. ( http://gerrit.cloudera.org:8080/15197 Change subject: KUDU-2996: trace when rpc_duration_too_long_ms exceeded .. KUDU-2996: trace when rpc_duration_too_long_ms exceeded Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05 --- M src/kudu/rpc/rpcz_store.cc 1 file changed, 5 insertions(+), 1 deletion(-) git pull ssh://gerrit.cloudera.org:29418/kudu refs/changes/97/15197/1 -- To view, visit http://gerrit.cloudera.org:8080/15197 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: kudu Gerrit-Branch: master Gerrit-MessageType: newchange Gerrit-Change-Id: I20d9b5e318f4a987051f1f7c2cd5b1d92c61bd05 Gerrit-Change-Number: 15197 Gerrit-PatchSet: 1 Gerrit-Owner: Tim Armstrong
