BatchInserterImpl throws IllegalStateException, not IndexEntryConflictException

[mdoering]

After updating neo4j from 3.2.4 to 3.3.1 the BatchInserter in an embedded neo db now throws IllegalStateException instead of an expected RuntimeException wrapping a IndexEntryConflictException.

The IllegalStateException in neo 3.3.1 is thrown in the finally section of the BatchInserterImpl at line 1019 when the lifecycle is shutdown, masking the previously, correctly thrown RuntimeException due to the broken unique constraint in line 1002.

Stacktrace

Caused by: org.neo4j.kernel.lifecycle.LifecycleException: Component 'org.neo4j.kernel.impl.pagecache.PageCacheLifecycle@3a479fda' failed to transition from stopped to shutting_down. Please see the attached cause exception "Cannot close the PageCache while files are still mapped:
	/private/var/folders/8r/b5mvzy0j4kq97v2vgs59s1600000gn/T/1515283308806-0/schema/index/lucene_native-1.0/8/native-1.0/index-8 (1 mapping)
	/private/var/folders/8r/b5mvzy0j4kq97v2vgs59s1600000gn/T/1515283308806-0/schema/index/lucene_native-1.0/6/native-1.0/index-6 (1 mapping)
	/private/var/folders/8r/b5mvzy0j4kq97v2vgs59s1600000gn/T/1515283308806-0/schema/index/lucene_native-1.0/1/native-1.0/index-1 (1 mapping)".
	at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.shutdown(LifeSupport.java:519)
	at org.neo4j.kernel.lifecycle.LifeSupport.shutdown(LifeSupport.java:206)
	at org.neo4j.unsafe.batchinsert.internal.BatchInserterImpl.shutdown(BatchInserterImpl.java:1019)
	at org.neo4j.unsafe.batchinsert.internal.FileSystemClosingBatchInserter.shutdown(FileSystemClosingBatchInserter.java:184)
	at org.gbif.checklistbank.neo.NeoInserter.close(NeoInserter.java:400)
	at org.gbif.checklistbank.neo.NeoInserterTest.testTaxonIDNotUnique(NeoInserterTest.java:142)
	... 15 more
Caused by: java.lang.IllegalStateException: Cannot close the PageCache while files are still mapped:
	/private/var/folders/8r/b5mvzy0j4kq97v2vgs59s1600000gn/T/1515283308806-0/schema/index/lucene_native-1.0/8/native-1.0/index-8 (1 mapping)
	/private/var/folders/8r/b5mvzy0j4kq97v2vgs59s1600000gn/T/1515283308806-0/schema/index/lucene_native-1.0/6/native-1.0/index-6 (1 mapping)
	/private/var/folders/8r/b5mvzy0j4kq97v2vgs59s1600000gn/T/1515283308806-0/schema/index/lucene_native-1.0/1/native-1.0/index-1 (1 mapping)
	at org.neo4j.io.pagecache.impl.muninn.MuninnPageCache.close(MuninnPageCache.java:553)
	at org.neo4j.kernel.impl.pagecache.PageCacheLifecycle.shutdown(PageCacheLifecycle.java:42)
	at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.shutdown(LifeSupport.java:511)
	... 29 more

Steps to reproduce

The code fragment that used to run fine in neo 3.2.4, taken from https://github.com/gbif/checklistbank/blob/master/checklistbank-cli/src/test/java/org/gbif/checklistbank/neo/NeoInserterTest.java#L96

  try {
      BatchInserter inserter = BatchInserters.inserter(storeDir);
      // define indices
      inserter.createDeferredConstraint(Labels.TAXON).assertPropertyIsUnique(NeoProperties.TAXON_ID).create();
      inserter.createDeferredSchemaIndex(Labels.TAXON).on(NeoProperties.SCIENTIFIC_NAME).create();
      inserter.createDeferredSchemaIndex(Labels.TAXON).on(NeoProperties.CANONICAL_NAME).create();

      // this is when lucene indices are build and thus throws RuntimeExceptions when unique constraints are broken
      // we catch these exceptions below
      inserter.shutdown();
  } catch (RuntimeException e) {
    Throwable t = e.getCause();
    // check if the cause was a broken unique constraint which can only be taxonID in our case
    if (t != null && t instanceof IndexEntryConflictException) {
      IndexEntryConflictException pe = (IndexEntryConflictException) t;
      LOG.error("TaxonID not unique. Value {} used for both node {} and {}", pe.getSinglePropertyValue(), pe.getExistingNodeId(), pe.getAddedNodeId());
      throw new NotUniqueRuntimeException("TaxonID", pe.getSinglePropertyValue());
    } else {
      throw e;
    }
  }

[tinwelint]

There's a lot going on that test. From what I can understand from your comments this is about type of exception thrown from shutdown() when there's a constraint violation building a uniqueness constraint, right?

I produced a small test to do only that, asserting that the cause of the thrown exception is IndexEntyConflictException. It goes like this:

    @Test
    public void shouldThrowCorrectExceptionOnConstraintViolationInShutdown() throws Exception
    {
        // given
        String key = "key";
        BatchInserter inserter = newBatchInserter();
        inserter.createDeferredConstraint( LABEL_ONE ).assertPropertyIsUnique( key ).create();

        inserter.createNode( map( key, "a" ), LABEL_ONE );
        inserter.createNode( map( key, "a" ), LABEL_ONE );

        try
        {
            inserter.shutdown();
        }
        catch ( RuntimeException e )
        {
            Throwable actual = e.getCause();
            assertTrue( actual instanceof IndexEntryConflictException );
        }
    }

It comes out green on 3.3. Am I missing something?

[mdoering]

Yes, your test is doing the right thing. But when I run this with neo4j 3.3.5 I do not get green lights but the mentioned IllegalStateException instead:

import com.google.common.collect.ImmutableMap;
import org.junit.Test;
import org.neo4j.graphdb.Label;
import org.neo4j.kernel.api.exceptions.index.IndexEntryConflictException;
import org.neo4j.unsafe.batchinsert.BatchInserter;
import org.neo4j.unsafe.batchinsert.BatchInserters;

import java.io.File;
import java.nio.file.Files;

import static org.junit.Assert.assertTrue;

public class BatchInserterTest {

  public enum Labels implements Label {
    FOO
  }

  @Test
  public void shouldThrowCorrectExceptionOnConstraintViolationInShutdown() throws Exception {
    // given
    File store = Files.createTempDirectory("neo.").toFile();
    String key = "key";

    try {
      BatchInserter inserter = BatchInserters.inserter(store);
      inserter.createDeferredConstraint(Labels.FOO).assertPropertyIsUnique(key).create();

      inserter.createNode(ImmutableMap.of(key, "a"), Labels.FOO);
      inserter.createNode(ImmutableMap.of(key, "a"), Labels.FOO);
      inserter.shutdown();

    } catch (RuntimeException e) {
      Throwable actual = e.getCause();
      System.out.println(actual);
      assertTrue(actual instanceof IndexEntryConflictException);
    }
  }
}

gives

java.lang.IllegalStateException: Cannot close the PageCache while files are still mapped:
	/private/var/folders/8r/b5mvzy0j4kq97v2vgs59s1600000gn/T/neo.4856079181897070649/schema/index/lucene_native-1.0/1/native-1.0/index-1 (1 mapping)

How can that be different to yours? Does the filesystem play a role? This does not happen with 3.2.4

[tinwelint]

OK so that IllegalStateException seems to be a secondary failure somehow, which gets thrown later when trying to shut down the inserter. Lemme look more closely into that.

[tinwelint]

I find this index repopulation logic in shutdown() code rather peculiar since it's designed so that if one index fails then all fail. I think it'd be much better if shutdown() would just repopulate to the best of its ability, log failures and mark failed indexes as FAILED, but complete normally. Wouldn't you say?

I was able to reproduce btw...

[mdoering]

I fully agree that would be a nice behaviour that allows code to deal with the failed index situation as it likes to