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.master;
019
020import static org.apache.hadoop.hbase.HConstants.HBASE_SPLIT_WAL_MAX_SPLITTER;
021import static org.apache.hadoop.hbase.SplitLogCounters.tot_mgr_wait_for_zk_delete;
022import static org.junit.jupiter.api.Assertions.assertEquals;
023import static org.junit.jupiter.api.Assertions.assertTrue;
024import static org.junit.jupiter.api.Assertions.fail;
025
026import java.io.IOException;
027import java.util.ArrayList;
028import java.util.Arrays;
029import java.util.Iterator;
030import java.util.List;
031import java.util.NavigableSet;
032import java.util.concurrent.ExecutorService;
033import java.util.concurrent.Executors;
034import java.util.concurrent.Future;
035import java.util.concurrent.TimeUnit;
036import java.util.concurrent.TimeoutException;
037import java.util.concurrent.atomic.LongAdder;
038import org.apache.hadoop.conf.Configuration;
039import org.apache.hadoop.fs.FSDataOutputStream;
040import org.apache.hadoop.fs.FileSystem;
041import org.apache.hadoop.fs.Path;
042import org.apache.hadoop.hbase.HBaseTestingUtil;
043import org.apache.hadoop.hbase.HConstants;
044import org.apache.hadoop.hbase.KeyValue;
045import org.apache.hadoop.hbase.ServerName;
046import org.apache.hadoop.hbase.SingleProcessHBaseCluster;
047import org.apache.hadoop.hbase.SplitLogCounters;
048import org.apache.hadoop.hbase.StartTestingClusterOption;
049import org.apache.hadoop.hbase.TableName;
050import org.apache.hadoop.hbase.Waiter;
051import org.apache.hadoop.hbase.client.Put;
052import org.apache.hadoop.hbase.client.RegionInfo;
053import org.apache.hadoop.hbase.client.RegionInfoBuilder;
054import org.apache.hadoop.hbase.client.RegionLocator;
055import org.apache.hadoop.hbase.client.Table;
056import org.apache.hadoop.hbase.coordination.ZKSplitLogManagerCoordination;
057import org.apache.hadoop.hbase.master.assignment.RegionStates;
058import org.apache.hadoop.hbase.regionserver.HRegion;
059import org.apache.hadoop.hbase.regionserver.HRegionServer;
060import org.apache.hadoop.hbase.regionserver.MultiVersionConcurrencyControl;
061import org.apache.hadoop.hbase.regionserver.Region;
062import org.apache.hadoop.hbase.util.Bytes;
063import org.apache.hadoop.hbase.util.CommonFSUtils;
064import org.apache.hadoop.hbase.util.EnvironmentEdgeManager;
065import org.apache.hadoop.hbase.util.JVMClusterUtil.MasterThread;
066import org.apache.hadoop.hbase.util.JVMClusterUtil.RegionServerThread;
067import org.apache.hadoop.hbase.util.Threads;
068import org.apache.hadoop.hbase.wal.WAL;
069import org.apache.hadoop.hbase.wal.WALEdit;
070import org.apache.hadoop.hbase.wal.WALEditInternalHelper;
071import org.apache.hadoop.hbase.wal.WALKeyImpl;
072import org.apache.hadoop.hbase.zookeeper.ZKUtil;
073import org.junit.jupiter.api.AfterAll;
074import org.junit.jupiter.api.AfterEach;
075import org.junit.jupiter.api.BeforeAll;
076import org.junit.jupiter.api.BeforeEach;
077import org.junit.jupiter.api.Test;
078import org.junit.jupiter.api.TestInfo;
079import org.slf4j.Logger;
080import org.slf4j.LoggerFactory;
081
082import org.apache.hadoop.hbase.shaded.protobuf.ProtobufUtil;
083
084/**
085 * Base class for testing distributed log splitting.
086 */
087public abstract class AbstractTestDLS {
088  private static final Logger LOG = LoggerFactory.getLogger(AbstractTestDLS.class);
089
090  private static final HBaseTestingUtil TEST_UTIL = new HBaseTestingUtil();
091
092  // Start a cluster with 2 masters and 5 regionservers
093  private static final int NUM_MASTERS = 2;
094  private static final int NUM_RS = 5;
095  private static byte[] COLUMN_FAMILY = Bytes.toBytes("family");
096
097  private TableName tableName;
098  private SingleProcessHBaseCluster cluster;
099  private HMaster master;
100  private Configuration conf;
101
102  @BeforeAll
103  public static void setup() throws Exception {
104    // Uncomment the following line if more verbosity is needed for
105    // debugging (see HBASE-12285 for details).
106    // Logger.getLogger("org.apache.hadoop.hbase").setLevel(Level.DEBUG);
107    TEST_UTIL.startMiniZKCluster();
108    TEST_UTIL.startMiniDFSCluster(3);
109  }
110
111  @AfterAll
112  public static void tearDown() throws Exception {
113    TEST_UTIL.shutdownMiniCluster();
114  }
115
116  protected abstract String getWalProvider();
117
118  private void startCluster(int numRS) throws Exception {
119    SplitLogCounters.resetCounters();
120    LOG.info("Starting cluster");
121    conf.setLong("hbase.splitlog.max.resubmit", 0);
122    // Make the failure test faster
123    conf.setInt("zookeeper.recovery.retry", 0);
124    conf.setInt(HConstants.REGIONSERVER_INFO_PORT, -1);
125    conf.setFloat(HConstants.LOAD_BALANCER_SLOP_KEY, (float) 100.0); // no load balancing
126    conf.setInt(HBASE_SPLIT_WAL_MAX_SPLITTER, 3);
127    conf.setInt(HConstants.REGION_SERVER_HIGH_PRIORITY_HANDLER_COUNT, 10);
128    conf.set("hbase.wal.provider", getWalProvider());
129    StartTestingClusterOption option =
130      StartTestingClusterOption.builder().numMasters(NUM_MASTERS).numRegionServers(numRS).build();
131    TEST_UTIL.startMiniHBaseCluster(option);
132    cluster = TEST_UTIL.getHBaseCluster();
133    LOG.info("Waiting for active/ready master");
134    cluster.waitForActiveAndReadyMaster();
135    master = cluster.getMaster();
136    TEST_UTIL.waitFor(120000, 200, new Waiter.Predicate<Exception>() {
137      @Override
138      public boolean evaluate() throws Exception {
139        return cluster.getLiveRegionServerThreads().size() >= numRS;
140      }
141    });
142  }
143
144  @BeforeEach
145  public void before(TestInfo testInfo) throws Exception {
146    conf = TEST_UTIL.getConfiguration();
147    tableName = TableName.valueOf(testInfo.getTestMethod().get().getName());
148  }
149
150  @AfterEach
151  public void after() throws Exception {
152    TEST_UTIL.shutdownMiniHBaseCluster();
153    TEST_UTIL.getTestFileSystem().delete(CommonFSUtils.getRootDir(TEST_UTIL.getConfiguration()),
154      true);
155    ZKUtil.deleteNodeRecursively(TEST_UTIL.getZooKeeperWatcher(), "/hbase");
156  }
157
158  @Test
159  public void testMasterStartsUpWithLogSplittingWork() throws Exception {
160    conf.setInt(ServerManager.WAIT_ON_REGIONSERVERS_MINTOSTART, NUM_RS - 1);
161    startCluster(NUM_RS);
162
163    int numRegionsToCreate = 40;
164    int numLogLines = 1000;
165    // turn off load balancing to prevent regions from moving around otherwise
166    // they will consume recovered.edits
167    master.balanceSwitch(false);
168
169    try (Table ht = installTable(numRegionsToCreate)) {
170      HRegionServer hrs = findRSToKill(false);
171      List<RegionInfo> regions = ProtobufUtil.getOnlineRegions(hrs.getRSRpcServices());
172      makeWAL(hrs, regions, numLogLines, 100);
173
174      // abort master
175      abortMaster(cluster);
176
177      // abort RS
178      LOG.info("Aborting region server: " + hrs.getServerName());
179      hrs.abort("testing");
180
181      // wait for abort completes
182      TEST_UTIL.waitFor(120000, 200, new Waiter.Predicate<Exception>() {
183        @Override
184        public boolean evaluate() throws Exception {
185          return cluster.getLiveRegionServerThreads().size() <= NUM_RS - 1;
186        }
187      });
188
189      Thread.sleep(2000);
190      LOG.info("Current Open Regions:" + HBaseTestingUtil.getAllOnlineRegions(cluster).size());
191
192      // wait for abort completes
193      TEST_UTIL.waitFor(120000, 200, new Waiter.Predicate<Exception>() {
194        @Override
195        public boolean evaluate() throws Exception {
196          return (HBaseTestingUtil.getAllOnlineRegions(cluster).size() >= (numRegionsToCreate + 1));
197        }
198      });
199
200      LOG.info("Current Open Regions After Master Node Starts Up:"
201        + HBaseTestingUtil.getAllOnlineRegions(cluster).size());
202
203      assertEquals(numLogLines, TEST_UTIL.countRows(ht));
204    }
205  }
206
207  @Test
208  public void testThreeRSAbort() throws Exception {
209    LOG.info("testThreeRSAbort");
210    int numRegionsToCreate = 40;
211    int numRowsPerRegion = 100;
212
213    startCluster(NUM_RS); // NUM_RS=6.
214
215    try (Table table = installTable(numRegionsToCreate)) {
216      populateDataInTable(numRowsPerRegion);
217
218      List<RegionServerThread> rsts = cluster.getLiveRegionServerThreads();
219      assertEquals(NUM_RS, rsts.size());
220      cluster.killRegionServer(rsts.get(0).getRegionServer().getServerName());
221      cluster.killRegionServer(rsts.get(1).getRegionServer().getServerName());
222      cluster.killRegionServer(rsts.get(2).getRegionServer().getServerName());
223
224      TEST_UTIL.waitFor(60000, new Waiter.ExplainingPredicate<Exception>() {
225
226        @Override
227        public boolean evaluate() throws Exception {
228          return cluster.getLiveRegionServerThreads().size() <= NUM_RS - 3;
229        }
230
231        @Override
232        public String explainFailure() throws Exception {
233          return "Timed out waiting for server aborts.";
234        }
235      });
236      TEST_UTIL.waitUntilAllRegionsAssigned(tableName);
237      int rows;
238      try {
239        rows = TEST_UTIL.countRows(table);
240      } catch (Exception e) {
241        Threads.printThreadInfo(System.out, "Thread dump before fail");
242        throw e;
243      }
244      assertEquals(numRegionsToCreate * numRowsPerRegion, rows);
245    }
246  }
247
248  @Test
249  public void testDelayedDeleteOnFailure() throws Exception {
250    if (
251      !this.conf.getBoolean(HConstants.HBASE_SPLIT_WAL_COORDINATED_BY_ZK,
252        HConstants.DEFAULT_HBASE_SPLIT_COORDINATED_BY_ZK)
253    ) {
254      // This test depends on zk coordination....
255      return;
256    }
257    LOG.info("testDelayedDeleteOnFailure");
258    startCluster(1);
259    final SplitLogManager slm = master.getMasterWalManager().getSplitLogManager();
260    final FileSystem fs = master.getMasterFileSystem().getFileSystem();
261    final Path rootLogDir =
262      new Path(CommonFSUtils.getWALRootDir(conf), HConstants.HREGION_LOGDIR_NAME);
263    final Path logDir = new Path(rootLogDir, ServerName.valueOf("x", 1, 1).toString());
264    fs.mkdirs(logDir);
265    ExecutorService executor = null;
266    try {
267      final Path corruptedLogFile = new Path(logDir, "x");
268      FSDataOutputStream out;
269      out = fs.create(corruptedLogFile);
270      out.write(0);
271      out.write(Bytes.toBytes("corrupted bytes"));
272      out.close();
273      ZKSplitLogManagerCoordination coordination =
274        (ZKSplitLogManagerCoordination) (master.getCoordinatedStateManager())
275          .getSplitLogManagerCoordination();
276      coordination.setIgnoreDeleteForTesting(true);
277      executor = Executors.newSingleThreadExecutor();
278      Runnable runnable = new Runnable() {
279        @Override
280        public void run() {
281          try {
282            // since the logDir is a fake, corrupted one, so the split log worker
283            // will finish it quickly with error, and this call will fail and throw
284            // an IOException.
285            slm.splitLogDistributed(logDir);
286          } catch (IOException ioe) {
287            try {
288              assertTrue(fs.exists(corruptedLogFile));
289              // this call will block waiting for the task to be removed from the
290              // tasks map which is not going to happen since ignoreZKDeleteForTesting
291              // is set to true, until it is interrupted.
292              slm.splitLogDistributed(logDir);
293            } catch (IOException e) {
294              assertTrue(Thread.currentThread().isInterrupted());
295              return;
296            }
297            fail("did not get the expected IOException from the 2nd call");
298          }
299          fail("did not get the expected IOException from the 1st call");
300        }
301      };
302      Future<?> result = executor.submit(runnable);
303      try {
304        result.get(2000, TimeUnit.MILLISECONDS);
305      } catch (TimeoutException te) {
306        // it is ok, expected.
307      }
308      waitForCounter(tot_mgr_wait_for_zk_delete, 0, 1, 10000);
309      executor.shutdownNow();
310      executor = null;
311
312      // make sure the runnable is finished with no exception thrown.
313      result.get();
314    } finally {
315      if (executor != null) {
316        // interrupt the thread in case the test fails in the middle.
317        // it has no effect if the thread is already terminated.
318        executor.shutdownNow();
319      }
320      fs.delete(logDir, true);
321    }
322  }
323
324  private Table installTable(int nrs) throws Exception {
325    return installTable(nrs, 0);
326  }
327
328  private Table installTable(int nrs, int existingRegions) throws Exception {
329    // Create a table with regions
330    byte[] family = Bytes.toBytes("family");
331    LOG.info("Creating table with " + nrs + " regions");
332    Table table = TEST_UTIL.createMultiRegionTable(tableName, family, nrs);
333    int numRegions = -1;
334    try (RegionLocator r = TEST_UTIL.getConnection().getRegionLocator(tableName)) {
335      numRegions = r.getStartKeys().length;
336    }
337    assertEquals(nrs, numRegions);
338    LOG.info("Waiting for no more RIT\n");
339    blockUntilNoRIT();
340    // disable-enable cycle to get rid of table's dead regions left behind
341    // by createMultiRegions
342    assertTrue(TEST_UTIL.getAdmin().isTableEnabled(tableName));
343    LOG.debug("Disabling table\n");
344    TEST_UTIL.getAdmin().disableTable(tableName);
345    LOG.debug("Waiting for no more RIT\n");
346    blockUntilNoRIT();
347    NavigableSet<String> regions = HBaseTestingUtil.getAllOnlineRegions(cluster);
348    LOG.debug("Verifying only catalog region is assigned\n");
349    if (regions.size() != 1) {
350      for (String oregion : regions) {
351        LOG.debug("Region still online: " + oregion);
352      }
353    }
354    assertEquals(1 + existingRegions, regions.size());
355    LOG.debug("Enabling table\n");
356    TEST_UTIL.getAdmin().enableTable(tableName);
357    LOG.debug("Waiting for no more RIT\n");
358    blockUntilNoRIT();
359    LOG.debug("Verifying there are " + numRegions + " assigned on cluster\n");
360    regions = HBaseTestingUtil.getAllOnlineRegions(cluster);
361    assertEquals(numRegions + 1 + existingRegions, regions.size());
362    return table;
363  }
364
365  void populateDataInTable(int nrows) throws Exception {
366    List<RegionServerThread> rsts = cluster.getLiveRegionServerThreads();
367    assertEquals(NUM_RS, rsts.size());
368
369    for (RegionServerThread rst : rsts) {
370      HRegionServer hrs = rst.getRegionServer();
371      List<RegionInfo> hris = ProtobufUtil.getOnlineRegions(hrs.getRSRpcServices());
372      for (RegionInfo hri : hris) {
373        if (hri.getTable().isSystemTable()) {
374          continue;
375        }
376        LOG.debug(
377          "adding data to rs = " + rst.getName() + " region = " + hri.getRegionNameAsString());
378        Region region = hrs.getOnlineRegion(hri.getRegionName());
379        assertTrue(region != null);
380        putData(region, hri.getStartKey(), nrows, Bytes.toBytes("q"), COLUMN_FAMILY);
381      }
382    }
383  }
384
385  public void makeWAL(HRegionServer hrs, List<RegionInfo> regions, int num_edits, int edit_size)
386    throws IOException {
387    makeWAL(hrs, regions, num_edits, edit_size, true);
388  }
389
390  public void makeWAL(HRegionServer hrs, List<RegionInfo> regions, int numEdits, int editSize,
391    boolean cleanShutdown) throws IOException {
392    // remove root and meta region
393    regions.remove(RegionInfoBuilder.FIRST_META_REGIONINFO);
394
395    for (Iterator<RegionInfo> iter = regions.iterator(); iter.hasNext();) {
396      RegionInfo regionInfo = iter.next();
397      if (regionInfo.getTable().isSystemTable()) {
398        iter.remove();
399      }
400    }
401    byte[] value = new byte[editSize];
402
403    List<RegionInfo> hris = new ArrayList<>();
404    for (RegionInfo region : regions) {
405      if (region.getTable() != tableName) {
406        continue;
407      }
408      hris.add(region);
409    }
410    LOG.info("Creating wal edits across " + hris.size() + " regions.");
411    for (int i = 0; i < editSize; i++) {
412      value[i] = (byte) ('a' + (i % 26));
413    }
414    int n = hris.size();
415    int[] counts = new int[n];
416    // sync every ~30k to line up with desired wal rolls
417    final int syncEvery = 30 * 1024 / editSize;
418    MultiVersionConcurrencyControl mvcc = new MultiVersionConcurrencyControl();
419    // HBASE-30335: match the per-region seqid invariant a real WAL preserves so the splitter's
420    // openSeqNum-seeded filter doesn't drop our injected edits as already-flushed.
421    long maxOpen = 0L;
422    for (RegionInfo info : hris) {
423      HRegion r = hrs.getRegion(info.getEncodedName());
424      if (r != null) {
425        maxOpen = Math.max(maxOpen, r.getOpenSeqNum());
426      }
427    }
428    if (maxOpen > 0L) {
429      mvcc.advanceTo(maxOpen);
430    }
431    if (n > 0) {
432      for (int i = 0; i < numEdits; i += 1) {
433        WALEdit e = new WALEdit();
434        RegionInfo curRegionInfo = hris.get(i % n);
435        WAL log = hrs.getWAL(curRegionInfo);
436        byte[] startRow = curRegionInfo.getStartKey();
437        if (startRow == null || startRow.length == 0) {
438          startRow = new byte[] { 0, 0, 0, 0, 1 };
439        }
440        byte[] row = Bytes.incrementBytes(startRow, counts[i % n]);
441        row = Arrays.copyOfRange(row, 3, 8); // use last 5 bytes because
442        // HBaseTestingUtility.createMultiRegions use 5 bytes key
443        byte[] qualifier = Bytes.toBytes("c" + Integer.toString(i));
444        WALEditInternalHelper.addExtendedCell(e,
445          new KeyValue(row, COLUMN_FAMILY, qualifier, EnvironmentEdgeManager.currentTime(), value));
446        log.appendData(curRegionInfo, new WALKeyImpl(curRegionInfo.getEncodedNameAsBytes(),
447          tableName, EnvironmentEdgeManager.currentTime(), mvcc), e);
448        if (0 == i % syncEvery) {
449          log.sync();
450        }
451        counts[i % n] += 1;
452      }
453    }
454    // done as two passes because the regions might share logs. shutdown is idempotent, but sync
455    // will cause errors if done after.
456    for (RegionInfo info : hris) {
457      WAL log = hrs.getWAL(info);
458      log.sync();
459    }
460    if (cleanShutdown) {
461      for (RegionInfo info : hris) {
462        WAL log = hrs.getWAL(info);
463        log.shutdown();
464      }
465    }
466    for (int i = 0; i < n; i++) {
467      LOG.info("region " + hris.get(i).getRegionNameAsString() + " has " + counts[i] + " edits");
468    }
469    return;
470  }
471
472  private void blockUntilNoRIT() throws Exception {
473    TEST_UTIL.waitUntilNoRegionsInTransition(60000);
474  }
475
476  private void putData(Region region, byte[] startRow, int numRows, byte[] qf, byte[]... families)
477    throws IOException {
478    for (int i = 0; i < numRows; i++) {
479      Put put = new Put(Bytes.add(startRow, Bytes.toBytes(i)));
480      for (byte[] family : families) {
481        put.addColumn(family, qf, null);
482      }
483      region.put(put);
484    }
485  }
486
487  private void waitForCounter(LongAdder ctr, long oldval, long newval, long timems)
488    throws InterruptedException {
489    long curt = EnvironmentEdgeManager.currentTime();
490    long endt = curt + timems;
491    while (curt < endt) {
492      if (ctr.sum() == oldval) {
493        Thread.sleep(100);
494        curt = EnvironmentEdgeManager.currentTime();
495      } else {
496        assertEquals(newval, ctr.sum());
497        return;
498      }
499    }
500    fail();
501  }
502
503  private void abortMaster(SingleProcessHBaseCluster cluster) throws InterruptedException {
504    for (MasterThread mt : cluster.getLiveMasterThreads()) {
505      if (mt.getMaster().isActiveMaster()) {
506        mt.getMaster().abort("Aborting for tests", new Exception("Trace info"));
507        mt.join();
508        break;
509      }
510    }
511    LOG.debug("Master is aborted");
512  }
513
514  /**
515   * Find a RS that has regions of a table.
516   * @param hasMetaRegion when true, the returned RS has hbase:meta region as well
517   */
518  private HRegionServer findRSToKill(boolean hasMetaRegion) throws Exception {
519    List<RegionServerThread> rsts = cluster.getLiveRegionServerThreads();
520    List<RegionInfo> regions = null;
521    HRegionServer hrs = null;
522
523    for (RegionServerThread rst : rsts) {
524      hrs = rst.getRegionServer();
525      while (rst.isAlive() && !hrs.isOnline()) {
526        Thread.sleep(100);
527      }
528      if (!rst.isAlive()) {
529        continue;
530      }
531      boolean isCarryingMeta = false;
532      boolean foundTableRegion = false;
533      regions = ProtobufUtil.getOnlineRegions(hrs.getRSRpcServices());
534      for (RegionInfo region : regions) {
535        if (region.isMetaRegion()) {
536          isCarryingMeta = true;
537        }
538        if (region.getTable() == tableName) {
539          foundTableRegion = true;
540        }
541        if (foundTableRegion && (isCarryingMeta || !hasMetaRegion)) {
542          break;
543        }
544      }
545      if (isCarryingMeta && hasMetaRegion) {
546        // clients ask for a RS with META
547        if (!foundTableRegion) {
548          HRegionServer destRS = hrs;
549          // the RS doesn't have regions of the specified table so we need move one to this RS
550          List<RegionInfo> tableRegions = TEST_UTIL.getAdmin().getRegions(tableName);
551          RegionInfo hri = tableRegions.get(0);
552          TEST_UTIL.getAdmin().move(hri.getEncodedNameAsBytes(), destRS.getServerName());
553          // wait for region move completes
554          RegionStates regionStates =
555            TEST_UTIL.getHBaseCluster().getMaster().getAssignmentManager().getRegionStates();
556          TEST_UTIL.waitFor(45000, 200, new Waiter.Predicate<Exception>() {
557            @Override
558            public boolean evaluate() throws Exception {
559              ServerName sn = regionStates.getRegionServerOfRegion(hri);
560              return (sn != null && sn.equals(destRS.getServerName()));
561            }
562          });
563        }
564        return hrs;
565      } else if (hasMetaRegion || isCarryingMeta) {
566        continue;
567      }
568      if (foundTableRegion) {
569        break;
570      }
571    }
572
573    return hrs;
574  }
575}