slf4j
slf4j copied to clipboard
qos-ch
Implementation of LoggerFactory.getLogger() which determines the calling class name through reflection.
Allows you to change invocations such as LoggerFactory.getLogger(MyClass.class); to LoggerFactory.getLogger();
This is a convenience method for simpler Logger creation, as well as allowing you to copy and paste Logger creation code without having to remember to change the classname.
Hi, Matt;
I did find SecurityManager.getClassContext, which seems to be faster but requires inheriting the class in order to call the package-private method:
- http://stackoverflow.com/a/20869375
- http://www.javaworld.com/article/2077517/core-java/java-tip-20--write-a-custom-security-manager-that-gathers-execution-information.html
- http://docs.oracle.com/javase/7/docs/api/java/lang/SecurityManager.html#getClassContext%28%29
I called Thread.currentThread.getStackTrace() and SecurityManager.getClassContext() one million times in a loop on my machine in Java 6 64-bit.
Results: 2.67 microseconds per call for getStackTrace
Results: 0.58 microseconds per call for getClassContext.
Would that implementation be better? To do this, I would add a small shim like this to the LoggerFactory:
private static class MySecurityManager extends java.lang.SecurityManager {
public Class[] getClassContext() {
return super.getClassContext();
}
};
private static final MySecurityManager INSTANCE = new MySecurityManager();
And then obtain the trace of classes using:
Class[] trace = INSTANCE.getClassContext();
// ... logic to find the right class...
return trace[i].getName();
We could also update documentation to advise people not to call this method in a loop, or check the stack trace to make sure people are calling this method from a static context, or some combination of these options.
What would you like to see?
You should write a benchmark test to see what the cost is for each approach. We might be surprised.
Hi, Matt;
I did run a benchmark on the two options. From my previous comment:
I called Thread.currentThread.getStackTrace() and SecurityManager.getClassContext() one million times in a loop on my machine in Java 6 64-bit. Results: 2.67 microseconds per call for getStackTrace Results: 0.58 microseconds per call for getClassContext.
Is there any other info you'd like to see?
Sorry you're right I see the timings. You'll need to update your pull request to use the Security Manager instead. That seems like the faster way to go.
I have updated the pull request to use the SecurityManager approach instead (and improved the unit test). Please take another look.
@ceki what do you think about the SecurityManager/getClassConext() approach? I agree that stackTrace is not good enough.
I like the fact that it is faster. To state the obvious, I think the LoggerFactory.getLogger(); interface would be a very useful improvement to slf4j-api.
However, given that the the association of logger name with that of the host class is such a central feature we must be 100% sure that it works under all reasonable circumstances. We know that it will work correctly in 99.5% of cases but that is not enough. 100% reliability is what I am looking for,
The question is how to ascertain the reliability of LoggerFactory.getLogger(); without actually releasing this feature to the wider public. Do you have any ideas on how to go about this?
Hi, @ceki;
I would appreciate any suggestions you have to make sure this works properly in all cases. I have added a unit test with all the checks I could think of, including anonymous, instance and static inner classes and nested classes. What else would you like to see? Any specific concerns you have that I could try and test?
Thanks! Alexander.
I was thinking of something more radical than unit tests along the lines of a "field study" phase. During this phase the LoggerFactory.getLogger() method would not be part of the slf4j-api. The main idea is to compare the given logger name to that computed by Util.getCallingClassName() and to raise some sort of alarm when a difference is detected.
That sounds like a good idea. What sort of alarm did you have in mind? Do you want to print a log line when this condition occurs, encouraging people to file a bug?
One thing to be aware of (and one of my primary motivations for implementing this) is that if you have code like this:
class Foo {
private static final Logger LOG = LoggerFactory.getLogger(Foo.class);
And you blindly copy-paste this (probably with a bunch of other stuff) into a class called Bar, you end up with this.
class Bar {
private static final Logger LOG = LoggerFactory.getLogger(Foo.class);
Eclipse and other IDEs will helpfully supply the necessary import to make this compile, and you may not ever notice that your logger is being created with the wrong class.
In this case, the logger's name (Foo) would differ from the value automatically computed value (Bar), but this would not be an error. So some rate of false positives would be expected.
So, what alarm would you like to see?
For the reasons you mentioned there are likely to be many false positives, probably many more than actual true positives that we are looking for. I think we need the involvement of conscientious users who can differentiate between false and true positives. Such users who are also interested in helping out would explicitly enable the comparison check I mentioned earlier via some system property and provide us with their results. The check would be deactivated by default for other users.
Thanks for the clarification. That approach sounds good to me.
Shall I go ahead and code the check you describe as another pull request?
I would need your help finding a suitable user base to test it, as I don't know enough people who use slf4j in interesting circumstances.
Another pull request incorporating the check would be great. The LoggerFactory.getLogger(); method would need to be removed for the time being for reasons discussed above.
As for the beta-testers, the number of slf4j users is quite large, so we'll figure out something.
What would you like to see happen if the field trial is enabled and there is a mismatch of names? Error logged? Exception thrown?
Guava has a @Beta annotation to mark new api in their lib. Maybe slf4j could create something similar?
Any eventual bug in Util.getCallingClassName() , and by richochet in LoggerFactory.getLogger(), could go unnoticed for a long time. Users will not inestigate issues relating to missing logs, especially occasional loss.
I am concerned that if LoggerFactory.getLogger() is released without prior validation and we discover a bug, it could have negative consequences to the reputation of slf4j. One validation mechanism is discussed above.
Just my friendly two cents. While reputation harm might be a concern I do not see that here. There are already multiple ways around this in the wild. Jcabi-logs and various cdi producers. If this does not degrade in speed my guess is that it will do something good and that is to make static analysis tools happy where cdi does not. I plus 1 this solution. I'd also like to see more frequent releases. Not being agile here hurts reputation more these days than new functionality in my opinion.
--- Original Message ---
From: "Ceki Gulcu" [email protected] Sent: December 3, 2014 5:17 AM To: "qos-ch/slf4j" [email protected] Subject: Re: [slf4j] Implementation of LoggerFactory.getLogger() which determines the calling class name through reflection. (#29)
Any eventual bug in Util.getCallingClassName() , and by richochet in LoggerFactory.getLogger(), could go unnoticed for a long time. Users will not inestigate issues relating to missing logs, especially occasional loss.
I am concerned that if LoggerFactory.getLogger() is released without prior validation and we discover a bug, it could have negative consequences to the reputation of slf4j. One validation mechanism is discussed above.
Reply to this email directly or view it on GitHub: https://github.com/qos-ch/slf4j/pull/29#issuecomment-65384742
Maybe a better solution is to pass keyword this into logger factory. Then most concerns go away and what this sets out to solve still is accomplished.
--- Original Message ---
From: "Ceki Gulcu" [email protected] Sent: December 3, 2014 5:17 AM To: "qos-ch/slf4j" [email protected] Subject: Re: [slf4j] Implementation of LoggerFactory.getLogger() which determines the calling class name through reflection. (#29)
Any eventual bug in Util.getCallingClassName() , and by richochet in LoggerFactory.getLogger(), could go unnoticed for a long time. Users will not inestigate issues relating to missing logs, especially occasional loss.
I am concerned that if LoggerFactory.getLogger() is released without prior validation and we discover a bug, it could have negative consequences to the reputation of slf4j. One validation mechanism is discussed above.
Reply to this email directly or view it on GitHub: https://github.com/qos-ch/slf4j/pull/29#issuecomment-65384742
@hazendaz What do you mean by "There are multiple ways around this this in the wild. Jcabi-logs and various cdi producers." ?
As for slf4j-reputation, I should have been more precise. I do not wish to release software with potential bugs in its core even if the feature is very cool. Having said that, there is no denying that there have been no slf4j releases in over 6 months and that's bad. It's just a different kind of bad.
Jcabi logs wraps slf4j so there is no retrieval of logger factory in a class. Their way probably adds unnecessary overhead. Cdi producers allow @inject on loggers so again no direct call to logging factory. With cdi it fails static scans as a result but works well. The producer knows the injection point and thus has the calling class. So basically either one allows users to not duplicate code through copy paste that might end up very well being wrong.
--- Original Message ---
From: "Ceki Gulcu" [email protected] Sent: December 3, 2014 7:59 AM To: "qos-ch/slf4j" [email protected] Cc: "Jeremy Landis" [email protected] Subject: Re: [slf4j] Implementation of LoggerFactory.getLogger() which determines the calling class name through reflection. (#29)
@hazendaz What do you mean by "There are multiple ways around this this in the wild. Jcabi-logs and various cdi producers." ?
Reply to this email directly or view it on GitHub: https://github.com/qos-ch/slf4j/pull/29#issuecomment-65402995
Thank you for your reply. In the case of jcabi-log and cdi, the name of the logger is known. In the case we are discussing here, the caller class needs to be computed.
If this new call is put into a util it will be stuck there forever. Better to put it on LoggerFactory and be optimistic about its success.
We need a way to release more often with experimental or new APIs that are marked as such so the user is aware of their new state. A @Beta annotation would convey this concept without harming the integrity of the product. Guava has both a good reputation and a rapidly evolving API because they give consumers a ways I didn't differentiate old from new. One can consider @Beta as the pair of @Deprecated.
See http://docs.guava-libraries.googlecode.com/git/javadoc/com/google/common/annotations/Beta.html
@hazendaz, the logger factory is (supposed to be) called from static context, so 'this' keyword won't work for this problem.
class Foo {
private static final Logger LOG = LoggerFactory.getLogger(Foo.class);
@ceki, how would you like the notification raised instead of mismatch? Exception thrown? Log message printed?
Okay, I've created a new pull request for the field trial (#91). Please take a look?
@adorokhine I'd like to send you a message by email. Is adorokhine () datagardens ! com (don't mind the obfuscation) the right address ?
@ceki I don't work there anymore so that wouldn't reach me. May I ask where you found that email so I can update it?
You can email cgs at dorokhine dot com.
@adorokhine I just googled for adorokhine, found "Alexander Dorokhine" and googled for that. The datagardens adress came up in an email you sent to the linux-raid mailing list.
@mattbishop writes:
If this new call is put into a util it will be stuck there forever. Better to put it on LoggerFactory and be optimistic about its success.
If the field trial is successful, in LoggerFactory we will add:
static Logger getLogger() { String callerName = Util.getClassName(); return getLogger(callerName); }
Thus, I don't see any issues renaming or moving the Util code. It's completely transparent to the user at this stage (field testing).
I was not aware of the Beta annotation in guava. It's something we could use in conjunction with the LogEvent API I plan to add to slf4j in the near future. I can tell you more on the mailing list if interested.
Happy new year!
How long did you want to leave the field trial in? Any early indications of issues yet?
FYI I have updated this pull request and rebased it onto HEAD.
Cheers, Alex.