This Bugzilla instance is a read-only archive of historic NetBeans bug reports. To report a bug in NetBeans please follow the project's instructions for reporting issues.
Happens every time now. The IDE does not start at all: 2014-03-24 11:59:25 Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.51-b03 mixed mode): "Attach Listener" daemon prio=10 tid=0x00007f4d9c001000 nid=0x56b8 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Inactive RequestProcessor thread [Was:TimedSoftReference/org.openide.util.TimedSoftReference]" daemon prio=10 tid=0x00007f4d80003000 nid=0x5693 in Object.wait() [0x00007f4dbc7f8000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000eb572330> (a java.lang.Object) at org.openide.util.RequestProcessor$Processor.run(RequestProcessor.java:1978) - locked <0x00000000eb572330> (a java.lang.Object) "Logging Flush" daemon prio=10 tid=0x00007f4d80001000 nid=0x566b waiting for monitor entry [0x00007f4d6bd7f000] java.lang.Thread.State: BLOCKED (on object monitor) at org.netbeans.core.startup.logging.NbFormatter.print(NbFormatter.java:106) at org.netbeans.core.startup.logging.NbFormatter.format(NbFormatter.java:68) at java.util.logging.StreamHandler.publish(StreamHandler.java:196) - locked <0x00000000c0660a58> (a java.util.logging.StreamHandler) at org.netbeans.core.startup.logging.DispatchingHandler.run(DispatchingHandler.java:175) at org.openide.util.RequestProcessor$Task.run(RequestProcessor.java:1423) at org.openide.util.RequestProcessor$Processor.run(RequestProcessor.java:2033) "AWT-XAWT" daemon prio=10 tid=0x00007f4d7c07d800 nid=0x5668 runnable [0x00007f4dbcbfa000] java.lang.Thread.State: RUNNABLE at sun.awt.X11.XToolkit.waitForEvents(Native Method) at sun.awt.X11.XToolkit.run(XToolkit.java:627) at sun.awt.X11.XToolkit.run(XToolkit.java:591) at java.lang.Thread.run(Thread.java:744) "Java2D Disposer" daemon prio=10 tid=0x00007f4d7c053000 nid=0x5667 in Object.wait() [0x00007f4dbcdfb000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000c07bfb30> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135) - locked <0x00000000c07bfb30> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151) at sun.java2d.Disposer.run(Disposer.java:145) at java.lang.Thread.run(Thread.java:744) "main" prio=10 tid=0x00007f4dc8397000 nid=0x5665 in Object.wait() [0x00007f4dbd1f9000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000eb349508> (a org.openide.util.RequestProcessor$Task) at java.lang.Object.wait(Object.java:503) at org.openide.util.Task.waitFinished(Task.java:135) - locked <0x00000000eb349508> (a org.openide.util.RequestProcessor$Task) at org.openide.util.RequestProcessor$Task.waitFinished(RequestProcessor.java:1677) at org.netbeans.core.startup.preferences.NbPreferences.sync(NbPreferences.java:320) at org.netbeans.modules.uihandler.Installer.<clinit>(Installer.java:199) at org.netbeans.modules.uihandler.EarlyHandler.publish(EarlyHandler.java:70) at org.netbeans.core.startup.TopLogging$LookupDel.publish(TopLogging.java:453) at java.util.logging.Logger.log(Logger.java:610) at java.util.logging.Logger.doLog(Logger.java:631) at java.util.logging.Logger.log(Logger.java:720) at org.netbeans.JarClassLoader$JarSource.opened(JarClassLoader.java:791) - locked <0x00000000c04151b0> (a java.util.HashMap) at org.netbeans.JarClassLoader$JarSource$1.call(JarClassLoader.java:529) at org.netbeans.JarClassLoader$JarSource$1.call(JarClassLoader.java:515) at java.util.concurrent.FutureTask.run(FutureTask.java:262) at org.netbeans.JarClassLoader$JarSource.getJarFile(JarClassLoader.java:550) at org.netbeans.JarClassLoader$JarSource.resource(JarClassLoader.java:591) at org.netbeans.Archive.getData(Archive.java:212) at org.netbeans.JarClassLoader$JarSource.readClass(JarClassLoader.java:577) at org.netbeans.JarClassLoader$Source.getClassData(JarClassLoader.java:374) at org.netbeans.JarClassLoader.doLoadClass(JarClassLoader.java:221) at org.netbeans.ProxyClassLoader.selfLoadClass(ProxyClassLoader.java:259) - locked <0x00000000f41f3e50> (a org.netbeans.StandardModule$OneModuleClassLoader) at org.netbeans.ProxyClassLoader.loadClass(ProxyClassLoader.java:187) - locked <0x00000000f41f3ad8> (a org.netbeans.StandardModule$OneModuleClassLoader) at java.lang.ClassLoader.loadClass(ClassLoader.java:358) at java.lang.Class.getDeclaredConstructors0(Native Method) at java.lang.Class.privateGetDeclaredConstructors(Class.java:2493) at java.lang.Class.getConstructor0(Class.java:2803) at java.lang.Class.newInstance(Class.java:345) at org.openide.util.lookup.implspi.SharedClassObjectBridge.newInstance(SharedClassObjectBridge.java:64) at org.openide.util.lookup.MetaInfServicesLookup$P.getInstance(MetaInfServicesLookup.java:509) - locked <0x00000000eb2c31b8> (a java.lang.Class for org.netbeans.core.netigso.Netigso) at org.openide.util.lookup.AbstractLookup.lookup(AbstractLookup.java:422) at org.netbeans.NetigsoHandle.getDefault(NetigsoHandle.java:78) - locked <0x00000000eb19b5c0> (a java.lang.Class for org.netbeans.NetigsoFramework) at org.netbeans.NetigsoHandle.turnOn(NetigsoHandle.java:127) at org.netbeans.ModuleManager.enable(ModuleManager.java:1182) at org.netbeans.ModuleManager.enable(ModuleManager.java:1017) at org.netbeans.core.startup.ModuleList.installNew(ModuleList.java:340) at org.netbeans.core.startup.ModuleList.trigger(ModuleList.java:276) at org.netbeans.core.startup.ModuleSystem.restore(ModuleSystem.java:301) at org.netbeans.core.startup.Main.getModuleSystem(Main.java:181) at org.netbeans.core.startup.Main.getModuleSystem(Main.java:150) at org.netbeans.core.startup.Main.start(Main.java:307) at org.netbeans.core.startup.TopThreadGroup.run(TopThreadGroup.java:123) at java.lang.Thread.run(Thread.java:744) "OpenIDE-request-processor-1" daemon prio=10 tid=0x00007f4dc838b000 nid=0x5664 waiting for monitor entry [0x00007f4dbd3fd000] java.lang.Thread.State: BLOCKED (on object monitor) at org.netbeans.JarClassLoader$JarSource.getJarFile(JarClassLoader.java:510) - waiting to lock <0x00000000c04151b0> (a java.util.HashMap) at org.netbeans.JarClassLoader$JarSource.resource(JarClassLoader.java:591) at org.netbeans.Archive.getData(Archive.java:212) at org.netbeans.JarClassLoader$JarSource.readClass(JarClassLoader.java:577) at org.netbeans.JarClassLoader$Source.getClassData(JarClassLoader.java:374) at org.netbeans.JarClassLoader.doLoadClass(JarClassLoader.java:221) at org.netbeans.ProxyClassLoader.selfLoadClass(ProxyClassLoader.java:259) - locked <0x00000000c08a2700> (a org.netbeans.MainImpl$BootClassLoader) at org.netbeans.ProxyClassLoader.loadClass(ProxyClassLoader.java:187) - locked <0x00000000c08a2700> (a org.netbeans.MainImpl$BootClassLoader) at java.lang.ClassLoader.loadClass(ClassLoader.java:358) at org.netbeans.core.startup.preferences.NbPreferences$1.run(NbPreferences.java:81) at org.openide.util.RequestProcessor$Task.run(RequestProcessor.java:1423) at org.openide.util.RequestProcessor$Processor.run(RequestProcessor.java:2033) "CLI Requests Server" daemon prio=10 tid=0x00007f4dc8378800 nid=0x5663 runnable [0x00007f4dc4be6000] java.lang.Thread.State: RUNNABLE at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398) at java.net.ServerSocket.implAccept(ServerSocket.java:530) at java.net.ServerSocket.accept(ServerSocket.java:498) at org.netbeans.CLIHandler$Server.run(CLIHandler.java:1100) "Active Reference Queue Daemon" daemon prio=10 tid=0x00007f4dc8355800 nid=0x5662 in Object.wait() [0x00007f4dc4de7000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000c08a1690> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135) - locked <0x00000000c08a1690> (a java.lang.ref.ReferenceQueue$Lock) at org.openide.util.lookup.implspi.ActiveQueue$Daemon.run(ActiveQueue.java:178) - locked <0x00000000c08a1690> (a java.lang.ref.ReferenceQueue$Lock) "Service Thread" daemon prio=10 tid=0x00007f4dc8278000 nid=0x5660 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread1" daemon prio=10 tid=0x00007f4dc8275800 nid=0x565f waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread0" daemon prio=10 tid=0x00007f4dc8272800 nid=0x565e waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Signal Dispatcher" daemon prio=10 tid=0x00007f4dc8268800 nid=0x565d runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Finalizer" daemon prio=10 tid=0x00007f4dc8252800 nid=0x565c in Object.wait() [0x00007f4dcccad000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000c01a54d8> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135) - locked <0x00000000c01a54d8> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:189) "Reference Handler" daemon prio=10 tid=0x00007f4dc824e800 nid=0x565b in Object.wait() [0x00007f4dcceae000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000c03bca78> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:503) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133) - locked <0x00000000c03bca78> (a java.lang.ref.Reference$Lock) "main" prio=10 tid=0x00007f4dc800b800 nid=0x5655 in Object.wait() [0x00007f4dd452c000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000c0614db8> (a org.netbeans.core.startup.TopThreadGroup) at java.lang.Object.wait(Object.java:503) at org.netbeans.core.startup.TopThreadGroup.start(TopThreadGroup.java:116) - locked <0x00000000c0614db8> (a org.netbeans.core.startup.TopThreadGroup) at org.netbeans.core.startup.Main.main(Main.java:98) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.netbeans.MainImpl.main(MainImpl.java:97) at org.netbeans.Main.main(Main.java:78) "VM Thread" prio=10 tid=0x00007f4dc824c000 nid=0x565a runnable "GC task thread#0 (ParallelGC)" prio=10 tid=0x00007f4dc8021800 nid=0x5656 runnable "GC task thread#1 (ParallelGC)" prio=10 tid=0x00007f4dc8023000 nid=0x5657 runnable "GC task thread#2 (ParallelGC)" prio=10 tid=0x00007f4dc8025000 nid=0x5658 runnable "GC task thread#3 (ParallelGC)" prio=10 tid=0x00007f4dc8027000 nid=0x5659 runnable "VM Periodic Task Thread" prio=10 tid=0x00007f4dc828a800 nid=0x5661 waiting on condition JNI global references: 284
Created attachment 146495 [details] Defering access to NbPreferences until the classloading is over Looks like the simplest fix is to delay prefs.sync() a bit. I think restored() is a good place, it is called on every initialization and hopefully soon enough. Please consider applying my patch.
...and ignore the jsbreakpoint related part of the fix.
This locks up in class loaders. We log a message during class loading and the log handler initialization waits for another class loading. I do not see a different fix, than change EarlyHandler to work asynchronously. Store the records in some queue, initialize Installer in a separate thread and then switch to the UI logger.
I've applied a hotfix, that should solve this particular issue. changeset: 273533:6d332776e3cc http://hg.netbeans.org/core-main/rev/6d332776e3cc But an asynchronous EarlyHandler might be necessary as well...
Integrated into 'main-silver', will be available in build *201404060001* on http://bits.netbeans.org/dev/nightly/ (upload may still be in progress) Changeset: http://hg.netbeans.org/main-silver/rev/6d332776e3cc User: mentlicher@netbeans.org Log: #243208: Do not access Installer class when we do not have to.
Blocked issue is P1. Making P1 and requesting integration into 8.0.
I did not reproduce this deadlock specifically, but the problem can be seen by starting NetBeans with -J-Dorg.netbeans.JarClassLoader.level=100 option. With the original code it crashes with java.lang.NullPointerException at java.lang.String.startsWith(String.java:1392) at java.lang.String.startsWith(String.java:1421) at org.netbeans.modules.uihandler.EarlyHandler.publish(EarlyHandler.java:79) at org.netbeans.core.startup.TopLogging$LookupDel.publish(TopLogging.java:453) at java.util.logging.Logger.log(Logger.java:731) at java.util.logging.Logger.doLog(Logger.java:754) at java.util.logging.Logger.log(Logger.java:839) at org.netbeans.JarClassLoader$JarSource.resource(JarClassLoader.java:606) at org.netbeans.Archive.getData(Archive.java:212) at org.netbeans.JarClassLoader$JarSource.readClass(JarClassLoader.java:577) at org.netbeans.JarClassLoader$Source.getClassData(JarClassLoader.java:374) at org.netbeans.JarClassLoader.doLoadClass(JarClassLoader.java:221) at org.netbeans.ProxyClassLoader.selfLoadClass(ProxyClassLoader.java:259) at org.netbeans.ProxyClassLoader.loadClass(ProxyClassLoader.java:187) at java.lang.ClassLoader.loadClass(ClassLoader.java:357) at org.netbeans.modules.uihandler.UIHandler.<clinit>(UIHandler.java:77) Caused: java.lang.ExceptionInInitializerError at org.netbeans.modules.uihandler.Installer.<clinit>(Installer.java:127) at org.netbeans.modules.uihandler.EarlyHandler.publish(EarlyHandler.java:79) at org.netbeans.core.startup.TopLogging$LookupDel.publish(TopLogging.java:453) With the "hotfix" it blocks and does not start up at all. An asynchronous handling of log records is probably the only way to go.
Fixed by changeset: 273906:63e55b1cb765 http://hg.netbeans.org/core-main/rev/63e55b1cb765 A test included.
Although it does not have much impact on functionality, this is likely worth to include as well, for consistency: changeset: 273928:23331fbb2009 http://hg.netbeans.org/core-main/rev/23331fbb2009
The fix has revealed a race-condition in class loading: issue #243945.
Integrated into 'main-silver', will be available in build *201404210001* on http://bits.netbeans.org/dev/nightly/ (upload may still be in progress) Changeset: http://hg.netbeans.org/main-silver/rev/63e55b1cb765 User: mentlicher@netbeans.org Log: #243208: EarlyHandler initializes and restores Installer asynchronously in order not to block records publishing.
Since the fix can be dangerous and has revealed issue #243945, I'm removing patch candidate.