LogManagerTest


1   /*-
2    * See the file LICENSE for redistribution information.
3    *
4    * Copyright (c) 2002,2006 Oracle.  All rights reserved.
5    *
6    * $Id: LogManagerTest.java,v 1.67 2006/10/30 21:14:47 bostic Exp $
7    */
8   
9   package com.sleepycat.je.log;
10  
11  import java.io.File  ;
12  import java.io.IOException  ;
13  import java.util.ArrayList  ;
14  import java.util.List  ;
15  
16  import junit.framework.TestCase;
17  
18  import com.sleepycat.je.DatabaseException;
19  import com.sleepycat.je.DbInternal;
20  import com.sleepycat.je.EnvironmentConfig;
21  import com.sleepycat.je.EnvironmentStats;
22  import com.sleepycat.je.StatsConfig;
23  import com.sleepycat.je.config.EnvironmentParams;
24  import com.sleepycat.je.dbi.EnvironmentImpl;
25  import com.sleepycat.je.util.TestUtils;
26  import com.sleepycat.je.utilint.DbLsn;
27  import com.sleepycat.je.utilint.Tracer;
28    
29  /**
30   * Test basic log management.
31   */
32  public class LogManagerTest extends TestCase {
33  
34      static private final boolean DEBUG = false;
35  
36      private FileManager fileManager;
37      private LogManager logManager;
38      private File   envHome;
39      private EnvironmentImpl env;
40  
41      public LogManagerTest() {
42          super();
43          envHome = new File  (System.getProperty(TestUtils.DEST_DIR));
44      }
45  
46      public void setUp()
47      throws DatabaseException, IOException    {
48  
49          TestUtils.removeFiles("Setup", envHome, FileManager.JE_SUFFIX);
50          TestUtils.removeFiles("Setup", envHome, FileManager.DEL_SUFFIX);
51      }
52      
53      public void tearDown()
54      throws IOException  , DatabaseException {
55  
56          TestUtils.removeFiles("TearDown", envHome, FileManager.JE_SUFFIX);
57      }
58  
59      /**
60       * Log and retrieve objects, with log in memory
61       */
62      public void testBasicInMemory()
63      throws DatabaseException {
64  
65          EnvironmentConfig envConfig = TestUtils.initEnvConfig();
66      DbInternal.disableParameterValidation(envConfig);
67          envConfig.setConfigParam(EnvironmentParams.NODE_MAX.getName(), "6");
68          envConfig.setConfigParam
69          (EnvironmentParams.LOG_FILE_MAX.getName(), "1000");
70  
71          envConfig.setAllowCreate(true);
72          env = new EnvironmentImpl(envHome, envConfig);
73          fileManager = env.getFileManager();
74          logManager = env.getLogManager();
75  
76          logAndRetrieve();
77          env.close();
78      }
79  
80      /**
81       * Log and retrieve objects, with log completely flushed to disk
82       */
83      public void testBasicOnDisk()
84      throws Throwable   {
85  
86          try {
87  
88              /* 
89               * Force the buffers and files to be small. The log buffer is
90               * actually too small, will have to grow dynamically. Each file
91               * only holds one test item (each test item is 50 bytes).
92               */
93              EnvironmentConfig envConfig = TestUtils.initEnvConfig();
94          DbInternal.disableParameterValidation(envConfig);
95              envConfig.setConfigParam(
96                              EnvironmentParams.LOG_MEM_SIZE.getName(),
97                  EnvironmentParams.LOG_MEM_SIZE_MIN_STRING);
98              envConfig.setConfigParam(
99                              EnvironmentParams.NUM_LOG_BUFFERS.getName(), "2");
100             envConfig.setConfigParam(
101                             EnvironmentParams.LOG_FILE_MAX.getName(), "79");
102             envConfig.setConfigParam(
103                             EnvironmentParams.NODE_MAX.getName(), "6");
104             envConfig.setConfigParam
105         (EnvironmentParams.JE_LOGGING_LEVEL.getName(), "CONFIG");
106             
107             /* Disable noisy UtilizationProfile database creation. */
108             DbInternal.setCreateUP(envConfig, false);
109             /* Don't checkpoint utilization info for this test. */
110             DbInternal.setCheckpointUP(envConfig, false);
111             /* Don't run the cleaner without a UtilizationProfile. */
112             envConfig.setConfigParam
113                 (EnvironmentParams.ENV_RUN_CLEANER.getName(), "false");
114 
115             /* 
116              * Don't run any daemons, those emit trace messages and other log
117              * entries and mess up our accounting.
118              */
119             turnOffDaemons(envConfig);
120             envConfig.setAllowCreate(true);
121 
122             /* 
123          * Recreate the file manager and log manager w/different configs.
124          */
125             env = new EnvironmentImpl(envHome, envConfig);
126             fileManager = env.getFileManager();
127             logManager = env.getLogManager();
128 
129             logAndRetrieve();
130 
131             /*
132              * Expect 13 je files, 7 to hold logged records, 1 to hold root, 3
133              * to hold recovery messages, 2 for checkpoint records
134              */
135             String  [] names = fileManager.listFiles(FileManager.JE_SUFFIXES);
136             assertEquals("Should be 13 files on disk", 13, names.length);
137         } catch (Throwable   t) {
138             t.printStackTrace();
139             throw t;
140         } finally {
141             env.close();
142         }
143     }
144 
145     /**
146      * Log and retrieve objects, with some of log flushed to disk, some of log
147      * in memory.
148      */
149     public void testComboDiskMemory()
150     throws Throwable   {
151 
152         try {
153 
154             /* 
155              * Force the buffers and files to be small. The log buffer is
156              * actually too small, will have to grow dynamically. Each file
157              * only holds one test item (each test item is 50 bytes)
158              */
159             EnvironmentConfig envConfig = TestUtils.initEnvConfig();
160     DbInternal.disableParameterValidation(envConfig);
161             envConfig.setConfigParam
162         (EnvironmentParams.LOG_MEM_SIZE.getName(),
163          EnvironmentParams.LOG_MEM_SIZE_MIN_STRING);
164             envConfig.setConfigParam
165         (EnvironmentParams.NUM_LOG_BUFFERS.getName(), "2");
166             envConfig.setConfigParam
167         (EnvironmentParams.JE_LOGGING_LEVEL.getName(), "CONFIG");
168             envConfig.setConfigParam(EnvironmentParams.LOG_FILE_MAX.getName(),
169                                      "142");
170             envConfig.setConfigParam(EnvironmentParams.NODE_MAX.getName(),
171                                      "6");
172             
173             /* Disable noisy UtilizationProfile database creation. */
174             DbInternal.setCreateUP(envConfig, false);
175             /* Don't checkpoint utilization info for this test. */
176             DbInternal.setCheckpointUP(envConfig, false);
177             /* Don't run the cleaner without a UtilizationProfile. */
178             envConfig.setConfigParam
179                 (EnvironmentParams.ENV_RUN_CLEANER.getName(), "false");
180 
181             /* 
182              * Don't run the cleaner or the checkpointer daemons, those create
183              * more log entries and mess up our accounting
184              */
185             turnOffDaemons(envConfig);
186             envConfig.setAllowCreate(true);
187 
188             env = new EnvironmentImpl(envHome, envConfig);
189             fileManager = env.getFileManager();
190             logManager = env.getLogManager();
191 
192             logAndRetrieve();
193 
194             /* 
195          * Expect 8 je files, 3 for records, 1 for root, 2 for recovery
196              * message, 2 for checkpoints.
197          */
198             String  [] names = fileManager.listFiles(FileManager.JE_SUFFIXES);
199             assertEquals("Should be 8 files on disk", 8, names.length);
200         } catch (Throwable   t) {
201             t.printStackTrace();
202             throw t;
203         } finally {
204             env.close();
205         }
206     }
207 
208     /**
209      * Log and retrieve objects, with some of log flushed to disk, some
210      * of log in memory. Force the read buffer to be very small
211      */
212     public void testFaultingIn()
213     throws Throwable   {
214 
215         try {
216 
217             /* 
218              * Force the buffers and files to be small. The log buffer is
219              * actually too small, will have to grow dynamically. We read in 32
220              * byte chunks, will have to re-read only holds one test item (each
221              * test item is 50 bytes)
222              */
223             EnvironmentConfig envConfig = TestUtils.initEnvConfig();
224         DbInternal.disableParameterValidation(envConfig);
225             envConfig.setConfigParam
226         (EnvironmentParams.LOG_MEM_SIZE.getName(),
227          EnvironmentParams.LOG_MEM_SIZE_MIN_STRING);
228             envConfig.setConfigParam
229         (EnvironmentParams.NUM_LOG_BUFFERS.getName(), "2");
230             envConfig.setConfigParam
231         (EnvironmentParams.LOG_FILE_MAX.getName(), "200");
232             envConfig.setConfigParam
233         (EnvironmentParams.LOG_FAULT_READ_SIZE.getName(), "32");
234             envConfig.setConfigParam
235         (EnvironmentParams.NODE_MAX.getName(), "6");
236             envConfig.setAllowCreate(true);
237             env = new EnvironmentImpl(envHome, envConfig);
238             fileManager = env.getFileManager();
239             logManager = env.getLogManager();
240 
241             logAndRetrieve();
242         } catch (Throwable   t) {
243             t.printStackTrace();
244             throw t;
245         } finally {
246             env.close();
247         }
248     }
249 
250     /**
251      * Log several objects, retrieve them.
252      */
253     private void logAndRetrieve()
254     throws DatabaseException {
255 
256         /* Make test loggable objects. */
257 
258         List   testRecs = new ArrayList  ();
259         for (int i = 0; i < 10; i++) {
260             testRecs.add(new Tracer("Hello there, rec " + (i+1)));
261         }
262 
263         /* Log three of them, remember their LSNs. */
264         List   testLsns = new ArrayList  ();
265 
266         for (int i = 0; i < 3; i++) {
267             long lsn = logManager.log((Tracer)testRecs.get(i));
268             if (DEBUG) {
269                 System.out.println("i = " + i + " test LSN: file = " +
270                                    DbLsn.getFileNumber(lsn) +
271                                    " offset = " + 
272                                    DbLsn.getFileOffset(lsn));
273             }
274             testLsns.add(new Long  (lsn));
275         }
276 
277         /* Ask for them back, out of order. */
278         assertEquals((Tracer) testRecs.get(2),
279                      (Tracer) logManager.get
280              (DbLsn.longToLsn((Long  ) testLsns.get(2))));
281         assertEquals((Tracer) testRecs.get(0),
282                      (Tracer) logManager.get
283              (DbLsn.longToLsn((Long  ) testLsns.get(0))));
284         assertEquals((Tracer) testRecs.get(1),
285                      (Tracer) logManager.get
286              (DbLsn.longToLsn((Long  ) testLsns.get(1))));
287 
288         /* Intersperse logging and getting. */
289         testLsns.add(new Long  (logManager.log((Tracer)testRecs.get(3))));
290         testLsns.add(new Long  (logManager.log((Tracer)testRecs.get(4))));
291 
292         assertEquals((Tracer) testRecs.get(2),
293                      (Tracer) logManager.get
294              (DbLsn.longToLsn((Long  ) testLsns.get(2))));
295         assertEquals((Tracer) testRecs.get(4),
296                      (Tracer) logManager.get
297              (DbLsn.longToLsn((Long  ) testLsns.get(4))));
298 
299         /* Intersperse logging and getting. */
300         testLsns.add(new Long  (logManager.log((Tracer) testRecs.get(5))));
301         testLsns.add(new Long  (logManager.log((Tracer) testRecs.get(6))));
302         testLsns.add(new Long  (logManager.log((Tracer) testRecs.get(7))));
303 
304         assertEquals((Tracer) testRecs.get(7),
305                      (Tracer) logManager.get
306              (DbLsn.longToLsn((Long  ) testLsns.get(7))));
307         assertEquals((Tracer) testRecs.get(0),
308                      (Tracer) logManager.get
309              (DbLsn.longToLsn((Long  ) testLsns.get(0))));
310         assertEquals((Tracer) testRecs.get(6),
311                      (Tracer) logManager.get
312              (DbLsn.longToLsn((Long  ) testLsns.get(6))));
313     }
314 
315     private void turnOffDaemons(EnvironmentConfig envConfig) {
316         envConfig.setConfigParam(
317                        EnvironmentParams.ENV_RUN_CLEANER.getName(),
318                       "false");
319         envConfig.setConfigParam(
320                        EnvironmentParams.ENV_RUN_CHECKPOINTER.getName(),
321                        "false");
322         envConfig.setConfigParam(
323                        EnvironmentParams.ENV_RUN_EVICTOR.getName(),
324                        "false");
325         envConfig.setConfigParam(
326                        EnvironmentParams.ENV_RUN_INCOMPRESSOR.getName(),
327                        "false");
328     }
329 
330     /**
331      * Log a few items, then hit exceptions. Make sure LSN state is correctly
332      * maintained and that items logged after the exceptions are at the correct
333      * locations on disk.
334      */
335     public void testExceptions()
336     throws Throwable   {
337         
338         int logBufferSize = ((int) EnvironmentParams.LOG_MEM_SIZE_MIN) / 3;
339         int numLogBuffers = 5;
340         int logBufferMemSize = logBufferSize * numLogBuffers;
341         int logFileMax = 1000;
342         int okCounter = 0;
343         
344         try {
345             EnvironmentConfig envConfig = TestUtils.initEnvConfig();
346         DbInternal.disableParameterValidation(envConfig);
347             envConfig.setConfigParam(EnvironmentParams.LOG_MEM_SIZE.getName(),
348                                      new Integer  (logBufferMemSize).toString());
349             envConfig.setConfigParam
350         (EnvironmentParams.NUM_LOG_BUFFERS.getName(), 
351          new Integer  (numLogBuffers).toString());
352             envConfig.setConfigParam
353         (EnvironmentParams.LOG_FILE_MAX.getName(), 
354          new Integer  (logFileMax).toString());
355             envConfig.setConfigParam(
356                             EnvironmentParams.NODE_MAX.getName(), "6");
357             envConfig.setConfigParam
358         (EnvironmentParams.JE_LOGGING_LEVEL.getName(), "SEVERE");
359             
360             /* Disable noisy UtilizationProfile database creation. */
361             DbInternal.setCreateUP(envConfig, false);
362             /* Don't checkpoint utilization info for this test. */
363             DbInternal.setCheckpointUP(envConfig, false);
364             /* Don't run the cleaner without a UtilizationProfile. */
365             envConfig.setConfigParam
366                 (EnvironmentParams.ENV_RUN_CLEANER.getName(), "false");
367 
368             /* 
369              * Don't run any daemons, those emit trace messages and other log
370              * entries and mess up our accounting.
371              */
372             turnOffDaemons(envConfig);
373             envConfig.setAllowCreate(true);
374             env = new EnvironmentImpl(envHome, envConfig);
375             fileManager = env.getFileManager();
376             logManager = env.getLogManager();
377 
378             /* Keep track of items logged and their LSNs. */
379             ArrayList   testRecs = new ArrayList  ();
380             ArrayList   testLsns = new ArrayList  ();
381 
382             /*
383              * Intersperse:
384              * - log successfully
385              * - log w/failure because the item doesn't fit in the log buffer
386              * - have I/O failures writing out the log
387              * Verify that all expected items can be read. Some will come 
388              * from the log buffer pool.
389              * Then close and re-open the environment, to verify that
390              * all log items are faulted from disk
391              */
392             
393             /* Successful log. */
394             addOkayItem(logManager, okCounter++,
395                         testRecs, testLsns, logBufferSize);
396             
397             /* Item that's too big for the log buffers. */
398             attemptTooBigItem(logManager, logBufferSize, testRecs, testLsns);
399 
400             /* Successful log. */
401             addOkayItem(logManager, okCounter++,
402                         testRecs, testLsns, logBufferSize);
403             
404             /* 
405              * This verify read the items from the log buffers. Note before SR
406              * #12638 existed (LSN state not restored properly after exception
407              * because of too-small log buffer), this verify hung.
408              */
409             verifyOkayItems(logManager, testRecs, testLsns, true);
410 
411             /* More successful logs, along with a few too-big items. */
412 
413             for (;okCounter < 23; okCounter++) {
414                 addOkayItem(logManager, okCounter, testRecs,
415                             testLsns, logBufferSize);
416 
417                 if ((okCounter % 4) == 0) {
418                     attemptTooBigItem(logManager, logBufferSize,
419                       testRecs, testLsns);
420                 }
421                 /* 
422                  * If we verify in the loop, sometimes we'll read from disk and
423                  * sometimes from the log buffer pool.
424                  */
425                 verifyOkayItems(logManager, testRecs, testLsns, true);
426             }
427 
428             /* 
429              * Test the case where we flip files and write the old write buffer
430              * out before we try getting a log buffer for the new item. We need
431              * to
432              * 
433              * - hit a log-too-small exceptin
434              * - right after, we need to log an item that is small enough
435              *   to fit in the log buffer but big enough to require that
436              *   we flip to a new file.
437              */
438             long nextLsn = fileManager.getNextLsn();
439             long fileOffset = DbLsn.getFileOffset(nextLsn);
440 
441             assertTrue((logFileMax - fileOffset ) < logBufferSize);
442             attemptTooBigItem(logManager, logBufferSize, testRecs, testLsns);
443             addOkayItem(logManager, okCounter++,
444                         testRecs, testLsns, logBufferSize,
445                         ((int)(logFileMax - fileOffset)));
446             verifyOkayItems(logManager, testRecs, testLsns, true);
447             
448             /* Invoke some i/o exceptions. */
449             for (;okCounter < 50; okCounter++) {
450                 attemptIOException(logManager, fileManager, testRecs,
451                                    testLsns, false);
452                 addOkayItem(logManager, okCounter,
453                             testRecs, testLsns, logBufferSize);
454                 verifyOkayItems(logManager, testRecs, testLsns, false);
455             }
456 
457             /* 
458              * Finally, close this environment and re-open, and read all
459              * expected items from disk.
460              */
461             env.close();
462             envConfig.setAllowCreate(false);
463             env = new EnvironmentImpl(envHome, envConfig);
464             fileManager = env.getFileManager();
465             logManager = env.getLogManager();
466             verifyOkayItems(logManager, testRecs, testLsns, false);
467 
468             /* Check that we read these items off disk. */
469             EnvironmentStats stats = new EnvironmentStats();
470             StatsConfig config = new StatsConfig();
471             logManager.loadStats(config, stats);
472             assertTrue(stats.getNNotResident() >= testRecs.size());
473 
474         } catch (Throwable   t) {
475             t.printStackTrace();
476             throw t;
477         } finally {
478             env.close();
479         }
480     }
481 
482     private void addOkayItem(LogManager logManager,
483                              int tag,
484                              List   testRecs,
485                              List   testLsns,
486                              int logBufferSize,
487                              int fillerLen) 
488         throws DatabaseException {
489 
490         String   filler = new String  (new byte[fillerLen]);
491         Tracer t = new Tracer("okay" + filler + tag );
492         assertTrue(logBufferSize > t.getLogSize());
493         testRecs.add(t);
494         long lsn = logManager.log(t);
495         testLsns.add(new Long  (lsn));
496     }
497 
498     private void addOkayItem(LogManager logManager,
499                              int tag,
500                              List   testRecs,
501                              List   testLsns,
502                              int logBufferSize) 
503         throws DatabaseException {
504 
505         addOkayItem(logManager, tag, testRecs, testLsns, logBufferSize, 0);
506     }
507 
508     private void attemptTooBigItem(LogManager logManager,
509                                    int logBufferSize,
510                                    LoggableObject l,
511                    List   testRecs,
512                    List   testLsns) {
513         assertTrue(l.getLogSize() > logBufferSize);
514 
515         try {
516             long lsn = logManager.log(l);
517         testLsns.add(new Long  (lsn));
518         testRecs.add(l);
519         } catch (DatabaseException expected) {
520             fail("Should not have hit exception.");
521         }
522     }
523     private void attemptTooBigItem(LogManager logManager,
524                                    int logBufferSize,
525                    List   testRecs,
526                    List   testLsns) {
527         String   stuff = "12345679890123456798901234567989012345679890";
528     while (stuff.length() < EnvironmentParams.LOG_MEM_SIZE_MIN) {
529         stuff += stuff;
530     }
531         Tracer t = new Tracer(stuff);
532         attemptTooBigItem(logManager, logBufferSize, t, testRecs, testLsns);
533     }
534 
535     private void attemptIOException(LogManager logManager, 
536                                     FileManager fileManager,
537                                     List   testRecs,
538                                     List   testLsns,
539                                     boolean forceFlush) {
540         Tracer t = new Tracer("ioException");
541         FileManager.IO_EXCEPTION_TESTING = true;
542         try {
543 
544             /*
545              * This object might get flushed to disk -- depend on whether
546              * the ioexception happened before or after the copy into the
547              * log buffer. Both are valid, but the test doesn't yet
548              * know how to differentiate the cases.
549 
550                testLsns.add(new Long(fileManager.getNextLsn()));
551                testRecs.add(t);
552             */
553             logManager.logForceFlush(t, true);
554             fail("expect io exception");
555         } catch (DatabaseException expected) {
556         } finally {
557             FileManager.IO_EXCEPTION_TESTING = false;
558         }
559     }
560 
561     private void verifyOkayItems(LogManager logManager,
562                                  ArrayList   testRecs,
563                                  ArrayList   testLsns,
564                                  boolean checkOrder) 
565         throws DatabaseException {
566 
567         /* read forwards. */
568         for (int i = 0; i < testRecs.size(); i++) {
569             assertEquals((Tracer) testRecs.get(i),
570                          (Tracer) logManager.get
571                          (DbLsn.longToLsn((Long  ) testLsns.get(i))));
572 
573         }
574 
575         /* Make sure LSNs are adjacent */
576         assertEquals(testLsns.size(), testRecs.size());
577 
578         if (checkOrder) {
579 
580             /* 
581          * TODO: sometimes an ioexception entry will make it into the write
582          * buffer, and sometimes it won't. It depends on whether the IO
583          * exception was thrown when before or after the logabble item was
584          * written into the buffer.  I haven't figure out yet how to tell
585          * the difference, so for now, we don't check order in the portion
586          * of the test that issues IO exceptions.
587              */
588             for (int i = 1; i < testLsns.size(); i++) {
589             
590                 long lsn = ((Long  ) testLsns.get(i)).longValue();
591                 long lsnFile = DbLsn.getFileNumber(lsn);
592                 long lsnOffset = DbLsn.getFileOffset(lsn);
593                 long prevLsn = ((Long  ) testLsns.get(i-1)).longValue();
594                 long prevFile = DbLsn.getFileNumber(prevLsn);
595                 long prevOffset = DbLsn.getFileOffset(prevLsn);
596                 if (prevFile == lsnFile) {
597                     assertEquals("item " + i + "prev = " +
598                                  DbLsn.toString(prevLsn) +
599                                  " current=" + DbLsn.toString(lsn), 
600                                  (((Tracer) testRecs.get(i-1)).getLogSize() + 
601                                   LogManager.HEADER_BYTES),
602                                  lsnOffset - prevOffset);
603                 } else {
604                     assertEquals(prevFile+1, lsnFile);
605                     assertEquals(FileManager.firstLogEntryOffset(),
606                                  lsnOffset);
607                 }
608             }
609         }
610 
611         /* read backwards. */
612         for (int i = testRecs.size() - 1; i > -1; i--) {
613             assertEquals((Tracer) testRecs.get(i),
614                          (Tracer) logManager.get
615                          (DbLsn.longToLsn((Long  ) testLsns.get(i))));
616 
617         }
618     }
619 }
620
A to Z: JavaDoc & Examples Daily Java News & Articles Open Source Projects Open Source Codes Free Computer Books Remove Frame
Popular Tags