-
Bug
-
Resolution: Fixed
-
P2
-
2.0
-
generic
-
generic
-
Not verified
When a connector does an addListener you can get the deadlock as below server side.
Got here with JDK 7 b33.
The client first fails with the stack below, then you know the server is deadlocked.
The client test code does a simple 'addNotificationListener(on, this, null, null);' when the issue occurs.
But it's important to notice that:
- the test uses the JMXWS protocol,
- the server has javax.remote.x.server.connection.timeout=5167 in its map,
- the client has javax.remote.x.client.connection.check.period=13331 in its map,
- the client asks for notification PUSH.
See attached full jstack output.
--------
The two threads involved in the deadlock are:
Name: LeaseManager0
State: BLOCKED on com.sun.jmx.remote.ws.api.JMXWSManDispatcher$ConnectionManager@1ad186f owned by: pool-3-thread-1
Total blocked: 1 Total waited: 1
Stack trace:
com.sun.jmx.remote.ws.api.JMXWSManDispatcher$ConnectionManager.removeConnection(JMXWSManDispatcher.java:573)
com.sun.jmx.remote.ws.api.JMXWSManDispatcher$ConnectionManager.access$400(JMXWSManDispatcher.java:458)
com.sun.jmx.remote.ws.api.JMXWSManDispatcher$ConnectionManager$Connection.run(JMXWSManDispatcher.java:509)
com.sun.jmx.remote.ws.event.LeaseManager$1.run(LeaseManager.java:139)
- locked [I@116880a
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
java.util.concurrent.FutureTask.run(FutureTask.java:166)
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:170)
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:285)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
java.lang.Thread.run(Thread.java:674)
Name: pool-3-thread-1
State: BLOCKED on [I@116880a owned by: LeaseManager0
Total blocked: 1 Total waited: 1
Stack trace:
com.sun.jmx.remote.ws.event.LeaseManager.init(LeaseManager.java:104)
com.sun.jmx.remote.ws.event.LeaseManager.lease(LeaseManager.java:67)
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.lang.reflect.Method.invoke(Method.java:623)
com.sun.jmx.remote.ws.EventServiceFactory.invokeOnTarget(EventServiceFactory.java:445)
com.sun.jmx.remote.ws.EventServiceFactory.access$100(EventServiceFactory.java:42)
com.sun.jmx.remote.ws.EventServiceFactory$LeaseManagerBridge.invoke(EventServiceFactory.java:534)
$Proxy49.lease(Unknown Source)
com.sun.jmx.remote.ws.api.JMXWSManDispatcher$ConnectionManager$Connection.lease(JMXWSManDispatcher.java:483)
com.sun.jmx.remote.ws.api.JMXWSManDispatcher$ConnectionManager$Connection.access$800(JMXWSManDispatcher.java:460)
com.sun.jmx.remote.ws.api.JMXWSManDispatcher$ConnectionManager.getOrCreateConnection(JMXWSManDispatcher.java:623)
- locked com.sun.jmx.remote.ws.api.JMXWSManDispatcher$ConnectionManager@1ad186f
com.sun.jmx.remote.ws.api.JMXWSManDispatcher$JMXWSManRequestDispatcher.call(JMXWSManDispatcher.java:4031)
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
java.util.concurrent.FutureTask.run(FutureTask.java:166)
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
java.util.concurrent.FutureTask.run(FutureTask.java:166)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
java.lang.Thread.run(Thread.java:674)
--------
Client's stack:
Exception in thread "main" java.lang.RuntimeException: java.lang.reflect.UndeclaredThrowableException
at javasoft.sqe.jmx.test.functional.ConnectionLeaseTest.run(ConnectionLeaseTest.java:126)
at javasoft.sqe.jmx.share.TestStarter.<init>(TestStarter.java:28)
at javasoft.sqe.jmx.share.TestStarter.main(TestStarter.java:79)
Caused by: java.lang.reflect.UndeclaredThrowableException
at $Proxy44.addNotificationListener(Unknown Source)
at com.sun.jmx.remote.ws.client.JMXWSConnector$RemoteMBeanServerConnection.invoke(JMXWSConnector.java:195)
at $Proxy38.addNotificationListener(Unknown Source)
at javasoft.sqe.jmx.test.functional.ConnectionLeaseTest.run(ConnectionLeaseTest.java:114)
... 2 more
Caused by: java.lang.reflect.InvocationTargetException
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:623)
at com.sun.jmx.remote.ws.EventServiceFactory.invokeOnTarget(EventServiceFactory.java:445)
at com.sun.jmx.remote.ws.EventServiceFactory.access$100(EventServiceFactory.java:42)
at com.sun.jmx.remote.ws.EventServiceFactory$EventClientBridge.invoke(EventServiceFactory.java:466)
... 6 more
Caused by: java.lang.reflect.UndeclaredThrowableException
at $Proxy39.addListener(Unknown Source)
at com.sun.jmx.remote.ws.event.EventClient.addNotificationListener(EventClient.java:376)
... 13 more
Caused by: java.lang.reflect.InvocationTargetException
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:623)
at com.sun.jmx.remote.ws.EventServiceFactory.invokeOnTarget(EventServiceFactory.java:445)
at com.sun.jmx.remote.ws.EventServiceFactory.access$100(EventServiceFactory.java:42)
at com.sun.jmx.remote.ws.EventServiceFactory$EventClientDelegateMBeanBridge.invoke(EventServiceFactory.java:551)
... 15 more
Caused by: java.io.IOException: Fault:
Action: http://schemas.dmtf.org/wbem/wsman/1/wsman/fault
Code: {http://www.w3.org/2003/05/soap-envelope}Receiver
Subcode: {http://schemas.dmtf.org/wbem/wsman/1/wsman.xsd}TimedOut
Reason: The operation has timed out.
at com.sun.jmx.remote.ws.EventServiceFactory$EventClientDelegateMBeanBridge.addListener(EventServiceFactory.java:587)
... 22 more
Caused by: Fault:
Action: http://schemas.dmtf.org/wbem/wsman/1/wsman/fault
Code: {http://www.w3.org/2003/05/soap-envelope}Receiver
Subcode: {http://schemas.dmtf.org/wbem/wsman/1/wsman.xsd}TimedOut
Reason: The operation has timed out.
at com.sun.jmx.remote.ws.wsman.JMXWSManHelper.mapFaultToException(JMXWSManHelper.java:797)
at com.sun.jmx.remote.ws.client.JMXWSManStub$WrappedStub.invoke(JMXWSManStub.java:1585)
at com.sun.jmx.remote.ws.client.JMXWSManStub$WrappedStub.access$3300(JMXWSManStub.java:1508)
at com.sun.jmx.remote.ws.client.JMXWSManStub.invoke(JMXWSManStub.java:1668)
at com.sun.jmx.remote.ws.client.JMXWSManStub.execute(JMXWSManStub.java:2066)
at com.sun.jmx.remote.ws.EventServiceFactory$EventClientDelegateMBeanBridge.addListener(EventServiceFactory.java:579)
... 22 more
Got here with JDK 7 b33.
The client first fails with the stack below, then you know the server is deadlocked.
The client test code does a simple 'addNotificationListener(on, this, null, null);' when the issue occurs.
But it's important to notice that:
- the test uses the JMXWS protocol,
- the server has javax.remote.x.server.connection.timeout=5167 in its map,
- the client has javax.remote.x.client.connection.check.period=13331 in its map,
- the client asks for notification PUSH.
See attached full jstack output.
--------
The two threads involved in the deadlock are:
Name: LeaseManager0
State: BLOCKED on com.sun.jmx.remote.ws.api.JMXWSManDispatcher$ConnectionManager@1ad186f owned by: pool-3-thread-1
Total blocked: 1 Total waited: 1
Stack trace:
com.sun.jmx.remote.ws.api.JMXWSManDispatcher$ConnectionManager.removeConnection(JMXWSManDispatcher.java:573)
com.sun.jmx.remote.ws.api.JMXWSManDispatcher$ConnectionManager.access$400(JMXWSManDispatcher.java:458)
com.sun.jmx.remote.ws.api.JMXWSManDispatcher$ConnectionManager$Connection.run(JMXWSManDispatcher.java:509)
com.sun.jmx.remote.ws.event.LeaseManager$1.run(LeaseManager.java:139)
- locked [I@116880a
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
java.util.concurrent.FutureTask.run(FutureTask.java:166)
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:170)
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:285)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
java.lang.Thread.run(Thread.java:674)
Name: pool-3-thread-1
State: BLOCKED on [I@116880a owned by: LeaseManager0
Total blocked: 1 Total waited: 1
Stack trace:
com.sun.jmx.remote.ws.event.LeaseManager.init(LeaseManager.java:104)
com.sun.jmx.remote.ws.event.LeaseManager.lease(LeaseManager.java:67)
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.lang.reflect.Method.invoke(Method.java:623)
com.sun.jmx.remote.ws.EventServiceFactory.invokeOnTarget(EventServiceFactory.java:445)
com.sun.jmx.remote.ws.EventServiceFactory.access$100(EventServiceFactory.java:42)
com.sun.jmx.remote.ws.EventServiceFactory$LeaseManagerBridge.invoke(EventServiceFactory.java:534)
$Proxy49.lease(Unknown Source)
com.sun.jmx.remote.ws.api.JMXWSManDispatcher$ConnectionManager$Connection.lease(JMXWSManDispatcher.java:483)
com.sun.jmx.remote.ws.api.JMXWSManDispatcher$ConnectionManager$Connection.access$800(JMXWSManDispatcher.java:460)
com.sun.jmx.remote.ws.api.JMXWSManDispatcher$ConnectionManager.getOrCreateConnection(JMXWSManDispatcher.java:623)
- locked com.sun.jmx.remote.ws.api.JMXWSManDispatcher$ConnectionManager@1ad186f
com.sun.jmx.remote.ws.api.JMXWSManDispatcher$JMXWSManRequestDispatcher.call(JMXWSManDispatcher.java:4031)
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
java.util.concurrent.FutureTask.run(FutureTask.java:166)
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
java.util.concurrent.FutureTask.run(FutureTask.java:166)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
java.lang.Thread.run(Thread.java:674)
--------
Client's stack:
Exception in thread "main" java.lang.RuntimeException: java.lang.reflect.UndeclaredThrowableException
at javasoft.sqe.jmx.test.functional.ConnectionLeaseTest.run(ConnectionLeaseTest.java:126)
at javasoft.sqe.jmx.share.TestStarter.<init>(TestStarter.java:28)
at javasoft.sqe.jmx.share.TestStarter.main(TestStarter.java:79)
Caused by: java.lang.reflect.UndeclaredThrowableException
at $Proxy44.addNotificationListener(Unknown Source)
at com.sun.jmx.remote.ws.client.JMXWSConnector$RemoteMBeanServerConnection.invoke(JMXWSConnector.java:195)
at $Proxy38.addNotificationListener(Unknown Source)
at javasoft.sqe.jmx.test.functional.ConnectionLeaseTest.run(ConnectionLeaseTest.java:114)
... 2 more
Caused by: java.lang.reflect.InvocationTargetException
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:623)
at com.sun.jmx.remote.ws.EventServiceFactory.invokeOnTarget(EventServiceFactory.java:445)
at com.sun.jmx.remote.ws.EventServiceFactory.access$100(EventServiceFactory.java:42)
at com.sun.jmx.remote.ws.EventServiceFactory$EventClientBridge.invoke(EventServiceFactory.java:466)
... 6 more
Caused by: java.lang.reflect.UndeclaredThrowableException
at $Proxy39.addListener(Unknown Source)
at com.sun.jmx.remote.ws.event.EventClient.addNotificationListener(EventClient.java:376)
... 13 more
Caused by: java.lang.reflect.InvocationTargetException
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:623)
at com.sun.jmx.remote.ws.EventServiceFactory.invokeOnTarget(EventServiceFactory.java:445)
at com.sun.jmx.remote.ws.EventServiceFactory.access$100(EventServiceFactory.java:42)
at com.sun.jmx.remote.ws.EventServiceFactory$EventClientDelegateMBeanBridge.invoke(EventServiceFactory.java:551)
... 15 more
Caused by: java.io.IOException: Fault:
Action: http://schemas.dmtf.org/wbem/wsman/1/wsman/fault
Code: {http://www.w3.org/2003/05/soap-envelope}Receiver
Subcode: {http://schemas.dmtf.org/wbem/wsman/1/wsman.xsd}TimedOut
Reason: The operation has timed out.
at com.sun.jmx.remote.ws.EventServiceFactory$EventClientDelegateMBeanBridge.addListener(EventServiceFactory.java:587)
... 22 more
Caused by: Fault:
Action: http://schemas.dmtf.org/wbem/wsman/1/wsman/fault
Code: {http://www.w3.org/2003/05/soap-envelope}Receiver
Subcode: {http://schemas.dmtf.org/wbem/wsman/1/wsman.xsd}TimedOut
Reason: The operation has timed out.
at com.sun.jmx.remote.ws.wsman.JMXWSManHelper.mapFaultToException(JMXWSManHelper.java:797)
at com.sun.jmx.remote.ws.client.JMXWSManStub$WrappedStub.invoke(JMXWSManStub.java:1585)
at com.sun.jmx.remote.ws.client.JMXWSManStub$WrappedStub.access$3300(JMXWSManStub.java:1508)
at com.sun.jmx.remote.ws.client.JMXWSManStub.invoke(JMXWSManStub.java:1668)
at com.sun.jmx.remote.ws.client.JMXWSManStub.execute(JMXWSManStub.java:2066)
at com.sun.jmx.remote.ws.EventServiceFactory$EventClientDelegateMBeanBridge.addListener(EventServiceFactory.java:579)
... 22 more