You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hbase.apache.org by "Xiao Liu (Jira)" <ji...@apache.org> on 2025/12/14 16:29:00 UTC
[jira] [Created] (HBASE-29777) Slow and Large Response RPC StartTime in SlowLog Operation Details page is incorrect
Xiao Liu created HBASE-29777:
--------------------------------
Summary: Slow and Large Response RPC StartTime in SlowLog Operation Details page is incorrect
Key: HBASE-29777
URL: https://issues.apache.org/jira/browse/HBASE-29777
Project: HBase
Issue Type: Bug
Affects Versions: 2.5.13, 2.6.4, 3.0.0-beta-1
Reporter: Xiao Liu
Assignee: Xiao Liu
Fix For: 2.7.0, 3.0.0-beta-2, 2.6.5, 2.5.14
Attachments: large.png, slow.png
When the slowlog feature is enabled, we observe a discrepancy between the start times displayed for SlowRPC and Large Response RPC on the RegionServer UI page and the actual times.
We can pull the latest code and compile it, then add the following configuration, and start the cluster, maybe after a scan meta table operation, then we can see that there's a discrepancy between the start time in the log and the displayed time, which feels quite odd.
{code:xml}
<property>
<name>hbase.regionserver.slowlog.systable.enabled</name>
<value>true</value>
</property>
<property>
<name>hbase.regionserver.slowlog.buffer.enabled</name>
<value>true</value>
</property>
<property>
<name>hbase.ipc.warn.response.time</name>
<value>1</value>
</property>
<property>
<name>hbase.ipc.warn.response.size</name>
<value>1</value>
</property>
{code}
{code:java}
2025-12-15T00:03:43,472 WARN [RpcServer.priority.RWQ.Fifo.read.handler=6,queue=4,port=16020] ipc.RpcServer: (responseTooLarge & TooSlow): {"call":"Scan(org.apache.hadoop.hbase.shaded.protobuf.generated.ClientProtos$ScanRequest)","starttimems":"1765728223468","responsesize":"935","method":"Scan","param":"region { type: REGION_NAME value: \"hbase:meta,,1\" } scan { column { family: \"info\" } attribute { name: \"_isolationlevel_\" value: \"\\000\" } start_row: \" <TRUNCATED>","processingtimems":3,"blockbytesscanned":"4136","fsreadtime":"0","client":"192.168.1.44:57802","queuetimems":0,"class":"HRegionServer"}
2025-12-15T00:03:43,472 WARN [RpcServer.priority.RWQ.Fifo.read.handler=11,queue=2,port=16020] ipc.RpcServer: (responseTooLarge & TooSlow): {"call":"Scan(org.apache.hadoop.hbase.shaded.protobuf.generated.ClientProtos$ScanRequest)","starttimems":"1765728223469","responsesize":"935","method":"Scan","param":"region { type: REGION_NAME value: \"hbase:meta,,1\" } scan { column { family: \"info\" } attribute { name: \"_isolationlevel_\" value: \"\\000\" } start_row: \" <TRUNCATED>","processingtimems":2,"blockbytesscanned":"4136","fsreadtime":"0","client":"192.168.1.44:57802","queuetimems":1,"class":"HRegionServer"}
2025-12-15T00:03:43,472 WARN [RpcServer.priority.RWQ.Fifo.read.handler=5,queue=3,port=16020] ipc.RpcServer: (responseTooLarge & TooSlow): {"call":"Scan(org.apache.hadoop.hbase.shaded.protobuf.generated.ClientProtos$ScanRequest)","starttimems":"1765728223469","responsesize":"935","method":"Scan","param":"region { type: REGION_NAME value: \"hbase:meta,,1\" } scan { column { family: \"info\" } attribute { name: \"_isolationlevel_\" value: \"\\000\" } start_row: \" <TRUNCATED>","processingtimems":2,"blockbytesscanned":"4136","fsreadtime":"0","client":"192.168.1.44:57802","queuetimems":1,"class":"HRegionServer"}
2025-12-15T00:03:43,472 WARN [RpcServer.priority.RWQ.Fifo.read.handler=16,queue=7,port=16020] ipc.RpcServer: (responseTooLarge & TooSlow): {"call":"Scan(org.apache.hadoop.hbase.shaded.protobuf.generated.ClientProtos$ScanRequest)","starttimems":"1765728223468","responsesize":"935","method":"Scan","param":"region { type: REGION_NAME value: \"hbase:meta,,1\" } scan { column { family: \"info\" } attribute { name: \"_isolationlevel_\" value: \"\\000\" } start_row: \" <TRUNCATED>","processingtimems":3,"blockbytesscanned":"4136","fsreadtime":"0","client":"192.168.1.44:57802","queuetimems":0,"class":"HRegionServer"}
2025-12-15T00:03:43,472 WARN [RpcServer.priority.RWQ.Fifo.read.handler=4,queue=2,port=16020] ipc.RpcServer: (responseTooLarge & TooSlow): {"call":"Scan(org.apache.hadoop.hbase.shaded.protobuf.generated.ClientProtos$ScanRequest)","starttimems":"1765728223468","responsesize":"935","method":"Scan","param":"region { type: REGION_NAME value: \"hbase:meta,,1\" } scan { column { family: \"info\" } attribute { name: \"_isolationlevel_\" value: \"\\000\" } start_row: \" <TRUNCATED>","processingtimems":3,"blockbytesscanned":"4136","fsreadtime":"0","client":"192.168.1.44:57802","queuetimems":0,"class":"HRegionServer"}
2025-12-15T00:03:43,472 WARN [RpcServer.priority.RWQ.Fifo.read.handler=12,queue=3,port=16020] ipc.RpcServer: (responseTooLarge & TooSlow): {"call":"Scan(org.apache.hadoop.hbase.shaded.protobuf.generated.ClientProtos$ScanRequest)","starttimems":"1765728223469","responsesize":"935","method":"Scan","param":"region { type: REGION_NAME value: \"hbase:meta,,1\" } scan { column { family: \"info\" } attribute { name: \"_isolationlevel_\" value: \"\\000\" } start_row: \" <TRUNCATED>","processingtimems":2,"blockbytesscanned":"4136","fsreadtime":"0","client":"192.168.1.44:57802","queuetimems":0,"class":"HRegionServer"}
2025-12-15T00:03:43,472 WARN [RpcServer.priority.RWQ.Fifo.read.handler=13,queue=4,port=16020] ipc.RpcServer: (responseTooLarge & TooSlow): {"call":"Scan(org.apache.hadoop.hbase.shaded.protobuf.generated.ClientProtos$ScanRequest)","starttimems":"1765728223468","responsesize":"935","method":"Scan","param":"region { type: REGION_NAME value: \"hbase:meta,,1\" } scan { column { family: \"info\" } attribute { name: \"_isolationlevel_\" value: \"\\000\" } start_row: \" <TRUNCATED>","processingtimems":3,"blockbytesscanned":"4136","fsreadtime":"0","client":"192.168.1.44:57802","queuetimems":0,"class":"HRegionServer"}
2025-12-15T00:03:43,473 WARN [RpcServer.priority.RWQ.Fifo.read.handler=6,queue=4,port=16020] ipc.RpcServer: (responseTooLarge): {"call":"Scan(org.apache.hadoop.hbase.shaded.protobuf.generated.ClientProtos$ScanRequest)","starttimems":"1765728223473","responsesize":"935","method":"Scan","param":"region { type: REGION_NAME value: \"hbase:meta,,1\" } scan { column { family: \"info\" } attribute { name: \"_isolationlevel_\" value: \"\\000\" } start_row: \" <TRUNCATED>","processingtimems":0,"blockbytesscanned":"4136","fsreadtime":"0","client":"192.168.1.44:57802","queuetimems":5,"class":"HRegionServer"}
2025-12-15T00:03:43,491 INFO [RpcServer.default.FPBQ.Fifo.handler=29,queue=2,port=16020] regionserver.HRegion: writing data to region hbase:slowlog,,1765727627468.64ed28e9c8e5a433df1d54662ff9e06f. with WAL disabled. Data may be lost in the event of a crash.
{code}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)