br1ghtyang / asterixdb

Automatically exported from code.google.com/p/asterixdb
0 stars 0 forks source link

Unequal number of valid Dictionary BTree, Inverted Lists, Deleted BTree, and Bloom Filter files found. Aborting cleanup. #518

Closed GoogleCodeExporter closed 8 years ago

GoogleCodeExporter commented 8 years ago
During the inverted index manual recovery test, the following two different 
exceptions occur sporadically. 
The first one is the same issue as in hyracks  Issue 112:   LSMBTreeMergeTest 
fails sporadically ==> Confirmed by Zach.
The second is another exception. 

What steps will reproduce the problem?

1. insert the following code as specified below into the executeTest() at 
TestUtils.java 

        for (CompilationUnit cUnit : cUnits) {
            testFileCtxs = testCaseCtx.getTestFiles(cUnit);
            expectedResultFileCtxs = testCaseCtx.getExpectedResultFiles(cUnit);

            //------- added code begins ---------------
            if (!(testCaseCtx.getTestCase().getFilePath().equals("dml")
                    && cUnit.getName().equals("scan-insert-inverted-index-ngram-secondary-index"))) {
                continue;
            }
           //-------added code ends ------------------

            for (TestFileContext ctx : testFileCtxs) {
                testFile = ctx.getFile();

2. Set break point as specified below in executeTest() at TestUtils.java

                    switch (ctx.getType()) {
                        case "ddl":
                            TestsUtils.executeDDL(statement);
                            break;
                        case "update":
                            TestsUtils.executeUpdate(statement);
                            break;
                        case "query":
                            try {
                                InputStream resultStream = executeQuery(statement);   <---- Set breakpoint here

3. Run ExecutionTest.java as Debug --> JUnitTest in eclipse.
When the test stops at the above breakpoint, terminate the test process by 
clicking 'red rectangle' button.

4. Comment out the following line in setUp() at ExecutionTest.java

        AsterixPropertiesAccessor apa = new AsterixPropertiesAccessor();
        txnProperties = new AsterixTransactionProperties(apa);

//        deleteTransactionLogs();   <------ comment out this line

        AsterixHyracksIntegrationUtil.init();

5. Run ExecutionTest.java as Debug --> JUnitTest in eclipse.
   Now, You may see the following exceptions sporadically.

What is the expected output? What do you see instead?
--------------------------------------
Exception1:
--------------------------------------
edu.uci.ics.asterix.common.exceptions.ACIDException: 
edu.uci.ics.hyracks.api.exceptions.HyracksDataException: Deleting open file
    at edu.uci.ics.asterix.transaction.management.service.recovery.RecoveryManager.checkpoint(RecoveryManager.java:465)
    at edu.uci.ics.asterix.hyracks.bootstrap.NCApplicationEntryPoint.notifyStartupComplete(NCApplicationEntryPoint.java:163)
    at edu.uci.ics.hyracks.control.nc.NodeControllerService.start(NodeControllerService.java:273)
    at edu.uci.ics.asterix.api.common.AsterixHyracksIntegrationUtil.init(AsterixHyracksIntegrationUtil.java:74)
    at edu.uci.ics.asterix.test.runtime.ExecutionTest.setUp(ExecutionTest.java:63)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:601)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
    at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:27)
    at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
    at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50)
    at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:467)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:683)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:390)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:197)
Caused by: edu.uci.ics.hyracks.api.exceptions.HyracksDataException: Deleting 
open file
    at edu.uci.ics.hyracks.storage.common.buffercache.BufferCache.deleteFile(BufferCache.java:782)
    at edu.uci.ics.hyracks.storage.am.common.impls.AbstractTreeIndex.destroy(AbstractTreeIndex.java:171)
    at edu.uci.ics.hyracks.storage.am.lsm.invertedindex.ondisk.OnDiskInvertedIndex.destroy(OnDiskInvertedIndex.java:208)
    at edu.uci.ics.hyracks.storage.am.lsm.invertedindex.impls.LSMInvertedIndexImmutableComponent.destroy(LSMInvertedIndexImmutableComponent.java:38)
    at edu.uci.ics.hyracks.storage.am.lsm.common.impls.AbstractImmutableLSMComponent.threadExit(AbstractImmutableLSMComponent.java:74)
    at edu.uci.ics.hyracks.storage.am.lsm.common.impls.LSMHarness.exitComponents(LSMHarness.java:104)
    at edu.uci.ics.hyracks.storage.am.lsm.common.impls.LSMHarness.merge(LSMHarness.java:234)
    at edu.uci.ics.hyracks.storage.am.lsm.invertedindex.impls.LSMInvertedIndexAccessor.merge(LSMInvertedIndexAccessor.java:100)
    at edu.uci.ics.hyracks.storage.am.lsm.invertedindex.impls.LSMInvertedIndexMergeOperation.perform(LSMInvertedIndexMergeOperation.java:78)
    at edu.uci.ics.hyracks.storage.am.lsm.common.impls.SynchronousScheduler.scheduleOperation(SynchronousScheduler.java:28)
    at edu.uci.ics.hyracks.storage.am.lsm.invertedindex.impls.LSMInvertedIndex.scheduleMerge(LSMInvertedIndex.java:520)
    at edu.uci.ics.hyracks.storage.am.lsm.common.impls.LSMHarness.scheduleMerge(LSMHarness.java:214)
    at edu.uci.ics.hyracks.storage.am.lsm.invertedindex.impls.LSMInvertedIndexAccessor.scheduleMerge(LSMInvertedIndexAccessor.java:95)
    at edu.uci.ics.asterix.common.context.ConstantMergePolicy.diskComponentAdded(ConstantMergePolicy.java:42)
    at edu.uci.ics.hyracks.storage.am.lsm.common.impls.LSMHarness.flush(LSMHarness.java:202)
    at edu.uci.ics.hyracks.storage.am.lsm.invertedindex.impls.LSMInvertedIndexAccessor.flush(LSMInvertedIndexAccessor.java:89)
    at edu.uci.ics.hyracks.storage.am.lsm.invertedindex.impls.LSMInvertedIndexFlushOperation.perform(LSMInvertedIndexFlushOperation.java:67)
    at edu.uci.ics.hyracks.storage.am.lsm.common.impls.SynchronousScheduler.scheduleOperation(SynchronousScheduler.java:28)
    at edu.uci.ics.hyracks.storage.am.lsm.invertedindex.impls.LSMInvertedIndex.scheduleFlush(LSMInvertedIndex.java:408)
    at edu.uci.ics.hyracks.storage.am.lsm.common.impls.LSMHarness.scheduleFlush(LSMHarness.java:178)
    at edu.uci.ics.hyracks.storage.am.lsm.invertedindex.impls.LSMInvertedIndexAccessor.scheduleFlush(LSMInvertedIndexAccessor.java:84)
    at edu.uci.ics.asterix.transaction.management.service.recovery.RecoveryManager.checkpoint(RecoveryManager.java:463)
    ... 20 more

java.lang.NullPointerException
    at edu.uci.ics.asterix.api.common.AsterixHyracksIntegrationUtil.deinit(AsterixHyracksIntegrationUtil.java:99)
    at edu.uci.ics.asterix.test.runtime.ExecutionTest.tearDown(ExecutionTest.java:77)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:601)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
    at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
    at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50)
    at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:467)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:683)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:390)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:197)

--------------------------------------
Exception2
--------------------------------------
edu.uci.ics.hyracks.api.exceptions.HyracksDataException: Unequal number of 
valid Dictionary BTree, Inverted Lists, Deleted BTree, and Bloom Filter files 
found. Aborting cleanup.
    at edu.uci.ics.hyracks.storage.am.lsm.invertedindex.impls.LSMInvertedIndexFileManager.cleanupAndGetValidFiles(LSMInvertedIndexFileManager.java:119)
    at edu.uci.ics.hyracks.storage.am.lsm.invertedindex.impls.LSMInvertedIndex.activate(LSMInvertedIndex.java:150)
    at edu.uci.ics.asterix.common.context.DatasetLifecycleManager.open(DatasetLifecycleManager.java:154)
    at edu.uci.ics.asterix.transaction.management.service.recovery.RecoveryManager.startRecovery(RecoveryManager.java:325)
    at edu.uci.ics.asterix.hyracks.bootstrap.NCApplicationEntryPoint.start(NCApplicationEntryPoint.java:80)
    at edu.uci.ics.hyracks.control.nc.NodeControllerService.startApplication(NodeControllerService.java:285)
    at edu.uci.ics.hyracks.control.nc.NodeControllerService.start(NodeControllerService.java:231)
    at edu.uci.ics.asterix.api.common.AsterixHyracksIntegrationUtil.init(AsterixHyracksIntegrationUtil.java:74)
    at edu.uci.ics.asterix.test.runtime.ExecutionTest.setUp(ExecutionTest.java:63)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:601)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
    at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:27)
    at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
    at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50)
    at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:467)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:683)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:390)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:197)

java.lang.NullPointerException
    at edu.uci.ics.asterix.api.common.AsterixHyracksIntegrationUtil.deinit(AsterixHyracksIntegrationUtil.java:99)
    at edu.uci.ics.asterix.test.runtime.ExecutionTest.tearDown(ExecutionTest.java:77)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:601)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
    at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
    at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50)
    at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:467)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:683)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:390)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:197)

Please use labels and text to provide additional information.

Original issue reported on code.google.com by kiss...@gmail.com on 6 Jun 2013 at 6:02

GoogleCodeExporter commented 8 years ago
I marked it as Severity-BetaBlocker.

@Sattam, Zach
It's quite reproducible even if it's sporadic. 
I'm investigating this issue, but could you also investigate this if you agree 
this is beta-blocker?

Young-Seok.

Original comment by kiss...@gmail.com on 6 Jun 2013 at 6:07

GoogleCodeExporter commented 8 years ago
@Young-Seok: please look into this issue after you come back from your vacation.

Original comment by che...@gmail.com on 21 Jun 2013 at 9:38

GoogleCodeExporter commented 8 years ago
I will work on this. 

Best,
Young-Seok.

Original comment by kiss...@gmail.com on 24 Jun 2013 at 7:56

GoogleCodeExporter commented 8 years ago
Based on Young-Seok, this issue is not reproducible anymore. The code has 
changed dramatically in the past few months and probably this issue is gone.

Original comment by salsuba...@gmail.com on 22 Nov 2013 at 1:04