Kiran Kumar Maturi created HBASE-29102:
------------------------------------------
Summary: Scan details missing for the last RPC call in
responseTooSlow or responseTooLarge
Key: HBASE-29102
URL: https://issues.apache.org/jira/browse/HBASE-29102
Project: HBase
Issue Type: Bug
Components: scan
Affects Versions: 2.5.11, 2.6.1
Reporter: Kiran Kumar Maturi
When a scan request is made that gets split into multiple rpc calls. For the
last rpc call the scandetails are removed from the scanners via the close
scanner call
{code:java}
if (!builder.getMoreResults() || !builder.getMoreResultsInRegion() ||
closeScanner) {
scannerClosed = true;
closeScanner(region, scanner, scannerName, rpcCall, false);
}
{code}
When we are trying to log the scan details that was slow or large these details
are missing
{code:java}
if (param instanceof ClientProtos.ScanRequest && rsRpcServices != null) {
ClientProtos.ScanRequest request = ((ClientProtos.ScanRequest) param);
String scanDetails;
if (request.hasScannerId()) {
long scannerId = request.getScannerId();
scanDetails = rsRpcServices.getScanDetailsWithId(scannerId)
} else {
scanDetails = rsRpcServices.getScanDetailsWithRequest(request);
}
if (scanDetails != null) {
responseInfo.put("scandetails", scanDetails);
}
}
{code}
scanDetails = rsRpcServices.getScanDetailsWithId(scannerId) are empty as the
scanner has been removed
We are using id attributeto track slow requests from client side when the last
call is slow we are not able to track it. I was able to reproduce this in a
unit test case
{code:java}
2025-01-28 13:14:49,671 WARN
[RpcServer.priority.RWQ.Fifo.read.handler=1,queue=1,port=41569]
ipc.RpcServer(556): (responseTooSlow):
{"call":"Get(org.apache.hadoop.hbase.shaded.protobuf.generated.ClientProtos$GetRequest)","starttimems":"1738050289670","responsesize":"55","method":"Get","param":"region=
hbase:meta,,1,
row=scanWithLimit","processingtimems":1,"client":"127.0.0.1:37716","queuetimems":0,"class":"MiniHBaseClusterRegionServer"}
2025-01-28 13:14:49,684 WARN
[RpcServer.default.FPBQ.Fifo.handler=2,queue=0,port=41569] ipc.RpcServer(556):
(responseTooSlow):
{"call":"Scan(org.apache.hadoop.hbase.shaded.protobuf.generated.ClientProtos$ScanRequest)","starttimems":"1738050289682","responsesize":"143","method":"Scan","param":"region
{ type: REGION_NAME value:
\"scanWithLimit,,1738050287249.a59c47d742d01e81f7280b849ca4af2a.\" } scan {
attribute { name: \"_operation.attributes.i
<TRUNCATED>","processingtimems":1,"client":"127.0.0.1:37716","queuetimems":1,"class":"MiniHBaseClusterRegionServer","scandetails":"table:
scanWithLimit region:
scanWithLimit,,1738050287249.a59c47d742d01e81f7280b849ca4af2a. operation_id:
last-row-scan"}
2025-01-28 13:14:49,690 WARN
[RpcServer.default.FPBQ.Fifo.handler=2,queue=0,port=41569] ipc.RpcServer(556):
(responseTooSlow):
{"call":"Scan(org.apache.hadoop.hbase.shaded.protobuf.generated.ClientProtos$ScanRequest)","starttimems":"1738050289688","responsesize":"137","method":"Scan","param":"scanner_id:
10141844372128268296 number_of_rows: 3 close_scanner: false next_call_seq: 0
client_handles_partials: true client_handles_heartbeats: true
<TRUNCATED>","processingtimems":1,"client":"127.0.0.1:37716","queuetimems":0,"class":"MiniHBaseClusterRegionServer","scandetails":"table:
scanWithLimit region:
scanWithLimit,,1738050287249.a59c47d742d01e81f7280b849ca4af2a. operation_id:
last-row-scan"}
2025-01-28 13:14:49,694 WARN
[RpcServer.default.FPBQ.Fifo.handler=2,queue=0,port=41569] ipc.RpcServer(556):
(responseTooSlow):
{"call":"Scan(org.apache.hadoop.hbase.shaded.protobuf.generated.ClientProtos$ScanRequest)","starttimems":"1738050289693","responsesize":"137","method":"Scan","param":"scanner_id:
10141844372128268296 number_of_rows: 3 close_scanner: false next_call_seq: 1
client_handles_partials: true client_handles_heartbeats: true
<TRUNCATED>","processingtimems":1,"client":"127.0.0.1:37716","queuetimems":1,"class":"MiniHBaseClusterRegionServer"}
{code}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)