From 000d08babe7b468422a5cdf43514cff841df6f8f Mon Sep 17 00:00:00 2001 From: tinwelint Date: Mon, 23 Jan 2017 11:34:30 +0100 Subject: [PATCH] Includes stack trace of unexpected checker dispatch error Previously only the exception message was logged into the consistency report. This in addition to the exception being swallowed created second failures that were hard to find root cause of. --- .../PropertyAndNode2LabelIndexProcessor.java | 15 ++++- .../report/ConsistencyReporter.java | 6 +- .../report/ConsistencyReporterTest.java | 62 +++++++++++++++++++ 3 files changed, 79 insertions(+), 4 deletions(-) diff --git a/community/consistency-check/src/main/java/org/neo4j/consistency/checking/full/PropertyAndNode2LabelIndexProcessor.java b/community/consistency-check/src/main/java/org/neo4j/consistency/checking/full/PropertyAndNode2LabelIndexProcessor.java index 5443716cc72af..c4e430e59d979 100644 --- a/community/consistency-check/src/main/java/org/neo4j/consistency/checking/full/PropertyAndNode2LabelIndexProcessor.java +++ b/community/consistency-check/src/main/java/org/neo4j/consistency/checking/full/PropertyAndNode2LabelIndexProcessor.java @@ -64,10 +64,19 @@ public void process( NodeRecord nodeRecord ) try ( MandatoryProperties.Check mandatoryCheck = mandatoryProperties.apply( nodeRecord ) ) { - for ( PropertyRecord property : client.getPropertiesFromCache() ) + Iterable properties = client.getPropertiesFromCache(); + + // We do this null-check here because even if nodeIndexCheck should provide the properties for us, + // or an empty list at least, it may fail in one way or another and exception be caught by + // broad exception handler in reporter. The caught exception will produce an ERROR so it will not + // go by unnoticed. + if ( properties != null ) { - reporter.forProperty( property, propertyCheck ); - mandatoryCheck.receive( ChainCheck.keys( property ) ); + for ( PropertyRecord property : properties ) + { + reporter.forProperty( property, propertyCheck ); + mandatoryCheck.receive( ChainCheck.keys( property ) ); + } } } } diff --git a/community/consistency-check/src/main/java/org/neo4j/consistency/report/ConsistencyReporter.java b/community/consistency-check/src/main/java/org/neo4j/consistency/report/ConsistencyReporter.java index 91b936693a0ea..ffdfcaabb1507 100644 --- a/community/consistency-check/src/main/java/org/neo4j/consistency/report/ConsistencyReporter.java +++ b/community/consistency-check/src/main/java/org/neo4j/consistency/report/ConsistencyReporter.java @@ -53,6 +53,7 @@ import static java.util.Arrays.asList; import static org.neo4j.helpers.Exceptions.launderedException; +import static org.neo4j.helpers.Exceptions.stringify; import static org.neo4j.helpers.Exceptions.withCause; public class ConsistencyReporter implements ConsistencyReport.Reporter @@ -126,7 +127,10 @@ void dispatch( RecordType type, ProxyFactory factory, RECORD record, Rec } catch ( Exception e ) { - handler.report.error( type, record, "Failed to check record: " + e.getMessage(), new Object[0] ); + // This is a rare event and exposing the stack trace is a good idea, otherwise we + // can only see that something went wrong, not at all what. + handler.report.error( type, record, "Failed to check record: " + stringify( e ), + new Object[0] ); } handler.updateSummary(); } diff --git a/community/consistency-check/src/test/java/org/neo4j/consistency/report/ConsistencyReporterTest.java b/community/consistency-check/src/test/java/org/neo4j/consistency/report/ConsistencyReporterTest.java index e4b9a2ea2c869..f8a9897aee8f2 100644 --- a/community/consistency-check/src/test/java/org/neo4j/consistency/report/ConsistencyReporterTest.java +++ b/community/consistency-check/src/test/java/org/neo4j/consistency/report/ConsistencyReporterTest.java @@ -24,6 +24,7 @@ import org.hamcrest.TypeSafeMatcher; import org.junit.Rule; import org.junit.Test; +import org.junit.rules.TestName; import org.junit.rules.TestRule; import org.junit.runner.RunWith; import org.junit.runners.Parameterized; @@ -38,11 +39,13 @@ import java.lang.reflect.Type; import java.util.ArrayList; import java.util.List; +import java.util.concurrent.atomic.AtomicReference; import org.neo4j.consistency.RecordType; import org.neo4j.consistency.checking.CheckerEngine; import org.neo4j.consistency.checking.ComparativeRecordChecker; import org.neo4j.consistency.checking.RecordCheck; +import org.neo4j.consistency.report.ConsistencyReport.NodeConsistencyReport; import org.neo4j.consistency.store.RecordAccess; import org.neo4j.consistency.store.RecordReference; import org.neo4j.consistency.store.synthetic.CountsEntry; @@ -64,9 +67,14 @@ import org.neo4j.kernel.impl.store.record.RelationshipTypeTokenRecord; import org.neo4j.kernel.impl.store.record.SchemaRule; +import static org.hamcrest.Matchers.containsString; +import static org.junit.Assert.assertNotNull; +import static org.junit.Assert.assertThat; +import static org.junit.Assert.assertTrue; import static org.mockito.Matchers.any; import static org.mockito.Matchers.argThat; import static org.mockito.Mockito.doAnswer; +import static org.mockito.Mockito.doThrow; import static org.mockito.Mockito.mock; import static org.mockito.Mockito.verify; import static org.mockito.Mockito.verifyNoMoreInteractions; @@ -84,6 +92,9 @@ public class ConsistencyReporterTest { public static class TestReportLifecycle { + @Rule + public final TestName testName = new TestName(); + @Test public void shouldSummarizeStatisticsAfterCheck() { @@ -139,6 +150,57 @@ public void shouldOnlySummarizeStatisticsWhenAllReferencesAreChecked() verify( summary ).update( RecordType.PROPERTY, 0, 0 ); verifyNoMoreInteractions( summary ); } + + @Test + public void shouldIncludeStackTraceInUnexpectedCheckException() throws Exception + { + // GIVEN + ConsistencySummaryStatistics summary = mock( ConsistencySummaryStatistics.class ); + RecordAccess records = mock( RecordAccess.class ); + final AtomicReference loggedError = new AtomicReference<>(); + InconsistencyLogger logger = new InconsistencyLogger() + { + @Override + public void error( RecordType recordType, AbstractBaseRecord record, String message, Object[] args ) + { + assertTrue( loggedError.compareAndSet( null, message ) ); + } + + @Override + public void error( RecordType recordType, AbstractBaseRecord oldRecord, AbstractBaseRecord newRecord, + String message, Object[] args ) + { + assertTrue( loggedError.compareAndSet( null, message ) ); + } + + @Override + public void warning( RecordType recordType, AbstractBaseRecord record, String message, Object[] args ) + { + } + + @Override + public void warning( RecordType recordType, AbstractBaseRecord oldRecord, AbstractBaseRecord newRecord, + String message, Object[] args ) + { + } + }; + InconsistencyReport inconsistencyReport = new InconsistencyReport( logger, summary ); + ConsistencyReporter reporter = new ConsistencyReporter( records, inconsistencyReport ); + NodeRecord node = new NodeRecord( 10 ); + RecordCheck checker = mock( RecordCheck.class ); + RuntimeException exception = new RuntimeException( "My specific exception" ); + doThrow( exception ).when( checker ) + .check( any( NodeRecord.class ), any( CheckerEngine.class ), any( RecordAccess.class ) ); + + // WHEN + reporter.forNode( node, checker ); + + // THEN + assertNotNull( loggedError.get() ); + String error = loggedError.get(); + assertThat( error, containsString( "at " ) ); + assertThat( error, containsString( testName.getMethodName() ) ); + } } @RunWith(Parameterized.class)