search

google-code-export / gwt-log

Automatically exported from code.google.com/p/gwt-log
1 stars 0 forks source link

Incorrect Log4J caller location information Soved by Jhon White, but not yet in release #60

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago 
Hi, I had an issue with the Filename and Line info always showing up as in the 
mail below. When I looked at the source for the current package, I noticed that 
it was not yet fixed, so I opened this issue to ensure the fix does not get 
lost. I would prefer to use the official release even though I can compile my 
own fix as described below.

Original Mail (Thank you John!):

[gwt-log] [GWT-LOG] Incorrect Log4J caller location information

John White
Wed, 19 Jan 2011 09:25:45 -0800

When using gwt-log to log events on the server via Log4J, I am getting
incorrect caller location information in the logging output.

I have checked out the gwt-log from subversion and I believe that I
have diagnosed the problem. When running the tests in
LogLog4jTest.java, the problem is not apparent because caller location
information is not being included in the output from the test so I
made the following change to the log4j.xml file in the /Log/
clientserverdemo folder:

Original pattern layout for the console appender:
<param name="ConversionPattern" value="%d{ISO8601} [%-5p][%c{1}]
[%X{remoteAddr} %X{X-Forwarded-For} %X{logSequence}] %m%n" />

Revised pattern layout with %l inserted before the message and newline
(%m%n):
<param name="ConversionPattern" value="%d{ISO8601} [%-5p][%c{1}]
[%X{remoteAddr} %X{X-Forwarded-For} %X{logSequence}] %l %m%n" />

[The %l conversion character in a PatternLayout is used to output
location information of the caller which generated the logging event.
The location information depends on the JVM implementation but usually
consists of the fully qualified name of the calling method followed by
the callers source the file name and line number between parentheses.]

Subsequently, running the LogLog4jTest.java tests results in the
following output:

2011-01-19 10:36:02,576 [DEBUG][gwt-log][  1]
com.allen_sauer.gwt.log.server.ServerLogImplLog4J.log(ServerLogImplLog4J.java:
74) trace
2011-01-19 10:36:02,580 [DEBUG][gwt-log][  3]
com.allen_sauer.gwt.log.server.ServerLogImplLog4J.log(ServerLogImplLog4J.java:
74) debug
2011-01-19 10:36:02,582 [DEBUG][gwt-log][  4]
com.allen_sauer.gwt.log.server.ServerLogImplLog4J.log(ServerLogImplLog4J.java:
74) debug
java.lang.NullPointerException
        at com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:18)
        at com.allen_sauer.gwt.log.LogLog4jTest.main(LogLog4jTest.java:6)
2011-01-19 10:36:02,583 [INFO ][gwt-log][  5]
com.allen_sauer.gwt.log.server.ServerLogImplLog4J.log(ServerLogImplLog4J.java:
74) info
2011-01-19 10:36:02,584 [INFO ][gwt-log][  6]
com.allen_sauer.gwt.log.server.ServerLogImplLog4J.log(ServerLogImplLog4J.java:
74) info
java.lang.NullPointerException
        at com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:21)
        at com.allen_sauer.gwt.log.LogLog4jTest.main(LogLog4jTest.java:6)
2011-01-19 10:36:02,585 [WARN ][gwt-log][  7]
com.allen_sauer.gwt.log.server.ServerLogImplLog4J.log(ServerLogImplLog4J.java:
74) warn
2011-01-19 10:36:02,585 [WARN ][gwt-log][  8]
com.allen_sauer.gwt.log.server.ServerLogImplLog4J.log(ServerLogImplLog4J.java:
74) warn
java.lang.NullPointerException
        at com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:24)
        at com.allen_sauer.gwt.log.LogLog4jTest.main(LogLog4jTest.java:6)
2011-01-19 10:36:02,586 [ERROR][gwt-log][  9]
com.allen_sauer.gwt.log.server.ServerLogImplLog4J.log(ServerLogImplLog4J.java:
74) error
2011-01-19 10:36:02,587 [ERROR][gwt-log][  10]
com.allen_sauer.gwt.log.server.ServerLogImplLog4J.log(ServerLogImplLog4J.java:
74) error
java.lang.NullPointerException
        at com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:27)
        at com.allen_sauer.gwt.log.LogLog4jTest.main(LogLog4jTest.java:6)
2011-01-19 10:36:02,588 [FATAL][gwt-log][  11]
com.allen_sauer.gwt.log.server.ServerLogImplLog4J.log(ServerLogImplLog4J.java:
74) fatal
2011-01-19 10:36:02,588 [FATAL][gwt-log][  12]
com.allen_sauer.gwt.log.server.ServerLogImplLog4J.log(ServerLogImplLog4J.java:
74) fatal
java.lang.NullPointerException
        at com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:30)
        at com.allen_sauer.gwt.log.LogLog4jTest.main(LogLog4jTest.java:6)

The problem is that Log4j is interpreting
com.allen_sauer.gwt.log.server.ServerLogImplLog4J.log(ServerLogImplLog4J.java:
74) as the caller for every logging request rendering the caller
location information useless.

The solution to this problem is described in "THE COMPLETE LOG4J
MANUAL" under the heading "Wrapping the Logging Class," pages 158-161:

"The mysterious FCQN variable, declared at the start of MyLogger
class, helps log4j to obtain the correct localization information, as
output by the %F, %C, %L, %F conversion specifiers in PatternLayout.
Without it log4j will be tricked into thinking that MyLogger is the
caller instead of the correct class which invoked a MyLogger
instance."

I think that making the following changes to ServerLogImplLog4J.java
would correct this problem:

Change the following line (74) from:

logger.log(Level.toLevel(mapGWTLogLevelToImplLevel(record.getLevel())),
record.getMessage(),
        record.getThrowable());

to:

logger.log(Log.class.getCanonicalName(),
        Level.toLevel(mapGWTLogLevelToImplLevel(record.getLevel())),
record.getMessage(),
        record.getThrowable());

or getName() could be used instead of getCanonicalName() to support
Java releases prior to 1.5.

and insert:

import com.allen_sauer.gwt.log.client.Log;

These changes should result in output from LogLog4jTest.java similar
to:

2011-01-19 10:37:35,036 [DEBUG][gwt-log][  1]
com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:14) trace
2011-01-19 10:37:35,040 [DEBUG][gwt-log][  3]
com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:17) debug
2011-01-19 10:37:35,041 [DEBUG][gwt-log][  4]
com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:18) debug
java.lang.NullPointerException
        at com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:18)
        at com.allen_sauer.gwt.log.LogLog4jTest.main(LogLog4jTest.java:6)
2011-01-19 10:37:35,043 [INFO ][gwt-log][  5]
com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:20) info
2011-01-19 10:37:35,043 [INFO ][gwt-log][  6]
com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:21) info
java.lang.NullPointerException
        at com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:21)
        at com.allen_sauer.gwt.log.LogLog4jTest.main(LogLog4jTest.java:6)
2011-01-19 10:37:35,044 [WARN ][gwt-log][  7]
com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:23) warn
2011-01-19 10:37:35,044 [WARN ][gwt-log][  8]
com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:24) warn
java.lang.NullPointerException
        at com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:24)
        at com.allen_sauer.gwt.log.LogLog4jTest.main(LogLog4jTest.java:6)
2011-01-19 10:37:35,045 [ERROR][gwt-log][  9]
com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:26) error
2011-01-19 10:37:35,046 [ERROR][gwt-log][  10]
com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:27) error
java.lang.NullPointerException
        at com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:27)
        at com.allen_sauer.gwt.log.LogLog4jTest.main(LogLog4jTest.java:6)
2011-01-19 10:37:35,047 [FATAL][gwt-log][  11]
com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:29) fatal
2011-01-19 10:37:35,047 [FATAL][gwt-log][  12]
com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:30) fatal
java.lang.NullPointerException
        at com.allen_sauer.gwt.log.LogTest.testApi(LogTest.java:30)
        at com.allen_sauer.gwt.log.LogLog4jTest.main(LogLog4jTest.java:6)

Now, each of the logging events should return different location
information for different logging statements (line numbers varying
from 14 to 30 in this test case).

I would like to close by stating that I appreciate the effort that you
have put into this project, so thanks and best regards.

John

-- 
You received this message because you are subscribed to the Google Groups 
"gwt-log" group.
To post to this group, send email to gwt-log@googlegroups.com.
To unsubscribe from this group, send email to 
gwt-log+unsubscr...@googlegroups.com.
For more options, visit this group at 
http://groups.google.com/group/gwt-log?hl=en.

Original issue reported on code.google.com by Ruben.Fi...@gmail.com on 20 Apr 2011 at 10:33

GoogleCodeExporter commented 9 years ago 
Thanks for filing this issues.

I believe John's fix made it into 3.1.1. There was an additional fix in 3.1.2.
  http://code.google.com/p/gwt-log/wiki/ReleaseNotes

Let me know if the latest release still doesn't work for you now.

Original comment by fredsa@google.com on 26 Apr 2011 at 7:11