View Javadoc

1   /**
2    * Licensed to the Apache Software Foundation (ASF) under one
3    * or more contributor license agreements.  See the NOTICE file
4    * distributed with this work for additional information
5    * regarding copyright ownership.  The ASF licenses this file
6    * to you under the Apache License, Version 2.0 (the
7    * "License"); you may not use this file except in compliance
8    * with the License.  You may obtain a copy of the License at
9    *
10   *     http://www.apache.org/licenses/LICENSE-2.0
11   *
12   * Unless required by applicable law or agreed to in writing, software
13   * distributed under the License is distributed on an "AS IS" BASIS,
14   * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
15   * See the License for the specific language governing permissions and
16   * limitations under the License.
17   */
18  
19  package org.apache.hadoop.hbase.procedure2.store.wal;
20  
21  import java.io.FileNotFoundException;
22  import java.io.IOException;
23  import java.io.InputStream;
24  import java.io.OutputStream;
25  import java.util.Arrays;
26  import java.util.Comparator;
27  import java.util.Iterator;
28  import java.util.HashSet;
29  import java.util.Set;
30  
31  import org.apache.commons.logging.Log;
32  import org.apache.commons.logging.LogFactory;
33  import org.apache.hadoop.fs.FileSystem;
34  import org.apache.hadoop.fs.FileStatus;
35  import org.apache.hadoop.fs.Path;
36  import org.apache.hadoop.hbase.HBaseCommonTestingUtility;
37  import org.apache.hadoop.hbase.procedure2.Procedure;
38  import org.apache.hadoop.hbase.procedure2.ProcedureTestingUtility;
39  import org.apache.hadoop.hbase.procedure2.ProcedureTestingUtility.LoadCounter;
40  import org.apache.hadoop.hbase.procedure2.ProcedureTestingUtility.TestProcedure;
41  import org.apache.hadoop.hbase.procedure2.SequentialProcedure;
42  import org.apache.hadoop.hbase.procedure2.store.ProcedureStore;
43  import org.apache.hadoop.hbase.procedure2.store.ProcedureStore.ProcedureIterator;
44  import org.apache.hadoop.hbase.testclassification.SmallTests;
45  import org.apache.hadoop.hbase.util.Bytes;
46  import org.apache.hadoop.io.IOUtils;
47  
48  import org.junit.After;
49  import org.junit.Before;
50  import org.junit.Assert;
51  import org.junit.Test;
52  import org.junit.experimental.categories.Category;
53  
54  import static org.junit.Assert.assertEquals;
55  import static org.junit.Assert.assertFalse;
56  import static org.junit.Assert.assertTrue;
57  import static org.junit.Assert.fail;
58  
59  @Category(SmallTests.class)
60  public class TestWALProcedureStore {
61    private static final Log LOG = LogFactory.getLog(TestWALProcedureStore.class);
62  
63    private static final int PROCEDURE_STORE_SLOTS = 1;
64    private static final Procedure NULL_PROC = null;
65  
66    private WALProcedureStore procStore;
67  
68    private HBaseCommonTestingUtility htu;
69    private FileSystem fs;
70    private Path testDir;
71    private Path logDir;
72  
73    @Before
74    public void setUp() throws IOException {
75      htu = new HBaseCommonTestingUtility();
76      testDir = htu.getDataTestDir();
77      fs = testDir.getFileSystem(htu.getConfiguration());
78      assertTrue(testDir.depth() > 1);
79  
80      logDir = new Path(testDir, "proc-logs");
81      procStore = ProcedureTestingUtility.createWalStore(htu.getConfiguration(), fs, logDir);
82      procStore.start(PROCEDURE_STORE_SLOTS);
83      procStore.recoverLease();
84      procStore.load(new LoadCounter());
85    }
86  
87    @After
88    public void tearDown() throws IOException {
89      procStore.stop(false);
90      fs.delete(logDir, true);
91    }
92  
93    private void storeRestart(ProcedureStore.ProcedureLoader loader) throws Exception {
94      ProcedureTestingUtility.storeRestart(procStore, loader);
95    }
96  
97    @Test
98    public void testEmptyRoll() throws Exception {
99      for (int i = 0; i < 10; ++i) {
100       procStore.periodicRollForTesting();
101     }
102     FileStatus[] status = fs.listStatus(logDir);
103     assertEquals(1, status.length);
104   }
105 
106   @Test
107   public void testEmptyLogLoad() throws Exception {
108     LoadCounter loader = new LoadCounter();
109     storeRestart(loader);
110     assertEquals(0, loader.getMaxProcId());
111     assertEquals(0, loader.getLoadedCount());
112     assertEquals(0, loader.getCorruptedCount());
113   }
114 
115   @Test
116   public void testLoad() throws Exception {
117     Set<Long> procIds = new HashSet<>();
118 
119     // Insert something in the log
120     Procedure proc1 = new TestSequentialProcedure();
121     procIds.add(proc1.getProcId());
122     procStore.insert(proc1, null);
123 
124     Procedure proc2 = new TestSequentialProcedure();
125     Procedure[] child2 = new Procedure[2];
126     child2[0] = new TestSequentialProcedure();
127     child2[1] = new TestSequentialProcedure();
128 
129     procIds.add(proc2.getProcId());
130     procIds.add(child2[0].getProcId());
131     procIds.add(child2[1].getProcId());
132     procStore.insert(proc2, child2);
133 
134     // Verify that everything is there
135     verifyProcIdsOnRestart(procIds);
136 
137     // Update and delete something
138     procStore.update(proc1);
139     procStore.update(child2[1]);
140     procStore.delete(child2[1].getProcId());
141     procIds.remove(child2[1].getProcId());
142 
143     // Verify that everything is there
144     verifyProcIdsOnRestart(procIds);
145 
146     // Remove 4 byte from the trailers
147     procStore.stop(false);
148     FileStatus[] logs = fs.listStatus(logDir);
149     assertEquals(3, logs.length);
150     for (int i = 0; i < logs.length; ++i) {
151       corruptLog(logs[i], 4);
152     }
153     verifyProcIdsOnRestart(procIds);
154   }
155 
156   @Test
157   public void testNoTrailerDoubleRestart() throws Exception {
158     // log-0001: proc 0, 1 and 2 are inserted
159     Procedure proc0 = new TestSequentialProcedure();
160     procStore.insert(proc0, null);
161     Procedure proc1 = new TestSequentialProcedure();
162     procStore.insert(proc1, null);
163     Procedure proc2 = new TestSequentialProcedure();
164     procStore.insert(proc2, null);
165     procStore.rollWriterForTesting();
166 
167     // log-0002: proc 1 deleted
168     procStore.delete(proc1.getProcId());
169     procStore.rollWriterForTesting();
170 
171     // log-0003: proc 2 is update
172     procStore.update(proc2);
173     procStore.rollWriterForTesting();
174 
175     // log-0004: proc 2 deleted
176     procStore.delete(proc2.getProcId());
177 
178     // stop the store and remove the trailer
179     procStore.stop(false);
180     FileStatus[] logs = fs.listStatus(logDir);
181     assertEquals(4, logs.length);
182     for (int i = 0; i < logs.length; ++i) {
183       corruptLog(logs[i], 4);
184     }
185 
186     // Test Load 1
187     LoadCounter loader = new LoadCounter();
188     storeRestart(loader);
189     assertEquals(1, loader.getLoadedCount());
190     assertEquals(0, loader.getCorruptedCount());
191 
192     // Test Load 2
193     assertEquals(5, fs.listStatus(logDir).length);
194     loader = new LoadCounter();
195     storeRestart(loader);
196     assertEquals(1, loader.getLoadedCount());
197     assertEquals(0, loader.getCorruptedCount());
198 
199     // remove proc-0
200     procStore.delete(proc0.getProcId());
201     procStore.periodicRollForTesting();
202     assertEquals(1, fs.listStatus(logDir).length);
203     storeRestart(loader);
204   }
205 
206   @Test
207   public void testCorruptedTrailer() throws Exception {
208     // Insert something
209     for (int i = 0; i < 100; ++i) {
210       procStore.insert(new TestSequentialProcedure(), null);
211     }
212 
213     // Stop the store
214     procStore.stop(false);
215 
216     // Remove 4 byte from the trailer
217     FileStatus[] logs = fs.listStatus(logDir);
218     assertEquals(1, logs.length);
219     corruptLog(logs[0], 4);
220 
221     LoadCounter loader = new LoadCounter();
222     storeRestart(loader);
223     assertEquals(100, loader.getLoadedCount());
224     assertEquals(0, loader.getCorruptedCount());
225   }
226 
227   @Test
228   public void testCorruptedEntries() throws Exception {
229     // Insert something
230     for (int i = 0; i < 100; ++i) {
231       procStore.insert(new TestSequentialProcedure(), null);
232     }
233 
234     // Stop the store
235     procStore.stop(false);
236 
237     // Remove some byte from the log
238     // (enough to cut the trailer and corrupt some entries)
239     FileStatus[] logs = fs.listStatus(logDir);
240     assertEquals(1, logs.length);
241     corruptLog(logs[0], 1823);
242 
243     LoadCounter loader = new LoadCounter();
244     storeRestart(loader);
245     assertTrue(procStore.getCorruptedLogs() != null);
246     assertEquals(1, procStore.getCorruptedLogs().size());
247     assertEquals(85, loader.getLoadedCount());
248     assertEquals(0, loader.getCorruptedCount());
249   }
250 
251   @Test
252   public void testCorruptedProcedures() throws Exception {
253     // Insert root-procedures
254     TestProcedure[] rootProcs = new TestProcedure[10];
255     for (int i = 1; i <= rootProcs.length; i++) {
256       rootProcs[i-1] = new TestProcedure(i, 0);
257       procStore.insert(rootProcs[i-1], null);
258       rootProcs[i-1].addStackId(0);
259       procStore.update(rootProcs[i-1]);
260     }
261     // insert root-child txn
262     procStore.rollWriterForTesting();
263     for (int i = 1; i <= rootProcs.length; i++) {
264       TestProcedure b = new TestProcedure(rootProcs.length + i, i);
265       rootProcs[i-1].addStackId(1);
266       procStore.insert(rootProcs[i-1], new Procedure[] { b });
267     }
268     // insert child updates
269     procStore.rollWriterForTesting();
270     for (int i = 1; i <= rootProcs.length; i++) {
271       procStore.update(new TestProcedure(rootProcs.length + i, i));
272     }
273 
274     // Stop the store
275     procStore.stop(false);
276 
277     // the first log was removed,
278     // we have insert-txn and updates in the others so everything is fine
279     FileStatus[] logs = fs.listStatus(logDir);
280     assertEquals(Arrays.toString(logs), 2, logs.length);
281     Arrays.sort(logs, new Comparator<FileStatus>() {
282       @Override
283       public int compare(FileStatus o1, FileStatus o2) {
284         return o1.getPath().getName().compareTo(o2.getPath().getName());
285       }
286     });
287 
288     LoadCounter loader = new LoadCounter();
289     storeRestart(loader);
290     assertEquals(rootProcs.length * 2, loader.getLoadedCount());
291     assertEquals(0, loader.getCorruptedCount());
292 
293     // Remove the second log, we have lost all the root/parent references
294     fs.delete(logs[0].getPath(), false);
295     loader.reset();
296     storeRestart(loader);
297     assertEquals(0, loader.getLoadedCount());
298     assertEquals(rootProcs.length, loader.getCorruptedCount());
299     for (Procedure proc: loader.getCorrupted()) {
300       assertTrue(proc.toString(), proc.getParentProcId() <= rootProcs.length);
301       assertTrue(proc.toString(),
302                   proc.getProcId() > rootProcs.length &&
303                   proc.getProcId() <= (rootProcs.length * 2));
304     }
305   }
306 
307   @Test(timeout=60000)
308   public void testWalReplayOrder_AB_A() throws Exception {
309     /*
310      * | A B | -> | A |
311      */
312     TestProcedure a = new TestProcedure(1, 0);
313     TestProcedure b = new TestProcedure(2, 1);
314 
315     procStore.insert(a, null);
316     a.addStackId(0);
317     procStore.update(a);
318 
319     procStore.insert(a, new Procedure[] { b });
320     b.addStackId(1);
321     procStore.update(b);
322 
323     procStore.rollWriterForTesting();
324 
325     a.addStackId(2);
326     procStore.update(a);
327 
328     storeRestart(new ProcedureStore.ProcedureLoader() {
329       @Override
330       public void setMaxProcId(long maxProcId) {
331         assertEquals(2, maxProcId);
332       }
333 
334       @Override
335       public void load(ProcedureIterator procIter) throws IOException {
336         assertTrue(procIter.hasNext());
337         assertEquals(1, procIter.nextAsProcedureInfo().getProcId());
338         assertTrue(procIter.hasNext());
339         assertEquals(2, procIter.nextAsProcedureInfo().getProcId());
340         assertFalse(procIter.hasNext());
341       }
342 
343       @Override
344       public void handleCorrupted(ProcedureIterator procIter) throws IOException {
345         assertFalse(procIter.hasNext());
346       }
347     });
348   }
349 
350   @Test(timeout=60000)
351   public void testWalReplayOrder_ABC_BAD() throws Exception {
352     /*
353      * | A B C | -> | B A D |
354      */
355     TestProcedure a = new TestProcedure(1, 0);
356     TestProcedure b = new TestProcedure(2, 1);
357     TestProcedure c = new TestProcedure(3, 2);
358     TestProcedure d = new TestProcedure(4, 0);
359 
360     procStore.insert(a, null);
361     a.addStackId(0);
362     procStore.update(a);
363 
364     procStore.insert(a, new Procedure[] { b });
365     b.addStackId(1);
366     procStore.update(b);
367 
368     procStore.insert(b, new Procedure[] { c });
369     b.addStackId(2);
370     procStore.update(b);
371 
372     procStore.rollWriterForTesting();
373 
374     b.addStackId(3);
375     procStore.update(b);
376 
377     a.addStackId(4);
378     procStore.update(a);
379 
380     procStore.insert(d, null);
381     d.addStackId(0);
382     procStore.update(d);
383 
384     storeRestart(new ProcedureStore.ProcedureLoader() {
385       @Override
386       public void setMaxProcId(long maxProcId) {
387         assertEquals(4, maxProcId);
388       }
389 
390       @Override
391       public void load(ProcedureIterator procIter) throws IOException {
392         assertTrue(procIter.hasNext());
393         assertEquals(4, procIter.nextAsProcedureInfo().getProcId());
394         // TODO: This will be multiple call once we do fast-start
395         //assertFalse(procIter.hasNext());
396 
397         assertTrue(procIter.hasNext());
398         assertEquals(1, procIter.nextAsProcedureInfo().getProcId());
399         assertTrue(procIter.hasNext());
400         assertEquals(2, procIter.nextAsProcedureInfo().getProcId());
401         assertTrue(procIter.hasNext());
402         assertEquals(3, procIter.nextAsProcedureInfo().getProcId());
403         assertFalse(procIter.hasNext());
404       }
405 
406       @Override
407       public void handleCorrupted(ProcedureIterator procIter) throws IOException {
408         assertFalse(procIter.hasNext());
409       }
410     });
411   }
412 
413   @Test
414   public void testRollAndRemove() throws IOException {
415     // Insert something in the log
416     Procedure proc1 = new TestSequentialProcedure();
417     procStore.insert(proc1, null);
418 
419     Procedure proc2 = new TestSequentialProcedure();
420     procStore.insert(proc2, null);
421 
422     // roll the log, now we have 2
423     procStore.rollWriterForTesting();
424     assertEquals(2, procStore.getActiveLogs().size());
425 
426     // everything will be up to date in the second log
427     // so we can remove the first one
428     procStore.update(proc1);
429     procStore.update(proc2);
430     assertEquals(1, procStore.getActiveLogs().size());
431 
432     // roll the log, now we have 2
433     procStore.rollWriterForTesting();
434     assertEquals(2, procStore.getActiveLogs().size());
435 
436     // remove everything active
437     // so we can remove all the logs
438     procStore.delete(proc1.getProcId());
439     procStore.delete(proc2.getProcId());
440     assertEquals(1, procStore.getActiveLogs().size());
441   }
442 
443   @Test
444   public void testFileNotFoundDuringLeaseRecovery() throws IOException {
445     TestProcedure[] procs = new TestProcedure[3];
446     for (int i = 0; i < procs.length; ++i) {
447       procs[i] = new TestProcedure(i + 1, 0);
448       procStore.insert(procs[i], null);
449     }
450     procStore.rollWriterForTesting();
451     for (int i = 0; i < procs.length; ++i) {
452       procStore.update(procs[i]);
453       procStore.rollWriterForTesting();
454     }
455     procStore.stop(false);
456 
457     FileStatus[] status = fs.listStatus(logDir);
458     assertEquals(procs.length + 2, status.length);
459 
460     // simulate another active master removing the wals
461     procStore = new WALProcedureStore(htu.getConfiguration(), fs, logDir,
462         new WALProcedureStore.LeaseRecovery() {
463       private int count = 0;
464 
465       @Override
466       public void recoverFileLease(FileSystem fs, Path path) throws IOException {
467         if (++count <= 2) {
468           fs.delete(path, false);
469           LOG.debug("Simulate FileNotFound at count=" + count + " for " + path);
470           throw new FileNotFoundException("test file not found " + path);
471         }
472         LOG.debug("Simulate recoverFileLease() at count=" + count + " for " + path);
473       }
474     });
475 
476     final LoadCounter loader = new LoadCounter();
477     procStore.start(PROCEDURE_STORE_SLOTS);
478     procStore.recoverLease();
479     procStore.load(loader);
480     assertEquals(procs.length, loader.getMaxProcId());
481     assertEquals(procs.length - 1, loader.getRunnableCount());
482     assertEquals(0, loader.getCompletedCount());
483     assertEquals(0, loader.getCorruptedCount());
484   }
485 
486   @Test
487   public void testLoadChildren() throws Exception {
488     TestProcedure a = new TestProcedure(1, 0);
489     TestProcedure b = new TestProcedure(2, 1);
490     TestProcedure c = new TestProcedure(3, 1);
491 
492     // INIT
493     procStore.insert(a, null);
494 
495     // Run A first step
496     a.addStackId(0);
497     procStore.update(a);
498 
499     // Run A second step
500     a.addStackId(1);
501     procStore.insert(a, new Procedure[] { b, c });
502 
503     // Run B first step
504     b.addStackId(2);
505     procStore.update(b);
506 
507     // Run C first and last step
508     c.addStackId(3);
509     procStore.update(c);
510 
511     // Run B second setp
512     b.addStackId(4);
513     procStore.update(b);
514 
515     // back to A
516     a.addStackId(5);
517     a.setFinishedState();
518     procStore.delete(a, new long[] { b.getProcId(), c.getProcId() });
519     restartAndAssert(3, 0, 1, 0);
520   }
521 
522   private void restartAndAssert(long maxProcId, long runnableCount,
523       int completedCount, int corruptedCount) throws Exception {
524     ProcedureTestingUtility.storeRestartAndAssert(procStore, maxProcId,
525       runnableCount, completedCount, corruptedCount);
526   }
527 
528   private void corruptLog(final FileStatus logFile, final long dropBytes)
529       throws IOException {
530     assertTrue(logFile.getLen() > dropBytes);
531     LOG.debug("corrupt log " + logFile.getPath() +
532               " size=" + logFile.getLen() + " drop=" + dropBytes);
533     Path tmpPath = new Path(testDir, "corrupted.log");
534     InputStream in = fs.open(logFile.getPath());
535     OutputStream out =  fs.create(tmpPath);
536     IOUtils.copyBytes(in, out, logFile.getLen() - dropBytes, true);
537     if (!fs.rename(tmpPath, logFile.getPath())) {
538       throw new IOException("Unable to rename");
539     }
540   }
541 
542   private void verifyProcIdsOnRestart(final Set<Long> procIds) throws Exception {
543     LOG.debug("expected: " + procIds);
544     LoadCounter loader = new LoadCounter();
545     storeRestart(loader);
546     assertEquals(procIds.size(), loader.getLoadedCount());
547     assertEquals(0, loader.getCorruptedCount());
548   }
549 
550   private void assertEmptyLogDir() {
551     try {
552       FileStatus[] status = fs.listStatus(logDir);
553       assertTrue("expected empty state-log dir", status == null || status.length == 0);
554     } catch (FileNotFoundException e) {
555       fail("expected the state-log dir to be present: " + logDir);
556     } catch (IOException e) {
557       fail("got en exception on state-log dir list: " + e.getMessage());
558     }
559   }
560 
561   public static class TestSequentialProcedure extends SequentialProcedure<Void> {
562     private static long seqid = 0;
563 
564     public TestSequentialProcedure() {
565       setProcId(++seqid);
566     }
567 
568     @Override
569     protected Procedure[] execute(Void env) { return null; }
570 
571     @Override
572     protected void rollback(Void env) { }
573 
574     @Override
575     protected boolean abort(Void env) { return false; }
576 
577     @Override
578     protected void serializeStateData(final OutputStream stream) throws IOException {
579       long procId = getProcId();
580       if (procId % 2 == 0) {
581         stream.write(Bytes.toBytes(procId));
582       }
583     }
584 
585     @Override
586     protected void deserializeStateData(InputStream stream) throws IOException {
587       long procId = getProcId();
588       if (procId % 2 == 0) {
589         byte[] bProcId = new byte[8];
590         assertEquals(8, stream.read(bProcId));
591         assertEquals(procId, Bytes.toLong(bProcId));
592       } else {
593         assertEquals(0, stream.available());
594       }
595     }
596   }
597 }