Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 2.1.0
    • Fix Version/s: 2.2.0
    • Component/s: None
    • Labels:
      None

      Description

      Persistence JDBC tests and other database connected tests have been suffering from slow down starting somewhere in September 2010 [1]. I can see this in my environment as well as Hudson builds:

      OpenJPA-trunk-deploy: Build #49 (Nov 7, 2010 6:46:34 AM): OpenJPA Persistence JDBC: 34 min

      OpenJPA-20x-deploy: Build #23 (Nov 5, 2010 7:14:48 PM): OpenJPA Persistence JDBC: 10 min

      As seen above, the trunk build executes much slower than the 2.0.x build yet the number of tests is roughly the same and there are no significant differences in execution times of modules that do not touch database.

      [1] http://openjpa.208410.n2.nabble.com/Slow-JDBC-test-suite-tp5594040p5594040.html

        Issue Links

          Activity

          Hide
          Rick Curtis added a comment -

          I looked at which tests are taking a long time this afternoon and came up with this list ... these are all 10+ seconds. I'm not sure which of these can be attributed to the 'problem' tests, but they are the longest running.

          Name Duration Tests

          TestClearableScheduler (org.apache.openjpa.persistence.datacache) 3m:01s,088ms 1
          TestQueryTimeout (org.apache.openjpa.persistence.query) 49s,306ms 12
          TestDaytrader (org.apache.openjpa.integration.daytrader) 42s,167ms 1
          TestTimeoutException (org.apache.openjpa.persistence.query) 30s,222ms 3
          TestSJVMCache (org.apache.openjpa.persistence.datacache) 24s,390ms 30
          TestDataCachePCDataGenerator (org.apache.openjpa.persistence.datacache) 23s,567ms 30
          TestTypesafeCriteria (org.apache.openjpa.persistence.criteria) 22s,802ms 100
          TestEnhancementWithMultiplePUs (org.apache.openjpa.enhance) 18s,864ms 3
          TestJPQLSubquery (org.apache.openjpa.persistence.criteria) 14s,346ms 59
          TestTypeSafeCondExpression (org.apache.openjpa.persistence.criteria) 13s,267ms 55
          TestEmbeddable (org.apache.openjpa.persistence.embed) 10s,862ms 26

          Show
          Rick Curtis added a comment - I looked at which tests are taking a long time this afternoon and came up with this list ... these are all 10+ seconds. I'm not sure which of these can be attributed to the 'problem' tests, but they are the longest running. Name Duration Tests TestClearableScheduler (org.apache.openjpa.persistence.datacache) 3m:01s,088ms 1 TestQueryTimeout (org.apache.openjpa.persistence.query) 49s,306ms 12 TestDaytrader (org.apache.openjpa.integration.daytrader) 42s,167ms 1 TestTimeoutException (org.apache.openjpa.persistence.query) 30s,222ms 3 TestSJVMCache (org.apache.openjpa.persistence.datacache) 24s,390ms 30 TestDataCachePCDataGenerator (org.apache.openjpa.persistence.datacache) 23s,567ms 30 TestTypesafeCriteria (org.apache.openjpa.persistence.criteria) 22s,802ms 100 TestEnhancementWithMultiplePUs (org.apache.openjpa.enhance) 18s,864ms 3 TestJPQLSubquery (org.apache.openjpa.persistence.criteria) 14s,346ms 59 TestTypeSafeCondExpression (org.apache.openjpa.persistence.criteria) 13s,267ms 55 TestEmbeddable (org.apache.openjpa.persistence.embed) 10s,862ms 26
          Hide
          Milosz Tylenda added a comment -

          Hi Rick. These are indeed the longest ones but in fact all database related tests are gradually slowed down.

          It might be related either to derby test profile or derby itself, since when I run the tests against another database, there is no slowdown.

          Show
          Milosz Tylenda added a comment - Hi Rick. These are indeed the longest ones but in fact all database related tests are gradually slowed down. It might be related either to derby test profile or derby itself, since when I run the tests against another database, there is no slowdown.
          Hide
          Milosz Tylenda added a comment -

          The direct cause is DELETE statements (without WHERE clause) gradually become slow on Derby while a test case is executed and we issue a lot of DELETEs at the beginning of most test methods.

          The issue is related or caused by DBCP pooling auto-enablement because when I specify the properties in the old way:

          <property>
          <name>openjpa.jdbc.DriverDataSource</name>
          <value>simple</value>
          </property>
          <dbcp.args>DriverClassName=org.apache.derby.jdbc.EmbeddedDriver,Url=jdbc:derby:target/database/openjpa-derby-database;create=true,Username=,Password=,MaxActive=10,MaxIdle=5,MinIdle=2,MaxWait=10000</dbcp.args>
          <connection.driver.name>org.apache.commons.dbcp.BasicDataSource</connection.driver.name>

          the execution time drops to the old level and JDBC log channel shows database and driver version as in 2.0.x branch.

          Show
          Milosz Tylenda added a comment - The direct cause is DELETE statements (without WHERE clause) gradually become slow on Derby while a test case is executed and we issue a lot of DELETEs at the beginning of most test methods. The issue is related or caused by DBCP pooling auto-enablement because when I specify the properties in the old way: <property> <name>openjpa.jdbc.DriverDataSource</name> <value>simple</value> </property> <dbcp.args>DriverClassName=org.apache.derby.jdbc.EmbeddedDriver,Url=jdbc:derby:target/database/openjpa-derby-database;create=true,Username=,Password=,MaxActive=10,MaxIdle=5,MinIdle=2,MaxWait=10000</dbcp.args> <connection.driver.name>org.apache.commons.dbcp.BasicDataSource</connection.driver.name> the execution time drops to the old level and JDBC log channel shows database and driver version as in 2.0.x branch.
          Hide
          Milosz Tylenda added a comment -

          Narrowing further, the issue happens because we set connection properties (e.g. JDBC driver class) in the main pom.xml differently after implementing DBCP pooling auto-enablement. This impacts automatic Derby shutdown when closing a data source. Although we have always had set DerbyDictionary.shutdownOnClose set to true, we were not shutting Derby down in our tests. After the properties changed, we started doing the shutdown and this is slowing DELETE statements (but why?). It looks like the shutdown might be a good option for user applications but not for unit tests. Setting DerbyDictionary.shutdownOnClose=false should resolve the issue.

          As for the lack of database and driver version message in the log, it is also caused by the properties change. However, it is quite a good thing here - it means OpenJPA is able to figure out DBDictionary class without connecting to the database.

          Show
          Milosz Tylenda added a comment - Narrowing further, the issue happens because we set connection properties (e.g. JDBC driver class) in the main pom.xml differently after implementing DBCP pooling auto-enablement. This impacts automatic Derby shutdown when closing a data source. Although we have always had set DerbyDictionary.shutdownOnClose set to true, we were not shutting Derby down in our tests. After the properties changed, we started doing the shutdown and this is slowing DELETE statements (but why?). It looks like the shutdown might be a good option for user applications but not for unit tests. Setting DerbyDictionary.shutdownOnClose=false should resolve the issue. As for the lack of database and driver version message in the log, it is also caused by the properties change. However, it is quite a good thing here - it means OpenJPA is able to figure out DBDictionary class without connecting to the database.
          Hide
          Albert Lee added a comment -

          Close issue in preparation for 2.2.0 release.

          Show
          Albert Lee added a comment - Close issue in preparation for 2.2.0 release.

            People

            • Assignee:
              Milosz Tylenda
              Reporter:
              Milosz Tylenda
            • Votes:
              0 Vote for this issue
              Watchers:
              0 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development