[xwiki-devs] [Proposal] Introduce 2 new loggers "org.xwiki.initialization" and "org.xwiki.shutdown"
Hi Devs, I’d like to add some logging to debug what happens when XWiki shuts down. One solution would be to just use the standard class loggers with LOGGER.debug(…). However this means activating debug logging for everything and thus you cannot just focus on the shutdown part. WDYT about adding 2 new loggers "org.xwiki.initialization" and “org.xwiki.shutdown”? Example usage: /** * Logger to use to log shutdown information. */ private static final Logger SHUTDOWN_LOGGER = LoggerFactory.getLogger("org.xwiki.shutdown"); ... SHUTDOWN_LOGGER.debug("Stopping component [{}]...", instance.getClass().getName()); ... SHUTDOWN_LOGGER.debug("Component [{}] has been stopped", instance.getClass().getName()); Then it becomes easy to set, in logback.xml: <logger name=“org.xwiki.shutdown" level=“debug"/> A small variation would be to use SHUTDOWN_LOGGER.info() and in logback.xml, by default to have: <logger name=“org.xwiki.shutdown" level=“warn"/> Note that this would be the first time we use non-class loggers which is why I’m asking for your go-ahead. Thanks -Vincent
It's not very clear for me where you exactly plan to use that. On Wed, Sep 24, 2014 at 2:06 PM, [email protected] <[email protected]> wrote:
Hi Devs,
I’d like to add some logging to debug what happens when XWiki shuts down.
One solution would be to just use the standard class loggers with LOGGER.debug(…).
However this means activating debug logging for everything and thus you cannot just focus on the shutdown part.
WDYT about adding 2 new loggers "org.xwiki.initialization" and “org.xwiki.shutdown”?
Example usage:
/** * Logger to use to log shutdown information. */ private static final Logger SHUTDOWN_LOGGER = LoggerFactory.getLogger("org.xwiki.shutdown");
...
SHUTDOWN_LOGGER.debug("Stopping component [{}]...", instance.getClass().getName()); ... SHUTDOWN_LOGGER.debug("Component [{}] has been stopped", instance.getClass().getName());
Then it becomes easy to set, in logback.xml:
<logger name=“org.xwiki.shutdown" level=“debug"/>
A small variation would be to use SHUTDOWN_LOGGER.info() and in logback.xml, by default to have:
<logger name=“org.xwiki.shutdown" level=“warn"/>
Note that this would be the first time we use non-class loggers which is why I’m asking for your go-ahead.
Thanks -Vincent _______________________________________________ devs mailing list [email protected] http://lists.xwiki.org/mailman/listinfo/devs
-- Thomas Mortagne
On 24 Sep 2014 at 15:01:04, Thomas Mortagne ([email protected](mailto:[email protected])) wrote:
It's not very clear for me where you exactly plan to use that.
For the “org.xwiki.shutdown” logger: - ECM (dispose()) - XWikiServletContextListener - DBCPConnectionProvider For the “org.xwiki.initialization” one I don’t know yet, I haven’t done it. Basically at places where important subsystems are initialized. Some ideas: - InitializableLifecycleHandler - SOLR init (maybe not needed if done through Initializable) - EM init (maybe not needed if done through Initializable) - ... Thanks -Vincent
On Wed, Sep 24, 2014 at 2:06 PM, [email protected] wrote:
Hi Devs,
I’d like to add some logging to debug what happens when XWiki shuts down.
One solution would be to just use the standard class loggers with LOGGER.debug(…).
However this means activating debug logging for everything and thus you cannot just focus on the shutdown part.
WDYT about adding 2 new loggers "org.xwiki.initialization" and “org.xwiki.shutdown”?
Example usage:
/** * Logger to use to log shutdown information. */ private static final Logger SHUTDOWN_LOGGER = LoggerFactory.getLogger("org.xwiki.shutdown");
...
SHUTDOWN_LOGGER.debug("Stopping component [{}]...", instance.getClass().getName()); ... SHUTDOWN_LOGGER.debug("Component [{}] has been stopped", instance.getClass().getName());
Then it becomes easy to set, in logback.xml:
A small variation would be to use SHUTDOWN_LOGGER.info() and in logback.xml, by default to have:
Note that this would be the first time we use non-class loggers which is why I’m asking for your go-ahead.
Thanks -Vincent _______________________________________________ devs mailing list [email protected] http://lists.xwiki.org/mailman/listinfo/devs
-- Thomas Mortagne _______________________________________________ devs mailing list [email protected] http://lists.xwiki.org/mailman/listinfo/devs
On Wed, Sep 24, 2014 at 3:07 PM, [email protected] <[email protected]> wrote:
On 24 Sep 2014 at 15:01:04, Thomas Mortagne ([email protected](mailto:[email protected])) wrote:
It's not very clear for me where you exactly plan to use that.
For the “org.xwiki.shutdown” logger:
- ECM (dispose()) - XWikiServletContextListener - DBCPConnectionProvider
Not all that is about XWiki shutting down, each time you delete a wiki ECM#dispose() is called to dispose the CM associated to that wiki.
For the “org.xwiki.initialization” one I don’t know yet, I haven’t done it. Basically at places where important subsystems are initialized. Some ideas:
- InitializableLifecycleHandler - SOLR init (maybe not needed if done through Initializable) - EM init (maybe not needed if done through Initializable) - ...
Thanks -Vincent
On Wed, Sep 24, 2014 at 2:06 PM, [email protected] wrote:
Hi Devs,
I’d like to add some logging to debug what happens when XWiki shuts down.
One solution would be to just use the standard class loggers with LOGGER.debug(…).
However this means activating debug logging for everything and thus you cannot just focus on the shutdown part.
WDYT about adding 2 new loggers "org.xwiki.initialization" and “org.xwiki.shutdown”?
Example usage:
/** * Logger to use to log shutdown information. */ private static final Logger SHUTDOWN_LOGGER = LoggerFactory.getLogger("org.xwiki.shutdown");
...
SHUTDOWN_LOGGER.debug("Stopping component [{}]...", instance.getClass().getName()); ... SHUTDOWN_LOGGER.debug("Component [{}] has been stopped", instance.getClass().getName());
Then it becomes easy to set, in logback.xml:
A small variation would be to use SHUTDOWN_LOGGER.info() and in logback.xml, by default to have:
Note that this would be the first time we use non-class loggers which is why I’m asking for your go-ahead.
Thanks -Vincent _______________________________________________ devs mailing list [email protected] http://lists.xwiki.org/mailman/listinfo/devs
-- Thomas Mortagne _______________________________________________ devs mailing list [email protected] http://lists.xwiki.org/mailman/listinfo/devs
devs mailing list [email protected] http://lists.xwiki.org/mailman/listinfo/devs
-- Thomas Mortagne
On 24 Sep 2014 at 15:30:53, Thomas Mortagne ([email protected](mailto:[email protected])) wrote:
On Wed, Sep 24, 2014 at 3:07 PM, [email protected] wrote:
On 24 Sep 2014 at 15:01:04, Thomas Mortagne ([email protected](mailto:[email protected])) wrote:
It's not very clear for me where you exactly plan to use that.
For the “org.xwiki.shutdown” logger:
- ECM (dispose()) - XWikiServletContextListener - DBCPConnectionProvider
Not all that is about XWiki shutting down, each time you delete a wiki ECM#dispose() is called to dispose the CM associated to that wiki.
ok, then we could call it “org.xwiki.disposal” or “org.xwiki.cleanup”. Thanks -Vincent
For the “org.xwiki.initialization” one I don’t know yet, I haven’t done it. Basically at places where important subsystems are initialized. Some ideas:
- InitializableLifecycleHandler - SOLR init (maybe not needed if done through Initializable) - EM init (maybe not needed if done through Initializable) - ...
Thanks -Vincent
On Wed, Sep 24, 2014 at 2:06 PM, [email protected] wrote:
Hi Devs,
I’d like to add some logging to debug what happens when XWiki shuts down.
One solution would be to just use the standard class loggers with LOGGER.debug(…).
However this means activating debug logging for everything and thus you cannot just focus on the shutdown part.
WDYT about adding 2 new loggers "org.xwiki.initialization" and “org.xwiki.shutdown”?
Example usage:
/** * Logger to use to log shutdown information. */ private static final Logger SHUTDOWN_LOGGER = LoggerFactory.getLogger("org.xwiki.shutdown");
...
SHUTDOWN_LOGGER.debug("Stopping component [{}]...", instance.getClass().getName()); ... SHUTDOWN_LOGGER.debug("Component [{}] has been stopped", instance.getClass().getName());
Then it becomes easy to set, in logback.xml:
A small variation would be to use SHUTDOWN_LOGGER.info() and in logback.xml, by default to have:
Note that this would be the first time we use non-class loggers which is why I’m asking for your go-ahead.
Thanks -Vincent
FYI this is what I get locally: 2014-09-24 15:55:23,982 [Thread-1] DEBUG o.x.shutdown - Starting XWiki shutdown... 2014-09-24 15:55:28,355 [Thread-1] DEBUG o.x.shutdown - Stopping component [org.xwiki.localization.wiki.internal.DocumentTranslationBundleFactory]... 2014-09-24 15:55:28,355 [Thread-1] DEBUG o.x.shutdown - Component [org.xwiki.localization.wiki.internal.DocumentTranslationBundleFactory] has been stopped 2014-09-24 15:55:28,356 [Thread-1] DEBUG o.x.shutdown - Stopping component [org.xwiki.search.solr.internal.DefaultSolrIndexer]... 2014-09-24 15:55:28,356 [Thread-1] DEBUG o.x.shutdown - Component [org.xwiki.search.solr.internal.DefaultSolrIndexer] has been stopped 2014-09-24 15:55:28,356 [Thread-1] DEBUG o.x.shutdown - Stopping component [org.xwiki.activeinstalls.internal.DefaultJestClientManager]... 2014-09-24 15:55:28,357 [Thread-1] DEBUG o.x.shutdown - Component [org.xwiki.activeinstalls.internal.DefaultJestClientManager] has been stopped 2014-09-24 15:55:28,357 [Thread-1] DEBUG o.x.shutdown - Stopping component [org.xwiki.search.solr.internal.EmbeddedSolrInstance]... 2014-09-24 15:55:28,366 [Thread-1] DEBUG o.x.shutdown - Component [org.xwiki.search.solr.internal.EmbeddedSolrInstance] has been stopped 2014-09-24 15:55:28,367 [Thread-1] DEBUG o.x.shutdown - Stopping component [org.xwiki.logging.logback.internal.LogbackEventGenerator]... 2014-09-24 15:55:28,367 [Thread-1] DEBUG o.x.shutdown - Component [org.xwiki.logging.logback.internal.LogbackEventGenerator] has been stopped 2014-09-24 15:55:28,367 [Thread-1] DEBUG o.x.shutdown - Stopping component [org.xwiki.cache.infinispan.internal.InfinispanCacheFactory]... 2014-09-24 15:55:28,388 [Thread-1] DEBUG o.x.shutdown - Component [org.xwiki.cache.infinispan.internal.InfinispanCacheFactory] has been stopped 2014-09-24 15:55:28,391 [Thread-1] DEBUG o.x.shutdown - Stopping component [org.xwiki.job.internal.DefaultJobExecutor]... 2014-09-24 15:55:28,391 [Thread-1] DEBUG o.x.shutdown - Component [org.xwiki.job.internal.DefaultJobExecutor] has been stopped 2014-09-24 15:55:28,393 [Thread-1] DEBUG o.x.shutdown - Stopping component [org.xwiki.localization.wiki.internal.ComponentDocumentTranslationBundle]... 2014-09-24 15:55:28,393 [Thread-1] DEBUG o.x.shutdown - Component [org.xwiki.localization.wiki.internal.ComponentDocumentTranslationBundle] has been stopped 2014-09-24 15:55:28,395 [Thread-1] DEBUG o.x.shutdown - Stopping component [com.xpn.xwiki.store.hibernate.DefaultHibernateSessionFactory]... 2014-09-24 15:55:28,395 [Thread-1] DEBUG o.x.shutdown - Stopping Database Connection Pool... 2014-09-24 15:55:28,574 [Thread-1] DEBUG o.x.shutdown - Database Connection Pool has been stopped 2014-09-24 15:55:28,574 [Thread-1] DEBUG o.x.shutdown - Component [com.xpn.xwiki.store.hibernate.DefaultHibernateSessionFactory] has been stopped 2014-09-24 15:55:28,575 [Thread-1] INFO o.x.shutdown - XWiki shutdown has been completed. Thanks -Vincent On 24 Sep 2014 at 15:38:14, [email protected] ([email protected](mailto:[email protected])) wrote:
On 24 Sep 2014 at 15:30:53, Thomas Mortagne ([email protected](mailto:[email protected])) wrote:
On Wed, Sep 24, 2014 at 3:07 PM, [email protected] wrote:
On 24 Sep 2014 at 15:01:04, Thomas Mortagne ([email protected](mailto:[email protected])) wrote:
It's not very clear for me where you exactly plan to use that.
For the “org.xwiki.shutdown” logger:
- ECM (dispose()) - XWikiServletContextListener - DBCPConnectionProvider
Not all that is about XWiki shutting down, each time you delete a wiki ECM#dispose() is called to dispose the CM associated to that wiki.
ok, then we could call it “org.xwiki.disposal” or “org.xwiki.cleanup”.
Thanks -Vincent
For the “org.xwiki.initialization” one I don’t know yet, I haven’t done it. Basically at places where important subsystems are initialized. Some ideas:
- InitializableLifecycleHandler - SOLR init (maybe not needed if done through Initializable) - EM init (maybe not needed if done through Initializable) - ...
Thanks -Vincent
On Wed, Sep 24, 2014 at 2:06 PM, [email protected] wrote:
Hi Devs,
I’d like to add some logging to debug what happens when XWiki shuts down.
One solution would be to just use the standard class loggers with LOGGER.debug(…).
However this means activating debug logging for everything and thus you cannot just focus on the shutdown part.
WDYT about adding 2 new loggers "org.xwiki.initialization" and “org.xwiki.shutdown”?
Example usage:
/** * Logger to use to log shutdown information. */ private static final Logger SHUTDOWN_LOGGER = LoggerFactory.getLogger("org.xwiki.shutdown");
...
SHUTDOWN_LOGGER.debug("Stopping component [{}]...", instance.getClass().getName()); ... SHUTDOWN_LOGGER.debug("Component [{}] has been stopped", instance.getClass().getName());
Then it becomes easy to set, in logback.xml:
A small variation would be to use SHUTDOWN_LOGGER.info() and in logback.xml, by default to have:
Note that this would be the first time we use non-class loggers which is why I’m asking for your go-ahead.
Thanks -Vincent
Instead of using hacks in various code that might be called during shutdown, why not dynamically enable debug log just before starting shutdown in XWikiServletContextListener#contextDestroyed for example ? You could control that trigger with some configuration. On Wed, Sep 24, 2014 at 3:38 PM, [email protected] <[email protected]> wrote:
On 24 Sep 2014 at 15:30:53, Thomas Mortagne ([email protected](mailto:[email protected])) wrote:
On Wed, Sep 24, 2014 at 3:07 PM, [email protected] wrote:
On 24 Sep 2014 at 15:01:04, Thomas Mortagne ([email protected](mailto:[email protected])) wrote:
It's not very clear for me where you exactly plan to use that.
For the “org.xwiki.shutdown” logger:
- ECM (dispose()) - XWikiServletContextListener - DBCPConnectionProvider
Not all that is about XWiki shutting down, each time you delete a wiki ECM#dispose() is called to dispose the CM associated to that wiki.
ok, then we could call it “org.xwiki.disposal” or “org.xwiki.cleanup”.
Thanks -Vincent
For the “org.xwiki.initialization” one I don’t know yet, I haven’t done it. Basically at places where important subsystems are initialized. Some ideas:
- InitializableLifecycleHandler - SOLR init (maybe not needed if done through Initializable) - EM init (maybe not needed if done through Initializable) - ...
Thanks -Vincent
On Wed, Sep 24, 2014 at 2:06 PM, [email protected] wrote:
Hi Devs,
I’d like to add some logging to debug what happens when XWiki shuts down.
One solution would be to just use the standard class loggers with LOGGER.debug(…).
However this means activating debug logging for everything and thus you cannot just focus on the shutdown part.
WDYT about adding 2 new loggers "org.xwiki.initialization" and “org.xwiki.shutdown”?
Example usage:
/** * Logger to use to log shutdown information. */ private static final Logger SHUTDOWN_LOGGER = LoggerFactory.getLogger("org.xwiki.shutdown");
...
SHUTDOWN_LOGGER.debug("Stopping component [{}]...", instance.getClass().getName()); ... SHUTDOWN_LOGGER.debug("Component [{}] has been stopped", instance.getClass().getName());
Then it becomes easy to set, in logback.xml:
A small variation would be to use SHUTDOWN_LOGGER.info() and in logback.xml, by default to have:
Note that this would be the first time we use non-class loggers which is why I’m asking for your go-ahead.
Thanks -Vincent
devs mailing list [email protected] http://lists.xwiki.org/mailman/listinfo/devs
-- Thomas Mortagne
Hi Vincent, I do not think this is the right way to fix your problem. Basically what you need is some transversal way to filter events. I have never used them, but if IIRC, SL4J implements Markers, which allows to mark some logging, and Logback should support filterinb on Markers. Could you check that solution, it could a better fit for your need IMO. On Wed, Sep 24, 2014 at 2:06 PM, [email protected] <[email protected]> wrote:
Hi Devs,
I’d like to add some logging to debug what happens when XWiki shuts down.
One solution would be to just use the standard class loggers with LOGGER.debug(…).
However this means activating debug logging for everything and thus you cannot just focus on the shutdown part.
WDYT about adding 2 new loggers "org.xwiki.initialization" and “org.xwiki.shutdown”?
Example usage:
/** * Logger to use to log shutdown information. */ private static final Logger SHUTDOWN_LOGGER = LoggerFactory.getLogger("org.xwiki.shutdown");
...
SHUTDOWN_LOGGER.debug("Stopping component [{}]...", instance.getClass().getName()); ... SHUTDOWN_LOGGER.debug("Component [{}] has been stopped", instance.getClass().getName());
Then it becomes easy to set, in logback.xml:
<logger name=“org.xwiki.shutdown" level=“debug"/>
A small variation would be to use SHUTDOWN_LOGGER.info() and in logback.xml, by default to have:
<logger name=“org.xwiki.shutdown" level=“warn"/>
Note that this would be the first time we use non-class loggers which is why I’m asking for your go-ahead.
Thanks -Vincent _______________________________________________ devs mailing list [email protected] http://lists.xwiki.org/mailman/listinfo/devs
-- Denis Gervalle SOFTEC sa - CEO
On 24 Sep 2014 at 16:32:53, Denis Gervalle ([email protected](mailto:[email protected])) wrote:
Hi Vincent,
I do not think this is the right way to fix your problem. Basically what you need is some transversal way to filter events. I have never used them, but if IIRC, SL4J implements Markers, which allows to mark some logging, and Logback should support filterinb on Markers. Could you check that solution, it could a better fit for your need IMO.
Good idea, I’ll check. Thanks -Vincent
On Wed, Sep 24, 2014 at 2:06 PM, [email protected] wrote:
Hi Devs,
I’d like to add some logging to debug what happens when XWiki shuts down.
One solution would be to just use the standard class loggers with LOGGER.debug(…).
However this means activating debug logging for everything and thus you cannot just focus on the shutdown part.
WDYT about adding 2 new loggers "org.xwiki.initialization" and “org.xwiki.shutdown”?
Example usage:
/** * Logger to use to log shutdown information. */ private static final Logger SHUTDOWN_LOGGER = LoggerFactory.getLogger("org.xwiki.shutdown");
...
SHUTDOWN_LOGGER.debug("Stopping component [{}]...", instance.getClass().getName()); ... SHUTDOWN_LOGGER.debug("Component [{}] has been stopped", instance.getClass().getName());
Then it becomes easy to set, in logback.xml:
A small variation would be to use SHUTDOWN_LOGGER.info() and in logback.xml, by default to have:
Note that this would be the first time we use non-class loggers which is why I’m asking for your go-ahead.
Thanks -Vincent _______________________________________________ devs mailing list [email protected] http://lists.xwiki.org/mailman/listinfo/devs
-- Denis Gervalle SOFTEC sa - CEO _______________________________________________ devs mailing list [email protected] http://lists.xwiki.org/mailman/listinfo/devs
On 24 Sep 2014 at 17:09:51, [email protected] ([email protected](mailto:[email protected])) wrote:
On 24 Sep 2014 at 16:32:53, Denis Gervalle ([email protected](mailto:[email protected])) wrote:
Hi Vincent,
I do not think this is the right way to fix your problem. Basically what you need is some transversal way to filter events. I have never used them, but if IIRC, SL4J implements Markers, which allows to mark some logging, and Logback should support filterinb on Markers. Could you check that solution, it could a better fit for your need IMO.
Good idea, I’ll check.
Ok it may work with Markers but it would work only with Logback. We would have to configure our logback.xml with something like this: http://logback.qos.ch/manual/appenders.html#OnMarkerEvaluator Actually I’m not even sure we can do what we want with this since in all the examples I’ve found you could decide to use a specific appender which is not our use case: we want the same appender but change the log level according to a marker. I think this can be achieved with Filter but that’s not in the SLF4J API AFAIK. Not sure it’s worth tying us to Logback just for this. OTOH having named loggers is something well understood and supported by all logging systems so I’d go for this. Thanks -Vincent
Thanks -Vincent
On Wed, Sep 24, 2014 at 2:06 PM, [email protected] wrote:
Hi Devs,
I’d like to add some logging to debug what happens when XWiki shuts down.
One solution would be to just use the standard class loggers with LOGGER.debug(…).
However this means activating debug logging for everything and thus you cannot just focus on the shutdown part.
WDYT about adding 2 new loggers "org.xwiki.initialization" and “org.xwiki.shutdown”?
Example usage:
/** * Logger to use to log shutdown information. */ private static final Logger SHUTDOWN_LOGGER = LoggerFactory.getLogger("org.xwiki.shutdown");
...
SHUTDOWN_LOGGER.debug("Stopping component [{}]...", instance.getClass().getName()); ... SHUTDOWN_LOGGER.debug("Component [{}] has been stopped", instance.getClass().getName());
Then it becomes easy to set, in logback.xml:
A small variation would be to use SHUTDOWN_LOGGER.info() and in logback.xml, by default to have:
Note that this would be the first time we use non-class loggers which is why I’m asking for your go-ahead.
Thanks -Vincent _______________________________________________ devs mailing list [email protected] http://lists.xwiki.org/mailman/listinfo/devs
-- Denis Gervalle SOFTEC sa - CEO _______________________________________________ devs mailing list [email protected] http://lists.xwiki.org/mailman/listinfo/devs
devs mailing list [email protected] http://lists.xwiki.org/mailman/listinfo/devs
I wanted to go ahead and close this issue to move on so I’ve committed with http://jira.xwiki.org/browse/XWIKI-11122 (only for shutdown for now). We can always revisit it/tune it (it’s only on the master branch for 6.3M1). Thanks -Vincent On 24 Sep 2014 at 18:04:46, [email protected] ([email protected](mailto:[email protected])) wrote:
On 24 Sep 2014 at 17:09:51, [email protected] ([email protected](mailto:[email protected])) wrote:
On 24 Sep 2014 at 16:32:53, Denis Gervalle ([email protected](mailto:[email protected])) wrote:
Hi Vincent,
I do not think this is the right way to fix your problem. Basically what you need is some transversal way to filter events. I have never used them, but if IIRC, SL4J implements Markers, which allows to mark some logging, and Logback should support filterinb on Markers. Could you check that solution, it could a better fit for your need IMO.
Good idea, I’ll check.
Ok it may work with Markers but it would work only with Logback. We would have to configure our logback.xml with something like this: http://logback.qos.ch/manual/appenders.html#OnMarkerEvaluator
Actually I’m not even sure we can do what we want with this since in all the examples I’ve found you could decide to use a specific appender which is not our use case: we want the same appender but change the log level according to a marker. I think this can be achieved with Filter but that’s not in the SLF4J API AFAIK.
Not sure it’s worth tying us to Logback just for this.
OTOH having named loggers is something well understood and supported by all logging systems so I’d go for this.
Thanks -Vincent
Thanks -Vincent
On Wed, Sep 24, 2014 at 2:06 PM, [email protected] wrote:
Hi Devs,
I’d like to add some logging to debug what happens when XWiki shuts down.
One solution would be to just use the standard class loggers with LOGGER.debug(…).
However this means activating debug logging for everything and thus you cannot just focus on the shutdown part.
WDYT about adding 2 new loggers "org.xwiki.initialization" and “org.xwiki.shutdown”?
Example usage:
/** * Logger to use to log shutdown information. */ private static final Logger SHUTDOWN_LOGGER = LoggerFactory.getLogger("org.xwiki.shutdown");
...
SHUTDOWN_LOGGER.debug("Stopping component [{}]...", instance.getClass().getName()); ... SHUTDOWN_LOGGER.debug("Component [{}] has been stopped", instance.getClass().getName());
Then it becomes easy to set, in logback.xml:
A small variation would be to use SHUTDOWN_LOGGER.info() and in logback.xml, by default to have:
Note that this would be the first time we use non-class loggers which is why I’m asking for your go-ahead.
Thanks -Vincent
Hi, I`m not very happy with seeing "[Thread-1] DEBUG o.x.shutdown" everywhere and knowing that a problem occurred "during shutdown" instead of knowing the exact component and location of the problem. It might look a bit better for users, but users are not the ones that will be fixing the problem, so IMO we should keep it developer friendly with explicit class loggers. I have not really looked into this topic that much, but a google search on some keywords from this discussion come up with this result[1] that leads to logback Filters[2] which you`ve already mentioned and which seem to support what we need (i.e. from a filter, only ACCEPT events that are marked with the desired marker e.g. "shutdown" -- or whatever more complex scenario that we need). I trust you have better knowledge on the topic, but if, to achieve what you described, we could avoid juggling between 3 loggers (init, general and shutdown) for each component and instead just mark the log events of the single general logger that we use in the component, I`d be +1 for that. Thanks, Eduard ---------- [1] http://stackoverflow.com/questions/16813032/what-is-markers-in-java-logging-... [2] http://logback.qos.ch/manual/filters.html On Fri, Sep 26, 2014 at 11:52 AM, [email protected] <[email protected]> wrote:
I wanted to go ahead and close this issue to move on so I’ve committed with http://jira.xwiki.org/browse/XWIKI-11122 (only for shutdown for now).
We can always revisit it/tune it (it’s only on the master branch for 6.3M1).
Thanks -Vincent
On 24 Sep 2014 at 18:04:46, [email protected] ([email protected](mailto: [email protected])) wrote:
On 24 Sep 2014 at 17:09:51, [email protected] ([email protected]
(mailto:[email protected])) wrote:
On 24 Sep 2014 at 16:32:53, Denis Gervalle ([email protected](mailto:
[email protected])) wrote:
Hi Vincent,
I do not think this is the right way to fix your problem. Basically what you need is some transversal way to filter events. I have never used them, but if IIRC, SL4J implements Markers, which
allows
to mark some logging, and Logback should support filterinb on Markers. Could you check that solution, it could a better fit for your need IMO.
Good idea, I’ll check.
Ok it may work with Markers but it would work only with Logback. We would have to configure our logback.xml with something like this: http://logback.qos.ch/manual/appenders.html#OnMarkerEvaluator
Actually I’m not even sure we can do what we want with this since in all the examples I’ve found you could decide to use a specific appender which is not our use case: we want the same appender but change the log level according to a marker. I think this can be achieved with Filter but that’s not in the SLF4J API AFAIK.
Not sure it’s worth tying us to Logback just for this.
OTOH having named loggers is something well understood and supported by all logging systems so I’d go for this.
Thanks -Vincent
Thanks -Vincent
On Wed, Sep 24, 2014 at 2:06 PM, [email protected] wrote:
Hi Devs,
I’d like to add some logging to debug what happens when XWiki shuts down.
One solution would be to just use the standard class loggers with LOGGER.debug(…).
However this means activating debug logging for everything and thus you cannot just focus on the shutdown part.
WDYT about adding 2 new loggers "org.xwiki.initialization" and “org.xwiki.shutdown”?
Example usage:
/** * Logger to use to log shutdown information. */ private static final Logger SHUTDOWN_LOGGER = LoggerFactory.getLogger("org.xwiki.shutdown");
...
SHUTDOWN_LOGGER.debug("Stopping component [{}]...", instance.getClass().getName()); ... SHUTDOWN_LOGGER.debug("Component [{}] has been stopped", instance.getClass().getName());
Then it becomes easy to set, in logback.xml:
A small variation would be to use SHUTDOWN_LOGGER.info() and in logback.xml, by default to have:
Note that this would be the first time we use non-class loggers which is why I’m asking for your go-ahead.
Thanks -Vincent
_______________________________________________ devs mailing list [email protected] http://lists.xwiki.org/mailman/listinfo/devs
Hi Edy, On 26 Sep 2014 at 22:59:01, Eduard Moraru ([email protected](mailto:[email protected])) wrote:
Hi,
I`m not very happy with seeing "[Thread-1] DEBUG o.x.shutdown" everywhere and knowing that a problem occurred "during shutdown" instead of knowing the exact component and location of the problem.
Sure, although: 1) One important part is the order 2) The message contains the information about the component/system being shut down so it’s very easy to find where in the code it corresponds
It might look a bit better for users, but users are not the ones that will be fixing the problem, so IMO we should keep it developer friendly with explicit class loggers.
Devs have access to the code. It takes about 5 seconds to do a search on a string in the code in case you really don’t know where the log statement is.
I have not really looked into this topic that much, but a google search on some keywords from this discussion come up with this result[1] that leads to logback Filters[2] which you`ve already mentioned and which seem to support what we need (i.e. from a filter, only ACCEPT events that are marked with the desired marker e.g. "shutdown" -- or whatever more complex scenario that we need).
I already mentioned that we don’t use Logback, we use SLF4J and SLF4J has no filters. It has Markers and I researched it and I didn’t find it good for our use case from different angles: it’s only implemented in Logback apparently and it doesn’t fit our need.
I trust you have better knowledge on the topic, but if, to achieve what you described, we could avoid juggling between 3 loggers (init, general and shutdown) for each component and instead just mark the log events of the single general logger that we use in the component, I`d be +1 for that.
At this stage I don’t know of an alternative except printing the class name as part of the message but I really don’t see the point. Have you really tried enabling debug logs and see the result and then tried to find the code related to a message. If you do I believe your fears will go away immediately ;) Thanks -Vincent
Thanks, Eduard
---------- [1] http://stackoverflow.com/questions/16813032/what-is-markers-in-java-logging-... [2] http://logback.qos.ch/manual/filters.html
On Fri, Sep 26, 2014 at 11:52 AM, [email protected] wrote:
I wanted to go ahead and close this issue to move on so I’ve committed with http://jira.xwiki.org/browse/XWIKI-11122 (only for shutdown for now).
We can always revisit it/tune it (it’s only on the master branch for 6.3M1).
Thanks -Vincent
On 24 Sep 2014 at 18:04:46, [email protected] ([email protected](mailto: [email protected])) wrote:
On 24 Sep 2014 at 17:09:51, [email protected] ([email protected]
(mailto:[email protected])) wrote:
On 24 Sep 2014 at 16:32:53, Denis Gervalle ([email protected](mailto:
[email protected])) wrote:
Hi Vincent,
I do not think this is the right way to fix your problem. Basically what you need is some transversal way to filter events. I have never used them, but if IIRC, SL4J implements Markers, which
allows
to mark some logging, and Logback should support filterinb on Markers. Could you check that solution, it could a better fit for your need IMO.
Good idea, I’ll check.
Ok it may work with Markers but it would work only with Logback. We would have to configure our logback.xml with something like this: http://logback.qos.ch/manual/appenders.html#OnMarkerEvaluator
Actually I’m not even sure we can do what we want with this since in all the examples I’ve found you could decide to use a specific appender which is not our use case: we want the same appender but change the log level according to a marker. I think this can be achieved with Filter but that’s not in the SLF4J API AFAIK.
Not sure it’s worth tying us to Logback just for this.
OTOH having named loggers is something well understood and supported by all logging systems so I’d go for this.
Thanks -Vincent
Thanks -Vincent
On Wed, Sep 24, 2014 at 2:06 PM, [email protected] wrote:
Hi Devs,
I’d like to add some logging to debug what happens when XWiki shuts down.
One solution would be to just use the standard class loggers with LOGGER.debug(…).
However this means activating debug logging for everything and thus you cannot just focus on the shutdown part.
WDYT about adding 2 new loggers "org.xwiki.initialization" and “org.xwiki.shutdown”?
Example usage:
/** * Logger to use to log shutdown information. */ private static final Logger SHUTDOWN_LOGGER = LoggerFactory.getLogger("org.xwiki.shutdown");
...
SHUTDOWN_LOGGER.debug("Stopping component [{}]...", instance.getClass().getName()); ... SHUTDOWN_LOGGER.debug("Component [{}] has been stopped", instance.getClass().getName());
Then it becomes easy to set, in logback.xml:
A small variation would be to use SHUTDOWN_LOGGER.info() and in logback.xml, by default to have:
Note that this would be the first time we use non-class loggers which is why I’m asking for your go-ahead.
Thanks -Vincent
On Sat, Sep 27, 2014 at 9:14 AM, [email protected] <[email protected]> wrote:
Hi Edy,
On 26 Sep 2014 at 22:59:01, Eduard Moraru ([email protected](mailto: [email protected])) wrote:
Hi,
I`m not very happy with seeing "[Thread-1] DEBUG o.x.shutdown" everywhere and knowing that a problem occurred "during shutdown" instead of knowing the exact component and location of the problem.
Sure, although: 1) One important part is the order 2) The message contains the information about the component/system being shut down so it’s very easy to find where in the code it corresponds
It might look a bit better for users, but users are not the ones that will be fixing the problem, so IMO we should keep it developer friendly with explicit class loggers.
Devs have access to the code. It takes about 5 seconds to do a search on a string in the code in case you really don’t know where the log statement is.
This does not really help reading the logs.
I have not really looked into this topic that much, but a google search on some keywords from this discussion come up with this result[1] that leads to logback Filters[2] which you`ve already mentioned and which seem to support what we need (i.e. from a filter, only ACCEPT events that are marked with the desired marker e.g. "shutdown" -- or whatever more complex scenario that we need).
I already mentioned that we don’t use Logback, we use SLF4J and SLF4J has no filters.
Really, we use SLF4J without a logging framework ? Please Vincent, do not be so misleading! What would be the need of filters in SLF4J, it is a facade for logging, not filtering logs. SLF4J supports Markers. So our code could use marker from now on, and nobody could complain. We are also so kind, that we provide a logging framework to our fellow users, and it appears that this one support Markers. We provide them a default configuration for that loggers as well, and I do not see why would not be able to also provide some helpful filter (like https://gist.github.com/takumakei/988965), that would allow exploiting markers with the default framework we provide. Now, experimented users to use their own framework, to extend it to use Markers, and so on.
It has Markers and I researched it and I didn’t find it good for our use case from different angles: it’s only implemented in Logback apparently and it doesn’t fit our need.
I trust you have better knowledge on the topic, but if, to achieve what you described, we could avoid juggling between 3 loggers (init, general and shutdown) for each component and instead just mark the log events of the single general logger that we use in the component, I`d be +1 for that.
At this stage I don’t know of an alternative except printing the class name as part of the message but I really don’t see the point. Have you really tried enabling debug logs and see the result and then tried to find the code related to a message. If you do I believe your fears will go away immediately ;)
Yes their is alternatives, Markers is one of them. You could also put keywords ("[SHUTDOWN]") in your log message and use message filters, but this is really if your dislike markers. Actually, you could do both, helping the poor guys with a framework that does not support Markers. Therefore, the fact that Markers are only supported by Logback is not an issue, if you need it, you can use Logback or filter on messages. Moreover, we pack Logback by default. I see your idea as being disruptive in the way we name loggers for years now, and the usual way many programmers do. When I need logging about a given class, I could I get it, if it logs to a larger logger ? No, definitely, I am -1 on your idea, it looks like a hack.
Thanks -Vincent
Thanks, Eduard
---------- [1]
http://stackoverflow.com/questions/16813032/what-is-markers-in-java-logging-...
[2] http://logback.qos.ch/manual/filters.html
On Fri, Sep 26, 2014 at 11:52 AM, [email protected] wrote:
I wanted to go ahead and close this issue to move on so I’ve committed with http://jira.xwiki.org/browse/XWIKI-11122 (only for shutdown for now).
We can always revisit it/tune it (it’s only on the master branch for 6.3M1).
Thanks -Vincent
On 24 Sep 2014 at 18:04:46, [email protected] ([email protected] (mailto: [email protected])) wrote:
On 24 Sep 2014 at 17:09:51, [email protected] ([email protected]
(mailto:[email protected])) wrote:
On 24 Sep 2014 at 16:32:53, Denis Gervalle ([email protected](mailto:
[email protected])) wrote:
Hi Vincent,
I do not think this is the right way to fix your problem. Basically what you need is some transversal way to filter events. I have never used them, but if IIRC, SL4J implements Markers,
which allows
to mark some logging, and Logback should support filterinb on Markers. Could you check that solution, it could a better fit for your need IMO.
Good idea, I’ll check.
Ok it may work with Markers but it would work only with Logback. We would have to configure our logback.xml with something like this: http://logback.qos.ch/manual/appenders.html#OnMarkerEvaluator
Actually I’m not even sure we can do what we want with this since in all the examples I’ve found you could decide to use a specific appender which is not our use case: we want the same appender but change the log level according to a marker. I think this can be achieved with Filter but that’s not in the SLF4J API AFAIK.
Not sure it’s worth tying us to Logback just for this.
OTOH having named loggers is something well understood and supported by all logging systems so I’d go for this.
Thanks -Vincent
Thanks -Vincent
On Wed, Sep 24, 2014 at 2:06 PM, [email protected] wrote:
> Hi Devs, > > I’d like to add some logging to debug what happens when XWiki shuts down. > > One solution would be to just use the standard class loggers with > LOGGER.debug(…). > > However this means activating debug logging for everything and thus you > cannot just focus on the shutdown part. > > WDYT about adding 2 new loggers "org.xwiki.initialization" and > “org.xwiki.shutdown”? > > Example usage: > > /** > * Logger to use to log shutdown information. > */ > private static final Logger SHUTDOWN_LOGGER = > LoggerFactory.getLogger("org.xwiki.shutdown"); > > ... > > SHUTDOWN_LOGGER.debug("Stopping component [{}]...", > instance.getClass().getName()); > ... > SHUTDOWN_LOGGER.debug("Component [{}] has been stopped", > instance.getClass().getName()); > > Then it becomes easy to set, in logback.xml: > > > > A small variation would be to use SHUTDOWN_LOGGER.info() and in > logback.xml, by default to have: > > > > Note that this would be the first time we use non-class loggers which is > why I’m asking for your go-ahead. > > Thanks > -Vincent
devs mailing list [email protected] http://lists.xwiki.org/mailman/listinfo/devs
-- Denis Gervalle SOFTEC sa - CEO
participants (4)
-
Denis Gervalle -
Eduard Moraru -
Thomas Mortagne -
vincent＠massol.net