JDK-8019496 : [macosx] -XstartOnFirstThread broken for multithreaded apps on Mac OS X (6_51 and 7_25)
  • Type: Bug
  • Component: client-libs
  • Sub-Component: java.awt
  • Affected Version: 7u25
  • Priority: P3
  • Status: Closed
  • Resolution: Not an Issue
  • OS: os_x
  • Submitted: 2013-07-01
  • Updated: 2013-08-21
  • Resolved: 2013-08-21
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 8
8Resolved
Related Reports
Relates :  
Description
FULL PRODUCT VERSION :
java version  " 1.7.0_25 " 
Java(TM) SE Runtime Environment (build 1.7.0_25-b15)
Java HotSpot(TM) 64-Bit Server VM (build 23.25-b01, mixed mode)

java version  " 1.6.0_51 " 
Java(TM) SE Runtime Environment (build 1.6.0_51-b11-457-11M4509)
Java HotSpot(TM) 64-Bit Server VM (build 20.51-b01-457, mixed mode)

ADDITIONAL OS VERSION INFORMATION :
Apple Mac OS X 10.8.4 12.4.0 Darwin Kernel Version 12.4.0: Wed May  1 17:57:12 PDT 2013; root:xnu-2050.24.15~1/RELEASE_X86_64 x86_64

EXTRA RELEVANT SYSTEM CONFIGURATION :
This occurs with the official Oracle 1.7 JVM as well as the corresponding Apple Java VM both with and without the hotfix detailed in http://support.apple.com/kb/DL1572

A DESCRIPTION OF THE PROBLEM :
When running an application which requires SWT and is multithreaded there is a good chance that application will fail to start and hang upon loading the AWT jni libraries (actually in our own apps it's 100%, but it depends on what exactly the program uses of the java se api). The issue is that for some reason the security fixes in 1.7.0_25 seem to trigger AWT initialisation from previously perfectly safe and to the user transparent locations such as creating a java.util.logger or registring an MBean. Everywhere the AppContext is touched this now happens. Unfortunately this isn't allowed on Mac OS X due to how the event system works. This is different bug than what caused Apple to roll out a hotfix for their 1.6.0_51 release because most swing apps didn't work anymore.

This only happens when -XstartOnFirstThread is given as JVM parameter but that one is absolutely necessary for all SWT applications.





STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
Run the included test code as a normal java application, no special security settings, no webstart, no applet, just normal.

Without JVM arguments : runs fine as you would expect
With -XstartOnFirstThread : hangs
With -XstartOnFirstThread and -Djava.awt.headless=true : runs fine


EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
Applications start up normally
ACTUAL -
All those applications just hang. They hang on loading the JNI AWT libs (just like the behavior was before -XstartOnFirstThread was introduced years ago). The hang can be triggered by places not using anything from AWT at all. It's very fishy that util.logging, jmx and others which are clearly tool locations trigger code in AWT.

ERROR MESSAGES/STACK TRACES THAT OCCUR :
None, complete hang Stack traces of applications also exhibiting this. These threads are marked runnable but will never leave the method they are in.  One shows an app locking up in JMX, the other one from an app locking up in ImageIO.

 " Thread-4 "  daemon prio=5 tid=7febb49ae800 nid=0x10f2fb000 runnable [10f2f6000]
   java.lang.Thread.State: RUNNABLE
at java.lang.ClassLoader$NativeLibrary.load(Native Method)
at java.lang.ClassLoader.loadLibrary0(ClassLoader.java:1827)
- locked <7dc02aec0> (a java.util.Vector)
- locked <7dc02aee0> (a java.util.Vector)
at java.lang.ClassLoader.loadLibrary(ClassLoader.java:1724)
at java.lang.Runtime.loadLibrary0(Runtime.java:823)
- locked <7dc02cb28> (a java.lang.Runtime)
at java.lang.System.loadLibrary(System.java:1045)
at sun.security.action.LoadLibraryAction.run(LoadLibraryAction.java:50)
at java.security.AccessController.doPrivileged(Native Method)
at java.awt.Toolkit.loadLibraries(Toolkit.java:1605)
at java.awt.Toolkit.<clinit>(Toolkit.java:1627)
at sun.awt.AppContext$2.run(AppContext.java:240)
at sun.awt.AppContext$2.run(AppContext.java:226)
at java.security.AccessController.doPrivileged(Native Method)
at sun.awt.AppContext.initMainAppContext(AppContext.java:226)
at sun.awt.AppContext.access$200(AppContext.java:112)
at sun.awt.AppContext$3.run(AppContext.java:306)
at java.security.AccessController.doPrivileged(Native Method)
at sun.awt.AppContext.getAppContext(AppContext.java:287)
at com.sun.jmx.trace.Trace.out(Trace.java:180)
- locked <7f8eea490> (a java.lang.Class for com.sun.jmx.trace.Trace)
at com.sun.jmx.trace.Trace.isSelected(Trace.java:88)
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.isTraceOn(DefaultMBeanServerInterceptor.java:1830)
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:929)
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:916)
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:312)
at com.sun.jmx.mbeanserver.JmxMBeanServer$2.run(JmxMBeanServer.java:1195)
at java.security.AccessController.doPrivileged(Native Method)
at com.sun.jmx.mbeanserver.JmxMBeanServer.initialize(JmxMBeanServer.java:1193)
at com.sun.jmx.mbeanserver.JmxMBeanServer.<init>(JmxMBeanServer.java:225)
at com.sun.jmx.mbeanserver.JmxMBeanServer.<init>(JmxMBeanServer.java:170)
at com.sun.jmx.mbeanserver.JmxMBeanServer.newMBeanServer(JmxMBeanServer.java:1401)
at javax.management.MBeanServerBuilder.newMBeanServer(MBeanServerBuilder.java:93)
at javax.management.MBeanServerFactory.newMBeanServer(MBeanServerFactory.java:311)
- locked <7d824f618> (a javax.management.MBeanServerBuilder)
at javax.management.MBeanServerFactory.createMBeanServer(MBeanServerFactory.java:214)
at javax.management.MBeanServerFactory.createMBeanServer(MBeanServerFactory.java:175)
at sun.management.ManagementFactory.createPlatformMBeanServer(ManagementFactory.java:302)
at java.lang.management.ManagementFactory.getPlatformMBeanServer(ManagementFactory.java:504)
- locked <7f8e00140> (a java.lang.Class for java.lang.management.ManagementFactory)
at id.core.version.provider.ProductVersionProvider.<init>(ProductVersionProvider.java:68)
at id.core.version.provider.ProductVersionProvider.getInstance(ProductVersionProvider.java:37)
- locked <7f8dd00a8> (a java.lang.Class for id.core.version.provider.ProductVersionProvider)
at id.core.version.VersionInfo.getProductID(VersionInfo.java:98)
at com.id.core.platform.util.application.ProductDirectories.calculateCurrentUserProgramDir(ProductDirectories.java:31)
at com.id.core.platform.util.application.ProductDirectories.<clinit>(ProductDirectories.java:22)
at com.id.core.platform.repository.BundleRepository.parsePluginFile(BundleRepository.java:235)
at com.id.core.platform.repository.BundleRepository.<init>(BundleRepository.java:101)
at com.id.core.platform.Platform.bootstrap(Platform.java:178)
- locked <7d81cb4c8> (a java.lang.Object)
- locked <7d81cb4a8> (a com.id.core.platform.Platform)
at com.id.core.platform.activator.Activator$1.run(Activator.java:77)
- locked <7d81aca68> (a java.lang.Object)


 " Thread-2 "  prio=5 tid=0x00007f9973093800 nid=0x7e03 runnable [0x0000000137b2f000]
   java.lang.Thread.State: RUNNABLE
at java.lang.ClassLoader$NativeLibrary.load(Native Method)
at java.lang.ClassLoader.loadLibrary1(ClassLoader.java:1957)
- locked <0x0000000128bc39a8> (a java.util.Vector)
- locked <0x0000000128bc3610> (a java.util.Vector)
at java.lang.ClassLoader.loadLibrary0(ClassLoader.java:1882)
at java.lang.ClassLoader.loadLibrary(ClassLoader.java:1843)
at java.lang.Runtime.load0(Runtime.java:795)
- locked <0x0000000110a457a8> (a java.lang.Runtime)
at java.lang.System.load(System.java:1061)
at java.lang.ClassLoader$NativeLibrary.load(Native Method)
at java.lang.ClassLoader.loadLibrary1(ClassLoader.java:1957)
- locked <0x0000000128bc39a8> (a java.util.Vector)
- locked <0x0000000128bc3610> (a java.util.Vector)
at java.lang.ClassLoader.loadLibrary0(ClassLoader.java:1882)
at java.lang.ClassLoader.loadLibrary(ClassLoader.java:1864)
at java.lang.Runtime.loadLibrary0(Runtime.java:849)
- locked <0x0000000110a457a8> (a java.lang.Runtime)
at java.lang.System.loadLibrary(System.java:1087)
at sun.security.action.LoadLibraryAction.run(LoadLibraryAction.java:67)
at sun.security.action.LoadLibraryAction.run(LoadLibraryAction.java:47)
at java.security.AccessController.doPrivileged(Native Method)
at java.awt.Toolkit.loadLibraries(Toolkit.java:1646)
at java.awt.Toolkit.<clinit>(Toolkit.java:1668)
at sun.awt.AppContext$2.run(AppContext.java:271)
at sun.awt.AppContext$2.run(AppContext.java:260)
at java.security.AccessController.doPrivileged(Native Method)
at sun.awt.AppContext.initMainAppContext(AppContext.java:260)
at sun.awt.AppContext.access$200(AppContext.java:133)
at sun.awt.AppContext$3.run(AppContext.java:316)
at sun.awt.AppContext$3.run(AppContext.java:298)
at java.security.AccessController.doPrivileged(Native Method)
at sun.awt.AppContext.getAppContext(AppContext.java:297)
at javax.imageio.spi.IIORegistry.getDefaultInstance(IIORegistry.java:154)
at com.id.external.javax.media.jai.Services.register(Services.java:20)
at com.id.external.javax.media.jai.activator.Activator.start(Activator.java:26)
at org.eclipse.osgi.framework.internal.core.BundleContextImpl$1.run(BundleContextImpl.java:711)
at java.security.AccessController.doPrivileged(Native Method)
at org.eclipse.osgi.framework.internal.core.BundleContextImpl.startActivator(BundleContextImpl.java:702)
at org.eclipse.osgi.framework.internal.core.BundleContextImpl.start(BundleContextImpl.java:683)
at org.eclipse.osgi.framework.internal.core.BundleHost.startWorker(BundleHost.java:381)
at org.eclipse.osgi.framework.internal.core.AbstractBundle.start(AbstractBundle.java:299)
at org.eclipse.osgi.framework.internal.core.AbstractBundle.start(AbstractBundle.java:291)
at com.id.core.platform.repository.BundleRepository.startBundle(BundleRepository.java:486)
at com.id.core.platform.repository.BundleRepository.handleResolvedBundle(BundleRepository.java:389)
at com.id.core.platform.repository.BundleRepository.scanBundles(BundleRepository.java:269)
at com.id.core.platform.repository.BundleRepository.start(BundleRepository.java:118)
- locked <0x00000001259d7d20> (a java.lang.Object)
at com.id.core.platform.Platform.bootstrap(Platform.java:184)
- locked <0x00000001259d4000> (a java.lang.Object)
- locked <0x00000001259d3fe0> (a com.id.core.platform.Platform)
at com.id.core.platform.activator.Activator$1.run(Activator.java:77)
- locked <0x00000001259ce758> (a java.lang.Object)

REPRODUCIBILITY :
This bug can be reproduced always.

---------- BEGIN SOURCE ----------
import java.lang.management.ManagementFactory;
import java.util.logging.Logger;

import javax.imageio.spi.IIORegistry;
import javax.management.MBeanServer;

/**
 * @author evanherc
 */
public class AppContextJVMBug {

public static void main(String[] args) {
try {
System.out.println( " Launching " );

final Thread t = new Thread(new Runnable() {
public void run() {
try {
utilLoggingHang();
jmxHang();
imageioHang();
} catch (Throwable t) {
t.printStackTrace();
}
}
});

t.start();
t.join();
System.out.println( " Finished " );
} catch (Throwable t) {
t.printStackTrace();
}
}

private static void utilLoggingHang() {
final Logger l = Logger.getLogger( " MyApp " );
System.out.println( " Done obtaining a logger  "  + l);
}

private static void jmxHang() {
final MBeanServer mb = ManagementFactory.getPlatformMBeanServer();
System.out.println( " Done getting the platform mbean server  "  + mb);
}

private static void imageioHang() {
final IIORegistry registry = IIORegistry.getDefaultInstance();
System.out.println( " Done retrieving image registry  "  + registry);
}
}

---------- END SOURCE ----------
Comments
Synchronization issues will be addressed in JDK-8019623.
21-08-2013

Yes, there are synchronization issues for sure. Right now, I'm discussing with Tema should we fix them under this bug or file a new one.
02-07-2013

Now I am a bit concerned about my evaluation. Have you noticed, that the main AppContext is initialized from 2 thread simultaneously? The AppContext.getAppContext provides an unsynchronized access to the lazy-initialized value and it's certainly not thread safe. Might it also be an issue?
02-07-2013

Expanding on Petr's correct, but somewhat terse, evaluation. AppContext is a part of AWT, so anything that touches AppContext triggers loading of the AWT libraries. On OS X, specifying -XstartOnFirstThread, has an effect that the AWT loader waits (on a conditional variable) until someone (supposedly SWT) starts the run loop. This is the hung the bug is concerned about. So, in order to fix this issue, jmx and IIORegistry should stop using AppContext. As a workaround, if one have to use - XstartOnFirstThread on OS X fror purposes other than SWT embedding, specify -Djava.awt.headless=true option. This will prevent the AWT loader from waiting for the run loop to start.
02-07-2013

This is an AppContext-related issue, hence assigning to Leonid for further evaluation.
02-07-2013

I would say that the problem is not with the -XstartOnFirstThread implementation, because AWT does was it is supposed to do: in case -XstartOnFirstThread is specified, the AWT loader supposes that it is working in the embedded mode and does not start it's own runLoop, waiting for SWT to start it. This is the correct behavior. The problem here is that AWT is being loaded at all.
02-07-2013