[opencms-dev] Synchronization problem in CmsSqlManager and Apache Commons DBCP & Pool

[Alexey Lapusta]

Hi guys,

We have been doing a load-testing of our website and noticed a
considerable page loading time growth when increasing concurrent user
number. Tests were done using ab utility (Apache Benchmark). We were
testing the front page, its dynamic, but quite simple – an xml, couple
includes and labels.

Test parameters:
ab –n 2000 –c 100 http://site.com/
Requests per second:    108.96 [#/sec] (mean)
Percentage of the requests served within a certain time (ms)
  50%    551
  66%   1351
  75%   1633
  80%   1723
  90%   1903
  95%   2049
  98%   2232
  99%   2365
 100%   3509 (longest request)

Not that bad, really. But if you increase the ‘-c’ parameter, which
stands for concurrent users, you get:
ab –n 2000 –c 400 http://site.com/
Requests per second:    54.64 [#/sec] (mean)
Percentage of the requests served within a certain time (ms)
  50%   6971
  66%   8103
  75%   8928
  80%   9484
  90%  11151
  95%  13157
  98%  16179
  99%  18651
 100%  20498 (longest request)

Average page loading increased by 10 times and we decided to find out
why that happens. After getting thread dump from Tomcat and exploring
it, we found an queue of threads using same monitor – CmsSqlManager
which were opening and closing connections. In the source code we
found that CmsSqlManager methods responsible for opening and closing
connections to database and methods used for creating prepared
statements (closeAll, getConnectionByUrl, getPreparedStatement) were
synchronized on same monitor.

We also found out that commons-dbcp & commons-pool libraries which are
used in OpenCms 7.5.3 have same problems, so we have updated them to
the latest version from Apache website and created own CmsSqlManager
with unsynchronized methods.

ab –n 2000 –c 100 http://site.com/

Requests per second:    166.20 [#/sec] (mean)
Percentage of the requests served within a certain time (ms)
  50%    374
  66%    510
  75%    632
  80%    735
  90%   1145
  95%   1635
  98%   2403
  99%   3210
 100%   5932 (longest request)

ab –n 2000 –c 400 http://site.com/
Requests per second:    156.02 [#/sec] (mean)
Percentage of the requests served within a certain time (ms)
  50%   1293
  66%   2039
  75%   3074
  80%   3944
  90%   5132
  95%   6428
  98%   8066
  99%   9500
 100%  11715 (longest request)

As you see, performance has drastically improved.

P.S. After writing this letter I found out that in latest 7.5.4 this
was fixed(Bug #1717), but libraries haven’t been updated. Will we see
updated apache commons in OpenCms 8?


-- 
Alexey Lapusta