From 620286b9b955966f0fa21a2b82d60e8107060a29 Mon Sep 17 00:00:00 2001 From: Emil Koutanov Date: Fri, 27 Apr 2018 21:20:38 +1000 Subject: [PATCH] PrintStreamLogTarget prints location information --- README.md | 4 +- bridge-jul/README.md | 2 +- .../zerolog/PrintStreamLogTarget.java | 14 +- .../com/obsidiandynamics/zerolog/Zlg.java | 2 +- .../zerolog/util/CallingClass.java | 11 -- .../obsidiandynamics/zerolog/util/Stacks.java | 108 ++++++++++++++ .../zerolog/util/CallingClassTest.java | 39 ----- .../zerolog/util/StacksTest.java | 134 ++++++++++++++++++ 8 files changed, 256 insertions(+), 58 deletions(-) delete mode 100644 src/main/java/com/obsidiandynamics/zerolog/util/CallingClass.java create mode 100644 src/main/java/com/obsidiandynamics/zerolog/util/Stacks.java delete mode 100644 src/test/java/com/obsidiandynamics/zerolog/util/CallingClassTest.java create mode 100644 src/test/java/com/obsidiandynamics/zerolog/util/StacksTest.java diff --git a/README.md b/README.md index eefc97e..5c578ea 100644 --- a/README.md +++ b/README.md @@ -161,8 +161,8 @@ The built-in log levels are, from lowest to highest: `TRACE`, `DEBUG`, `CONF`, ` Being a façade, Zlg delegates all log calls to an actual logger — an implementation of `LogService`. By default, Zlg comes pre-packaged with a very basic 'failsafe' `SysOutLogService` that prints entries to `System.out` in a fixed format. Example below. ``` -21:23:16.814 INF [main]: Connecting to github.com:80 [timeout: 30.0 sec] -21:23:16.818 WRN [main] [I/O]: Error connecting to github.com:80 +21:18:11.771 INF [main] SysOutLoggingSample.open:20: Connecting to github.com:80 [timeout: 30.0 sec] +21:18:11.773 WRN [main] [I/O] SysOutLoggingSample.open:25: Error connecting to github.com:80 ``` Zlg detects installed bindings using Java's [SPI](https://docs.oracle.com/javase/tutorial/ext/basics/spi.html) plugin mechanism. By simply including a binding on the classpath, Zlg will switch over to the new binding by default. diff --git a/bridge-jul/README.md b/bridge-jul/README.md index 30f93b1..694f3fb 100644 --- a/bridge-jul/README.md +++ b/bridge-jul/README.md @@ -14,7 +14,7 @@ compile "com.obsidiandynamics.zerolog:zerolog-core:x.y.z" compile "com.obsidiandynamics.zerolog:zerolog-bridge-jul:x.y.z" ``` -## Installing programmatically +## Programmatic installation The following example installs the bridge for the root logger (stashing prior handlers first) and demonstrates logging via JUL, ending up in Zlg. Afterwards the original handlers are restored from the stash. ```java diff --git a/src/main/java/com/obsidiandynamics/zerolog/PrintStreamLogTarget.java b/src/main/java/com/obsidiandynamics/zerolog/PrintStreamLogTarget.java index 46fa8a6..98c4b07 100644 --- a/src/main/java/com/obsidiandynamics/zerolog/PrintStreamLogTarget.java +++ b/src/main/java/com/obsidiandynamics/zerolog/PrintStreamLogTarget.java @@ -20,16 +20,22 @@ public boolean isEnabled(int level) { } @Override - public void log(int level, String tag, String format, int argc, Object[] argv, Throwable throwable, String entrypoint) { + public void log(int level, String tag, String format, int argc, Object[] argv, + Throwable throwable, String entrypoint) { final String line; final String levelName = LogLevel.Enum.match(level).getShortName(); final String threadName = Thread.currentThread().getName(); - final String time = dateFormat.format(new Date()); + final String time; + synchronized (dateFormat) { + time = dateFormat.format(new Date()); + } final String message = SafeFormat.format(format, argc, argv); + final String location = Stacks.formatLocation(Stacks.locate(entrypoint)); + if (tag != null) { - line = time + " " + levelName + " [" + threadName + "] [" + tag + "]: " + message; + line = time + " " + levelName + " [" + threadName + "] [" + tag + "] " + location + ": " + message; } else { - line = time + " " + levelName + " [" + threadName + "]: " + message; + line = time + " " + levelName + " [" + threadName + "] " + location + ": " + message; } stream.println(line); if (throwable != null) { diff --git a/src/main/java/com/obsidiandynamics/zerolog/Zlg.java b/src/main/java/com/obsidiandynamics/zerolog/Zlg.java index 55d51dc..ad36b62 100644 --- a/src/main/java/com/obsidiandynamics/zerolog/Zlg.java +++ b/src/main/java/com/obsidiandynamics/zerolog/Zlg.java @@ -158,7 +158,7 @@ static ZlgBuilder forClass(Class cls) { } static ZlgBuilder forDeclaringClass() { - return forClass(CallingClass.forDepth(2)); + return forClass(Stacks.classForDepth(2)); } /** Pre-canned no-op logger. */ diff --git a/src/main/java/com/obsidiandynamics/zerolog/util/CallingClass.java b/src/main/java/com/obsidiandynamics/zerolog/util/CallingClass.java deleted file mode 100644 index 26ee386..0000000 --- a/src/main/java/com/obsidiandynamics/zerolog/util/CallingClass.java +++ /dev/null @@ -1,11 +0,0 @@ -package com.obsidiandynamics.zerolog.util; - -public final class CallingClass extends SecurityManager { - private static final CallingClass instance = new CallingClass(); - - private CallingClass() {} - - public static Class forDepth(int depth) { - return instance.getClassContext()[depth]; - } -} diff --git a/src/main/java/com/obsidiandynamics/zerolog/util/Stacks.java b/src/main/java/com/obsidiandynamics/zerolog/util/Stacks.java new file mode 100644 index 0000000..ea1d021 --- /dev/null +++ b/src/main/java/com/obsidiandynamics/zerolog/util/Stacks.java @@ -0,0 +1,108 @@ +package com.obsidiandynamics.zerolog.util; + +/** + * Utilities for working with the call stack. + */ +public final class Stacks extends SecurityManager { + private static final Stacks instance = new Stacks(); + + private Stacks() {} + + /** + * Obtains the class at the given stack depth. + * + * @param depth The stack depth. + * @return The {@link Class} at the given depth. + */ + public static Class classForDepth(int depth) { + return instance.getClassContext()[depth]; + } + + /** + * Obtains a {@link StackTraceElement} at the location immediately preceding the + * entrypoint. + * + * @param entrypoint The entrypoint. + * @return The preceding {@link StackTraceElement}, or {@code null} if no matching + * location could be obtained. + */ + public static StackTraceElement locate(String entrypoint) { + final StackTraceElement[] elements = Thread.currentThread().getStackTrace(); + final int index = indexOf(entrypoint, elements); + return index != -1 && index < elements.length - 1 ? elements[index + 1] : null; + } + + private static int indexOf(String entrypoint, StackTraceElement[] elements) { + for (int i = 1; i < elements.length; i++) { + final StackTraceElement element = elements[i]; + if (element.getClassName().equals(entrypoint)) { + return i; + } + } + return -1; + } + + /** + * Formats the location in the form <simple class name>.<method name>:<line number>.

+ * + * If a {@code null} element is provided, the resulting location will be returned + * as the string {@code "?.?:?"}. + * + * @param element The stack trace element; may be {@code null}. + * @return The formatted location. + */ + public static String formatLocation(StackTraceElement element) { + if (element != null) { + final String simpleName = getSimpleClassName(element.getClassName()); + return simpleName + "." + element.getMethodName() + ":" + element.getLineNumber(); + } else { + return "?.?:?"; + } + } + + /** + * Returns the simple name of the underlying class as given in the source code or + * an empty string if the underlying class is anonymous. This implementation is + * significantly faster than {@link Class#getSimpleName()} as it doesn't require a + * class lookup.

+ * + * This implementation is a close approximation {@link Class#getSimpleName()}; the + * differences are:
+ * 1. This implementation ignores array component types.
+ * 2. Extraneous $ characters are mistaken for an inner/local/anonymous class demarcator.
+ * 3. This implementation is more lenient, allowing certain invalid characters.
+ * + * @param className The class name. + * @return The simple name of the given class. + */ + public static String getSimpleClassName(String className) { + final int lastDollar = className.lastIndexOf('$'); + if (lastDollar != -1) { + // inner, local or anonymous class + final int length = className.length(); + int index = lastDollar + 1; + + // skip over any leading digits that follow '$' in anonymous classes + while (index < length && isAsciiDigit(className.charAt(index))) { + index++; + } + return className.substring(index); + } else { + // top-level class + final int lastDot = className.lastIndexOf('.'); + return lastDot != -1 ? className.substring(lastDot + 1) : className; + } + } + + /** + * Checks if the given character is an ASCII digit. Differs from {@link Character#isDigit()} + * in that the latter considers the Unicode character set and answers {@code true} to some + * non-ASCII digits. + * + * @param ch The character to test. + * @return True if the character is an ASCII digit. + */ + private static boolean isAsciiDigit(char ch) { + return '0' <= ch && ch <= '9'; + } +} diff --git a/src/test/java/com/obsidiandynamics/zerolog/util/CallingClassTest.java b/src/test/java/com/obsidiandynamics/zerolog/util/CallingClassTest.java deleted file mode 100644 index 149c850..0000000 --- a/src/test/java/com/obsidiandynamics/zerolog/util/CallingClassTest.java +++ /dev/null @@ -1,39 +0,0 @@ -package com.obsidiandynamics.zerolog.util; - -import static org.junit.Assert.*; - -import org.junit.*; - -import com.obsidiandynamics.assertion.*; - -public final class CallingClassTest { - private final Class staticField = CallingClass.forDepth(1); - - @Test - public void testConformance() { - Assertions.assertUtilityClassWellDefined(CallingClass.class); - } - - @Test - public void testCallerDepth1() { - final Class cls = CallingClass.forDepth(1); - assertEquals(CallingClassTest.class, cls); - } - - private static class Nested { - static Class get() { - return CallingClass.forDepth(2); - } - } - - @Test - public void testCallerDepth2() { - final Class cls = Nested.get(); - assertEquals(CallingClassTest.class, cls); - } - - @Test - public void testStaticField() { - assertEquals(CallingClassTest.class, staticField); - } -} diff --git a/src/test/java/com/obsidiandynamics/zerolog/util/StacksTest.java b/src/test/java/com/obsidiandynamics/zerolog/util/StacksTest.java new file mode 100644 index 0000000..c043e32 --- /dev/null +++ b/src/test/java/com/obsidiandynamics/zerolog/util/StacksTest.java @@ -0,0 +1,134 @@ +package com.obsidiandynamics.zerolog.util; + +import static org.junit.Assert.*; + +import java.util.concurrent.atomic.*; + +import org.junit.*; + +import com.obsidiandynamics.assertion.*; + +public final class StacksTest { + private static final class Inner { + static final Class staticField = Stacks.classForDepth(1); + } + + @Test + public void testConformance() { + Assertions.assertUtilityClassWellDefined(Stacks.class); + } + + @Test + public void testCallerDepth1() { + final Class cls = Stacks.classForDepth(1); + assertEquals(StacksTest.class, cls); + } + + private static class Nested { + static Class get() { + return Stacks.classForDepth(2); + } + } + + @Test + public void testCallerDepth2() { + final Class cls = Nested.get(); + assertEquals(StacksTest.class, cls); + } + + @Test + public void testStaticField() { + assertEquals(Inner.class, Inner.staticField); + } + + @Test + public void testLocationFound() { + final StackTraceElement element = Stacks.locate(Stacks.class.getName()); + assertNotNull(element); + assertEquals(StacksTest.class.getName(), element.getClassName()); + assertEquals("testLocationFound", element.getMethodName()); + } + + @Test + public void testLocationNotFound() { + assertNull(Stacks.locate("foo")); + } + + @Test + public void testLocationNotFoundTooShallow() throws Throwable { + final AtomicReference error = new AtomicReference<>(); + final Thread thread = new Thread(() -> { + try { + assertNull(Stacks.locate(Thread.class.getName())); + } catch (Throwable e) { + error.set(e); + } + }); + thread.start(); + thread.join(); + if (error.get() != null) { + throw error.get(); + } + } + + @Test + public void testGetSimpleClassNameTopLevel() { + final Class cls = StacksTest.class; + assertEquals(cls.getSimpleName(), Stacks.getSimpleClassName(cls.getName())); + } + + @Test + public void testGetSimpleClassNameTopLevelInvalidChars() { + final String className = "package.$+Class"; + // the getSimpleClassName() implementation is a little more lenient than Class.getSimpleName() + assertEquals("+Class", Stacks.getSimpleClassName(className)); + } + + @Test + public void testGetSimpleClassNameInner() { + final Class cls = StacksTest.Inner.class; + assertEquals(cls.getSimpleName(), Stacks.getSimpleClassName(cls.getName())); + } + + private static class In0 { + static class In1 {} + } + + @Test + public void testGetSimpleClassNameInner2() { + final Class cls = StacksTest.In0.In1.class; + assertEquals(cls.getSimpleName(), Stacks.getSimpleClassName(cls.getName())); + } + + @Test + public void testGetSimpleClassNameAnonymous() { + final Class cls = new Object() {}.getClass(); + assertEquals(cls.getSimpleName(), Stacks.getSimpleClassName(cls.getName())); + } + + @Test + public void testGetSimpleClassNameLocal() { + class $Local {} + final Class cls = $Local.class; + // this varies from Class.getSimpleName() + assertEquals("Local", Stacks.getSimpleClassName(cls.getName())); + } + + @Test + public void testGetSimpleClassNameDefaultPackage() { + final Class cls = int.class; + assertEquals(cls.getSimpleName(), Stacks.getSimpleClassName(cls.getName())); + } + + @Test + public void testFormatLocationNonNull() { + final StackTraceElement element = + new StackTraceElement("pkg.Foo$Bar", "doSomething", null, 42); + assertEquals("Bar.doSomething:42", Stacks.formatLocation(element)); + } + + @Test + public void testFormatLocationNull() { + assertEquals("?.?:?", Stacks.formatLocation(null)); + } +}