-
Notifications
You must be signed in to change notification settings - Fork 9.2k
HADOOP-18082.Add debug log when RPC#Reader gets a Call. #3891
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
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. |
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;
}
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 . |
virajjasani
left a comment
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
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. |
ayushtkn
left a comment
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.