[
https://issues.apache.org/jira/browse/HBASE-16972?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15631494#comment-15631494
]
Yu Li commented on HBASE-16972:
-------------------------------
bq. What's the total change in log message appearance with HBASE-16033 and this
in place
Before HBASE-16033 for responseTooSlow logging we only have
{noformat}
2016-06-08 12:18:04,363 WARN
[B.defaultRpcServer.handler=127,queue=10,port=16020]
ipc.RpcServer: (responseTooSlow):
{"processingtimems":13125,"call":"Multi(org.apache.hadoop.hbase.protobuf.generated.ClientProtos$MultiRequest)",
"client":"11.251.158.22:36331","starttimems":1465359471238,"queuetimems":1540116,
"class":"HRegionServer","responsesize":17,"method":"Multi"}
{noformat}
And after we will have
{noformat}
2016-06-15 13:43:33,763 WARN [B.defaultRpcServer.handler=4,queue=4,port=16020]
ipc.RpcServer:
(responseTooSlow):
{"processingtimems":10776,"call":"Multi(org.apache.hadoop.hbase.protobuf.generated.ClientProtos$MultiRequest)",
"client":"11.251.157.88:56954","param":"region=
msgtable,0535:,1465226523303.930e1623ba37566bd44dfca3bfcdd43e.,
for 1 actions and 1st row
key=0535:20160615134322:533698458535","starttimems":1465969402987,"queuetimems":0,
"class":"HRegionServer","responsesize":8,"method":"Multi"}
{noformat}
So we are not deleting any existing message from log but add more details for
easier debugging.
And after the patch here will have additional "scandetails" which includes
table/region information, and no message removed still.
Honestly, I don't think the responseTooSlow log useful before HBASE-16033, I
mean what can we do w/o knowing which table/region the slow request is
against...
[~busbey] let me know your thoughts sir. Thanks.
> Log more details for Scan#next request when responseTooSlow
> -----------------------------------------------------------
>
> Key: HBASE-16972
> URL: https://issues.apache.org/jira/browse/HBASE-16972
> Project: HBase
> Issue Type: Improvement
> Components: Operability
> Reporter: Yu Li
> Assignee: Yu Li
> Attachments: HBASE-16972.patch, HBASE-16972.v2.patch,
> HBASE-16972.v3.patch
>
>
> Currently for if responseTooSlow happens on the scan.next call, we will get
> warn log like below:
> {noformat}
> 2016-10-31 11:43:23,430 WARN
> [RpcServer.FifoWFPBQ.priority.handler=5,queue=1,port=60193]
> ipc.RpcServer(2574):
> (responseTooSlow):
> {"call":"Scan(org.apache.hadoop.hbase.shaded.protobuf.generated.ClientProtos$ScanRequest)",
> "starttimems":1477885403428,"responsesize":52,"method":"Scan","param":"scanner_id:
> 11 number_of_rows: 2147483647
> close_scanner: false next_call_seq: 0 client_handles_partials: true
> client_handles_heartbeats: true
> track_scan_metrics: false renew:
> false","processingtimems":2,"client":"127.0.0.1:60254","queuetimems":0,"class":"HMaster"}
> {noformat}
> From which we only have a {{scanner_id}} and impossible to know what exactly
> this scan is about, like against which region of which table.
> After this JIRA, we will improve the message to something like below (notice
> the last line):
> {noformat}
> 2016-10-31 11:43:23,430 WARN
> [RpcServer.FifoWFPBQ.priority.handler=5,queue=1,port=60193]
> ipc.RpcServer(2574):
> (responseTooSlow):
> {"call":"Scan(org.apache.hadoop.hbase.shaded.protobuf.generated.ClientProtos$ScanRequest)",
> "starttimems":1477885403428,"responsesize":52,"method":"Scan","param":"scanner_id:
> 11 number_of_rows: 2147483647
> close_scanner: false next_call_seq: 0 client_handles_partials: true
> client_handles_heartbeats: true
> track_scan_metrics: false renew:
> false","processingtimems":2,"client":"127.0.0.1:60254","queuetimems":0,"class":"HMaster",
> "scandetails":"table: hbase:meta region: hbase:meta,,1.1588230740"}
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
