View Javadoc

1   /*
2    * Licensed to the Apache Software Foundation (ASF) under one or more
3    * contributor license agreements. See the NOTICE file distributed with this
4    * work for additional information regarding copyright ownership. The ASF
5    * licenses this file to you under the Apache License, Version 2.0 (the
6    * "License"); you may not use this file except in compliance with the License.
7    * You may obtain a copy of the License at
8    *
9    * http://www.apache.org/licenses/LICENSE-2.0
10   *
11   * Unless required by applicable law or agreed to in writing, software
12   * distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
13   * WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
14   * License for the specific language governing permissions and limitations
15   * under the License.
16   */
17  package org.apache.hadoop.hbase.util;
18  
19  import static org.apache.hadoop.hbase.util.test.LoadTestDataGenerator.INCREMENT;
20  import static org.apache.hadoop.hbase.util.test.LoadTestDataGenerator.MUTATE_INFO;
21  
22  import java.io.IOException;
23  import java.util.Arrays;
24  import java.util.Collection;
25  import java.util.HashMap;
26  import java.util.Map;
27  import java.util.Random;
28  import java.util.Set;
29  import java.util.concurrent.atomic.AtomicInteger;
30  import java.util.concurrent.atomic.AtomicLong;
31  
32  import org.apache.commons.logging.Log;
33  import org.apache.commons.logging.LogFactory;
34  import org.apache.hadoop.conf.Configuration;
35  import org.apache.hadoop.hbase.Cell;
36  import org.apache.hadoop.hbase.CellUtil;
37  import org.apache.hadoop.hbase.HBaseTestingUtility;
38  import org.apache.hadoop.hbase.HRegionLocation;
39  import org.apache.hadoop.hbase.RegionLocations;
40  import org.apache.hadoop.hbase.TableName;
41  import org.apache.hadoop.hbase.client.ClusterConnection;
42  import org.apache.hadoop.hbase.client.HConnection;
43  import org.apache.hadoop.hbase.client.HConnectionManager;
44  import org.apache.hadoop.hbase.client.Result;
45  import org.apache.hadoop.hbase.io.compress.Compression.Algorithm;
46  import org.apache.hadoop.hbase.io.encoding.DataBlockEncoding;
47  import org.apache.hadoop.hbase.protobuf.generated.ClientProtos.MutationProto.MutationType;
48  import org.apache.hadoop.hbase.util.test.LoadTestDataGenerator;
49  import org.apache.hadoop.hbase.util.test.LoadTestKVGenerator;
50  import org.apache.hadoop.util.StringUtils;
51  
52  import com.google.common.base.Preconditions;
53  
54  /**
55   * Common base class for reader and writer parts of multi-thread HBase load
56   * test ({@link LoadTestTool}).
57   */
58  public abstract class MultiThreadedAction {
59    private static final Log LOG = LogFactory.getLog(MultiThreadedAction.class);
60  
61    protected final TableName tableName;
62    protected final Configuration conf;
63    protected final HConnection connection; // all reader / writer threads will share this connection
64  
65    protected int numThreads = 1;
66  
67    /** The start key of the key range, inclusive */
68    protected long startKey = 0;
69  
70    /** The end key of the key range, exclusive */
71    protected long endKey = 1;
72  
73    protected AtomicInteger numThreadsWorking = new AtomicInteger();
74    protected AtomicLong numKeys = new AtomicLong();
75    protected AtomicLong numCols = new AtomicLong();
76    protected AtomicLong totalOpTimeMs = new AtomicLong();
77    protected boolean verbose = false;
78  
79    protected LoadTestDataGenerator dataGenerator = null;
80  
81    /**
82     * Default implementation of LoadTestDataGenerator that uses LoadTestKVGenerator, fixed
83     * set of column families, and random number of columns in range. The table for it can
84     * be created manually or, for example, via
85     * {@link HBaseTestingUtility#createPreSplitLoadTestTable(
86     * org.apache.hadoop.hbase.Configuration, byte[], byte[], Algorithm, DataBlockEncoding)}
87     */
88    public static class DefaultDataGenerator extends LoadTestDataGenerator {
89      private byte[][] columnFamilies = null;
90      private int minColumnsPerKey;
91      private int maxColumnsPerKey;
92      private final Random random = new Random();
93  
94      public DefaultDataGenerator(int minValueSize, int maxValueSize,
95          int minColumnsPerKey, int maxColumnsPerKey, byte[]... columnFamilies) {
96        super(minValueSize, maxValueSize);
97        this.columnFamilies = columnFamilies;
98        this.minColumnsPerKey = minColumnsPerKey;
99        this.maxColumnsPerKey = maxColumnsPerKey;
100     }
101 
102     public DefaultDataGenerator(byte[]... columnFamilies) {
103       // Default values for tests that didn't care to provide theirs.
104       this(256, 1024, 1, 10, columnFamilies);
105     }
106 
107     @Override
108     public byte[] getDeterministicUniqueKey(long keyBase) {
109       return LoadTestKVGenerator.md5PrefixedKey(keyBase).getBytes();
110     }
111 
112     @Override
113     public byte[][] getColumnFamilies() {
114       return columnFamilies;
115     }
116 
117     @Override
118     public byte[][] generateColumnsForCf(byte[] rowKey, byte[] cf) {
119       int numColumns = minColumnsPerKey + random.nextInt(maxColumnsPerKey - minColumnsPerKey + 1);
120       byte[][] columns = new byte[numColumns][];
121       for (int i = 0; i < numColumns; ++i) {
122         columns[i] = Integer.toString(i).getBytes();
123       }
124       return columns;
125     }
126 
127     @Override
128     public byte[] generateValue(byte[] rowKey, byte[] cf, byte[] column) {
129       return kvGenerator.generateRandomSizeValue(rowKey, cf, column);
130     }
131 
132     @Override
133     public boolean verify(byte[] rowKey, byte[] cf, byte[] column, byte[] value) {
134       return LoadTestKVGenerator.verify(value, rowKey, cf, column);
135     }
136 
137     @Override
138     public boolean verify(byte[] rowKey, byte[] cf, Set<byte[]> columnSet) {
139       return (columnSet.size() >= minColumnsPerKey) && (columnSet.size() <= maxColumnsPerKey);
140     }
141   }
142 
143   /** "R" or "W" */
144   private String actionLetter;
145 
146   /** Whether we need to print out Hadoop Streaming-style counters */
147   private boolean streamingCounters;
148 
149   public static final int REPORTING_INTERVAL_MS = 5000;
150 
151   public MultiThreadedAction(LoadTestDataGenerator dataGen, Configuration conf,
152                              TableName tableName,
153                              String actionLetter) throws IOException {
154     this.conf = conf;
155     this.dataGenerator = dataGen;
156     this.tableName = tableName;
157     this.actionLetter = actionLetter;
158     this.connection = HConnectionManager.createConnection(conf);
159   }
160 
161   public void start(long startKey, long endKey, int numThreads) throws IOException {
162     this.startKey = startKey;
163     this.endKey = endKey;
164     this.numThreads = numThreads;
165     (new Thread(new ProgressReporter(actionLetter),
166         "MultiThreadedAction-ProgressReporter-" + System.currentTimeMillis())).start();
167   }
168 
169   private static String formatTime(long elapsedTime) {
170     String format = String.format("%%0%dd", 2);
171     elapsedTime = elapsedTime / 1000;
172     String seconds = String.format(format, elapsedTime % 60);
173     String minutes = String.format(format, (elapsedTime % 3600) / 60);
174     String hours = String.format(format, elapsedTime / 3600);
175     String time =  hours + ":" + minutes + ":" + seconds;
176     return time;
177   }
178 
179   /** Asynchronously reports progress */
180   private class ProgressReporter implements Runnable {
181 
182     private String reporterId = "";
183 
184     public ProgressReporter(String id) {
185       this.reporterId = id;
186     }
187 
188     @Override
189     public void run() {
190       long startTime = System.currentTimeMillis();
191       long priorNumKeys = 0;
192       long priorCumulativeOpTime = 0;
193       int priorAverageKeysPerSecond = 0;
194 
195       // Give other threads time to start.
196       Threads.sleep(REPORTING_INTERVAL_MS);
197 
198       while (numThreadsWorking.get() != 0) {
199         String threadsLeft =
200             "[" + reporterId + ":" + numThreadsWorking.get() + "] ";
201         if (numKeys.get() == 0) {
202           LOG.info(threadsLeft + "Number of keys = 0");
203         } else {
204           long numKeys = MultiThreadedAction.this.numKeys.get();
205           long time = System.currentTimeMillis() - startTime;
206           long totalOpTime = totalOpTimeMs.get();
207 
208           long numKeysDelta = numKeys - priorNumKeys;
209           long totalOpTimeDelta = totalOpTime - priorCumulativeOpTime;
210 
211           double averageKeysPerSecond =
212               (time > 0) ? (numKeys * 1000 / time) : 0;
213 
214           LOG.info(threadsLeft
215               + "Keys="
216               + numKeys
217               + ", cols="
218               + StringUtils.humanReadableInt(numCols.get())
219               + ", time="
220               + formatTime(time)
221               + ((numKeys > 0 && time > 0) ? (" Overall: [" + "keys/s= "
222                   + numKeys * 1000 / time + ", latency=" + totalOpTime
223                   / numKeys + " ms]") : "")
224               + ((numKeysDelta > 0) ? (" Current: [" + "keys/s="
225                   + numKeysDelta * 1000 / REPORTING_INTERVAL_MS + ", latency="
226                   + totalOpTimeDelta / numKeysDelta + " ms]") : "")
227               + progressInfo());
228 
229           if (streamingCounters) {
230             printStreamingCounters(numKeysDelta,
231                 averageKeysPerSecond - priorAverageKeysPerSecond);
232           }
233 
234           priorNumKeys = numKeys;
235           priorCumulativeOpTime = totalOpTime;
236           priorAverageKeysPerSecond = (int) averageKeysPerSecond;
237         }
238 
239         Threads.sleep(REPORTING_INTERVAL_MS);
240       }
241     }
242 
243     private void printStreamingCounters(long numKeysDelta,
244         double avgKeysPerSecondDelta) {
245       // Write stats in a format that can be interpreted as counters by
246       // streaming map-reduce jobs.
247       System.err.println("reporter:counter:numKeys," + reporterId + ","
248           + numKeysDelta);
249       System.err.println("reporter:counter:numCols," + reporterId + ","
250           + numCols.get());
251       System.err.println("reporter:counter:avgKeysPerSecond," + reporterId
252           + "," + (long) (avgKeysPerSecondDelta));
253     }
254   }
255 
256   public void close() {
257     if (connection != null) {
258       try {
259         connection.close();
260       } catch (Exception ex) {
261         LOG.warn("Could not close the connection: " + ex);
262       }
263     }
264   }
265 
266   public void waitForFinish() {
267     while (numThreadsWorking.get() != 0) {
268       Threads.sleepWithoutInterrupt(1000);
269     }
270     close();
271   }
272 
273   public boolean isDone() {
274     return (numThreadsWorking.get() == 0);
275   }
276 
277   protected void startThreads(Collection<? extends Thread> threads) {
278     numThreadsWorking.addAndGet(threads.size());
279     for (Thread thread : threads) {
280       thread.start();
281     }
282   }
283 
284   /** @return the end key of the key range, exclusive */
285   public long getEndKey() {
286     return endKey;
287   }
288 
289   /** Returns a task-specific progress string */
290   protected abstract String progressInfo();
291 
292   protected static void appendToStatus(StringBuilder sb, String desc,
293       long v) {
294     if (v == 0) {
295       return;
296     }
297     sb.append(", ");
298     sb.append(desc);
299     sb.append("=");
300     sb.append(v);
301   }
302 
303   protected static void appendToStatus(StringBuilder sb, String desc,
304       String v) {
305     sb.append(", ");
306     sb.append(desc);
307     sb.append("=");
308     sb.append(v);
309   }
310 
311   /**
312    * See {@link #verifyResultAgainstDataGenerator(Result, boolean, boolean)}.
313    * Does not verify cf/column integrity.
314    */
315   public boolean verifyResultAgainstDataGenerator(Result result, boolean verifyValues) {
316     return verifyResultAgainstDataGenerator(result, verifyValues, false);
317   }
318 
319   /**
320    * Verifies the result from get or scan using the dataGenerator (that was presumably
321    * also used to generate said result).
322    * @param verifyValues verify that values in the result make sense for row/cf/column combination
323    * @param verifyCfAndColumnIntegrity verify that cf/column set in the result is complete. Note
324    *                                   that to use this multiPut should be used, or verification
325    *                                   has to happen after writes, otherwise there can be races.
326    * @return
327    */
328   public boolean verifyResultAgainstDataGenerator(Result result, boolean verifyValues,
329       boolean verifyCfAndColumnIntegrity) {
330     String rowKeyStr = Bytes.toString(result.getRow());
331     // See if we have any data at all.
332     if (result.isEmpty()) {
333       LOG.error("Error checking data for key [" + rowKeyStr + "], no data returned");
334       printLocations(result);
335       return false;
336     }
337 
338     if (!verifyValues && !verifyCfAndColumnIntegrity) {
339       return true; // as long as we have something, we are good.
340     }
341 
342     // See if we have all the CFs.
343     byte[][] expectedCfs = dataGenerator.getColumnFamilies();
344     if (verifyCfAndColumnIntegrity && (expectedCfs.length != result.getMap().size())) {
345       LOG.error("Error checking data for key [" + rowKeyStr
346         + "], bad family count: " + result.getMap().size());
347       printLocations(result);
348       return false;
349     }
350 
351     // Verify each column family from get in the result.
352     for (byte[] cf : result.getMap().keySet()) {
353       String cfStr = Bytes.toString(cf);
354       Map<byte[], byte[]> columnValues = result.getFamilyMap(cf);
355       if (columnValues == null) {
356         LOG.error("Error checking data for key [" + rowKeyStr
357           + "], no data for family [" + cfStr + "]]");
358         printLocations(result);
359         return false;
360       }
361 
362       Map<String, MutationType> mutateInfo = null;
363       if (verifyCfAndColumnIntegrity || verifyValues) {
364         if (!columnValues.containsKey(MUTATE_INFO)) {
365           LOG.error("Error checking data for key [" + rowKeyStr + "], column family ["
366             + cfStr + "], column [" + Bytes.toString(MUTATE_INFO) + "]; value is not found");
367           printLocations(result);
368           return false;
369         }
370 
371         long cfHash = Arrays.hashCode(cf);
372         // Verify deleted columns, and make up column counts if deleted
373         byte[] mutateInfoValue = columnValues.remove(MUTATE_INFO);
374         mutateInfo = parseMutateInfo(mutateInfoValue);
375         for (Map.Entry<String, MutationType> mutate: mutateInfo.entrySet()) {
376           if (mutate.getValue() == MutationType.DELETE) {
377             byte[] column = Bytes.toBytes(mutate.getKey());
378             long columnHash = Arrays.hashCode(column);
379             long hashCode = cfHash + columnHash;
380             if (hashCode % 2 == 0) {
381               if (columnValues.containsKey(column)) {
382                 LOG.error("Error checking data for key [" + rowKeyStr + "], column family ["
383                   + cfStr + "], column [" + mutate.getKey() + "]; should be deleted");
384                 printLocations(result);
385                 return false;
386               }
387               byte[] hashCodeBytes = Bytes.toBytes(hashCode);
388               columnValues.put(column, hashCodeBytes);
389             }
390           }
391         }
392 
393         // Verify increment
394         if (!columnValues.containsKey(INCREMENT)) {
395           LOG.error("Error checking data for key [" + rowKeyStr + "], column family ["
396             + cfStr + "], column [" + Bytes.toString(INCREMENT) + "]; value is not found");
397           printLocations(result);
398           return false;
399         }
400         long currentValue = Bytes.toLong(columnValues.remove(INCREMENT));
401         if (verifyValues) {
402           long amount = mutateInfo.isEmpty() ? 0 : cfHash;
403           long originalValue = Arrays.hashCode(result.getRow());
404           long extra = currentValue - originalValue;
405           if (extra != 0 && (amount == 0 || extra % amount != 0)) {
406             LOG.error("Error checking data for key [" + rowKeyStr + "], column family ["
407               + cfStr + "], column [increment], extra [" + extra + "], amount [" + amount + "]");
408             printLocations(result);
409             return false;
410           }
411           if (amount != 0 && extra != amount) {
412             LOG.warn("Warning checking data for key [" + rowKeyStr + "], column family ["
413               + cfStr + "], column [increment], incremented [" + (extra / amount) + "] times");
414           }
415         }
416 
417         // See if we have correct columns.
418         if (verifyCfAndColumnIntegrity
419             && !dataGenerator.verify(result.getRow(), cf, columnValues.keySet())) {
420           String colsStr = "";
421           for (byte[] col : columnValues.keySet()) {
422             if (colsStr.length() > 0) {
423               colsStr += ", ";
424             }
425             colsStr += "[" + Bytes.toString(col) + "]";
426           }
427           LOG.error("Error checking data for key [" + rowKeyStr
428             + "], bad columns for family [" + cfStr + "]: " + colsStr);
429           printLocations(result);
430           return false;
431         }
432         // See if values check out.
433         if (verifyValues) {
434           for (Map.Entry<byte[], byte[]> kv : columnValues.entrySet()) {
435             String column = Bytes.toString(kv.getKey());
436             MutationType mutation = mutateInfo.get(column);
437             boolean verificationNeeded = true;
438             byte[] bytes = kv.getValue();
439             if (mutation != null) {
440               boolean mutationVerified = true;
441               long columnHash = Arrays.hashCode(kv.getKey());
442               long hashCode = cfHash + columnHash;
443               byte[] hashCodeBytes = Bytes.toBytes(hashCode);
444               if (mutation == MutationType.APPEND) {
445                 int offset = bytes.length - hashCodeBytes.length;
446                 mutationVerified = offset > 0 && Bytes.equals(hashCodeBytes,
447                   0, hashCodeBytes.length, bytes, offset, hashCodeBytes.length);
448                 if (mutationVerified) {
449                   int n = 1;
450                   while (true) {
451                     int newOffset = offset - hashCodeBytes.length;
452                     if (newOffset < 0 || !Bytes.equals(hashCodeBytes, 0,
453                         hashCodeBytes.length, bytes, newOffset, hashCodeBytes.length)) {
454                       break;
455                     }
456                     offset = newOffset;
457                     n++;
458                   }
459                   if (n > 1) {
460                     LOG.warn("Warning checking data for key [" + rowKeyStr + "], column family ["
461                       + cfStr + "], column [" + column + "], appended [" + n + "] times");
462                   }
463                   byte[] dest = new byte[offset];
464                   System.arraycopy(bytes, 0, dest, 0, offset);
465                   bytes = dest;
466                 }
467               } else if (hashCode % 2 == 0) { // checkAndPut
468                 mutationVerified = Bytes.equals(bytes, hashCodeBytes);
469                 verificationNeeded = false;
470               }
471               if (!mutationVerified) {
472                 LOG.error("Error checking data for key [" + rowKeyStr
473                   + "], mutation checking failed for column family [" + cfStr + "], column ["
474                   + column + "]; mutation [" + mutation + "], hashCode ["
475                   + hashCode + "], verificationNeeded ["
476                   + verificationNeeded + "]");
477                 printLocations(result);
478                 return false;
479               }
480             } // end of mutation checking
481             if (verificationNeeded &&
482                 !dataGenerator.verify(result.getRow(), cf, kv.getKey(), bytes)) {
483               LOG.error("Error checking data for key [" + rowKeyStr + "], column family ["
484                 + cfStr + "], column [" + column + "], mutation [" + mutation
485                 + "]; value of length " + bytes.length);
486               printLocations(result);
487               return false;
488             }
489           }
490         }
491       }
492     }
493     return true;
494   }
495 
496   private void printLocations(Result r) {
497     RegionLocations rl = null;
498     if (r == null) {
499       LOG.info("FAILED FOR null Result");
500       return;
501     }
502     LOG.info("FAILED FOR " + resultToString(r) + " Stale " + r.isStale());
503     if (r.getRow() == null) {
504       return;
505     }
506     try {
507       rl = ((ClusterConnection)connection).locateRegion(tableName, r.getRow(), true, true);
508     } catch (IOException e) {
509       LOG.warn("Couldn't get locations for row " + Bytes.toString(r.getRow()));
510     }
511     HRegionLocation locations[] = rl.getRegionLocations();
512     for (HRegionLocation h : locations) {
513       LOG.info("LOCATION " + h);
514     }
515   }
516 
517   private String resultToString(Result result) {
518     StringBuilder sb = new StringBuilder();
519     sb.append("cells=");
520     if(result.isEmpty()) {
521       sb.append("NONE");
522       return sb.toString();
523     }
524     sb.append("{");
525     boolean moreThanOne = false;
526     for(Cell cell : result.listCells()) {
527       if(moreThanOne) {
528         sb.append(", ");
529       } else {
530         moreThanOne = true;
531       }
532       sb.append(CellUtil.toString(cell, true));
533     }
534     sb.append("}");
535     return sb.toString();
536   }
537 
538   // Parse mutate info into a map of <column name> => <update action>
539   private Map<String, MutationType> parseMutateInfo(byte[] mutateInfo) {
540     Map<String, MutationType> mi = new HashMap<String, MutationType>();
541     if (mutateInfo != null) {
542       String mutateInfoStr = Bytes.toString(mutateInfo);
543       String[] mutations = mutateInfoStr.split("#");
544       for (String mutation: mutations) {
545         if (mutation.isEmpty()) continue;
546         Preconditions.checkArgument(mutation.contains(":"),
547           "Invalid mutation info " + mutation);
548         int p = mutation.indexOf(":");
549         String column = mutation.substring(0, p);
550         MutationType type = MutationType.valueOf(
551           Integer.parseInt(mutation.substring(p+1)));
552         mi.put(column, type);
553       }
554     }
555     return mi;
556   }
557 }