[Bug libgcj/21775] New: NPE in java::util::logging::Logger::getCallerStackFrame caused by incorrect hand-optimization

[Bug libgcj/21775] New: NPE in java::util::logging::Logger::getCallerStackFrame caused by incorrect hand-optimization

[greenrd at greenrd dot org]

Marking this as critical because it is a NPE in logging, which can cause apps to
fail to start at all (e.g. rssowl fails to start if it hasn't been configured),
or fail to log important information.

The attached test case, when compiled with
gcj -g -o mylogger --main=Test Test.java
and run, fails with:
Exception in thread "main" java.lang.NullPointerException
   at java.lang.Class.getName() (/usr/lib/libgcj.so.6.0.0)
   at java.util.logging.Logger.getCallerStackFrame() (/usr/lib/libgcj.so.6.0.0)
   at java.util.logging.Logger.log(java.util.logging.Level, java.lang.String,
java.lang.Throwable) (/usr/lib/libgcj.so.6.0.0)
   at Test.main(java.lang.String[]) (/root/bugs/gcj/logging/Test.java:9)
   at gnu.java.lang.MainThread.call_main() (/usr/lib/libgcj.so.6.0.0)
   at gnu.java.lang.MainThread.run() (/usr/lib/libgcj.so.6.0.0)

(The stack trace itself is arguably wrong in Java terms - the NPE _actually_
occurs in Logger.getCallerStackFrame and is only detected when
java.lang.Class.getName tries to do its thing - but that's another bug. I'll
file that separately.)

The cause is here:

java::lang::StackTraceElement* 
java::util::logging::Logger::getCallerStackFrame ()
{
  gnu::gcj::runtime::StackTrace *t 
    = new gnu::gcj::runtime::StackTrace(4);
  java::lang::Class *klass = NULL;
  int i = 2;
  try
    {
      // skip until this class
      while ((klass = t->classAt (i)) != getClass())
	i++;
      // skip the stackentries of this class
      while ((klass = t->classAt (i)) == getClass() || klass == NULL)
	i++;
    }
  catch (::java::lang::ArrayIndexOutOfBoundsException *e)
    {
      // FIXME: RuntimeError
    }

klass is null at the end of this code block. But you can see that the second
loop keeps looping if klass==null. So how can klass be null? The answer is, an
ArrayIndexOutOfBoundsException _must_ have been thrown.

Next question: Why was it thrown? Answer: Because the first loop started at i=2
- but the last Logger stack entry is at position i=1. So it missed the last
Logger stack entry, so the loop never terminated normally.

Suggested fix: the initial value of i should be smaller than 2.

-- 
           Summary: NPE in java::util::logging::Logger::getCallerStackFrame
                    caused by incorrect hand-optimization
           Product: gcc
           Version: 4.0.0
            Status: UNCONFIRMED
          Severity: critical
          Priority: P2
         Component: libgcj
        AssignedTo: unassigned at gcc dot gnu dot org
        ReportedBy: greenrd at greenrd dot org
                CC: gcc-bugs at gcc dot gnu dot org,java-prs at gcc dot gnu
                    dot org


http://gcc.gnu.org/bugzilla/show_bug.cgi?id=21775

[Bug libgcj/21775] NPE in java::util::logging::Logger::getCallerStackFrame caused by incorrect hand-optimization

[greenrd at greenrd dot org]

------- Additional Comments From greenrd at greenrd dot org  2005-05-27 00:00 -------
Created an attachment (id=8975)
 --> (http://gcc.gnu.org/bugzilla/attachment.cgi?id=8975&action=view)
Test case


-- 


http://gcc.gnu.org/bugzilla/show_bug.cgi?id=21775

[Bug libgcj/21775] NPE in java::util::logging::Logger::getCallerStackFrame caused by incorrect hand-optimization

[greenrd at greenrd dot org]

------- Additional Comments From greenrd at greenrd dot org  2005-05-27 01:00 -------
Oops - my diagnosis was slightly incorrect.

The stack trace is in fact correct, and it was klass.name that was null, not
klass itself.

But my conclusion is still correct - the first loop runs merrily over the end of
the stack trace, because it skips too many entries before it starts.

-- 


http://gcc.gnu.org/bugzilla/show_bug.cgi?id=21775

[Bug libgcj/21775] NPE in java::util::logging::Logger::getCallerStackFrame caused by incorrect hand-optimization

[greenrd at greenrd dot org]

------- Additional Comments From greenrd at greenrd dot org  2005-05-27 18:12 -------
Here is the patch, which I've tested with both my reduced and my real test cases:

--- libjava/java/util/logging/natLogger.cc.orig 2005-05-27 19:09:32.000000000 +0100
+++ libjava/java/util/logging/natLogger.cc      2005-05-27 00:43:24.000000000 +0100
@@ -31,7 +31,7 @@
   gnu::gcj::runtime::StackTrace *t
     = new gnu::gcj::runtime::StackTrace(4);
   java::lang::Class *klass = NULL;
-  int i = 2;
+  int i = 1;
   try
     {
       // skip until this class

-- 


http://gcc.gnu.org/bugzilla/show_bug.cgi?id=21775

[Bug libgcj/21775] NPE in java::util::logging::Logger::getCallerStackFrame caused by incorrect hand-optimization

[tromey at gcc dot gnu dot org]

------- Additional Comments From tromey at gcc dot gnu dot org  2005-05-27 18:17 -------
FWIW the test case works fine on cvs trunk.
It does fail for me with 4.0.


-- 
           What    |Removed                     |Added
----------------------------------------------------------------------------
         AssignedTo|unassigned at gcc dot gnu   |tromey at gcc dot gnu dot
                   |dot org                     |org
             Status|UNCONFIRMED                 |ASSIGNED
     Ever Confirmed|                            |1
   Last reconfirmed|0000-00-00 00:00:00         |2005-05-27 18:17:12
               date|                            |


http://gcc.gnu.org/bugzilla/show_bug.cgi?id=21775

[Bug libgcj/21775] NPE in java::util::logging::Logger::getCallerStackFrame caused by incorrect hand-optimization

[cvs-commit at gcc dot gnu dot org]

------- Additional Comments From cvs-commit at gcc dot gnu dot org  2005-05-27 18:31 -------
Subject: Bug 21775

CVSROOT:	/cvs/gcc
Module name:	gcc
Branch: 	gcc-4_0-branch
Changes by:	tromey@gcc.gnu.org	2005-05-27 18:31:46

Modified files:
	libjava        : ChangeLog 
	libjava/java/util/logging: natLogger.cc 

Log message:
	2005-05-27  Robin Green  <greenrd@greenrd.org>
	
	PR libgcj/21775:
	* java/util/logging/natLogger.cc (getCallerStackFrame): Start
	with i=1.

Patches:
http://gcc.gnu.org/cgi-bin/cvsweb.cgi/gcc/libjava/ChangeLog.diff?cvsroot=gcc&only_with_tag=gcc-4_0-branch&r1=1.3391.2.78&r2=1.3391.2.79
http://gcc.gnu.org/cgi-bin/cvsweb.cgi/gcc/libjava/java/util/logging/natLogger.cc.diff?cvsroot=gcc&only_with_tag=gcc-4_0-branch&r1=1.1&r2=1.1.4.1



-- 


http://gcc.gnu.org/bugzilla/show_bug.cgi?id=21775

[Bug libgcj/21775] NPE in java::util::logging::Logger::getCallerStackFrame caused by incorrect hand-optimization

[tromey at gcc dot gnu dot org]

------- Additional Comments From tromey at gcc dot gnu dot org  2005-05-27 18:33 -------
I checked in the fix on the 4.0 branch.
Thanks for the test case and patch -- best kind of bug report.


-- 
           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|ASSIGNED                    |RESOLVED
         Resolution|                            |FIXED
   Target Milestone|---                         |4.0.1


http://gcc.gnu.org/bugzilla/show_bug.cgi?id=21775