Could Lombok help with log context?

[Matei]

Hi,

One feature I miss in Java coming from C++ is that log statements cannot automatically pinpoint the source location of the log message. In C++, log statements can be preprocessor macros that use other compiler-specific macros that refer to the file and line number where the log message comes from. In Java on the other hand, I don't know of a way to do this without paying the cost of walking up stack traces. I believe Log4J2 has options related to this, with disclaimers that using them will be slow. As a result, log messages tend to look like:

void a() {

   log.info("a start: ", ...);

   log.info("a end: ", ...);

}

void b() {

   log.info("b start: ", ...);

   log.info("b end: ", ...);

}

The boilerplate here are the log prefixes.

Since Lombok has the ability to modify existing classes during annotation processing, is there a way Lombok could help with this issue? Assuming log comes e.g. from @Slf4j, could Lombok be used to configure a prefix for log messages, based on things not normally available, such as method name and line number? E.g.:

@Slf4j(prefix = "${methodName}:${lineNumber} ")

Thanks,

Matei

[Joseph Ottinger]

Loggers in Java already have that facility: it's part of the logging pattern. The logger line itself has no need to incorporate the line number. Note that generating the line number isn't *fast* but the facility is already there.

--
You received this message because you are subscribed to the Google Groups "Project Lombok" group.
To unsubscribe from this group and stop receiving emails from it, send an email to project-lombo...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/4ac068bd-1bf4-4794-8e68-fc69d2b3b2bd%40googlegroups.com.

--

Joseph B. Ottinger
http://www.enigmastation.com

Memento mori.

[Matei]

"Including location information is done by walking the stacktrace of an exception, which creates temporary objects, so the following patterns are not garbage-free"

https://logging.apache.org/log4j/2.x/manual/garbagefree.html

Yes, loggers may definitely walk up stacktraces, which is slow, and at least the case of Log4J2 garbage-producing.

What I'm wondering about is whether Lombok could alter the log statement at annotataion processing time to append a configurable prefix, so that getting the location is neither slow nor garbage-producing.

On Saturday, October 19, 2019 at 11:11:08 PM UTC-4, Joseph Ottinger wrote:

Loggers in Java already have that facility: it's part of the logging pattern. The logger line itself has no need to incorporate the line number. Note that generating the line number isn't *fast* but the facility is already there.

On Sat, Oct 19, 2019 at 11:08 PM Matei <matei...@gmail.com> wrote:

Hi,

One feature I miss in Java coming from C++ is that log statements cannot automatically pinpoint the source location of the log message. In C++, log statements can be preprocessor macros that use other compiler-specific macros that refer to the file and line number where the log message comes from. In Java on the other hand, I don't know of a way to do this without paying the cost of walking up stack traces. I believe Log4J2 has options related to this, with disclaimers that using them will be slow. As a result, log messages tend to look like:

void a() {

   log.info("a start: ", ...);

   log.info("a end: ", ...);

}

void b() {

   log.info("b start: ", ...);

   log.info("b end: ", ...);

}

The boilerplate here are the log prefixes.

Since Lombok has the ability to modify existing classes during annotation processing, is there a way Lombok could help with this issue? Assuming log comes e.g. from @Slf4j, could Lombok be used to configure a prefix for log messages, based on things not normally available, such as method name and line number? E.g.:

@Slf4j(prefix = "${methodName}:${lineNumber} ")

Thanks,

Matei

--
You received this message because you are subscribed to the Google Groups "Project Lombok" group.

To unsubscribe from this group and stop receiving emails from it, send an email to project...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/4ac068bd-1bf4-4794-8e68-fc69d2b3b2bd%40googlegroups.com.

[Joseph Ottinger]

Without trying to speak for the Lombok developers, I'd say it's possibly doable, but not likely; the extra garbage created by the loggers is slow, but not actually slow, and the garbage is created, but not actually impactful under most circumstances. It'd be more effort than it's worth, IMO, but obviously they make their own decisions about such things.

To unsubscribe from this group and stop receiving emails from it, send an email to project-lombo...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/bdbedf16-2b73-4f8e-9dfc-225a95f65bec%40googlegroups.com.

[Martin Grajcar]

This is something I always wanted, too (Disclaimer: I'm not a Lombok team member). Maybe I even posted about it, but my idea was more complicated (something like string interpolation or alike). Yours

@Slf4j(prefix = "${methodName}:${lineNumber} ")

is much simpler. Concerning the overhead for stack walking, it got better with https://openjdk.java.net/jeps/259, but it's still not free. I don't know all the details, but, apart from garbage, one problem is that the stack we want to see hardly corresponds with the real stack due to inlining, etc., so some non-trivial mapping must be done.

IMHO it'd be very useful. Sometimes, there's some useful information to be added to the message, but most of the time it's not worth it, so I end up with "start"/"end" just as you wrote. However, I'd prefer a lombok.config setting for it as I'd prefer to format all messages the same.

--

You received this message because you are subscribed to the Google Groups "Project Lombok" group.
To unsubscribe from this group and stop receiving emails from it, send an email to project-lombo...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/4ac068bd-1bf4-4794-8e68-fc69d2b3b2bd%40googlegroups.com.

[Reinier Zwitserloot]

Forget the abilities and limitations of java for a second. Just look at the log API itself.

Clearly, 'including the method name and line number here' is part of the 'pattern' side of things, it has absolutely no business whatsoever being part of the code that creates the log message.

Thus, having lombok add this is _SOLELY_ a crappy workaround (in that it is a leaky abstraction and makes your code messy and confusing by putting things in places they should not be, and basically messing up a large point of a logging system which is that you configure the format in a single place, and not at the 812430 log statements smeared out across your entire code base).

If that's just how its gotta be (the job is common, and almost everybody is ALREADY doing this crap workaround, knowing full well how ugly it is, but there is simply no alternative), i can see lombok coming to the rescue, but this is not common, and I see no proof that the garbage-ful stackwalker strategy is ACTUALLY slow; the log frameworks DO avoid the cost when the log statement doesn't go anywhere (example: a FINER level log statement when that level is disabled), or does not include the need to include the method name in the first place, and otherwise it 'fast garbage' (turns into garbage almost immediately after creation and is never shared with other threads, though that optimization might not currently apply to stack traces).

That means: [A] I _REALLY_ want to see profiler reports showing how big of a problem this is, and then [B] even then I'm really hesitant on this; this is a thing the JVM should be fixing. If we fix it now that's just a great way to end up with a ton of lombok features that make no sense whatsoever (give it 2 years and java is much better at this, and now we still have to maintain a lombok feature that is just a stupid idea unless you're running on old VMs). I don't think that's a good place for lombok to be.

If there is a logging framework out there that lets you optionally pass in method name to avoid the stackwalker overhead, I can definitely foresee a lombok feature that will silently replace your log-calls with this alternative variant, but given that the log frameworks _THEMSELVES_ do not, apparently,  consider this enough of a big deal to try to at least adapt their API to deal with the crappy situation as best as they can, well, I don't see why lombok should sacrifice itself on the altar of pragmatism, in trade of ending up in a scenario where we are on the hook for maintaining a useless feature.

I rate it snowball's chance, in other words. I need an in-depth performance and profiler analysis showing this is REALLY pricey, and how it is HIGHLY unlikely java will just solve this on its own within the next 5 years.

To unsubscribe from this group and stop receiving emails from it, send an email to project-lombok+unsubscribe@googlegroups.com.

[Matei]

Well, at least the answer was very entertaining. :)

I agree it's merely a fix for a JVM hiccup, I just wanted to put it out there.

One thing I would add is that because of the warning and the garbage potential, I personally would never run log4j2 with those flags in a low latency PROD, therefore I could never rely on method name & line no being available when I need them, therefore I would always use the boilerplate prefix, a small price to pay versus the gamble posed by GC disruption (which I confess don't fully understand). In other words, there is no way I will stop using the silly prefixes due to improvements in the stack trace API, certainly not with log4j2's note out there in its current form.

To unsubscribe from this group and stop receiving emails from it, send an email to project...@googlegroups.com.

[Jan Materne]

If you really need that, you could try to get it with AOP tools and bytecode weaving. In that way you dont have to annotate as much ...

Jan

To unsubscribe from this group and stop receiving emails from it, send an email to project-lombo...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/6a553f2b-6db7-477b-ac24-885884234c82%40googlegroups.com.

[Martin Grajcar]

 but given that the log frameworks _THEMSELVES_ do not, apparently,  consider this enough of a big deal to try to at least adapt their API to deal with the crappy situation as best as they can

But there's *nothing* they can do:

An slf4j Logger has five logging levels. Each logging method has variants with and without a Marker. There's a few overloads there:

trace(Exception e);

trace(String format);

trace(String format, Object arg);

trace(String format, Object arg1, Object arg2);

trace(String format, Object... args);

All in all, there are 5 * 2 * 5 = 50 logging methods, that's a lot.

20% of them are AFAIK superfluous (at least in Logback, an exception as the last argument gets special treatment, anyway).

60% of them exist only in order to avoid garbage (which is important here as it concerns the case of disabled loggers, too).

Adding something like

trace(String methodName, int lineNo, String format)

would mean doubling the already huge API size (or worse: introducing irregularities).

Obviously, without Lombok (or another tool) being so nice and filling the arguments, nobody would use these overloads.

Would you add 50 unusable methods to an API?

That all said, your other arguments are unfortunately valid.

Thus, having lombok add this is _SOLELY_ a crappy workaround (in that it is a leaky abstraction and makes your code messy and confusing by putting things in places they should not be, and basically messing up a large point of a logging system which is that you configure the format in a single place, and not at the 812430 log statements smeared out across your entire code base).

I'd be happy to write logging statements like

trace(a, b+c)

which would get transformed into

trace("someMethodName:42 a={}, b+c={}", a, b+c)

with no local configuration whatsoever. While some people care about nice-looking self-explaining all-in-one log lines, I don't give a damn.

All I need is that all important information is present and this should be achieved with minimal overhead per statement.

To unsubscribe from this group and stop receiving emails from it, send an email to project-lombo...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/4ac068bd-1bf4-4794-8e68-fc69d2b3b2bd%40googlegroups.com.

--

You received this message because you are subscribed to the Google Groups "Project Lombok" group.

To unsubscribe from this group and stop receiving emails from it, send an email to project-lombo...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/61318c66-b3e8-490c-af0a-0b5e57a07068%40googlegroups.com.

[Moises Lejter]

As an alternative - Log4j has (had?) this notion of a "mapped diagnostic context" (MDC), which is a map that can be used to provide data to be used in the log output (MDC keys can be included in the template, and Log4j will replace them with their values).  Lombok could generate code to automatically add "methodName" and 'lineNumber" keys to the MDC prior to each call to a logger method, and then people could take advantage of these in their templates?

I don't know if this is available in other logging frameworks - but it seems like a simple thing to add, at least in the case of Log4j...

Moises

To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/CAGsWfGgwPg18fJwssW48rxim4T1igzuvJninpXVYM49hnKQyfg%40mail.gmail.com.

[Matei]

Following the discussion, it feels like there are a number of Java hiccups that Lombok could potentially help with, more than mentioned in the OP:

- Add method name and line number, to eliminate the log message format prefix.

- Add a default format, to eliminate log message format altogether.

- Eliminate the need to box primitives.

- Eliminate the boilerplate needed to ensure conditional execution, which is either a capturing lambda or an if statement.

So this current code:

log.info("update: aString={}, anInt={}, aResult={}", aString, box(anInt), () -> f());

... could be written as:

log.info(aString, anInt, f());

... and transformed by Lombok into:

if (log.isInfoEnabled) {

    final StringBuilder sb = lombok.Helper.reserveThreadLocalStringBuilder();

    sb

        .append("update:42:")

        .append(" aString=")

        .append(aString)

        .append(" anInt=")

        .append(anInt)

        .append(" f()=")

        .append(f());

    log.info("{}", sb);

    lombok.Helper.releaseThreadLocalStringBuilder(sb);

}

Now, isn't that exciting?

To unsubscribe from this group and stop receiving emails from it, send an email to project...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/4ac068bd-1bf4-4794-8e68-fc69d2b3b2bd%40googlegroups.com.

--
You received this message because you are subscribed to the Google Groups "Project Lombok" group.

To unsubscribe from this group and stop receiving emails from it, send an email to project...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/61318c66-b3e8-490c-af0a-0b5e57a07068%40googlegroups.com.

--
You received this message because you are subscribed to the Google Groups "Project Lombok" group.

To unsubscribe from this group and stop receiving emails from it, send an email to project...@googlegroups.com.

[Reinier Zwitserloot]

I'm not excited. Except about the bit where 'log.info(a + b)' turning into a log line that includes the string "a + b", verbatim - now that IS exciting.

The onus of adding a runtime component really sucks though. But, what is the point of having a threadlocal StringBuilder? Isn't the new indy based string concat built into javac itself good enough here? I believe a single expression using + to concat many strings is fine (what's still not fine is something like: String z = ""; for (String a : list) z += a; // nope; you should be using a StringBuilder instead).

But this still means we need to be in the business of making an API. There are already 10 logging APIs, I really don't think we should be in the business of adding another. The lambda unwrap is not needed; given that lombok would already inject an if (logLevelIsEnabled) guard, you can just call f() there. All we're adding here is the method name, and line number, and.. we did not solve the problem where the formatting of these elements relative to the things the log frameworks add for you (logger name which hopefully gives the class name, without which the method name and line number is kinda useless, the level, and a timestamp).

So, cool, but, I kinda need a logger framework builder on board as well at least.

[Martin Grajcar]

On Thu, Oct 31, 2019 at 8:23 AM Reinier Zwitserloot <rein...@gmail.com> wrote:

I'm not excited. Except about the bit where 'log.info(a + b)' turning into a log line that includes the string "a + b", verbatim - now that IS exciting.

For me, the method name and line number are much more important.... it'd allow me to only care about what to log, without needing to describe it (sure, a good logging message is important, but only for important log lines).

 

The onus of adding a runtime component really sucks though. But, what is the point of having a threadlocal StringBuilder? Isn't the new indy based string concat built into javac itself good enough here? I believe a single expression using + to concat many strings is fine (what's still not fine is something like: String z = ""; for (String a : list) z += a; // nope; you should be using a StringBuilder instead).

The thread-local StringBuilder would avoid allocations (except for the resulting string). However, indy may be equally smart or become equally smart in the future. It's quite possible that the cost of thread-local access doesn't pay.

AFAIK the line

log.info("{}", sb);

could be replaced by just

log.info(sb.toString());

But this still means we need to be in the business of making an API. There are already 10 logging APIs, I really don't think we should be in the business of adding another. The lambda unwrap is not needed; given that lombok would already inject an if (logLevelIsEnabled) guard, you can just call f() there. All we're adding here is the method name, and line number, and.. we did not solve the problem where the formatting of these elements relative to the things the log frameworks add for you (logger name which hopefully gives the class name, without which the method name and line number is kinda useless, the level, and a timestamp).

I wouldn't think about the things the log frameworks add as they get always added.... at least with slf4j, it works like this:

• frontend: a message is formed used the provided arguments (e.g., trace("wow: {}", aString) → "wow: " + aString)
• backend: the timestamp and logger name and whatever gets added

There's nothing to configure in the frontend and what Lombok would do is just the frontend. Assuming

import static lombok.Llogger.trace; // this is no typo, when there can be "flogger", why not Lombok's "llogger"?

it would just transform

trace(a + b, c * d);

into

if (log.isTraceEnabled()) {

    log.trace(myMethodName + ":" + myLineNo + ": " + "a + b=" + (a + b) + ", c * d" + (c  * d));

}

It's just some pre-processing. AFAIK with single-argument methods, every logger frontend just passes the argument to the backend (which adds more stuff as configured).

This should work with every logger API. A downside is that existing logger configuration cannot be used for this API. But this is an upside as well as there's nothing there what could be used. And even if there were something useful, it's meant to be reflect changes at runtime, which would be much harder to implement and API-specific.

These are just my thoughts (possibly missing the point of other proposers), but in this form, it's rather simple and yet useful:

• It minimizes the runtime cost.
• It's all compile-time only.
• Importing lombok.Llogger or any of its methods would automatically create a static logger instance of the proper type, if configured so.
• The interaction with the logger framework is pretty non-existent and so the resulting problems.
• There would be just a few var-args(*) methods supporting both the error-warn-info-debug-trace and severe-warning-info-fine-finer-finest lines.
• (*) The var-args are free as they get eliminated by Lombok.

So, cool, but, I kinda need a logger framework builder on board as well at least.

In my proposal, nothing is needed except maybe for some formatting configuration.

To unsubscribe from this group and stop receiving emails from it, send an email to project-lombo...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/379b9fcb-48af-4e68-998e-02c6bfbb8715%40googlegroups.com.

[Matei]

The simple format-free syntax makes me excited is because it allows one to concentrate on business logic, not on logging.

The reason I mentioned a StringBuilder is to ensure garbage-free operation, which goes a long way towards the worry-free aspect. Perhaps a single String concatenation as Maaartin suggests would be fine. I confess I didn't realize Lombok has no runtime component. Still, one could add a StringBuilder mechanism inside a private static inner class.

FTR- If the String-s are not reliable today, one would need a ThreadLocal pool of StringBuilder-s, to allow for the exceptional but alas possible case of recursion occuring during the processing of a log statement: log.info(f()), with the very same statement being reached again while f() is running. Of course this can happen "for real", not just in error. The use pattern of the pool would be that of a Stack, FILO, but a normal ArrayList backing would do just fine.

I also do not understand why any logger apis or backends would need to be explicitly "onboard". The functionality we're talking about affects the logging api exclusively, and we are actually reducing what is needed of the api, not extending it. We are effectively replacing all log.level(fmt, args...) functions by a single log.level("{}", CharSequence). Since the latter is always legal, I don't see why the api would have to be explicitly "onboard". Moreover, the logger backend has nothing to do with all this.

Maaartin: I'm not sure whether log.info(sb.toString()) == log.info("{}", sb). Specifically, is it ok for sb to contain "{}"? Is this a per-backend issue?

In terms on configuration, the api & backend usually configure the log line prefix (timestamps, threads, classes) and the log message is (usually) the log line suffix. With the proposal above, everything is the same, except the log message (not line!) starts with the generated prefix method name & line no, which is what happens nowadays anyhow with ad-hoc message prefixes.

The Lombok solution would need at minimum a new configuration option (also settable from lombok.config) e.g.

@Slf4j(enableLombokFormatting = true)

To accomodate existing code, the option should default to false.

Beyond that, it might be useful to add the option to name the arguments by index instead of copying the string, e.g.

@Slf4j(useArgumentIndexAsName = true)

log.info(a, b+c) => "[0]=5, [1]=7"

This is meant as a fallback solution when the expressions themselves are too cumbersome to have in the log line.

Perhaps something smarter can be done here, specify on a per-call per-argument basis, etc.

To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/379b9fcb-48af-4e68-998e-02c6bfbb8715%40googlegroups.com.

[Pascal]

TL;DR: Yes, it can.

Long story:

In our company, we started (long before log4j or other popular logging frameworks were popular, and Java 1.0 was the only available version) developing our own logging framework, which is very flexible, speed-optimized, catches NPEs on toString(), nicely logs exceptions, collections and arrays, has optional live logging configuration using RMI or using property files, and allows hierarchical, fine grained listener configuration down to method level (many features which are now also available using other logger frameworks).

By definition, we introduced into our production code log statements on every method entry (on "MTD"-Level) and at every interesting point (on DBG-level), e.g. when a variable value changed (to log our app on customer site without any debug possibility). Many, many log calls.

Our benchmarks (long time ago) showed, that every log()-method call is expensive, in comparison to accessing a field. So to have a logging-call to be an almost-no-op, you have to check the logger level before issuing the real method call.

So our code was full with logging code like this (already an optimized version):


package de.qfs.bla;

import de.qfs.lib.log.Log;

class LoggerQFLog {
    private static final de.qfs.lib.log.QFLogger logger =
            new de.qfs.lib.log.QFLogger("de.qfs.bla.LoggerQFLog");

    public LoggerQFLog(final int x) {
        super();
        if (logger.level >= Log.MTD) {
            logger.lvlBuild(Log.MTD, "LoggerQFLog(int)")
                .addDetail("x", x).log();
        }
    }

    public void test(final String blubb, final boolean flag) {
        if (logger.level >= Log.MTD) {
            logger.lvlBuild(Log.MTD, "test(String,boolean)")
                .addDetail("blubb", blubb)
                .addDetail("flag", flag).log();
        }

        System.out.println("In method.");

        if (logger.level >= Log.MSG) {
            logger.lvlBuild(Log.MSG, "test(String,boolean)")
                .add("A message")
                .add("flag", flag)
                .addDetail("blubb", blubb)
                .addAll("list",new java.util.ArrayList())
                .add("done").log();
        }
        if (logger.level >= Log.DBG) {
            logger.lvlBuild(Log.DBG, "test(String,boolean)")
                .add("Some answer: ", 42)
                .addDetail("blubb", blubb)
                .addDetail("flag", flag)
                .dumpStack();
        }
        if (logger.level >= Log.WRN) {
            logger.lvlBuild(Log.WRN, "test(String,boolean)")
                .add("If ").add(blubb)
                .add(" would be ").add(flag)
                .add("...").log();
        }
    }
}

The explicit method and classname strings are required, since the code itself is obfuscated and nobody likes class and method names like "a", "b" or "C" in the log (so inspecting the stacktrace to get the method name in the log()-method is not an option).

And we had all the problems: Code duplication without end, unreadable code, copy-and-paste errors (e.g. when the method signature was changed, nobody changed the strings in the log calls), missing ".log()" calls at the end of the builder...

Entering lombok (and about 2500 lines of custom lombok handlers for Eclipse and Javac, written about 5 years ago):

package de.qfs.bla;

import lombok.extern.qfs.QFLog;

@QFLog
class LoggerQFLog {
    public LoggerQFLog(final int x) {
    }

    public void test(final String blubb, final boolean flag) {

        System.out.println("In method.");

        qflog(MSG,"A message").add(flag).detail(blubb)
        .all("list", new java.util.ArrayList()).add("done.");
        qflog(DBG,"Some answer: ",42).params().dump();
        qflog(WRN,"If " + blubb + " would be " + flag + "...");
    }
}


This saves us *A LOT* of boilerplate code, makes our system flexible while we retain the runtime speed (since the code after generation stays the same), plus a lot of bonus features not doable without lombok:

* Automatic MTD-call generation (also in generated get/is...() and set...() methods from @Getter/@Setter/@Data)
* Automatic label-generation in log calls from the variable names ( i.e. the code-string of the logged value) (like "myVar: " + myVar)
* Automatic enumeration of all method parameters, (with .params())
* Clean code, no duplication, no copy-and-paste errors
* NullPointerException-free "+"-String concatenation
* And finally: Inclusion of line numbers in the log statement (that was the killer feature that finally motivated our CTO to sponsor the lombok project)


Therefore we adore the Lombok guys.

Pascal


PS: Yes, there is a @QFLog(skipMtd=false) and a @QFLog(skipMtdNames={"%get[A-Z].*\(\)"}) if you don't like to log *every* method (and an emacs macro to convert no-lombok-log-constructs to qflog()-calls).

[Reinier Zwitserloot]

Okay, well, geez, Pascal and Maaartin are way ahead of me on this. I have a few final concerns and ideas:

1. I think we SHOULD aim to fully replace the entire logging API. After all, if you're doing relatively exotic things with an exotic logging framework, how would we recognize the actual 'message' part of the log statement, and how would we know what to turn it into? Or should we just let you write your logging statements as you had them, and attempt to 'mess' with them in place, and inject an if-based guarding statement to skip it entirely if the log level is not enabled? Or is it better to let this insta-upgrade your entire project in a single swoop, upgrading ALL already written log statements to include the expression form? I think the latter sounds awesome but is problematic. Turning:

    log.info("chairs: {}", numChairs);

into:

    if (log.isInfoEnabled()) log.info("chairs: numChairs = {}", numChars);

is not good.

I can see an option to give you free if-loglevel-guards for existing code, but rewriting the log statement to include the full expression for _EXISTING_ lines? That part not so much.

So, given that we really kinda WANT those who write logging statements to explicitly indicate they want lombok's expression-in-the-log-statement functionality, why not a separate API?

2. If we replace the API, we can indeed move on from `@Slf4j` and company: Just.. use the public static final `log` field in class `lombok.LombokLogger` and we'll take care of everything else, based on guidance in the lombok.config file about what framework to use. Speaking of: I prefer generating an error that explains what to do if you did not configure this; I prefer this over picking some default logging framework to use if you don't explicitly pick one in lombok.config and also over having 1 `lombok.Slf4jLombokLogger` named class for each and every framework we support.

3. I don't think it is a good idea to suggest to the user that you should/can use static imports to end up with a java statement: `info(a + b)`. That's too obscure to my tastes; it is no longer obvious that line tries to log that expression (including the actual string "a + b") at loglevel INFO. Put `log.` in front of it and I think we're good.

4. IF we go for full API replace, how do we cater to exotic logging features, for example, flogger's `atMostEvery` and `every`? Do we try to add these? Do we then error these if you try to use them if you've got a framework configured that cannot handle them, or do we attempt to find a way to implement these somehow (WITHOUT runtime libs to rely on!)?

5. In perusing the very scarce flogger docs, it looks like I was wrong: There is at least one logging framework that attempts to care about this issue.. and it is flogger. They have the notion of a so-called LogSite which is like a stacktrace but [A] can discern between 2 log statements on the same line (red: who cares) and [B] can be injected into the bytecode with a bytecode post processor tool (red: now we're talking!). Given that replacing your logging code with lombok's logging code is about as much effort as replacing your log frontend framework with flogger, should we still do this, presumably primarily based on the notion that flogger seems like abandonware? For example, I have no idea where to find such a bytecode post-processor for injecting LogSites!

6. What's gonna be the call on StringBuilder, ThreadLocal, and performance? Given that the threadlocal trick requires a _LIST_ of stringbuilders or logging calls cannot themselves execute code that would also produce logging calls without messing everything up, I think that part would add a ton of complexity. But, if the performance of straight string concat just will not do, well, if people like Pascal wouldn't use this feature, why are we bothering to build it?

[Martin Grajcar]

FTR- If the String-s are not reliable today, one would need a ThreadLocal pool of StringBuilder-s, to allow for the exceptional but alas possible case of recursion occuring during the processing of a log statement: log.info(f()), with the very same statement being reached again while f() is running.

IMHO having a single StringBuilder per thread should do as the recursive cases are surely rare enough to be simply handled by a non-pooled StringBuilder.
An alternative is evaluate everything upfront transforming
Llogger.trace(a+b, f(c));
into
if (log.isTraceEnabled()) {
    val $1 = a+b;
    val $2 = f(c); // f may use the very same StringBuilder as the next line, no problem here.
    val $sb = LloggerSupport.getThreadLocalStringBuilder().append("myMethodName").append(':').append(myLineNo).append(": ").append($1).append($2);
    try {
        log.trace($sb.toString());
    } finally {
        $sc.setLength(0);
    }
}

I'm not sure whether log.info(sb.toString()) == log.info("{}", sb). Specifically, is it ok for sb to contain "{}"? Is this a per-backend issue?

We'd need to check all frameworks for this, but the logging methods are heavily overloaded for efficiency reasons and not interpreting the single argument as format is a very trivial optimization.

The Lombok solution would need at minimum a new configuration option (also settable from lombok.config) e.g. @Slf4j(enableLombokFormatting = true)

IMHO no annotation is needed. I wouldn't piggyback on existing framework-specific annotations, but rather start anew.
Using Llogger's static methods would be the trigger and it'd do the above transform and create a log like e.g., @Slf4j does.
All old logging statements would continue to works as is, which would make the transition simple.

Beyond that, it might be useful to add the option to name the arguments by index instead of copying the string, e.g.
@Slf4j(useArgumentIndexAsName = true)
log.info(a, b+c) => "[0]=5, [1]=7"
This is meant as a fallback solution when the expressions themselves are too cumbersome to have in the log line.

Agreed, that some fallback is needed, but it could look like
Llogger.info().unnamed(a, b+c);
I guess, method chaining would allow for a nice and flexible API.

Or should we just let you write your logging statements as you had them, and attempt to 'mess' with them in place, and inject an if-based guarding statement to skip it entirely if the log level is not enabled?

This would be surely interesting for all conservative guys and also for the migration phase.

Just.. use the public static final `log` field in class `lombok.LombokLogger` and we'll take care of everything else, based on guidance in the lombok.config file about what framework to use.

Why not just the static methods lombok.Llogger.trace etc?

I prefer generating an error that explains what to do if you did not configure this; I prefer this over picking some default logging framework to use if you don't explicitly pick one in lombok.config and also over having 1 `lombok.Slf4jLombokLogger` named class for each and every framework we support.

Sure.

I don't think it is a good idea to suggest to the user that you should/can use static imports to end up with a java statement: `info(a + b)`. That's too obscure to my tastes; it is no longer obvious that line tries to log that expression (including the actual string "a + b") at loglevel INFO. Put `log.` in front of it and I think we're good.

The static import is just a user's preference. I actually use them for Preconditions only and I guess, I'd prefer to write Llogger.info.

IF we go for full API replace, how do we cater to exotic logging features, for example, flogger's `atMostEvery` and `every`?

I guess, flogger is far to exotic to be fully supported.

Given that the threadlocal trick requires a _LIST_ of stringbuilders or logging calls cannot themselves execute code that would also produce logging calls without messing everything up,

As I wrote, I believe a ThreadLocal<StringBuilder> should do, no need for a list.

But, if the performance of straight string concat just will not do, well, if people like Pascal wouldn't use this feature, why are we bothering to build it?

A runtime library would allow both more features and better implementation of existing features. For a garbage-free logger, a class to hold the ThreadLocal, which means a runtime library (or an APT-like-generated class or whatever, but there must be only one as e.g., a per class ThreadLocal would be a memory hog). In theory, Lombok could support both, just replace the LloggerSupport.getThreadLocalStringBuilder() call by new StringBuilder().

I could imagine core Lombok working as is and Lombok-ext having a runtime dependency. Obviously, maintaining both means more work, but for the library there'll be way more contributors as it's much easier to do.

--

You received this message because you are subscribed to the Google Groups "Project Lombok" group.

To unsubscribe from this group and stop receiving emails from it, send an email to project-lombo...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/6068c3fe-20b9-449c-85d4-a6057352d0ce%40googlegroups.com.

[Marco Servetto]

Since we are discussing logging a lot....
what is the current support for logging on generated methods, like
what I have to do to log the call to a generated constructor and pass
the newy created object to a custom logging functionality?

> To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/CAGsWfGhS0TeKZwUQxWjYuufK0DyoQ3Vd8gEMfpa-CLWGNfCPwA%40mail.gmail.com.

[Pascal]

I have used a visitor to traverse the source and added the code to every method body, see here:

https://gitlab.com/qfs/qfs-lombok/blob/master/qfs/src/lombok/eclipse/handlers/HandleQFLog.java#L859

https://gitlab.com/qfs/qfs-lombok/blob/master/qfs/src/lombok/javac/handlers/HandleQFLog.java#L714

>> To unsubscribe from this group and stop receiving emails from it, send an email to project...@googlegroups.com.

>> To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/6068c3fe-20b9-449c-85d4-a6057352d0ce%40googlegroups.com.
>
> --
> You received this message because you are subscribed to the Google Groups "Project Lombok" group.

> To unsubscribe from this group and stop receiving emails from it, send an email to project...@googlegroups.com.

[Marco Servetto]

Sorry, I do not know about the inner working of lombok enough to
understand that code,
I do not even understand if you are showing me somethingt that would
be a new feature in lombok....how it would work in the details from a
user perspective?

> To unsubscribe from this group and stop receiving emails from it, send an email to project-lombo...@googlegroups.com.
> To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/74a39fbc-01b1-42e4-a3f7-fc20962c4746%40googlegroups.com.

[Pascal]

Afaik it is not possible to add logging to generated methods using vanilla lombok, you have to program some handler yourself, like shown in my example.

For this extension, the user perspective is: Add @QFLog to the class and get calls to (our) logging framework at the beginning of each method.

> To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/74a39fbc-01b1-42e4-a3f7-fc20962c4746%40googlegroups.com.

[Reinier Zwitserloot]

Almost all of lombok's features generate some code that could feasibly have a log statement on it, but, adding (generateLog = true) style params to almost all lombok annotations seems a tad much. If only you could annotate annotations ;P

I have no problem adding this, except for the bit where we convolute the syntax of lombok features. Does anyone have a good idea how to do this in a rather 'invisible' (perusing the docs of a feature won't force you to also read about the 'add a log statement') way? We could have a @LogGeneratedMethodEntry annotation that applies to everything lombok generated, but now you can't be selective about which method(s) you want them on.

>> To unsubscribe from this group and stop receiving emails from it, send an email to project-lombok+unsubscribe@googlegroups.com.

>> To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/6068c3fe-20b9-449c-85d4-a6057352d0ce%40googlegroups.com.
>
> --
> You received this message because you are subscribed to the Google Groups "Project Lombok" group.

> To unsubscribe from this group and stop receiving emails from it, send an email to project-lombok+unsubscribe@googlegroups.com.

[Martin Grajcar]

We could have a @LogGeneratedMethodEntry annotation that applies to everything lombok generated, but now you can't be selective about which method(s) you want them on.

This would be pretty unusable as you may want to log setter calls and you'd get all getter calls as a bonus. So maybe three orders of magnitude more lines than wanted.

This @LogGeneratedMethodEntry could be made somewhat selective by listing all annotations it should apply to, possibly with an argument exceptFor allowing to specify the methods which shouldn't be logged instead. I guess, with some hack like @__, it could work.

There could be more such things, so aggregating them may justify adding the aggregate to every annotation like

@Getter(value=AccessLevel.PACKAGE, kitchenSink=@__(@LogGeneratedMethodEntry, @LogGeneratedMethodExit, @WhatElse, @AndMore)))

There's an FR which could easily incorporate this: Writing

@MyEtters = @Getter, @Setter+LogGeneratedMethodEntry+LogGeneratedMethodExit

into lombok.config would allow to create composed annotation and also configure them in ways not possible otherwise. The syntax could be more readable with

@MyEtters += @Getter

@MyEtters += @Setter +LogGeneratedMethodEntry +LogGeneratedMethodExit

i.e., one annotation (possibly with standard options) per line possibly followed with your "invisible" options.

The day it gets implemented (if ever), I'll add

@NoEtters += @Getter(AccessLevel.NONE)

@NoEtters += @Setter(AccessLevel.NONE)

@InjectConstructor += @RequiredArgsConstructor(onConstructor=@__(@Inject)))

@LoggedInjectConstructor += @InjectConstructor +LogGeneratedMethodEntry

to my lombok.config.

>> To unsubscribe from this group and stop receiving emails from it, send an email to project-lombo...@googlegroups.com.

>> To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/6068c3fe-20b9-449c-85d4-a6057352d0ce%40googlegroups.com.
>
> --
> You received this message because you are subscribed to the Google Groups "Project Lombok" group.

> To unsubscribe from this group and stop receiving emails from it, send an email to project-lombo...@googlegroups.com.

> To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/CAGsWfGhS0TeKZwUQxWjYuufK0DyoQ3Vd8gEMfpa-CLWGNfCPwA%40mail.gmail.com.

--

You received this message because you are subscribed to the Google Groups "Project Lombok" group.

To unsubscribe from this group and stop receiving emails from it, send an email to project-lombo...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/project-lombok/0c8df1ba-c957-4d1f-af2f-02f5d4c767dd%40googlegroups.com.