I’ve been thinking about this a lot. There are a few issues. 1. I’d like to not have to generate new source code for every class doing logging. I am not sure how Lombok does it but I will want to investigate that. 2. Your solution looks like it is still done at runtime. I would like to do it at compile time. My though is to use the annotation processor and generate a new class that captures all the stack trace elements.I would then replace every logging call with a LogBuilder call. So logger.info <http://logger.info/>(“Hello {}”, user); would become logger.atInfo().withLocation(Log4jLocations.locations.get(“ThisFQCN”)).log(“Hello {}”, user);
So, like Lombok, any class wanting this would be annotated with @Log4j2, but in addition to getting a logger declared they would also have the locations generated. The issues I have are a) I haven’t figured out how Logbok performs its magic without generating new code or affecting line numbers, b) I haven’t figured out how to get the location information while in the annotation processor. However, to solve b I think it is just a matter of walking through the source code, which has to be done anyway to find all the logger calls. Ralph > On Jul 9, 2022, at 3:04 AM, Volkan Yazıcı <vol...@yazi.ci> wrote: > > Inspired by this SO post <https://stackoverflow.com/a/72437386/1278899> and > with some help from Piotr <https://stackoverflow.com/a/72916795/1278899>, I > have drafted an example where I redefine a class such that every logger > call is preceded with a static source location capture. The experiment aims > to replace the current source location capture that uses an exception-based > expensive mechanism with inlining the source location using bytecode > weaving. The sources are publicly available on GitHub. > <https://github.com/vy/asm-playground/tree/master/src/main/java/com/vlkan> > In a nutshell, the magic is as follows: > > I have a logger library (Log4j.java > <https://github.com/vy/asm-playground/blob/master/src/main/java/com/vlkan/Log4j.java>) > as follows: > > public static final ThreadLocal<SourceLocation> LOCATION_REF = > ThreadLocal.withInitial(SourceLocation::new); > > public static void log() { > SourceLocation location = LOCATION_REF.get(); > boolean locationProvided = location.lineNumber > 0; > if (!locationProvided) { > StackTraceElement[] stackTraceElements = new > Throwable().getStackTrace(); > // Skip the first element pointing to this method. > StackTraceElement stackTraceElement = stackTraceElements[1]; > location.init( > stackTraceElement.getFileName(), > stackTraceElement.getClassName(), > stackTraceElement.getMethodName(), > stackTraceElement.getLineNumber()); > } > System.out.format( > "[%s] %s%n", > location, > locationProvided ? "provided location" : "populated > location"); > } > > Here note how `log()` uses a thread-local to see if there is already a > `SourceLocation` provided. If so, it leverages that, otherwise it populates > the source location using the stack trace of an exception. > > Below is my actual application (AppActual.java > <https://github.com/vy/asm-playground/blob/master/src/main/java/com/vlkan/AppActual.java>), > that is, what the actual/existing user code looks like: > > public static void main(String[] args) { > System.out.println("should log at line 9"); > log(); > System.out.println("nothing to see here"); > System.out.println("should log at line 12"); > log(); > f(); > } > > private static void f() { > System.out.println("adding some indirection"); > System.out.println("should log at line 19"); > log(); > } > > I want to transform this into the following expected form (AppExpected.java > <https://github.com/vy/asm-playground/blob/master/src/main/java/com/vlkan/AppExpected.java>) > that exploits the `LOCATION_REF` thread-local to inline the source location > information: > > public static void main(String[] args) { > System.out.println("should log at line 9"); > LOCATION_REF.get().init("AppExpected.java", > "com.vlkan.AppExpected", "main", 9); > log(); > System.out.println("nothing to see here"); > System.out.println("should log at line 12"); > LOCATION_REF.get().init("AppExpected.java", > "com.vlkan.AppExpected", "main", 12); > log(); > f(); > } > > private static void f() { > System.out.println("adding some indirection"); > System.out.println("should log at line 19"); > LOCATION_REF.get().init("AppExpected.java", > "com.vlkan.AppExpected", "main", 19); > log(); > } > > And... 👉 AppTransforming.java > <https://github.com/vy/asm-playground/blob/master/src/main/java/com/vlkan/AppTransforming.java> > 👈, my dear friends, performs exactly this transformation: converts > `AppActual` bytecode into `AppExpected`. 😍 > > I think we can extend this experiment to implement zero-cost source > location capture for Log4j. Though I will appreciate your help on some > loose ends. Assuming we have a bullet-proof mechanism to inline source > location capture given a class, what is the right way to ship this? As a > Maven plugin that kicks in at compile time? Wouldn't that make this feature > impossible to use without recompiling user sources? As a runtime utility? > If so, what about the cost of classpath scanning & weaving? If the bytecode > weaving only intercepts at Log4j API calls, this won't work for Log4j 1 > bridge, SLF4J, or any other indirect access to the Log4j API. What do you > think? I have used a thread-local to pass the source location to the > caller, is there a better alternative? (Putting aside the dynamic-scoped > variables to be shipped with Loom.)
