Blocked threads are detected when having a lot of concurrent XML parsing

• Type: Bug
• Status: Closed
• Resolution: Fixed
• Affects Version/s: 6.2.10 EE GA1, 6.2.X EE, 7.0.X EE, Master
• Fix Version/s: 6.2.X EE, 7.0.0 DXP FP14, 7.0.0 DXP SP3, 7.0.3 CE GA4, 7.0.X EE, 7.1.X, Master
• Component/s: Performance
• Labels:
  • 62-ee-sp20
  • ee-ts
  • liferay-digital-enterprise-70-sp3
  • liferay-fixpack-de-14-7010
  • liferay-fixpack-portal-152-6210
• Branch Version/s:
  7.0.x, 6.2.x
• Backported to Branch:
  Committed
• Story Points: 1.25
• Fix Priority: 3
• Git Pull Request: https://github.com/brianchandotcom/liferay-portal/pull/48029

Blocked threads are detected when having a lot of concurrent XML parsing using com.liferay.portal.xml.SAXReaderImpl.read

We have detected two kinds of blocked threads:

• At SAXParser creation, a lock is detected in java.util.zip.ZipFile.getEntry

  java.lang.Thread.State: BLOCKED (on object monitor)
  	at java.util.zip.ZipFile.getEntry(ZipFile.java:304)
  	- waiting to lock <0x0000000601133ce8> (a java.util.jar.JarFile)
  	at java.util.jar.JarFile.getEntry(JarFile.java:227)
  	at java.util.jar.JarFile.getJarEntry(JarFile.java:210)
  	at sun.misc.URLClassPath$JarLoader.getResource(URLClassPath.java:840)
  	at sun.misc.URLClassPath$JarLoader.findResource(URLClassPath.java:818)
  	at sun.misc.URLClassPath.findResource(URLClassPath.java:176)
  	at java.net.URLClassLoader$2.run(URLClassLoader.java:551)
  	at java.net.URLClassLoader$2.run(URLClassLoader.java:549)
  	at java.security.AccessController.doPrivileged(Native Method)
  	at java.net.URLClassLoader.findResource(URLClassLoader.java:548)
  	at java.lang.ClassLoader.getResource(ClassLoader.java:1147)
  	at java.net.URLClassLoader.getResourceAsStream(URLClassLoader.java:227)
  	at org.apache.catalina.loader.WebappClassLoader.getResourceAsStream(WebappClassLoader.java:1530)
  	at org.apache.xerces.parsers.SecuritySupport$6.run(Unknown Source)
  	at java.security.AccessController.doPrivileged(Native Method)
  	at org.apache.xerces.parsers.SecuritySupport.getResourceAsStream(Unknown Source)
  	at org.apache.xerces.parsers.ObjectFactory.findJarServiceProvider(Unknown Source)
  	at org.apache.xerces.parsers.ObjectFactory.createObject(Unknown Source)
  	at org.apache.xerces.parsers.ObjectFactory.createObject(Unknown Source)
  	at org.apache.xerces.parsers.SAXParser.<init>(Unknown Source)
  	at org.apache.xerces.parsers.SAXParser.<init>(Unknown Source)
  	at com.liferay.portal.security.xml.SecureXMLFactoryProviderImpl.newXMLReader(SecureXMLFactoryProviderImpl.java:116)
  	at com.liferay.portal.xml.SAXReaderImpl.getSAXReader(SAXReaderImpl.java:584)
  	at com.liferay.portal.xml.SAXReaderImpl.read(SAXReaderImpl.java:430)
  	at com.liferay.portal.xml.SAXReaderImpl.read(SAXReaderImpl.java:411)
  	at com.liferay.portal.xml.SAXReaderImpl.read(SAXReaderImpl.java:446)
  	at com.liferay.portal.kernel.xml.SAXReaderUtil.read(SAXReaderUtil.java:177)
  

  The same issue is explained in following page: https://www.mail-archive.com/[email protected]/msg03825.html

• At XML parsing, a lock is detected in org.dom4j.tree.QNameCache.get(QNameCache.java:117)

  java.lang.Thread.State: BLOCKED (on object monitor)
  	at java.util.Collections$SynchronizedMap.get(Collections.java:2037)
  	- waiting to lock <0x00000004e47eb0f0> (a java.util.Collections$SynchronizedMap)
  	at org.dom4j.tree.QNameCache.get(QNameCache.java:117)
  	at org.dom4j.DocumentFactory.createQName(DocumentFactory.java:199)
  	at org.dom4j.tree.NamespaceStack.createQName(NamespaceStack.java:392)
  	at org.dom4j.tree.NamespaceStack.pushQName(NamespaceStack.java:374)
  	at org.dom4j.tree.NamespaceStack.getQName(NamespaceStack.java:213)
  	at org.dom4j.io.SAXContentHandler.startElement(SAXContentHandler.java:234)
  	at org.apache.xerces.parsers.AbstractSAXParser.startElement(Unknown Source)
  	at org.apache.xerces.impl.XMLNSDocumentScannerImpl.scanStartElement(Unknown Source)
  	at org.apache.xerces.impl.XMLNSDocumentScannerImpl$NSContentDispatcher.scanRootElementHook(Unknown Source)
  	at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl$FragmentContentDispatcher.dispatch(Unknown Source)
  	at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl.scanDocument(Unknown Source)
  	at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
  	at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
  	at org.apache.xerces.parsers.XMLParser.parse(Unknown Source)
  	at org.apache.xerces.parsers.AbstractSAXParser.parse(Unknown Source)
  	at com.liferay.portal.security.xml.StripDoctypeXMLReader.parse(StripDoctypeXMLReader.java:132)
  	at org.dom4j.io.SAXReader.read(SAXReader.java:465)
  	at org.dom4j.io.SAXReader.read(SAXReader.java:365)
  

  The same issue was detected in LPS-7427 but it wasn't fixed

Steps to reproduce

1. This issue can be reproduced executing attached groovy script parallel_calls_to_SAXParser.groovy
2. The script will create 100 threads and 20000 XML parsing requests will be queued
3. You can check blocked threads using jstack:

   jstack -l <pid>
   

1. Following blocked threads must not be displayed
   • java.lang.Thread.State: BLOCKED (on object monitor) at java.util.zip.ZipFile.getEntry(ZipFile.java:304)
   • java.lang.Thread.State: BLOCKED (on object monitor) at java.util.Collections$SynchronizedMap.get(Collections.java:2037)
2. Execution time should be shorter in case of not having blocked threads

---

QA/Solution Notes
The following system property has been added:

system.properties

## Dom4j
##

    #
    # Configure a custom document factory in order to use a thread safe QName
    # cache.
    #
    org.dom4j.factory=com.liferay.portal.xml.DocumentFactory
    #org.dom4j.factory=org.dom4j.DocumentFactory