Mailing-List: contact issues-help@hbase.apache.org; run by ezmlm
Precedence: bulk
Date: Thu, 8 Jan 2015 01:48:35 +0000 (UTC)
From: "Andrew Purtell (JIRA)" <jira@apache.org>
To: issues@hbase.apache.org
Message-ID: <JIRA.12718263.1401833974000.34292.1420681715207@Atlassian.JIRA>
In-Reply-To: <JIRA.12718263.1401833974000@Atlassian.JIRA>
References: <JIRA.12718263.1401833974000@Atlassian.JIRA>
 <JIRA.12718263.1401833974801@arcas>
Subject: [jira] [Commented] (HBASE-11295) Long running scan produces
 OutOfOrderScannerNextException
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: 7bit


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

Andrew Purtell commented on HBASE-11295:
----------------------------------------

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)