Re: Database related performance degradation after upgrading from Tomcat 9.0.33 to Tomcat 9.0.69

2023-02-23 Thread Artur Tomusiak - Hannon Hill
Thanks everyone for the information and advice. Thanks to you we were able
to track this down to a specific version of Tomcat and DBCP. Simply copying
tomcat-dbcp.jar file from Tomcat 9.0.38 to Tomcat 9.0.33 and running Tomcat
9.0.33 results in the slowness. This means that the issue was introduced in
DBCP 2.8.0-SNAPSHOT 6d232e5. Using the tomcat-dbcp.jar file from Tomcat
9.0.72 results in the same slowness as Tomcat 9.0.38, so that means that
the newest version of DBCP 2.10.0-SNAPSHOT f131286 has not fixed the
problem.

It does sound like https://issues.apache.org/jira/browse/DBCP-558 has
introduced the problem with latency. Based on the linked Pull Request
<https://github.com/apache/commons-dbcp/pull/35> and implementation of
com.mysql.jdbc.ConnectionImpl it looks like calling
`connection.isReadOnly()` results in an extra trip to the database. Based
on implementation of com.mysql.jdbc.ConnectionImpl, providing an extra
parameter in connection URL: `&useLocalSessionState=true` fixes the
performance problem in Tomcat 9.0.69.

Without providing the extra `&useLocalSessionState=true` parameter in
connection URL, copying tomcat-dbcp.jar file from Tomcat 9.0.33 to Tomcat
9.0.69 also fixes the database performance in Tomcat 9.0.69 and it does not
seem to be causing any problems at first sight, so we have found the
culprit and we have 2 potential workarounds:

   - Use tomcat-dbcp.jar file from Tomcat 9.0.33 in Tomcat 9.0.69, or
   - Append `&useLocalSessionState=true` param to connection URL

A few follow up questions:

   - Which of the two workarounds would be more recommended? Would there be
   any problems with mismatching tomcat-dbcp.jar version or with using the
   useLocalSessionState parameter?
   - Since the solution in the Pull Request seems to result in a
   considerable performance hit, would that be considered an issue or
   necessary evil? Should we expect such an issue to be fixed in the future or
   do we just need to adjust and live with it?
   - Out of curiosity, has anyone else here noticed such database
   connection performance degradation between these versions of Tomcat
   (essentially between 9.0.37 or earlier, and 9.0.38 or later)? Since DBCP
   2.8.0 was released in 2020-09-21 and Tomcat 9.0.38 was released
   in 2020-08-11, it's a bit strange that this issue was not reported
   previously by anyone.

Thank you,
Artur Tomusiak

On Wed, Feb 22, 2023 at 12:43 PM Mark Thomas  wrote:

> On 22/02/2023 04:58, Konstantin Kolinko wrote:
> > ср, 22 февр. 2023 г. в 01:31, Artur Tomusiak - Hannon Hill
> > :
> >>
> >> After upgrading from Tomcat 9.0.33 to Tomcat 9.0.69,
> >
> > Note that using a binary search (bisection) one could limit the version
> range.
>
> Relevant version information is:
>
> 9.0.71 - DBCP f131286  2.10.0-SNAPSHOT  2022-12-30
> 9.0.53 - DBCP 2abdb49  2.9.02021-08-03
> 9.0.42 - DBCP e24196a  2.9.0-SNAPSHOT   2021-01-15
> 9.0.38 - DBCP 6d232e5  2.8.0-SNAPSHOT   2020-08-11
> 9.0.30 - DBCP a363906  2.8.0-SNAPSHOT   2019-12-06
>
>
> > Alternatively, it is possible to reconfigure the pool to use Apache
> > Commons DBCP 2 and Apache Commons Pool 2 directly (instead of
> > package-renamed version used by Tomcat), and bisect their version
> > ranges.
>
> Given Tomcat's tendency to update to specific commits rather than
> releases, bisecting Tomcat versions is probably easier.
>
> Does your database provide any form of debug logging? The additional
> commands should be easy to spot in such a log.
>
> Changes to autoCommit and readOnly handling in 9.0.38 could result in
> additional database calls. See
> https://issues.apache.org/jira/browse/DBCP-558
>
> I don't see anything else obvious in the change history but a debug log
> for the connection is likely to be the quickest way to see what is going
> on.
>
> Mark
>
> -
> To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
> For additional commands, e-mail: users-h...@tomcat.apache.org
>
>


Database related performance degradation after upgrading from Tomcat 9.0.33 to Tomcat 9.0.69

2023-02-21 Thread Artur Tomusiak - Hannon Hill
After upgrading from Tomcat 9.0.33 to Tomcat 9.0.69, jobs in our
application that execute lots of quick database queries end up being
visibly slower - 16% slower on average in a typical setup where a database
is on a local area network. Here is additional information we have
confirmed:

   - This is not specific to operating system (tested on Linux and MacOS)
   - This is not related to database vendors (tested on MySQL and Oracle)
   - This is not related to our software (identical code runs on different
   versions of Tomcat)
   - This is related to database connection latency as opposed to the speed
   of the database or the app - the longer the database latency, the more
   significant the slowdown is. When testing with a local database on the same
   machine, there is no performance hit between the two versions of Tomcat.
   When testing with a database on another network across the Internet (very
   high latency), the job running on Tomcat 9.0.69 is about 50% slower than
   Tomcat 9.0.33.
   - This might be coincidental, but based on the number of queries the job
   executes and the database connection latency, it appears as if each
   database query required 2 additional network trips to the database on
   Tomcat 9.0.69 as compared to Tomcat 9.0.33.
  - For example, if a job executes about 37,000 queries, and the
  database connection latency is about 0.15 ms, the job ends up being about
  11 seconds slower on Tomcat 9.0.69 than Tomcat 9.0.33 based on our tests.
  This seems to add up to 2 extra network trips per query because 37,000
  queries * 0.15 ms/trip * 2 extra trips/query = 11,100 ms = 11.1 s.
  - Another example is when testing with a db connection over the
  Internet (25 ms latency) and a job that executes 1,231 queries,
that job is
  more or less 60 seconds slower on Tomcat 9.0.69 than Tomcat
9.0.33 based on
  our tests. Again, if we assumed that there are extra 2 trips to the
  database per query, this adds up: 1,231 queries * 25 ms/trip * 2 extra
  trips/query = 61,550 ms = 61.55 s.

We are suspecting that the slowness comes from around getting a database
connection from the connection pool, though we spotted an occasional
slowness around transaction committing as well.

Here is our database connection configuration in context.xml file:

  

Is this a known issue? If not, is there any additional information I could
provide to help troubleshoot or replicate the problem?

Thank you,
Artur Tomusiak