[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Tim Armstrong has submitted this change and it was merged. (
http://gerrit.cloudera.org:8080/14668 )
Change subject: IMPALA-9128: part 2: dump traces for slow RPCs
..
IMPALA-9128: part 2: dump traces for slow RPCs
This adds trace events for data stream RPCs and
dumps them when they take longer than
--impala_slow_rpc_threshold_ms.
I needed to modify the KRPC code to do this because it
currently only dumps traces for RPCs with deadlines.
I plan to add some version of this upstream in Kudu
so that we don't diverge our KRPC implementation.
Example output from test_exchange_small_buffer:
I 08:38:53.732910 26509 rpcz_store.cc:265] Call
impala.DataStreamService.TransmitData from 127.0.0.1:42434 (request call id 43)
took 7799ms. Request Metrics: {}
I 08:38:53.732928 26509 rpcz_store.cc:269] Trace:
08:38:45.933412 (+ 0us) impala-service-pool.cc:167] Inserting onto
call queue
08:38:45.933449 (+37us) impala-service-pool.cc:254] Handling call
08:38:45.933470 (+21us) krpc-data-stream-mgr.cc:227] Added early sender
08:38:47.906542 (+1973072us) krpc-data-stream-recvr.cc:327] Enqueuing
deferred RPC
08:38:53.732858 (+5826316us) krpc-data-stream-recvr.cc:506] Processing
deferred RPC
08:38:53.732860 (+ 2us) krpc-data-stream-recvr.cc:399] Deserializing
batch
08:38:53.732888 (+28us) krpc-data-stream-recvr.cc:426] Enqueuing
deserialized batch
08:38:53.732895 (+ 7us) inbound_call.cc:162] Queueing success response
Disabled +-clang-diagnostic-gnu-zero-variadic-macro-arguments because it
had false positives on the TRACE_TO invocations.
Testing:
* Ran exhaustive and ASAN tests
* Ran stress test
Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947
Reviewed-on: http://gerrit.cloudera.org:8080/14668
Reviewed-by: Tim Armstrong
Tested-by: Impala Public Jenkins
---
M .clang-tidy
M be/src/kudu/rpc/rpcz_store.cc
M be/src/runtime/krpc-data-stream-mgr.cc
M be/src/runtime/krpc-data-stream-recvr.cc
M tests/custom_cluster/test_exchange_deferred_batches.py
M tests/custom_cluster/test_exchange_delays.py
6 files changed, 43 insertions(+), 10 deletions(-)
Approvals:
Tim Armstrong: Looks good to me, approved
Impala Public Jenkins: Verified
--
To view, visit http://gerrit.cloudera.org:8080/14668
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings
Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: merged
Gerrit-Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947
Gerrit-Change-Number: 14668
Gerrit-PatchSet: 8
Gerrit-Owner: Tim Armstrong
Gerrit-Reviewer: Impala Public Jenkins
Gerrit-Reviewer: Lars Volker
Gerrit-Reviewer: Thomas Tauber-Marshall
Gerrit-Reviewer: Tim Armstrong
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Impala Public Jenkins has posted comments on this change. ( http://gerrit.cloudera.org:8080/14668 ) Change subject: IMPALA-9128: part 2: dump traces for slow RPCs .. Patch Set 7: Verified+1 -- To view, visit http://gerrit.cloudera.org:8080/14668 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: Impala-ASF Gerrit-Branch: master Gerrit-MessageType: comment Gerrit-Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947 Gerrit-Change-Number: 14668 Gerrit-PatchSet: 7 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Impala Public Jenkins Gerrit-Reviewer: Lars Volker Gerrit-Reviewer: Thomas Tauber-Marshall Gerrit-Reviewer: Tim Armstrong Gerrit-Comment-Date: Thu, 14 Nov 2019 20:18:19 + Gerrit-HasComments: No
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Tim Armstrong has posted comments on this change. ( http://gerrit.cloudera.org:8080/14668 ) Change subject: IMPALA-9128: part 2: dump traces for slow RPCs .. Patch Set 7: I didn't see a significant perf change in any of the exchange targeted perf benchmarks. -- To view, visit http://gerrit.cloudera.org:8080/14668 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: Impala-ASF Gerrit-Branch: master Gerrit-MessageType: comment Gerrit-Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947 Gerrit-Change-Number: 14668 Gerrit-PatchSet: 7 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Impala Public Jenkins Gerrit-Reviewer: Lars Volker Gerrit-Reviewer: Thomas Tauber-Marshall Gerrit-Reviewer: Tim Armstrong Gerrit-Comment-Date: Thu, 14 Nov 2019 18:33:21 + Gerrit-HasComments: No
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Tim Armstrong has posted comments on this change. ( http://gerrit.cloudera.org:8080/14668 ) Change subject: IMPALA-9128: part 2: dump traces for slow RPCs .. Patch Set 7: 17:07:05 E: Failed to fetch http://us-west-2.ec2.archive.ubuntu.com/ubuntu/dists/xenial-updates/main/binary-amd64/Packages.xz Hash Sum mismatch 17:07:05 E: Some index files failed to download. They have been ignored, or old ones used instead. -- To view, visit http://gerrit.cloudera.org:8080/14668 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: Impala-ASF Gerrit-Branch: master Gerrit-MessageType: comment Gerrit-Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947 Gerrit-Change-Number: 14668 Gerrit-PatchSet: 7 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Impala Public Jenkins Gerrit-Reviewer: Lars Volker Gerrit-Reviewer: Thomas Tauber-Marshall Gerrit-Reviewer: Tim Armstrong Gerrit-Comment-Date: Thu, 14 Nov 2019 15:44:17 + Gerrit-HasComments: No
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Impala Public Jenkins has posted comments on this change. ( http://gerrit.cloudera.org:8080/14668 ) Change subject: IMPALA-9128: part 2: dump traces for slow RPCs .. Patch Set 7: Build started: https://jenkins.impala.io/job/gerrit-verify-dryrun/5212/ DRY_RUN=true -- To view, visit http://gerrit.cloudera.org:8080/14668 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: Impala-ASF Gerrit-Branch: master Gerrit-MessageType: comment Gerrit-Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947 Gerrit-Change-Number: 14668 Gerrit-PatchSet: 7 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Impala Public Jenkins Gerrit-Reviewer: Lars Volker Gerrit-Reviewer: Thomas Tauber-Marshall Gerrit-Reviewer: Tim Armstrong Gerrit-Comment-Date: Thu, 14 Nov 2019 15:44:31 + Gerrit-HasComments: No
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Impala Public Jenkins has posted comments on this change. ( http://gerrit.cloudera.org:8080/14668 ) Change subject: IMPALA-9128: part 2: dump traces for slow RPCs .. Patch Set 7: Verified-1 Build failed: https://jenkins.impala.io/job/gerrit-verify-dryrun/5209/ -- To view, visit http://gerrit.cloudera.org:8080/14668 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: Impala-ASF Gerrit-Branch: master Gerrit-MessageType: comment Gerrit-Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947 Gerrit-Change-Number: 14668 Gerrit-PatchSet: 7 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Impala Public Jenkins Gerrit-Reviewer: Lars Volker Gerrit-Reviewer: Thomas Tauber-Marshall Gerrit-Reviewer: Tim Armstrong Gerrit-Comment-Date: Wed, 13 Nov 2019 21:09:13 + Gerrit-HasComments: No
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Impala Public Jenkins has posted comments on this change. ( http://gerrit.cloudera.org:8080/14668 ) Change subject: IMPALA-9128: part 2: dump traces for slow RPCs .. Patch Set 7: Build started: https://jenkins.impala.io/job/gerrit-verify-dryrun/5209/ DRY_RUN=true -- To view, visit http://gerrit.cloudera.org:8080/14668 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: Impala-ASF Gerrit-Branch: master Gerrit-MessageType: comment Gerrit-Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947 Gerrit-Change-Number: 14668 Gerrit-PatchSet: 7 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Impala Public Jenkins Gerrit-Reviewer: Lars Volker Gerrit-Reviewer: Thomas Tauber-Marshall Gerrit-Reviewer: Tim Armstrong Gerrit-Comment-Date: Wed, 13 Nov 2019 16:41:58 + Gerrit-HasComments: No
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Tim Armstrong has posted comments on this change. ( http://gerrit.cloudera.org:8080/14668 ) Change subject: IMPALA-9128: part 2: dump traces for slow RPCs .. Patch Set 5: I hit https://issues.apache.org/jira/browse/IMPALA-9154 unfortunately when doing the perf run. Rebased and going to run precommit in parallel with redoing my perf run. -- To view, visit http://gerrit.cloudera.org:8080/14668 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: Impala-ASF Gerrit-Branch: master Gerrit-MessageType: comment Gerrit-Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947 Gerrit-Change-Number: 14668 Gerrit-PatchSet: 5 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Impala Public Jenkins Gerrit-Reviewer: Lars Volker Gerrit-Reviewer: Thomas Tauber-Marshall Gerrit-Reviewer: Tim Armstrong Gerrit-Comment-Date: Wed, 13 Nov 2019 16:41:38 + Gerrit-HasComments: No
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Tim Armstrong has posted comments on this change. ( http://gerrit.cloudera.org:8080/14668 ) Change subject: IMPALA-9128: part 2: dump traces for slow RPCs .. Patch Set 7: Code-Review+2 -- To view, visit http://gerrit.cloudera.org:8080/14668 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: Impala-ASF Gerrit-Branch: master Gerrit-MessageType: comment Gerrit-Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947 Gerrit-Change-Number: 14668 Gerrit-PatchSet: 7 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Impala Public Jenkins Gerrit-Reviewer: Lars Volker Gerrit-Reviewer: Thomas Tauber-Marshall Gerrit-Reviewer: Tim Armstrong Gerrit-Comment-Date: Wed, 13 Nov 2019 16:41:48 + Gerrit-HasComments: No
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Hello Thomas Tauber-Marshall, Lars Volker, Impala Public Jenkins,
I'd like you to reexamine a change. Please visit
http://gerrit.cloudera.org:8080/14668
to look at the new patch set (#7).
Change subject: IMPALA-9128: part 2: dump traces for slow RPCs
..
IMPALA-9128: part 2: dump traces for slow RPCs
This adds trace events for data stream RPCs and
dumps them when they take longer than
--impala_slow_rpc_threshold_ms.
I needed to modify the KRPC code to do this because it
currently only dumps traces for RPCs with deadlines.
I plan to add some version of this upstream in Kudu
so that we don't diverge our KRPC implementation.
Example output from test_exchange_small_buffer:
I 08:38:53.732910 26509 rpcz_store.cc:265] Call
impala.DataStreamService.TransmitData from 127.0.0.1:42434 (request call id 43)
took 7799ms. Request Metrics: {}
I 08:38:53.732928 26509 rpcz_store.cc:269] Trace:
08:38:45.933412 (+ 0us) impala-service-pool.cc:167] Inserting onto
call queue
08:38:45.933449 (+37us) impala-service-pool.cc:254] Handling call
08:38:45.933470 (+21us) krpc-data-stream-mgr.cc:227] Added early sender
08:38:47.906542 (+1973072us) krpc-data-stream-recvr.cc:327] Enqueuing
deferred RPC
08:38:53.732858 (+5826316us) krpc-data-stream-recvr.cc:506] Processing
deferred RPC
08:38:53.732860 (+ 2us) krpc-data-stream-recvr.cc:399] Deserializing
batch
08:38:53.732888 (+28us) krpc-data-stream-recvr.cc:426] Enqueuing
deserialized batch
08:38:53.732895 (+ 7us) inbound_call.cc:162] Queueing success response
Disabled +-clang-diagnostic-gnu-zero-variadic-macro-arguments because it
had false positives on the TRACE_TO invocations.
Testing:
* Ran exhaustive and ASAN tests
* Ran stress test
Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947
---
M .clang-tidy
M be/src/kudu/rpc/rpcz_store.cc
M be/src/runtime/krpc-data-stream-mgr.cc
M be/src/runtime/krpc-data-stream-recvr.cc
M tests/custom_cluster/test_exchange_deferred_batches.py
M tests/custom_cluster/test_exchange_delays.py
6 files changed, 43 insertions(+), 10 deletions(-)
git pull ssh://gerrit.cloudera.org:29418/Impala-ASF refs/changes/68/14668/7
--
To view, visit http://gerrit.cloudera.org:8080/14668
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings
Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: newpatchset
Gerrit-Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947
Gerrit-Change-Number: 14668
Gerrit-PatchSet: 7
Gerrit-Owner: Tim Armstrong
Gerrit-Reviewer: Impala Public Jenkins
Gerrit-Reviewer: Lars Volker
Gerrit-Reviewer: Thomas Tauber-Marshall
Gerrit-Reviewer: Tim Armstrong
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Impala Public Jenkins has posted comments on this change. ( http://gerrit.cloudera.org:8080/14668 ) Change subject: IMPALA-9128: part 2: dump traces for slow RPCs .. Patch Set 5: Verified+1 -- To view, visit http://gerrit.cloudera.org:8080/14668 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: Impala-ASF Gerrit-Branch: master Gerrit-MessageType: comment Gerrit-Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947 Gerrit-Change-Number: 14668 Gerrit-PatchSet: 5 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Impala Public Jenkins Gerrit-Reviewer: Lars Volker Gerrit-Reviewer: Thomas Tauber-Marshall Gerrit-Reviewer: Tim Armstrong Gerrit-Comment-Date: Wed, 13 Nov 2019 02:48:27 + Gerrit-HasComments: No
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Tim Armstrong has posted comments on this change. ( http://gerrit.cloudera.org:8080/14668 ) Change subject: IMPALA-9128: part 2: dump traces for slow RPCs .. Patch Set 5: (1 comment) http://gerrit.cloudera.org:8080/#/c/14668/5//COMMIT_MSG Commit Message: http://gerrit.cloudera.org:8080/#/c/14668/5//COMMIT_MSG@38 PS5, Line 38: * basic perf testing > Is tracing on by default? I assume the perf impact is negligible? I think so in practice, but wanted to do a sanity test. It does always log the trace to a buffer, which requires allocating memory from an arena and substituting the message text. Should be negligible in the context of other overhead from the RPC, but wanted to be sure, since I did add several additional traces per RPC. -- To view, visit http://gerrit.cloudera.org:8080/14668 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: Impala-ASF Gerrit-Branch: master Gerrit-MessageType: comment Gerrit-Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947 Gerrit-Change-Number: 14668 Gerrit-PatchSet: 5 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Impala Public Jenkins Gerrit-Reviewer: Lars Volker Gerrit-Reviewer: Thomas Tauber-Marshall Gerrit-Reviewer: Tim Armstrong Gerrit-Comment-Date: Wed, 13 Nov 2019 01:55:05 + Gerrit-HasComments: Yes
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Impala Public Jenkins has posted comments on this change. ( http://gerrit.cloudera.org:8080/14668 ) Change subject: IMPALA-9128: part 2: dump traces for slow RPCs .. Patch Set 5: Build started: https://jenkins.impala.io/job/gerrit-verify-dryrun/5204/ DRY_RUN=true -- To view, visit http://gerrit.cloudera.org:8080/14668 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: Impala-ASF Gerrit-Branch: master Gerrit-MessageType: comment Gerrit-Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947 Gerrit-Change-Number: 14668 Gerrit-PatchSet: 5 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Impala Public Jenkins Gerrit-Reviewer: Lars Volker Gerrit-Reviewer: Thomas Tauber-Marshall Gerrit-Comment-Date: Tue, 12 Nov 2019 22:19:06 + Gerrit-HasComments: No
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Thomas Tauber-Marshall has posted comments on this change. ( http://gerrit.cloudera.org:8080/14668 ) Change subject: IMPALA-9128: part 2: dump traces for slow RPCs .. Patch Set 5: Code-Review+2 (1 comment) http://gerrit.cloudera.org:8080/#/c/14668/5//COMMIT_MSG Commit Message: http://gerrit.cloudera.org:8080/#/c/14668/5//COMMIT_MSG@38 PS5, Line 38: * basic perf testing Is tracing on by default? I assume the perf impact is negligible? -- To view, visit http://gerrit.cloudera.org:8080/14668 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: Impala-ASF Gerrit-Branch: master Gerrit-MessageType: comment Gerrit-Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947 Gerrit-Change-Number: 14668 Gerrit-PatchSet: 5 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Impala Public Jenkins Gerrit-Reviewer: Lars Volker Gerrit-Reviewer: Thomas Tauber-Marshall Gerrit-Comment-Date: Tue, 12 Nov 2019 20:02:35 + Gerrit-HasComments: Yes
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Impala Public Jenkins has posted comments on this change. ( http://gerrit.cloudera.org:8080/14668 ) Change subject: IMPALA-9128: part 2: dump traces for slow RPCs .. Patch Set 4: Build Successful https://jenkins.impala.io/job/gerrit-code-review-checks/5007/ : Initial code review checks passed. Use gerrit-verify-dryrun-external or gerrit-verify-dryrun to run full precommit tests. -- To view, visit http://gerrit.cloudera.org:8080/14668 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: Impala-ASF Gerrit-Branch: master Gerrit-MessageType: comment Gerrit-Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947 Gerrit-Change-Number: 14668 Gerrit-PatchSet: 4 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Impala Public Jenkins Gerrit-Reviewer: Lars Volker Gerrit-Reviewer: Thomas Tauber-Marshall Gerrit-Comment-Date: Tue, 12 Nov 2019 18:22:37 + Gerrit-HasComments: No
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Hello Thomas Tauber-Marshall, Lars Volker, Impala Public Jenkins,
I'd like you to reexamine a change. Please visit
http://gerrit.cloudera.org:8080/14668
to look at the new patch set (#5).
Change subject: IMPALA-9128: part 2: dump traces for slow RPCs
..
IMPALA-9128: part 2: dump traces for slow RPCs
This adds trace events for data stream RPCs and
dumps them when they take longer than
--impala_slow_rpc_threshold_ms.
I needed to modify the KRPC code to do this because it
currently only dumps traces for RPCs with deadlines.
I plan to add some version of this upstream in Kudu
so that we don't diverge our KRPC implementation.
Example output from test_exchange_small_buffer:
I 08:38:53.732910 26509 rpcz_store.cc:265] Call
impala.DataStreamService.TransmitData from 127.0.0.1:42434 (request call id 43)
took 7799ms. Request Metrics: {}
I 08:38:53.732928 26509 rpcz_store.cc:269] Trace:
08:38:45.933412 (+ 0us) impala-service-pool.cc:167] Inserting onto
call queue
08:38:45.933449 (+37us) impala-service-pool.cc:254] Handling call
08:38:45.933470 (+21us) krpc-data-stream-mgr.cc:227] Added early sender
08:38:47.906542 (+1973072us) krpc-data-stream-recvr.cc:327] Enqueuing
deferred RPC
08:38:53.732858 (+5826316us) krpc-data-stream-recvr.cc:506] Processing
deferred RPC
08:38:53.732860 (+ 2us) krpc-data-stream-recvr.cc:399] Deserializing
batch
08:38:53.732888 (+28us) krpc-data-stream-recvr.cc:426] Enqueuing
deserialized batch
08:38:53.732895 (+ 7us) inbound_call.cc:162] Queueing success response
Disabled +-clang-diagnostic-gnu-zero-variadic-macro-arguments because it
had false positives on the TRACE_TO invocations.
Testing:
* Ran exhaustive and ASAN tests
TODO:
* stress testing
* basic perf testing
Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947
---
M .clang-tidy
M be/src/kudu/rpc/rpcz_store.cc
M be/src/runtime/krpc-data-stream-mgr.cc
M be/src/runtime/krpc-data-stream-recvr.cc
M tests/custom_cluster/test_exchange_deferred_batches.py
M tests/custom_cluster/test_exchange_delays.py
6 files changed, 43 insertions(+), 10 deletions(-)
git pull ssh://gerrit.cloudera.org:29418/Impala-ASF refs/changes/68/14668/5
--
To view, visit http://gerrit.cloudera.org:8080/14668
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings
Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: newpatchset
Gerrit-Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947
Gerrit-Change-Number: 14668
Gerrit-PatchSet: 5
Gerrit-Owner: Tim Armstrong
Gerrit-Reviewer: Impala Public Jenkins
Gerrit-Reviewer: Lars Volker
Gerrit-Reviewer: Thomas Tauber-Marshall
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Hello Thomas Tauber-Marshall, Lars Volker, Impala Public Jenkins,
I'd like you to reexamine a change. Please visit
http://gerrit.cloudera.org:8080/14668
to look at the new patch set (#4).
Change subject: IMPALA-9128: part 2: dump traces for slow RPCs
..
IMPALA-9128: part 2: dump traces for slow RPCs
This adds trace events for data stream RPCs and
dumps them when they take longer than
--impala_slow_rpc_threshold_ms.
I needed to modify the KRPC code to do this because it
currently only dumps traces for RPCs with deadlines.
I plan to add some version of this upstream in Kudu
so that we don't diverge our KRPC implementation.
Example output from test_exchange_small_buffer:
I 08:38:53.732910 26509 rpcz_store.cc:265] Call
impala.DataStreamService.TransmitData from 127.0.0.1:42434 (request call id 43)
took 7799ms. Request Metrics: {}
I 08:38:53.732928 26509 rpcz_store.cc:269] Trace:
08:38:45.933412 (+ 0us) impala-service-pool.cc:167] Inserting onto
call queue
08:38:45.933449 (+37us) impala-service-pool.cc:254] Handling call
08:38:45.933470 (+21us) krpc-data-stream-mgr.cc:227] Added early sender
08:38:47.906542 (+1973072us) krpc-data-stream-recvr.cc:327] Enqueuing
deferred RPC
08:38:53.732858 (+5826316us) krpc-data-stream-recvr.cc:506] Processing
deferred RPC
08:38:53.732860 (+ 2us) krpc-data-stream-recvr.cc:399] Deserializing
batch
08:38:53.732888 (+28us) krpc-data-stream-recvr.cc:426] Enqueuing
deserialized batch
08:38:53.732895 (+ 7us) inbound_call.cc:162] Queueing success response
Testing:
* Ran exhaustive and ASAN tests
TODO:
* stress testing
* basic perf testing
Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947
---
M .clang-tidy
M be/src/kudu/rpc/rpcz_store.cc
M be/src/runtime/krpc-data-stream-mgr.cc
M be/src/runtime/krpc-data-stream-recvr.cc
M tests/custom_cluster/test_exchange_deferred_batches.py
M tests/custom_cluster/test_exchange_delays.py
6 files changed, 43 insertions(+), 10 deletions(-)
git pull ssh://gerrit.cloudera.org:29418/Impala-ASF refs/changes/68/14668/4
--
To view, visit http://gerrit.cloudera.org:8080/14668
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings
Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: newpatchset
Gerrit-Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947
Gerrit-Change-Number: 14668
Gerrit-PatchSet: 4
Gerrit-Owner: Tim Armstrong
Gerrit-Reviewer: Impala Public Jenkins
Gerrit-Reviewer: Lars Volker
Gerrit-Reviewer: Thomas Tauber-Marshall
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Impala Public Jenkins has posted comments on this change. ( http://gerrit.cloudera.org:8080/14668 ) Change subject: IMPALA-9128: part 2: dump traces for slow RPCs .. Patch Set 3: Build Failed https://jenkins.impala.io/job/gerrit-code-review-checks/5005/ : Initial code review checks failed. See linked job for details on the failure. -- To view, visit http://gerrit.cloudera.org:8080/14668 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: Impala-ASF Gerrit-Branch: master Gerrit-MessageType: comment Gerrit-Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947 Gerrit-Change-Number: 14668 Gerrit-PatchSet: 3 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Impala Public Jenkins Gerrit-Reviewer: Lars Volker Gerrit-Reviewer: Thomas Tauber-Marshall Gerrit-Comment-Date: Tue, 12 Nov 2019 17:13:19 + Gerrit-HasComments: No
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Tim Armstrong has uploaded a new patch set (#3). (
http://gerrit.cloudera.org:8080/14668 )
Change subject: IMPALA-9128: part 2: dump traces for slow RPCs
..
IMPALA-9128: part 2: dump traces for slow RPCs
This adds trace events for data stream RPCs and
dumps them when they take longer than
--impala_slow_rpc_threshold_ms.
I needed to modify the KRPC code to do this because it
currently only dumps traces for RPCs with deadlines.
I plan to add some version of this upstream in Kudu
so that we don't diverge our KRPC implementation.
Example output from test_exchange_small_buffer:
I 08:38:53.732910 26509 rpcz_store.cc:265] Call
impala.DataStreamService.TransmitData from 127.0.0.1:42434 (request call id 43)
took 7799ms. Request Metrics: {}
I 08:38:53.732928 26509 rpcz_store.cc:269] Trace:
08:38:45.933412 (+ 0us) impala-service-pool.cc:167] Inserting onto
call queue
08:38:45.933449 (+37us) impala-service-pool.cc:254] Handling call
08:38:45.933470 (+21us) krpc-data-stream-mgr.cc:227] Added early sender
08:38:47.906542 (+1973072us) krpc-data-stream-recvr.cc:327] Enqueuing
deferred RPC
08:38:53.732858 (+5826316us) krpc-data-stream-recvr.cc:506] Processing
deferred RPC
08:38:53.732860 (+ 2us) krpc-data-stream-recvr.cc:399] Deserializing
batch
08:38:53.732888 (+28us) krpc-data-stream-recvr.cc:426] Enqueuing
deserialized batch
08:38:53.732895 (+ 7us) inbound_call.cc:162] Queueing success response
Testing:
* Ran exhaustive and ASAN tests
TODO:
* stress testing
* basic perf testing
Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947
---
M be/src/kudu/rpc/rpcz_store.cc
M be/src/runtime/krpc-data-stream-mgr.cc
M be/src/runtime/krpc-data-stream-recvr.cc
M tests/custom_cluster/test_exchange_deferred_batches.py
M tests/custom_cluster/test_exchange_delays.py
5 files changed, 42 insertions(+), 10 deletions(-)
git pull ssh://gerrit.cloudera.org:29418/Impala-ASF refs/changes/68/14668/3
--
To view, visit http://gerrit.cloudera.org:8080/14668
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings
Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: newpatchset
Gerrit-Change-Id: Ic7af4b45c43ec731d742d3696112c5f800849947
Gerrit-Change-Number: 14668
Gerrit-PatchSet: 3
Gerrit-Owner: Tim Armstrong
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Tim Armstrong has abandoned this change. ( http://gerrit.cloudera.org:8080/14669 ) Change subject: IMPALA-9128: part 2: dump traces for slow RPCs .. Abandoned Didn't mean to publish -- To view, visit http://gerrit.cloudera.org:8080/14669 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: Impala-ASF Gerrit-Branch: master Gerrit-MessageType: abandon Gerrit-Change-Id: Ia53da1ffe2d07906d44cef6c7d0a80ef130c7724 Gerrit-Change-Number: 14669 Gerrit-PatchSet: 1 Gerrit-Owner: Tim Armstrong Gerrit-Reviewer: Impala Public Jenkins
[Impala-ASF-CR] IMPALA-9128: part 2: dump traces for slow RPCs
Tim Armstrong has uploaded this change for review. ( http://gerrit.cloudera.org:8080/14669 Change subject: IMPALA-9128: part 2: dump traces for slow RPCs .. IMPALA-9128: part 2: dump traces for slow RPCs This adds trace events for data stream RPCs and dumps them when they take longer than --impala_slow_rpc_threshold_ms. I needed to modify the KRPC code to do this because it currently only dumps traces for RPCs with deadlines. I plan to add some version of this upstream in Kudu so that we don't diverge our KRPC implementation. Change-Id: Ia53da1ffe2d07906d44cef6c7d0a80ef130c7724 --- M be/src/kudu/rpc/rpcz_store.cc M be/src/runtime/krpc-data-stream-mgr.cc M be/src/runtime/krpc-data-stream-recvr.cc M be/src/runtime/krpc-data-stream-sender.cc 4 files changed, 36 insertions(+), 12 deletions(-) git pull ssh://gerrit.cloudera.org:29418/Impala-ASF refs/changes/69/14669/1 -- To view, visit http://gerrit.cloudera.org:8080/14669 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-Project: Impala-ASF Gerrit-Branch: master Gerrit-MessageType: newchange Gerrit-Change-Id: Ia53da1ffe2d07906d44cef6c7d0a80ef130c7724 Gerrit-Change-Number: 14669 Gerrit-PatchSet: 1 Gerrit-Owner: Tim Armstrong
