001/**
002 * Licensed to the Apache Software Foundation (ASF) under one
003 * or more contributor license agreements.  See the NOTICE file
004 * distributed with this work for additional information
005 * regarding copyright ownership.  The ASF licenses this file
006 * to you under the Apache License, Version 2.0 (the
007 * "License"); you may not use this file except in compliance
008 * with the License.  You may obtain a copy of the License at
009 *
010 *     http://www.apache.org/licenses/LICENSE-2.0
011 *
012 * Unless required by applicable law or agreed to in writing, software
013 * distributed under the License is distributed on an "AS IS" BASIS,
014 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
015 * See the License for the specific language governing permissions and
016 * limitations under the License.
017 */
018package org.apache.hadoop.hbase.wal;
019
020import static org.junit.Assert.assertEquals;
021import static org.junit.Assert.assertFalse;
022import static org.junit.Assert.assertTrue;
023import static org.junit.Assert.fail;
024
025import java.io.FileNotFoundException;
026import java.io.IOException;
027import java.lang.reflect.Method;
028import java.security.PrivilegedExceptionAction;
029import java.util.ArrayList;
030import java.util.Arrays;
031import java.util.Collections;
032import java.util.HashMap;
033import java.util.HashSet;
034import java.util.List;
035import java.util.Map;
036import java.util.NavigableSet;
037import java.util.Objects;
038import java.util.Set;
039import java.util.concurrent.atomic.AtomicBoolean;
040import java.util.concurrent.atomic.AtomicInteger;
041import java.util.concurrent.atomic.AtomicLong;
042import java.util.stream.Collectors;
043import org.apache.hadoop.conf.Configuration;
044import org.apache.hadoop.fs.FSDataInputStream;
045import org.apache.hadoop.fs.FSDataOutputStream;
046import org.apache.hadoop.fs.FileStatus;
047import org.apache.hadoop.fs.FileSystem;
048import org.apache.hadoop.fs.FileUtil;
049import org.apache.hadoop.fs.Path;
050import org.apache.hadoop.fs.PathFilter;
051import org.apache.hadoop.hbase.Cell;
052import org.apache.hadoop.hbase.HBaseClassTestRule;
053import org.apache.hadoop.hbase.HBaseConfiguration;
054import org.apache.hadoop.hbase.HBaseTestingUtility;
055import org.apache.hadoop.hbase.HConstants;
056import org.apache.hadoop.hbase.KeyValue;
057import org.apache.hadoop.hbase.ServerName;
058import org.apache.hadoop.hbase.TableName;
059import org.apache.hadoop.hbase.client.RegionInfo;
060import org.apache.hadoop.hbase.client.RegionInfoBuilder;
061import org.apache.hadoop.hbase.regionserver.HRegion;
062import org.apache.hadoop.hbase.regionserver.wal.FaultyProtobufLogReader;
063import org.apache.hadoop.hbase.regionserver.wal.InstrumentedLogWriter;
064import org.apache.hadoop.hbase.regionserver.wal.ProtobufLogReader;
065import org.apache.hadoop.hbase.security.User;
066import org.apache.hadoop.hbase.testclassification.LargeTests;
067import org.apache.hadoop.hbase.testclassification.RegionServerTests;
068import org.apache.hadoop.hbase.util.Bytes;
069import org.apache.hadoop.hbase.util.CancelableProgressable;
070import org.apache.hadoop.hbase.util.EnvironmentEdgeManager;
071import org.apache.hadoop.hbase.util.FSUtils;
072import org.apache.hadoop.hbase.util.Threads;
073import org.apache.hadoop.hbase.wal.WAL.Entry;
074import org.apache.hadoop.hbase.wal.WAL.Reader;
075import org.apache.hadoop.hbase.wal.WALProvider.Writer;
076import org.apache.hadoop.hbase.wal.WALSplitter.CorruptedLogFileException;
077import org.apache.hadoop.hdfs.DFSTestUtil;
078import org.apache.hadoop.hdfs.server.namenode.LeaseExpiredException;
079import org.apache.hadoop.ipc.RemoteException;
080import org.junit.After;
081import org.junit.AfterClass;
082import org.junit.Before;
083import org.junit.BeforeClass;
084import org.junit.ClassRule;
085import org.junit.Rule;
086import org.junit.Test;
087import org.junit.experimental.categories.Category;
088import org.junit.rules.TestName;
089import org.mockito.Mockito;
090import org.mockito.invocation.InvocationOnMock;
091import org.mockito.stubbing.Answer;
092import org.slf4j.Logger;
093import org.slf4j.LoggerFactory;
094
095import org.apache.hbase.thirdparty.com.google.common.base.Joiner;
096import org.apache.hbase.thirdparty.com.google.common.collect.ImmutableList;
097import org.apache.hbase.thirdparty.com.google.common.collect.ImmutableMap;
098import org.apache.hbase.thirdparty.com.google.protobuf.ByteString;
099
100import org.apache.hadoop.hbase.shaded.protobuf.ProtobufUtil;
101import org.apache.hadoop.hbase.shaded.protobuf.generated.WALProtos;
102
103/**
104 * Testing {@link WAL} splitting code.
105 */
106@Category({RegionServerTests.class, LargeTests.class})
107public class TestWALSplit {
108
109  @ClassRule
110  public static final HBaseClassTestRule CLASS_RULE =
111      HBaseClassTestRule.forClass(TestWALSplit.class);
112
113  {
114    // Uncomment the following lines if more verbosity is needed for
115    // debugging (see HBASE-12285 for details).
116    //((Log4JLogger)DataNode.LOG).getLogger().setLevel(Level.ALL);
117    //((Log4JLogger)LeaseManager.LOG).getLogger().setLevel(Level.ALL);
118    //((Log4JLogger)FSNamesystem.LOG).getLogger().setLevel(Level.ALL);
119  }
120  private final static Logger LOG = LoggerFactory.getLogger(TestWALSplit.class);
121
122  private static Configuration conf;
123  private FileSystem fs;
124
125  protected final static HBaseTestingUtility TEST_UTIL = new HBaseTestingUtility();
126
127  private Path HBASEDIR;
128  private Path HBASELOGDIR;
129  private Path WALDIR;
130  private Path OLDLOGDIR;
131  private Path CORRUPTDIR;
132  private Path TABLEDIR;
133
134  private static final int NUM_WRITERS = 10;
135  private static final int ENTRIES = 10; // entries per writer per region
136
137  private static final String FILENAME_BEING_SPLIT = "testfile";
138  private static final TableName TABLE_NAME =
139      TableName.valueOf("t1");
140  private static final byte[] FAMILY = Bytes.toBytes("f1");
141  private static final byte[] QUALIFIER = Bytes.toBytes("q1");
142  private static final byte[] VALUE = Bytes.toBytes("v1");
143  private static final String WAL_FILE_PREFIX = "wal.dat.";
144  private static List<String> REGIONS = new ArrayList<>();
145  private static final String HBASE_SKIP_ERRORS = "hbase.hlog.split.skip.errors";
146  private static String ROBBER;
147  private static String ZOMBIE;
148  private static String [] GROUP = new String [] {"supergroup"};
149
150  static enum Corruptions {
151    INSERT_GARBAGE_ON_FIRST_LINE,
152    INSERT_GARBAGE_IN_THE_MIDDLE,
153    APPEND_GARBAGE,
154    TRUNCATE,
155    TRUNCATE_TRAILER
156  }
157
158  @BeforeClass
159  public static void setUpBeforeClass() throws Exception {
160    conf = TEST_UTIL.getConfiguration();
161    conf.setClass("hbase.regionserver.hlog.writer.impl",
162        InstrumentedLogWriter.class, Writer.class);
163    // This is how you turn off shortcircuit read currently.  TODO: Fix.  Should read config.
164    System.setProperty("hbase.tests.use.shortcircuit.reads", "false");
165    // Create fake maping user to group and set it to the conf.
166    Map<String, String []> u2g_map = new HashMap<>(2);
167    ROBBER = User.getCurrent().getName() + "-robber";
168    ZOMBIE = User.getCurrent().getName() + "-zombie";
169    u2g_map.put(ROBBER, GROUP);
170    u2g_map.put(ZOMBIE, GROUP);
171    DFSTestUtil.updateConfWithFakeGroupMapping(conf, u2g_map);
172    conf.setInt("dfs.heartbeat.interval", 1);
173    TEST_UTIL.startMiniDFSCluster(2);
174  }
175
176  @AfterClass
177  public static void tearDownAfterClass() throws Exception {
178    TEST_UTIL.shutdownMiniDFSCluster();
179  }
180
181  @Rule
182  public TestName name = new TestName();
183  private WALFactory wals = null;
184
185  @Before
186  public void setUp() throws Exception {
187    LOG.info("Cleaning up cluster for new test.");
188    fs = TEST_UTIL.getDFSCluster().getFileSystem();
189    HBASEDIR = TEST_UTIL.createRootDir();
190    HBASELOGDIR = TEST_UTIL.createWALRootDir();
191    OLDLOGDIR = new Path(HBASELOGDIR, HConstants.HREGION_OLDLOGDIR_NAME);
192    CORRUPTDIR = new Path(HBASELOGDIR, HConstants.CORRUPT_DIR_NAME);
193    TABLEDIR = FSUtils.getTableDir(HBASEDIR, TABLE_NAME);
194    REGIONS.clear();
195    Collections.addAll(REGIONS, "bbb", "ccc");
196    InstrumentedLogWriter.activateFailure = false;
197    wals = new WALFactory(conf, name.getMethodName());
198    WALDIR = new Path(HBASELOGDIR,
199        AbstractFSWALProvider.getWALDirectoryName(ServerName.valueOf(name.getMethodName(),
200            16010, System.currentTimeMillis()).toString()));
201    //fs.mkdirs(WALDIR);
202  }
203
204  @After
205  public void tearDown() throws Exception {
206    try {
207      wals.close();
208    } catch(IOException exception) {
209      // Some tests will move WALs out from under us. In those cases, we'll get an error on close.
210      LOG.info("Ignoring an error while closing down our WALFactory. Fine for some tests, but if" +
211          " you see a failure look here.");
212      LOG.debug("exception details", exception);
213    } finally {
214      wals = null;
215      fs.delete(HBASEDIR, true);
216      fs.delete(HBASELOGDIR, true);
217    }
218  }
219
220  /**
221   * Simulates splitting a WAL out from under a regionserver that is still trying to write it.
222   * Ensures we do not lose edits.
223   * @throws IOException
224   * @throws InterruptedException
225   */
226  @Test
227  public void testLogCannotBeWrittenOnceParsed() throws IOException, InterruptedException {
228    final AtomicLong counter = new AtomicLong(0);
229    AtomicBoolean stop = new AtomicBoolean(false);
230    // Region we'll write edits too and then later examine to make sure they all made it in.
231    final String region = REGIONS.get(0);
232    final int numWriters = 3;
233    Thread zombie = new ZombieLastLogWriterRegionServer(counter, stop, region, numWriters);
234    try {
235      long startCount = counter.get();
236      zombie.start();
237      // Wait till writer starts going.
238      while (startCount == counter.get()) Threads.sleep(1);
239      // Give it a second to write a few appends.
240      Threads.sleep(1000);
241      final Configuration conf2 = HBaseConfiguration.create(conf);
242      final User robber = User.createUserForTesting(conf2, ROBBER, GROUP);
243      int count = robber.runAs(new PrivilegedExceptionAction<Integer>() {
244        @Override
245        public Integer run() throws Exception {
246          StringBuilder ls = new StringBuilder("Contents of WALDIR (").append(WALDIR)
247              .append("):\n");
248          for (FileStatus status : fs.listStatus(WALDIR)) {
249            ls.append("\t").append(status.toString()).append("\n");
250          }
251          LOG.debug(Objects.toString(ls));
252          LOG.info("Splitting WALs out from under zombie. Expecting " + numWriters + " files.");
253          WALSplitter.split(HBASEDIR, WALDIR, OLDLOGDIR, fs, conf2, wals);
254          LOG.info("Finished splitting out from under zombie.");
255          Path[] logfiles = getLogForRegion(HBASEDIR, TABLE_NAME, region);
256          assertEquals("wrong number of split files for region", numWriters, logfiles.length);
257          int count = 0;
258          for (Path logfile: logfiles) {
259            count += countWAL(logfile);
260          }
261          return count;
262        }
263      });
264      LOG.info("zombie=" + counter.get() + ", robber=" + count);
265      assertTrue("The log file could have at most 1 extra log entry, but can't have less. " +
266              "Zombie could write " + counter.get() + " and logfile had only " + count,
267          counter.get() == count || counter.get() + 1 == count);
268    } finally {
269      stop.set(true);
270      zombie.interrupt();
271      Threads.threadDumpingIsAlive(zombie);
272    }
273  }
274
275  /**
276   * This thread will keep writing to a 'wal' file even after the split process has started.
277   * It simulates a region server that was considered dead but woke up and wrote some more to the
278   * last log entry. Does its writing as an alternate user in another filesystem instance to
279   * simulate better it being a regionserver.
280   */
281  class ZombieLastLogWriterRegionServer extends Thread {
282    final AtomicLong editsCount;
283    final AtomicBoolean stop;
284    final int numOfWriters;
285    /**
286     * Region to write edits for.
287     */
288    final String region;
289    final User user;
290
291    public ZombieLastLogWriterRegionServer(AtomicLong counter, AtomicBoolean stop,
292        final String region, final int writers)
293        throws IOException, InterruptedException {
294      super("ZombieLastLogWriterRegionServer");
295      setDaemon(true);
296      this.stop = stop;
297      this.editsCount = counter;
298      this.region = region;
299      this.user = User.createUserForTesting(conf, ZOMBIE, GROUP);
300      numOfWriters = writers;
301    }
302
303    @Override
304    public void run() {
305      try {
306        doWriting();
307      } catch (IOException e) {
308        LOG.warn(getName() + " Writer exiting " + e);
309      } catch (InterruptedException e) {
310        LOG.warn(getName() + " Writer exiting " + e);
311      }
312    }
313
314    private void doWriting() throws IOException, InterruptedException {
315      this.user.runAs(new PrivilegedExceptionAction<Object>() {
316        @Override
317        public Object run() throws Exception {
318          // Index of the WAL we want to keep open.  generateWALs will leave open the WAL whose
319          // index we supply here.
320          int walToKeepOpen = numOfWriters - 1;
321          // The below method writes numOfWriters files each with ENTRIES entries for a total of
322          // numOfWriters * ENTRIES added per column family in the region.
323          Writer writer = null;
324          try {
325            writer = generateWALs(numOfWriters, ENTRIES, walToKeepOpen);
326          } catch (IOException e1) {
327            throw new RuntimeException("Failed", e1);
328          }
329          // Update counter so has all edits written so far.
330          editsCount.addAndGet(numOfWriters * ENTRIES);
331          loop(writer);
332          // If we've been interruped, then things should have shifted out from under us.
333          // closing should error
334          try {
335            writer.close();
336            fail("Writing closing after parsing should give an error.");
337          } catch (IOException exception) {
338            LOG.debug("ignoring error when closing final writer.", exception);
339          }
340          return null;
341        }
342      });
343    }
344
345    private void loop(final Writer writer) {
346      byte [] regionBytes = Bytes.toBytes(this.region);
347      while (!stop.get()) {
348        try {
349          long seq = appendEntry(writer, TABLE_NAME, regionBytes,
350              Bytes.toBytes("r" + editsCount.get()), regionBytes, QUALIFIER, VALUE, 0);
351          long count = editsCount.incrementAndGet();
352          LOG.info(getName() + " sync count=" + count + ", seq=" + seq);
353          try {
354            Thread.sleep(1);
355          } catch (InterruptedException e) {
356            //
357          }
358        } catch (IOException ex) {
359          LOG.error(getName() + " ex " + ex.toString());
360          if (ex instanceof RemoteException) {
361            LOG.error("Juliet: got RemoteException " + ex.getMessage() +
362                " while writing " + (editsCount.get() + 1));
363          } else {
364            LOG.error(getName() + " failed to write....at " + editsCount.get());
365            fail("Failed to write " + editsCount.get());
366          }
367          break;
368        } catch (Throwable t) {
369          LOG.error(getName() + " HOW? " + t);
370          LOG.debug("exception details", t);
371          break;
372        }
373      }
374      LOG.info(getName() + " Writer exiting");
375    }
376  }
377
378  /**
379   * {@see https://issues.apache.org/jira/browse/HBASE-3020}
380   */
381  @Test
382  public void testRecoveredEditsPathForMeta() throws IOException {
383    byte[] encoded = RegionInfoBuilder.FIRST_META_REGIONINFO.getEncodedNameAsBytes();
384    Path tdir = FSUtils.getTableDir(HBASEDIR, TableName.META_TABLE_NAME);
385    Path regiondir = new Path(tdir,
386      RegionInfoBuilder.FIRST_META_REGIONINFO.getEncodedName());
387    fs.mkdirs(regiondir);
388    long now = System.currentTimeMillis();
389    Entry entry =
390        new Entry(new WALKeyImpl(encoded,
391            TableName.META_TABLE_NAME, 1, now, HConstants.DEFAULT_CLUSTER_ID),
392            new WALEdit());
393    Path p = WALSplitter.getRegionSplitEditsPath(fs, entry, HBASEDIR,
394        FILENAME_BEING_SPLIT);
395    String parentOfParent = p.getParent().getParent().getName();
396    assertEquals(parentOfParent, RegionInfoBuilder.FIRST_META_REGIONINFO.getEncodedName());
397  }
398
399  /**
400   * Test old recovered edits file doesn't break WALSplitter.
401   * This is useful in upgrading old instances.
402   */
403  @Test
404  public void testOldRecoveredEditsFileSidelined() throws IOException {
405    byte [] encoded = RegionInfoBuilder.FIRST_META_REGIONINFO.getEncodedNameAsBytes();
406    Path tdir = FSUtils.getTableDir(HBASEDIR, TableName.META_TABLE_NAME);
407    Path regiondir = new Path(tdir,
408      RegionInfoBuilder.FIRST_META_REGIONINFO.getEncodedName());
409    fs.mkdirs(regiondir);
410    long now = System.currentTimeMillis();
411    Entry entry =
412        new Entry(new WALKeyImpl(encoded,
413            TableName.META_TABLE_NAME, 1, now, HConstants.DEFAULT_CLUSTER_ID),
414            new WALEdit());
415    Path parent = WALSplitter.getRegionDirRecoveredEditsDir(regiondir);
416    assertEquals(HConstants.RECOVERED_EDITS_DIR, parent.getName());
417    fs.createNewFile(parent); // create a recovered.edits file
418
419    Path p = WALSplitter.getRegionSplitEditsPath(fs, entry, HBASEDIR,
420        FILENAME_BEING_SPLIT);
421    String parentOfParent = p.getParent().getParent().getName();
422    assertEquals(parentOfParent, RegionInfoBuilder.FIRST_META_REGIONINFO.getEncodedName());
423    WALFactory.createRecoveredEditsWriter(fs, p, conf).close();
424  }
425
426  private void useDifferentDFSClient() throws IOException {
427    // make fs act as a different client now
428    // initialize will create a new DFSClient with a new client ID
429    fs.initialize(fs.getUri(), conf);
430  }
431
432  @Test
433  public void testSplitPreservesEdits() throws IOException{
434    final String REGION = "region__1";
435    REGIONS.clear();
436    REGIONS.add(REGION);
437
438    generateWALs(1, 10, -1, 0);
439    useDifferentDFSClient();
440    WALSplitter.split(HBASEDIR, WALDIR, OLDLOGDIR, fs, conf, wals);
441    Path originalLog = (fs.listStatus(OLDLOGDIR))[0].getPath();
442    Path[] splitLog = getLogForRegion(HBASEDIR, TABLE_NAME, REGION);
443    assertEquals(1, splitLog.length);
444
445    assertTrue("edits differ after split", logsAreEqual(originalLog, splitLog[0]));
446  }
447
448  @Test
449  public void testSplitRemovesRegionEventsEdits() throws IOException{
450    final String REGION = "region__1";
451    REGIONS.clear();
452    REGIONS.add(REGION);
453
454    generateWALs(1, 10, -1, 100);
455    useDifferentDFSClient();
456    WALSplitter.split(HBASEDIR, WALDIR, OLDLOGDIR, fs, conf, wals);
457    Path originalLog = (fs.listStatus(OLDLOGDIR))[0].getPath();
458    Path[] splitLog = getLogForRegion(HBASEDIR, TABLE_NAME, REGION);
459    assertEquals(1, splitLog.length);
460
461    assertFalse("edits differ after split", logsAreEqual(originalLog, splitLog[0]));
462    // split log should only have the test edits
463    assertEquals(10, countWAL(splitLog[0]));
464  }
465
466
467  @Test
468  public void testSplitLeavesCompactionEventsEdits() throws IOException{
469    RegionInfo hri = RegionInfoBuilder.newBuilder(TABLE_NAME).build();
470    REGIONS.clear();
471    REGIONS.add(hri.getEncodedName());
472    Path regionDir = new Path(FSUtils.getTableDir(HBASEDIR, TABLE_NAME), hri.getEncodedName());
473    LOG.info("Creating region directory: " + regionDir);
474    assertTrue(fs.mkdirs(regionDir));
475
476    Writer writer = generateWALs(1, 10, 0, 10);
477    String[] compactInputs = new String[]{"file1", "file2", "file3"};
478    String compactOutput = "file4";
479    appendCompactionEvent(writer, hri, compactInputs, compactOutput);
480    writer.close();
481
482    useDifferentDFSClient();
483    WALSplitter.split(HBASEDIR, WALDIR, OLDLOGDIR, fs, conf, wals);
484
485    Path originalLog = (fs.listStatus(OLDLOGDIR))[0].getPath();
486    // original log should have 10 test edits, 10 region markers, 1 compaction marker
487    assertEquals(21, countWAL(originalLog));
488
489    Path[] splitLog = getLogForRegion(HBASEDIR, TABLE_NAME, hri.getEncodedName());
490    assertEquals(1, splitLog.length);
491
492    assertFalse("edits differ after split", logsAreEqual(originalLog, splitLog[0]));
493    // split log should have 10 test edits plus 1 compaction marker
494    assertEquals(11, countWAL(splitLog[0]));
495  }
496
497  /**
498   * @param expectedEntries -1 to not assert
499   * @return the count across all regions
500   */
501  private int splitAndCount(final int expectedFiles, final int expectedEntries)
502      throws IOException {
503    useDifferentDFSClient();
504    WALSplitter.split(HBASEDIR, WALDIR, OLDLOGDIR, fs, conf, wals);
505    int result = 0;
506    for (String region : REGIONS) {
507      Path[] logfiles = getLogForRegion(HBASEDIR, TABLE_NAME, region);
508      assertEquals(expectedFiles, logfiles.length);
509      int count = 0;
510      for (Path logfile: logfiles) {
511        count += countWAL(logfile);
512      }
513      if (-1 != expectedEntries) {
514        assertEquals(expectedEntries, count);
515      }
516      result += count;
517    }
518    return result;
519  }
520
521  @Test
522  public void testEmptyLogFiles() throws IOException {
523    testEmptyLogFiles(true);
524  }
525
526  @Test
527  public void testEmptyOpenLogFiles() throws IOException {
528    testEmptyLogFiles(false);
529  }
530
531  private void testEmptyLogFiles(final boolean close) throws IOException {
532    // we won't create the hlog dir until getWAL got called, so
533    // make dir here when testing empty log file
534    fs.mkdirs(WALDIR);
535    injectEmptyFile(".empty", close);
536    generateWALs(Integer.MAX_VALUE);
537    injectEmptyFile("empty", close);
538    splitAndCount(NUM_WRITERS, NUM_WRITERS * ENTRIES); // skip 2 empty
539  }
540
541  @Test
542  public void testOpenZeroLengthReportedFileButWithDataGetsSplit() throws IOException {
543    // generate logs but leave wal.dat.5 open.
544    generateWALs(5);
545    splitAndCount(NUM_WRITERS, NUM_WRITERS * ENTRIES);
546  }
547
548  @Test
549  public void testTralingGarbageCorruptionFileSkipErrorsPasses() throws IOException {
550    conf.setBoolean(HBASE_SKIP_ERRORS, true);
551    generateWALs(Integer.MAX_VALUE);
552    corruptWAL(new Path(WALDIR, WAL_FILE_PREFIX + "5"),
553        Corruptions.APPEND_GARBAGE, true);
554    splitAndCount(NUM_WRITERS, NUM_WRITERS * ENTRIES);
555  }
556
557  @Test
558  public void testFirstLineCorruptionLogFileSkipErrorsPasses() throws IOException {
559    conf.setBoolean(HBASE_SKIP_ERRORS, true);
560    generateWALs(Integer.MAX_VALUE);
561    corruptWAL(new Path(WALDIR, WAL_FILE_PREFIX + "5"),
562        Corruptions.INSERT_GARBAGE_ON_FIRST_LINE, true);
563    splitAndCount(NUM_WRITERS - 1, (NUM_WRITERS - 1) * ENTRIES); //1 corrupt
564  }
565
566  @Test
567  public void testMiddleGarbageCorruptionSkipErrorsReadsHalfOfFile() throws IOException {
568    conf.setBoolean(HBASE_SKIP_ERRORS, true);
569    generateWALs(Integer.MAX_VALUE);
570    corruptWAL(new Path(WALDIR, WAL_FILE_PREFIX + "5"),
571        Corruptions.INSERT_GARBAGE_IN_THE_MIDDLE, false);
572    // the entries in the original logs are alternating regions
573    // considering the sequence file header, the middle corruption should
574    // affect at least half of the entries
575    int goodEntries = (NUM_WRITERS - 1) * ENTRIES;
576    int firstHalfEntries = (int) Math.ceil(ENTRIES / 2) - 1;
577    int allRegionsCount = splitAndCount(NUM_WRITERS, -1);
578    assertTrue("The file up to the corrupted area hasn't been parsed",
579        REGIONS.size() * (goodEntries + firstHalfEntries) <= allRegionsCount);
580  }
581
582  @Test
583  public void testCorruptedFileGetsArchivedIfSkipErrors() throws IOException {
584    conf.setBoolean(HBASE_SKIP_ERRORS, true);
585    List<FaultyProtobufLogReader.FailureType> failureTypes = Arrays
586        .asList(FaultyProtobufLogReader.FailureType.values()).stream()
587        .filter(x -> x != FaultyProtobufLogReader.FailureType.NONE).collect(Collectors.toList());
588    for (FaultyProtobufLogReader.FailureType failureType : failureTypes) {
589      final Set<String> walDirContents = splitCorruptWALs(failureType);
590      final Set<String> archivedLogs = new HashSet<>();
591      final StringBuilder archived = new StringBuilder("Archived logs in CORRUPTDIR:");
592      for (FileStatus log : fs.listStatus(CORRUPTDIR)) {
593        archived.append("\n\t").append(log.toString());
594        archivedLogs.add(log.getPath().getName());
595      }
596      LOG.debug(archived.toString());
597      assertEquals(failureType.name() + ": expected to find all of our wals corrupt.", archivedLogs,
598          walDirContents);
599    }
600  }
601
602  /**
603   * @return set of wal names present prior to split attempt.
604   * @throws IOException if the split process fails
605   */
606  private Set<String> splitCorruptWALs(final FaultyProtobufLogReader.FailureType failureType)
607      throws IOException {
608    Class<?> backupClass = conf.getClass("hbase.regionserver.hlog.reader.impl",
609        Reader.class);
610    InstrumentedLogWriter.activateFailure = false;
611
612    try {
613      conf.setClass("hbase.regionserver.hlog.reader.impl", FaultyProtobufLogReader.class,
614        Reader.class);
615      conf.set("faultyprotobuflogreader.failuretype", failureType.name());
616      // Clean up from previous tests or previous loop
617      try {
618        wals.shutdown();
619      } catch (IOException exception) {
620        // since we're splitting out from under the factory, we should expect some closing failures.
621        LOG.debug("Ignoring problem closing WALFactory.", exception);
622      }
623      wals.close();
624      try {
625        for (FileStatus log : fs.listStatus(CORRUPTDIR)) {
626          fs.delete(log.getPath(), true);
627        }
628      } catch (FileNotFoundException exception) {
629        LOG.debug("no previous CORRUPTDIR to clean.");
630      }
631      // change to the faulty reader
632      wals = new WALFactory(conf, name.getMethodName());
633      generateWALs(-1);
634      // Our reader will render all of these files corrupt.
635      final Set<String> walDirContents = new HashSet<>();
636      for (FileStatus status : fs.listStatus(WALDIR)) {
637        walDirContents.add(status.getPath().getName());
638      }
639      useDifferentDFSClient();
640      WALSplitter.split(HBASEDIR, WALDIR, OLDLOGDIR, fs, conf, wals);
641      return walDirContents;
642    } finally {
643      conf.setClass("hbase.regionserver.hlog.reader.impl", backupClass,
644          Reader.class);
645    }
646  }
647
648  @Test (expected = IOException.class)
649  public void testTrailingGarbageCorruptionLogFileSkipErrorsFalseThrows()
650      throws IOException {
651    conf.setBoolean(HBASE_SKIP_ERRORS, false);
652    splitCorruptWALs(FaultyProtobufLogReader.FailureType.BEGINNING);
653  }
654
655  @Test
656  public void testCorruptedLogFilesSkipErrorsFalseDoesNotTouchLogs()
657      throws IOException {
658    conf.setBoolean(HBASE_SKIP_ERRORS, false);
659    try {
660      splitCorruptWALs(FaultyProtobufLogReader.FailureType.BEGINNING);
661    } catch (IOException e) {
662      LOG.debug("split with 'skip errors' set to 'false' correctly threw");
663    }
664    assertEquals("if skip.errors is false all files should remain in place",
665        NUM_WRITERS, fs.listStatus(WALDIR).length);
666  }
667
668  private void ignoreCorruption(final Corruptions corruption, final int entryCount,
669      final int expectedCount) throws IOException {
670    conf.setBoolean(HBASE_SKIP_ERRORS, false);
671
672    final String REGION = "region__1";
673    REGIONS.clear();
674    REGIONS.add(REGION);
675
676    Path c1 = new Path(WALDIR, WAL_FILE_PREFIX + "0");
677    generateWALs(1, entryCount, -1, 0);
678    corruptWAL(c1, corruption, true);
679
680    useDifferentDFSClient();
681    WALSplitter.split(HBASEDIR, WALDIR, OLDLOGDIR, fs, conf, wals);
682
683    Path[] splitLog = getLogForRegion(HBASEDIR, TABLE_NAME, REGION);
684    assertEquals(1, splitLog.length);
685
686    int actualCount = 0;
687    Reader in = wals.createReader(fs, splitLog[0]);
688    @SuppressWarnings("unused")
689    Entry entry;
690    while ((entry = in.next()) != null) ++actualCount;
691    assertEquals(expectedCount, actualCount);
692    in.close();
693
694    // should not have stored the EOF files as corrupt
695    FileStatus[] archivedLogs = fs.listStatus(CORRUPTDIR);
696    assertEquals(0, archivedLogs.length);
697
698  }
699
700  @Test
701  public void testEOFisIgnored() throws IOException {
702    int entryCount = 10;
703    ignoreCorruption(Corruptions.TRUNCATE, entryCount, entryCount-1);
704  }
705
706  @Test
707  public void testCorruptWALTrailer() throws IOException {
708    int entryCount = 10;
709    ignoreCorruption(Corruptions.TRUNCATE_TRAILER, entryCount, entryCount);
710  }
711
712  @Test
713  public void testLogsGetArchivedAfterSplit() throws IOException {
714    conf.setBoolean(HBASE_SKIP_ERRORS, false);
715    generateWALs(-1);
716    useDifferentDFSClient();
717    WALSplitter.split(HBASEDIR, WALDIR, OLDLOGDIR, fs, conf, wals);
718    FileStatus[] archivedLogs = fs.listStatus(OLDLOGDIR);
719    assertEquals("wrong number of files in the archive log", NUM_WRITERS, archivedLogs.length);
720  }
721
722  @Test
723  public void testSplit() throws IOException {
724    generateWALs(-1);
725    splitAndCount(NUM_WRITERS, NUM_WRITERS * ENTRIES);
726  }
727
728  @Test
729  public void testLogDirectoryShouldBeDeletedAfterSuccessfulSplit()
730      throws IOException {
731    generateWALs(-1);
732    useDifferentDFSClient();
733    WALSplitter.split(HBASEDIR, WALDIR, OLDLOGDIR, fs, conf, wals);
734    FileStatus [] statuses = null;
735    try {
736      statuses = fs.listStatus(WALDIR);
737      if (statuses != null) {
738        fail("Files left in log dir: " +
739            Joiner.on(",").join(FileUtil.stat2Paths(statuses)));
740      }
741    } catch (FileNotFoundException e) {
742      // hadoop 0.21 throws FNFE whereas hadoop 0.20 returns null
743    }
744  }
745
746  @Test(expected = IOException.class)
747  public void testSplitWillFailIfWritingToRegionFails() throws Exception {
748    //leave 5th log open so we could append the "trap"
749    Writer writer = generateWALs(4);
750    useDifferentDFSClient();
751
752    String region = "break";
753    Path regiondir = new Path(TABLEDIR, region);
754    fs.mkdirs(regiondir);
755
756    InstrumentedLogWriter.activateFailure = false;
757    appendEntry(writer, TABLE_NAME, Bytes.toBytes(region),
758        Bytes.toBytes("r" + 999), FAMILY, QUALIFIER, VALUE, 0);
759    writer.close();
760
761    try {
762      InstrumentedLogWriter.activateFailure = true;
763      WALSplitter.split(HBASEDIR, WALDIR, OLDLOGDIR, fs, conf, wals);
764    } catch (IOException e) {
765      assertTrue(e.getMessage().
766          contains("This exception is instrumented and should only be thrown for testing"));
767      throw e;
768    } finally {
769      InstrumentedLogWriter.activateFailure = false;
770    }
771  }
772
773  @Test
774  public void testSplitDeletedRegion() throws IOException {
775    REGIONS.clear();
776    String region = "region_that_splits";
777    REGIONS.add(region);
778
779    generateWALs(1);
780    useDifferentDFSClient();
781
782    Path regiondir = new Path(TABLEDIR, region);
783    fs.delete(regiondir, true);
784    WALSplitter.split(HBASEDIR, WALDIR, OLDLOGDIR, fs, conf, wals);
785    assertFalse(fs.exists(regiondir));
786  }
787
788  @Test
789  public void testIOEOnOutputThread() throws Exception {
790    conf.setBoolean(HBASE_SKIP_ERRORS, false);
791
792    generateWALs(-1);
793    useDifferentDFSClient();
794    FileStatus[] logfiles = fs.listStatus(WALDIR);
795    assertTrue("There should be some log file",
796        logfiles != null && logfiles.length > 0);
797    // wals with no entries (like the one we don't use in the factory)
798    // won't cause a failure since nothing will ever be written.
799    // pick the largest one since it's most likely to have entries.
800    int largestLogFile = 0;
801    long largestSize = 0;
802    for (int i = 0; i < logfiles.length; i++) {
803      if (logfiles[i].getLen() > largestSize) {
804        largestLogFile = i;
805        largestSize = logfiles[i].getLen();
806      }
807    }
808    assertTrue("There should be some log greater than size 0.", 0 < largestSize);
809    // Set up a splitter that will throw an IOE on the output side
810    WALSplitter logSplitter = new WALSplitter(wals, conf, HBASEDIR, fs, null, null) {
811      @Override
812      protected Writer createWriter(Path logfile) throws IOException {
813        Writer mockWriter = Mockito.mock(Writer.class);
814        Mockito.doThrow(new IOException("Injected")).when(
815            mockWriter).append(Mockito.<Entry>any());
816        return mockWriter;
817      }
818    };
819    // Set up a background thread dumper.  Needs a thread to depend on and then we need to run
820    // the thread dumping in a background thread so it does not hold up the test.
821    final AtomicBoolean stop = new AtomicBoolean(false);
822    final Thread someOldThread = new Thread("Some-old-thread") {
823      @Override
824      public void run() {
825        while(!stop.get()) Threads.sleep(10);
826      }
827    };
828    someOldThread.setDaemon(true);
829    someOldThread.start();
830    final Thread t = new Thread("Background-thread-dumper") {
831      @Override
832      public void run() {
833        try {
834          Threads.threadDumpingIsAlive(someOldThread);
835        } catch (InterruptedException e) {
836          e.printStackTrace();
837        }
838      }
839    };
840    t.setDaemon(true);
841    t.start();
842    try {
843      logSplitter.splitLogFile(logfiles[largestLogFile], null);
844      fail("Didn't throw!");
845    } catch (IOException ioe) {
846      assertTrue(ioe.toString().contains("Injected"));
847    } finally {
848      // Setting this to true will turn off the background thread dumper.
849      stop.set(true);
850    }
851  }
852
853  /**
854   * @param spiedFs should be instrumented for failure.
855   */
856  private void retryOverHdfsProblem(final FileSystem spiedFs) throws Exception {
857    generateWALs(-1);
858    useDifferentDFSClient();
859
860    try {
861      WALSplitter.split(HBASEDIR, WALDIR, OLDLOGDIR, spiedFs, conf, wals);
862      assertEquals(NUM_WRITERS, fs.listStatus(OLDLOGDIR).length);
863      assertFalse(fs.exists(WALDIR));
864    } catch (IOException e) {
865      fail("There shouldn't be any exception but: " + e.toString());
866    }
867  }
868
869  // Test for HBASE-3412
870  @Test
871  public void testMovedWALDuringRecovery() throws Exception {
872    // This partial mock will throw LEE for every file simulating
873    // files that were moved
874    FileSystem spiedFs = Mockito.spy(fs);
875    // The "File does not exist" part is very important,
876    // that's how it comes out of HDFS
877    Mockito.doThrow(new LeaseExpiredException("Injected: File does not exist")).
878        when(spiedFs).append(Mockito.<Path>any());
879    retryOverHdfsProblem(spiedFs);
880  }
881
882  @Test
883  public void testRetryOpenDuringRecovery() throws Exception {
884    FileSystem spiedFs = Mockito.spy(fs);
885    // The "Cannot obtain block length", "Could not obtain the last block",
886    // and "Blocklist for [^ ]* has changed.*" part is very important,
887    // that's how it comes out of HDFS. If HDFS changes the exception
888    // message, this test needs to be adjusted accordingly.
889    //
890    // When DFSClient tries to open a file, HDFS needs to locate
891    // the last block of the file and get its length. However, if the
892    // last block is under recovery, HDFS may have problem to obtain
893    // the block length, in which case, retry may help.
894    Mockito.doAnswer(new Answer<FSDataInputStream>() {
895      private final String[] errors = new String[] {
896          "Cannot obtain block length", "Could not obtain the last block",
897          "Blocklist for " + OLDLOGDIR + " has changed"};
898      private int count = 0;
899
900      @Override
901      public FSDataInputStream answer(InvocationOnMock invocation) throws Throwable {
902        if (count < 3) {
903          throw new IOException(errors[count++]);
904        }
905        return (FSDataInputStream)invocation.callRealMethod();
906      }
907    }).when(spiedFs).open(Mockito.<Path>any(), Mockito.anyInt());
908    retryOverHdfsProblem(spiedFs);
909  }
910
911  @Test
912  public void testTerminationAskedByReporter() throws IOException, CorruptedLogFileException {
913    generateWALs(1, 10, -1);
914    FileStatus logfile = fs.listStatus(WALDIR)[0];
915    useDifferentDFSClient();
916
917    final AtomicInteger count = new AtomicInteger();
918
919    CancelableProgressable localReporter
920        = new CancelableProgressable() {
921      @Override
922      public boolean progress() {
923        count.getAndIncrement();
924        return false;
925      }
926    };
927
928    FileSystem spiedFs = Mockito.spy(fs);
929    Mockito.doAnswer(new Answer<FSDataInputStream>() {
930      @Override
931      public FSDataInputStream answer(InvocationOnMock invocation) throws Throwable {
932        Thread.sleep(1500); // Sleep a while and wait report status invoked
933        return (FSDataInputStream)invocation.callRealMethod();
934      }
935    }).when(spiedFs).open(Mockito.<Path>any(), Mockito.anyInt());
936
937    try {
938      conf.setInt("hbase.splitlog.report.period", 1000);
939      boolean ret = WALSplitter.splitLogFile(
940          HBASEDIR, logfile, spiedFs, conf, localReporter, null, null, wals);
941      assertFalse("Log splitting should failed", ret);
942      assertTrue(count.get() > 0);
943    } catch (IOException e) {
944      fail("There shouldn't be any exception but: " + e.toString());
945    } finally {
946      // reset it back to its default value
947      conf.setInt("hbase.splitlog.report.period", 59000);
948    }
949  }
950
951  /**
952   * Test log split process with fake data and lots of edits to trigger threading
953   * issues.
954   */
955  @Test
956  public void testThreading() throws Exception {
957    doTestThreading(20000, 128*1024*1024, 0);
958  }
959
960  /**
961   * Test blocking behavior of the log split process if writers are writing slower
962   * than the reader is reading.
963   */
964  @Test
965  public void testThreadingSlowWriterSmallBuffer() throws Exception {
966    doTestThreading(200, 1024, 50);
967  }
968
969  /**
970   * Sets up a log splitter with a mock reader and writer. The mock reader generates
971   * a specified number of edits spread across 5 regions. The mock writer optionally
972   * sleeps for each edit it is fed.
973   * *
974   * After the split is complete, verifies that the statistics show the correct number
975   * of edits output into each region.
976   *
977   * @param numFakeEdits number of fake edits to push through pipeline
978   * @param bufferSize size of in-memory buffer
979   * @param writerSlowness writer threads will sleep this many ms per edit
980   */
981  private void doTestThreading(final int numFakeEdits,
982      final int bufferSize,
983      final int writerSlowness) throws Exception {
984
985    Configuration localConf = new Configuration(conf);
986    localConf.setInt("hbase.regionserver.hlog.splitlog.buffersize", bufferSize);
987
988    // Create a fake log file (we'll override the reader to produce a stream of edits)
989    Path logPath = new Path(WALDIR, WAL_FILE_PREFIX + ".fake");
990    FSDataOutputStream out = fs.create(logPath);
991    out.close();
992
993    // Make region dirs for our destination regions so the output doesn't get skipped
994    final List<String> regions = ImmutableList.of("r0", "r1", "r2", "r3", "r4");
995    makeRegionDirs(regions);
996
997    // Create a splitter that reads and writes the data without touching disk
998    WALSplitter logSplitter = new WALSplitter(wals, localConf, HBASEDIR, fs, null, null) {
999
1000      /* Produce a mock writer that doesn't write anywhere */
1001      @Override
1002      protected Writer createWriter(Path logfile) throws IOException {
1003        Writer mockWriter = Mockito.mock(Writer.class);
1004        Mockito.doAnswer(new Answer<Void>() {
1005          int expectedIndex = 0;
1006
1007          @Override
1008          public Void answer(InvocationOnMock invocation) {
1009            if (writerSlowness > 0) {
1010              try {
1011                Thread.sleep(writerSlowness);
1012              } catch (InterruptedException ie) {
1013                Thread.currentThread().interrupt();
1014              }
1015            }
1016            Entry entry = (Entry) invocation.getArgument(0);
1017            WALEdit edit = entry.getEdit();
1018            List<Cell> cells = edit.getCells();
1019            assertEquals(1, cells.size());
1020            Cell cell = cells.get(0);
1021
1022            // Check that the edits come in the right order.
1023            assertEquals(expectedIndex, Bytes.toInt(cell.getRowArray(), cell.getRowOffset(),
1024                cell.getRowLength()));
1025            expectedIndex++;
1026            return null;
1027          }
1028        }).when(mockWriter).append(Mockito.<Entry>any());
1029        return mockWriter;
1030      }
1031
1032      /* Produce a mock reader that generates fake entries */
1033      @Override
1034      protected Reader getReader(Path curLogFile, CancelableProgressable reporter)
1035          throws IOException {
1036        Reader mockReader = Mockito.mock(Reader.class);
1037        Mockito.doAnswer(new Answer<Entry>() {
1038          int index = 0;
1039
1040          @Override
1041          public Entry answer(InvocationOnMock invocation) throws Throwable {
1042            if (index >= numFakeEdits) return null;
1043
1044            // Generate r0 through r4 in round robin fashion
1045            int regionIdx = index % regions.size();
1046            byte region[] = new byte[] {(byte)'r', (byte) (0x30 + regionIdx)};
1047
1048            Entry ret = createTestEntry(TABLE_NAME, region,
1049                Bytes.toBytes(index / regions.size()),
1050                FAMILY, QUALIFIER, VALUE, index);
1051            index++;
1052            return ret;
1053          }
1054        }).when(mockReader).next();
1055        return mockReader;
1056      }
1057    };
1058
1059    logSplitter.splitLogFile(fs.getFileStatus(logPath), null);
1060
1061    // Verify number of written edits per region
1062    Map<byte[], Long> outputCounts = logSplitter.outputSink.getOutputCounts();
1063    for (Map.Entry<byte[], Long> entry : outputCounts.entrySet()) {
1064      LOG.info("Got " + entry.getValue() + " output edits for region " +
1065          Bytes.toString(entry.getKey()));
1066      assertEquals((long)entry.getValue(), numFakeEdits / regions.size());
1067    }
1068    assertEquals("Should have as many outputs as regions", regions.size(), outputCounts.size());
1069  }
1070
1071  // Does leaving the writer open in testSplitDeletedRegion matter enough for two tests?
1072  @Test
1073  public void testSplitLogFileDeletedRegionDir() throws IOException {
1074    LOG.info("testSplitLogFileDeletedRegionDir");
1075    final String REGION = "region__1";
1076    REGIONS.clear();
1077    REGIONS.add(REGION);
1078
1079    generateWALs(1, 10, -1);
1080    useDifferentDFSClient();
1081
1082    Path regiondir = new Path(TABLEDIR, REGION);
1083    LOG.info("Region directory is" + regiondir);
1084    fs.delete(regiondir, true);
1085    WALSplitter.split(HBASEDIR, WALDIR, OLDLOGDIR, fs, conf, wals);
1086    assertFalse(fs.exists(regiondir));
1087  }
1088
1089  @Test
1090  public void testSplitLogFileEmpty() throws IOException {
1091    LOG.info("testSplitLogFileEmpty");
1092    // we won't create the hlog dir until getWAL got called, so
1093    // make dir here when testing empty log file
1094    fs.mkdirs(WALDIR);
1095    injectEmptyFile(".empty", true);
1096    useDifferentDFSClient();
1097
1098    WALSplitter.split(HBASEDIR, WALDIR, OLDLOGDIR, fs, conf, wals);
1099    Path tdir = FSUtils.getTableDir(HBASEDIR, TABLE_NAME);
1100    assertFalse(fs.exists(tdir));
1101
1102    assertEquals(0, countWAL(fs.listStatus(OLDLOGDIR)[0].getPath()));
1103  }
1104
1105  @Test
1106  public void testSplitLogFileMultipleRegions() throws IOException {
1107    LOG.info("testSplitLogFileMultipleRegions");
1108    generateWALs(1, 10, -1);
1109    splitAndCount(1, 10);
1110  }
1111
1112  @Test
1113  public void testSplitLogFileFirstLineCorruptionLog()
1114      throws IOException {
1115    conf.setBoolean(HBASE_SKIP_ERRORS, true);
1116    generateWALs(1, 10, -1);
1117    FileStatus logfile = fs.listStatus(WALDIR)[0];
1118
1119    corruptWAL(logfile.getPath(),
1120        Corruptions.INSERT_GARBAGE_ON_FIRST_LINE, true);
1121
1122    useDifferentDFSClient();
1123    WALSplitter.split(HBASEDIR, WALDIR, OLDLOGDIR, fs, conf, wals);
1124
1125    final Path corruptDir = new Path(FSUtils.getWALRootDir(conf), HConstants.CORRUPT_DIR_NAME);
1126    assertEquals(1, fs.listStatus(corruptDir).length);
1127  }
1128
1129  /**
1130   * {@see https://issues.apache.org/jira/browse/HBASE-4862}
1131   */
1132  @Test
1133  public void testConcurrentSplitLogAndReplayRecoverEdit() throws IOException {
1134    LOG.info("testConcurrentSplitLogAndReplayRecoverEdit");
1135    // Generate wals for our destination region
1136    String regionName = "r0";
1137    final Path regiondir = new Path(TABLEDIR, regionName);
1138    REGIONS.clear();
1139    REGIONS.add(regionName);
1140    generateWALs(-1);
1141
1142    wals.getWAL(null);
1143    FileStatus[] logfiles = fs.listStatus(WALDIR);
1144    assertTrue("There should be some log file",
1145        logfiles != null && logfiles.length > 0);
1146
1147    WALSplitter logSplitter = new WALSplitter(wals, conf, HBASEDIR, fs, null, null) {
1148      @Override
1149      protected Writer createWriter(Path logfile)
1150          throws IOException {
1151        Writer writer = wals.createRecoveredEditsWriter(this.fs, logfile);
1152        // After creating writer, simulate region's
1153        // replayRecoveredEditsIfAny() which gets SplitEditFiles of this
1154        // region and delete them, excluding files with '.temp' suffix.
1155        NavigableSet<Path> files = WALSplitter.getSplitEditFilesSorted(fs, regiondir);
1156        if (files != null && !files.isEmpty()) {
1157          for (Path file : files) {
1158            if (!this.fs.delete(file, false)) {
1159              LOG.error("Failed delete of " + file);
1160            } else {
1161              LOG.debug("Deleted recovered.edits file=" + file);
1162            }
1163          }
1164        }
1165        return writer;
1166      }
1167    };
1168    try{
1169      logSplitter.splitLogFile(logfiles[0], null);
1170    } catch (IOException e) {
1171      LOG.info(e.toString(), e);
1172      fail("Throws IOException when spliting "
1173          + "log, it is most likely because writing file does not "
1174          + "exist which is caused by concurrent replayRecoveredEditsIfAny()");
1175    }
1176    if (fs.exists(CORRUPTDIR)) {
1177      if (fs.listStatus(CORRUPTDIR).length > 0) {
1178        fail("There are some corrupt logs, "
1179            + "it is most likely caused by concurrent replayRecoveredEditsIfAny()");
1180      }
1181    }
1182  }
1183
1184  private Writer generateWALs(int leaveOpen) throws IOException {
1185    return generateWALs(NUM_WRITERS, ENTRIES, leaveOpen, 0);
1186  }
1187
1188  private Writer generateWALs(int writers, int entries, int leaveOpen) throws IOException {
1189    return generateWALs(writers, entries, leaveOpen, 7);
1190  }
1191
1192  private void makeRegionDirs(List<String> regions) throws IOException {
1193    for (String region : regions) {
1194      LOG.debug("Creating dir for region " + region);
1195      fs.mkdirs(new Path(TABLEDIR, region));
1196    }
1197  }
1198
1199  /**
1200   * @param leaveOpen index to leave un-closed. -1 to close all.
1201   * @return the writer that's still open, or null if all were closed.
1202   */
1203  private Writer generateWALs(int writers, int entries, int leaveOpen, int regionEvents) throws IOException {
1204    makeRegionDirs(REGIONS);
1205    fs.mkdirs(WALDIR);
1206    Writer [] ws = new Writer[writers];
1207    int seq = 0;
1208    int numRegionEventsAdded = 0;
1209    for (int i = 0; i < writers; i++) {
1210      ws[i] = wals.createWALWriter(fs, new Path(WALDIR, WAL_FILE_PREFIX + i));
1211      for (int j = 0; j < entries; j++) {
1212        int prefix = 0;
1213        for (String region : REGIONS) {
1214          String row_key = region + prefix++ + i + j;
1215          appendEntry(ws[i], TABLE_NAME, Bytes.toBytes(region), Bytes.toBytes(row_key), FAMILY,
1216              QUALIFIER, VALUE, seq++);
1217
1218          if (numRegionEventsAdded < regionEvents) {
1219            numRegionEventsAdded ++;
1220            appendRegionEvent(ws[i], region);
1221          }
1222        }
1223      }
1224      if (i != leaveOpen) {
1225        ws[i].close();
1226        LOG.info("Closing writer " + i);
1227      }
1228    }
1229    if (leaveOpen < 0 || leaveOpen >= writers) {
1230      return null;
1231    }
1232    return ws[leaveOpen];
1233  }
1234
1235
1236
1237  private Path[] getLogForRegion(Path rootdir, TableName table, String region)
1238      throws IOException {
1239    Path tdir = FSUtils.getTableDir(rootdir, table);
1240    @SuppressWarnings("deprecation")
1241    Path editsdir = WALSplitter.getRegionDirRecoveredEditsDir(HRegion.getRegionDir(tdir,
1242        Bytes.toString(Bytes.toBytes(region))));
1243    FileStatus[] files = fs.listStatus(editsdir, new PathFilter() {
1244      @Override
1245      public boolean accept(Path p) {
1246        if (WALSplitter.isSequenceIdFile(p)) {
1247          return false;
1248        }
1249        return true;
1250      }
1251    });
1252    Path[] paths = new Path[files.length];
1253    for (int i = 0; i < files.length; i++) {
1254      paths[i] = files[i].getPath();
1255    }
1256    return paths;
1257  }
1258
1259  private void corruptWAL(Path path, Corruptions corruption, boolean close) throws IOException {
1260    FSDataOutputStream out;
1261    int fileSize = (int) fs.listStatus(path)[0].getLen();
1262
1263    FSDataInputStream in = fs.open(path);
1264    byte[] corrupted_bytes = new byte[fileSize];
1265    in.readFully(0, corrupted_bytes, 0, fileSize);
1266    in.close();
1267
1268    switch (corruption) {
1269      case APPEND_GARBAGE:
1270        fs.delete(path, false);
1271        out = fs.create(path);
1272        out.write(corrupted_bytes);
1273        out.write(Bytes.toBytes("-----"));
1274        closeOrFlush(close, out);
1275        break;
1276
1277      case INSERT_GARBAGE_ON_FIRST_LINE:
1278        fs.delete(path, false);
1279        out = fs.create(path);
1280        out.write(0);
1281        out.write(corrupted_bytes);
1282        closeOrFlush(close, out);
1283        break;
1284
1285      case INSERT_GARBAGE_IN_THE_MIDDLE:
1286        fs.delete(path, false);
1287        out = fs.create(path);
1288        int middle = (int) Math.floor(corrupted_bytes.length / 2);
1289        out.write(corrupted_bytes, 0, middle);
1290        out.write(0);
1291        out.write(corrupted_bytes, middle, corrupted_bytes.length - middle);
1292        closeOrFlush(close, out);
1293        break;
1294
1295      case TRUNCATE:
1296        fs.delete(path, false);
1297        out = fs.create(path);
1298        out.write(corrupted_bytes, 0, fileSize
1299            - (32 + ProtobufLogReader.PB_WAL_COMPLETE_MAGIC.length + Bytes.SIZEOF_INT));
1300        closeOrFlush(close, out);
1301        break;
1302
1303      case TRUNCATE_TRAILER:
1304        fs.delete(path, false);
1305        out = fs.create(path);
1306        out.write(corrupted_bytes, 0, fileSize - Bytes.SIZEOF_INT);// trailer is truncated.
1307        closeOrFlush(close, out);
1308        break;
1309    }
1310  }
1311
1312  private void closeOrFlush(boolean close, FSDataOutputStream out)
1313      throws IOException {
1314    if (close) {
1315      out.close();
1316    } else {
1317      Method syncMethod = null;
1318      try {
1319        syncMethod = out.getClass().getMethod("hflush", new Class<?> []{});
1320      } catch (NoSuchMethodException e) {
1321        try {
1322          syncMethod = out.getClass().getMethod("sync", new Class<?> []{});
1323        } catch (NoSuchMethodException ex) {
1324          throw new IOException("This version of Hadoop supports " +
1325              "neither Syncable.sync() nor Syncable.hflush().");
1326        }
1327      }
1328      try {
1329        syncMethod.invoke(out, new Object[]{});
1330      } catch (Exception e) {
1331        throw new IOException(e);
1332      }
1333      // Not in 0out.hflush();
1334    }
1335  }
1336
1337  private int countWAL(Path log) throws IOException {
1338    int count = 0;
1339    Reader in = wals.createReader(fs, log);
1340    while (in.next() != null) {
1341      count++;
1342    }
1343    in.close();
1344    return count;
1345  }
1346
1347  private static void appendCompactionEvent(Writer w, RegionInfo hri, String[] inputs,
1348      String output) throws IOException {
1349    WALProtos.CompactionDescriptor.Builder desc = WALProtos.CompactionDescriptor.newBuilder();
1350    desc.setTableName(ByteString.copyFrom(hri.getTable().toBytes()))
1351        .setEncodedRegionName(ByteString.copyFrom(hri.getEncodedNameAsBytes()))
1352        .setRegionName(ByteString.copyFrom(hri.getRegionName()))
1353        .setFamilyName(ByteString.copyFrom(FAMILY))
1354        .setStoreHomeDir(hri.getEncodedName() + "/" + Bytes.toString(FAMILY))
1355        .addAllCompactionInput(Arrays.asList(inputs))
1356        .addCompactionOutput(output);
1357
1358    WALEdit edit = WALEdit.createCompaction(hri, desc.build());
1359    WALKeyImpl key = new WALKeyImpl(hri.getEncodedNameAsBytes(), TABLE_NAME, 1,
1360        EnvironmentEdgeManager.currentTime(), HConstants.DEFAULT_CLUSTER_ID);
1361    w.append(new Entry(key, edit));
1362    w.sync();
1363  }
1364
1365  private static void appendRegionEvent(Writer w, String region) throws IOException {
1366    WALProtos.RegionEventDescriptor regionOpenDesc = ProtobufUtil.toRegionEventDescriptor(
1367        WALProtos.RegionEventDescriptor.EventType.REGION_OPEN,
1368        TABLE_NAME.toBytes(),
1369        Bytes.toBytes(region),
1370        Bytes.toBytes(String.valueOf(region.hashCode())),
1371        1,
1372        ServerName.parseServerName("ServerName:9099"), ImmutableMap.<byte[], List<Path>>of());
1373    final long time = EnvironmentEdgeManager.currentTime();
1374    KeyValue kv = new KeyValue(Bytes.toBytes(region), WALEdit.METAFAMILY, WALEdit.REGION_EVENT,
1375        time, regionOpenDesc.toByteArray());
1376    final WALKeyImpl walKey = new WALKeyImpl(Bytes.toBytes(region), TABLE_NAME, 1, time,
1377        HConstants.DEFAULT_CLUSTER_ID);
1378    w.append(
1379        new Entry(walKey, new WALEdit().add(kv)));
1380    w.sync();
1381  }
1382
1383  public static long appendEntry(Writer writer, TableName table, byte[] region,
1384      byte[] row, byte[] family, byte[] qualifier,
1385      byte[] value, long seq)
1386      throws IOException {
1387    LOG.info(Thread.currentThread().getName() + " append");
1388    writer.append(createTestEntry(table, region, row, family, qualifier, value, seq));
1389    LOG.info(Thread.currentThread().getName() + " sync");
1390    writer.sync();
1391    return seq;
1392  }
1393
1394  private static Entry createTestEntry(
1395      TableName table, byte[] region,
1396      byte[] row, byte[] family, byte[] qualifier,
1397      byte[] value, long seq) {
1398    long time = System.nanoTime();
1399
1400    seq++;
1401    final KeyValue cell = new KeyValue(row, family, qualifier, time, KeyValue.Type.Put, value);
1402    WALEdit edit = new WALEdit();
1403    edit.add(cell);
1404    return new Entry(new WALKeyImpl(region, table, seq, time,
1405        HConstants.DEFAULT_CLUSTER_ID), edit);
1406  }
1407
1408  private void injectEmptyFile(String suffix, boolean closeFile) throws IOException {
1409    Writer writer =
1410        WALFactory.createWALWriter(fs, new Path(WALDIR, WAL_FILE_PREFIX + suffix), conf);
1411    if (closeFile) {
1412      writer.close();
1413    }
1414  }
1415
1416  private boolean logsAreEqual(Path p1, Path p2) throws IOException {
1417    Reader in1, in2;
1418    in1 = wals.createReader(fs, p1);
1419    in2 = wals.createReader(fs, p2);
1420    Entry entry1;
1421    Entry entry2;
1422    while ((entry1 = in1.next()) != null) {
1423      entry2 = in2.next();
1424      if ((entry1.getKey().compareTo(entry2.getKey()) != 0) ||
1425          (!entry1.getEdit().toString().equals(entry2.getEdit().toString()))) {
1426        return false;
1427      }
1428    }
1429    in1.close();
1430    in2.close();
1431    return true;
1432  }
1433}