diff --git a/log4j-api-scala_2.10/src/main/scala/org/apache/logging/log4j/scala/Logger.scala b/log4j-api-scala_2.10/src/main/scala/org/apache/logging/log4j/scala/Logger.scala index 4ee7d07..d2366ff 100644 --- a/log4j-api-scala_2.10/src/main/scala/org/apache/logging/log4j/scala/Logger.scala +++ b/log4j-api-scala_2.10/src/main/scala/org/apache/logging/log4j/scala/Logger.scala @@ -431,12 +431,18 @@ class Logger private(val delegate: ExtendedLogger) extends AnyVal { * * @param params the parameters to the method. * @return The built `EntryMessage` + * @since 13.2.0 */ def traceEntry(params: AnyRef*): EntryMessage = { - if (params.isEmpty) { - delegate.traceEntry() + if (delegate.isTraceEnabled) { + if (params.isEmpty) { + delegate.traceEntry() + } else { + val head = params.head + delegate.traceEntry(if (head == null) null.asInstanceOf[String] else head.toString, params.tail: _*) + } } else { - delegate.traceEntry(params.head.toString, params.tail:_*) + null } } diff --git a/log4j-api-scala_2.10/src/test/scala/org/apache/logging/log4j/scala/LoggerTest.scala b/log4j-api-scala_2.10/src/test/scala/org/apache/logging/log4j/scala/LoggerTest.scala index 979b8b6..7f2046a 100644 --- a/log4j-api-scala_2.10/src/test/scala/org/apache/logging/log4j/scala/LoggerTest.scala +++ b/log4j-api-scala_2.10/src/test/scala/org/apache/logging/log4j/scala/LoggerTest.scala @@ -435,6 +435,7 @@ class LoggerTest extends AnyFunSuite with MockitoSugar { test("traceEntry") { val f = fixture + when(f.mockLogger.isTraceEnabled).thenReturn(true) when(f.mockLogger.isEnabled(Level.TRACE, AbstractLogger.ENTRY_MARKER, null.asInstanceOf[AnyRef], null)).thenReturn(true) val logger = Logger(f.mockLogger) logger.traceEntry() @@ -443,6 +444,7 @@ class LoggerTest extends AnyFunSuite with MockitoSugar { test("traceEntry enabled with params") { val f = fixture + when(f.mockLogger.isTraceEnabled).thenReturn(true) when(f.mockLogger.isEnabled(Level.TRACE, AbstractLogger.ENTRY_MARKER, null.asInstanceOf[AnyRef], null)).thenReturn(true) val logger = Logger(f.mockLogger) logger.traceEntry("foo", "bar") @@ -453,15 +455,38 @@ class LoggerTest extends AnyFunSuite with MockitoSugar { val f = fixture when(f.mockLogger.isEnabled(Level.TRACE, AbstractLogger.ENTRY_MARKER, null.asInstanceOf[AnyRef], null)).thenReturn(false) val logger = Logger(f.mockLogger) - logger.traceEntry("foo", "bar") - //traceEntry is now passes through to the underlying logger without checking if logging is enabled (the delegate checks anyway) - verify(f.mockLogger).traceEntry("foo", "bar") + val entryMessage = logger.traceEntry("foo", "bar") + assert(entryMessage == null) + verify(f.mockLogger, never).traceEntry(anyString(), any[AnyRef]) } - test("traceEntry enabled with message") { + test("traceEntry enabled with null params") { val f = fixture + when(f.mockLogger.isTraceEnabled).thenReturn(true) when(f.mockLogger.isEnabled(Level.TRACE, AbstractLogger.ENTRY_MARKER, null.asInstanceOf[AnyRef], null)).thenReturn(true) val logger = Logger(f.mockLogger) + logger.traceEntry(null, null) + verify(f.mockLogger).traceEntry(any[String], any[AnyRef]) + } + + test("traceEntry disabled with throwing params") { + val f = fixture + when(f.mockLogger.isEnabled(Level.TRACE, AbstractLogger.ENTRY_MARKER, null.asInstanceOf[AnyRef], null)).thenReturn(false) + val logger = Logger(f.mockLogger) + + // This should NOT crash because toString should not be called + val entryMessage = logger.traceEntry(new AnyRef { + override def toString: String = throw new RuntimeException("Should not be called") + }) + + assert(entryMessage == null) + } + + test("traceEntry enabled with message") { + val f = fixture + // traceEntry(Message) currently doesn't check isEnabled in the Scala wrapper, + // it delegates directly to the underlying logger which does the check. + val logger = Logger(f.mockLogger) logger.traceEntry(msg) verify(f.mockLogger).traceEntry(eqv(msg)) } diff --git a/log4j-api-scala_3/src/main/scala/org/apache/logging/log4j/scala/Logger.scala b/log4j-api-scala_3/src/main/scala/org/apache/logging/log4j/scala/Logger.scala index 5b677c3..088ab84 100644 --- a/log4j-api-scala_3/src/main/scala/org/apache/logging/log4j/scala/Logger.scala +++ b/log4j-api-scala_3/src/main/scala/org/apache/logging/log4j/scala/Logger.scala @@ -432,12 +432,18 @@ class Logger private(val delegate: ExtendedLogger) extends AnyVal { * * @param params the parameters to the method. * @return The built `EntryMessage` + * @since 13.2.0 */ inline def traceEntry(inline params: AnyRef*): EntryMessage = { - if (params.isEmpty) { - delegate.traceEntry() + if (delegate.isTraceEnabled) { + if (params.isEmpty) { + delegate.traceEntry() + } else { + val head = params.head + delegate.traceEntry(if (head == null) null.asInstanceOf[String] else head.toString, params.tail:_*) + } } else { - delegate.traceEntry(params.head.toString, params.tail:_*) + null } } diff --git a/log4j-api-scala_3/src/test/scala/org/apache/logging/log4j/scala/LoggerTest.scala b/log4j-api-scala_3/src/test/scala/org/apache/logging/log4j/scala/LoggerTest.scala index 4ea8fc9..df6521d 100644 --- a/log4j-api-scala_3/src/test/scala/org/apache/logging/log4j/scala/LoggerTest.scala +++ b/log4j-api-scala_3/src/test/scala/org/apache/logging/log4j/scala/LoggerTest.scala @@ -437,6 +437,7 @@ class LoggerTest extends AnyFunSuite with MockitoSugar { test("traceEntry") { val f = fixture + when(f.mockLogger.isTraceEnabled).thenReturn(true) when(f.mockLogger.isEnabled(Level.TRACE, AbstractLogger.ENTRY_MARKER, null.asInstanceOf[AnyRef], null)).thenReturn(true) val logger = Logger(f.mockLogger) logger.traceEntry() @@ -445,6 +446,7 @@ class LoggerTest extends AnyFunSuite with MockitoSugar { test("traceEntry enabled with params") { val f = fixture + when(f.mockLogger.isTraceEnabled).thenReturn(true) when(f.mockLogger.isEnabled(Level.TRACE, AbstractLogger.ENTRY_MARKER, null.asInstanceOf[AnyRef], null)).thenReturn(true) val logger = Logger(f.mockLogger) logger.traceEntry("foo", "bar") @@ -455,15 +457,38 @@ class LoggerTest extends AnyFunSuite with MockitoSugar { val f = fixture when(f.mockLogger.isEnabled(Level.TRACE, AbstractLogger.ENTRY_MARKER, null.asInstanceOf[AnyRef], null)).thenReturn(false) val logger = Logger(f.mockLogger) - logger.traceEntry("foo", "bar") - //traceEntry is now passes through to the underlying logger without checking if logging is enabled (the delegate checks anyway) - verify(f.mockLogger).traceEntry("foo", "bar") + val entryMessage = logger.traceEntry("foo", "bar") + assert(entryMessage == null) + verify(f.mockLogger, never).traceEntry(anyString(), any[AnyRef]) } - test("traceEntry enabled with message") { + test("traceEntry enabled with null params") { val f = fixture + when(f.mockLogger.isTraceEnabled).thenReturn(true) when(f.mockLogger.isEnabled(Level.TRACE, AbstractLogger.ENTRY_MARKER, null.asInstanceOf[AnyRef], null)).thenReturn(true) val logger = Logger(f.mockLogger) + logger.traceEntry(null, null) + verify(f.mockLogger).traceEntry(any[String], any[AnyRef]) + } + + test("traceEntry disabled with throwing params") { + val f = fixture + when(f.mockLogger.isEnabled(Level.TRACE, AbstractLogger.ENTRY_MARKER, null.asInstanceOf[AnyRef], null)).thenReturn(false) + val logger = Logger(f.mockLogger) + + // This should NOT crash because toString should not be called + val entryMessage = logger.traceEntry(new AnyRef { + override def toString: String = throw new RuntimeException("Should not be called") + }) + + assert(entryMessage == null) + } + + test("traceEntry enabled with message") { + val f = fixture + // traceEntry(Message) currently doesn't check isEnabled in the Scala wrapper, + // it delegates directly to the underlying logger which does the check. + val logger = Logger(f.mockLogger) logger.traceEntry(msg) verify(f.mockLogger).traceEntry(eqv(msg)) } diff --git a/src/changelog/.13.x.x/fix_trace_entry_npe_eager_eval.xml b/src/changelog/.13.x.x/fix_trace_entry_npe_eager_eval.xml new file mode 100644 index 0000000..4ef6c91 --- /dev/null +++ b/src/changelog/.13.x.x/fix_trace_entry_npe_eager_eval.xml @@ -0,0 +1,8 @@ + + + + Fix NPE and eager evaluation in `Logger.traceEntry` by adding null checks and ensuring logging is enabled before parameter processing. + diff --git a/src/site/antora/modules/ROOT/pages/index.adoc b/src/site/antora/modules/ROOT/pages/index.adoc index 1280168..66542fc 100644 --- a/src/site/antora/modules/ROOT/pages/index.adoc +++ b/src/site/antora/modules/ROOT/pages/index.adoc @@ -82,6 +82,20 @@ As all logger calls are implemented as macros, using string interpolation direct logger.debug(s"Logging in user ${user.getName} with birthday ${user.calcBirthday}") ---- +[#flow-logging] +== Flow logging + +The Scala API supports flow logging (tracing method entry and exit) via `traceEntry` and `traceExit` methods. +Starting from version `13.2.0`, `traceEntry` is safe to use with `null` parameters and evaluates arguments lazily, ensuring no overhead or crashes when trace logging is disabled. + +[source,scala] +---- +def doSomething(foo: String, bar: Int): Unit = { + logger.traceEntry(foo, bar) + // do something +} +---- + [#logger-names] == Logger names