Bug 27717 - <x:forEach> very slow in JSTL 1.1
<x:forEach> very slow in JSTL 1.1
Status: RESOLVED FIXED
Product: Taglibs
Classification: Unclassified
Component: Standard Taglib
1.1
Sun Solaris
: P2 major with 4 votes (vote)
: ---
Assigned To: Tomcat Developers Mailing List
:
: 33297 40717 (view as bug list)
Depends on:
Blocks:
  Show dependency tree
 
Reported: 2004-03-16 17:27 UTC by Chris Johnson
Modified: 2012-10-05 10:23 UTC (History)
4 users (show)



Attachments
Test xforeach jsp file (1.18 KB, text/plain)
2004-07-29 20:27 UTC, Justyna Horwat
Details
Test xtransform jsp file (840 bytes, text/plain)
2004-07-29 20:27 UTC, Justyna Horwat
Details
Test xml file (70.33 KB, text/plain)
2004-07-29 20:28 UTC, Justyna Horwat
Details
Test xsl file (861 bytes, text/plain)
2004-07-29 20:28 UTC, Justyna Horwat
Details
Update ExprSupport to use JAXP (3.71 KB, text/plain)
2010-07-11 01:18 UTC, Jeremy Boynes
Details
Supporting variable resolver (6.36 KB, text/plain)
2010-07-11 01:19 UTC, Jeremy Boynes
Details
Patch to use JAXP XPath support (93.37 KB, patch)
2010-12-23 15:11 UTC, Jeremy Boynes
Details | Diff
Patch for XPath using Xalan API (118.54 KB, patch)
2010-12-27 14:18 UTC, Jeremy Boynes
Details | Diff
Updated patch using Xalan directly (84.24 KB, patch)
2010-12-30 22:06 UTC, Jeremy Boynes
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Chris Johnson 2004-03-16 17:27:15 UTC
SunOS 5.6: J2SE 1.4.2_03: tomcat 5.0.19, JSTL 1.1

Very poor performance when using <x:forEach> in JSTL 1.1.  Did not have this 
problem in JSTL 1.0 (all other variables the same - os, java version, tomcat 
version).  I think this only shows when looping on a fairly high number of 
elements though.  My example is about 1750 elements.  Here's my test code:

<%@ taglib prefix="c" uri="http://java.sun.com/jsp/jstl/core" %>
<%@ taglib prefix="x" uri="http://java.sun.com/jsp/jstl/xml" %>

<html>
<body>
<c:import url="WebUI.xml" varReader="raw">
    <x:parse var="xml" xml="${raw}"/>
</c:import>
<x:forEach select="$xml//column">
    <x:out select="."/><br>
</x:forEach>
</body>
</html>

Here's a snippet of my data (I don't know if I can put it all):

<?xml version="1.0"?>^M
<uiData>^M
    <station name="PH_HOLD" headerColor="#FFFFFF">^M
        <row color="#FFFFFF">^M
            <column name="_rank">1</column>^M
            <column name="+ROW">1</column>^M
            <column name="_lotid">3324197</column>^M
            <column name="+LOTID">3324197</column>^M
            <column name="+InProc" />^M
            <column name="+LP">6990</column>^M
            <column name="+OPN">8250</column>^M
            <column name="+DEVICE">B6A/182514SF5</column>^M
            <column name="+TEST" />^M
            <column name="+RECIPE" />^M
            <column name="+RET_FURN">E363-710</column>^M
            <column name="+THK_TIME" />^M
            <column name="+TOOL">XM 16 18 </column>^M
            <column name="+QTY">22</column>^M
            <column name="+PRI">2</column>^M
            <column name="+H">Y</column>^M
            <column name="+T" />^M
            <column name="+stocker">WIP73-4</column>^M
            <column name="+LPAge">1.2</column>^M
            <column name="+LOTSTART" />^M
            <column name="+TIME REMAIN." />^M
            <column name="+LC2">66</column>^M
            <column name="+Rank">-991.0</column>^M
            <column name="+Next_BN">PH_LS66D</column>^M
            <column name="+BNFF">0.00</column>^M
            <column name="+CR">3.14</column>^M
            <column name="_assigned">03/11/04 12:18:33</column>^M
            <column name="_batch">1</column>^M
            <column name="_site_defined1">1</column>^M
            <column name="_site_defined2">PH_HOLD</column>^M
            <column name="_site_defined3">22</column>^M
            <column name="_site_defined4">0.0</column>^M
            <column name="_site_defined5">3.1</column>^M
            <column name="_site_defined6">Y</column>^M
            <column name="_site_defined7">6990</column>^M
            <column name="_site_defined8">B6A/182514SF5</column>^M
            <column name="_site_defined9">8250</column>^M
            <column name="_site_defined10">[Not Set]</column>^M
            <column name="_site_defined11">00:00:00</column>^M
            <column name="_site_defined12" />^M
            <column name="_site_defined13">-991.0</column>^M
            <column name="_site_defined14">01/01/99 00:00:00</column>^M
            <column name="_site_defined15">NONE</column>^M
            <column name="_site_defined16">03/10/04 06:32:40</column>^M
            <column name="_site_defined17">29:45:37</column>^M
            <column name="_site_defined18" />^M
            <column name="_site_defined19">03/11/2004 09:00:19</column>^M
            <column name="_site_defined20" />^M
            <column name="_eqpid" />^M
            <column name="_site_defined21" />^M
        </row>^M
        <row color="#FFFFFF">^M
            <column name="_rank">2</column>^M
            <column name="+ROW">2</column>^M
            <column name="_lotid">4048139</column>^M
            <column name="+LOTID">4048139</column>^M
            <column name="+InProc" />^M
            <column name="+LP">1960</column>^M
            <column name="+OPN">8300</column>^M
            <column name="+DEVICE">D3P/4770FH</column>^M
            <column name="+TEST" />^M
            <column name="+RECIPE" />^M
            <column name="+RET_FURN">E251-178</column>^M
            <column name="+THK_TIME" />^M 
            <column name="+TOOL">LM 08 07 06 05 </column>^M
            <column name="+QTY">12</column>^M
            <column name="+PRI">3</column>^M
            <column name="+H">F</column>^M
            <column name="+T" />^M
            <column name="+stocker">XK101P</column>^M
            <column name="+LPAge">4.4</column>^M
            <column name="+LOTSTART" />^M
            <column name="+TIME REMAIN." />^M
            <column name="+LC2">53</column>^M
            <column name="+Rank">-991.0</column>^M
            <column name="+Next_BN">PH_LS53D</column>^M
            <column name="+BNFF">0.00</column>^M
            <column name="+CR">0.68</column>^M
            <column name="_assigned">03/11/04 12:18:33</column>^M
            <column name="_batch">1</column>^M
            <column name="_site_defined1">2</column>^M
            <column name="_site_defined2">PH_HOLD</column>^M
            <column name="_site_defined3">12</column>^M
            <column name="_site_defined4">0.0</column>^M
            <column name="_site_defined5">0.7</column>^M
            <column name="_site_defined6">F</column>^M
            <column name="_site_defined7">1960</column>^M
            <column name="_site_defined8">D3P/4770FH</column>^M
            <column name="_site_defined9">8300</column>^M
            <column name="_site_defined10">06:14:40:03</column>^M
            <column name="_site_defined11">00:00:00</column>^M
            <column name="_site_defined12" />^M
            <column name="_site_defined13">-991.0</column>^M
            <column name="_site_defined14">01/01/99 00:00:00</column>^M
            <column name="_site_defined15">NONE</column>^M
            <column name="_site_defined16">03/07/04 03:37:12</column>^M
            <column name="_site_defined17">104:41:05</column>^M
            <column name="_site_defined18" />^M
            <column name="_site_defined19">03/09/2004 16:19:53</column>^M
            <column name="_site_defined20" />^M
            <column name="_eqpid" />^M
            <column name="_site_defined21" />^M
        </row>^M
        ...
    </station>^M
</uiData>^M

Another thing to note is that when I truss'd the tomcat process while the loop 
was ongoing, I was seeing errors pointing to a failure to find the 
jaxp.properties and xalan.properties files, plus lots of locking, unlocking and 
waiting.  I see none of this when using JSTL 1.0.  Even after setting system 
properties to define the parser and xslt paths, the performance was poor.  Here 
is what I've seen with truss:

stat64("/usr/j2sdk1.4.2_03/jre/lib/jaxp.properties",0xDF97FFF8) Err#2 ENOENT
stat64("/usr/j2sdk1.4.2_03/jre/lib/xalan.properties", 0xDF47F850) Err#2 ENOENT
lwp_mutex_lock(0x0002E7E0)                      = 0
lwp_mutex_unlock(0x0002E7E0)                    = 0
lwp_mutex_lock(0x0002E710)                      = 0
lwp_cond_wait(0x0002E728, 0x0002E710, 0x00000000) = 0
lwp_cond_broadcast(0x0002E728)                  = 0
lwp_mutex_unlock(0x0002E778)                    = 0
lwp_mutex_lock(0x0002E778)                      = 0
lwp_cond_broadcast(0x0002E860)                  = 0
lwp_cond_wait(0x0002E860, 0x0002E848, 0x00000000) = 0
lwp_mutex_unlock(0x0002E848)                    = 0
lwp_mutex_lock(0x0002E848)                      = 0
poll(0xE997FBC0, 0, 50)                         = 0
poll(0xE997FBC0, 0, 50)                         = 0
lwp_cond_wait(0x0002E7F8, 0x0002E7E0, 0xEC681B08) = 0
lwp_cond_signal(0x0002E7F8)                     = 0
lwp_cond_broadcast(0x0002E860)                  = 0
lwp_cond_wait(0x0002E860, 0x0002E848, 0x00000000) = 0
poll(0xE997FBC0, 0, 50)                         = 0
poll(0xE997FBC0, 0, 50)                         = 0
poll(0xE997FBC0, 0, 50)                         = 0
lwp_cond_wait(0x0002E7F8, 0x0002E7E0, 0xEC681B08) = 0


Thanks for the help,
Chris Johnson
Comment 1 Kris Schneider 2004-03-16 18:22:58 UTC
Couple of comments:

Previous id of problem:
http://www.mail-archive.com/taglibs-user@jakarta.apache.org/msg06308.html

Temporary workaround (use XSLT and <x:transform>):
http://www.mail-archive.com/taglibs-user@jakarta.apache.org/msg06337.html

I certainly don't have my head completely around the codebase, but it appears
that Standard 1.1 is using an approach that leverages Xalan's XPathAPI as
opposed to CachedXPathAPI. As a data point, I put together a test using an XML
file like:

<root>
    <child/>
    <child/>
    <!-- about 1400 total children -->
    ...
</root>

and two code variations:

#1
--
Document doc = ...;
String xpathStr = "//child";
CachedXPathAPI cachedXPath = new CachedXPathAPI();
NodeIterator i = cachedXPath.selectNodeIterator(doc, xpathStr);
Map values = new TreeMap();
int count = 1;
long now = System.currentTimeMillis();
for (Node node = i.nextNode(); node != null; node = i.nextNode()) {
  XObject xo = cachedXPath.eval(node, ".");
  values.put(new Integer(count), xo);
  count++;
}
long delta = System.currentTimeMillis() - now;
System.out.println("duration: " + delta + "ms");

#2
--
Document doc = ...;
String xpathStr = "//child";
NodeIterator i = XPathAPI.selectNodeIterator(doc, xpathStr);
Map values = new TreeMap();
int count = 1;
long now = System.currentTimeMillis();
for (Node node = i.nextNode(); node != null; node = i.nextNode()) {
  XObject xo = XPathAPI.eval(node, ".");
  values.put(new Integer(count), xo);
  count++;
}
long delta = System.currentTimeMillis() - now;
System.out.println("duration: " + delta + "ms");

Running on WinXP with Sun's JDK 1.4.2_03 plus Xerces 2.6.2 and Xalan 2.6.0, the
CachedXPathAPI test completes in under 700ms. The XPathAPI test threw an
OutOfMemoryError. I had to use -Xmx256 (it failed with 220!) and then it
completed in just under 10000ms.

Again, I haven't spent the time in the codebase to say whether this is truly
equivalent to how Standard 1.1 is using Xalan, but if it is, it looks like a
memory issue in addition to a performance issue.
Comment 2 Felipe Leme 2004-05-12 00:26:51 UTC
CC'ing the taglibs-dev address to all Standard bugs. 
Comment 3 Mike Skells 2004-05-12 07:04:57 UTC
We have noticed that x:set also appears very slow.

SHould I file this as a seperate issue
Comment 4 Felipe Leme 2004-05-12 08:58:28 UTC
Hi Mike,

Yes, please fill a new bug, preferably with instructions on how to reproduce it.

If we later realize the new bug is caused by the same problem , we can mark it
then as duplicated of this one.

Thanks,

Felipe
Comment 5 Justyna Horwat 2004-07-29 20:27:25 UTC
Created attachment 12261 [details]
Test xforeach jsp file
Comment 6 Justyna Horwat 2004-07-29 20:27:55 UTC
Created attachment 12262 [details]
Test xtransform jsp file
Comment 7 Justyna Horwat 2004-07-29 20:28:23 UTC
Created attachment 12263 [details]
Test xml file
Comment 8 Justyna Horwat 2004-07-29 20:28:55 UTC
Created attachment 12264 [details]
Test xsl file
Comment 9 Justyna Horwat 2004-07-29 20:31:31 UTC
Justyna,

I prepared two test cases which show the difference
in execution time between en x:forEach loop and an x:transform.

Just try them.

Test_xforeach.jsp uses Test.xml as input. (countains xml data)

Test_xtransform.jsp uses Test.xml as input and Test.xsl as stylesheet.

With jstl 1.1 things become problematic for the x:foreach loop

The x:foreach loop with jstl 1.0 gives the same,good, response times
as the x:transform in jstl 1.1

Regards
Wim

ps : the jsp files are send as .txt as attachment. You have to rename them.



-----Oorspronkelijk bericht-----
Van: Justyna Horwat
Verzonden: woensdag 28 juli 2004 19:36
Aan: Tag Libraries Users List
Onderwerp: Re: JSTL 1.1 jaxp problem (under tomcat 5.0.19/java 1.4.2_03)


Hi Wim,

Have you tried the following to avoid the property file lookups? What
were the results when you set the following properties?

----
jaxp.properties file lookup:


JAVA_OPTS="$JAVA_OPTS
-Djavax.xml.parsers.DocumentBuilderFactory=org.apache.xerces.jaxp.DocumentBu
ilderFactoryImpl"


Lookup procedure (for my own reference):
http://java.sun.com/j2se/1.4.2/docs/api/javax/xml/parsers/DocumentBuilderFac
tory.html#newInstance()

----

xalan.properties file lookup:


JAVA_OPTS="$JAVA_OPTS
-Dorg.apache.xml.dtm.DTMManager=org.apache.xml.dtm.ref.DTMManagerDefault"


Lookup procedure (for my own reference):
http://xml.apache.org/xalan-j/apidocs/org/apache/xml/dtm/DTMManager.html#new
Instance(org.apache.xml.utils.XMLStringFactory)
----

Thanks,

Justyna

Wim Goossens wrote:


>> Chris, Kris, Pierre,
>>
>> Do you know anything about a fix for this problem ?
>> I also submitted a bug report, probably at the wrong place,
>> in february. No solution so far.
>> http://developer.java.sun.com/developer/bugParade/bugs/4993200.html
>>
>> Regards,
>> Wim
>>
>>
>>
>> -----Oorspronkelijk bericht-----
>> Van: Johnson, Chris
>> Verzonden: dinsdag 16 maart 2004 18:29
>> Aan: Tag Libraries Users List
>> Onderwerp: RE: JSTL 1.1 jaxp problem (under tomcat 5.0.19/java 1.4.2_03)
>>
>>
>> Thanks for all of the help so far.
>>
>> I submitted bug 27717.
>>
>> Chris
>>
>> -----Original Message-----
>> From: Pierre.Delisle
>> Sent: Tuesday, March 16, 2004 10:58 AM
>> To: Tag Libraries Users List
>> Subject: Re: JSTL 1.1 jaxp problem (under tomcat 5.0.19/java 1.4.2_03)
>>
>>
>> Yes, as Kris mentioned, please file a bug report with proper test cases.
>> We'll have a look into it.
>>
>>     -- Pierre
>>
>> Kris Schneider wrote:
>>
>>
>
>>>>You're posting to the right place to make people aware of the problem.
>
>>
>>
>
>>>>To formalize the issue, a bug report should probably get submitted:
>>>>
>>>>http://issues.apache.org/bugzilla/enter_bug.cgi?product=Taglibs
>>>>
>>>>As part of the report, it would be helpful to include a simplified
>>>>test case (XML and JSP files) that reproduces the problem. If you have
>
>>
>>
>
>>>>any questions about the bug submission process just let me (us) know.
>>>>At this point, the problem seems to be either the way JSTL is using
>>>>Xalan or Xalan itself.
>>>>
>>>>Quoting "Johnson, Chris" <chrisjohnson>:
>>>>
>>>>
>>>>
>>
>>>>>>That gets rid of the xalan file search, but the performance is still
>>>>>>awful.  For now I guess I'll try to look into xslt, but this looks
>>>>>>like a bug that needs to be fixed or something.  Who else needs to
>>>>>>know about this to get it either fixed, or to tell me what else I
>>>>>>might be doing wrong (if anything).  Here's more of what truss is
>>>>>>spitting out if that
>>>>>>helps:
>>>>>>
>>>>>>lwp_cond_wait(0x0002E7F8, 0x0002E7E0, 0xEC681B08) = 0
>>>>>>lwp_cond_signal(0x0002E7F8)                     = 0
>>>>>>lwp_mutex_lock(0x0002E7E0)                      = 0
>>>>>>lwp_mutex_unlock(0x0002E7E0)                    = 0
>>>>>>lwp_mutex_lock(0x0002E710)                      = 0
>>>>>>lwp_cond_wait(0x0002E728, 0x0002E710, 0x00000000) = 0
>>>>>>lwp_cond_broadcast(0x0002E728)                  = 0
>>>>>>lwp_mutex_unlock(0x0002E778)                    = 0
>>>>>>lwp_mutex_lock(0x0002E778)                      = 0
>>>>>>lwp_cond_broadcast(0x0002E860)                  = 0
>>>>>>lwp_cond_wait(0x0002E860, 0x0002E848, 0x00000000) = 0
>>>>>>lwp_mutex_unlock(0x0002E848)                    = 0
>>>>>>lwp_mutex_lock(0x0002E848)                      = 0
>>>>>>poll(0xE997FBC0, 0, 50)                         = 0
>>>>>>poll(0xE997FBC0, 0, 50)                         = 0
>>>>>>lwp_cond_wait(0x0002E7F8, 0x0002E7E0, 0xEC681B08) = 0
>>>>>>lwp_cond_signal(0x0002E7F8)                     = 0
>>>>>>lwp_cond_broadcast(0x0002E860)                  = 0
>>>>>>lwp_cond_wait(0x0002E860, 0x0002E848, 0x00000000) = 0
>>>>>>poll(0xE997FBC0, 0, 50)                         = 0
>>>>>>poll(0xE997FBC0, 0, 50)                         = 0
>>>>>>poll(0xE997FBC0, 0, 50)                         = 0
>>>>>>lwp_cond_wait(0x0002E7F8, 0x0002E7E0, 0xEC681B08) = 0
>>>>>>lwp_cond_signal(0x0002E7F8)                     = 0
>>>>>>lwp_cond_broadcast(0x0002E860)                  = 0
>>>>>>lwp_cond_wait(0x0002E860, 0x0002E848, 0x00000000) = 0
>>>>>>poll(0xE997FBC0, 0, 50)                         = 0
>>>>>>poll(0xE997FBC0, 0, 50)                         = 0
>>>>>>poll(0xE997FBC0, 0, 50)                         = 0
>>>>>>lwp_cond_wait(0x0002E7F8, 0x0002E7E0, 0xEC681B08) = 0
>>>>>>lwp_cond_signal(0x0002E7F8)                     = 0
>>>>>>lwp_cond_broadcast(0x0002E860)                  = 0
>>>>>>lwp_cond_wait(0x0002E860, 0x0002E848, 0x00000000) = 0
>>>>>>lwp_mutex_unlock(0x0002E848)                    = 0
>>>>>>lwp_mutex_lock(0x0002E848)                      = 0
>>>>>>poll(0xE997FBC0, 0, 50)                         = 0
>>>>>>poll(0xE997FBC0, 0, 50)                         = 0
>>>>>>poll(0xE997FBC0, 0, 50)                         = 0
>>>>>>lwp_cond_wait(0x0002E7F8, 0x0002E7E0, 0xEC681B08) = 0
>>>>>>lwp_cond_signal(0x0002E7F8)                     = 0
>>>>>>lwp_mutex_lock(0x0002E7E0)                      = 0
>>>>>>lwp_mutex_unlock(0x0002E7E0)                    = 0
>>>>>>lwp_mutex_lock(0x0002E710)                      = 0
>>>>>>lwp_cond_wait(0x0002E728, 0x0002E710, 0x00000000) = 0
>>>>>>lwp_cond_broadcast(0x0002E728)                  = 0
>>>>>>lwp_mutex_unlock(0x0002E778)                    = 0
>>>>>>lwp_mutex_lock(0x0002E778)                      = 0
>>>>>>lwp_mutex_lock(0x0002E848)                      = 0
>>>>>>lwp_cond_broadcast(0x0002E860)                  = 0
>>>>>>lwp_cond_wait(0x0002E860, 0x0002E848, 0x00000000) = 0
>>>>>>poll(0xE997FBC0, 0, 50)                         = 0
>>>>>>poll(0xE997FBC0, 0, 50)                         = 0
>>>>>>poll(0xE997FBC0, 0, 50)                         = 0
>>>>>>
>>>>>>It looks like a lot of locking, unlocking and waiting to me, but what
>>>>>>do I know?
>>>>>>
>>>>>>Any help you can get me in escalating this would be much appreciated.
>>>>>>
>>>>>>Thanks again,
>>>>>>Chris
>>>>>>
>>>>>>-----Original Message-----
>>>>>>From: Kris Schneider []
>>>>>>Sent: Monday, March 15, 2004 3:37 PM
>>>>>>To: Tag Libraries Users List
>>>>>>Subject: RE: JSTL 1.1 jaxp problem (under tomcat 5.0.19/java 1.4.2_03)
>>>>>>
>>>>>>
>>>>>>Try adding
>>>>>>-Dorg.apache.xml.dtm.DTMManager=org.apache.xml.dtm.ref.DTMManagerDefau
>>>>>>lt
>>>>>>to JAVA_OPTS.
>>>>>>
>>>>>>Quoting "Johnson, Chris" <chrisjohnson@ti.com>:
>>>>>>
>>>>>>
>>>>>>
>>>
>>>>>>>>Thanks, Kris.
>>>>>>>>
>>>>>>>>I did all that you suggested (setting the system properties and
>>>>>>>>installing new jars), and indeed tomcat doesn't seem to be searching
>>>>>>>>for the jaxp.properties file any longer.  But, the performance is
>>>>>>>>still just about as bad as before.  So, I did truss again and now
>>>>>>>>tomcat is looking for xalan.properties
>>>>>>>>(stat64("/usr/j2sdk1.4.2_03/jre/lib/xalan.properties", 0xDF47F850)
>>>>>>>>Err#2 ENOENT), just about as much, if not more, than it was for
>>>>>>>>jaxp.properties.  So how can I fix this?
>>>>>>>>
>>>>>>>>Chris
>>>>>>>>
>>>>>>>>-----Original Message-----
>>>>>>>>From: Kris Schneider []
>>>>>>>>Sent: Monday, March 15, 2004 2:32 PM
>>>>>>>>To: Tag Libraries Users List
>>>>>>>>Subject: Re: JSTL 1.1 jaxp problem (under tomcat 5.0.19/java
>>>>>>>>1.4.2_03)
>>>>>>>>
>>>>>>>>
>>>>>>>>Interesting. <x:forEach> has been tagged as a performance problem
>>>>>>>>before for JSTL 1.1, but without the accompanying truss info. The
>>>>>>>>XPath engine for JSTL was changed from Jaxen/SAXPath in 1.0 to Xalan
>>>>>>>>in 1.1. If you can replace <x:forEach> with <x:transform> and an XSLT
>
>>
>>
>
>>>>>>>>stylesheet, that seemed to help with the last performance issue.
>>>>>>>>Otherwise, you could try explicitly configuring JAXP by setting the
>>>>>>>>appropriate system properties (assuming Xerces and Xalan):
>>>>>>>>
>>>>>>>>env
>>>>>>>>JAVA_OPTS="-Djavax.xml.parsers.DocumentBuilderFactory=org.apache.xerc
>
>>
>> e
>>
>
>>>>>>>>s.
>>>>>>>>jaxp.DocumentBuilderFactoryImpl
>>>>>>>>
>>>
>>>>>>
>>>>>>-Djavax.xml.parsers.SAXParserFactory=org.apache.xerces.jaxp.SAXParserF
>>>>>>ac
>>>>>>
>>>>>>
>>>
>>>>>>>>toryImpl
>>>>>>>>
>>>
>>>>>>
>>>>>>-Djavax.xml.transform.TransformerFactory=org.apache.xalan.processor.Tr
>>>>>>an
>>>>>>
>>>>>>
>>>
>>>>>>>>sformerFactoryImpl"
>>>>>>>>$CATALINA_HOME/bin/startup.sh
>>>>>>>>
>>>>>>>>That way, jaxp.properties should never be searched for. You may also
>>>>>>>>want to download the latest Xalan release and dump the following in
>>>>>>>>$CATALINA_HOME/common/endorsed:
>>>>>>>>
>>>>>>>>xalan.jar
>>>>>>>>xercesImpl.jar
>>>>>>>>xml-apis.jar
>>>>>>>>
>>>>>>>>Quoting "Johnson, Chris" <chrisjohnson>:
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>
>>>>>>>>>>Hello,
>>>>>>>>>>
>>>>>>>>>>I'm new to the world of JSP/JSTL, but have managed to get some code
>>>>>>>>>>running under tomcat 4.1.29 (bundled with jboss 3.2.3 - as I'm using
>>>
>>>>>>
>>>
>>>>>>>>>>JMS too)/JSTL 1.0.  I'm using java 1.4.2_03.
>>>>>>>>>>
>>>>>>>>>>I'm using only the c and x libraries currently, but wanted to use
>>>>>>>>>>the
>>>>>>>>>>new EL functions of JSTL 1.1, so I installed tomcat 5.0.19 alongside
>>>
>>>>>>
>>>
>>>>>>>>>>the previously mentioned jboss/tomcat versions.
>>>>>>>>>>
>>>>>>>>>>I've gotten the code to run under the new tomcat, but the
>>>>>>>>>>performance
>>>>>>>>>>is terrible.  I've narrowed the performance problem down to any
>>>>>>>>>><x:forEach> loop.  There wasn't anything of interest in the tomcat
>>>>>>>>>>log, so I did a truss on the tomcat process, and found it spitting
>>>
>>>>>>
>>>>>>out
>>>>>>
>>>>>>
>>>
>>>>>>>>>>this error over and over:
>>>>>>>>>>stat64("/usr/j2sdk1.4.2_03/jre/lib/jaxp.properties",
>>>>>>>>>>0xDF97FFF8) Err#2 ENOENT.  I understand this to be tomcat looking
>>>
>>>>>>
>>>>>>for
>>>>>>
>>>>>>
>>>
>>>>>>>>>>the jaxp.properties file and not finding it.  I never saw this error
>
>>
>>
>
>>>>>>>>>>message while trussing the tomcat 4.1.29 process, and it processes
>>>
>>>>>>
>>>>>>the
>>>>>>
>>>>>>
>>>
>>>>>>>>>>xml extremely quickly.
>>>>>>>>>>
>>>>>>>>>>With the older tomcat and JSTL 1.0, I didn't have to do any special
>>>>>>>>>>configuration of jaxp (I understood that to be built into java
>>>>>>>>>>1.4.2x), so I figured it would be the same with the newer tomcat,
>>>
>>>>>>
>>>>>>but
>>>>>>
>>>>>>
>>>
>>>>>>>>>>I guess not.
>>>>>>>>>>
>>>>>>>>>>So far I've tried setting parser system properties in the web.xml
>>>>>>>>>>and
>>>>>>>>>>in files under META-INF with no change.  What am I missing?  If
>>>>>>>>>>someone can just point me to some good docs on the subject, I'd
>>>>>>>>>>appreciate it greatly.
>>>>>>>>>>
>>>>>>>>>>Thanks,
>>>>>>>>>>Chris Johnson
Comment 10 Rahul Akolkar 2005-09-24 16:53:35 UTC
*** Bug 33297 has been marked as a duplicate of this bug. ***
Comment 11 Henri Yandell 2006-11-06 15:36:23 UTC
*** Bug 40717 has been marked as a duplicate of this bug. ***
Comment 12 Henri Yandell 2006-12-07 12:02:23 UTC
See the suggested fix in 40717.
Comment 13 Henri Yandell 2007-12-10 22:49:00 UTC
Ignore the fix suggestion in 40717 - I believe it is really just suggesting a
change that would be akin to reverting back to CachedXPathUtil. 
Comment 14 Henri Yandell 2007-12-11 01:28:07 UTC
Pushing this a bit - I don't think the problem is in x:foreach. I think it's in
x:out. x:foreach executes relatively quickly, but then each execution of x:out
is not cheap and it's adding up as the loop gets bigger.

Presumably running the following is hurting:

        XPathUtil xu = new XPathUtil(pageContext);
        String result = xu.valueOf(XPathUtil.getContext(this), select);

Digging into valueOf leads to agreement with David Winterbourne's comment in
40717 that the problem is in fillVarStack. It's in valueOf too and definitely
looks like a culprit. So apologies for my last comment on 40717 being akin to
CachedXPathAPI. That just caches the xpathSupport variable.

Looking at the speed of things, I've not found where the slow down is yet. There
are times when there are large chunks of slow down (100 milliseconds), which
might be GC due to massive object creation. Also over time the general time
taken on each eval call slowly rises, although still only to 10 milliseconds. 

Obviously I need to test in a profiler etc.
Comment 15 Kris Schneider 2007-12-20 18:52:39 UTC
(In reply to comment #14)
> Obviously I need to test in a profiler etc.

Speaking of which, I just grabbed NB6 and set up Standard 1.0.6 and Standard
1.1.2 projects to get a better idea of the performance difference. Using the
Test.xml attached a few years back and the following loop:

<% long start = System.currentTimeMillis(); %>
<x:forEach select="$doc//countries/country">
country id: <x:out select="id"/>
country description: <x:out select="description"/>
country countrycode: <x:out select="countrycode"/>
country carcode: <x:out select="carcode"/>
country nationality: <x:out select="nationality"/>
</x:forEach>
<% long delta = System.currentTimeMillis() - start; out.println("Duration: " +
delta + "ms"); %>

Here's what I got:
Standard 1.0.6: ~150ms
Standard 1.1.2: ~16000ms

I'm running JDK 1.5.0_12, Xalan 2.7.0, Xerces 2.7.1, Tomcat 5.5.23, and WinXP SP2.
Comment 16 Henri Yandell 2008-01-06 22:26:04 UTC
Profiling, all the time is spent in the following line:

            int ctxtNode = xpathSupport.getDTMHandleFromNode(contextNode);

The Javadoc for this method notes that it is non-optimal [wheee].

Reading CachedXPathAPI, what it does is cache the DTMManager, so definitely
makes sense that switching back to CachedXPathAPI will fix the slowness of x:out.

As there's no JSTL API to modify the DOM, I don't see any reason not to use
CachedXPathAPI - except for the memory issue of caching and figuring out where
in the lifecycle to remove it.

Given that this is only a notable problem for x:out in x:foreach, it would seem
that we need to attach the cache to the x:foreach start/close cycle, and have
the x:out notice that its session has such a thing.

Time to poke around in the code.
Comment 17 Henri Yandell 2008-01-06 23:15:02 UTC
The src/org/apache/taglibs/standard/tag/common/xml/ForEachTag.java class needs
to cache its XPathUtil object in setAttribute (default page scope), and tell
XPathUtil to use CachedJSTLXPathAPI rather than JSTLXPathAPI.

Additionally, XPathUtil needs that change, and a CachedJSTLXPathAPI needs to
exist that includes all the changes that JSTLXPathAPI has had from Xalan's XPathAPI.

ExprSupport needs to be changed to (somehow) find the XPathUtil and use it
instead of making a new one. Presumably this can be attached to the forEach's
var attribute (and whatever system is used to handle nested var's with the same
name (such as default name).

---

Maybe. I think the problem with all that is that x:foreach is supplying a new
node each time around. We need to cache the original node, and adjust the x:out
by appending(?) it to the x:foreach pattern each time. That all seems very dodgy.

CachedXPathAPI says that:  "A faster way is to precompile the XPaths using the
low-level API, and then just use the XPaths over and over". That sounds quite
attractive - each x:out could precompile an XPath and run it on its node. The
pain there is figuring out how to use the low level XPath API.
Comment 18 Jeremy Boynes 2010-07-04 21:28:58 UTC
(In reply to comment #17)
> CachedXPathAPI says that:  "A faster way is to precompile the XPaths using the
> low-level API, and then just use the XPaths over and over". That sounds quite
> attractive - each x:out could precompile an XPath and run it on its node. The
> pain there is figuring out how to use the low level XPath API.

Java5 introduced a standard XPath API that supports pre-compilation of XPath expressions. How about parsing the supplied XPath in the setter for the tag attribute and relying on tag pooling to avoid unnecessary recompilations?

The API also provides for a XPathVariableResolver that could work with the ELResolver to handle variables present in the XPath expressions.
Comment 19 Jeremy Boynes 2010-07-11 01:18:30 UTC
Created attachment 25749 [details]
Update ExprSupport to use JAXP
Comment 20 Jeremy Boynes 2010-07-11 01:19:20 UTC
Created attachment 25750 [details]
Supporting variable resolver
Comment 21 Jeremy Boynes 2010-12-23 15:11:18 UTC
Created attachment 26445 [details]
Patch to use JAXP XPath support

Patch attached to abstract the XPath API and provide an implementation using JAXP XPath.

However, there is a issue with <x:set> as it does not appear JAXP's XPath class can return the actual result type of the XPath expression - it requires coercion to specific return type. This breaks the contract for <x:set> where the variable needs to be set to the actual return type.
Comment 22 Jeremy Boynes 2010-12-27 14:18:26 UTC
Created attachment 26448 [details]
Patch for XPath using Xalan API

Continuation of patch 26445 with addition of a Xalan based implementation.
Comment 23 Jeremy Boynes 2010-12-30 22:06:15 UTC
Created attachment 26452 [details]
Updated patch using Xalan directly

Simplified patch that just uses the low-level Xalan APIs directly.
Comment 24 Jeremy Boynes 2010-12-31 18:18:43 UTC
Fixed in revision 1054175
Refactored XPath support to use Xalan low-level APIs directly.

Performance for large data sets scales with n^2 due to Xalan constructing a backing array for the iterator with a monotonic block size causing multiple calls to System.arrayCopy(). On a 2006 generation MacBookPro iterating 100000 elements takes ~1600ms.
Comment 25 Mark Thomas 2012-10-05 10:23:01 UTC
Reverting spam changes