You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hbase.apache.org by "Yu Li (JIRA)" <ji...@apache.org> on 2016/11/01 02:47:58 UTC

[jira] [Commented] (HBASE-16972) Log more details for Scan#next request when responseTooSlow

    [ https://issues.apache.org/jira/browse/HBASE-16972?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15624143#comment-15624143 ] 

Yu Li commented on HBASE-16972:
-------------------------------

Yes, for the first scan request ({{ScannerCallable#openScanner}} or {{ClientSmallScanner#rpcCall}}), it will include the region info natively. If it's too slow, we would see something like:
{noformat}
2016-11-01 10:34:33,697 WARN  [RpcServer.FifoWFPBQ.default.handler=4,queue=0,port=54492] ipc.RpcServer(2574):
(responseTooSlow): {"call":"Scan(org.apache.hadoop.hbase.shaded.protobuf.generated.ClientProtos$ScanRequest)",
"starttimems":1477967673696,"responsesize":8,"method":"Scan","param":"region { type: REGION_NAME value:
\"testReversedScanUnderMultiRegions,005,1477967671055.de8f4c6457fbd1712878d09073b5b6b9.\" } scan { start_row:
\"005\\377\\377\\377\\377" max_versions: 1 cache_blocks: true max_result_size: 2097152 reversed: true
caching: 2147483647 } number_of_rows: 0 close_scanner: false client_handles_partials: true client_handles_heartbeats:
true track_scan_metrics: false","processingtimems":3,"client":"127.0.0.1:54591","queuetimems":0,
"class":"MiniHBaseClusterRegionServer"}
{noformat}
And this is why we only improve the *w/ scanner_id* case here.

> 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
>
>
> 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)