Wei-Chiu Chuang created HADOOP-15840:
----------------------------------------
Summary: Slow RPC logger too spammy
Key: HADOOP-15840
URL: https://issues.apache.org/jira/browse/HADOOP-15840
Project: Hadoop Common
Issue Type: Improvement
Affects Versions: 3.0.0-alpha1, 2.7.4, 2.8.0
Reporter: Wei-Chiu Chuang
HADOOP-12325 added a capability where "slow" RPCs are logged in NN log when
ipc.server.log.slow.rpc is enabled.
The "slow" RPCs are supposed to be those whose processing time is outside 3
standard deviation, and it supposed to account for 0.3% of total RPCs.
However, I found in practice, NN marks more than 1% of total RPCs as slow, and
I've seen RPCs whose processing time is 1ms declared slow too.
{noformat}
2018-10-08 01:48:33,203 WARN org.apache.hadoop.ipc.Server: Slow RPC :
sendHeartbeat took 1 milliseconds to process from client 10.17.199.16:56645
2018-10-08 01:48:33,219 WARN org.apache.hadoop.ipc.Server: Slow RPC :
sendHeartbeat took 1 milliseconds to process from client 10.17.190.44:36435
2018-10-08 01:48:33,308 WARN org.apache.hadoop.ipc.Server: Slow RPC :
sendHeartbeat took 1 milliseconds to process from client 10.17.190.43:56530
{noformat}
This is too many. 1% means NN spits hundreds slow RPCs per second on average in
NN log.
How about:
# use 4 stddev?
# use microsecond precision. Majority of RPCs takes less than 1 millisecond
anyway. It makes the stddev calculation imprecise. An RPC could be calculated
to spend 1 millisecond and be marked as "slow", since it starts from one
millisecond and ends in the next millisecond.
[~anu] any thoughts?
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
---------------------------------------------------------------------
To unsubscribe, e-mail: common-dev-unsubscr...@hadoop.apache.org
For additional commands, e-mail: common-dev-h...@hadoop.apache.org
