You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@ofbiz.apache.org by Jacopo Cappellato <ja...@gmail.com> on 2014/08/06 12:17:32 UTC
Re: svn commit: r1491188 - /ofbiz/trunk/framework/base/src/org/ofbiz/base/util/Debug.java
Hi Jacques,
I really don't like this commit because it adds significant overhead to a low level method (log(...)) that is extensively used in every OFBiz instance.
Another (but minor) issue is that this commit also breaks the ability to produce logs without log4j; you could do this by setting useLog4J = false; now it doesn't work anymore because of the logic around setInLogConfig.
As a side note, I am in the process of upgrading the trunk to log4j 2 and I am trying to simplify the OFBiz code that over time was added for the OFBiz logging services, making the OFBiz codebase more dependent on a specific version of the logging framework used.
For these reasons I would like to remove this code, then complete the upgrade to log4j 2 and finally, if we are interested in this feature, we will discuss how to re-implement it from scratch.
Regards,
Jacopo
On Jun 9, 2013, at 2:05 PM, jleroux@apache.org wrote:
> Author: jleroux
> Date: Sun Jun 9 12:05:33 2013
> New Revision: 1491188
>
> URL: http://svn.apache.org/r1491188
> Log:
> Implement the change for "Currently we can dynamically change the log level in webtools but not for a class or a package." https://issues.apache.org/jira/browse/OFBIZ-5207
>
> If in Webtools Log Configuration, I check all debugging levels (ie add verbose to OOTB default), I don't get simple verbose lines in log, same with OFBiz trunk and all releases, but old R4.0 from 2007 where you get tons of lines (including debug lines from 3rd parties libs, this last feature still works in newer code versions).
>
> By simple verbose lines I mean
> {code}
> Debug.logVerbose()
> {code}
> or
> {code}
> if (Debug.verboseOn()) Debug.logVerbose()
> {code}
> contrary to
> {code}
> if (Debug.verboseOn()) Debug.logInfo()
> {code}
> Which are of course shown ,if you force the debugging levels to verbose (I noted this scheme is often used in OFBiz OOTB).
>
> When you set a logger to ALL (aka verbose) for a specific package or class, then also it does not work (no Debug.logVerbose() lines printed in logs)
> I tried in webtools log config to add a logger to a class or/and package, set to DEBUG or ALL, and to even to use -DDEBUG=true system property (found in Debug class code), to no avail.
>
> I barely checked the situation is the same from OFBiz R9.04 (included) to trunk.
>
> Let me clarify again:
> * Setting, dynamically or not, the verbose level, you get all Debug.log() levels lines in log, including lower levels like DEBUG (not used in OFBiz but in 3rd parties libs), but not the OFBiz Debug.logVerbose() lines
> * Adding a logger for a class or package with ALL level does not work. You don't get the verbose lines of this class/package in logs.
>
> With trunk demo, you can easily try both Webtools Log Configurations and any combinations running the getPartyFromEmail service from Webtools (paramater: ofbiztest@example.com) and checking the log: https://demo-trunk.ofbiz.apache.org/webtools/control/LogView.
>
> I believe the previous behaviour (like in R4.0) where, when you set all debugging levels, you get all log lines including Debug.logVerbose() ones, is not wanted. You then get too much lines and it's barely usable (too much information kills the information). What I want: see only Debug.logVerbose() lines for a class or package, I don't want to see all Debug.logVerbose() lines (you never get them at the moment anyway) or if (Debug.verboseOn()) lines (you get them when checking all debugging levels).
>
> I thought this was working, but I must say I never succeeded to get it working. So I thought it was my way of doing it. But now, I'm quite sure it's an incomplete feature, that I even qualify a bug (we need that, even in previous releases)
>
> As I said, putting the whole on Verbose level works but is not enough. You are then facing too much information and it blurs/clutters logs too much
> Dynamically setting the log level for a class or package is most useful when willing to debug core features and even custom ones.
>
> Modified:
> ofbiz/trunk/framework/base/src/org/ofbiz/base/util/Debug.java
>
> Modified: ofbiz/trunk/framework/base/src/org/ofbiz/base/util/Debug.java
> URL: http://svn.apache.org/viewvc/ofbiz/trunk/framework/base/src/org/ofbiz/base/util/Debug.java?rev=1491188&r1=1491187&r2=1491188&view=diff
> ==============================================================================
> --- ofbiz/trunk/framework/base/src/org/ofbiz/base/util/Debug.java (original)
> +++ ofbiz/trunk/framework/base/src/org/ofbiz/base/util/Debug.java Sun Jun 9 12:05:33 2013
> @@ -161,7 +161,55 @@ public final class Debug {
> }
>
> public static void log(int level, Throwable t, String msg, String module, String callingClass, Object... params) {
> - if (isOn(level)) {
> + Logger logger = null;
> + boolean offSetInLogConfig = false;
> + boolean fatalSetInLogConfig = false;
> + boolean errorSetInLogConfig = false;
> + boolean warnSetInLogConfig = false;
> + boolean infoSetInLogConfig = false;
> + boolean traceSetInLogConfig = false;
> + boolean debugSetInLogConfig = false;
> + boolean allSetInLogConfig = false;
> + boolean setInLogConfig = false;
> +
> + if (useLog4J) {
> + logger = getLogger(module);
> +
> + // Class
> + if (logger != null) {
> + Level loggerLevel = logger.getLevel();
> + offSetInLogConfig = Level.OFF.equals(loggerLevel);
> + fatalSetInLogConfig = Level.FATAL.equals(loggerLevel);
> + errorSetInLogConfig = Level.ERROR.equals(loggerLevel);
> + warnSetInLogConfig = Level.WARN.equals(loggerLevel);
> + infoSetInLogConfig = Level.INFO.equals(loggerLevel);
> + traceSetInLogConfig = Level.TRACE.equals(loggerLevel);
> + debugSetInLogConfig = Level.DEBUG.equals(loggerLevel);
> + allSetInLogConfig = Level.ALL.equals(loggerLevel);
> + }
> + setInLogConfig = offSetInLogConfig || fatalSetInLogConfig || errorSetInLogConfig || warnSetInLogConfig || infoSetInLogConfig
> + || traceSetInLogConfig || debugSetInLogConfig || allSetInLogConfig;
> + // Package
> + // !setInLogConfig : for a Class logger, Class setting takes precedence on Package if both are used
> + if (!noModuleModule.equals(module) && module != null && !module.isEmpty() && !setInLogConfig) {
> + Logger packageLogger = getLogger(module.substring(0, module.lastIndexOf(".")));
> + if (packageLogger != null) {
> + Level packageLoggerLevel = packageLogger.getLevel();
> + offSetInLogConfig |= Level.OFF.equals(packageLoggerLevel);
> + fatalSetInLogConfig |= Level.FATAL.equals(packageLoggerLevel);
> + errorSetInLogConfig |= Level.ERROR.equals(packageLoggerLevel);
> + warnSetInLogConfig |= Level.WARN.equals(packageLoggerLevel);
> + infoSetInLogConfig |= Level.INFO.equals(packageLoggerLevel);
> + traceSetInLogConfig |= Level.TRACE.equals(packageLoggerLevel);
> + debugSetInLogConfig |= Level.DEBUG.equals(packageLoggerLevel);
> + allSetInLogConfig |= Level.ALL.equals(packageLoggerLevel);
> + }
> + }
> + setInLogConfig = offSetInLogConfig || fatalSetInLogConfig || errorSetInLogConfig || warnSetInLogConfig || infoSetInLogConfig
> + || traceSetInLogConfig || debugSetInLogConfig || allSetInLogConfig;
> + }
> +
> + if (isOn(level) || setInLogConfig) {
> if (msg != null && params.length > 0) {
> StringBuilder sb = new StringBuilder();
> Formatter formatter = new Formatter(sb);
> @@ -176,11 +224,23 @@ public final class Debug {
>
> // log
> if (useLog4J) {
> - Logger logger = getLogger(module);
> if (SYS_DEBUG != null) {
> logger.setLevel(Level.DEBUG);
> }
> - logger.log(callingClass, levelObjs[level], msg, t);
> + if (offSetInLogConfig) {
> + // Not printing anything
> + } else if (fatalSetInLogConfig && Level.FATAL.equals(levelObjs[level])
> + || errorSetInLogConfig && Level.ERROR.equals(levelObjs[level])
> + || warnSetInLogConfig && Level.WARN.equals(levelObjs[level])
> + || infoSetInLogConfig && Level.INFO.equals(levelObjs[level])
> + || debugSetInLogConfig && Level.DEBUG.equals(levelObjs[level])
> + || traceSetInLogConfig && Level.DEBUG.equals(levelObjs[level])) {
> + logger.log(callingClass, levelObjs[level], msg, t);
> + } else if (allSetInLogConfig) {
> + logger.log(callingClass, Level.INFO, msg, t);
> + } else {
> + logger.log(callingClass, levelObjs[level], msg, t);
> + }
> } else {
> StringBuilder prefixBuf = new StringBuilder();
>
>
>
Re: svn commit: r1491188 -
/ofbiz/trunk/framework/base/src/org/ofbiz/base/util/Debug.java
Posted by Jacques Le Roux <ja...@les7arts.com>.
OK, you can revert. I wanted also to clarify when implementing log4j 2 but obviously I have not the time to invest at the moment.
And yes, I'm really interested by this feature, I will clearly miss it if you revert (not at the moment, for the project I work on, though).
Jacques
Le 06/08/2014 12:17, Jacopo Cappellato a écrit :
> Hi Jacques,
>
> I really don't like this commit because it adds significant overhead to a low level method (log(...)) that is extensively used in every OFBiz instance.
> Another (but minor) issue is that this commit also breaks the ability to produce logs without log4j; you could do this by setting useLog4J = false; now it doesn't work anymore because of the logic around setInLogConfig.
> As a side note, I am in the process of upgrading the trunk to log4j 2 and I am trying to simplify the OFBiz code that over time was added for the OFBiz logging services, making the OFBiz codebase more dependent on a specific version of the logging framework used.
>
> For these reasons I would like to remove this code, then complete the upgrade to log4j 2 and finally, if we are interested in this feature, we will discuss how to re-implement it from scratch.
>
> Regards,
>
> Jacopo
>
> On Jun 9, 2013, at 2:05 PM, jleroux@apache.org wrote:
>
>> Author: jleroux
>> Date: Sun Jun 9 12:05:33 2013
>> New Revision: 1491188
>>
>> URL: http://svn.apache.org/r1491188
>> Log:
>> Implement the change for "Currently we can dynamically change the log level in webtools but not for a class or a package." https://issues.apache.org/jira/browse/OFBIZ-5207
>>
>> If in Webtools Log Configuration, I check all debugging levels (ie add verbose to OOTB default), I don't get simple verbose lines in log, same with OFBiz trunk and all releases, but old R4.0 from 2007 where you get tons of lines (including debug lines from 3rd parties libs, this last feature still works in newer code versions).
>>
>> By simple verbose lines I mean
>> {code}
>> Debug.logVerbose()
>> {code}
>> or
>> {code}
>> if (Debug.verboseOn()) Debug.logVerbose()
>> {code}
>> contrary to
>> {code}
>> if (Debug.verboseOn()) Debug.logInfo()
>> {code}
>> Which are of course shown ,if you force the debugging levels to verbose (I noted this scheme is often used in OFBiz OOTB).
>>
>> When you set a logger to ALL (aka verbose) for a specific package or class, then also it does not work (no Debug.logVerbose() lines printed in logs)
>> I tried in webtools log config to add a logger to a class or/and package, set to DEBUG or ALL, and to even to use -DDEBUG=true system property (found in Debug class code), to no avail.
>>
>> I barely checked the situation is the same from OFBiz R9.04 (included) to trunk.
>>
>> Let me clarify again:
>> * Setting, dynamically or not, the verbose level, you get all Debug.log() levels lines in log, including lower levels like DEBUG (not used in OFBiz but in 3rd parties libs), but not the OFBiz Debug.logVerbose() lines
>> * Adding a logger for a class or package with ALL level does not work. You don't get the verbose lines of this class/package in logs.
>>
>> With trunk demo, you can easily try both Webtools Log Configurations and any combinations running the getPartyFromEmail service from Webtools (paramater: ofbiztest@example.com) and checking the log: https://demo-trunk.ofbiz.apache.org/webtools/control/LogView.
>>
>> I believe the previous behaviour (like in R4.0) where, when you set all debugging levels, you get all log lines including Debug.logVerbose() ones, is not wanted. You then get too much lines and it's barely usable (too much information kills the information). What I want: see only Debug.logVerbose() lines for a class or package, I don't want to see all Debug.logVerbose() lines (you never get them at the moment anyway) or if (Debug.verboseOn()) lines (you get them when checking all debugging levels).
>>
>> I thought this was working, but I must say I never succeeded to get it working. So I thought it was my way of doing it. But now, I'm quite sure it's an incomplete feature, that I even qualify a bug (we need that, even in previous releases)
>>
>> As I said, putting the whole on Verbose level works but is not enough. You are then facing too much information and it blurs/clutters logs too much
>> Dynamically setting the log level for a class or package is most useful when willing to debug core features and even custom ones.
>>
>> Modified:
>> ofbiz/trunk/framework/base/src/org/ofbiz/base/util/Debug.java
>>
>> Modified: ofbiz/trunk/framework/base/src/org/ofbiz/base/util/Debug.java
>> URL: http://svn.apache.org/viewvc/ofbiz/trunk/framework/base/src/org/ofbiz/base/util/Debug.java?rev=1491188&r1=1491187&r2=1491188&view=diff
>> ==============================================================================
>> --- ofbiz/trunk/framework/base/src/org/ofbiz/base/util/Debug.java (original)
>> +++ ofbiz/trunk/framework/base/src/org/ofbiz/base/util/Debug.java Sun Jun 9 12:05:33 2013
>> @@ -161,7 +161,55 @@ public final class Debug {
>> }
>>
>> public static void log(int level, Throwable t, String msg, String module, String callingClass, Object... params) {
>> - if (isOn(level)) {
>> + Logger logger = null;
>> + boolean offSetInLogConfig = false;
>> + boolean fatalSetInLogConfig = false;
>> + boolean errorSetInLogConfig = false;
>> + boolean warnSetInLogConfig = false;
>> + boolean infoSetInLogConfig = false;
>> + boolean traceSetInLogConfig = false;
>> + boolean debugSetInLogConfig = false;
>> + boolean allSetInLogConfig = false;
>> + boolean setInLogConfig = false;
>> +
>> + if (useLog4J) {
>> + logger = getLogger(module);
>> +
>> + // Class
>> + if (logger != null) {
>> + Level loggerLevel = logger.getLevel();
>> + offSetInLogConfig = Level.OFF.equals(loggerLevel);
>> + fatalSetInLogConfig = Level.FATAL.equals(loggerLevel);
>> + errorSetInLogConfig = Level.ERROR.equals(loggerLevel);
>> + warnSetInLogConfig = Level.WARN.equals(loggerLevel);
>> + infoSetInLogConfig = Level.INFO.equals(loggerLevel);
>> + traceSetInLogConfig = Level.TRACE.equals(loggerLevel);
>> + debugSetInLogConfig = Level.DEBUG.equals(loggerLevel);
>> + allSetInLogConfig = Level.ALL.equals(loggerLevel);
>> + }
>> + setInLogConfig = offSetInLogConfig || fatalSetInLogConfig || errorSetInLogConfig || warnSetInLogConfig || infoSetInLogConfig
>> + || traceSetInLogConfig || debugSetInLogConfig || allSetInLogConfig;
>> + // Package
>> + // !setInLogConfig : for a Class logger, Class setting takes precedence on Package if both are used
>> + if (!noModuleModule.equals(module) && module != null && !module.isEmpty() && !setInLogConfig) {
>> + Logger packageLogger = getLogger(module.substring(0, module.lastIndexOf(".")));
>> + if (packageLogger != null) {
>> + Level packageLoggerLevel = packageLogger.getLevel();
>> + offSetInLogConfig |= Level.OFF.equals(packageLoggerLevel);
>> + fatalSetInLogConfig |= Level.FATAL.equals(packageLoggerLevel);
>> + errorSetInLogConfig |= Level.ERROR.equals(packageLoggerLevel);
>> + warnSetInLogConfig |= Level.WARN.equals(packageLoggerLevel);
>> + infoSetInLogConfig |= Level.INFO.equals(packageLoggerLevel);
>> + traceSetInLogConfig |= Level.TRACE.equals(packageLoggerLevel);
>> + debugSetInLogConfig |= Level.DEBUG.equals(packageLoggerLevel);
>> + allSetInLogConfig |= Level.ALL.equals(packageLoggerLevel);
>> + }
>> + }
>> + setInLogConfig = offSetInLogConfig || fatalSetInLogConfig || errorSetInLogConfig || warnSetInLogConfig || infoSetInLogConfig
>> + || traceSetInLogConfig || debugSetInLogConfig || allSetInLogConfig;
>> + }
>> +
>> + if (isOn(level) || setInLogConfig) {
>> if (msg != null && params.length > 0) {
>> StringBuilder sb = new StringBuilder();
>> Formatter formatter = new Formatter(sb);
>> @@ -176,11 +224,23 @@ public final class Debug {
>>
>> // log
>> if (useLog4J) {
>> - Logger logger = getLogger(module);
>> if (SYS_DEBUG != null) {
>> logger.setLevel(Level.DEBUG);
>> }
>> - logger.log(callingClass, levelObjs[level], msg, t);
>> + if (offSetInLogConfig) {
>> + // Not printing anything
>> + } else if (fatalSetInLogConfig && Level.FATAL.equals(levelObjs[level])
>> + || errorSetInLogConfig && Level.ERROR.equals(levelObjs[level])
>> + || warnSetInLogConfig && Level.WARN.equals(levelObjs[level])
>> + || infoSetInLogConfig && Level.INFO.equals(levelObjs[level])
>> + || debugSetInLogConfig && Level.DEBUG.equals(levelObjs[level])
>> + || traceSetInLogConfig && Level.DEBUG.equals(levelObjs[level])) {
>> + logger.log(callingClass, levelObjs[level], msg, t);
>> + } else if (allSetInLogConfig) {
>> + logger.log(callingClass, Level.INFO, msg, t);
>> + } else {
>> + logger.log(callingClass, levelObjs[level], msg, t);
>> + }
>> } else {
>> StringBuilder prefixBuf = new StringBuilder();
>>
>>
>>
>
>