-
Notifications
You must be signed in to change notification settings - Fork 8.9k
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
HADOOP-18082.Add debug log when RPC#Reader gets a Call. #3891
Conversation
💔 -1 overall
This message was automatically generated. |
Here are some failed unit tests: It doesn't look like it has much to do with what I'm submitting. |
@@ -3046,6 +3046,8 @@ private void internalQueueCall(Call call, boolean blocking) | |||
} else { | |||
callQueue.add(call); | |||
} | |||
|
|||
LOG.debug("{} has entered the CallQueue and is waiting to be processed.", call); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
If only callId
is output, there may be too little useful information. What do you think?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Thanks @tomscut for the comment and review.
The detailed log here is this:
2022-01-18 16:37:56,653 DEBUG org.apache.hadoop.ipc.Server: Call#75 Retry#0 org.apache.hadoop.hdfs.protocol.ClientProtocol.getFileInfo from xxxx.xxxx.xxxx.xxxx:port has entered the CallQueue and is waiting to be processed. 2022-01-18 16:37:56,654 DEBUG org.apache.hadoop.ipc.Server: Call#76 Retry#0 org.apache.hadoop.hdfs.protocol.ClientProtocol.getFileInfo from xxxx.xxxx.xxxx.xxxx:port has entered the CallQueue and is waiting to be processed.
When the Call is processed by Hanler, the detailed log is as follows:
2022-01-18 16:37:59,725 [5178363759] - WARN [IPC Server handler 126 on 8025:Server@494] - Slow RPC : getFileInfo took 509 milliseconds to process from client Call#76 Retry#0 org.apache.hadoop.hdfs.protocol.ClientProtocol.getFileInfo from xxxx.xxxx.xxxx.xxxx:port
In my opinion, the Calls recorded in these two places should be consistent.
@tomscut , do you have any good suggestions.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'm sorry I made a mistake. The output here is not only callId
. And I think it is ok.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The change to add a DEBUG log seems good, but how about this line instead?
LOG.debug("Call has entered the CallQueue and is waiting to be processed. Call details: {}", call);
Usually we tend to read object's string presentation at the end to not mix up with the log statement, e.g RpcCall's toString() has word "from" and perhaps it becomes bit difficult to read the whole statement at the first sight, but if put at the end of the statement, we know that now we are only looking at RpcCall details:
@Override
public String toString() {
return super.toString() + " " + rpcRequest + " from " + connection;
}
@@ -3046,6 +3046,8 @@ private void internalQueueCall(Call call, boolean blocking) | |||
} else { | |||
callQueue.add(call); | |||
} | |||
|
|||
LOG.debug("{} has entered the CallQueue and is waiting to be processed.", call); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'm sorry I made a mistake. The output here is not only callId
. And I think it is ok.
Thanks @tomscut . |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Left a minor comment
@@ -3046,6 +3046,8 @@ private void internalQueueCall(Call call, boolean blocking) | |||
} else { | |||
callQueue.add(call); | |||
} | |||
|
|||
LOG.debug("{} has entered the CallQueue and is waiting to be processed.", call); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The change to add a DEBUG log seems good, but how about this line instead?
LOG.debug("Call has entered the CallQueue and is waiting to be processed. Call details: {}", call);
Usually we tend to read object's string presentation at the end to not mix up with the log statement, e.g RpcCall's toString() has word "from" and perhaps it becomes bit difficult to read the whole statement at the first sight, but if put at the end of the statement, we know that now we are only looking at RpcCall details:
@Override
public String toString() {
return super.toString() + " " + rpcRequest + " from " + connection;
}
d3cc513
to
05f7c9e
Compare
05f7c9e
to
8554c43
Compare
💔 -1 overall
This message was automatically generated. |
💔 -1 overall
This message was automatically generated. |
Latest change looks good. +1(non-binding) |
Thanks @virajjasani . |
💔 -1 overall
This message was automatically generated. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
LGTM
Thanks @ayushtkn . |
Hi @ayushtkn , can this pr be merged into trunk branch or other main branch? |
Merged. Thanx Everyone!!! |
…. Contributed by JiangHua Zhu." Exposes a Race Condition. Which leads to test failures in YARN. (HADOOP-18143) This reverts commit 2025243.
…. Contributed by JiangHua Zhu.
Description of PR
Log some information from the moment Call enters the RPC inside, which will help us understand more about Call.
The records here should be in the form of logs. The priority of the logs should not be too high, and debugging is the best.
Details: HADOOP-18082
How was this patch tested?
Corresponding to the test, the pressure is not large.