You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hbase.apache.org by "ASF GitHub Bot (Jira)" <ji...@apache.org> on 2025/12/14 16:30:00 UTC

[jira] [Updated] (HBASE-29777) Slow and Large Response RPC StartTime in SlowLog Operation Details page is incorrect

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

ASF GitHub Bot updated HBASE-29777:
-----------------------------------
    Labels: pull-request-available  (was: )

> 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: 3.0.0-beta-1, 2.6.4, 2.5.13
>            Reporter: Xiao Liu
>            Assignee: Xiao Liu
>            Priority: Major
>              Labels: pull-request-available
>             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)