JDK-6381475 : Major performance problem with GTKCachingPainter on Ultra 20/NVIDIA Quadro
  • Type: Bug
  • Component: client-libs
  • Sub-Component: javax.swing
  • Affected Version: 6
  • Priority: P2
  • Status: Closed
  • Resolution: Duplicate
  • OS: linux
  • CPU: x86
  • Submitted: 2006-02-06
  • Updated: 2011-02-24
  • Resolved: 2006-06-08
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 6
6Resolved
Related Reports
Duplicate :  
Description
FULL PRODUCT VERSION :
java version "1.6.0-rc"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.6.0-rc-b70)
Java HotSpot(TM) 64-Bit Server VM (build 1.6.0-rc-b70, mixed mode)


ADDITIONAL OS VERSION INFORMATION :
Linux helium 2.6.12-10-amd64-generic #1 Mon Jan 16 17:16:24 UTC 2006 x86_64 GNU/Linux


A DESCRIPTION OF THE PROBLEM :
Changing tabs is unusably slow (taking multiple seconds) on my Ultra 20 if i use the GTK+ LAF in Java 6. (other components are slow too, but this is the most noticeable and effectively prevents deeper testing.)

STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
java -jar SwingSet2.jar

click back and forth between the "internal frames demo" and "source code" tabs until it reaches a decent speed with the default (metal) LAF. then change to the GTK+ LAF, and see that no matter how long you keep clicking between them, it doesn't approach an acceptable speed.

EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
i should be able to change tabs in less than 100ms.
ACTUAL -
often changing tabs takes > 4s! on an idle machine! (and only with the GTK+ LAF in 6.0.)

ERROR MESSAGES/STACK TRACES THAT OCCUR :
running an editor (http://software.jessies.org/edit/) with built-in EDT hang detection (see source below for just the EDT hang detector), the sample output when i just click between the various tabs over and over is attached seperatly.

REPRODUCIBILITY :
This bug can be reproduced always.

---------- BEGIN SOURCE ----------
package e.debug;

import e.util.Log;
import java.awt.*;
import java.awt.event.*;
import java.io.*;
import java.lang.management.*;
import java.util.*;

/**
 * Monitors the AWT event dispatch thread for events that take longer than
 * a certain time to be dispatched.
 *
 * The principle is to record the time at which we start processing an event,
 * and have another thread check frequently to see if we're still processing.
 * If the other thread notices that we've been processing a single event for
 * too long, it prints a stack trace showing what the event dispatch thread
 * is doing, and continues to time it until it finally finishes.
 *
 * This is useful in determining what code is causing your Java application's
 * GUI to be unresponsive.
 *
 * @author Elliott Hughes <###@###.###>
 */
public final class EventDispatchThreadHangMonitor extends EventQueue {
    private static final EventQueue INSTANCE = new EventDispatchThreadHangMonitor();
    
    // Time to wait between checks that the event dispatch thread isn't hung.
    private static final long CHECK_INTERVAL_MS = 100;
    
    // Maximum time we won't warn about. This used to be 500 ms, but 1.5 on
    // late-2004 hardware isn't really up to it; there are too many parts of
    // the JDK that can go away for that long (often code that has to be
    // called on the event dispatch thread, like font loading).
    private static final long UNREASONABLE_DISPATCH_DURATION_MS = 1000;
    
    // Used as the value of startedLastEventDispatchAt when we're not in
    // the middle of event dispatch.
    private static final long NO_CURRENT_EVENT = 0;
    
    // When we started dispatching the current event, in milliseconds.
    private long startedLastEventDispatchAt = NO_CURRENT_EVENT;
    
    // Have we already dumped a stack trace for the current event dispatch?
    private boolean reportedHang = false;
    
    // Help distinguish multiple hangs in the log, and match start and end too.
    private int hangCount = 0;
    
    // The event dispatch thread, for the purpose of getting stack traces.
    private Thread eventDispatchThread = null;
    
    private EventDispatchThreadHangMonitor() {
        initTimer();
    }
    
    /**
     * Sets up a timer to check for hangs frequently.
     */
    private void initTimer() {
        final long initialDelayMs = 0;
        final boolean isDaemon = true;
        Timer timer = new Timer("EventDispatchThreadHangMonitor", isDaemon);
        timer.schedule(new HangChecker(), initialDelayMs, CHECK_INTERVAL_MS);
    }
    
    private class HangChecker extends TimerTask {
        @Override
        public void run() {
            // Synchronize on the outer class, because that's where all
            // the state lives.
            synchronized (INSTANCE) {
                checkForHang();
            }
        }
        
        private void checkForHang() {
            if (startedLastEventDispatchAt == NO_CURRENT_EVENT) {
                // We don't destroy the timer when there's nothing happening
                // because it would mean a lot more work on every single AWT
                // event that gets dispatched.
                return;
            }
            if (timeSoFar() > UNREASONABLE_DISPATCH_DURATION_MS) {
                reportHang();
            }
        }
        
        private void reportHang() {
            if (reportedHang) {
                // Don't keep reporting the same hang every 100 ms.
                return;
            }
            
            reportedHang = true;
            String stackTrace = stackTraceToString(eventDispatchThread.getStackTrace());
            Log.warn("(hang #" + ++hangCount + ") event dispatch thread stuck processing event for " +  timeSoFar() + " ms:" + stackTrace);
            checkForDeadlock();
        }
        
        private void checkForDeadlock() {
            ThreadMXBean threadBean = ManagementFactory.getThreadMXBean();
            long[] threadIds = threadBean.findMonitorDeadlockedThreads();
            if (threadIds == null) {
                return;
            }
            Log.warn("deadlock detected involving the following threads:");
            ThreadInfo[] threadInfos = threadBean.getThreadInfo(threadIds, Integer.MAX_VALUE);
            for (ThreadInfo info : threadInfos) {
                Log.warn("Thread #" + info.getThreadId() + " " + info.getThreadName() + " (" + info.getThreadState() + ") waiting on " + info.getLockName() + " held by " + info.getLockOwnerName() + stackTraceToString(info.getStackTrace()));
            }
        }
        
        private String stackTraceToString(StackTraceElement[] stackTrace) {
            StringBuilder result = new StringBuilder();
            // We know that it's not interesting to show any code above where
            // we get involved in event dispatch, so we stop printing the stack
            // trace when we get as far back as our code.
            final String ourEventQueueClassName = EventDispatchThreadHangMonitor.class.getName();
            for (StackTraceElement stackTraceElement : stackTrace) {
                if (stackTraceElement.getClassName().equals(ourEventQueueClassName)) {
                    break;
                }
                result.append("\n    " + stackTraceElement);
            }
            return result.toString();
        }
    }
    
    /**
     * Returns how long we've been processing the current event (in
     * milliseconds).
     */
    private long timeSoFar() {
        long currentTime = System.currentTimeMillis();
        return (currentTime - startedLastEventDispatchAt);
    }
    
    /**
     * Sets up hang detection for the event dispatch thread.
     */
    public static void initMonitoring() {
        Toolkit.getDefaultToolkit().getSystemEventQueue().push(INSTANCE);
    }
    
    /**
     * Overrides EventQueue.dispatchEvent to call our pre and post hooks either
     * side of the system's event dispatch code.
     */
    @Override
    protected void dispatchEvent(AWTEvent event) {
        preDispatchEvent();
        super.dispatchEvent(event);
        postDispatchEvent();
    }
    
    /**
     * Stores the time at which we started processing the current event.
     */
    private synchronized void preDispatchEvent() {
        if (eventDispatchThread == null) {
            // I don't know of any API for getting the event dispatch thread,
            // but we can assume that it's the current thread if we're in the
            // middle of dispatching an AWT event...
            eventDispatchThread = Thread.currentThread();
        }
        
        reportedHang = false;
        startedLastEventDispatchAt = System.currentTimeMillis();
    }
    
    /**
     * Reports the end of any ongoing hang, and notes that we're no longer
     * processing an event.
     */
    private synchronized void postDispatchEvent() {
        if (reportedHang) {
            Log.warn("(hang #" + hangCount + ") event dispatch thread unstuck after " + timeSoFar() + " ms.");
        }
        startedLastEventDispatchAt = NO_CURRENT_EVENT;
    }
}

---------- END SOURCE ----------

CUSTOMER SUBMITTED WORKAROUND :
don't use the GTK+ LAF, or don't use Java 6.

Comments
EVALUATION GTKCachingPainter was removed completely as part of 6361745.
08-06-2006

EVALUATION We're working on bug 6361745: Mustang: Improve the image caching mechanism used by GTK L&F. The fix will likely eliminate GTKCachingPainter completely.
16-02-2006