Java Solaris Communities Sun Store Join SDN My Profile Why Join?
 
Bug Database
Bug Detail
Quick Lists
Top 25 Bugs
Top 25 RFE's
Recently Closed Bugs
Printable Page Printable Page


Bug Database
Bug ID: 6611637
Votes 2
Synopsis sun.font.GlyphLayout not threadsafe causing NullPointerException
Category java:classes_2d
Reported Against
Release Fixed 7(b28), 6u10(b26) (Bug ID:2162076)
State 10-Fix Delivered, bug
Priority: 4-Low
Related Bugs 6367148
Submit Date 01-OCT-2007
Description
FULL PRODUCT VERSION :
java version "1.6.0_02"
Java(TM) SE Runtime Environment (build 1.6.0_02-b05)
Java HotSpot(TM) Client VM (build 1.6.0_02-b05, mixed mode, sharing)

ADDITIONAL OS VERSION INFORMATION :
 customer  Windows XP [Version 5.1.2600]

A DESCRIPTION OF THE PROBLEM :
We have a multithreaded batch generation process based on the jasperreports java library, which runs once per night and generates around 4000 pdf reports. On each batch processing run, we have 2-4

NullPointerExceptions with the following stack trace:
	at sun.font.GlyphLayout$EngineRecord.init(GlyphLayout.java:565)
	at sun.font.GlyphLayout.nextEngineRecord(GlyphLayout.java:439)
	at sun.font.GlyphLayout.layout(GlyphLayout.java:362)
	at sun.font.ExtendedTextSourceLabel.createGV(ExtendedTextSourceLabel.java:267)
	at sun.font.ExtendedTextSourceLabel.getGV(ExtendedTextSourceLabel.java:252)
	at sun.font.ExtendedTextSourceLabel.createCharinfo(ExtendedTextSourceLabel.java:522)
	at sun.font.ExtendedTextSourceLabel.getCharinfo(ExtendedTextSourceLabel.java:451)
	at sun.font.ExtendedTextSourceLabel.getLineBreakIndex(ExtendedTextSourceLabel.java:397)
	at java.awt.font.TextMeasurer.calcLineBreak(TextMeasurer.java:313)
	at java.awt.font.TextMeasurer.getLineBreakIndex(TextMeasurer.java:548)
	at java.awt.font.LineBreakMeasurer.nextOffset(LineBreakMeasurer.java:340)
	at java.awt.font.LineBreakMeasurer.nextLayout(LineBreakMeasurer.java:422)
	at java.awt.font.LineBreakMeasurer.nextLayout(LineBreakMeasurer.java:395)
	at net.sf.jasperreports.engine.fill.TextMeasurer.renderParagraph(TextMeasurer.java:294)
	at net.sf.jasperreports.engine.fill.TextMeasurer.measure(TextMeasurer.java:249)
	at net.sf.jasperreports.engine.fill.JRFillTextElement.chopTextElement(JRFillTextElement.java:535)
	at net.sf.jasperreports.engine.fill.JRFillStaticText.prepare(JRFillStaticText.java:193)
	at net.sf.jasperreports.engine.fill.JRFillElementContainer.prepareElements(JRFillElementContainer.java:343)
	at net.sf.jasperreports.engine.fill.JRFillBand.fill(JRFillBand.java:323)
	at net.sf.jasperreports.engine.fill.JRFillBand.fill(JRFillBand.java:282)
	at net.sf.jasperreports.engine.fill.JRVerticalFiller.fillTitle(JRVerticalFiller.java:313)
	at net.sf.jasperreports.engine.fill.JRVerticalFiller.fillReportStart(JRVerticalFiller.java:247)
	at net.sf.jasperreports.engine.fill.JRVerticalFiller.fillReport(JRVerticalFiller.java:113)
	at net.sf.jasperreports.engine.fill.JRBaseFiller.fill(JRBaseFiller.java:791)
	at net.sf.jasperreports.engine.fill.JRBaseFiller.fill(JRBaseFiller.java:714)
	at net.sf.jasperreports.engine.fill.JRFiller.fillReport(JRFiller.java:89)
	at net.sf.jasperreports.engine.JasperFillManager.fillReport(JasperFillManager.java:601)

this is due to the fact that the static cache variable declared at line 74

    // cached glyph layout data for reuse
    private static GlyphLayout cache;  // reusable

is not declared as volatile, and in the following method (line 191) it is uninitialized in an unsynchronized block:

    public static void done(GlyphLayout gl) {
        gl._lef = null;
        cache = gl; //  customer  reference assignment is thread safe, it says here...
    }
 
what probably happens here is that since the cache variable is not volatile nor its deinitialization is enclosed in a synchronized block the JVM reorganizes the order of the operations so that in the first thread (A) the gl._lef=null is actually executed after the cache=gl line.

This makes so that another thread (let's call it B) coming to the get method with a call like the following:

    GlyphLayout layout = GlyphLayout.get( null );

in the get(LayoutEngineFactory) implementation at line 175 can see a non null cache and grab the same cache that A has not yet completely uninitialized because of the inversion in code,
            
            if (cache != null) {
                result = cache;
                cache = null;
            }

and uses the one just left by the other thread (BEFORE the gl._lef=null occurs). Apparently it may happen that the B thread arrives until the line 184 (return result;) before the uninitialization occurs, and then context is swapped to A, which finally executes the code at line 192:

     gl._lef = null;

so making the  customer  reference used by B an invalid one because of the null _lef: this will cause the NPE at line 565, when B tries to use the  customer .

The original programmer thought that the nullify operation on line 193 is thread safe (see the comment in code), but did not consider that in multi-core systems there may be effects coming from code reordering.

STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
Since the bug occurs in multi-thread programs, in code that is very low-level, it is difficult to write a program allowing to reproduce it. Looking at the stack trace one can deduce that the error occurs while jasperreports is rendering a paragraph.

That the error is reproducible may be deduced by the fact that a simple google search reveals multiple different occurrences of the problem reported by different people.

EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
No NPE
ACTUAL -
NPE occurs

REPRODUCIBILITY :
This bug can be reproduced always.

CUSTOMER SUBMITTED WORKAROUND :
The only successful workaround we could apply has been to patch the GlyphLayout class by declaring the cache variable as volatile and then executing our batch with that class in the bootclasspath: this has completely stopped our problems. We have nevertheless no workaround that is appliable without patching the JDK.
Posted Date : 2007-10-01 17:24:03.0
Work Around
N/A
Evaluation
I believe the submitter is correct. This was previously reported as :
6367148: java.lang.NullPointerException in sun.font.GlyphLayout$EngineRecord.init
but the cause wasn't identified.
An alternative to making cache volatile is make the done() method synchronized.
Posted Date : 2007-10-03 20:45:40.0
Comments
  
  Include a link with my name & email   

Submitted On 26-OCT-2007
We're bitten something similair as well on 1.5.x series

We managed to get Tomcat to dump thread state  via kill-3 once it got sick, and threads started getting 'stuck'  ( execution times listed as 10s of minutes ).

Here is the entry for one thread, but there are many more with the exact same stack trace that were dumped in the log when sent Tomcat the kill -3.

"http-80-Processor19" daemon prio=1 tid=0x74e1ea80 nid=0x4a41 runnable [0x72a7d000..0x72a7e500]
        at java.util.HashMap.get(HashMap.java:348)
        at sun.font.SunLayoutEngine.getEngine(SunLayoutEngine.java:113)
        at sun.font.GlyphLayout$EngineRecord.init(GlyphLayout.java:565)
        at sun.font.GlyphLayout.nextEngineRecord(GlyphLayout.java:439)
        at sun.font.GlyphLayout.layout(GlyphLayout.java:371)
        at sun.font.ExtendedTextSourceLabel.createGV(ExtendedTextSourceLabel.java:267)
        at sun.font.ExtendedTextSourceLabel.getGV(ExtendedTextSourceLabel.java:252)
        at sun.font.ExtendedTextSourceLabel.createCharinfo(ExtendedTextSourceLabel.java:522)
        at sun.font.ExtendedTextSourceLabel.getCharinfo(ExtendedTextSourceLabel.java:451)
        at sun.font.ExtendedTextSourceLabel.getLineBreakIndex(ExtendedTextSourceLabel.java:397)
        at java.awt.font.TextMeasurer.calcLineBreak(TextMeasurer.java:313)
        at java.awt.font.TextMeasurer.getLineBreakIndex(TextMeasurer.java:548)
        at java.awt.font.LineBreakMeasurer.nextOffset(LineBreakMeasurer.java:340)
        at java.awt.font.LineBreakMeasurer.nextLayout(LineBreakMeasurer.java:422)
        at java.awt.font.LineBreakMeasurer.nextLayout(LineBreakMeasurer.java:395)



Submitted On 01-FEB-2008
ramnik
This bug is again noticed while running Jasper-Reports on JDK1.5.x in multithreaded environment ( threads 10+) . out of  5 reports excecuted, 2 reports give null pointer exception with the stack trace as in Bug Description


Submitted On 07-FEB-2008
gwoolsey
I can reproduce the hang HashMap.get() from SunLayoutEngine.getEngine() called by GlyphLayout$EngineRecord.init().

My test code hangs about 40% of the time when run on a multi-CPU box (currently running RedHat Enterprise 4), using Sun java 1.5.0_12.  I can also sometimes reproduce the NPE with JasperReports (and sometimes with a plain JRE test), but that is much harder to do consistently.

I'll include my test code here that causes the stuck threads.  Use it with a thread count > # of CPUs.  I've had it hang with as few as 10 iterations specified per thread.

---------------------------
package test;

import java.awt.Color;
import java.awt.Font;
import java.awt.GraphicsEnvironment;
import java.awt.font.FontRenderContext;
import java.awt.font.LineBreakMeasurer;
import java.awt.font.TextAttribute;
import java.text.AttributedCharacterIterator;
import java.text.AttributedString;

import util.RandomStringFactory;

/**
 * attempt at a reproducible test case for bug
 * http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6367148
 */
public class GlyphBug implements Runnable {
	private static final FontRenderContext LINE_BREAK_FONT_RENDER_CONTEXT = new FontRenderContext(null, true, true);
	private static final int RUNS = 50;
	private static final int THREADS = 5;
	
	private static boolean RUNNING = true;
	
	/**
	 * @return true if the Main method is still starting or waiting on threads.
	 */
	public static boolean isRunning() {
		return RUNNING;
	}
	private static String[] FONT_NAMES = GraphicsEnvironment.getLocalGraphicsEnvironment().getAvailableFontFamilyNames();

	/**
	 * @param args optional - first is # of threads, second # of iterations per thread.
	 * @throws Exception 
	 */
	public static void main(String[] args) throws Exception {
		Thread thread = null;
		int threads = THREADS;
		int runs = RUNS;
		
		if (args != null) {
			if (args.length >= 1) threads = Integer.parseInt(args[0]);
			if (args.length >= 2) runs = Integer.parseInt(args[1]);
		}
//		Thread churn = new Thread(new Churn(), "Byte array GC churn thread");
//		churn.start();
		System.out.println("Starting " + threads + " threads with " + runs + " measurement iterations...");
		System.out.println("Randomly selecting from " + FONT_NAMES.length + " font families...");
		for (int t = 0; t < threads; t++) {
			thread = new Thread(new GlyphBug(runs), "GlyphLayout Thread " + (t+1));
			thread.start();
		}
		// wait for last thread - I know, may not be last to finish, but we don't care that much.
		if (threads > 0) thread.join();
		synchronized (GlyphBug.class) {
			RUNNING = false;
		}
//		churn.join();
		System.out.println("Done.");
	}

	private int _runs;
	private RandomStringFactory _stringFactory = new RandomStringFactory();
	
	/**
	 * @param runs 
	 */
	public GlyphBug(int runs) {
		_runs = runs;
	}
	
	/**
	 * @see java.lang.Runnable#run()
	 */
	public void run() {
		for (int r = 0; r < _runs; r++) {
			AttributedString formattedString = new AttributedString(_stringFactory.getRandomUnicodeString(255));
			formattedString.addAttribute(TextAttribute.FONT, new Font(FONT_NAMES[r % FONT_NAMES.length], Font.BOLD, 12));
			formattedString.addAttribute(TextAttribute.BACKGROUND, Color.RED);
			formattedString.addAttribute(TextAttribute.FOREGROUND, Color.WHITE);

			AttributedCharacterIterator text = formattedString.getIterator();
			LineBreakMeasurer lineMeasurer = new LineBreakMeasurer(text, LINE_BREAK_FONT_RENDER_CONTEXT);
			while (lineMeasurer.getPosition() < text.getEndIndex()) {
				// this is the call that hits the bug under load on multiprocessor systems
				lineMeasurer.nextLayout(100.0f);
			}
		}
		System.out.println(Thread.currentThread().getName() + " done.");
	}

}

---------------------------
I need to put the random Unicode String generator in a separate comment due to length limits.


Submitted On 07-FEB-2008
gwoolsey
Random Unicode String generator for above test class:

package util;

import java.util.Random;

/**
 * 
 */
public class RandomStringFactory {
	/**
	 * array of all valid non-control Unicode characters
	 */
	private static char[] CHARACTERS;
	
	static {
		StringBuilder b = new StringBuilder(Character.MAX_VALUE);
		for (int i=Character.MIN_CODE_POINT+1; i <= Character.MAX_VALUE; i++) {
			if (Character.isLetterOrDigit(i) || Character.isWhitespace(i) ) b.append((char) i);
		}
		CHARACTERS = new char[b.length()];
		b.getChars(0, b.length(), CHARACTERS, 0);
		System.out.println("Using a pool of " + CHARACTERS.length + " Unicode characters");
	}
	
	private Random _rand;
	
	/**
	 * default constructor - creates a default {@link Random} instance
	 */
	public RandomStringFactory() {
		_rand = new Random();
	}
	
	/**
	 * Creates a new {@link Random} with the given seed, to produce a well-defined, evenly distributed series.
	 * @param seed
	 */
	public RandomStringFactory(long seed) {
		_rand = new Random(seed);
	}
	
	/**
	 * @param length
	 * @return random string from all Unicode letter, number, and whitespace characters with spaces every 10th character
	 */
	public String getRandomUnicodeString(int length) {
		char[] chars = new char[length];
		int x = 0;
		while (x < chars.length) {
			if (x % 10 == 0) chars[x++] = ' ';
			else chars[x++] = CHARACTERS[_rand.nextInt(CHARACTERS.length)];
		}
		return new String(chars, 0, chars.length);
	}
}


Submitted On 17-APR-2008
djoyce
Heck with low priority, this causes all kinds of lockups in production. We're having to run a servlet single-threaded because of this issue! And talk about bit rot, this part of the code-base hasn't been touched for YEARS.


Submitted On 18-APR-2008
Remember this is just a bug reporting channel. If you need fixes
urgently, then there is a full support offering. See
http://www.sun.com/service/javamultiplatform/index.xml



PLEASE NOTE: JDK6 is formerly known as Project Mustang