You are viewing a plain text version of this content. The canonical link for it is here.
Posted to common-issues@hadoop.apache.org by "Todd Lipcon (JIRA)" <ji...@apache.org> on 2012/07/26 02:47:34 UTC

[jira] [Updated] (HADOOP-8624) ProtobufRpcEngine should log all RPCs if TRACE logging is enabled

     [ https://issues.apache.org/jira/browse/HADOOP-8624?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Todd Lipcon updated HADOOP-8624:
--------------------------------

    Attachment: hadoop-8624.txt

This patch implements the above for the client side. I didn't instrument the server side with extra tracing as of yet, but we could do that separately. In the context of unit tests where I"m using this, having one side of the connection is enough to be very useful.

It doesn't include new tests, but here is some example output:

{code}
2012-07-25 17:38:10,313 TRACE ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(197)) - 46: Call -> null@/127.0.0.1:48275: getJournalState {jid { identifier: "testQuorumJournalManager" }}
2012-07-25 17:38:10,313 TRACE ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(197)) - 45: Call -> null@/127.0.0.1:46462: getJournalState {jid { identifier: "testQuorumJournalManager" }}
2012-07-25 17:38:10,313 TRACE ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(197)) - 47: Call -> null@/127.0.0.1:60394: getJournalState {jid { identifier: "testQuorumJournalManager" }}
2012-07-25 17:38:10,354 INFO  server.JournalNode (JournalNode.java:getOrCreateJournal(73)) - Initializing journal in directory build/test/data/dfs/journalnode-0/testQuorumJournalManager
2012-07-25 17:38:10,354 INFO  server.JournalNode (JournalNode.java:getOrCreateJournal(73)) - Initializing journal in directory build/test/data/dfs/journalnode-1/testQuorumJournalManager
2012-07-25 17:38:10,354 INFO  server.JournalNode (JournalNode.java:getOrCreateJournal(73)) - Initializing journal in directory build/test/data/dfs/journalnode-2/testQuorumJournalManager
2012-07-25 17:38:10,361 INFO  common.Storage (Storage.java:analyzeStorage(429)) - Storage directory /home/todd/git/hadoop-common/hadoop-hdfs-project/hadoop-hdfs/build/test/data/dfs/journalnode-0/testQuorumJournalManager does not exist.
2012-07-25 17:38:10,361 INFO  common.Storage (Storage.java:analyzeStorage(429)) - Storage directory /home/todd/git/hadoop-common/hadoop-hdfs-project/hadoop-hdfs/build/test/data/dfs/journalnode-1/testQuorumJournalManager does not exist.
2012-07-25 17:38:10,361 INFO  common.Storage (Storage.java:analyzeStorage(429)) - Storage directory /home/todd/git/hadoop-common/hadoop-hdfs-project/hadoop-hdfs/build/test/data/dfs/journalnode-2/testQuorumJournalManager does not exist.
2012-07-25 17:38:10,363 DEBUG ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(217)) - Call: getJournalState took 240ms
2012-07-25 17:38:10,363 DEBUG ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(217)) - Call: getJournalState took 240ms
2012-07-25 17:38:10,363 DEBUG ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(217)) - Call: getJournalState took 240ms
2012-07-25 17:38:10,364 TRACE ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(232)) - 47: Response <- null@/127.0.0.1:60394: getJournalState {lastPromisedEpoch: 0 httpPort: 60071}
2012-07-25 17:38:10,364 TRACE ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(232)) - 45: Response <- null@/127.0.0.1:46462: getJournalState {lastPromisedEpoch: 0 httpPort: 48186}
2012-07-25 17:38:10,364 TRACE ipc.ProtobufRpcEngine (ProtobufRpcEngine.java:invoke(232)) - 46: Response <- null@/127.0.0.1:48275: getJournalState {lastPromisedEpoch: 0 httpPort: 50970}
{code}

The logs make it very clear what's going on under the hood, which helped me debug an issue.
                
> ProtobufRpcEngine should log all RPCs if TRACE logging is enabled
> -----------------------------------------------------------------
>
>                 Key: HADOOP-8624
>                 URL: https://issues.apache.org/jira/browse/HADOOP-8624
>             Project: Hadoop Common
>          Issue Type: Improvement
>          Components: ipc
>    Affects Versions: 3.0.0, 2.2.0-alpha
>            Reporter: Todd Lipcon
>            Assignee: Todd Lipcon
>            Priority: Minor
>         Attachments: hadoop-8624.txt
>
>
> Since all RPC requests/responses are now ProtoBufs, it's easy to add a TRACE level logging output for ProtobufRpcEngine that actually shows the full content of all calls. This is very handy especially when writing/debugging unit tests, but might also be useful to enable at runtime for short periods of time to debug certain production issues.

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira