Performance-optimized version of ComponentSupport.findChildByTagId() #4808
Conversation
Signed-off-by: Marc Beyerle <marc.beyerle@de.ibm.com>
|
@tandraschko: Maybe you can have a look at this one as well as #4809 and #4810. Maybe some of this ideas may be interresting for MyFaces too. I´ll do a custom Mojarra 2.3 - build for my organization including this PR tomorrow and do some real-world test´s against our COVID-19 tracing application. |
|
I can have a look, thanks. Im almost sure that the 2 other linked issues are highly optimized in MyFaces |
|
Yep, verified it and posted a small improvement in #4810 |
|
@zjavaperf could you share a testview or whole testcase here? We dont have such a cache in MyFaces but i also see a very limited use of this method in general in MF. Im not sure if its used more often in Mojarra but that i will save 20-25% of all java methods called in a application sounds very heavy. |
|
@tandraschko here is a small sample in order to reproduce the heavy calls to
@christophs78 Nice to see you jumping in here 👍 Edit: I apologize, I had a small flaw in the sample that caused the bean for the Edit 2: See 2 comments below for |
|
Some performance-data. Our main personDetail.xhtml (in our COVID-19 tracing application) has about 1.400 lines. And it uses some rather simple composit components. We see a improvement of about 25% for buildView. The total impact (as far as we know at this point in time) is less - some data metered with Dynatrace: This is data for a whole-page-request. For Ajax-requests with partial page rendering, ... it may have more impact. |
|
@zjavaperf @christophs78 where is RowData from? |
|
@tandraschko My bad... Sorry. I forgot to add it to |
|
Ok, thanks. NOTE: i'm not a part of the Mojarra team and therefor not sure if it's the best way to fix it. |
|
he is my testcase inside a forked "primefaces-test", you can easily run it with mojarra2.0 - 2.3 and myfaces 2.0 - 2.3-next. |
|
I will test this PR as well, as I have also noticed a performance issue on the RESTORE_PHASE on views with large component tree when upgrading from Mojarra 2.2.13 to 2.3.9 (there are changes on the ComponentSupport.findChildByTagId() implementation), I have reported the issue RESTORE_PHASE is slow on Mojarra 2.3 #4811 |
|
We have our own Mojarra 2.3.14-build including this PR by @zjavaperf since about 3 weeks in production. We didn´t find any regression yet. (Complex enterprise-grade application for COVID-19 contact-tracing.) |
|
I finally had some time to look through this and it looks very good, thanks a lot! And extra thanks to everyone who jumped in. Since this is for the 2.3 branch, I'll do a cherry-pick for master. |
|
Awesome 👍 Thank you very much, @arjantijms! |
|
Probably we should get this into Master (=4.0.) too. |
|
I've made sure it's in 2.3 / 3.0 / 4.0. Thank you for your contribution! |
|
Just a small hint here: removeFromDescendantMarkIdCache is public now and shouldnt be published to a official "faces-api" jar |
|
Right. I'll have to review and fix this API leak. |
|
Fixed in #4905 and commented in #4811 (comment) |
|
I now realize that the PR is created by a different user than the issue ticket. @zjavaperf can you please re-assert that the performance problem doesn't regress with #4905 ? |
|
It's now merged nonetheless. |
|
It has been reverted because TCK test failed on this and blocked 2.3.15 release. We'll take a second look for next release once we've figured out the exact failing test case. |
Revert #4808 due to being possible cause of failing TCK
|
Hi @BalusC, sorry for not answering earlier, I am at the moment stumbling from one project to the next without any time left in between to look after things like this here... Trying to catch up now. Regarding the performance regression in #4811: I didn't write my patches in order to solve this particular issue... Perhaps my patches actually do solve it, but I haven't tried. I hadn't even heard about it until @wafa-ogh mentioned it a couple of comments above. I only analyzed our customer's COVID-19 tracing application, found that Mojarra was consuming a good amount of application time, thought about possible ways to improve it, and finally came up with my patches here. Regarding your refactoring: I had a cursory look at your changes and they do look good to me 👍 At first sight, I cannot see anything that would introduce additional overhead. Regarding the TCK failing: This seems weird since all test cases that come with the Mojarra integration test suite passed successfully with my patches enabled. Do you already have an idea why the TCK fails? And is this TCK you're talking about something that I can use on my laptop? Or is it only available in your build environments? If it is publicly available, I would like to try myself and see whether something in my patches breaks the TCK and if yes, what exactly makes it break. Cheers, |
|
@zjavaperf the TCK is of course fully open source. It concern over 5000 tests, which take 3 hours to run (depending on your hardware). They can be found here: https://github.com/eclipse-ee4j/jakartaee-tck/tree/master/src/com/sun/ts/tests/jsf A standalone build is available from: https://download.eclipse.org/ee4j/jakartaee-tck/jakartaee8-eftl/promoted/eclipse-faces-tck-2.3.0.zip The CI that runs this job is publicly visible: https://ci.eclipse.org/mojarra/job/2_mojarra-run-tck-against-staged-build_2_3/ This script can be taken at a guidance how to run it: https://github.com/eclipse-ee4j/jakartaee-tck/blob/master/docker/jsftck.sh The CI runs a derived script, somewhat adjusted for Jenkins/Groovy: #!/usr/bin/env groovy
node {
def API_JAR_NAME = "jakarta.faces-api.jar"
def DOWNLOAD_API_JAR_NAME = "jakarta.faces-api-2.3.2.jar"
def API_URL = "https://jakarta.oss.sonatype.org/content/repositories/staging/jakarta/faces/jakarta.faces-api/2.3.2/${DOWNLOAD_API_JAR_NAME}"
def IMPL_JAR_NAME = "jakarta.faces.jar"
def DOWNLOAD_IMPL_JAR_NAME = "jakarta.faces-${IMPL_VERSION}.jar"
def IMPL_URL = "https://jakarta.oss.sonatype.org/content/repositories/staging/org/glassfish/jakarta.faces/${IMPL_VERSION}/${DOWNLOAD_IMPL_JAR_NAME}"
def TCK_BUNDLE_URL = "https://download.eclipse.org/ee4j/jakartaee-tck/jakartaee8-eftl/promoted/eclipse-faces-tck-2.3.0.zip"
def GF_URL = "https://www.eclipse.org/downloads/download.php?file=/glassfish/glassfish-5.1.0.zip"
// TCK properties
env.deliverabledir="faces"
env.TCK_HOME="${env.WORKSPACE}"
env.TS_HOME="${env.WORKSPACE}/${env.deliverabledir}-tck"
env.javaee_home="${env.WORKSPACE}/glassfish5"
env.ANT_VERSION='1.9.15'
env.TOOLS_PREFIX='/opt/tools'
env.JAVA_PREFIX="${TOOLS_PREFIX}/java/oracle"
env.MVN_HOME="${TOOLS_PREFIX}/apache-maven/latest"
env.JAVA_HOME="${JAVA_PREFIX}/jdk-8/latest"
env.PATH="${MVN_HOME}/bin:${JAVA_HOME}/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"
env.ANT_HOME="${TS_HOME}/tools/ant"
env.PATH="${ANT_HOME}/bin:${PATH}"
env.ANT_OPTS="-Djavax.xml.accessExternalSchema=all"
stage("Init") {
// https://go.cloudbees.com/docs/cloudbees-documentation/cjoc-user-guide/index.html#cluster-copy-artifacts
dir ("download") {
// If any artefacts from other jobs need to be used, they can be placed here
// copyRemoteArtifacts(from: "${GF_BUILD_JOB}")
// copyRemoteArtifacts(from: "${TS_JTE_BUILD_JOB}")
}
sh '''#!/bin/bash -x
ls /opt/tools/java
mkdir download
'''
}
stage("Grab GF") {
env.GF_URL = "${GF_URL}"
sh '''#!/bin/bash -ex
cd ${WORKSPACE}/download
wget -q ${GF_URL} -O glassfish.zip
cd ${WORKSPACE}
unzip -q ${WORKSPACE}/download/glassfish.zip
'''
}
stage("Grab IMPL") {
env.API_URL = "${API_URL}"
env.API_JAR_NAME = "${API_JAR_NAME}"
env.IMPL_URL = "${IMPL_URL}"
env.IMPL_JAR_NAME = "${IMPL_JAR_NAME}"
sh '''#!/bin/bash -ex
# cd ${WORKSPACE}/download
# wget -q ${API_URL} -O ${API_JAR_NAME}
cd ${WORKSPACE}/download
if [ $IMPL_SOURCE == 'STAGE' ]; then
wget -q ${IMPL_URL} -O ${IMPL_JAR_NAME}
fi
if [ $IMPL_SOURCE == 'BRANCH' ]; then
mkdir mojarra-build
cd mojarra-build
git clone https://github.com/eclipse-ee4j/mojarra.git .
git checkout $IMPL_BRANCH
mvn clean install
find ./impl/target/ -name 'jakarta.faces*-SNAPSHOT.jar' -exec bash -c 'mv $0 jakarta-faces.jar' {} \\;
cp jakarta-faces.jar ${WORKSPACE}/download/${IMPL_JAR_NAME}
fi
ls -altrh ${WORKSPACE}/download/
'''
}
stage("Grab TCK") {
env.TCK_BUNDLE_URL = "${TCK_BUNDLE_URL}"
sh '''#!/bin/bash -ex
cd ${WORKSPACE}/download
wget -q ${TCK_BUNDLE_URL} -O ${deliverabledir}tck.zip
cd ${WORKSPACE}
unzip ${WORKSPACE}/download/${deliverabledir}tck.zip
'''
}
stage ("Grab ANT") {
sh '''#!/bin/bash -ex
cd ${WORKSPACE}/download
wget -q http://mirror.koddos.net/apache/ant/binaries/apache-ant-${ANT_VERSION}-bin.tar.gz -O ant.tar.gz
tar xfz ant.tar.gz
mkdir -p ${ANT_HOME} && cp -a ${WORKSPACE}/download/apache-ant-${ANT_VERSION}/. ${ANT_HOME}
'''
}
stage ("Replace IMPL in GF") {
env.API_JAR_NAME = "${API_JAR_NAME}"
env.DOWNLOAD_API_JAR_NAME = "${DOWNLOAD_API_JAR_NAME}"
env.IMPL_JAR_NAME = "${IMPL_JAR_NAME}"
env.DOWNLOAD_IMPL_JAR_NAME = "${DOWNLOAD_IMPL_JAR_NAME}"
sh '''#!/bin/bash -ex
# rm $javaee_home/glassfish/modules/${API_JAR_NAME}
# cp -v ${WORKSPACE}/download/${API_JAR_NAME} $javaee_home/glassfish/modules
rm $javaee_home/glassfish/modules/${IMPL_JAR_NAME}
cp -v ${WORKSPACE}/download/${IMPL_JAR_NAME} $javaee_home/glassfish/modules
'''
}
stage ("Configure ts.jte") {
sh '''#!/bin/bash -ex
cd ${TS_HOME}/bin/
sed -i "s#webServerHome=.*#webServerHome=$TCK_HOME/glassfish5/glassfish#g" ts.jte
sed -i "s#^webServerHost=.*#webServerHost=localhost#g" ts.jte
sed -i "s#^webServerPort=.*#webServerPort=8080#g" ts.jte
sed -i "s#^impl.vi=.*#impl.vi=glassfish#g" ts.jte
sed -i "s#^impl.vi.deploy.dir=.*#impl.vi.deploy.dir=$TCK_HOME/glassfish5/glassfish/domains/domain1/autodeploy#g" ts.jte
sed -i "s#^jsf.classes=.*#jsf.classes=${webServerHome}/modules/cdi-api.jar;${webServerHome}/modules/jakarta.servlet.jsp.jstl-api.jar;${webServerHome}/modules/jakarta.inject.jar;${webServerHome}/modules/jakarta.faces.jar;${webServerHome}/modules/jakarta.servlet.jsp-api.jar;${webServerHome}/modules/jakarta.servlet-api.jar;${webServerHome}/modules/jakarta.el.jar#g" ts.jte
sed -i 's#^impl.deploy.timeout.multiplier=.*#impl.deploy.timeout.multiplier=960#g' ts.jte
sed -i "s#^report.dir=.*#report.dir=$TCK_HOME/${TCK_NAME}report/${TCK_NAME}#g" ts.jte
sed -i "s#^work.dir=.*#work.dir=$TCK_HOME/${TCK_NAME}work/${TCK_NAME}#g" ts.jte
'''
}
stage("Restart GF") {
sh '''#!/bin/bash -ex
cd $javaee_home/bin
./asadmin stop-domain
if [ $retval != 0 ]; then
echo "Pending process to be killed:"
ps -eaf | grep "com.sun.enterprise.admin.cli.AdminMain" | grep -v "grep" | grep -v "nohup"
for i in `ps -eaf | grep "com.sun.enterprise.admin.cli.AdminMain" | grep -v "grep" | grep -v "nohup" | tr -s " " | cut -d" " -f2`
do
echo "[killJava.sh] kill -9 $i"
kill $i
done
fi
./asadmin start-domain
'''
}
stage("Configure TCK") {
sh '''#!/bin/bash -ex
echo cat log
cat $javaee_home/glassfish/domains/domain1/logs/server.log
cd $TS_HOME/src/com/sun/ts/tests/jsf
ant -Dutil.dir=$TS_HOME deploy.all || true
cat $javaee_home/glassfish/domains/domain1/logs/server.log
OUT=$?
if [ $OUT -ne 0 ];then
cat $javaee_home/glassfish/domains/domain1/logs/server.log
exit $OUT;
fi
'''
}
stage ("Run TCK tests") {
sh '''#!/bin/bash -x
SHA256_IMPL=`sha256sum ${TCK_HOME}/glassfish5/glassfish/modules/${IMPL_JAR_NAME} | awk '{print $1}'`
SHA256_TCK=`sha256sum ${WORKSPACE}/download/${deliverabledir}tck.zip | awk '{print $1}'`
echo SHA256_IMPL=${SHA256_IMPL}
echo SHA256_TCK=${SHA256_TCK}
echo Product_download=${GF_URL}
echo IMPL_download=${IMPL_URL}
echo TCK_download=${TCK_BUNDLE_URL}
OS1=`lsb_release -a || true`
OS2=`cat /etc/issue.net || true`
OS3=`cat /etc/*_version || true`
OS4=`cat /etc/*-release || true`
if [ ! -z "${OS1}" ]; then
echo OS1=${OS1}
fi
if [ ! -z "${OS2}" ]; then
echo OS2=${OS2}
fi
if [ ! -z "${OS3}" ]; then
echo OS3=${OS3}
fi
if [ ! -z "${OS4}" ]; then
echo OS4=${OS4}
fi
JDK_VERSION=$(java -version 2>&1 || true)
echo JDK_VERSION=${JDK_VERSION}
cd $TS_HOME/src/com/sun/ts/tests/jsf
ant -Dutil.dir=$TS_HOME runclient | tee -a ${TS_HOME}/bin/run.log
'''
}
stage ("Create summary.txt, API, and run.log artifacts") {
sh '''#!/bin/bash -ex
cd ${TS_HOME}/bin
cat run.log | sed -e '1,/Completed running/d' > summary.txt
PASSED_COUNT=`head -1 summary.txt | tail -1 | sed 's/.*=\\s\\(.*\\)/\\1/'`
FAILED_COUNT=`head -2 summary.txt | tail -1 | sed 's/.*=\\s\\(.*\\)/\\1/'`
ERROR_COUNT=`head -3 summary.txt | tail -1 | sed 's/.*=\\s\\(.*\\)/\\1/'`
echo ERROR_COUNT=${ERROR_COUNT}
echo FAILED_COUNT=${FAILED_COUNT}
echo PASSED_COUNT=${PASSED_COUNT}
SHA256_IMPL=`sha256sum ${TCK_HOME}/glassfish5/glassfish/modules/${IMPL_JAR_NAME} | awk '{print $1}'`
SHA256_TCK=`sha256sum ${WORKSPACE}/download/${deliverabledir}tck.zip | awk '{print $1}'`
echo SHA256_IMPL=${SHA256_IMPL} | tee -a summary.txt
echo SHA256_TCK=${SHA256_TCK} | tee -a summary.txt
echo Product_download=${GF_URL} | tee -a summary.txt
echo IMPL_download=${IMPL_URL} | tee -a summary.txt
echo TCK_download=${TCK_BUNDLE_URL} | tee -a summary.txt
OS1=`lsb_release -a || true`
OS2=`cat /etc/issue.net || true`
OS3=`cat /etc/*_version || true`
OS4=`cat /etc/*-release || true`
if [ ! -z "${OS1}" ]; then
echo OS1=${OS1} | tee -a summary.txt
fi
if [ ! -z "${OS2}" ]; then
echo OS2=${OS2} | tee -a summary.txt
fi
if [ ! -z "${OS3}" ]; then
echo OS3=${OS3} | tee -a summary.txt
fi
if [ ! -z "${OS4}" ]; then
echo OS4=${OS4} | tee -a summary.txt
fi
JDK_VERSION=$(java -version 2>&1 || true)
echo JDK_VERSION=${JDK_VERSION} | tee -a summary.txt
'''
archiveArtifacts artifacts: "${env.deliverabledir}-tck/bin/summary.txt", fingerprint: true
archiveArtifacts artifacts: "${env.deliverabledir}-tck/bin/run.log", fingerprint: true
archiveArtifacts artifacts: "glassfish5/glassfish/modules/${IMPL_JAR_NAME}", fingerprint: true
}
} |
|
Hi @arjantijms, thanks for all the infos! As I wrote in my last comment, I'm currently pretty swamped with high priority work. Therefore, I cannot give you an exact outlook when I will be able to actually work on this. I will try, however, to take some time aside during the next couple of days. Cheers, |
|
Hello, Thank you all, the fix proposed here has fixed RESTORE_PHASE is slow on Mojarra 2.3 #4811 I have added some test results here |
|
@wafa-ogh Awesome - it's really nice to hear that my patch has this nice "side-effect" of fixing the performance regression you observed although I haven't specifically designed it for it. And also a big thanks to both @BalusC and @arjantijms for taking care of integrating my patch into the various releases 👍 |
Hi,
this is Marc from IBM. Not sure where the right place to say "Hello" is, so I will try here. Since I haven't contributed to Mojarra yet, let me quickly introduce myself. I am a Java Performance Analyst and work in the IBM Lab in Boeblingen, Germany. Nowadays, I spend most of my time improving the performance of IBM products, but I also have a long history of analyzing and optimizing the performance of customer Java applications.
One of our IBM Mainframe customers is running their COVID-19 tracing application based on Eclipse Mojarra and they asked me to analyze its performance, since they are struggling with the high amount of CPU that their application consumes. I found a number of tuning opportunities in the Mojarra code, and this patch here is one of them. Since the customer hasn't been able to test my patches yet, I can only provide an educated guess, but my expectation is that the combination of all patches will save ca. 20-25% of all Java method calls in the customer's situation.
Let me explain my
findChildByTagId()patch a bit: In the original version of the code, the logic inComponentSupport.javaperforms a BFS for the child withMARK_ID"id". While this works very well in small component trees, it quickly becomes quite a heavy call when the component tree underneath of the "parent"UIComponentis large. In the customer's situation, I have seen tree depths of up to 12 and breadths of the individual nodes of more than 140 in the traces. So you can imagine how many visits it may take until the search is complete. This is particularly heavy when the child doesn't exist and the entire tree has to be searched almost all of the time.What my patch does is that it stores the
MARK_IDs of all descendants of aUIComponentin a hash map that belongs to the component, along with references to the descendant components. I called this thedescendantMarkIdCache. Now whenfindChildByTagId()is called inComponentSupport, the only operation that has to be performed is a lookup thedescendantMarkIdCachehash map of "parent". There is no more searching in the component tree.Of course, remembering all descendants of a component in a hash map comes at a certain cost, but I have done a number of measurements in order to validate the effectiveness of my patch and the outcome was that it is still much cheaper compared to the current BFS approach. In one test case, the pages/sec throughput increased by ca. 23%, which is equivalent to ca. 18% savings in CPU consumption. The more complex - i.e. nested - the Facelet is, the more the
descendantMarkIdCachepays off.I still have to perform a more in depth analysis regarding the additional Java heap consumption caused by the
findChildByTagId()patch, but from my initial cursory check the increase in heap consumption should be rather moderate.I have run every Mojarra integration test that completed successfully without my patches also with my patches enabled: glassfish, javaee6/6web/7/8, servlet30/31/40. The outcome was that all integration tests passed successfully.
I am really looking forward to your comments on this patch!
Cheers,
Marc
Signed-off-by: Marc Beyerle marc.beyerle@de.ibm.com