diff --git a/README.md b/README.md index a6e3299..8bc9a89 100644 --- a/README.md +++ b/README.md @@ -144,15 +144,27 @@ setLogger() ### Using the `@TraceLogLevel` annotation Trace events in a `TraceEventListener` can be annotated with the `@TraceLogLevel` annotation. -This annotation allows you to specify a log level, using parameter `logLevel` that will + +#### `@TraceLoglevel(logLevel=...)` + +`@TraceLoglevel` allows you to specify a log level, using parameter `logLevel` that will be used to output the trace event to a standard logger using a specific log level, such as `INFO`, `DEBUG`, `ERROR`, etc. -It also offers the option to specify logging a full stack trace of a logged exception, using +#### `@TraceLoglevel(logStackTrace=true|false)` + +`@TraceLoglevel` also offers the option to specify logging a full stack trace of a logged exception, using the optional parameter `logStackTrace`. This applies to the last argument of an event (if it is a `Throwable` object). By default, the stack trace is included. -Finally, it offers the option, using `includeOwnerClass` to add the class owning the event +#### `@TraceLoglevel(logCaller=true|false)` + +`@TraceLoglevel` also offers the option to specify logging the filename and line number of +the caller of an event. By default, the caller is not provided. + +#### `@TraceLoglevel(logOwnerClass=true|false)` + +`@TraceLoglevel` offers the option, using `logOwnerClass` to add the class owning the event interface to the log message, or omit that. By default, the owner class is not included. Example: @@ -419,6 +431,10 @@ Contributors: Timon Kanters, Jeroen Erik Jensen ## Release notes +### 1.0.9 + +* Added `logCaller` to `@TraceLoglevel` add the caller filename and line number to the logger. + ### 1.0.8 * Added `logStackTrace` to annotation `@TraceLogLevel`. diff --git a/pom.xml b/pom.xml index 50f2712..4be1603 100644 --- a/pom.xml +++ b/pom.xml @@ -21,7 +21,7 @@ com.tomtom.kotlin kotlin-tools - 1.0.8 + 1.0.9 pom Kotlin Tools diff --git a/traceevents/pom.xml b/traceevents/pom.xml index 4817f06..1490bb0 100644 --- a/traceevents/pom.xml +++ b/traceevents/pom.xml @@ -24,7 +24,7 @@ com.tomtom.kotlin kotlin-tools - 1.0.8 + 1.0.9 traceevents diff --git a/traceevents/src/main/java/com/tomtom/kotlin/traceevents/TraceLogLevel.kt b/traceevents/src/main/java/com/tomtom/kotlin/traceevents/TraceLogLevel.kt index 4117fd1..3a72a14 100644 --- a/traceevents/src/main/java/com/tomtom/kotlin/traceevents/TraceLogLevel.kt +++ b/traceevents/src/main/java/com/tomtom/kotlin/traceevents/TraceLogLevel.kt @@ -26,11 +26,20 @@ import com.tomtom.kotlin.traceevents.TraceLog.LogLevel * @param logStackTrace Specifies whether a stack trace should be included if the last parameter * of the event is derived from [Throwable]. If false, only the exception message is shown. * Default value is true. + * + * @param logCaller Specifies whether the filename and line number of the caller + * should be logged or not. + * Default is false. + * + * @param logOwnerClass Specifies whether owner class of the event definition should be logged + * or not. + * Default is false. */ @Retention(AnnotationRetention.RUNTIME) @Target(AnnotationTarget.FUNCTION) annotation class TraceLogLevel( val logLevel: LogLevel, val logStackTrace: Boolean = true, - val includeOwnerClass: Boolean = false + val logCaller: Boolean = false, + val logOwnerClass: Boolean = false ) diff --git a/traceevents/src/main/java/com/tomtom/kotlin/traceevents/Tracer.kt b/traceevents/src/main/java/com/tomtom/kotlin/traceevents/Tracer.kt index 743436a..fde38eb 100644 --- a/traceevents/src/main/java/com/tomtom/kotlin/traceevents/Tracer.kt +++ b/traceevents/src/main/java/com/tomtom/kotlin/traceevents/Tracer.kt @@ -32,6 +32,7 @@ import java.time.format.DateTimeFormatter import kotlin.reflect.KClass import kotlin.reflect.full.isSubclassOf + /** * GENERAL DOCUMENTATION ON TRACE EVENTS * ------------------------------------- @@ -217,8 +218,10 @@ class Tracer private constructor( method.getDeclaredAnnotation(TraceLogLevel::class.java)?.logLevel ?: LogLevel.DEBUG val logStackTraceAnnotation = method.getDeclaredAnnotation(TraceLogLevel::class.java)?.logStackTrace ?: true + val logCaller = + method.getDeclaredAnnotation(TraceLogLevel::class.java)?.logCaller ?: false val includeOwnerClassAnnotation = - method.getDeclaredAnnotation(TraceLogLevel::class.java)?.includeOwnerClass ?: false + method.getDeclaredAnnotation(TraceLogLevel::class.java)?.logOwnerClass ?: false /** * Skip event when the method is a standard (possibly auto-generated) class method. @@ -260,6 +263,7 @@ class Tracer private constructor( "event=${createLogMessage( event, includeTime = false, + logCaller = logCaller, logStackTrace = logStackTraceAnnotation, includeOwnerClass = includeOwnerClassAnnotation )}" @@ -301,6 +305,7 @@ class Tracer private constructor( "Event lost, event=${createLogMessage( event, includeTime = true, + logCaller = true, logStackTrace = true, includeOwnerClass = true )}" @@ -351,6 +356,7 @@ class Tracer private constructor( companion object { val TAG = Tracer::class.simpleName!! + const val STACK_TRACE_DEPTH = 5L /** * Names of simple, predefined log functions (from standard loggers). @@ -616,6 +622,7 @@ class Tracer private constructor( internal fun createLogMessage( traceEvent: TraceEvent, includeTime: Boolean, + logCaller: Boolean, logStackTrace: Boolean, includeOwnerClass: Boolean ): String { @@ -628,8 +635,11 @@ class Tracer private constructor( convertToStringUsingRegistry(it) }})" ) + if (logCaller) { + sb.append(", caller=${getCaller()}") + } if (includeOwnerClass) { - sb.append(", from ${traceEvent.ownerClass}") + sb.append(", ownerClass=${traceEvent.ownerClass}") } if (logStackTrace && !traceEvent.args.isEmpty()) { (traceEvent.args.last() as? Throwable)?.let { @@ -654,6 +664,47 @@ class Tracer private constructor( e.message } + private fun getCaller(): String { + + /** + * For Java 9, we suggest the following optimization: + * + * Use the [StackWalker] instead of [Thread.getStackTrace], because it's much, much + * faster to not get all frames. + * + * Get the stack up to a maximum of [STACK_TRACE_DEPTH] levels deep. Our caller must be + * in those first calls. If it's not, the unit tests fails and informs the developer + * the reconsider the value of [STACK_TRACE_DEPTH]. + * + * 
+             *     val stack = StackWalker.getInstance().walk {
+             *         frames -> frames.limit(STACK_TRACE_DEPTH).collect(Collectors.toList())
+             *
+ * + * For now, use the slower Java 8 version: + */ + val stack = Throwable().stackTrace + + // Find our own 'invoke' function call on the stack that called this function. + var i = 0 + while (i < stack.size && + stack[i].className != "com.tomtom.kotlin.traceevents.Tracer" && + stack[i].methodName != "invoke" + ) i++ + + // The function call 2 levels deeper is the actual caller function. + return if (i < stack.size - 2) { + + // Skip the com.sun.proxy function call and get the info from the next item. + val item = stack[i + 2] + "${item.fileName}:${item.methodName}(${item.lineNumber})" + } else { + + // This shouldn't happen, but we certainly shouldn't throw here. + "(error: can't find `invoke` function on stack)" + } + } + init { // Always switch on synchronous logging by default. diff --git a/traceevents/src/test/java/com/tomtom/kotlin/traceevents/LogTest.kt b/traceevents/src/test/java/com/tomtom/kotlin/traceevents/LogTest.kt index bca8d44..f18535d 100644 --- a/traceevents/src/test/java/com/tomtom/kotlin/traceevents/LogTest.kt +++ b/traceevents/src/test/java/com/tomtom/kotlin/traceevents/LogTest.kt @@ -16,7 +16,9 @@ package com.tomtom.kotlin.traceevents import com.tomtom.kotlin.traceevents.TraceLog.LogLevel import com.tomtom.kotlin.traceevents.TraceLog.Logger +import org.junit.Before import org.junit.Test +import kotlin.system.measureTimeMillis import kotlin.test.assertEquals import kotlin.test.assertFalse import kotlin.test.assertTrue @@ -51,13 +53,21 @@ class LogTest { @TraceLogLevel(LogLevel.ERROR) fun allArgs(aInt: Int?, aString: String?, aArray: Array?, aList: List?) - @TraceLogLevel(LogLevel.DEBUG, logStackTrace = true, includeOwnerClass = true) + @TraceLogLevel(LogLevel.DEBUG, logCaller = true) + fun withCaller(message: String) + + @TraceLogLevel(LogLevel.DEBUG, logStackTrace = true, logOwnerClass = true) fun withStackTrace(e: Throwable?) - @TraceLogLevel(LogLevel.DEBUG, logStackTrace = false, includeOwnerClass = false) + @TraceLogLevel(LogLevel.DEBUG, logStackTrace = false, logOwnerClass = false) fun withoutStackTrace(e: Throwable?) } + @Before + fun setUp() { + TraceLog.setLogger() + } + @Test fun `specific consumer`() { val logger = LoggerCalled() @@ -214,7 +224,7 @@ class LogTest { sut.withStackTrace(null) } val expected = - "$TIME: [DEBUG] LogTest: event=withStackTrace(null), from com.tomtom.kotlin.traceevents.LogTest\n" + "$TIME: [DEBUG] LogTest: event=withStackTrace(null), ownerClass=com.tomtom.kotlin.traceevents.LogTest\n" assertEquals(expected, actual) } @@ -226,7 +236,7 @@ class LogTest { // Cut off just enough to NOT include line numbers of source code as they may change. val prefix = - "$TIME: [DEBUG] LogTest: event=withStackTrace(java.lang.IllegalStateException: error1), from com.tomtom.kotlin.traceevents.LogTest\n" + + "$TIME: [DEBUG] LogTest: event=withStackTrace(java.lang.IllegalStateException: error1), ownerClass=com.tomtom.kotlin.traceevents.LogTest\n" + "java.lang.IllegalStateException: error1\n" + "\tat com.tomtom.kotlin.traceevents.LogTest\$log event with exception to stdout with stacktrace\$actual\$1.invoke(LogTest.kt:" val suffix = @@ -239,6 +249,20 @@ class LogTest { assertTrue(replaceNumber(actual, NUMBER).endsWith(suffix)) } + @Test + fun `log event with caller`() { + val actual = captureStdoutReplaceTime(TIME) { + sut.withCaller("test") + } + + println(actual) + // Cut off just enough to NOT include line numbers of source code as they may change. + val expected = + "$TIME: [DEBUG] LogTest: event=withCaller(test), caller=LogTest.kt:invoke($NUMBER)\n" + assertEquals(expected, replaceNumber(actual, NUMBER), + "Perhaps you should increase STACK_TRACE_DEPTH?") + } + companion object { const val TIME = "[TIME]" const val NUMBER = "[NUMBER]"