hbase-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Andrew Purtell (JIRA)" <j...@apache.org>
Subject [jira] [Comment Edited] (HBASE-11295) Long running scan produces OutOfOrderScannerNextException
Date Thu, 08 Jan 2015 01:49:38 GMT

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

Andrew Purtell edited comment on HBASE-11295 at 1/8/15 1:49 AM:
----------------------------------------------------------------

Lars and I were tracing through the HBase client code today and spotted where in ScannerCallable#call
we curiously do not increment the next sequence ID to use (for a retry) until *after* we issue
a RPC and wait for a successful response. If for some reason the RPC times out on the client
- network issue perhaps - we leave call() without incrementing the sequence ID. The server
will not see the client side timeout before it has incremented the expected next sequence
ID. When the caller submits the retry we have a sequence mismatch.

Is the below correct (diff against 0.98)? I would be surprised because retries would never
have worked in the face of a client side network timeout. Maybe that is just not that common?
Although I suppose we could have this JIRA because it is common enough.

{code}
diff --git a/hbase-client/src/main/java/org/apache/hadoop/hbase/client/ScannerCallable.java
b/hbase-clie
index e329c3b..a9d3be0 100644
--- a/hbase-client/src/main/java/org/apache/hadoop/hbase/client/ScannerCallable.java
+++ b/hbase-client/src/main/java/org/apache/hadoop/hbase/client/ScannerCallable.java
@@ -170,8 +170,6 @@ public class ScannerCallable extends RegionServerCallable<Result[]>
{
           request = RequestConverter.buildScanRequest(scannerId, caching, false, nextCallSeq);
           ScanResponse response = null;
           try {
-            controller.setPriority(getTableName());
-            response = getStub().scan(controller, request);
             // Client and RS maintain a nextCallSeq number during the scan. Every next()
call
             // from client to server will increment this number in both sides. Client passes
this
             // number along with the request and at RS side both the incoming nextCallSeq
and its
@@ -179,9 +177,16 @@ public class ScannerCallable extends RegionServerCallable<Result[]>
{
             // should not happen. If at the server side fetching of next batch of data was
over,
             // there will be mismatch in the nextCallSeq number. Server will throw
             // OutOfOrderScannerNextException and then client will reopen the scanner with
startrow
-            // as the last successfully retrieved row.
-            // See HBASE-5974
+            // as the last successfully retrieved row. See HBASE-5974.
+
+            // Increment the call seq BEFORE network IO.
             nextCallSeq++;
+
+            // Now issue the RPC
+            controller.setPriority(getTableName());
+            response = getStub().scan(controller, request);
+
+            // Process results
             long timestamp = System.currentTimeMillis();
             // Results are returned via controller
             CellScanner cellScanner = controller.cellScanner();
{code}

[~lhofhansl]


was (Author: apurtell):
Lars and I were tracing through the HBase client code today and spotted where in ScannerCallable#call
we curiously do not increment the next sequence ID to use (for a retry) until *after* we issue
a RPC and wait for a successful response. If for some reason the RPC times out on the client
- network issue perhaps - we leave call() without incrementing the sequence ID. The server
will not see the client side timeout. The server will have incremented the expected next sequence
ID. When the caller submits the retry we have a sequence mismatch.

Is the below correct (diff against 0.98)? I would be surprised because retries would never
have worked in the face of a client side network timeout. Maybe that is just not that common?
Although I suppose we could have this JIRA because it is common enough.

{code}
diff --git a/hbase-client/src/main/java/org/apache/hadoop/hbase/client/ScannerCallable.java
b/hbase-clie
index e329c3b..a9d3be0 100644
--- a/hbase-client/src/main/java/org/apache/hadoop/hbase/client/ScannerCallable.java
+++ b/hbase-client/src/main/java/org/apache/hadoop/hbase/client/ScannerCallable.java
@@ -170,8 +170,6 @@ public class ScannerCallable extends RegionServerCallable<Result[]>
{
           request = RequestConverter.buildScanRequest(scannerId, caching, false, nextCallSeq);
           ScanResponse response = null;
           try {
-            controller.setPriority(getTableName());
-            response = getStub().scan(controller, request);
             // Client and RS maintain a nextCallSeq number during the scan. Every next()
call
             // from client to server will increment this number in both sides. Client passes
this
             // number along with the request and at RS side both the incoming nextCallSeq
and its
@@ -179,9 +177,16 @@ public class ScannerCallable extends RegionServerCallable<Result[]>
{
             // should not happen. If at the server side fetching of next batch of data was
over,
             // there will be mismatch in the nextCallSeq number. Server will throw
             // OutOfOrderScannerNextException and then client will reopen the scanner with
startrow
-            // as the last successfully retrieved row.
-            // See HBASE-5974
+            // as the last successfully retrieved row. See HBASE-5974.
+
+            // Increment the call seq BEFORE network IO.
             nextCallSeq++;
+
+            // Now issue the RPC
+            controller.setPriority(getTableName());
+            response = getStub().scan(controller, request);
+
+            // Process results
             long timestamp = System.currentTimeMillis();
             // Results are returned via controller
             CellScanner cellScanner = controller.cellScanner();
{code}

[~lhofhansl]

> Long running scan produces OutOfOrderScannerNextException
> ---------------------------------------------------------
>
>                 Key: HBASE-11295
>                 URL: https://issues.apache.org/jira/browse/HBASE-11295
>             Project: HBase
>          Issue Type: Bug
>          Components: regionserver
>    Affects Versions: 0.96.0
>            Reporter: Jeff Cunningham
>         Attachments: OutOfOrderScannerNextException.tar.gz
>
>
> Attached Files:
> HRegionServer.java - instramented from 0.96.1.1-cdh5.0.0
> HBaseLeaseTimeoutIT.java - reproducing JUnit 4 test
> WaitFilter.java - Scan filter (extends FilterBase) that overrides filterRowKey() to sleep
during invocation
> SpliceFilter.proto - Protobuf defintiion for WaitFilter.java
> OutOfOrderScann_InstramentedServer.log - instramented server log
> Steps.txt - this note
> Set up:
> In HBaseLeaseTimeoutIT, create a scan, set the given filter (which sleeps in overridden
filterRowKey() method) and set it on the scan, and scan the table.
> This is done in test client_0x0_server_150000x10().
> Here's what I'm seeing (see also attached log):
> A new request comes into server (ID 1940798815214593802 - RpcServer.handler=96) and a
RegionScanner is created for it, cached by ID, immediately looked up again and cached RegionScannerHolder's
nextCallSeq incremeted (now at 1).
> The RegionScan thread goes to sleep in WaitFilter#filterRowKey().
> A short (variable) period later, another request comes into the server (ID 8946109289649235722
- RpcServer.handler=98) and the same series of events happen to this request.
> At this point both RegionScanner threads are sleeping in WaitFilter.filterRowKey(). After
another period, the client retries another scan request which thinks its next_call_seq is
0.  However, HRegionServer's cached RegionScannerHolder thinks the matching RegionScanner's
nextCallSeq should be 1.



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message