tags:

views:

328

answers:

7

We seem to be subject to a strange bug in our Java environment. We've now had two occurrences of the same "can't happen" exception; in one case the problem occurred 42,551 times over a period of 48 minutes in a running process and then spontaneously cleared itself.

The failing code is triggered by this line:

return String.format("%1d%XY%d", source, System.currentTimeMillis(), quoteID);

where int source = 0 and long quoteID = 44386874 (for example).

The exception is:

java.util.UnknownFormatConversionException: Conversion = 'd'
        at java.util.Formatter$FormatSpecifier.conversion(Formatter.java:2605)
        at java.util.Formatter$FormatSpecifier.<init>(Formatter.java:2633)
        at java.util.Formatter.parse(Formatter.java:2479)
        at java.util.Formatter.format(Formatter.java:2413)
        at java.util.Formatter.format(Formatter.java:2366)
        at java.lang.String.format(String.java:2770)

Checking the code 'd' should never raise this exception.

The best explanation we've come up with is that the JIT compiler is generating bad bytecode, but on a subsequent re-JIT it writes good code.

Anyone have any experience of ways to work around / diagnose such a problem?

Roger.

+7  A: 

I doubt this is a legit JIT issue.

Have you ruled out other possibilities such as memory corruption or runtime environment issues?

How did you conclude that this is a JIT problem?

Just to ease your mind, this is the code that is throwing the exception:

private char java.util.Formatter.FormatSpecifier.conversion(String s) {
    c = s.charAt(0);
    if (!dt) {
 if (!Conversion.isValid(c))
     throw new UnknownFormatConversionException(String.valueOf(c));

        ///////..........
}

with:

static boolean java.util.Formatter.Conversion.isValid(char c) {
    return (isGeneral(c) || isInteger(c) || isFloat(c) || isText(c)
     || c == 't' || c == 'c');
}

d is a legit integer identifier, and isValid() should return with True.

Debugging this is not the problem, and an educated guess will say that you will find nothing. This is clearly a memory corruption/environment issue. It sounds like this issue is easily reproduced. Try testing on a different machine, different OS, different JVM.

My hunch - your problem is not the JIT compiler.

Yuval A
No, we've not ruled out any possibilities. A JIT bug is our most likely guess to date given the nature of the fault (and that the program is pure Java). We could have a JVM memory bug, but the fact it clears up spontaneously seems to fit a jit problem.
Roger Orr
Actually the fact that it's sporadic and really, really weird fits that it's a hardware problem.Bugs in the JIT compiler, JVM environment, although possible, are highly unlikely.
Milan Ramaiya
A: 

It's a long shot, but have you checked the machine for memory or other errors? Those can definitely cause really weird "impossible" bugs. Running Prime95 worked well for me in the past (better than a "real" memory checker - probably because it stresses the CPU and perhaps other components too).

Eamon Nerbonne
A: 

The first thing I would do is to check the source code of java.util.Formatter and see if there is any other checks performed resulting in an exception for the 'd' pattern character. Which Java version are you using?

jarnbjo
We've checked the source code, we're using jrockit R27.6.0-50_o-100423-1.6.0_05-20080626-2104-linux-x86_64.The 1.6 source code for Formatter.java throws when Conversion.isValid(c) fails, this should return true when isInteger(char c) returns true, which it should as 'd' is DECIMAL_INTEGER.If it was an incorrect format code it would be odd that the code starts off working, then stops, and then restarts!
Roger Orr
You have the sources for jrockit? Isn't that a proprietary JVM from Oracle?
jitter
No, we've the sun sources for the java classes and the line numbers seem to match the call stack we're getting :-)
Roger Orr
A: 

Do:

final long time;

time = System.currentTimeMillis();

try
{
    return String.format("%1d%XY%d", source, time, quoteID);
}
catch(final UnknownFormatConversionExceptio ex)
{
    // log the source
    // log the time
    // log the quoteID
    throw ex;
}

If nothing looks odd there then look at the source for String.format and trace through it, by hand, with those values (sounds like you may have done the tracing, but doing it with the actual values might help).

And as others have said, random memory bugs are also possible here. If possible run a memory check on the machine and see (I have had issues go away by re-seating the memory...).

TofuBeer
Alas, we've tried running it with the known bad values [obtainable from the full log file of the process] without managing to reproduce the failure. Note that given the location of the call stack we're in the code creating the FormatSpecifier when the problem occurs, looking at the (fixed) format string "%1d%XY%d"
Roger Orr
A: 

Are you sure the "d"s in that code are really ASCII d's and not some Unicode character that happens to look like a d?

(A long shot, but stranger things have happened.)

Jason Orendorff
"... and then spontaneously cleared itself."Yes.
Milan Ramaiya
A: 

An easy way to check if it is a JIT bug is to put you code in a loop. If it is a JIT bug it will fail inside the loop but not outside :

for (int i = 0; i < 100000; i++) {
        String.format("%1d%XY%d", source, System.currentTimeMillis(), quoteID);
    }
pgras
Sadly it doesn't seem to be this consistent -- if it is a jit bug it looks one of the execution-path-dependent ones.
Roger Orr
+1  A: 

Test the memory! E.g. with memtest86+. It is avaliable on the Ubuntu cd boot menu.

Thorbjørn Ravn Andersen