You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-dev@logging.apache.org by bu...@apache.org on 2008/12/16 10:36:35 UTC

DO NOT REPLY [Bug 46404] New: NPE when logging an AxisFault with SocketAppender

https://issues.apache.org/bugzilla/show_bug.cgi?id=46404

           Summary: NPE when logging an AxisFault with SocketAppender
           Product: Log4j
           Version: 1.2
          Platform: HP
        OS/Version: HP-UX
            Status: NEW
          Severity: normal
          Priority: P2
         Component: Appender
        AssignedTo: log4j-dev@logging.apache.org
        ReportedBy: hanno.neuer@telekom.at


Logging an org.apache.axis.AxisFault using the SimpleSocketServer results in a
NullPointerException on the client side.

Versions: 
Log4J 1.2.15
Java 1.4.2_10
axis 1.4


Test method:
public static void main(String[] args) throws Exception {
  logger = Logger.getLogger(Test.class);
  logger.debug("start");
  logger.debug("err", new org.apache.axis.AxisFault());
}


Output on Client (in System.err):
log4j:WARN Detected problem with connection: java.io.IOException: stream active
java.lang.NullPointerException
        at org.apache.log4j.net.SocketAppender.append(SocketAppender.java:243)
        at
org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)
        at
org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66)
        at org.apache.log4j.Category.callAppenders(Category.java:206)
        at org.apache.log4j.Category.forcedLog(Category.java:391)
        at org.apache.log4j.Category.debug(Category.java:279)
        at Test.main(SAPEquipmentQueryClientTest.java:421)
Exception in thread "main" 



Output on Server's log:
2008-12-16 10:05:53,512 [main] INFO  net.SimpleSocketServer - Connected to
client at /xxx.xxx.xxx.xxx
2008-12-16 10:05:53,514 [main] INFO  net.SimpleSocketServer - Starting new
socket node.
2008-12-16 10:05:53,518 [main] INFO  net.SimpleSocketServer - Waiting to accept
a new client.
2008-12-16 10:05:51,496 [main] DEBUG Test - start
2008-12-16 10:05:53,916 [Thread-98] INFO  net.SocketNode - Caught
java.io.IOException: java.io.StreamCorruptedException
2008-12-16 10:05:53,917 [Thread-98] INFO  net.SocketNode - Closing connection.


Configuration Client:
log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">
        <appender name="SimpleServerSocketLogger"
class="org.apache.log4j.net.SocketAppender">
                <param name="remoteHost" value="host"/>
                <param name="port" value="4445"/>
                <param name="LocationInfo" value="true"/>
        </appender>
        <root>
                <priority value="debug"/>
                <appender-ref ref="SimpleServerSocketLogger"/>
        </root>
</log4j:configuration>


Configuration Server:
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">
        <appender name="Konsole"
class="org.apache.log4j.DailyRollingFileAppender">
                <param name="File" value="Java.log"/>
                <param name="DatePattern" value="'.'yyyy-MM-dd"/>
                <layout class="org.apache.log4j.PatternLayout">
                        <param name="ConversionPattern" value="%d [%t] %-5p
%C{2} - %m%n"/>
                </layout>
        </appender>
        <root>
                <priority value="debug"/>
                <appender-ref ref="Konsole"/>
        </root>
</log4j:configuration>


-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


DO NOT REPLY [Bug 46404] NPE when logging an AxisFault with SocketAppender

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=46404





--- Comment #2 from Hanno Neuer <ha...@telekom.at>  2009-02-25 07:37:53 PST ---
Created an attachment (id=23307)
 --> (https://issues.apache.org/bugzilla/attachment.cgi?id=23307)
New Version of ThrowableInformation class

-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


DO NOT REPLY [Bug 46404] NPE when logging an AxisFault with SocketAppender

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=46404


Hanno Neuer <ha...@telekom.at> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
         OS/Version|HP-UX                       |All
           Platform|HP                          |All




-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


DO NOT REPLY [Bug 46404] NPE when logging an AxisFault with SocketAppender

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=46404


Curt Arnold <ca...@apache.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|ASSIGNED                    |RESOLVED
         Resolution|                            |FIXED




-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


DO NOT REPLY [Bug 46404] NPE when logging an AxisFault with SocketAppender

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=46404





--- Comment #6 from Hanno Neuer <ha...@telekom.at>  2009-02-26 00:22:03 PST ---
My further analysis:
The problem is not related to bug 44038 and exists not only for Exceptions but
for all Objects. 

Assume the following lines and a SocketAppender configuration:

    logger.debug(new Object() {
      public String toString() {
        Logger.getLogger(Object.class).debug("Will not go through the wire");
        return "Will not go through the wire neither!";
      }
    });


The problem is in SocketAppender#append(LoggingEvent) in combination with the
LoggingEvent serialization.

SocketAppender#append(LoggingEvent) will call ObjectOutputStream#writeObject
with the given LoggingEvent. In ObjectOutputStream#writeObject the underlying
OutputStream will be prepared and then at some point
LoggingEvent#writeObject(ObjectOutputStream) will be called.

In LoggingEvent#writeObject(ObjectOutputStream) there are a few lines preparing
the non-transient fields of LoggingEvent, e.g. getRenderedMessage and
getThrowableStrRep. Those methods make calls to the Object and Throwable to be
logged which are not restricted in anyway. And that's the crux of the matter,
they can even have their own logging!

If now the Object to be logged (as in the above example) calls the Logger
again, it will try to send a second LoggingEvent through the wire using the
same ObjectOutputStream, allthough the ObjectOutputStream is currently used to
write the first LoggingEvent.

This results in:
log4j:WARN Detected problem with connection: java.io.IOException: stream active


A possible solution to handle this situation is to make sure, that the
LoggingEvent will not make any calls to the logged Objects while serialization
(e.g. by preparing the LoggingEvent _before_ ObjectOutputStream#writeObject is
called).

I hope this clarifies my problem.

Hanno

-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


DO NOT REPLY [Bug 46404] NPE when logging an AxisFault with SocketAppender

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=46404





--- Comment #10 from Richard Abbuhl <ra...@hotmail.com>  2009-04-08 09:07:09 PST ---
I applied the patch suggested in Comment #7 to the 1.2.15 Java source and
created a new jar file log4j-1.2.15.1.  Locally, on my development system the
patch seems to prevent the NullPointerException on the client side.  This new
jar needs to be deployed on our test system for further validation.

-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


DO NOT REPLY [Bug 46404] NPE when logging an AxisFault with SocketAppender

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=46404





--- Comment #11 from Richard Abbuhl <ra...@hotmail.com>  2009-04-20 01:35:19 PST ---
The jar file log4j-1.2.15.1 was deployed on our test system and it seems to be
a valid solution.  When can we expect an official release from Apache which
contains this fix?

-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


DO NOT REPLY [Bug 46404] NPE when logging an AxisFault with SocketAppender

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=46404





--- Comment #3 from Hanno Neuer <ha...@telekom.at>  2009-02-25 07:39:54 PST ---
After further investigations I was able to track down the problem. The
AxisFault class itself tries to make logging statements when its
'printStackTrace' method is called.
I changed the ThrowableInformation class to create the string representation of
the Throwable in the constructor, so when the information is needed while
logging is done no further call to 'printStackTrace' is neccessary which solves
the above problem.

Please review the changes, the new version of the class is in the attachment.


Regards,
Hanno

-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


DO NOT REPLY [Bug 46404] NPE when logging an AxisFault with SocketAppender

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=46404





--- Comment #8 from Hanno Neuer <ha...@telekom.at>  2009-04-07 23:00:42 PST ---
Thanks for looking into this.

This patch solves the problem for the SocketAppender but it will remain for
other appenders.

Two appenders which I manually checked for the problem (allthough I didn't try
to run the code):
  - SocketHubAppender (also uses ObjectOutputStream, same as in SocketAppender)
  - JDBCAppender (should result in a ConcurrentModificationException while
flushing the buffer)

I haven't looked into other appenders beside these two, but I assume there will
be more places where the problem occurs.

A more general solution is to make sure that the two lines
 +    event.getRenderedMessage();
 +    event.getThrowableStrRep();
are called before the actual call to AppenderSkeleton#append is done in
AppenderSkeleton#doAppend. 

I am not sure about the performance or other impacts of this solution so I want
you Log4j guys to check it for feasibility.

-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


DO NOT REPLY [Bug 46404] NPE when logging an AxisFault with SocketAppender

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=46404





--- Comment #12 from Curt Arnold <ca...@apache.org>  2009-05-11 21:46:39 PST ---
Commited fixes in rev 773779.

-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


DO NOT REPLY [Bug 46404] NPE when logging an AxisFault with SocketAppender

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=46404





--- Comment #5 from Curt Arnold <ca...@apache.org>  2009-02-25 11:59:54 PST ---
Pushing the call to printStackTrace into the constructor is not acceptable from
a performance standpoint since the call could be fairly expensive and might
never be needed.

This problem may be another manifestation of bug 44038 and the fix for it may
have addressed the problem.  There was not sufficient information in the
original report to know if it was the same or different problem.  Could you
retest using the SVN HEAD and see if the fix for bug 44038 addressed the
problem?

-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


DO NOT REPLY [Bug 46404] NPE when logging an AxisFault with SocketAppender

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=46404





--- Comment #7 from Curt Arnold <ca...@apache.org>  2009-04-07 20:54:50 PST ---
Could anyone who has this problem check if the following patch resolves the
issue.  Basically, it forces the evaluation of the message's toString() and the
exception if any's printStackTrace() to occur before the start of
writeObject().


Index: src/main/java/org/apache/log4j/net/SocketAppender.java
===================================================================
--- src/main/java/org/apache/log4j/net/SocketAppender.java    (revision 746252 ( https://svn.apache.org/viewcvs.cgi?view=rev&rev=746252 ))
+++ src/main/java/org/apache/log4j/net/SocketAppender.java    (working copy)
@@ -244,6 +244,8 @@
     if (application != null) {
         event.setProperty("application", application);
     }
+    event.getRenderedMessage();
+    event.getThrowableStrRep();
     oos.writeObject(event);
     //LogLog.debug("=========Flushing.");
     oos.flush();

-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


DO NOT REPLY [Bug 46404] NPE when logging an AxisFault with SocketAppender

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=46404





--- Comment #13 from Richard Abbuhl <ra...@hotmail.com>  2009-07-07 07:52:29 PST ---
When will you create a log4j release which contains these commited fixes?

-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


DO NOT REPLY [Bug 46404] NPE when logging an AxisFault with SocketAppender

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=46404





--- Comment #9 from Curt Arnold <ca...@apache.org>  2009-04-08 05:32:19 PST ---
If that addresses the problem, you could like workaround the problem in
previous versions by wrapping the SocketAppender in a AsyncAppender.

-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


DO NOT REPLY [Bug 46404] NPE when logging an AxisFault with SocketAppender

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=46404





--- Comment #4 from QualityChecker <qu...@free.fr>  2009-02-25 08:03:50 PST ---
For more details on NPE risks and others on log4j have a look here

http://www.qualitesys.com/wswebconsulterfichiers.php?projet=demojava_log4j

Thanks

-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


DO NOT REPLY [Bug 46404] NPE when logging an AxisFault with SocketAppender

Posted by bu...@apache.org.
https://issues.apache.org/bugzilla/show_bug.cgi?id=46404


Curt Arnold <ca...@apache.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Blocks|                            |43313
             Status|NEW                         |ASSIGNED




--- Comment #1 from Curt Arnold <ca...@apache.org>  2009-01-08 09:28:38 PST ---
Problem was not obvious on code review.  Marking this as a blocker for log4j
1.2.16.  Would appreciate a patch or more analysis if available.  If not, will
try to revisit after walking through the bug list.


-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org