From bea3a2bf28f29da9d187218967b364b23da87288 Mon Sep 17 00:00:00 2001 From: Alistair Jones Date: Tue, 19 Apr 2016 23:40:17 +0100 Subject: [PATCH] Include error reference in both user and debug logs. The unique reference allows the user to locate a detailed stack trace that corresponds to a briefer messages in the user log, and to the short message sent back to the client. --- .../msgprocess/MessageProcessingCallback.java | 17 ++- .../v1/runtime/internal/ErrorReporter.java | 22 +--- .../runtime/internal/ErrorReporterTest.java | 124 +++++++++--------- .../v1/runtime/internal/Neo4jErrorTest.java | 13 ++ .../neo4j/kernel/api/exceptions/Status.java | 31 ++--- 5 files changed, 103 insertions(+), 104 deletions(-) diff --git a/community/bolt/src/main/java/org/neo4j/bolt/v1/messaging/msgprocess/MessageProcessingCallback.java b/community/bolt/src/main/java/org/neo4j/bolt/v1/messaging/msgprocess/MessageProcessingCallback.java index ba6aeab8efd84..cfaa9655f61d6 100644 --- a/community/bolt/src/main/java/org/neo4j/bolt/v1/messaging/msgprocess/MessageProcessingCallback.java +++ b/community/bolt/src/main/java/org/neo4j/bolt/v1/messaging/msgprocess/MessageProcessingCallback.java @@ -34,20 +34,19 @@ public class MessageProcessingCallback extends Session.Callback.Adapter out, Neo4jError error ) throws IOException { - if ( error.status().code().classification().publishable() ) + if ( error.status().code().classification().refersToLog() ) { - // If publishable, we forward the message as-is to the user. - out.handleFailureMessage( error.status(), error.message() ); - } - else - { - // If not publishable, we only return an error reference to the user. This must - // be cross-referenced with the log files for full error detail. This feature - // exists to improve security so that sensitive information is not leaked. + // If not intended for client, we only return an error reference. This must + // be cross-referenced with the log files for full error detail. out.handleFailureMessage( error.status(), String.format( "An unexpected failure occurred, see details in the database " + "logs, reference number %s.", error.reference() ) ); } + else + { + // If intended for client, we forward the message as-is. + out.handleFailureMessage( error.status(), error.message() ); + } } protected final Log log; diff --git a/community/bolt/src/main/java/org/neo4j/bolt/v1/runtime/internal/ErrorReporter.java b/community/bolt/src/main/java/org/neo4j/bolt/v1/runtime/internal/ErrorReporter.java index 58b6db88ad5e8..fe525052f4fda 100644 --- a/community/bolt/src/main/java/org/neo4j/bolt/v1/runtime/internal/ErrorReporter.java +++ b/community/bolt/src/main/java/org/neo4j/bolt/v1/runtime/internal/ErrorReporter.java @@ -19,7 +19,6 @@ */ package org.neo4j.bolt.v1.runtime.internal; -import org.neo4j.helpers.Exceptions; import org.neo4j.kernel.impl.logging.LogService; import org.neo4j.logging.Log; @@ -30,8 +29,6 @@ */ class ErrorReporter { - private static final String EMPTY_STRING = ""; - private final Log userLog; private final Log debugLog; @@ -49,20 +46,15 @@ class ErrorReporter public void report( Neo4jError error ) { - if ( !error.status().code().classification().publishable() ) + if ( error.status().code().classification().refersToLog() ) { - userLog.error( format( "Client triggered an unexpected error: %s. See debug.log for more details.", - error.cause().getMessage() ) ); - } + userLog.error( "Client triggered an unexpected error [%s]: %s. " + + "See debug.log for more details, reference %s.", + error.status(), error.message(), error.reference() ); - if ( somethingToLog( error ) ) - { - debugLog.error( Exceptions.stringify( error.cause() ) ); + debugLog.error( format( "Client triggered an unexpected error [%s]: %s, reference %s.", + error.status(), error.message(), error.reference() ), + error.cause() ); } } - - private boolean somethingToLog( Neo4jError error ) - { - return error != null && error.cause() != null; - } } diff --git a/community/bolt/src/test/java/org/neo4j/bolt/v1/runtime/internal/ErrorReporterTest.java b/community/bolt/src/test/java/org/neo4j/bolt/v1/runtime/internal/ErrorReporterTest.java index f2e3724604eb0..c13da165da7df 100644 --- a/community/bolt/src/test/java/org/neo4j/bolt/v1/runtime/internal/ErrorReporterTest.java +++ b/community/bolt/src/test/java/org/neo4j/bolt/v1/runtime/internal/ErrorReporterTest.java @@ -19,110 +19,114 @@ */ package org.neo4j.bolt.v1.runtime.internal; +import java.util.UUID; + import org.junit.Test; import org.neo4j.kernel.api.exceptions.Status; import org.neo4j.logging.AssertableLogProvider; -import org.neo4j.logging.Log; -import static org.hamcrest.CoreMatchers.equalTo; -import static org.hamcrest.MatcherAssert.assertThat; -import static org.mockito.Matchers.contains; import static org.mockito.Mockito.mock; -import static org.mockito.Mockito.verify; +import static org.mockito.Mockito.when; public class ErrorReporterTest { @Test - public void shouldLogFullMessageInDebugLogAndHelpfulPointerInUserLog() throws Exception + public void clientErrorShouldNotLog() throws Exception { // given - Log userLog = mock( Log.class ); - Log internalLog = mock( Log.class ); - ErrorReporter reporter = new ErrorReporter( userLog, internalLog ); + AssertableLogProvider userLog = new AssertableLogProvider(); + AssertableLogProvider internalLog = new AssertableLogProvider(); + ErrorReporter reporter = + new ErrorReporter( userLog.getLog( "userLog" ), internalLog.getLog( "internalLog" ) ); + - Throwable cause = new Throwable( "Hello World" ); - Neo4jError error = Neo4jError.from( cause ); + Status.Code code = mock( Status.Code.class ); + Neo4jError error = new Neo4jError( () -> code, "Should not be logged" ); + when( code.classification() ).thenReturn( Status.Classification.ClientError ); // when reporter.report( error ); // then - verify( userLog ).error( "Client triggered an unexpected error: Hello World. See debug.log for more details." ); - verify( internalLog ).error( contains( "java.lang.Throwable: Hello World" ) ); + + userLog.assertNoLoggingOccurred(); + internalLog.assertNoLoggingOccurred(); } @Test - public void shouldReportUnknownErrorsInUserLog() + public void clientNotificationShouldNotLog() throws Exception { - // Given - AssertableLogProvider provider = new AssertableLogProvider(); + // given + AssertableLogProvider userLog = new AssertableLogProvider(); + AssertableLogProvider internalLog = new AssertableLogProvider(); ErrorReporter reporter = - new ErrorReporter( provider.getLog( "userLog" ), provider.getLog( "internalLog" ) ); + new ErrorReporter( userLog.getLog( "userLog" ), internalLog.getLog( "internalLog" ) ); - Throwable cause = new Throwable( "This is not an error we know how to handle." ); - Neo4jError error = Neo4jError.from( cause ); - // When + Status.Code code = mock( Status.Code.class ); + Neo4jError error = new Neo4jError( () -> code, "Should not be logged" ); + when( code.classification() ).thenReturn( Status.Classification.ClientNotification ); + + // when reporter.report( error ); - // Then - assertThat( error.status(), equalTo( (Status) Status.General.UnknownError ) ); - provider.assertContainsMessageContaining( error.cause().getMessage() ); + // then + + userLog.assertNoLoggingOccurred(); + internalLog.assertNoLoggingOccurred(); } + @Test - public void shouldNotReportOOMErrorsInUserLog() + public void databaseErrorShouldLogFullMessageInDebugLogAndHelpfulPointerInUserLog() throws Exception { - // Given - AssertableLogProvider provider = new AssertableLogProvider(); + // given + AssertableLogProvider userLog = new AssertableLogProvider(); + AssertableLogProvider internalLog = new AssertableLogProvider(); ErrorReporter reporter = - new ErrorReporter( provider.getLog( "userLog" ), provider.getLog( "internalLog" ) ); + new ErrorReporter( userLog.getLog( "userLog" ), internalLog.getLog( "internalLog" ) ); - Throwable cause = new OutOfMemoryError( "memory is fading" ); - Neo4jError error = Neo4jError.from( cause ); + Status.Code code = mock( Status.Code.class ); + Neo4jError error = new Neo4jError( () -> code, "Database error" ); + when( code.classification() ).thenReturn( Status.Classification.DatabaseError ); + UUID reference = error.reference(); - // When + // when reporter.report( error ); - // Then - assertThat( error.status(), equalTo( (Status) Status.General.OutOfMemoryError ) ); - assertThat( error.message(), - equalTo( "There is not enough memory to perform the current task. Please try increasing " + - "'dbms.memory.heap.max_size' in the process wrapper configuration (normally in " + - "'conf/neo4j-wrapper" + - ".conf' or, if you are using Neo4j Desktop, found through the user interface) or if you are " + - "running an embedded " + - "installation increase the heap by using '-Xmx' command line flag, and then restart the " + - "database." ) ); - provider.assertContainsMessageContaining( cause.getClass().getName() ); + // then + userLog.assertContainsLogCallContaining( "Client triggered an unexpected error" ); + userLog.assertContainsLogCallContaining( reference.toString() ); + userLog.assertContainsLogCallContaining( "Database error" ); + + internalLog.assertContainsLogCallContaining( reference.toString() ); + internalLog.assertContainsLogCallContaining( "Database error" ); } @Test - public void shouldReportStackOverflowErrorsInInternalLog() + public void transientErrorShouldLogFullMessageInDebugLogAndHelpfulPointerInUserLog() throws Exception { - // Given - AssertableLogProvider provider = new AssertableLogProvider(); + // given + AssertableLogProvider userLog = new AssertableLogProvider(); + AssertableLogProvider internalLog = new AssertableLogProvider(); ErrorReporter reporter = - new ErrorReporter( provider.getLog( "userLog" ), provider.getLog( "internalLog" ) ); + new ErrorReporter( userLog.getLog( "userLog" ), internalLog.getLog( "internalLog" ) ); - Throwable cause = new StackOverflowError( "some rewriter is probably not tail recursive" ); - Neo4jError error = Neo4jError.from( cause ); + Status.Code code = mock( Status.Code.class ); + Neo4jError error = new Neo4jError( () -> code, "Transient error" ); + when( code.classification() ).thenReturn( Status.Classification.TransientError ); + UUID reference = error.reference(); - // When + // when reporter.report( error ); - // Then - assertThat( error.status(), equalTo( (Status) Status.General.StackOverFlowError ) ); - assertThat( error.message(), equalTo( - "There is not enough stack size to perform the current task. This is generally considered to be a " + - "database error, so please contact Neo4j support. You could try increasing the stack size: " + - "for example to set the stack size to 2M, add `dbms.jvm.additional=-Xss2M' to " + - "in the process wrapper configuration (normally in 'conf/neo4j-wrapper.conf' or, if you are " + - "using " + - "Neo4j Desktop, found through the user interface) or if you are running an embedded " + - "installation " + - "just add -Xss2M as command line flag." ) ); - provider.assertContainsMessageContaining( cause.getClass().getName() ); + // then + userLog.assertContainsLogCallContaining( "Client triggered an unexpected error" ); + userLog.assertContainsLogCallContaining( reference.toString() ); + userLog.assertContainsLogCallContaining( "Transient error" ); + + internalLog.assertContainsLogCallContaining( reference.toString() ); + internalLog.assertContainsLogCallContaining( "Transient error" ); } } \ No newline at end of file diff --git a/community/bolt/src/test/java/org/neo4j/bolt/v1/runtime/internal/Neo4jErrorTest.java b/community/bolt/src/test/java/org/neo4j/bolt/v1/runtime/internal/Neo4jErrorTest.java index c81b9546766c5..3686712a13ae9 100644 --- a/community/bolt/src/test/java/org/neo4j/bolt/v1/runtime/internal/Neo4jErrorTest.java +++ b/community/bolt/src/test/java/org/neo4j/bolt/v1/runtime/internal/Neo4jErrorTest.java @@ -25,9 +25,22 @@ import org.neo4j.kernel.api.exceptions.Status; import static junit.framework.TestCase.assertEquals; +import static org.hamcrest.CoreMatchers.equalTo; +import static org.hamcrest.MatcherAssert.assertThat; public class Neo4jErrorTest { + @Test + public void shouldAssignUnknownStatusToUnpredictedException() + { + // Given + Throwable cause = new Throwable( "This is not an error we know how to handle." ); + Neo4jError error = Neo4jError.from( cause ); + + // Then + assertThat( error.status(), equalTo( (Status) Status.General.UnknownError ) ); + } + @Test public void shouldConvertDeadlockException() throws Throwable { diff --git a/community/common/src/main/java/org/neo4j/kernel/api/exceptions/Status.java b/community/common/src/main/java/org/neo4j/kernel/api/exceptions/Status.java index 13bfcb3b35164..a62b39bf702db 100644 --- a/community/common/src/main/java/org/neo4j/kernel/api/exceptions/Status.java +++ b/community/common/src/main/java/org/neo4j/kernel/api/exceptions/Status.java @@ -550,14 +550,14 @@ public int hashCode() enum Classification { /** The Client sent a bad request - changing the request might yield a successful outcome. */ - ClientError( TransactionEffect.ROLLBACK, PublishingPolicy.PUBLISHABLE, + ClientError( TransactionEffect.ROLLBACK, PublishingPolicy.REPORTS_TO_CLIENT, "The Client sent a bad request - changing the request might yield a successful outcome."), /** There are notifications about the request sent by the client.*/ - ClientNotification( TransactionEffect.NONE, PublishingPolicy.PUBLISHABLE, + ClientNotification( TransactionEffect.NONE, PublishingPolicy.REPORTS_TO_CLIENT, "There are notifications about the request sent by the client." ), /** The database cannot service the request right now, retrying later might yield a successful outcome. */ - TransientError( TransactionEffect.ROLLBACK, PublishingPolicy.PUBLISHABLE, + TransientError( TransactionEffect.ROLLBACK, PublishingPolicy.REFERS_TO_LOG, "The database cannot service the request right now, retrying later might yield a successful outcome. "), // Implementation note: These are a sharp tool, database error signals @@ -565,37 +565,28 @@ enum Classification // an error report back to us. Only use this if the code path you are // at would truly indicate the database is in a broken or bug-induced state. /** The database failed to service the request. */ - DatabaseError( TransactionEffect.ROLLBACK, PublishingPolicy.INTERNAL, - "The database failed to service the request. " ), - - ; + DatabaseError( TransactionEffect.ROLLBACK, PublishingPolicy.REFERS_TO_LOG, + "The database failed to service the request. " ); private enum TransactionEffect { ROLLBACK, NONE, } - /** - * A PUBLISHABLE error/warning is one which allows sending a meaningful error message to - * the client with the expectation that the user will be able to take any necessary action - * to resolve the error. INTERNAL errors are more sensitive and may not be resolvable by - * the user - these will be logged and only a reference will be forwarded to the user. - * This is a security feature to avoid leaking potentially sensitive information to end - * users. - */ + private enum PublishingPolicy { - PUBLISHABLE, INTERNAL, + REPORTS_TO_CLIENT, REFERS_TO_LOG } private final boolean rollbackTransaction; - private final boolean publishable; + private final boolean refersToLog; private final String description; Classification( TransactionEffect transactionEffect, PublishingPolicy publishingPolicy, String description ) { this.description = description; - this.publishable = publishingPolicy == PublishingPolicy.PUBLISHABLE; + this.refersToLog = publishingPolicy == PublishingPolicy.REFERS_TO_LOG; this.rollbackTransaction = transactionEffect == TransactionEffect.ROLLBACK; } @@ -604,9 +595,9 @@ public boolean rollbackTransaction() return rollbackTransaction; } - public boolean publishable() + public boolean refersToLog() { - return publishable; + return refersToLog; } public String description()