Closed Bug 717986 Opened 12 years ago Closed 7 years ago

Deadlock when the test for bug 579079 attempts to load the Java plugin

Categories

(Core Graveyard :: Plug-ins, defect)

x86
macOS
defect
Not set
normal

Tracking

(Not tracked)

RESOLVED WONTFIX

People

(Reporter: ehsan.akhgari, Unassigned)

References

()

Details

Attachments

(3 files)

Attached file Full backtrace
I can reproduce this when running test_bug579079.html 100% of the time.  My java plugin version is 13.6.0.

I'm attaching a full backtrace of all of the threads.
What version of OS X does this happen on?

> My java plugin version is 13.6.0.

This information (by itself) isn't particularly meaningful.  What we
really need to know is which of Apple's Java updates you've installed,
and whether you've installed the latest one.  You should be able to
check by looking at Software Update : Installed Software.

If you're running OS X 10.6.8 (which I'd guess you are), Apple's
latest Java update is "Java for Mac OS X 10.6 Update 6".

The next time you hang, please also provide following (in addition to
the output of "thread apply all bt full"):

The output of "thread apply all bt" (I frankly find that easier to
read).

The output of "call (void) pss()".  This should print a Java stack
trace for all threads.

> I can reproduce this when running test_bug579079.html 100% of the time.

I assume most others can't ... or this would have been reported
before.
(In reply to Steven Michaud from comment #1)
> What version of OS X does this happen on?

10.6.8.

> > My java plugin version is 13.6.0.
> 
> This information (by itself) isn't particularly meaningful.  What we
> really need to know is which of Apple's Java updates you've installed,
> and whether you've installed the latest one.  You should be able to
> check by looking at Software Update : Installed Software.
> 
> If you're running OS X 10.6.8 (which I'd guess you are), Apple's
> latest Java update is "Java for Mac OS X 10.6 Update 6".

I have update 5.

> The next time you hang, please also provide following (in addition to
> the output of "thread apply all bt full"):
> 
> The output of "thread apply all bt" (I frankly find that easier to
> read).
> 
> The output of "call (void) pss()".  This should print a Java stack
> trace for all threads.

http://pastebin.mozilla.org/1448150

Note that I did not get a Java stack, which is not surprising as I don't think there's any Java code running at all.  This happen when loading the plugin.

> > I can reproduce this when running test_bug579079.html 100% of the time.
> 
> I assume most others can't ... or this would have been reported
> before.

Well, it depends on whether they run the particular set of tests.  I run mochitests pretty regularly, and this is the first time I'm seeing this.
The output of "call (void) pss()" might have gone elsewhere.  Try looking at what you can see from the Console app.

Java is definitely running -- all the threads with jio_snprintf in them are Java threads.  Note that the Java symbols are all spurious, since the JVM has its symbols stripped.

Please try again to find the output from pss().
I can't see any indication in your stack trace of a non-Java hang.

And note that the main thread is in Java code.  This is pretty clearly a Java hang.

So we really need the output of pss().
Oops, you're right.  Here's the output of pss():

"Executing pss"
2012-01-13 18:02:29
Full thread dump Java HotSpot(TM) 64-Bit Server VM (20.4-b02-402 mixed mode):

"JVM[id=1]-Heartbeat" prio=5 tid=152800000 nid=0x15142a000 in Object.wait() [151429000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <7f732b3d0> (a sun.plugin2.message.Queue)
	at sun.plugin2.message.Queue.waitForMessage(Queue.java:86)
	- locked <7f732b3d0> (a sun.plugin2.message.Queue)
	at sun.plugin2.message.Pipe.receive(Pipe.java:107)
	at sun.plugin2.main.server.HeartbeatThread.run(HeartbeatThread.java:104)

"JRE 1.6.0.29 Worker Thread" prio=5 tid=14d1d9000 nid=0x152307000 in Object.wait() [152306000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <7f7176c90> (a sun.plugin2.message.Queue)
	at sun.plugin2.message.Queue.waitForMessage(Queue.java:61)
	- locked <7f7176c90> (a sun.plugin2.message.Queue)
	at sun.plugin2.message.Pipe.receive(Pipe.java:93)
	at sun.plugin2.main.server.JVMInstance$WorkerThread.run(JVMInstance.java:584)

"JRE 1.6.0.29 Output Reader Thread" prio=5 tid=14d0f8000 nid=0x152204000 runnable [152203000]
   java.lang.Thread.State: RUNNABLE
	at java.io.FileInputStream.readBytes(Native Method)
	at java.io.FileInputStream.read(FileInputStream.java:198)
	at java.lang.UNIXProcess$DeferredCloseInputStream.read(UNIXProcess.java:218)
	at sun.plugin2.main.server.JVMInstance$StreamMonitor.run(JVMInstance.java:1511)
	at java.lang.Thread.run(Thread.java:680)

"JRE 1.6.0.29 Output Reader Thread" prio=5 tid=14d0f7800 nid=0x152101000 runnable [152100000]
   java.lang.Thread.State: RUNNABLE
	at java.io.FileInputStream.readBytes(Native Method)
	at java.io.FileInputStream.read(FileInputStream.java:220)
	at java.lang.UNIXProcess$DeferredCloseInputStream.read(UNIXProcess.java:227)
	at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
	at java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
	at java.io.BufferedInputStream.read(BufferedInputStream.java:317)
	- locked <7f717f110> (a java.io.BufferedInputStream)
	at java.io.FilterInputStream.read(FilterInputStream.java:90)
	at sun.plugin2.main.server.JVMInstance$StreamMonitor.run(JVMInstance.java:1511)
	at java.lang.Thread.run(Thread.java:680)

"Thread-3" prio=5 tid=14d0b6800 nid=0x151733000 in Object.wait() [151732000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <7f717cd00> (a java.lang.UNIXProcess)
	at java.lang.Object.wait(Object.java:485)
	at java.lang.UNIXProcess.waitFor(UNIXProcess.java:115)
	- locked <7f717cd00> (a java.lang.UNIXProcess)
	at sun.plugin2.jvm.JVMLauncher$JVMWatcher.run(JVMLauncher.java:302)
	at java.lang.Thread.run(Thread.java:680)

"process reaper" daemon prio=5 tid=14d143000 nid=0x151630000 runnable [15162f000]
   java.lang.Thread.State: RUNNABLE
	at java.lang.UNIXProcess.waitForProcessExit(Native Method)
	at java.lang.UNIXProcess.access$900(UNIXProcess.java:17)
	at java.lang.UNIXProcess$2$1.run(UNIXProcess.java:86)

"Java Plug-In Pipe Worker Thread (Server-Side)" daemon prio=5 tid=14c8a2800 nid=0x15152d000 runnable [15152c000]
   java.lang.Thread.State: RUNNABLE
	at com.sun.deploy.net.socket.UnixSocketImpl.unStreamSocketRead(Native Method)
	at com.sun.deploy.net.socket.UnixDomainSocket.read(UnixDomainSocket.java:449)
	at com.sun.deploy.net.socket.UnixDomainSocket.read(UnixDomainSocket.java:395)
	at sun.plugin2.ipc.unix.DomainSocketNamedPipe.read(DomainSocketNamedPipe.java:113)
	at sun.plugin2.message.transport.NamedPipeTransport$SerializerImpl.read(NamedPipeTransport.java:92)
	at sun.plugin2.message.transport.NamedPipeTransport$SerializerImpl.readByte(NamedPipeTransport.java:121)
	at sun.plugin2.message.AbstractSerializer.readInt(AbstractSerializer.java:162)
	at sun.plugin2.message.transport.SerializingTransport.read(SerializingTransport.java:97)
	at sun.plugin2.message.Pipe$WorkerThread.run(Pipe.java:209)

"Poller SunPKCS11-Darwin" daemon prio=1 tid=14c89b000 nid=0x151327000 waiting on condition [151326000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
	at java.lang.Thread.sleep(Native Method)
	at sun.security.pkcs11.SunPKCS11$TokenPoller.run(SunPKCS11.java:692)
	at java.lang.Thread.run(Thread.java:680)

"traceMsgQueueThread" daemon prio=5 tid=14c881800 nid=0x150f01000 in Object.wait() [150f00000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <7f6e829c8> (a java.util.ArrayList)
	at java.lang.Object.wait(Object.java:485)
	at com.sun.deploy.util.Trace$TraceMsgQueueChecker.run(Trace.java:78)
	- locked <7f6e829c8> (a java.util.ArrayList)
	at java.lang.Thread.run(Thread.java:680)

"Low Memory Detector" daemon prio=5 tid=14c001800 nid=0x150a05000 runnable [00000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" daemon prio=9 tid=14c001000 nid=0x150902000 waiting on condition [00000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=9 tid=14c84b800 nid=0x14bf8d000 waiting on condition [00000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=9 tid=14c84a800 nid=0x14be8a000 runnable [00000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=8 tid=14c846000 nid=0x14bd87000 in Object.wait() [14bd86000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <7f6e01300> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
	- locked <7f6e01300> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=14c845000 nid=0x14b9f5000 in Object.wait() [14b9f4000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <7f6e011d8> (a java.lang.ref.Reference$Lock)
	at java.lang.Object.wait(Object.java:485)
	at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
	- locked <7f6e011d8> (a java.lang.ref.Reference$Lock)

"AWT-AppKit" prio=8 tid=14c801000 nid=0x7fff7065ccc0 in Object.wait() [7fff5fbf5000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <7f7182d80> (a sun.plugin2.ipc.InProcEvent)
	at sun.plugin2.ipc.InProcEvent.waitForSignal(InProcEvent.java:27)
	- locked <7f7182d80> (a sun.plugin2.ipc.InProcEvent)
	at sun.plugin2.main.server.MozillaPlugin$UnixHandler.waitForSignal(MozillaPlugin.java:1168)
	at sun.plugin2.main.server.MozillaPlugin$UnixHandler.waitForSignal(MozillaPlugin.java:1164)
	at sun.plugin2.main.server.ResultHandler.waitForResult(ResultHandler.java:41)
	at sun.plugin2.main.server.AbstractPlugin.getScriptingObjectForApplet(AbstractPlugin.java:313)
	at sun.plugin2.main.server.MozillaPlugin.getScriptingObjectForApplet(MozillaPlugin.java:1023)

"VM Thread" prio=9 tid=14c840800 nid=0x14b8f2000 runnable

"VM Periodic Task Thread" prio=10 tid=14c013800 nid=0x150b08000 waiting on condition

"Exception Catcher Thread" prio=10 tid=14c801800 nid=0x14a6fb000 runnable
Thanks for the info!

But all I can say is that your hang seems to be a bug in the JVM :-(

Note all the instances of "WAITING (on object monitor)" from JVM code.  Note also that the browser seems to be stuck in the plugin's NPP_GetValue() trying to get the NPPVpluginScriptableNPObject.

It may be possible to work around this bug by fiddling with the timing of the browser's call to get the plugin's NPPVpluginScriptableNPObject.  But this'd only be worthwhile if a *lot* of people are effected by this bug.

The obvious thing to try is to upgrade to "Java for Mac OS X 10.6 Update 6".  But beware that if you do this you can't go back to the previous version (without doing a clean reinstall of Mac OS X, that is).

Did you have a reason not to upgrade?
By the way, the "AWT-AppKit" thread in the Java stack is the main thread.
(In reply to Steven Michaud from comment #6)
> Did you have a reason not to upgrade?

No.  That update was never offered to me.  Otherwise I'd have installed it.
> That update was never offered to me.

That's odd, and maybe a sign of something else wrong.

You don't see "Java for Mac OS X 10.6 Update 6" when you check for updates in Software Update?

I suspect, though, that you *have* installed Update 6.  Take another look at your list of "Installed Software" under Software Update.  Make sure you scroll it down :-)
Oh crap, this UI is confusing.  I thought that it would show the latest version, but it shows every installed version!  Indeed I do have update 6.  :/
I just noticed something odd in your C/C++ stack trace:  Your call to pss() from gdb is there on the main thread.

Please trigger another hang, then break in gdb and get the output of "thread apply all bt" and "call (void) pss()" in that order.  Then please attach them here (instead of pasting them into a comment).
And yet another request:

As a sanity check, break on "NPP_New" in gdb before you run the test and hang.  This is a (non-spurious) symbol in the JVM.  The idea is to make sure the browser is calling the Java plugin's NPP_New before it calls its NPP_GetValue.
Attached file bt and pss output
(In reply to Steven Michaud from comment #11)
> I just noticed something odd in your C/C++ stack trace:  Your call to pss()
> from gdb is there on the main thread.
> 
> Please trigger another hang, then break in gdb and get the output of "thread
> apply all bt" and "call (void) pss()" in that order.  Then please attach
> them here (instead of pasting them into a comment).

See this file.
Attached file NPP_New backtrace
(In reply to Steven Michaud from comment #12)
> And yet another request:
> 
> As a sanity check, break on "NPP_New" in gdb before you run the test and
> hang.  This is a (non-spurious) symbol in the JVM.  The idea is to make sure
> the browser is calling the Java plugin's NPP_New before it calls its
> NPP_GetValue.

NPP_New is being called before the hang.
Thanks, Ehsan, for the new info -- it shows that Java wasn't loaded by your call to pss().

But my diagnosis is still the same:  This is a Java hang, and looks like a bug in the JVM.

As such, it isn't worth trying to work around it until everyone can easily reproduce it and we know that it effects lots of people.
Have you tried to see if you can reproduce by running the tests?  Is there any way for us to report this bug to Apple?
> Have you tried to see if you can reproduce by running the tests?

I haven't tried.  I've got too much other stuff (all of it more urgent) on my plate just now.

> Is there any way for us to report this bug to Apple?

You could do it :-)

You need a (free) ADC account.  Then go to https://bugreport.apple.com/.  Note that Apple's bug database isn't public -- only Apple and the reporter can see the bug.  If/when you do it, put Apple's bug number (the "radar number") in the whiteboard using the format "rdar://nnnnnnnn".
I would report the bug to Apple, except that I don't know what to tell them.  Running the mochitests is not going to be a useful set of STRs for Apple.  ;-)

I guess I'll just leave the bug as it is, until someone can take a closer look at it...
(Following up comment #17)

Sometime later this week or next week I'll try to reproduce this bug
myself.  But even if I can, it's not worth pursuing unless it causes
*major* breakage -- for example if it breaks all our Java plugin
tests, or is the equivalent of a Mac topcrasher.

I've worked around *lots* of Apple bugs in my time, including bugs in
their JVM.  But doing so is *very* time consuming.

> I would report the bug to Apple, except that I don't know what to
> tell them.

Neither	do I :-(  Which basically means we don't have enough
information to make a good bug report -- one that Apple	is likely to
act on.
For what it's worth, I find I can reproduce this in close-to-current trunk code (an opt custom build with symbols not stripped) on OS X 10.6.8, with Apple's Java for Mac OS X 10.6 Update 7.

Boris at bug 741448 scared me into thinking that Apple's latest Java updates (Update 8 for 10.6 and 003 for Lion) might have broken all Java applets in FF trunk builds.  But I expect it's really this bug he's seeing.

This is still almost certainly an Apple bug, though -- about which we're unlikely to be able to do anything.
After playing with this bug some more, I've only now realized what's going on:

The test for bug 579079's APPLET tag is illegal!  Among other things it has no class field!

So we're hanging while trying to load an illegal APPLET tag.

I'll open a new bug on the subject when I have time (probably tomorrow).  I'll see what happens in other browsers.
Neither Safari nor Chrome nor Opera hang opening the same test.  So we have a real bug on our hands.  It may already have been filed.  I'll check tomorrow.
I'm marking this bug as WONTFIX per bug #1269807.

For more information see - https://blog.mozilla.org/futurereleases/2015/10/08/npapi-plugins-in-firefox/
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → WONTFIX
Product: Core → Core Graveyard
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: