@Log logger instance visibility

[Tumi]

Hi,

Why the log instance injected by the @Log annotation is declared as private? I think it should be declared as protected by default, so subclasses could use the parent log static field without the need of creating a new logger instances, and of course the developer can always annotate the subclass with its own @Log hiding the parent static field visibility.

Also, attributes to the annotation could be added to change that default visibility, and/or to inject a new getLog() static getter method.

I also propose that @Log could annotate interfaces, in which case of course the static field must be public.

Cheers and happy new year!

[Robbert Jan Grootjans]

Changing the default scoping of a feature might break existing code (though I don't think we think that is too bad if we have a good enough reason). Though I can't think up a use-case at the moment that the change to a default level of protected would break.

Of course, less is more, and I would really like to know what motivation you would have to change the default visibility for your loggers and the reason to inject a getLog() static getter method. I'd say that if you have enough reason to change the default log level, or add specific code, you have the option to write out the logger declaration. If we're missing some often-used cases, I'd love to know which ones.

And, happy new year to you too ;)!

--
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.
For more options, visit https://groups.google.com/groups/opt_out.

[Tumi]

Thanks for your quick response. Let me explain and even go further ;-)

In my humble oppinion or at least in my experience, I think that having one logger instance/subsystem per class is not a good idea. It should be at least per java package. I'm talking about j.u.l. as I have few experience on Log4J and others.

In fact I think in general people doesn't elect well the granularity of the "logger subsystems" (Logger instances in LogManager):

1. If during runtime / configuration you use one global configuration to elect the logging level and the handlers, you actually need only the global logger. This represents probably a 75% of the real cases.
2. If you do need/want to be able to configure different logging levels for different subsystems, definetily you need some coarse-grained logging subsystems to elect the logging level for your core, for your IO subsystem, for your different tiers, etc. But in very rarely situations you will need to tell the System Administrator to change only the logging level of a very specific class and no for others related to its behaviour.

In large, complex systems, defining one logger subsystem per class will not only increase innecesary the memory footprint of the application with tons of Logger instances, but also will do it difficult to administrate.

This was the motivation for proposing to change the logger visibility, but in fact I think that a more realistic proposal is this double change:

@Log

Creates protected static final java.util.logging.Logger log = java.util.logging.Logger.getLogger(LogExample.class.getPackage().getName());

Cheers,
Tumi

[Tumi]

Or even why not package protected instead of protected!

[Robbert Jan Grootjans]

thanks for your reaction, let me see if I can add a few more cents.

We might at two sides of the discussion, information wise, since I do not have a lot of experience with j.u.l. The one I did have was too interspersed with DIY code, and we threw it out in favor of Slf4Jwith a logback backend. The basics of j.u.l. logging are of course not that hard, but configuring loggers is something that might be a bit harder than say in Log4J or Slf4J. 

So, though I'm not really sure about the options in j.u.l., the configuration of loggers in Slf4J implementation (log4j, logback, log4j2, ... ) all seem to have a lot of convenience to configure groups of loggers based on their package name. I agree that in most systems a single, global, log output, is more than enough. But that use case is really easy in these systems, and using a single logging instance does not really make easier. It does however make it harder when you do want to differentiate in a deployed instance. And though this use case is probably not very common (or something you want to avoid), using a single logger will, afaik, result in a situation where all differentiating information is gone.

The memory footprint of the individual loggers for the types of applications I have worked with pales in comparison to the entire class/perm-gen overhead. I must admit I don't have hard figures, and only the word of the implementers of Log4J and Logback. Though they seem to have a fun time pointing towards each other when mentioning performance (http://logback.qos.ch/reasonsToSwitch.html, http://logging.apache.org/log4j/2.x/performance.html). Of course, j.u.l. is never mentioned here, and neither is a comparison of memory footprint. In general people seem to care more about memory throughput because it can become a bottleneck when you do a rather large amount of logging on a JVM. In short, I don't really see the memory argument here, but have zero figures to back myself up. 100% pure opinion and gut feeling. Perhaps if I feel inspired I'll do a measurement or get lucky and find that someone else has already done this work for me ;)

cheers,

RJ

[Jesús Viñuales]

j.u.l. is a little bit tricky in this sense. If you run this code snippet using the default j.u.l.LogManager:

 

       Logger l1 = Logger.getLogger("org.acme.spacecraft.commons.core.SpecificClass1");

       Logger l2 = Logger.getLogger("org.acme.spacecraft.rocket.engine.boosters.SpecificClass2");

       Logger l3 = Logger.getLogger("org.acmear.spacecraft.rocket.engine.boosters.SpecificClass3");

      

       String configFileContents =

".level = OFF \n"+

"org.acme.spacecraft.commons.level = ALL \n"+

"org.acme.spacecraft.rocket.engine.level = ALL \n" +

"org.acme.spacecraft.rocket.engine.boosters.SpecificClass3.level = OFF \n";

       LogManager logManager = LogManager.getLogManager();

       logManager.readConfiguration(new ByteArrayInputStream(configFileContents.getBytes("UTF-8")));

      

       System.out.println(l1.isLoggable(Level.FINE));

       System.out.println(l2.isLoggable(Level.FINE));

       System.out.println(l3.isLoggable(Level.FINE));

      

       Logger.getLogger("org.acme.spacecraft.commons");

       Logger.getLogger("org.acme.spacecraft.rocket.engine");

      

       System.out.println('-');

       System.out.println(l1.isLoggable(Level.FINE));

       System.out.println(l2.isLoggable(Level.FINE));

       System.out.println(l3.isLoggable(Level.FINE));

 

You will get:

 

false

false

false

-

true

true

false

 

Silly? It is because the parent loggers in the hierarchy are injected by the LogManager only when they are explicitly created in code, so a coarse-grained configuration in a config properties file or ApplicationServer console isn’t available except if you do the hack.

 

This is with the DEFAULT JDK implementation. Please note that JBossAS, WebLogic, WebSphere and Glassfish actually use a more sophisticated LogManager (if I remember well), so this behaviour may change.

 

Cheers!

[Martin Grajcar]

On Tue, Jan 7, 2014 at 7:52 PM, Robbert Jan Grootjans <groo...@gmail.com> wrote:

thanks for your reaction, let me see if I can add a few more cents.

I personally don't have the experience, but I know there are servers producing daily gigabytes of logs on their default level. With something like this you really don't want to switch a whole package to ALL.

 

We might at two sides of the discussion, information wise, since I do not have a lot of experience with j.u.l. The one I did have was too interspersed with DIY code, and we threw it out in favor of Slf4Jwith a logback backend. The basics of j.u.l. logging are of course not that hard, but configuring loggers is something that might be a bit harder than say in Log4J or Slf4J. 

So, though I'm not really sure about the options in j.u.l., the configuration of loggers in Slf4J implementation (log4j, logback, log4j2, ... ) all seem to have a lot of convenience to configure groups of loggers based on their package name. I agree that in most systems a single, global, log output, is more than enough. But that use case is really easy in these systems, and using a single logging instance does not really make easier. It does however make it harder when you do want to differentiate in a deployed instance. And though this use case is probably not very common (or something you want to avoid), using a single logger will, afaik, result in a situation where all differentiating information is gone.

I can only second that. If I encountered the need for differentiate logging, I'd immediately make all loggers private.

 

The memory footprint of the individual loggers for the types of applications I have worked with pales in comparison to the entire class/perm-gen overhead. I must admit I don't have hard figures, and only the word of the implementers of Log4J and Logback. Though they seem to have a fun time pointing towards each other when mentioning performance (http://logback.qos.ch/reasonsToSwitch.html, http://logging.apache.org/log4j/2.x/performance.html).

You mean Ceki talks to himself? ;)

 

Of course, j.u.l. is never mentioned here, and neither is a comparison of memory footprint. In general people seem to care more about memory throughput because it can become a bottleneck when you do a rather large amount of logging on a JVM. In short, I don't really see the memory argument here, but have zero figures to back myself up. 100% pure opinion and gut feeling. Perhaps if I feel inspired I'll do a measurement or get lucky and find that someone else has already done this work for me ;)

Looking at the source of ch.qos.logback.classic.Logger I can see that the result depends on the logger hierarchy (childrenList) and configuration (aai), so I rather doubt a measurement could be helpful here. I'd say <100 bytes per logger even with non-compressed OOPs.

[Jesús Viñuales]

What do you think of this new proposal?:

·         Admit a default value in the annotation

·         If empty value, same as now: private and initialized with the class name as the logger subsystem name.

·         If present, make the field protected / package protected, and use that specified name

 

@Log

@Log(“subsystemName”)

 

 

J

 

thanks for your reaction, let me see if I can add a few more cents.

[Fabrizio Giudici]

On Wed, 08 Jan 2014 20:31:26 +0100, Jesús Viñuales
<serverpe...@gmail.com> wrote:

> What do you think of this new proposal?:
>
> · Admit a default value in the annotation
>
> · If empty value, same as now: private and initialized with the
> class name as the logger subsystem name.
>
> · If present, make the field protected / package protected, and
> use
> that specified name

I never used and I think I'll never use loggers in the proposed way, but
the enhancement seems backward compatible, not harmful and not hard to
implement... At the end of the day it's one more way to do things, so for
what concerns my useless opinion, it would be ok.


--
Fabrizio Giudici - Java Architect @ Tidalwave s.a.s.
"We make Java work. Everywhere."
http://tidalwave.it/fabrizio/blog - fabrizio...@tidalwave.it

[Reinier Zwitserloot]

.... except this proposal is not 'natural' (as in, it is not easy to fathom what is going on just reading the usage). I'm okay with non-natural usage to an extent, but it is definitely a downside to any proposal, and this proposal is already on shaky ground.

If I see @Log in class A, and @Log("foo") in class B, I can more or less guess that the name is going to change for the generated logger field in class B. So far, so good.

But there's no way I'll guess that this means A's logger is private, but B's logger is protected.

As far as I know, all logging frameworks (the ones worth using, anyway) allow you to configure loggers based on wildcards. Also, the overhead of a created logger is tiny (different threads talk about 1 logger per instance instead of 1 logger per class, so imagine the overhead there!). That's why I think this proposal is on shaky ground.

In the short term, we have other interesting proposals we'll be looking at first.

[Jesús Viñuales]

Yes, you are right about the accesibility of the fied. But please consider adding the value attribute with the name.

Best!

 

De: Reinier Zwitserloot [mailto:rein...@gmail.com]
Enviado el: jueves, 09 de enero de 2014 1:00
Para: project...@googlegroups.com
CC: Jesús Viñuales
Asunto: Re: [project lombok] @Log logger instance visibility

 

.... except this proposal is not 'natural' (as in, it is not easy to fathom what is going on just reading the usage). I'm okay with non-natural usage to an extent, but it is definitely a downside to any proposal, and this proposal is already on shaky ground.

[Reinier Zwitserloot]

Yes, but we have a different solution for this. We assume that, if you wish to change the name of the log field, you'd want to do that in all your classes.

That's a lot of classes. Thus, that's a lot of @Log annotations. You'd have to remember to add the appropriate field name every time you add a @Log variant to your classes.

We've been working on a 'configuration' system, to allow you to configure lombok on a per-project (or per-package, as you wish) basis, and this is one of the launch features for the configuration system: The ability to configure the name of the field that @Log (and @Slf4j etc) generate. This way, you only need to configure this once, for your project.

It's not out yet, but if you want to see what we're up to, you can check out the 'configuration' branch on github.com/rzwitserloot/lombok and check it out.

 --Reinier Zwitserloot

[Tumi]

Cool! Sounds really interesting and plenty of possibilities.

I will try to make time to try it. By the way, I didn't explained it well, I was not talking about the name of the variable (though it is a good idea to make it configurable), but about the "logger subsystem name" (which currently is the class name, but it could be some arbitrary name specified as value in each annotation (@Log("CORE"), @Log("IO") etc)

Cheers,
Tumi

---

From: Reinier Zwitserloot <rein...@gmail.com>

Date: Wed, 22 Jan 2014 19:59:23 +0100

To: Jesús Viñuales<serverpe...@gmail.com>

ReplyTo: rei...@zwitserloot.com

Cc: project-lombok<project...@googlegroups.com>

Subject: Re: [project lombok] @Log logger instance visibility

[Roel Spilker]

IF we're ever going to make it, It probably won't be the value parameter. so instead of @Log("fooooo") it would become @Log(loggerName="foooooo") or something like that.

[Reinier Zwitserloot]

Do all logging systems offer string-based naming?

[Jesús Viñuales]

Good question. I think so. For the currently supported logging frameworks at least, see:

 

@CommonsLog : http://commons.apache.org/proper/commons-logging/apidocs/org/apache/commons/logging/LogFactory.html#getLog(java.lang.String)

 

@Log : http://docs.oracle.com/javase/6/docs/api/java/util/logging/Logger.html#getLogger(java.lang.String)

 

@Log4j : http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/Logger.html#getLogger(java.lang.String)

 

@Log4j2 : http://logging.apache.org/log4j/2.0/log4j-api/apidocs/org/apache/logging/log4j/LogManager.html#getLogger(java.lang.String)

 

@Slf4j : http://www.slf4j.org/apidocs/org/slf4j/LoggerFactory.html#getLogger(java.lang.String)

 

@XSlf4j : http://www.slf4j.org/apidocs/org/slf4j/ext/XLoggerFactory.html#getXLogger(java.lang.String)

[Reinier Zwitserloot]

Hmm, so, do we add this? my principal worry is that users will misunderstand (as I did) what @Log("HelloWorld") means. I'm afraid they think this means a logger field will be created that is called 'HelloWorld' instead of 'log'. We can fix it with @Log(name="HelloWorld"), except everything I can come with for the name of that field ('name' in the example before) is still easily interpreted as the wrong thing. 'name', 'logName', 'loggerName', etc. Perhaps 'id'? Doesn't really look right to me, though.

[Tumi]

As these names are technically calle "logging system name" (at lears in the JUL world), I would vote for @Log(system="name") or Log(logName="name").

Surely this isn't prioritary as no other for now has talked anything in this sense and you are not sure about it, this can be delayed.

Thank you anyway!!

---

From: Reinier Zwitserloot <rein...@gmail.com>

Sender: project...@googlegroups.com

Date: Fri, 31 Jan 2014 08:07:25 -0800 (PST)

To: <project...@googlegroups.com>

ReplyTo: project...@googlegroups.com

[Mike Power]

topic?

[Reinier Zwitserloot]

"topic" has got my vote. This is getting added to lombok in the near future.

[Tumi]

Great!!

---

From: Reinier Zwitserloot <rein...@gmail.com>

Sender: project...@googlegroups.com

Date: Thu, 6 Feb 2014 11:37:05 -0800 (PST)

To: <project...@googlegroups.com>

ReplyTo: project...@googlegroups.com

[eric.giese]

Ist this feature really necessary?

If you don't use per-class based logging but only very few named loggers, you can as well use a constant and import it statically. Thats more concise than anything that lombok will do for you.

Besides, not using per-class loggers is non-standard really just an antipattern in all projects where I've seen it.

[Reinier Zwitserloot]

Oh, and we were so close :P

Statically import a public static log field initialized with a single name? That's.... yeah, I can see how that's actually quite concise, scalable, etc.

Anyone else wanna chime in? I'm particularly interested in the use cases of the topically named loggers; personally I always just use named-after-class and then use patterns in the log settings if I want to change behaviour depending on the source of the logs. Generally, at package scale. What are the use cases specifically for explicit topic loggers?