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

Hadoop QA commented on HBASE-21503:
-----------------------------------

| (/) *{color:green}+1 overall{color}* |
\\
\\
|| Vote || Subsystem || Runtime || Comment ||
| {color:blue}0{color} | {color:blue} reexec {color} | {color:blue}  0m 
11s{color} | {color:blue} Docker mode activated. {color} |
|| || || || {color:brown} Prechecks {color} ||
| {color:green}+1{color} | {color:green} hbaseanti {color} | {color:green}  0m  
0s{color} | {color:green} Patch does not have any anti-patterns. {color} |
| {color:green}+1{color} | {color:green} @author {color} | {color:green}  0m  
0s{color} | {color:green} The patch does not contain any @author tags. {color} |
| {color:green}+1{color} | {color:green} test4tests {color} | {color:green}  0m 
 0s{color} | {color:green} The patch appears to include 1 new or modified test 
files. {color} |
|| || || || {color:brown} master Compile Tests {color} ||
| {color:green}+1{color} | {color:green} mvninstall {color} | {color:green}  3m 
57s{color} | {color:green} master passed {color} |
| {color:green}+1{color} | {color:green} compile {color} | {color:green}  1m 
47s{color} | {color:green} master passed {color} |
| {color:green}+1{color} | {color:green} checkstyle {color} | {color:green}  1m 
 5s{color} | {color:green} master passed {color} |
| {color:green}+1{color} | {color:green} shadedjars {color} | {color:green}  3m 
50s{color} | {color:green} branch has no errors when building our shaded 
downstream artifacts. {color} |
| {color:green}+1{color} | {color:green} findbugs {color} | {color:green}  1m 
55s{color} | {color:green} master passed {color} |
| {color:green}+1{color} | {color:green} javadoc {color} | {color:green}  0m 
30s{color} | {color:green} master passed {color} |
|| || || || {color:brown} Patch Compile Tests {color} ||
| {color:green}+1{color} | {color:green} mvninstall {color} | {color:green}  4m 
 2s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} compile {color} | {color:green}  1m 
43s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} javac {color} | {color:green}  1m 
43s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} checkstyle {color} | {color:green}  1m 
 7s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} whitespace {color} | {color:green}  0m 
 0s{color} | {color:green} The patch has no whitespace issues. {color} |
| {color:green}+1{color} | {color:green} shadedjars {color} | {color:green}  3m 
43s{color} | {color:green} patch has no errors when building our shaded 
downstream artifacts. {color} |
| {color:green}+1{color} | {color:green} hadoopcheck {color} | {color:green}  
8m 25s{color} | {color:green} Patch does not cause any errors with Hadoop 2.7.4 
or 3.0.0. {color} |
| {color:green}+1{color} | {color:green} findbugs {color} | {color:green}  2m  
7s{color} | {color:green} the patch passed {color} |
| {color:green}+1{color} | {color:green} javadoc {color} | {color:green}  0m 
30s{color} | {color:green} the patch passed {color} |
|| || || || {color:brown} Other Tests {color} ||
| {color:green}+1{color} | {color:green} unit {color} | {color:green}125m 
37s{color} | {color:green} hbase-server in the patch passed. {color} |
| {color:green}+1{color} | {color:green} asflicense {color} | {color:green}  0m 
28s{color} | {color:green} The patch does not generate ASF License warnings. 
{color} |
| {color:black}{color} | {color:black} {color} | {color:black}161m 26s{color} | 
{color:black} {color} |
\\
\\
|| Subsystem || Report/Notes ||
| Docker | Client=17.05.0-ce Server=17.05.0-ce Image:yetus/hbase:b002b0b |
| JIRA Issue | HBASE-21503 |
| JIRA Patch URL | 
https://issues.apache.org/jira/secure/attachment/12948963/HBASE-21503.patch |
| Optional Tests |  dupname  asflicense  javac  javadoc  unit  findbugs  
shadedjars  hadoopcheck  hbaseanti  checkstyle  compile  |
| uname | Linux 359b8f3784c3 4.4.0-138-generic #164-Ubuntu SMP Tue Oct 2 
17:16:02 UTC 2018 x86_64 GNU/Linux |
| Build tool | maven |
| Personality | 
/home/jenkins/jenkins-slave/workspace/PreCommit-HBASE-Build/component/dev-support/hbase-personality.sh
 |
| git revision | master / 5ded294419 |
| maven | version: Apache Maven 3.5.4 
(1edded0938998edf8bf061f1ceb3cfdeccf443fe; 2018-06-17T18:33:14Z) |
| Default Java | 1.8.0_181 |
| findbugs | v3.1.0-RC3 |
|  Test Results | 
https://builds.apache.org/job/PreCommit-HBASE-Build/15081/testReport/ |
| Max. process+thread count | 4880 (vs. ulimit of 10000) |
| modules | C: hbase-server U: hbase-server |
| Console output | 
https://builds.apache.org/job/PreCommit-HBASE-Build/15081/console |
| Powered by | Apache Yetus 0.8.0   http://yetus.apache.org |


This message was automatically generated.



> Replication normal source can get stuck due potential race conditions between 
> source wal reader and wal provider initialization threads.
> ----------------------------------------------------------------------------------------------------------------------------------------
>
>                 Key: HBASE-21503
>                 URL: https://issues.apache.org/jira/browse/HBASE-21503
>             Project: HBase
>          Issue Type: Bug
>          Components: Replication
>            Reporter: Wellington Chevreuil
>            Assignee: Wellington Chevreuil
>            Priority: Blocker
>             Fix For: 3.0.0, 2.2.0, 2.0.3, 2.1.2
>
>         Attachments: HBASE-21503-master.001.patch, HBASE-21503.patch
>
>
> Noticed replication sources could get stuck while doing some tests that 
> involved RS restart. On these cases, upon RS restart, the newly created 
> normal source was reaching wal end and not recognising it was open for write, 
> what leads to remove it from source queue. Thus, no new OP get's replicated 
> unless this log goes to a recovery queue.
> Checking this further, my understanding is that, during restart, RS will 
> start replication services, which inits ReplicationSourceManager and 
> ReplicationSources for each wal group id, in below sequence:
> {noformat}
> HRegionServer -> Replication.startReplicationService() -> 
> ReplicationSourceManager.init() -> add ReplicationSource 
> {noformat}
> At this point, ReplicationSources have no paths yet, so WAL reader thread is 
> not running. ReplicationSourceManager is registered as a WAL listener, in 
> order to get notified whenever new wal file is available. During 
> ReplicationSourceManager and ReplicationSource instances creation, a 
> WALFileLengthProvider instance is obtained from WALProvider and cached by 
> both ReplicationSourceManager and ReplicationSource. The default 
> implementation for this WALFileLengthProvider is below, on WALProvider 
> interface:
> {noformat}
> default WALFileLengthProvider getWALFileLengthProvider() {
>     return path -> getWALs().stream().map(w -> 
> w.getLogFileSizeIfBeingWritten(path))
>         .filter(o -> o.isPresent()).findAny().orElse(OptionalLong.empty());
>   } 
> {noformat}
> Notice that if WALProvider.getWALs returns an empty list, this 
> WALFileLengthProvider instance is always going to return nothing. This is 
> relevant because when ReplicationSource finally starts 
> ReplicationSourceWALReader thread, it passes this WALFileLengthProvider, 
> which is used by WALEntryStream (inside the wal reader) to determine if wal 
> is being written (and should be kept in the queue) here:
> {noformat}
>   private void tryAdvanceEntry() throws IOException {
>     if (checkReader()) {
>       boolean beingWritten = readNextEntryAndRecordReaderPosition();
>       LOG.trace("reading wal file {}. Current open for write: {}", 
> this.currentPath, beingWritten);
>       if (currentEntry == null && !beingWritten) {
>         // no more entries in this log file, and the file is already closed, 
> i.e, rolled
>         // Before dequeueing, we should always get one more attempt at 
> reading.
>         // This is in case more entries came in after we opened the reader, 
> and the log is rolled
>         // while we were reading. See HBASE-6758
>         resetReader();
>         readNextEntryAndRecordReaderPosition();
>         if (currentEntry == null) {
>           if (checkAllBytesParsed()) { // now we're certain we're done with 
> this log file
>             dequeueCurrentLog();
>             if (openNextLog()) {
>               readNextEntryAndRecordReaderPosition();
>             }
>           }
>         }
>       }
> ...
> {noformat}
> Here code snippet for WALEntryStream.readNextEntryAndRecordReaderPosition() 
> method that relies on the WALFileLengthProvider:
> {noformat}
> ...
> #1   OptionalLong fileLength = 
> walFileLengthProvider.getLogFileSizeIfBeingWritten(currentPath);
>     if (fileLength.isPresent() && readerPos > fileLength.getAsLong()) {
>       // see HBASE-14004, for AsyncFSWAL which uses fan-out, it is possible 
> that we read uncommitted
>       // data, so we need to make sure that we do not read beyond the 
> committed file length.
>       if (LOG.isDebugEnabled()) {
>         LOG.debug("The provider tells us the valid length for " + currentPath 
> + " is " +
>             fileLength.getAsLong() + ", but we have advanced to " + 
> readerPos);
>       }
>       resetReader();
>       return true;
>     }
>     if (readEntry != null) {
>       metrics.incrLogEditsRead();
>       metrics.incrLogReadInBytes(readerPos - currentPositionOfEntry);
>     }
>     currentEntry = readEntry; // could be null
>     this.currentPositionOfReader = readerPos;
>     return fileLength.isPresent();
> ...
> {noformat}
> The problem can occur because when wal file is indeed created in 
> AbstractFSWALProvider.getWAL() method (snippet shown below), line marked as 
> #2 in below snippet triggers notification of registered WALListeners, 
> including ReplicationSourceManager, which will start 
> ReplicationSourceWALReader thread. If ReplicationSourceWALReader thread 
> reaches the point #1 from snippet above before the thread running 
> AbstractFSWALProvider.getWAL() method gets to point #3 from below snippet, 
> then WALFileLengthProvider will return empty and the wal will not be 
> considered as open, causing it to be dequeued:
> {noformat}
>   @Override
>   public T getWAL(RegionInfo region) throws IOException {
>     T walCopy = wal;
>     if (walCopy == null) {
>       // only lock when need to create wal, and need to lock since
>       // creating hlog on fs is time consuming
>       synchronized (walCreateLock) {
>         walCopy = wal;
>         if (walCopy == null) {
>           walCopy = createWAL();
>           boolean succ = false;
>           try {
> #2            walCopy.init();
>             succ = true;
>           } finally {
>             if (!succ) {
>               walCopy.close();
>             }
>           }
>  #3         wal = walCopy;
>         }
>       }
>     }
>     return walCopy;
>   }
> {noformat}
> This can be sorted by making AbstractFSWALProvider.getWALs reuse 
> AbstractFSWALProvider.getWAL method to obtain the WAL instance. Do we really 
> have scenarios where we want to return no WAL instance? Another possibility 
> could be to synchronize getWALs on same lock currently used by getWAL.
> Am proposing an initial patch with the 1st solution, after some tests, it 
> does seem to be enough to sort the problem.



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)

Reply via email to