You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Christopher Schultz <ch...@christopherschultz.net> on 2014/03/05 02:50:29 UTC
Performance drop under load for Tomcat8/DBCP2 with respect to Tomcat
7/DBCP1
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256
All,
I've been piloting Tomcat 8 in my development environment on and off
for the last few months, and I just started working on some new
functionality that causes a #*(%^storm of JDBC activity: I have a main
page which loads dozens of images, which are actually SVGs built on
the fly by pulling similar data from the database.
This has all been working for several years, and I added some caching
at the very start because most of this data all comes from the same
place, so the first image to be loaded ends up doing the hard work
while the others wait for the cached data to become available, then
everything goes quickly after that with very little CPU usage, etc.
Now, I'm trying to load a different image simultaneously that uses
similar data yet different. This causes the two pieces of code to
fight over the cached data in a way that essentially continuously
invalidates the cache. I'll get that worked out myself because it's a
bad situation in general, but I have observed that when I run this
under Tomcat 7, it takes a long time (on the order of maybe 5 seconds)
to fulfill the request, but it makes steady progress.
When I run under Tomcat 8.0.3, a couple of the images are loaded, and
then the whole ... thing ... just ... stops. If I watch my log4j log
file, every so often a flurry of activity occurs: several pieces of
information are actually fetched from the database, and progress is
made. But I have waited like 10 minutes and the series of requests
never finishes in that time.
(Something odd I can see: when that small amount of progress is made,
the idle connection in MySQL *remains* idle. The only conclusion I can
come to is that a new connection is being created to fetch that data
and then it's being dropped, or that something is giving up somewhere
without telling me. Neither conclusion makes much sense. I haven't
actually confirmed that any real progress is made... just that I can
see "loading XYZ from db" in my log files... those messages are logged
*before* the data is loaded so I don't know it has been at this point).
Thread dumps show that everything is waiting on:
- org.apache.tomcat.dbcp.dbcp2.BasicDataSource.getConnection()
@bci=55, line=1385 (Interpreted frame)
It's not that large a number of threads. It's something like 30-40
threads waiting on connections. (I'm not entirely sure why there are
so many threads active... I'm the only one using this environment and
I made a single top-level request... I thought most browsers limited
their outgoing connections to something like 8 per hostname, but that
appears not to be the case).
I have a variety of methods in operation at that time, but they are
all waiting on a database connection.
My DataSource configuration:
<Resource name="jdbc/diagnosis"
description="JDBC connection to main CHADIS database"
auth="Container"
type="javax.sql.DataSource"
maxActive="1"
maxIdle="1"
maxWait="10000"
url="[url]"
username="[user]"
password="[user]"
driverClassName="com.mysql.jdbc.Driver"
removeAbandoned="true"
removeAbandonedTimeout="30"
logAbandoned="true"
testOnBorrow="true"
validationQuery="/* ping */ SELECT 1"
/>
Note that I have a single database connection in the pool. This is to
catch any potential deadlocks in my JDBC code, and to catch abandoned
resources as soon as possible. I get *no warnings* about abandoned
anything. I don't even get timeouts waiting for connections from the
pool (there is supposed to be a 10-second connection timeout waiting
for a connection from the pool... those timeouts do not appear to be
happening... they should trigger exceptions in my log file). The MySQL
database reports that the connection held by my web application is
completely idle, and sits there doing nothing. No query is in progress.
It looks like DBCP2 is kind of hosing, here.
I don't have a simple test case right now, unfortunately, but I do
know that it has worked every time (maybe a dozen times) under Tomcat
7.0.47 and failed every time (maybe 5 times, now) under Tomcat 8.0.3.
I'm going to try using tomcat-pool to see if it makes any difference.
I suspect it will, since they are completely different architectures.
Any suggestions?
- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1
Comment: GPGTools - http://gpgtools.org
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
iQIcBAEBCAAGBQJTFoLjAAoJEBzwKT+lPKRYMOIP/3HestrhGen4GMPRTDpM5VJN
5kW8dxlPJ4U9vLioLk9FgvLVWdPOsaHQpzWP0rII2qvynhb1XIf/D3idRCOsQ9Q8
jxjDxEMhX2RRuMjqZES5ACY1CxhaElBcfzYI39Gh0hPfqdotilQ/3U+7yCR7N0F/
NbGmjYFSOBXgPFYwMGTB6Z7cXq+PyAcz0H7N7sc6vFOqBY4cjwFKTNkacxyogCcP
a163TFqdo5FbZ5zat76QHy96SkFLzT9wez7tMWJLyQlSA2XUHgyj0ch9THCvfNea
o+PVkClnR2Cz5PCJKRTZ5X+14Gs/oSquRSlsqjlA78trDnJu2joC7KfE7WwnkwdT
WCkDepAoSD5SSH4YWLz2PScp3vNl1sZ6cQVSJ0IjfQdDkSt62jzbjUoNbnSEEC0s
hi3ChqoZoB1s+bY+eM3Yd70Fwv5YGlDEsPaemmwz3psZt+xw8/8NeH+a+KABVM6S
azIblSM9Gsq0Knv2LJeTzby8SxO4Luqcyf5b0M+USeWrEXxiFpDv2VtHCeqwnaLD
9ojx5AGvlbJN/WXYCXvHS60FYdhlZIWXltrkO7FticbEkJUC5ptNMfPfHqCcf+KG
CbaMs6QiAKmlPDQ+f5tQXOvnwR8eB9jdkwjkicjXogwmvKmLh6luVuq5+TyGD/0s
f4dzoI/10l9h/RivLSnB
=qNjE
-----END PGP SIGNATURE-----
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Performance drop under load for Tomcat8/DBCP2 with respect to
Tomcat 7/DBCP1
Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256
All,
On 3/5/14, 4:43 PM, Christopher Schultz wrote:
> All,
>
> On 3/5/14, 10:01 AM, Christopher Schultz wrote:
>> Oddly enough, things seem to work with only an updated
>> configuration: setting maxInitial and maxTotal instead of
>> maxActive and maxWaitMillis instead of maxWait (actually, I have
>> both sets of configuration in there, so I can start Tomcat 7 or
>> Tomcat 8 with the same context.xml file). It still takes 5
>> seconds to render the whole page, but that's /my/ problem, now
>> ;)
>
> I spoke too soon: it's still locking-up intermittently with
> 8.0.3... hard to reproduce at this point.
>
> I'll try with trunk as well.
After spending some time on this with a trunk build, I can't seem to
lock-up the connection pool, so I'm thinking this is likely to be
fixed -- likely by the fix for POOL-248.
Thanks for the pointers, Mark.
- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1
Comment: GPGTools - http://gpgtools.org
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
iQIcBAEBCAAGBQJTGe3iAAoJEBzwKT+lPKRY1ioP+gPF+zg9i52QbD1LDYjTmhXm
dfqchx0EsQ6px8nvkX8uOL2xfDZ4jGEmbslZMG2LQjdiqVwC1ZUZcg1SkNJysrAS
uUKSLVjpyg4Xo+4MAiRX+/DM1r6Z8ZwnqVQ0yjqqHF4vs2G2BvX3uf2gN1WM1tMG
eeOCPbRertanpgMqJi65VZw/ugFr/bv2d7/49qi3hr993HsCdivwYD4b85mrGDi3
HYh7MiihK9jrkZf7z4jiMniWV1rbNlmZwSbiw9aqThrA1K/Qpx0Q8Ac+c6g1GUn8
80YOI0jAuivhHyR21QAr+3x5G66xJ0iPP8sSC1/C67GNEih6HaN2OcHdDRbRATmr
CpLHzEmNZ/sWN7btALNesH24ypfEGMCm1lJsDcLuStFf3zilFPYTI4v+YnZsTzxz
cIaCCX8WW/2bHTFJSCrVmnxQW1JeoZL0BD4btMVttLpsRT7mMgjS2/NGv3aSKQ+X
ukID59AdCZti7Y7FHA52q+ILDHaGsj3naFaHUQfRdnLA+WBOX4WK3u9orQZt48i1
egFbXMXu5mwIJ8ti8BJZDsfn6SHLj6IaaYUHDwnzx7g2Lucj55czO/j9y+nkKNDZ
IdUQTT56ioOlGTXd244FrT7u/qJB61fodlNpfqv99s88uwZEfSxGAcnzwayorEIP
pdrFBe92SBRu09r9XOeD
=ZsHN
-----END PGP SIGNATURE-----
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Performance drop under load for Tomcat8/DBCP2 with respect to
Tomcat 7/DBCP1
Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256
All,
On 3/5/14, 10:01 AM, Christopher Schultz wrote:
> Oddly enough, things seem to work with only an updated
> configuration: setting maxInitial and maxTotal instead of maxActive
> and maxWaitMillis instead of maxWait (actually, I have both sets of
> configuration in there, so I can start Tomcat 7 or Tomcat 8 with
> the same context.xml file). It still takes 5 seconds to render the
> whole page, but that's /my/ problem, now ;)
I spoke too soon: it's still locking-up intermittently with 8.0.3...
hard to reproduce at this point.
I'll try with trunk as well.
- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1
Comment: GPGTools - http://gpgtools.org
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
iQIcBAEBCAAGBQJTF5p5AAoJEBzwKT+lPKRYXtAQAIGKEHafS1UdWQ6oO++cqgqa
Fl2a8opuvOaFzy2t6tMDImQzZptFevlNHzf9YtUWngTAdKB4wQ0fbRgr1jNIiRNC
KjndgisEWywA6+iU//+CRav9sdrCbS5GXA0cI2a/cxckyaslTFYo37jD02CgrUFG
Rbcp1pERfufidHE6nKSwe6LlsbUC3baWuUXPQ+Rw8R0n4Xg+DDtIqKezAqGnB5kW
efPXeCDkEJzQKqK4Z7Tsv36BJUhQvyIZa5OrFITQdxEJHRJ+TI24y6LEs1DrVo2o
uAXMlKq8rDLxIbHV6kKDaMPu67+BNswdNBaKp17g3ha+t235l0LTAI55ODNx4wMw
GEyFHFtz0xtRNbAvcWbKX/anjKC1Gz2AGALVy5OsNho6ZQbBVSLPsaXNskEhhsSX
G47bcwms10YVbFBSMinh3QWqM9GhrxMlWt5mIcav74hf73R3J8PAH2ri2SDM69/M
rcpyGSPKgZ6JHYNiN5+LaiKHOE9+pl08unLIYvmMln3BF6sYSD+J4vqjoiYJHqiz
P0B5/hIIvQDRQPMX88eZ8Zt6Uur2F0eTPAPyx3CczE9JhZYVw9Yb87lcA0mJczxG
A9OpQQqs2gf+6Q1+AUJjTIReqsRIZbKvK+BPYOFIPTTbTo5qbCoGYbhCzjMkSuTv
bTTEIJ0shtxkULT9KnHv
=m6GW
-----END PGP SIGNATURE-----
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Performance drop under load for Tomcat8/DBCP2 with respect to
Tomcat 7/DBCP1
Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256
Mark,
On 3/5/14, 9:48 AM, Christopher Schultz wrote:
> Mark,
>
> On 3/5/14, 8:56 AM, Mark Thomas wrote:
>> On 05/03/2014 13:38, Christopher Schultz wrote:
>>>>> My DataSource configuration:
>
>>>>> <Resource name="jdbc/diagnosis" description="JDBC
>>>>> connection to main CHADIS database" auth="Container"
>>>>> type="javax.sql.DataSource" maxActive="1" maxIdle="1"
>>>>> maxWait="10000" url="[url]" username="[user]"
>>>>> password="[user]" driverClassName="com.mysql.jdbc.Driver"
>>>>> removeAbandoned="true" removeAbandonedTimeout="30"
>>>>> logAbandoned="true" testOnBorrow="true"
>>>>> validationQuery="/* ping */ SELECT 1" />
>
>>>>> Note that I have a single database connection in the pool.
>
>>>> Not with DBCP 2 you don't. maxActive has been renamed to
>>>> maxTotal so you'll have the default (8 from memory)
>>>> connections in the pool. This is likely to be a common
>>>> problem. We probably need to add something to catch this,
>>>> report a warning and set the correct attribute.
>
>>> Okay, I'll take a look at that. What I can observe practically
>>> is that only a single connection to my MySQL database has been
>>> made, whatever the reason. Perhaps that's part of the trouble.
>
>> Hmm. I don't recall exactly when this was renamed in DBCP 2. It
>> is always possible the build you are using does what you think
>> it does.
>
> I checked the configuration reference for DBCP 2, and two
> important configuration properties were renames:
> maxActive->maxTotal and maxWait->maxWaitMillis. When a connection
> couldn't be obtained (for whatever reason... possibly POOL-248),
> the checkout was waiting forever instead of timing-out after 10
> seconds.
>
> I'm re-testing with the modified configuration, but still with a
> stock 8.0.3.
Oddly enough, things seem to work with only an updated configuration:
setting maxInitial and maxTotal instead of maxActive and maxWaitMillis
instead of maxWait (actually, I have both sets of configuration in
there, so I can start Tomcat 7 or Tomcat 8 with the same context.xml
file). It still takes 5 seconds to render the whole page, but that's
/my/ problem, now ;)
I'll see if I can tell what the difference is between the two
configurations using JMX. When using maxActive, I should have gotten
the default of 8 connections but instead I got a single connection
that got stuck somehow under some load (authentication and initial
page-load worked, so the connection /was/ available at some point).
- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1
Comment: GPGTools - http://gpgtools.org
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
iQIcBAEBCAAGBQJTFzxBAAoJEBzwKT+lPKRYnGYQALVDmUdeBGkZPTdv7c6pmbQG
t/aAK49JCjrOZ2CRgdwbNgBNByeTY6dpBVtp/S9S9yigYRkfGq0Dlkp0496rGtyz
1ihR0g3Af37DCaQiBKgJEYlhVJGvpNBTPTQYhX1U0kbv0e807nfYrqXmk0YguKeM
z2Ca6GxhlNy8uW/FWhXraSICCFV4crrMn9r01qPcOPjLhCRm0yqBLJzRHKY8XSEK
UsDBMp9J93gOAf5wh7mqFUEVbJ4RbPouP7UmgSqAiv1kUHoGpMCNBtu8P1CFjIQh
7vSCe89+UIkJPPi2QN4qZ9atF/LZYyEer9tAPF6SHpGk7C4UFEG16AdDtPBxuYDE
zw5HZqrl1y/Ugrr62+MOrIjYMzecCTgAAOPdzkqc+Dh+BGgZaHKPg/Bvz9Ch+Doo
tythI27HxFyMCAXSwm17BRtCHwbxVAzM6V3q5Ns4KMc+tNwwyxxTHhQdfCIpYnXQ
2A2iOMGy6WFxHy8FR1dljdVp2zxJN3W+xNGESw/1y0DmKkC1HI49i/o4aV+mXD1V
e7wI7jBJLKZ6X8J7AbWJp4NzEykHVqlWRdr07nPcWlQN5pd9sJSB6f15OtgDkw+o
iTRLZ642lMtyNWD8jhCDcnZNG+Q5G2h2eLmhbaFCgfnsOynNQpe2T47jZJYnrzcI
JPmg/zqYsxMBfI7kHnK5
=tWti
-----END PGP SIGNATURE-----
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Performance drop under load for Tomcat8/DBCP2 with respect to
Tomcat 7/DBCP1
Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256
Mark,
On 3/5/14, 8:56 AM, Mark Thomas wrote:
> On 05/03/2014 13:38, Christopher Schultz wrote:
>>>> My DataSource configuration:
>
>>>> <Resource name="jdbc/diagnosis" description="JDBC connection
>>>> to main CHADIS database" auth="Container"
>>>> type="javax.sql.DataSource" maxActive="1" maxIdle="1"
>>>> maxWait="10000" url="[url]" username="[user]"
>>>> password="[user]" driverClassName="com.mysql.jdbc.Driver"
>>>> removeAbandoned="true" removeAbandonedTimeout="30"
>>>> logAbandoned="true" testOnBorrow="true" validationQuery="/*
>>>> ping */ SELECT 1" />
>
>>>> Note that I have a single database connection in the pool.
>
>>> Not with DBCP 2 you don't. maxActive has been renamed to
>>> maxTotal so you'll have the default (8 from memory)
>>> connections in the pool. This is likely to be a common problem.
>>> We probably need to add something to catch this, report a
>>> warning and set the correct attribute.
>
>> Okay, I'll take a look at that. What I can observe practically
>> is that only a single connection to my MySQL database has been
>> made, whatever the reason. Perhaps that's part of the trouble.
>
> Hmm. I don't recall exactly when this was renamed in DBCP 2. It is
> always possible the build you are using does what you think it
> does.
I checked the configuration reference for DBCP 2, and two important
configuration properties were renames: maxActive->maxTotal and
maxWait->maxWaitMillis. When a connection couldn't be obtained (for
whatever reason... possibly POOL-248), the checkout was waiting
forever instead of timing-out after 10 seconds.
I'm re-testing with the modified configuration, but still with a stock
8.0.3.
- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1
Comment: GPGTools - http://gpgtools.org
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
iQIcBAEBCAAGBQJTFzk3AAoJEBzwKT+lPKRYAs0P/0/nCg1LQnTnemwrDgExFkXW
HtONMDSyJE77UrIemf+apSBq0OU34Vym4tBJf8asx+kyRSZifVWQp01lzl9CPZm7
d5RIfbsvfCimafsKGipqAFskNeFNCXH6RNEMwcAR0gMBijIlQd0IArL9OOuSJVHA
OrYaq38Yi56Tq2ENcjDTn+fjyJ/IEcluNuoI2lBqgTM3UmRxF1ItjditTzTkC4NW
oc3BLguoyOokOymJ9AQn2PuP0EtrrwnWS69Q/HiKaNLmrawVGDqoA2QDjlZF3XkM
Q2hP4EJSoDPFxIrTF+JiEv6pPt2PbtlC+JrjT04tJdnApl29Q2zalHdnudOSO9M5
80ivyU7mEgW1gwR5m48FKGZGB8l5UkQu+RdvvhvTfipqmN5rdqP/NjSsRok13YiV
HqE3g/8bcAMejDAjl916xa68npRXQLHPmKJMMSoc6Ri731INKflsAukScc5EIMmi
BI/EiJXgyNUK2L5MaWGgjrHNyzIlo1v8WFZAoMw0u5BtnNeWRSs/TE43sYUuiosu
FC8mJzg6U0f1CdSCCuIvm7Z3BwK4x9VW8ox30DomPA3Fs+p8O3PwAhLfjGEnMfDN
YgBmgS1WcXEfCQZZ5+VLrW7IiVotUB+3rY+Fd6Alo/vweXf230jJWIMY+BMa86rD
kk30PQpoyViGIztqxyHZ
=SLmC
-----END PGP SIGNATURE-----
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Performance drop under load for Tomcat8/DBCP2 with respect to
Tomcat 7/DBCP1
Posted by Mark Thomas <ma...@apache.org>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
On 05/03/2014 13:38, Christopher Schultz wrote:
> Mark,
>
> On 3/5/14, 3:32 AM, Mark Thomas wrote:
>> On 05/03/2014 01:50, Christopher Schultz wrote:
>
>> <snip/>
>
>>> When I run under Tomcat 8.0.3, a couple of the images are
>>> loaded, and then the whole ... thing ... just ... stops. If I
>>> watch my log4j log file, every so often a flurry of activity
>>> occurs: several pieces of information are actually fetched
>>> from the database, and progress is made. But I have waited like
>>> 10 minutes and the series of requests never finishes in that
>>> time.
>
>> I'd suggest compiling 8.0.x from trunk as that is now using the
>> released DBCP 2.0 and Pool 2.2. There was a pool issue
>> (POOL-248) that was fixed after the 8.0.x release that might have
>> caused this.
>
> I was thinking about that last night. I also saw the commit that
> upgrades to the DBCP2 release version, which was what really
> triggered that thought. Can you point me to the JIRA issue you were
> specifically thinking could be what I'm encountering?
POOL-248.
>>> (Something odd I can see: when that small amount of progress is
>>> made, the idle connection in MySQL *remains* idle. The only
>>> conclusion I can come to is that a new connection is being
>>> created to fetch that data and then it's being dropped, or
>>> that something is giving up somewhere without telling me.
>>> Neither conclusion makes much sense. I haven't actually
>>> confirmed that any real progress is made... just that I can see
>>> "loading XYZ from db" in my log files... those messages are
>>> logged *before* the data is loaded so I don't know it has been
>>> at this point).
>
>> Take a look at the pool with JMX. Again, if you work with trunk
>> you'll get lots of detail of exactly what each connection is
>> doing.
>
> I'll do that.
>
>
>>> Thread dumps show that everything is waiting on:
>
>>> - org.apache.tomcat.dbcp.dbcp2.BasicDataSource.getConnection()
>>> @bci=55, line=1385 (Interpreted frame)
>
>>> It's not that large a number of threads. It's something like
>>> 30-40 threads waiting on connections. (I'm not entirely sure
>>> why there are so many threads active... I'm the only one using
>>> this environment and I made a single top-level request... I
>>> thought most browsers limited their outgoing connections to
>>> something like 8 per hostname, but that appears not to be the
>>> case).
>
>> While that doesn't rule out a DBCP issuee, it does suggest that
>> there is at least something else going on that you need to get
>> to the bottom of.
>
> I need to re-run the test again, but I have a new theory after
> watching nothing but the log files and the number of stuck-threads
> in jstack on my previous run: Firefox is giving-up on the
> connections that never returned any data and closes them, making
> new requests to take their place.
>
> My evidence is that when the "primary" request completes (that's
> the one that generates the HTML page that requires follow-up
> resources), only a few threads get stuck (immediately). After some
> time interval (exactly 5 minutes), I get another flurry of "Loading
> data" lines in my log file and another set of threads gets stuck
> waiting on a connection.
>
>>> My DataSource configuration:
>
>>> <Resource name="jdbc/diagnosis" description="JDBC connection to
>>> main CHADIS database" auth="Container"
>>> type="javax.sql.DataSource" maxActive="1" maxIdle="1"
>>> maxWait="10000" url="[url]" username="[user]" password="[user]"
>>> driverClassName="com.mysql.jdbc.Driver" removeAbandoned="true"
>>> removeAbandonedTimeout="30" logAbandoned="true"
>>> testOnBorrow="true" validationQuery="/* ping */ SELECT 1" />
>
>>> Note that I have a single database connection in the pool.
>
>> Not with DBCP 2 you don't. maxActive has been renamed to
>> maxTotal so you'll have the default (8 from memory) connections
>> in the pool. This is likely to be a common problem. We probably
>> need to add something to catch this, report a warning and set the
>> correct attribute.
>
> Okay, I'll take a look at that. What I can observe practically is
> that only a single connection to my MySQL database has been made,
> whatever the reason. Perhaps that's part of the trouble.
Hmm. I don't recall exactly when this was renamed in DBCP 2. It is
always possible the build you are using does what you think it does.
>> You can also drop the validationQuery. DBCP2 will use isValid()
>> which is just as fast and frequently faster.
>
> Okay. For my remaining tests, I'll leave things alone.
>
> (Why would isValid be better? Is it because the driver itself can
> determine the fastest way to test the connection's validity?
Yes.
Mark
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (MingW32)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
iQIcBAEBAgAGBQJTFy0NAAoJEBDAHFovYFnnAwsQAPeHLWrK5Q8uANmrxqau+9/y
rLkiODMTXPDvQbqod2AavqKKX+uLGQzyEI2mw4svuE+rca0Q37TfXNGsfK9F6u3x
NzJl91VaXOyT/3fuHfGeYHWmwdM1uT1QrK8ISRmf0eZEN9YSqk96rPnx/iB1UvYz
lxCbzndn5qVxwz/t1gMhW9WYTYGNQpMnFUtMt+G1m/yQ+uSs0kN1v5Ns6ppK8Q3S
RizQYWrUr8P1K/IsmuVnWOBLuNJJxaufGa3C3T6qFumGSDibiTgR/NwMeVpZ3JIa
r8t0XJrDZBw4MJqS2I2ns9sYeBecCbUn5EvAp5VDOTBoGmagk6ZBJOschREw8NFb
6VFx3Ke0cH4dL8baEybSr4a/lMeg6uX12nwkLVWHu0ZWkgOqRD1VWBGqWj5JN1eK
761WtLzPsEw2EzpzoGfuT2EEuK1Iq0FQTbmfbffJLgNHZ4u9HX0hRxIpIAfU+ThH
/8WazFGKORQt44pVFK5JyZ3h7iqN7M/hawcYl+JgePzhokYgRae8hYGDJLLihHlp
8KYgMk0IDRSCcp4CTmvDjKlq4CcLfpI6sUSNu6AS5Xv9XowOM+F+83V0lzZtCFoU
kY0k2j8kwDS51dFMXws6VZOyqos2gQpSvK/VL+Ku5xaxeNbAEHYLhW0X7wCRsssD
6ihY3xEhdBJt2e2PTisJ
=CB4N
-----END PGP SIGNATURE-----
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Performance drop under load for Tomcat8/DBCP2 with respect to
Tomcat 7/DBCP1
Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256
Mark,
On 3/5/14, 3:32 AM, Mark Thomas wrote:
> On 05/03/2014 01:50, Christopher Schultz wrote:
>
> <snip/>
>
>> When I run under Tomcat 8.0.3, a couple of the images are
>> loaded, and then the whole ... thing ... just ... stops. If I
>> watch my log4j log file, every so often a flurry of activity
>> occurs: several pieces of information are actually fetched from
>> the database, and progress is made. But I have waited like 10
>> minutes and the series of requests never finishes in that time.
>
> I'd suggest compiling 8.0.x from trunk as that is now using the
> released DBCP 2.0 and Pool 2.2. There was a pool issue (POOL-248)
> that was fixed after the 8.0.x release that might have caused
> this.
I was thinking about that last night. I also saw the commit that
upgrades to the DBCP2 release version, which was what really triggered
that thought. Can you point me to the JIRA issue you were specifically
thinking could be what I'm encountering?
>> (Something odd I can see: when that small amount of progress is
>> made, the idle connection in MySQL *remains* idle. The only
>> conclusion I can come to is that a new connection is being
>> created to fetch that data and then it's being dropped, or that
>> something is giving up somewhere without telling me. Neither
>> conclusion makes much sense. I haven't actually confirmed that
>> any real progress is made... just that I can see "loading XYZ
>> from db" in my log files... those messages are logged *before*
>> the data is loaded so I don't know it has been at this point).
>
> Take a look at the pool with JMX. Again, if you work with trunk
> you'll get lots of detail of exactly what each connection is
> doing.
I'll do that.
>
>> Thread dumps show that everything is waiting on:
>
>> - org.apache.tomcat.dbcp.dbcp2.BasicDataSource.getConnection()
>> @bci=55, line=1385 (Interpreted frame)
>
>> It's not that large a number of threads. It's something like
>> 30-40 threads waiting on connections. (I'm not entirely sure why
>> there are so many threads active... I'm the only one using this
>> environment and I made a single top-level request... I thought
>> most browsers limited their outgoing connections to something
>> like 8 per hostname, but that appears not to be the case).
>
> While that doesn't rule out a DBCP issuee, it does suggest that
> there is at least something else going on that you need to get to
> the bottom of.
I need to re-run the test again, but I have a new theory after
watching nothing but the log files and the number of stuck-threads in
jstack on my previous run: Firefox is giving-up on the connections
that never returned any data and closes them, making new requests to
take their place.
My evidence is that when the "primary" request completes (that's the
one that generates the HTML page that requires follow-up resources),
only a few threads get stuck (immediately). After some time interval
(exactly 5 minutes), I get another flurry of "Loading data" lines in
my log file and another set of threads gets stuck waiting on a connection.
>> My DataSource configuration:
>
>> <Resource name="jdbc/diagnosis" description="JDBC connection to
>> main CHADIS database" auth="Container"
>> type="javax.sql.DataSource" maxActive="1" maxIdle="1"
>> maxWait="10000" url="[url]" username="[user]" password="[user]"
>> driverClassName="com.mysql.jdbc.Driver" removeAbandoned="true"
>> removeAbandonedTimeout="30" logAbandoned="true"
>> testOnBorrow="true" validationQuery="/* ping */ SELECT 1" />
>
>> Note that I have a single database connection in the pool.
>
> Not with DBCP 2 you don't. maxActive has been renamed to maxTotal
> so you'll have the default (8 from memory) connections in the pool.
> This is likely to be a common problem. We probably need to add
> something to catch this, report a warning and set the correct
> attribute.
Okay, I'll take a look at that. What I can observe practically is that
only a single connection to my MySQL database has been made, whatever
the reason. Perhaps that's part of the trouble.
> You can also drop the validationQuery. DBCP2 will use isValid()
> which is just as fast and frequently faster.
Okay. For my remaining tests, I'll leave things alone.
(Why would isValid be better? Is it because the driver itself can
determine the fastest way to test the connection's validity? For
MySQL, the /* ping */ in the validationQuery gets the job done without
issuing the query at all, which is nice.)
>> It looks like DBCP2 is kind of hosing, here.
>
>> I don't have a simple test case right now, unfortunately, but I
>> do know that it has worked every time (maybe a dozen times)
>> under Tomcat 7.0.47 and failed every time (maybe 5 times, now)
>> under Tomcat 8.0.3.
>
>> I'm going to try using tomcat-pool to see if it makes any
>> difference. I suspect it will, since they are completely
>> different architectures.=
>
>> Any suggestions?
>
> - Fix the config
I'll try this first just to see if it helps. I suspect not, as I was
only seeing a single connection, anyway. I'll let you know.
> - Switch to a trunk build
I'll definitely do that.
> In terms of performance, I've been looking at DBCP2 vs tomcat-pool
> using the unit tests in tomcat-pool and there is a 10 to 20%
> performance difference (tomcat-pool is faster) but when you look
> into the why, the difference is pretty much entirely explained by
> the extra default features in DBCP (like calling clearWarnings() on
> a connection when it is returned to the pool).
>
> When you are talking about a test that performs 100,000 checkouts
> and returns in 4s or 5s you quickly realise the performance
> difference is likely to be in the noise once those database
> connections start doing some real work.
Yup. I've never been tempted to switch to tomcat-pool "for performance
reasons" since DB queries themselves are so long-running
(comparatively) that saving a few ns in the object synchronization,
etc. hasn't been a priority for me.
- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1
Comment: GPGTools - http://gpgtools.org
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
iQIcBAEBCAAGBQJTFyjfAAoJEBzwKT+lPKRYVw8QAItQSG5N5MTiy0CUE0bj7YKF
EOwgLTAkrO7bfOw1cElH+u0dvJptIhrmsAAjm4HJk8cu3Ua75A/B025wrp8yhq+a
mZFmNBfrYYARPWyr1vdDmt8V/sTY0UY4DrP8fp3ubR5Z6JcuHMrTBB/uIdfGTR9J
ZkpF6JDnFCFMi3wcO0V7Ki775NZ+aNj78Ti5anYQYfX+aqUXY/ESozDznGelwEnE
FwxjeEimQvCOtGtN+YeK8bQOAIxna/BJWn03GmI3Xo8OC/764dPI4uCrMkWAhvOh
CY7thtOD6hwGOYPkTVfImV2LU8KQ9b6foLyjT5LKLfVE7a/CX+29ZCplFErMS0Gx
px1uLDtpfZKsKxEYCoR0A+5XgrIXZaZ+9fgHsuWDYBauU1nPv//3gb5AzRmZFx4l
lt5I/guWlRincELovQ8oos/2lkG3AvRV4GsgQiDGX9Hr5Z1gpENM12hMp0SoaeqX
WXrIW+uuq0oM8ISjhFB2fsSQro6NKFhB/ev3Bm/9yJMH0yW7/3Rgv8um5SFxyieI
rt3G6yAM0z30+jgybcX3+EtMbs+MQKS6Bct1K2tK1cpsHozAtIggEylUWKgfO+no
u8a8f0roWuwpFhe8bP5SzC1Ww6tgLKhnhFU46YIuNG31mhQImYEwgmMGj+wkQFL/
grTQ0S1zIOaJZx9xundT
=xvm5
-----END PGP SIGNATURE-----
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Performance drop under load for Tomcat8/DBCP2 with respect to
Tomcat 7/DBCP1
Posted by Mark Thomas <ma...@apache.org>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
On 05/03/2014 01:50, Christopher Schultz wrote:
<snip/>
> When I run under Tomcat 8.0.3, a couple of the images are loaded,
> and then the whole ... thing ... just ... stops. If I watch my
> log4j log file, every so often a flurry of activity occurs: several
> pieces of information are actually fetched from the database, and
> progress is made. But I have waited like 10 minutes and the series
> of requests never finishes in that time.
I'd suggest compiling 8.0.x from trunk as that is now using the
released DBCP 2.0 and Pool 2.2. There was a pool issue (POOL-248) that
was fixed after the 8.0.x release that might have caused this.
> (Something odd I can see: when that small amount of progress is
> made, the idle connection in MySQL *remains* idle. The only
> conclusion I can come to is that a new connection is being created
> to fetch that data and then it's being dropped, or that something
> is giving up somewhere without telling me. Neither conclusion makes
> much sense. I haven't actually confirmed that any real progress is
> made... just that I can see "loading XYZ from db" in my log
> files... those messages are logged *before* the data is loaded so I
> don't know it has been at this point).
Take a look at the pool with JMX. Again, if you work with trunk you'll
get lots of detail of exactly what each connection is doing.
> Thread dumps show that everything is waiting on:
>
> - org.apache.tomcat.dbcp.dbcp2.BasicDataSource.getConnection()
> @bci=55, line=1385 (Interpreted frame)
>
> It's not that large a number of threads. It's something like 30-40
> threads waiting on connections. (I'm not entirely sure why there
> are so many threads active... I'm the only one using this
> environment and I made a single top-level request... I thought most
> browsers limited their outgoing connections to something like 8 per
> hostname, but that appears not to be the case).
While that doesn't rule out a DBCP issuee, it does suggest that there
is at least something else going on that you need to get to the bottom of.
> My DataSource configuration:
>
> <Resource name="jdbc/diagnosis" description="JDBC connection to
> main CHADIS database" auth="Container" type="javax.sql.DataSource"
> maxActive="1" maxIdle="1" maxWait="10000" url="[url]"
> username="[user]" password="[user]"
> driverClassName="com.mysql.jdbc.Driver" removeAbandoned="true"
> removeAbandonedTimeout="30" logAbandoned="true"
> testOnBorrow="true" validationQuery="/* ping */ SELECT 1" />
>
> Note that I have a single database connection in the pool.
Not with DBCP 2 you don't. maxActive has been renamed to maxTotal so
you'll have the default (8 from memory) connections in the pool. This
is likely to be a common problem. We probably need to add something to
catch this, report a warning and set the correct attribute.
You can also drop the validationQuery. DBCP2 will use isValid() which
is just as fast and frequently faster.
> It looks like DBCP2 is kind of hosing, here.
>
> I don't have a simple test case right now, unfortunately, but I do
> know that it has worked every time (maybe a dozen times) under
> Tomcat 7.0.47 and failed every time (maybe 5 times, now) under
> Tomcat 8.0.3.
>
> I'm going to try using tomcat-pool to see if it makes any
> difference. I suspect it will, since they are completely different
> architectures.=
>
> Any suggestions?
- - Fix the config
- - Switch to a trunk build
In terms of performance, I've been looking at DBCP2 vs tomcat-pool
using the unit tests in tomcat-pool and there is a 10 to 20%
performance difference (tomcat-pool is faster) but when you look into
the why, the difference is pretty much entirely explained by the extra
default features in DBCP (like calling clearWarnings() on a connection
when it is returned to the pool).
When you are talking about a test that performs 100,000 checkouts and
returns in 4s or 5s you quickly realise the performance difference is
likely to be in the noise once those database connections start doing
some real work.
Mark
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (MingW32)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
iQIcBAEBAgAGBQJTFuEYAAoJEBDAHFovYFnnqHoQALvntENdBi2dJBqiZvAR6pYA
eYbWWMQZz/qy7WoCtuzR9gmBj51WpXB6fLGpd+nIWcU2p2I4GO6CugL+G2Pmulxd
dcSxSV0hwFK7qTSvnmzzEN4EN7hIbiV9AyP3uMvJADwo7stwY9OWQN+jiXPksWRH
5tQ52ZYF807RcCcvdNKp4yAudod9vn4hroMR/Bt8mQ72y7WzEbyHVSgLuARWnCcu
bPBSJwLFZ329oqNXRFuf3JTk4hH8H2KlPB5BLQLeVI56bA+HcpwsjzPxU5YrqZdb
Jj0brLigh3ReEfL1SwmaDGmo5kMUBDS5JNjtXXTmd43PX8wO6OeuwY82Q83iCWK+
WMksIdpIb7MdE8VNfmWHHzRQMfskEGd96HVJMG4ALnr1ZBhnEPorHlGeA02tdiER
7P5/3RUbTvNRPCV0ktDkvWgn87WJ+3MTO6uJl7zBuCjg0UU59eydXFk31s0u5I3q
u1310TsWTuKLtqTPU5yuhSxLynizdlKClAA9x8xuY/0V3UeBNZdsBDm3tCrwXwBU
wrkVy45W2rcmd0OYQpVJE4F43p1SiY2s6fX9inilju7T4be/aElEeVrDUBaude1P
dsrqNbQFofsys4jRs+MuE2HJ+NbKypeIitr+9TunSSNdvBJDSZvUWXmICY65r19g
96rGnU4v4p2tbiaYZ9nA
=X7lB
-----END PGP SIGNATURE-----
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org