[
https://issues.apache.org/jira/browse/AMQ-8011?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Andrew Levandoski updated AMQ-8011:
-----------------------------------
Description:
ClassLoadingAwareObjectInputStream.checkSecurity( ) is inefficient as it's
repeatedly calling Class.getPackage( ).
It only needs to be invoked once.
It doesn't need to be invoked at all if trustAllPackage( ) == true
Class.getPackage( ) calls Package.getPackage( )
Package.getPackage( ) calls ClassLoader.getPackage(name)
ClassLoader.getPackage( ) contains a synchronized block (on HashMap) that ends
up delaying other threads when:
* The rate of messaging is very high when security is enabled.
* it's made worse by the number of packages in TRUSTED_PACKAGES
* also made worse by the ordering of packages in TRUSTED_PACKAGES
* if the package being compared is further down the list, it exacerbates the
issue.
We have seen our code calling clazz.getPackage( ) upwards of 15 times during
the handling of a single message.
StackTrace of delayed threads:
{code:java}
"ActiveMQ Session Task-1280" #164931 prio=7 os_prio=0 tid=0x00007f2764002800
nid=0x522d waiting for monitor entry [0x00007f24c3436000]
java.lang.Thread.State: BLOCKED (on object monitor)
at java.lang.ClassLoader.getPackage(ClassLoader.java:1611)
- waiting to lock <0x00000006dd9b39c0> (a java.util.HashMap)
at java.lang.Package.getPackage(Package.java:334)
at java.lang.Class.getPackage(Class.java:796)
at
org.apache.activemq.util.ClassLoadingAwareObjectInputStream.checkSecurity(ClassLoadingAwareObjectInputStream.java:106)
at
org.apache.activemq.util.ClassLoadingAwareObjectInputStream.resolveClass(ClassLoadingAwareObjectInputStream.java:57)
at
java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1924)
at java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1807)
at
java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1941)
at java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1807)
at
java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1941)
at java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1807)
at
java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2098)
at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1624)
at java.io.ObjectInputStream.readObject(ObjectInputStream.java:464)
at java.io.ObjectInputStream.readObject(ObjectInputStream.java:422)
at java.util.ArrayList.readObject(ArrayList.java:797)
at sun.reflect.GeneratedMethodAccessor97.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
java.io.ObjectStreamClass.invokeReadObject(ObjectStreamClass.java:1184)
at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:2234)
at
java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2125)
at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1624)
at
java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:2343)
at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:2267)
at
java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2125)
at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1624)
at
java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:2343)
at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:2267)
at
java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2125)
at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1624)
at java.io.ObjectInputStream.readObject(ObjectInputStream.java:464)
at java.io.ObjectInputStream.readObject(ObjectInputStream.java:422)
at
org.apache.activemq.command.ActiveMQObjectMessage.getObject(ActiveMQObjectMessage.java:206)
{code}
StackTrace of the thread holding the lock:
{noformat}
"ActiveMQ Session Task-3517" #164719 prio=7 os_prio=0 tid=0x00007f26ac008800
nid=0x225c waiting for monitor entry [0x00007f26fb41d000]
java.lang.Thread.State: BLOCKED (on object monitor)
at java.lang.ClassLoader.getPackage(ClassLoader.java:1611)
- locked <0x00000006dd9b39c0> (a java.util.HashMap)
at java.lang.Package.getPackage(Package.java:334)
at java.lang.Class.getPackage(Class.java:796)
at
org.apache.activemq.util.ClassLoadingAwareObjectInputStream.checkSecurity(ClassLoadingAwareObjectInputStream.java:106)
at
org.apache.activemq.util.ClassLoadingAwareObjectInputStream.resolveClass(ClassLoadingAwareObjectInputStream.java:57)
at
java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1924)
at java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1807)
at
java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2098)
at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1624)
at java.io.ObjectInputStream.readObject(ObjectInputStream.java:464)
at java.io.ObjectInputStream.readObject(ObjectInputStream.java:422)
at
org.apache.activemq.command.ActiveMQObjectMessage.getObject(ActiveMQObjectMessage.java:206){noformat}
The code in 5.16.0 looks the same and probably is subject to the same issue.
was:
ClassLoadingAwareObjectInputStream.checkSecurity( ) is inefficient as it's
repeatedly calling Class.getPackage( ).
It only needs to be invoked once.
It doesn't need to be invoked at all if trustAllPackage( ) == true
Class.getPackage( ) calls Package.getPackage( )
Package.getPackage( ) calls ClassLoader.getPackage(name)
ClassLoader.getPackage( ) contains a synchronized block (on HashMap) that ends
up delaying other threads when:
- The rate of messaging is very high when security is enabled.
- it's made worse by the number of packages in TRUSTED_PACKAGES
- also made worse by the ordering of packages in TRUSTED_PACKAGES
- if the package being compared is further down the list, it exacerbates
the issue.
We have seen our code calling clazz.getPackage( ) upwards of 15 times during
the handling of a single message.
StackTrace of delayed threads:
{{"ActiveMQ Session Task-1280" #164931 prio=7 os_prio=0 tid=0x00007f2764002800
nid=0x522d waiting for monitor entry [0x00007f24c3436000]}}
{{ java.lang.Thread.State: BLOCKED (on object monitor)}}
{{ at java.lang.ClassLoader.getPackage(ClassLoader.java:1611)}}
{{ - waiting to lock <0x00000006dd9b39c0> (a java.util.HashMap)}}
{{ at java.lang.Package.getPackage(Package.java:334)}}
{{ at java.lang.Class.getPackage(Class.java:796)}}
{{ at
org.apache.activemq.util.ClassLoadingAwareObjectInputStream.checkSecurity(ClassLoadingAwareObjectInputStream.java:106)}}
{{ at
org.apache.activemq.util.ClassLoadingAwareObjectInputStream.resolveClass(ClassLoadingAwareObjectInputStream.java:57)}}
{{ at java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1924)}}
{{ at java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1807)}}
{{ at java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1941)}}
{{ at java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1807)}}
{{ at java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1941)}}
{{ at java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1807)}}
{{ at
java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2098)}}
{{ at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1624)}}
{{ at java.io.ObjectInputStream.readObject(ObjectInputStream.java:464)}}
{{ at java.io.ObjectInputStream.readObject(ObjectInputStream.java:422)}}
{{ at java.util.ArrayList.readObject(ArrayList.java:797)}}
{{ at sun.reflect.GeneratedMethodAccessor97.invoke(Unknown Source)}}
{{ at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)}}
{{ at java.lang.reflect.Method.invoke(Method.java:498)}}
{{ at java.io.ObjectStreamClass.invokeReadObject(ObjectStreamClass.java:1184)}}
{{ at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:2234)}}
{{ at
java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2125)}}
{{ at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1624)}}
{{ at java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:2343)}}
{{ at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:2267)}}
{{ at
java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2125)}}
{{ at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1624)}}
{{ at java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:2343)}}
{{ at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:2267)}}
{{ at
java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2125)}}
{{ at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1624)}}
{{ at java.io.ObjectInputStream.readObject(ObjectInputStream.java:464)}}
{{ at java.io.ObjectInputStream.readObject(ObjectInputStream.java:422)}}
{{ at
org.apache.activemq.command.ActiveMQObjectMessage.getObject(ActiveMQObjectMessage.java:206)}}
{{StackTrace of the Thread holding the lock:}}
"ActiveMQ Session Task-3517" #164719 prio=7 os_prio=0 tid=0x00007f26ac008800
nid=0x225c waiting for monitor entry [0x00007f26fb41d000]
java.lang.Thread.State: BLOCKED (on object monitor)
at java.lang.ClassLoader.getPackage(ClassLoader.java:1611)
- locked <0x00000006dd9b39c0> (a java.util.HashMap)
at java.lang.Package.getPackage(Package.java:334)
at java.lang.Class.getPackage(Class.java:796)
at
org.apache.activemq.util.ClassLoadingAwareObjectInputStream.checkSecurity(ClassLoadingAwareObjectInputStream.java:106)
at
org.apache.activemq.util.ClassLoadingAwareObjectInputStream.resolveClass(ClassLoadingAwareObjectInputStream.java:57)
at java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1924)
at java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1807)
at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2098)
at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1624)
at java.io.ObjectInputStream.readObject(ObjectInputStream.java:464)
at java.io.ObjectInputStream.readObject(ObjectInputStream.java:422)
at
org.apache.activemq.command.ActiveMQObjectMessage.getObject(ActiveMQObjectMessage.java:206)
The code in 5.16.0 looks the same and probably is subject to the same issue.
> Performance Related issue in
> ClassLoadingAwareObjectInputStream.checkSecurity( )
> --------------------------------------------------------------------------------
>
> Key: AMQ-8011
> URL: https://issues.apache.org/jira/browse/AMQ-8011
> Project: ActiveMQ
> Issue Type: Bug
> Components: JMS client
> Affects Versions: 5.14.5
> Reporter: Andrew Levandoski
> Priority: Major
>
> ClassLoadingAwareObjectInputStream.checkSecurity( ) is inefficient as it's
> repeatedly calling Class.getPackage( ).
> It only needs to be invoked once.
> It doesn't need to be invoked at all if trustAllPackage( ) == true
>
> Class.getPackage( ) calls Package.getPackage( )
> Package.getPackage( ) calls ClassLoader.getPackage(name)
> ClassLoader.getPackage( ) contains a synchronized block (on HashMap) that
> ends up delaying other threads when:
> * The rate of messaging is very high when security is enabled.
> * it's made worse by the number of packages in TRUSTED_PACKAGES
> * also made worse by the ordering of packages in TRUSTED_PACKAGES
> * if the package being compared is further down the list, it exacerbates the
> issue.
> We have seen our code calling clazz.getPackage( ) upwards of 15 times during
> the handling of a single message.
>
>
> StackTrace of delayed threads:
>
> {code:java}
> "ActiveMQ Session Task-1280" #164931 prio=7 os_prio=0 tid=0x00007f2764002800
> nid=0x522d waiting for monitor entry [0x00007f24c3436000]
> java.lang.Thread.State: BLOCKED (on object monitor)
> at java.lang.ClassLoader.getPackage(ClassLoader.java:1611)
> - waiting to lock <0x00000006dd9b39c0> (a java.util.HashMap)
> at java.lang.Package.getPackage(Package.java:334)
> at java.lang.Class.getPackage(Class.java:796)
> at
> org.apache.activemq.util.ClassLoadingAwareObjectInputStream.checkSecurity(ClassLoadingAwareObjectInputStream.java:106)
> at
> org.apache.activemq.util.ClassLoadingAwareObjectInputStream.resolveClass(ClassLoadingAwareObjectInputStream.java:57)
> at
> java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1924)
> at
> java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1807)
> at
> java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1941)
> at
> java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1807)
> at
> java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1941)
> at
> java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1807)
> at
> java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2098)
> at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1624)
> at java.io.ObjectInputStream.readObject(ObjectInputStream.java:464)
> at java.io.ObjectInputStream.readObject(ObjectInputStream.java:422)
> at java.util.ArrayList.readObject(ArrayList.java:797)
> at sun.reflect.GeneratedMethodAccessor97.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at
> java.io.ObjectStreamClass.invokeReadObject(ObjectStreamClass.java:1184)
> at
> java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:2234)
> at
> java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2125)
> at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1624)
> at
> java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:2343)
> at
> java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:2267)
> at
> java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2125)
> at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1624)
> at
> java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:2343)
> at
> java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:2267)
> at
> java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2125)
> at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1624)
> at java.io.ObjectInputStream.readObject(ObjectInputStream.java:464)
> at java.io.ObjectInputStream.readObject(ObjectInputStream.java:422)
> at
> org.apache.activemq.command.ActiveMQObjectMessage.getObject(ActiveMQObjectMessage.java:206)
> {code}
>
> StackTrace of the thread holding the lock:
> {noformat}
> "ActiveMQ Session Task-3517" #164719 prio=7 os_prio=0 tid=0x00007f26ac008800
> nid=0x225c waiting for monitor entry [0x00007f26fb41d000]
> java.lang.Thread.State: BLOCKED (on object monitor)
> at java.lang.ClassLoader.getPackage(ClassLoader.java:1611)
> - locked <0x00000006dd9b39c0> (a java.util.HashMap)
> at java.lang.Package.getPackage(Package.java:334)
> at java.lang.Class.getPackage(Class.java:796)
> at
> org.apache.activemq.util.ClassLoadingAwareObjectInputStream.checkSecurity(ClassLoadingAwareObjectInputStream.java:106)
> at
> org.apache.activemq.util.ClassLoadingAwareObjectInputStream.resolveClass(ClassLoadingAwareObjectInputStream.java:57)
> at
> java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1924)
> at
> java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1807)
> at
> java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2098)
> at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1624)
> at java.io.ObjectInputStream.readObject(ObjectInputStream.java:464)
> at java.io.ObjectInputStream.readObject(ObjectInputStream.java:422)
> at
> org.apache.activemq.command.ActiveMQObjectMessage.getObject(ActiveMQObjectMessage.java:206){noformat}
>
>
> The code in 5.16.0 looks the same and probably is subject to the same issue.
>
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
