Merge pull request #34 from bluegroundltd/chore/sw-699-update-logging…

…-structure

[SW-699] Update outbox handling logging

README.md

@@ -27,7 +27,7 @@ Transactional Outbox is published on `mavenCentral`. In order to use it just add
 
 ```gradle
 
-implementation("io.github.bluegroundltd:transactional-outbox-core:2.3.0")
+implementation("io.github.bluegroundltd:transactional-outbox-core:2.3.1")
 
 ```
 

core/gradle.properties

@@ -1,6 +1,6 @@
 GROUP=io.github.bluegroundltd
 POM_ARTIFACT_ID=transactional-outbox-core
-VERSION_NAME=2.3.0
+VERSION_NAME=2.3.1
 
 POM_NAME=Transactional Outbox Core
 POM_DESCRIPTION=Easily implement the transactional outbox pattern in your JVM application

core/src/main/kotlin/io/github/bluegroundltd/outbox/processing/OutboxHandlerException.kt

@@ -0,0 +1,17 @@
+package io.github.bluegroundltd.outbox.processing
+
+import io.github.bluegroundltd.outbox.item.OutboxItem
+
+internal data class OutboxHandlerException @JvmOverloads constructor(
+  private val item: OutboxItem,
+  override val cause: Throwable,
+  override val message: String = formatDefaultMessage(item, cause),
+) : RuntimeException(message, cause) {
+  companion object {
+    private fun formatDefaultMessage(item: OutboxItem, cause: Throwable) =
+      "Handler for outbox: ${item.id} failed${formatCauseMessage(cause.message)}."
+
+    private fun formatCauseMessage(message: String?): String =
+      message?.let { " with message: '$it'" } ?: ""
+  }
+}

core/src/main/kotlin/io/github/bluegroundltd/outbox/processing/OutboxItemProcessor.kt

@@ -44,7 +44,7 @@ internal class OutboxItemProcessor(
       } else {
         handleRetryableFailure(handler, exception)
       }
-      throw exception
+      throw OutboxHandlerException(item, exception)
     } finally {
       store.update(item)
     }
@@ -99,7 +99,7 @@ internal class OutboxItemProcessor(
   }
 
   private fun handleTerminalFailure(handler: OutboxHandler, exception: Exception) {
-    logger.info(
+    logger.error(
       "$LOGGER_PREFIX Failure handling outbox item with id: ${item.id} and type: ${item.type}. " +
         "Item reached max-retries (${item.retries}), delegating failure to handler.",
       exception

core/src/main/kotlin/io/github/bluegroundltd/outbox/processing/OutboxProcessingHost.kt

@@ -34,7 +34,7 @@ internal class OutboxProcessingHost(
     try {
       processingAction.run()
     } catch (e: Exception) {
-      logger.error("$LOGGER_PREFIX ${e.message}")
+      e.log()
       processingAction.reset()
     }
   }
@@ -48,4 +48,15 @@ internal class OutboxProcessingHost(
   fun reset() {
     processingAction.reset()
   }
+
+  private fun Exception.log() {
+    when (this) {
+      // Outbox handler exceptions are logged by the item processor itself.
+      is OutboxHandlerException -> {}
+      // This is a semi-expected exception. The item will be retried at a later time.
+      is InvalidOutboxStateException -> logger.info("$LOGGER_PREFIX ${this.message}")
+      // This is a systemic/library exception that presumably won't be fixed by a retry.
+      else -> logger.error("$LOGGER_PREFIX ${this.message}")
+    }
+  }
 }

core/src/test/groovy/io/github/bluegroundltd/outbox/processing/OutboxHandlerExceptionSpec.groovy

@@ -0,0 +1,50 @@
+package io.github.bluegroundltd.outbox.processing
+
+import io.github.bluegroundltd.outbox.item.OutboxItem
+import io.github.bluegroundltd.outbox.utils.OutboxItemBuilder
+import spock.lang.Specification
+
+class OutboxHandlerExceptionSpec extends Specification {
+  def "Should build an [OutboxHandlerException] with default values"() {
+    given:
+      def outboxItem = OutboxItemBuilder.make().build()
+      def cause = Mock(Throwable)
+      def expectedMessage = outboxItem.with {
+        "Handler for outbox: ${it.id} failed${expectedCauseMessage}."
+      }
+
+    when:
+      def exception = new OutboxHandlerException(outboxItem, cause)
+
+    then:
+      1 * cause.getMessage() >> causeMessage
+      0 * _
+
+    and:
+      exception.cause == cause
+      exception.message == expectedMessage
+      0 * _
+
+    where:
+      causeMessage        || expectedCauseMessage
+      "Exception Message" || " with message: 'Exception Message'"
+      null                || ""
+  }
+
+  def "Should build an [OutboxHandlerException] with the supplied values"() {
+    given:
+      def outboxItem = GroovyMock(OutboxItem)
+      def cause = Mock(Throwable)
+      def message = "Exception Message"
+
+    when:
+      def exception = new OutboxHandlerException(outboxItem, cause, message)
+
+    then:
+      0 * _
+
+    and:
+      exception.message == message
+      exception.cause == cause
+  }
+}

core/src/test/groovy/io/github/bluegroundltd/outbox/processing/OutboxItemProcessorSpec.groovy

@@ -135,16 +135,16 @@ class OutboxItemProcessorSpec extends Specification {
       0 * _
   }
 
-  def "Should handle a processing failure when it has reached the max number of retries"() {
+  def "Should gracefully handle a processing failure when it has reached the max number of retries"() {
     given:
-      def exception = new RuntimeException()
+      def caughtException = new RuntimeException()
 
     when:
       processor.run()
 
     then:
       1 * handler.getSupportedType() >> processedItem.type
-      1 * handler.handle(processedItem.payload) >> { throw exception }
+      1 * handler.handle(processedItem.payload) >> { throw caughtException }
       1 * handler.hasReachedMaxRetries(processedItem.retries) >> true
       1 * handler.handleFailure(processedItem.payload)
       1 * store.update(_) >> { OutboxItem item ->
@@ -156,21 +156,21 @@ class OutboxItemProcessorSpec extends Specification {
       0 * _
 
     and:
-      def ex = thrown(Exception)
-      ex == exception
+      def ex = thrown(OutboxHandlerException)
+      ex.cause == caughtException
   }
 
   def "Should gracefully handle a processing failure when it hasn't reached the max number of retries"() {
     given:
       def expectedNextRun = Instant.now(clock)
-      def exception = new RuntimeException()
+      def caughtException = new RuntimeException()
 
     when:
       processor.run()
 
     then:
       1 * handler.getSupportedType() >> processedItem.type
-      1 * handler.handle(processedItem.payload) >> { throw exception }
+      1 * handler.handle(processedItem.payload) >> { throw caughtException }
       1 * handler.hasReachedMaxRetries(processedItem.retries) >> false
       1 * handler.getNextExecutionTime(processedItem.retries) >> expectedNextRun
       1 * store.update(_) >> { OutboxItem item ->
@@ -184,8 +184,8 @@ class OutboxItemProcessorSpec extends Specification {
       0 * _
 
     and:
-      def ex = thrown(Exception)
-      ex == exception
+      def ex = thrown(OutboxHandlerException)
+      ex.cause == caughtException
   }
 
   def "Should set item status to 'PENDING' when [reset] is invoked"() {

core/src/test/groovy/io/github/bluegroundltd/outbox/processing/OutboxProcessingHostSpec.groovy

@@ -1,5 +1,6 @@
 package io.github.bluegroundltd.outbox.processing
 
+import io.github.bluegroundltd.outbox.utils.OutboxItemBuilder
 import spock.lang.Specification
 
 class OutboxProcessingHostSpec extends Specification {
@@ -45,7 +46,7 @@ class OutboxProcessingHostSpec extends Specification {
       noExceptionThrown()
   }
 
-  def "Should catch all exceptions and reset the processor when an exception occurs while processing"() {
+  def "Should catch #exceptionType that occurs while processing and reset the processor"() {
     when:
       processingHost.run()
 
@@ -56,6 +57,14 @@ class OutboxProcessingHostSpec extends Specification {
 
     and:
       noExceptionThrown()
+
+      // The only difference between the cases is the logging which is not really testable.
+      // However, they are all included for coverage.
+    where:
+      exceptionType               | exception
+      "a handler exception"       | makeHandlerException()
+      "an outbox state exception" | makeOutboxStateException()
+      "a non-handler exception"   | new Exception("Processing Exception")
   }
 
   def "Should delegate to the processor when [reset] is called"() {
@@ -69,4 +78,15 @@ class OutboxProcessingHostSpec extends Specification {
     and:
       noExceptionThrown()
   }
+
+  private static OutboxHandlerException makeHandlerException() {
+    def outboxItem = OutboxItemBuilder.make().build()
+    def cause = new RuntimeException("Exception Message")
+    return new OutboxHandlerException(outboxItem, cause)
+  }
+
+  private static InvalidOutboxStateException makeOutboxStateException() {
+    def outboxItem = OutboxItemBuilder.make().build()
+    return new InvalidOutboxStateException(outboxItem)
+  }
 }