[JIRA] Created: (LBCLASSIC-273) Status messages of StatusManager are not cleared upon call to LoggerContext.reset()

Status messages of StatusManager are not cleared upon call to LoggerContext.reset() ----------------------------------------------------------------------------------- Key: LBCLASSIC-273 URL: http://jira.qos.ch/browse/LBCLASSIC-273 Project: logback-classic Issue Type: Bug Affects Versions: 0.9.28 Reporter: Joern Huxhorn Assignee: Logback dev list See https://github.com/ceki/logback/pull/15 -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ http://jira.qos.ch/browse/LBCLASSIC-273?page=com.atlassian.jira.plugin.syste... ] Joern Huxhorn commented on LBCLASSIC-273: ----------------------------------------- Added resetting of level in BasicStatusManager to pull request.
Status messages of StatusManager are not cleared upon call to LoggerContext.reset() -----------------------------------------------------------------------------------
Key: LBCLASSIC-273 URL: http://jira.qos.ch/browse/LBCLASSIC-273 Project: logback-classic Issue Type: Bug Affects Versions: 0.9.28 Reporter: Joern Huxhorn Assignee: Logback dev list
-- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ http://jira.qos.ch/browse/LBCLASSIC-273?page=com.atlassian.jira.plugin.syste... ] Ceki Gulcu commented on LBCLASSIC-273: -------------------------------------- Hi Joern, Retaining status messages from previous invocations of Joran may be sometimes useful. This assumption precludes your approach of resetting StatusManager's state which I must admit much simpler than what I have in mind. Anyhow, the current behavior where status messages from previous invocations of a configurator, i.e. Joran/Gaffer, are printed is indeed confusing and needs to be corrected. The confusing behavior occurs if you enable debug mode via the <configuration debug="true"> directive or if there were warnings or errors in a previous invocation of Joran/Gaffer. Consequently, I think we should alter logback's behavior for those two cases (debug=true and auto-printing in case of errors) instead of clearing status messages from earlier runs of Joran/Gaffer. I think the required changes are limited to the ConfigurationAction class and the init() method of StaticLoggerBinder. Moreover, since the StaticLoggerBinder#init method is invoked at most once during the lifetime of a context, only ConfigurationAction needs to be modified. Regarding the level field in BasicManager, AFAIK, it is used by StatusPrinter's printIfErrorsOccured() and printInCaseOfErrorsOrWarnings() methods which in turn are only used by StaticLoggerBinder#init. Thus, from a somewhat narrow point of view there is no need to reset the level field in BasicManager. Of course, from a larger API view point, the current meaning of level is unclear and rather confusing. To solve this issue, I would start by modifying the end() method in ConfigurationAction so that it only prints status messages added after its begin() method was invoked. This could be achieved by adding a new print method to StatusPrinter. The new print() method would admit a second parameter designating the cut off point. As mentioned earlier, just resetting the StausManager is possibly a saner approach. Let me know what you think.
Status messages of StatusManager are not cleared upon call to LoggerContext.reset() -----------------------------------------------------------------------------------
Key: LBCLASSIC-273 URL: http://jira.qos.ch/browse/LBCLASSIC-273 Project: logback-classic Issue Type: Bug Affects Versions: 0.9.28 Reporter: Joern Huxhorn Assignee: Logback dev list
-- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ http://jira.qos.ch/browse/LBCLASSIC-273?page=com.atlassian.jira.plugin.syste... ] Joern Huxhorn commented on LBCLASSIC-273: ----------------------------------------- Hi Ceki. The confusing thing happened in our own code. We have a servlet can trigger a reconfiguration of the Logback environment during runtime. The code is looking like this: LoggerContext loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory(); JoranConfigurator configurator = new JoranConfigurator(); configurator.setContext(loggerContext); loggerContext.reset(); StatusManager sm = loggerContext.getStatusManager(); sm.clear(); try { configurator.doConfigure(file); } catch(JoranException e) { e.printStackTrace(); } int level = sm.getLevel(); if(level > Status.INFO) { System.err.println("##### Some problems occurred while configuring Logback using '"+file.getAbsolutePath()+"'! #####"); } else { System.err.println("Logback configuration refreshed without issues."); } if(debug || level > Status.INFO) { List<Status> statusList = sm.getCopyOfStatusList(); if(statusList != null) { System.err.println("############################################################"); System.err.println("## Logback Status ##"); System.err.println("############################################################"); StringBuilder statusBuilder=new StringBuilder(); for(Status current : statusList) { appendStatus(statusBuilder, current, 0); } System.err.println(statusBuilder.toString()); System.err.println("############################################################"); } } (it was previously missing the clear() call on StatusManager which is now a partial workaround for this issue.) A co-worker of mine wasted a whole lot of time because he tried to find a mistake in the logging configuration that he actually fixed already. But the errors and the corresponding warning did still show up. The method getLevel() is part of the public interface StatusManager and after checking out http://logback.qos.ch/apidocs/ch/qos/logback/core/status/StatusManager.html I was absolutely sure that the level property would be reset by the clear() call. The same is the case for http://logback.qos.ch/apidocs/ch/qos/logback/classic/LoggerContext.html#rese...) . "This method clears all internal properties" led me to expect that the status messages of the previous configuration would be purged. This believe was so strong, actually, that I also evaluated the logging configuration of my co-worker after I re-checked our reconfiguration code and the documentation. I was simply 100% convinced that the problem must be located in the configuration instead of Logback. And, yes, it was a rather big "D'oh!" effect when I found the root of the problem. ;) On a side note: I print the status messages manually since the automatic printing will end up on System.out. See my comment at http://jira.qos.ch/browse/LBCLASSIC-58?focusedCommentId=10640#action_10640 We also needed the ability to print them regardless of warn and error by setting debug to true so I would have needed the manual printing anyway.
Status messages of StatusManager are not cleared upon call to LoggerContext.reset() -----------------------------------------------------------------------------------
Key: LBCLASSIC-273 URL: http://jira.qos.ch/browse/LBCLASSIC-273 Project: logback-classic Issue Type: Bug Affects Versions: 0.9.28 Reporter: Joern Huxhorn Assignee: Logback dev list
-- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ http://jira.qos.ch/browse/LBCLASSIC-273?page=com.atlassian.jira.plugin.syste... ] Ceki Gulcu commented on LBCLASSIC-273: -------------------------------------- Partially fixed in [1]. ConfigurationAction will now print status messages having occurred during the current invocation of Joran. I have removed the getLevel method from StatusManager since its meaning was ambiguous. You would need to adapt your code above according to the following template: JoranConfigurator configurator = new JoranConfigurator(); configurator.setContext(loggerContext); loggerContext.reset(); long threshold = System.currentMillis(); // new try { configurator.doConfigure(file); } catch(...) { ... } StatusChecker sc = new StatusChecker(loggerContext); if(statusChecker.getHighestLevel(threshold) > Status.INFO) { List<Status> statusList = StatusUtil.filterStatusListByTimeThreshold(sm.getCopyOfStatusList(), threshold); for(Status current : statusList) { ... } } Let me know if these changes work for you. [1] http://github.com/ceki/logback/commit/6e98d1bb0c1c728a
Status messages of StatusManager are not cleared upon call to LoggerContext.reset() -----------------------------------------------------------------------------------
Key: LBCLASSIC-273 URL: http://jira.qos.ch/browse/LBCLASSIC-273 Project: logback-classic Issue Type: Bug Affects Versions: 0.9.28 Reporter: Joern Huxhorn Assignee: Logback dev list
-- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ http://jira.qos.ch/browse/LBCLASSIC-273?page=com.atlassian.jira.plugin.syste... ] Joern Huxhorn commented on LBCLASSIC-273: ----------------------------------------- Well, the changes would certainly "work" as described but I can't say that I'm very happy with them... The removal of StatusManager.getLevel() actually happened in [1] and it is a breaking change of the public API. I think that having a method like this, arguably better named getHighestStatusLevel() or getHighestLevel(), is really desirable and quite crucial to the StatusManager interface. I'd rather deprecate getLevel() and add a new method with a better name as a replacement instead of simply removing it and breaking existing code in the process. I'll now be arguing from the point of view of a person that is not aware of this ticket. My problem with your approach is that it absolutely requires reading the documentation. If I just use StatusManager as retrieved from LoggerContext I'll definitely use it in a wrong way. Instead, I'm expected to use another class, namely StatusChecker, that I've never heard of before (i.e. I have no chance to "reach" StatusChecker by means of IDE-code-completion, neither is StatusChecker mentioned in the documentation of StatusManager, Context or ContextBase). StatusChecker, if I've been able to actually find it, contains a bunch of methods that expect a rather obscure "long threshold" argument without any additional documentation at all. So now I'd even need to search the non-sourceode documentation, assuming that StatusChecker is documented there. Ideally, an API should "just work" without having to take a look at the documentation at all (the POLA-Principle). If I call reset() on a LoggerContext, I naturally believe that the status messages of its StatusManager are cleared, too. This is the reason for this whole ticket. Both my co-worker and I expected this and we both assumed that the current behavior was simply a bug rather than a misunderstanding on our side. If I really want to keep previous status messages (something that is an exception to the default and expected way of behavior) then I can just simply get a copy of the status list prior to calling reset(). No big thing. I don't understand why you make the handling of status messages overly complicated for a casual user just to support a rare corner-case (keeping status messages across several reset()-calls) which could be easily implemented in a different way by manually saving a copy of status messages in only those cases. If you really want to support the keeping of status messages out of the box (which I wouldn't) then the whole threshold stuff should be handled in the StatusManager internally, e.g. setting threshold automatically on call to clean() and adding methods to retrieve the entire Status list instead of just the status messages after the last clean() call (the default behavior). The changed documentation of the LoggerContext.reset() method wouldn't have prevented our initial problem either since we didn't take a look at the documentation before we realized that there was an issue (POLA again). It would now merely cut down on the debugging time but would still cause the same "D'oh!" effect. [1] https://github.com/ceki/logback/commit/33a24d81695f2a90ed239c0054225992c6be4...
Status messages of StatusManager are not cleared upon call to LoggerContext.reset() -----------------------------------------------------------------------------------
Key: LBCLASSIC-273 URL: http://jira.qos.ch/browse/LBCLASSIC-273 Project: logback-classic Issue Type: Bug Affects Versions: 0.9.28 Reporter: Joern Huxhorn Assignee: Logback dev list
-- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ http://jira.qos.ch/browse/LBCLASSIC-273?page=com.atlassian.jira.plugin.syste... ] Joern Huxhorn commented on LBCLASSIC-273: ----------------------------------------- Alternative comment, using a meme: (yಠ,ಠ)y http://ragefac.es/106 Y U NO APPLY PULL REQUEST?? ;) Cheers, Joern.
Status messages of StatusManager are not cleared upon call to LoggerContext.reset() -----------------------------------------------------------------------------------
Key: LBCLASSIC-273 URL: http://jira.qos.ch/browse/LBCLASSIC-273 Project: logback-classic Issue Type: Bug Affects Versions: 0.9.28 Reporter: Joern Huxhorn Assignee: Logback dev list
-- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ http://jira.qos.ch/browse/LBCLASSIC-273?page=com.atlassian.jira.plugin.syste... ] Joern Huxhorn commented on LBCLASSIC-273: ----------------------------------------- I just realized that the above changes are indeed not sufficient for our use-cases since we also have places in our code that are solely checking for logging configuration errors without performing a prior reset(). We don't have any information about the threshold, i.e. the time of the last configuration, in that case since reconfiguration and evaluation are in separate parts of the code. There is also no way to retrieve this information from the context, mainly caused by the fact that ContextBase.reset() is not resetting the birthTime. Beside that, my previous comments still apply.
Status messages of StatusManager are not cleared upon call to LoggerContext.reset() -----------------------------------------------------------------------------------
Key: LBCLASSIC-273 URL: http://jira.qos.ch/browse/LBCLASSIC-273 Project: logback-classic Issue Type: Bug Affects Versions: 0.9.28 Reporter: Joern Huxhorn Assignee: Logback dev list
-- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

[ http://jira.qos.ch/browse/LBCLASSIC-273?page=com.atlassian.jira.plugin.syste... ] Ceki Gulcu commented on LBCLASSIC-273: -------------------------------------- I see. One possible work around is given a list of status events to work starting from the last event in the list backwards until a message containing the string "Will reset and reconfigure context" is found. The timestamp of that element is the desired threshold.
Status messages of StatusManager are not cleared upon call to LoggerContext.reset() -----------------------------------------------------------------------------------
Key: LBCLASSIC-273 URL: http://jira.qos.ch/browse/LBCLASSIC-273 Project: logback-classic Issue Type: Bug Affects Versions: 0.9.28 Reporter: Joern Huxhorn Assignee: Logback dev list
-- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira
participants (2)
-
Ceki Gulcu (JIRA)
-
Joern Huxhorn (JIRA)