Change in properties for logging: deliberate?
Hey folks, I can't find reference to this in a relnote, so I thought I would ask. If we have the following files: logging.properties: # Set the level of the root logger .level = INFO # Send the root logger's output to the console .handlers = java.util.logging.ConsoleHandler Test.java: public class Test { public static void main(String[] args) { java.util.logging.Logger.getAnonymousLogger().info("Hi!"); } } In Java 8, we will see console output, and in Java 9, we won't. # Java 8 $ java -Djava.util.logging.config.file=logging.properties Test Nov 08, 2017 5:02:05 PM Test main INFO: Hi! # Java 9 $ java -Djava.util.logging.config.file=logging.properties Test I thought that, perhaps, a decision was made to have the empty string no longer mean the root logger, so I took it off of .handlers: logging.properties: # Set the level of the root logger .level = INFO # Send the root logger's output to the console handlers = java.util.logging.ConsoleHandler Success in the sense that this got me output in Java 9. However, .level still seems to work; if I then have: # Set the level of the root logger .level = WARNING # Send the root logger's output to the console handlers = java.util.logging.ConsoleHandler it sets the root logger's level to WARNING. I don't see any of this in a relnote anywhere, and I don't see an obvious bug about it anywhere. There seem to have been a fair few changes to java.util.logging in Java 9. Was a documented decision made to have .handlers stop meaning handlers on the root logger, but to allow .level to continue meaning level on the root logger? Or do I just have the wrong end of the stick on this? Thanks! Jeremy
Hi Jeremy, Which jdk version/distribution are you using? I see .level = INFO in the jdk9/master sources: http://hg.openjdk.java.net/jdk9/jdk9/jdk/file/tip/src/java.logging/share/con... There should be no changes WRT the default level between 8 and 9. best regards, -- daniel On 09/11/2017 01:09, Jeremy Manson wrote:
Hey folks,
I can't find reference to this in a relnote, so I thought I would ask. If we have the following files:
logging.properties:
# Set the level of the root logger .level = INFO
# Send the root logger's output to the console .handlers = java.util.logging.ConsoleHandler
Test.java: public class Test { public static void main(String[] args) { java.util.logging.Logger.getAnonymousLogger().info("Hi!"); } }
In Java 8, we will see console output, and in Java 9, we won't.
# Java 8 $ java -Djava.util.logging.config.file=logging.properties Test Nov 08, 2017 5:02:05 PM Test main INFO: Hi!
# Java 9 $ java -Djava.util.logging.config.file=logging.properties Test
I thought that, perhaps, a decision was made to have the empty string no longer mean the root logger, so I took it off of .handlers:
logging.properties:
# Set the level of the root logger .level = INFO
# Send the root logger's output to the console handlers = java.util.logging.ConsoleHandler
Success in the sense that this got me output in Java 9. However, .level still seems to work; if I then have:
# Set the level of the root logger .level = WARNING
# Send the root logger's output to the console handlers = java.util.logging.ConsoleHandler
it sets the root logger's level to WARNING.
I don't see any of this in a relnote anywhere, and I don't see an obvious bug about it anywhere. There seem to have been a fair few changes to java.util.logging in Java 9. Was a documented decision made to have .handlers stop meaning handlers on the root logger, but to allow .level to continue meaning level on the root logger? Or do I just have the wrong end of the stick on this?
Thanks!
Jeremy
Sorry Jeremy, I think I misread your issue. The issue is that .handlers=X behaves differently than handlers=X I'm afraid I might have introduced this regression with https://bugs.openjdk.java.net/browse/JDK-8033661 :-( The obvious workaround for now would be to use handlers= as documented in the logging.properties file. For compatibility reasons then I think we unfortunately must continue to support ".handlers" as well, if that used to work in 8. I logged https://bugs.openjdk.java.net/browse/JDK-8191033 best regards, -- daniel On 09/11/2017 12:36, Daniel Fuchs wrote:
Hi Jeremy,
Which jdk version/distribution are you using?
I see .level = INFO in the jdk9/master sources: http://hg.openjdk.java.net/jdk9/jdk9/jdk/file/tip/src/java.logging/share/con...
There should be no changes WRT the default level between 8 and 9.
best regards,
-- daniel
On 09/11/2017 01:09, Jeremy Manson wrote:
Hey folks,
I can't find reference to this in a relnote, so I thought I would ask. If we have the following files:
logging.properties:
# Set the level of the root logger .level = INFO
# Send the root logger's output to the console .handlers = java.util.logging.ConsoleHandler
Test.java: public class Test { public static void main(String[] args) { java.util.logging.Logger.getAnonymousLogger().info("Hi!"); } }
In Java 8, we will see console output, and in Java 9, we won't.
# Java 8 $ java -Djava.util.logging.config.file=logging.properties Test Nov 08, 2017 5:02:05 PM Test main INFO: Hi!
# Java 9 $ java -Djava.util.logging.config.file=logging.properties Test
I thought that, perhaps, a decision was made to have the empty string no longer mean the root logger, so I took it off of .handlers:
logging.properties:
# Set the level of the root logger .level = INFO
# Send the root logger's output to the console handlers = java.util.logging.ConsoleHandler
Success in the sense that this got me output in Java 9. However, .level still seems to work; if I then have:
# Set the level of the root logger .level = WARNING
# Send the root logger's output to the console handlers = java.util.logging.ConsoleHandler
it sets the root logger's level to WARNING.
I don't see any of this in a relnote anywhere, and I don't see an obvious bug about it anywhere. There seem to have been a fair few changes to java.util.logging in Java 9. Was a documented decision made to have .handlers stop meaning handlers on the root logger, but to allow .level to continue meaning level on the root logger? Or do I just have the wrong end of the stick on this?
Thanks!
Jeremy
Thanks, Daniel. That is the issue. I probably should have described it more clearly. Do you have a sense of a fix timeline? If there is a relatively prompt fix, I can backport it to our internal build instead of introducing churn in our many, many logging configuration files. If it is likely to be a long time, I'll go ahead and change the logging configs. Jeremy On Thu, Nov 9, 2017 at 7:09 AM, Daniel Fuchs <daniel.fuchs@oracle.com> wrote:
Sorry Jeremy,
I think I misread your issue.
The issue is that .handlers=X behaves differently than handlers=X I'm afraid I might have introduced this regression with https://bugs.openjdk.java.net/browse/JDK-8033661 :-(
The obvious workaround for now would be to use handlers= as documented in the logging.properties file.
For compatibility reasons then I think we unfortunately must continue to support ".handlers" as well, if that used to work in 8.
I logged https://bugs.openjdk.java.net/browse/JDK-8191033
best regards,
-- daniel
On 09/11/2017 12:36, Daniel Fuchs wrote:
Hi Jeremy,
Which jdk version/distribution are you using?
I see .level = INFO in the jdk9/master sources: http://hg.openjdk.java.net/jdk9/jdk9/jdk/file/tip/src/java. logging/share/conf/logging.properties
There should be no changes WRT the default level between 8 and 9.
best regards,
-- daniel
On 09/11/2017 01:09, Jeremy Manson wrote:
Hey folks,
I can't find reference to this in a relnote, so I thought I would ask. If we have the following files:
logging.properties:
# Set the level of the root logger .level = INFO
# Send the root logger's output to the console .handlers = java.util.logging.ConsoleHandler
Test.java: public class Test { public static void main(String[] args) { java.util.logging.Logger.getAnonymousLogger().info("Hi!"); } }
In Java 8, we will see console output, and in Java 9, we won't.
# Java 8 $ java -Djava.util.logging.config.file=logging.properties Test Nov 08, 2017 5:02:05 PM Test main INFO: Hi!
# Java 9 $ java -Djava.util.logging.config.file=logging.properties Test
I thought that, perhaps, a decision was made to have the empty string no longer mean the root logger, so I took it off of .handlers:
logging.properties:
# Set the level of the root logger .level = INFO
# Send the root logger's output to the console handlers = java.util.logging.ConsoleHandler
Success in the sense that this got me output in Java 9. However, .level still seems to work; if I then have:
# Set the level of the root logger .level = WARNING
# Send the root logger's output to the console handlers = java.util.logging.ConsoleHandler
it sets the root logger's level to WARNING.
I don't see any of this in a relnote anywhere, and I don't see an obvious bug about it anywhere. There seem to have been a fair few changes to java.util.logging in Java 9. Was a documented decision made to have .handlers stop meaning handlers on the root logger, but to allow .level to continue meaning level on the root logger? Or do I just have the wrong end of the stick on this?
Thanks!
Jeremy
Hi Jeremy, I'm afraid I don't have a timeline at this point, but I will try having a look at the issue in the next couple of days. best regards, -- daniel On 09/11/2017 17:42, Jeremy Manson wrote:
Thanks, Daniel. That is the issue. I probably should have described it more clearly.
Do you have a sense of a fix timeline? If there is a relatively prompt fix, I can backport it to our internal build instead of introducing churn in our many, many logging configuration files. If it is likely to be a long time, I'll go ahead and change the logging configs.
Jeremy
Daniel - we should add this known issue in the release note and document the workaround. Mandy On 11/9/17 9:48 AM, Daniel Fuchs wrote:
Hi Jeremy,
I'm afraid I don't have a timeline at this point, but I will try having a look at the issue in the next couple of days.
best regards,
-- daniel
On 09/11/2017 17:42, Jeremy Manson wrote:
Thanks, Daniel. That is the issue. I probably should have described it more clearly.
Do you have a sense of a fix timeline? If there is a relatively prompt fix, I can backport it to our internal build instead of introducing churn in our many, many logging configuration files. If it is likely to be a long time, I'll go ahead and change the logging configs.
Jeremy
On 09/11/2017 19:16, mandy chung wrote:
Daniel - we should add this known issue in the release note and document the workaround.
Hi Mandy, Right, it either need to be fixed, or documented in the release notes. Let me first have a look at the issue though. best regards, -- daniel
Daniel, I would assume you would fix since it is advertised as a feature over here: https://docs.oracle.com/javase/1.5.0/docs/guide/logging/changes.html If it helps, I've dug up a lot of the history on this over here a while back: https://stackoverflow.com/questions/36726431/in-a-java-util-logging-logging-... I've updated that to include the links to this new issue. Now that I've linked this message thread to that message thread that should crash the internet. :) Jason ________________________________________ From: core-libs-dev <core-libs-dev-bounces@openjdk.java.net> on behalf of Daniel Fuchs <daniel.fuchs@oracle.com> Sent: Thursday, November 9, 2017 1:29 PM To: mandy chung Cc: core-libs-dev@openjdk.java.net Subject: Re: Change in properties for logging: deliberate? On 09/11/2017 19:16, mandy chung wrote:
Daniel - we should add this known issue in the release note and document the workaround.
Hi Mandy, Right, it either need to be fixed, or documented in the release notes. Let me first have a look at the issue though. best regards, -- daniel
Hi Jason, I have done a few tests with JDK 8 & 7. I have created custom handlers and added some debug traces in their constructors and debug methods. Then I have added these two lines to my logging.properties: handlers = custom.Handler .handlers = custom.DotHandler What I see is this: - the first time the configuration is read, two handlers are added to the root logger: - an instance of DotHandler (first), then an instance of Handler (second). Then if you call LogManager.readConfiguration() again, both handlers are closed, and this time only one instance of Handler is added to the root logger. No instance of DotHandler is added. From now on the property is ignored. This is because the root logger is a special beast: it will not be removed (like all other loggers) when LogManager.readConfiguration() is called. And as it happens, handlers are added to loggers when the loggers are added to the LogManager. As it happens, the ".handlers" property is only parsed and read when the root logger is added to the LogManager, and thus only once. The "handlers" property on the other hand is parsed every time LogManager.readConfiguration() is called. Given that, I suspect we should deprecate the use of ".handlers" for the root logger, as it appears that it has never worked properly. I could work on a patch for 10 (possibly backport it to 9 update) to preserve the strange behavior of 7 & 8, but is it worth it? What are your thoughts? best regards, -- daniel On 09/11/2017 19:50, Jason Mehrens wrote:
Daniel,
I would assume you would fix since it is advertised as a feature over here: https://docs.oracle.com/javase/1.5.0/docs/guide/logging/changes.html
If it helps, I've dug up a lot of the history on this over here a while back: https://stackoverflow.com/questions/36726431/in-a-java-util-logging-logging-...
I've updated that to include the links to this new issue. Now that I've linked this message thread to that message thread that should crash the internet. :)
Jason
________________________________________ From: core-libs-dev <core-libs-dev-bounces@openjdk.java.net> on behalf of Daniel Fuchs <daniel.fuchs@oracle.com> Sent: Thursday, November 9, 2017 1:29 PM To: mandy chung Cc: core-libs-dev@openjdk.java.net Subject: Re: Change in properties for logging: deliberate?
On 09/11/2017 19:16, mandy chung wrote:
Daniel - we should add this known issue in the release note and document the workaround.
Hi Mandy,
Right, it either need to be fixed, or documented in the release notes. Let me first have a look at the issue though.
best regards,
-- daniel
Can’t you just deprecate java.util.logging? While I am half kidding, can someone explain why it doesn’t use a ServiceLoader to locate the LogManager implementation? Ralph
On Nov 10, 2017, at 9:04 AM, Daniel Fuchs <daniel.fuchs@oracle.com> wrote:
Hi Jason,
I have done a few tests with JDK 8 & 7.
I have created custom handlers and added some debug traces in their constructors and debug methods.
Then I have added these two lines to my logging.properties:
handlers = custom.Handler .handlers = custom.DotHandler
What I see is this:
- the first time the configuration is read, two handlers are added to the root logger: - an instance of DotHandler (first), then an instance of Handler (second).
Then if you call LogManager.readConfiguration() again, both handlers are closed, and this time only one instance of Handler is added to the root logger. No instance of DotHandler is added. From now on the property is ignored.
This is because the root logger is a special beast: it will not be removed (like all other loggers) when LogManager.readConfiguration() is called.
And as it happens, handlers are added to loggers when the loggers are added to the LogManager. As it happens, the ".handlers" property is only parsed and read when the root logger is added to the LogManager, and thus only once.
The "handlers" property on the other hand is parsed every time LogManager.readConfiguration() is called.
Given that, I suspect we should deprecate the use of ".handlers" for the root logger, as it appears that it has never worked properly. I could work on a patch for 10 (possibly backport it to 9 update) to preserve the strange behavior of 7 & 8, but is it worth it?
What are your thoughts?
best regards,
-- daniel
On 09/11/2017 19:50, Jason Mehrens wrote:
Daniel, I would assume you would fix since it is advertised as a feature over here: https://docs.oracle.com/javase/1.5.0/docs/guide/logging/changes.html If it helps, I've dug up a lot of the history on this over here a while back: https://stackoverflow.com/questions/36726431/in-a-java-util-logging-logging-... I've updated that to include the links to this new issue. Now that I've linked this message thread to that message thread that should crash the internet. :) Jason ________________________________________ From: core-libs-dev <core-libs-dev-bounces@openjdk.java.net> on behalf of Daniel Fuchs <daniel.fuchs@oracle.com> Sent: Thursday, November 9, 2017 1:29 PM To: mandy chung Cc: core-libs-dev@openjdk.java.net Subject: Re: Change in properties for logging: deliberate? On 09/11/2017 19:16, mandy chung wrote:
Daniel - we should add this known issue in the release note and document the workaround. Hi Mandy, Right, it either need to be fixed, or documented in the release notes. Let me first have a look at the issue though. best regards, -- daniel
Daniel, Thanks for taking a look at this. I'd like to disagree with the reasoning here. First, it isn't just JDKs 7 and 8 - the behavior is the same all the way back to JDK 1.4, when the java.util.logging API was introduced. So changes affect 15 years' worth of logging configuration files. For example, there are no fewer than 350 instances of this pattern in our codebase. Imagine multiplying that across the entire world - everyone who is doing this has to change their configuration. That's a pretty big cost to introduce on the developer community. This is worse on legacy systems, because the handlers property was broken for a long time, and people basically had to use .handlers: http://bugs.java.com/bugdatabase/view_bug.do?bug_id=6207335. Second, it is inconsistent for ".level" to work for level for the root logger, and ".handlers" not to work for handlers for the root logger. The empty string represents the root logger, and having it only represent the root logger sometimes is (to me) counterintuitive. Without checking, my suspicion is that .level behaves the same way as .handlers (that is, it is only loaded once). If we can live with the inconsistency there, we can live with it here. You can even document that that is the difference. Jeremy On Fri, Nov 10, 2017 at 8:04 AM, Daniel Fuchs <daniel.fuchs@oracle.com> wrote:
Hi Jason,
I have done a few tests with JDK 8 & 7.
I have created custom handlers and added some debug traces in their constructors and debug methods.
Then I have added these two lines to my logging.properties:
handlers = custom.Handler .handlers = custom.DotHandler
What I see is this:
- the first time the configuration is read, two handlers are added to the root logger: - an instance of DotHandler (first), then an instance of Handler (second).
Then if you call LogManager.readConfiguration() again, both handlers are closed, and this time only one instance of Handler is added to the root logger. No instance of DotHandler is added. From now on the property is ignored.
This is because the root logger is a special beast: it will not be removed (like all other loggers) when LogManager.readConfiguration() is called.
And as it happens, handlers are added to loggers when the loggers are added to the LogManager. As it happens, the ".handlers" property is only parsed and read when the root logger is added to the LogManager, and thus only once.
The "handlers" property on the other hand is parsed every time LogManager.readConfiguration() is called.
Given that, I suspect we should deprecate the use of ".handlers" for the root logger, as it appears that it has never worked properly. I could work on a patch for 10 (possibly backport it to 9 update) to preserve the strange behavior of 7 & 8, but is it worth it?
What are your thoughts?
best regards,
-- daniel
On 09/11/2017 19:50, Jason Mehrens wrote:
Daniel,
I would assume you would fix since it is advertised as a feature over here: https://docs.oracle.com/javase/1.5.0/docs/guide/logging/ changes.html
If it helps, I've dug up a lot of the history on this over here a while back: https://stackoverflow.com/questions/36726431/in-a-java-util- logging-logging-properties-file-whats-the-difference-between-h
I've updated that to include the links to this new issue. Now that I've linked this message thread to that message thread that should crash the internet. :)
Jason
________________________________________ From: core-libs-dev <core-libs-dev-bounces@openjdk.java.net> on behalf of Daniel Fuchs <daniel.fuchs@oracle.com> Sent: Thursday, November 9, 2017 1:29 PM To: mandy chung Cc: core-libs-dev@openjdk.java.net Subject: Re: Change in properties for logging: deliberate?
On 09/11/2017 19:16, mandy chung wrote:
Daniel - we should add this known issue in the release note and document the workaround.
Hi Mandy,
Right, it either need to be fixed, or documented in the release notes. Let me first have a look at the issue though.
best regards,
-- daniel
Hi Jeremy, I will propose a fix then. However be aware that logging configuration files that use ".handlers" instead of "handlers" to configure the root logger are fragile, as it seems that any subsequent call to LogManager.readConfiguration() will remove this configuration. Though I agree this might not be an issue if it has stayed unnoticed for 15 years. I will need to verify the behavior of ".level". Thanks for pointing that out. I don't think it has the same flaw but I will need to make sure. best regards, -- daniel On 10/11/17 20:48, Jeremy Manson wrote:
Daniel,
Thanks for taking a look at this. I'd like to disagree with the reasoning here.
First, it isn't just JDKs 7 and 8 - the behavior is the same all the way back to JDK 1.4, when the java.util.logging API was introduced. So changes affect 15 years' worth of logging configuration files. For example, there are no fewer than 350 instances of this pattern in our codebase. Imagine multiplying that across the entire world - everyone who is doing this has to change their configuration. That's a pretty big cost to introduce on the developer community.
This is worse on legacy systems, because the handlers property was broken for a long time, and people basically had to use .handlers: http://bugs.java.com/bugdatabase/view_bug.do?bug_id=6207335.
Second, it is inconsistent for ".level" to work for level for the root logger, and ".handlers" not to work for handlers for the root logger. The empty string represents the root logger, and having it only represent the root logger sometimes is (to me) counterintuitive. Without checking, my suspicion is that .level behaves the same way as .handlers (that is, it is only loaded once). If we can live with the inconsistency there, we can live with it here. You can even document that that is the difference.
Jeremy
On Fri, Nov 10, 2017 at 8:04 AM, Daniel Fuchs <daniel.fuchs@oracle.com <mailto:daniel.fuchs@oracle.com>> wrote:
Hi Jason,
I have done a few tests with JDK 8 & 7.
I have created custom handlers and added some debug traces in their constructors and debug methods.
Then I have added these two lines to my logging.properties:
handlers = custom.Handler .handlers = custom.DotHandler
What I see is this:
- the first time the configuration is read, two handlers are added to the root logger: - an instance of DotHandler (first), then an instance of Handler (second).
Then if you call LogManager.readConfiguration() again, both handlers are closed, and this time only one instance of Handler is added to the root logger. No instance of DotHandler is added. From now on the property is ignored.
This is because the root logger is a special beast: it will not be removed (like all other loggers) when LogManager.readConfiguration() is called.
And as it happens, handlers are added to loggers when the loggers are added to the LogManager. As it happens, the ".handlers" property is only parsed and read when the root logger is added to the LogManager, and thus only once.
The "handlers" property on the other hand is parsed every time LogManager.readConfiguration() is called.
Given that, I suspect we should deprecate the use of ".handlers" for the root logger, as it appears that it has never worked properly. I could work on a patch for 10 (possibly backport it to 9 update) to preserve the strange behavior of 7 & 8, but is it worth it?
What are your thoughts?
best regards,
-- daniel
On 09/11/2017 19:50, Jason Mehrens wrote:
Daniel,
I would assume you would fix since it is advertised as a feature over here: https://docs.oracle.com/javase/1.5.0/docs/guide/logging/changes.html <https://docs.oracle.com/javase/1.5.0/docs/guide/logging/changes.html>
If it helps, I've dug up a lot of the history on this over here a while back: https://stackoverflow.com/questions/36726431/in-a-java-util-logging-logging-... <https://stackoverflow.com/questions/36726431/in-a-java-util-logging-logging-properties-file-whats-the-difference-between-h>
I've updated that to include the links to this new issue. Now that I've linked this message thread to that message thread that should crash the internet. :)
Jason
________________________________________ From: core-libs-dev <core-libs-dev-bounces@openjdk.java.net <mailto:core-libs-dev-bounces@openjdk.java.net>> on behalf of Daniel Fuchs <daniel.fuchs@oracle.com <mailto:daniel.fuchs@oracle.com>> Sent: Thursday, November 9, 2017 1:29 PM To: mandy chung Cc: core-libs-dev@openjdk.java.net <mailto:core-libs-dev@openjdk.java.net> Subject: Re: Change in properties for logging: deliberate?
On 09/11/2017 19:16, mandy chung wrote:
Daniel - we should add this known issue in the release note and document the workaround.
Hi Mandy,
Right, it either need to be fixed, or documented in the release notes. Let me first have a look at the issue though.
best regards,
-- daniel
Thanks for the attention, Daniel. You may want to consider adjusting it so that the behavior of .level and .handlers are consistent with each other, if they aren't... I don't think that should break anyone significantly. Jeremy On Fri, Nov 10, 2017 at 1:20 PM, Daniel Fuchs <daniel.fuchs@oracle.com> wrote:
Hi Jeremy,
I will propose a fix then.
However be aware that logging configuration files that use ".handlers" instead of "handlers" to configure the root logger are fragile, as it seems that any subsequent call to LogManager.readConfiguration() will remove this configuration. Though I agree this might not be an issue if it has stayed unnoticed for 15 years.
I will need to verify the behavior of ".level". Thanks for pointing that out. I don't think it has the same flaw but I will need to make sure.
best regards,
-- daniel
On 10/11/17 20:48, Jeremy Manson wrote:
Daniel,
Thanks for taking a look at this. I'd like to disagree with the reasoning here.
First, it isn't just JDKs 7 and 8 - the behavior is the same all the way back to JDK 1.4, when the java.util.logging API was introduced. So changes affect 15 years' worth of logging configuration files. For example, there are no fewer than 350 instances of this pattern in our codebase. Imagine multiplying that across the entire world - everyone who is doing this has to change their configuration. That's a pretty big cost to introduce on the developer community.
This is worse on legacy systems, because the handlers property was broken for a long time, and people basically had to use .handlers: http://bugs.java.com/bugdatabase/view_bug.do?bug_id=6207335.
Second, it is inconsistent for ".level" to work for level for the root logger, and ".handlers" not to work for handlers for the root logger. The empty string represents the root logger, and having it only represent the root logger sometimes is (to me) counterintuitive. Without checking, my suspicion is that .level behaves the same way as .handlers (that is, it is only loaded once). If we can live with the inconsistency there, we can live with it here. You can even document that that is the difference.
Jeremy
On Fri, Nov 10, 2017 at 8:04 AM, Daniel Fuchs <daniel.fuchs@oracle.com <mailto:daniel.fuchs@oracle.com>> wrote:
Hi Jason,
I have done a few tests with JDK 8 & 7.
I have created custom handlers and added some debug traces in their constructors and debug methods.
Then I have added these two lines to my logging.properties:
handlers = custom.Handler .handlers = custom.DotHandler
What I see is this:
- the first time the configuration is read, two handlers are added to the root logger: - an instance of DotHandler (first), then an instance of Handler (second).
Then if you call LogManager.readConfiguration() again, both handlers are closed, and this time only one instance of Handler is added to the root logger. No instance of DotHandler is added. From now on the property is ignored.
This is because the root logger is a special beast: it will not be removed (like all other loggers) when LogManager.readConfiguration() is called.
And as it happens, handlers are added to loggers when the loggers are added to the LogManager. As it happens, the ".handlers" property is only parsed and read when the root logger is added to the LogManager, and thus only once.
The "handlers" property on the other hand is parsed every time LogManager.readConfiguration() is called.
Given that, I suspect we should deprecate the use of ".handlers" for the root logger, as it appears that it has never worked properly. I could work on a patch for 10 (possibly backport it to 9 update) to preserve the strange behavior of 7 & 8, but is it worth it?
What are your thoughts?
best regards,
-- daniel
On 09/11/2017 19:50, Jason Mehrens wrote:
Daniel,
I would assume you would fix since it is advertised as a feature over here: https://docs.oracle.com/javase/1.5.0/docs/guide/logging/ changes.html <https://docs.oracle.com/javase/1.5.0/docs/guide/logging/ changes.html>
If it helps, I've dug up a lot of the history on this over here a while back: https://stackoverflow.com/questions/36726431/in-a-java-util- logging-logging-properties-file-whats-the-difference-between-h <https://stackoverflow.com/questions/36726431/in-a-java-util -logging-logging-properties-file-whats-the-difference-between-h>
I've updated that to include the links to this new issue. Now that I've linked this message thread to that message thread that should crash the internet. :)
Jason
________________________________________ From: core-libs-dev <core-libs-dev-bounces@openjdk.java.net <mailto:core-libs-dev-bounces@openjdk.java.net>> on behalf of Daniel Fuchs <daniel.fuchs@oracle.com <mailto:daniel.fuchs@oracle.com>> Sent: Thursday, November 9, 2017 1:29 PM To: mandy chung Cc: core-libs-dev@openjdk.java.net <mailto:core-libs-dev@openjdk.java.net> Subject: Re: Change in properties for logging: deliberate?
On 09/11/2017 19:16, mandy chung wrote:
Daniel - we should add this known issue in the release note and document the workaround.
Hi Mandy,
Right, it either need to be fixed, or documented in the release notes. Let me first have a look at the issue though.
best regards,
-- daniel
Hi Jeremy, On 10/11/17 23:24, Jeremy Manson wrote:
Thanks for the attention, Daniel. You may want to consider adjusting it so that the behavior of .level and .handlers are consistent with each other, if they aren't... I don't think that should break anyone significantly.
I think the way .handlers works in 7 and 8 (and probably earlier) is a bug. It should work like "handlers" - but I am not sure it should be changed now as some applications might depend on it: it seems safer to simply fix 10 and 9 to match the earlier behavior and have all releases work the same. best regards, -- daniel
Jeremy
On Fri, Nov 10, 2017 at 1:20 PM, Daniel Fuchs <daniel.fuchs@oracle.com <mailto:daniel.fuchs@oracle.com>> wrote:
Hi Jeremy,
I will propose a fix then.
However be aware that logging configuration files that use ".handlers" instead of "handlers" to configure the root logger are fragile, as it seems that any subsequent call to LogManager.readConfiguration() will remove this configuration. Though I agree this might not be an issue if it has stayed unnoticed for 15 years.
I will need to verify the behavior of ".level". Thanks for pointing that out. I don't think it has the same flaw but I will need to make sure.
best regards,
-- daniel
On 10/11/17 20:48, Jeremy Manson wrote:
Daniel,
Thanks for taking a look at this. I'd like to disagree with the reasoning here.
First, it isn't just JDKs 7 and 8 - the behavior is the same all the way back to JDK 1.4, when the java.util.logging API was introduced. So changes affect 15 years' worth of logging configuration files. For example, there are no fewer than 350 instances of this pattern in our codebase. Imagine multiplying that across the entire world - everyone who is doing this has to change their configuration. That's a pretty big cost to introduce on the developer community.
This is worse on legacy systems, because the handlers property was broken for a long time, and people basically had to use .handlers: http://bugs.java.com/bugdatabase/view_bug.do?bug_id=6207335 <http://bugs.java.com/bugdatabase/view_bug.do?bug_id=6207335>.
Second, it is inconsistent for ".level" to work for level for the root logger, and ".handlers" not to work for handlers for the root logger. The empty string represents the root logger, and having it only represent the root logger sometimes is (to me) counterintuitive. Without checking, my suspicion is that .level behaves the same way as .handlers (that is, it is only loaded once). If we can live with the inconsistency there, we can live with it here. You can even document that that is the difference.
Jeremy
On Fri, Nov 10, 2017 at 8:04 AM, Daniel Fuchs <daniel.fuchs@oracle.com <mailto:daniel.fuchs@oracle.com> <mailto:daniel.fuchs@oracle.com <mailto:daniel.fuchs@oracle.com>>> wrote:
Hi Jason,
I have done a few tests with JDK 8 & 7.
I have created custom handlers and added some debug traces in their constructors and debug methods.
Then I have added these two lines to my logging.properties:
handlers = custom.Handler .handlers = custom.DotHandler
What I see is this:
- the first time the configuration is read, two handlers are added to the root logger: - an instance of DotHandler (first), then an instance of Handler (second).
Then if you call LogManager.readConfiguration() again, both handlers are closed, and this time only one instance of Handler is added to the root logger. No instance of DotHandler is added. From now on the property is ignored.
This is because the root logger is a special beast: it will not be removed (like all other loggers) when LogManager.readConfiguration() is called.
And as it happens, handlers are added to loggers when the loggers are added to the LogManager. As it happens, the ".handlers" property is only parsed and read when the root logger is added to the LogManager, and thus only once.
The "handlers" property on the other hand is parsed every time LogManager.readConfiguration() is called.
Given that, I suspect we should deprecate the use of ".handlers" for the root logger, as it appears that it has never worked properly. I could work on a patch for 10 (possibly backport it to 9 update) to preserve the strange behavior of 7 & 8, but is it worth it?
What are your thoughts?
best regards,
-- daniel
On 09/11/2017 19:50, Jason Mehrens wrote:
Daniel,
I would assume you would fix since it is advertised as a feature over here: https://docs.oracle.com/javase/1.5.0/docs/guide/logging/changes.html <https://docs.oracle.com/javase/1.5.0/docs/guide/logging/changes.html>
<https://docs.oracle.com/javase/1.5.0/docs/guide/logging/changes.html <https://docs.oracle.com/javase/1.5.0/docs/guide/logging/changes.html>>
If it helps, I've dug up a lot of the history on this over here a while back: https://stackoverflow.com/questions/36726431/in-a-java-util-logging-logging-... <https://stackoverflow.com/questions/36726431/in-a-java-util-logging-logging-properties-file-whats-the-difference-between-h>
<https://stackoverflow.com/questions/36726431/in-a-java-util-logging-logging-... <https://stackoverflow.com/questions/36726431/in-a-java-util-logging-logging-properties-file-whats-the-difference-between-h>>
I've updated that to include the links to this new issue. Now that I've linked this message thread to that message thread that should crash the internet. :)
Jason
________________________________________ From: core-libs-dev <core-libs-dev-bounces@openjdk.java.net <mailto:core-libs-dev-bounces@openjdk.java.net> <mailto:core-libs-dev-bounces@openjdk.java.net <mailto:core-libs-dev-bounces@openjdk.java.net>>> on behalf of Daniel Fuchs <daniel.fuchs@oracle.com <mailto:daniel.fuchs@oracle.com> <mailto:daniel.fuchs@oracle.com <mailto:daniel.fuchs@oracle.com>>> Sent: Thursday, November 9, 2017 1:29 PM To: mandy chung Cc: core-libs-dev@openjdk.java.net <mailto:core-libs-dev@openjdk.java.net> <mailto:core-libs-dev@openjdk.java.net <mailto:core-libs-dev@openjdk.java.net>> Subject: Re: Change in properties for logging: deliberate?
On 09/11/2017 19:16, mandy chung wrote:
Daniel - we should add this known issue in the release note and document the workaround.
Hi Mandy,
Right, it either need to be fixed, or documented in the release notes. Let me first have a look at the issue though.
best regards,
-- daniel
Hi Daniel, Sorry for the late reply I was offline for the long weekend. Hot reloads of the LogManager have always been a problem. I think you are running into https://bugs.openjdk.java.net/browse/JDK-8033661 in your testing and that is going to give you troubling results on what is recreated after the call. Make sure you test updateConfiguration which is the replacement everyone is to use going forward. I think you'll want to make it so that "handlers" is just an alias name ".handlers". That way empty string is just name of the root logger which enables consistent use of other properties like ".level" and ".filter". If both are defined in the logging.properties, then install the union of the two lines. Jason ________________________________________ From: Daniel Fuchs <daniel.fuchs@oracle.com> Sent: Friday, November 10, 2017 10:04 AM To: Jason Mehrens; mandy chung Cc: core-libs-dev@openjdk.java.net Subject: Re: Change in properties for logging: deliberate? Hi Jason, I have done a few tests with JDK 8 & 7. I have created custom handlers and added some debug traces in their constructors and debug methods. Then I have added these two lines to my logging.properties: handlers = custom.Handler .handlers = custom.DotHandler What I see is this: - the first time the configuration is read, two handlers are added to the root logger: - an instance of DotHandler (first), then an instance of Handler (second). Then if you call LogManager.readConfiguration() again, both handlers are closed, and this time only one instance of Handler is added to the root logger. No instance of DotHandler is added. From now on the property is ignored. This is because the root logger is a special beast: it will not be removed (like all other loggers) when LogManager.readConfiguration() is called. And as it happens, handlers are added to loggers when the loggers are added to the LogManager. As it happens, the ".handlers" property is only parsed and read when the root logger is added to the LogManager, and thus only once. The "handlers" property on the other hand is parsed every time LogManager.readConfiguration() is called. Given that, I suspect we should deprecate the use of ".handlers" for the root logger, as it appears that it has never worked properly. I could work on a patch for 10 (possibly backport it to 9 update) to preserve the strange behavior of 7 & 8, but is it worth it? What are your thoughts? best regards, -- daniel On 09/11/2017 19:50, Jason Mehrens wrote:
Daniel,
I would assume you would fix since it is advertised as a feature over here: https://docs.oracle.com/javase/1.5.0/docs/guide/logging/changes.html
If it helps, I've dug up a lot of the history on this over here a while back: https://stackoverflow.com/questions/36726431/in-a-java-util-logging-logging-...
I've updated that to include the links to this new issue. Now that I've linked this message thread to that message thread that should crash the internet. :)
Jason
________________________________________ From: core-libs-dev <core-libs-dev-bounces@openjdk.java.net> on behalf of Daniel Fuchs <daniel.fuchs@oracle.com> Sent: Thursday, November 9, 2017 1:29 PM To: mandy chung Cc: core-libs-dev@openjdk.java.net Subject: Re: Change in properties for logging: deliberate?
On 09/11/2017 19:16, mandy chung wrote:
Daniel - we should add this known issue in the release note and document the workaround.
Hi Mandy,
Right, it either need to be fixed, or documented in the release notes. Let me first have a look at the issue though.
best regards,
-- daniel
Hi Jason, On 13/11/2017 15:14, Jason Mehrens wrote:
Hi Daniel,
Sorry for the late reply I was offline for the long weekend.
Hot reloads of the LogManager have always been a problem. I think you are running into https://bugs.openjdk.java.net/browse/JDK-8033661 in your testing and that is going to give you troubling results on what is recreated after the call. Make sure you test updateConfiguration which is the replacement everyone is to use going forward.
Yes - I know - I fixed that one ;-)
I think you'll want to make it so that "handlers" is just an alias name ".handlers". That way empty string is just name of the root logger which enables consistent use of other properties like ".level" and ".filter". If both are defined in the logging.properties, then install the union of the two line.
That's precisely where I didn't want to go. When I fixed JDK-8033661 I choose to use "handlers" for the root logger instead of ".handlers" when implementing updateConfiguration() because "handlers" is explicitly documented in LogManager API documentation and conf/logging.properties. So for the root logger the mapping function will only consider "handlers" but not ".handlers". Trying to change that would add too much complexity IMHO. best regards, -- daniel
Jason
________________________________________ From: Daniel Fuchs <daniel.fuchs@oracle.com> Sent: Friday, November 10, 2017 10:04 AM To: Jason Mehrens; mandy chung Cc: core-libs-dev@openjdk.java.net Subject: Re: Change in properties for logging: deliberate?
Hi Jason,
I have done a few tests with JDK 8 & 7.
I have created custom handlers and added some debug traces in their constructors and debug methods.
Then I have added these two lines to my logging.properties:
handlers = custom.Handler .handlers = custom.DotHandler
What I see is this:
- the first time the configuration is read, two handlers are added to the root logger: - an instance of DotHandler (first), then an instance of Handler (second).
Then if you call LogManager.readConfiguration() again, both handlers are closed, and this time only one instance of Handler is added to the root logger. No instance of DotHandler is added. From now on the property is ignored.
This is because the root logger is a special beast: it will not be removed (like all other loggers) when LogManager.readConfiguration() is called.
And as it happens, handlers are added to loggers when the loggers are added to the LogManager. As it happens, the ".handlers" property is only parsed and read when the root logger is added to the LogManager, and thus only once.
The "handlers" property on the other hand is parsed every time LogManager.readConfiguration() is called.
Given that, I suspect we should deprecate the use of ".handlers" for the root logger, as it appears that it has never worked properly. I could work on a patch for 10 (possibly backport it to 9 update) to preserve the strange behavior of 7 & 8, but is it worth it?
What are your thoughts?
best regards,
-- daniel
On 09/11/2017 19:50, Jason Mehrens wrote:
Daniel,
I would assume you would fix since it is advertised as a feature over here: https://docs.oracle.com/javase/1.5.0/docs/guide/logging/changes.html
If it helps, I've dug up a lot of the history on this over here a while back: https://stackoverflow.com/questions/36726431/in-a-java-util-logging-logging-...
I've updated that to include the links to this new issue. Now that I've linked this message thread to that message thread that should crash the internet. :)
Jason
________________________________________ From: core-libs-dev <core-libs-dev-bounces@openjdk.java.net> on behalf of Daniel Fuchs <daniel.fuchs@oracle.com> Sent: Thursday, November 9, 2017 1:29 PM To: mandy chung Cc: core-libs-dev@openjdk.java.net Subject: Re: Change in properties for logging: deliberate?
On 09/11/2017 19:16, mandy chung wrote:
Daniel - we should add this known issue in the release note and document the workaround.
Hi Mandy,
Right, it either need to be fixed, or documented in the release notes. Let me first have a look at the issue though.
best regards,
-- daniel
Hey folks, Any thoughts on a timeline for this? We're just having to decide what to do internally. If a patch is likely to arrive in the next month or so, then we'll probably wait, but if not, we should probably figure out a workaround. (I'm not trying to be too pushy - we can certainly figure out a workaround.) Jeremy On Mon, Nov 13, 2017 at 7:30 AM, Daniel Fuchs <daniel.fuchs@oracle.com> wrote:
Hi Jason,
On 13/11/2017 15:14, Jason Mehrens wrote:
Hi Daniel,
Sorry for the late reply I was offline for the long weekend.
Hot reloads of the LogManager have always been a problem. I think you are running into https://bugs.openjdk.java.net/browse/JDK-8033661 in your testing and that is going to give you troubling results on what is recreated after the call. Make sure you test updateConfiguration which is the replacement everyone is to use going forward.
Yes - I know - I fixed that one ;-)
I think you'll want to make it so that "handlers" is just an alias name
".handlers". That way empty string is just name of the root logger which enables consistent use of other properties like ".level" and ".filter". If both are defined in the logging.properties, then install the union of the two line.
That's precisely where I didn't want to go.
When I fixed JDK-8033661 I choose to use "handlers" for the root logger instead of ".handlers" when implementing updateConfiguration() because "handlers" is explicitly documented in LogManager API documentation and conf/logging.properties.
So for the root logger the mapping function will only consider "handlers" but not ".handlers". Trying to change that would add too much complexity IMHO.
best regards,
-- daniel
Jason
________________________________________ From: Daniel Fuchs <daniel.fuchs@oracle.com> Sent: Friday, November 10, 2017 10:04 AM To: Jason Mehrens; mandy chung Cc: core-libs-dev@openjdk.java.net Subject: Re: Change in properties for logging: deliberate?
Hi Jason,
I have done a few tests with JDK 8 & 7.
I have created custom handlers and added some debug traces in their constructors and debug methods.
Then I have added these two lines to my logging.properties:
handlers = custom.Handler .handlers = custom.DotHandler
What I see is this:
- the first time the configuration is read, two handlers are added to the root logger: - an instance of DotHandler (first), then an instance of Handler (second).
Then if you call LogManager.readConfiguration() again, both handlers are closed, and this time only one instance of Handler is added to the root logger. No instance of DotHandler is added. From now on the property is ignored.
This is because the root logger is a special beast: it will not be removed (like all other loggers) when LogManager.readConfiguration() is called.
And as it happens, handlers are added to loggers when the loggers are added to the LogManager. As it happens, the ".handlers" property is only parsed and read when the root logger is added to the LogManager, and thus only once.
The "handlers" property on the other hand is parsed every time LogManager.readConfiguration() is called.
Given that, I suspect we should deprecate the use of ".handlers" for the root logger, as it appears that it has never worked properly. I could work on a patch for 10 (possibly backport it to 9 update) to preserve the strange behavior of 7 & 8, but is it worth it?
What are your thoughts?
best regards,
-- daniel
On 09/11/2017 19:50, Jason Mehrens wrote:
Daniel,
I would assume you would fix since it is advertised as a feature over here: https://docs.oracle.com/javase/1.5.0/docs/guide/logging/chan ges.html
If it helps, I've dug up a lot of the history on this over here a while back: https://stackoverflow.com/questions/36726431/in-a-java-util- logging-logging-properties-file-whats-the-difference-between-h
I've updated that to include the links to this new issue. Now that I've linked this message thread to that message thread that should crash the internet. :)
Jason
________________________________________ From: core-libs-dev <core-libs-dev-bounces@openjdk.java.net> on behalf of Daniel Fuchs <daniel.fuchs@oracle.com> Sent: Thursday, November 9, 2017 1:29 PM To: mandy chung Cc: core-libs-dev@openjdk.java.net Subject: Re: Change in properties for logging: deliberate?
On 09/11/2017 19:16, mandy chung wrote:
Daniel - we should add this known issue in the release note and document the workaround.
Hi Mandy,
Right, it either need to be fixed, or documented in the release notes. Let me first have a look at the issue though.
best regards,
-- daniel
Hi Jeremy, I just proposed a patch on core-libs-dev. best regards, -- daniel On 06/12/2017 01:17, Jeremy Manson wrote:
Hey folks,
Any thoughts on a timeline for this? We're just having to decide what to do internally. If a patch is likely to arrive in the next month or so, then we'll probably wait, but if not, we should probably figure out a workaround.
(I'm not trying to be too pushy - we can certainly figure out a workaround.)
Jeremy
participants (5)
-
Daniel Fuchs
-
Jason Mehrens
-
Jeremy Manson
-
mandy chung
-
Ralph Goers