You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@commons.apache.org by "Derek Hulley (JIRA)" <ji...@apache.org> on 2011/02/01 15:45:28 UTC

[jira] Created: (DBCP-352) Repeated calls to getMetadata in a transaction leads to performance degredation

Repeated calls to getMetadata in a transaction leads to performance degredation
-------------------------------------------------------------------------------

                 Key: DBCP-352
                 URL: https://issues.apache.org/jira/browse/DBCP-352
             Project: Commons Dbcp
          Issue Type: Bug
    Affects Versions: 1.4
         Environment: PostgreSQL, MySQL, JDK 1.6
            Reporter: Derek Hulley
            Priority: Critical


During long-running transactions that utilize conditional logic based on the database metadata, it is possible to get thousands of calls to Connection.getMetaData.  An ArrayList is built up containing objects which are never removed (this is the cause of DBCP-330).  However, the array is shared with all other PreparedStatements, so the array scan and modification time keeps rising as the transaction progresses.

I will attempt to attach an Eclipse project; profiling (or even a few JStacks) will show that most of the time is spent scanning the cluttered and growing array for objects to remove.

-- 
This message is automatically generated by JIRA.
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] Updated: (DBCP-352) Repeated calls to getMetadata in a transaction leads to performance degredation

Posted by "Derek Hulley (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DBCP-352?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Derek Hulley updated DBCP-352:
------------------------------

    Attachment: DBCPMetadataTest.zip

Requires table:
   CREATE TABLE dbcp_test( val integer NOT NULL );

Example arguments:
jdbc:postgresql://localhost:5432/dbcptest
test
test
10000

Crank up the getMetaData calls and profile.  Once you've hit 100K getMetaData calls, things start looking really bad; CPU usage suffers.

> Repeated calls to getMetadata in a transaction leads to performance degredation
> -------------------------------------------------------------------------------
>
>                 Key: DBCP-352
>                 URL: https://issues.apache.org/jira/browse/DBCP-352
>             Project: Commons Dbcp
>          Issue Type: Bug
>    Affects Versions: 1.4
>         Environment: PostgreSQL, MySQL, JDK 1.6
>            Reporter: Derek Hulley
>            Priority: Critical
>         Attachments: DBCPMetadataTest.zip
>
>
> During long-running transactions that utilize conditional logic based on the database metadata, it is possible to get thousands of calls to Connection.getMetaData.  An ArrayList is built up containing objects which are never removed (this is the cause of DBCP-330).  However, the array is shared with all other PreparedStatements, so the array scan and modification time keeps rising as the transaction progresses.
> I will attempt to attach an Eclipse project; profiling (or even a few JStacks) will show that most of the time is spent scanning the cluttered and growing array for objects to remove.

-- 
This message is automatically generated by JIRA.
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] [Resolved] (DBCP-352) Repeated calls to getMetadata in a transaction leads to performance degredation

Posted by "Phil Steitz (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DBCP-352?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Phil Steitz resolved DBCP-352.
------------------------------

    Resolution: Fixed

Fixed in trunk (r1096260) and 1_4 branch (r1096259).

> Repeated calls to getMetadata in a transaction leads to performance degredation
> -------------------------------------------------------------------------------
>
>                 Key: DBCP-352
>                 URL: https://issues.apache.org/jira/browse/DBCP-352
>             Project: Commons Dbcp
>          Issue Type: Bug
>    Affects Versions: 1.2.2, 1.3.1, 1.4
>         Environment: PostgreSQL, MySQL, JDK 1.6
>            Reporter: Derek Hulley
>            Priority: Critical
>             Fix For: 1.3.1, 1.4.1
>
>         Attachments: DBCPMetadataTest.zip, commons-dbcp-1.4-patched.diff
>
>
> During long-running transactions that utilize conditional logic based on the database metadata, it is possible to get thousands of calls to Connection.getMetaData.  An ArrayList is built up containing objects which are never removed (this is the cause of DBCP-330).  However, the array is shared with all other PreparedStatements, so the array scan and modification time keeps rising as the transaction progresses.
> I will attempt to attach an Eclipse project; profiling (or even a few JStacks) will show that most of the time is spent scanning the cluttered and growing array for objects to remove.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

[jira] Commented: (DBCP-352) Repeated calls to getMetadata in a transaction leads to performance degredation

Posted by "Phil Steitz (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DBCP-352?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12989236#comment-12989236 ] 

Phil Steitz commented on DBCP-352:
----------------------------------

The fix that I suggested for DBCP-330 should resolve this as well.  I would appreciate review and comments on the fix proposed there.

> Repeated calls to getMetadata in a transaction leads to performance degredation
> -------------------------------------------------------------------------------
>
>                 Key: DBCP-352
>                 URL: https://issues.apache.org/jira/browse/DBCP-352
>             Project: Commons Dbcp
>          Issue Type: Bug
>    Affects Versions: 1.4
>         Environment: PostgreSQL, MySQL, JDK 1.6
>            Reporter: Derek Hulley
>            Priority: Critical
>         Attachments: DBCPMetadataTest.zip
>
>
> During long-running transactions that utilize conditional logic based on the database metadata, it is possible to get thousands of calls to Connection.getMetaData.  An ArrayList is built up containing objects which are never removed (this is the cause of DBCP-330).  However, the array is shared with all other PreparedStatements, so the array scan and modification time keeps rising as the transaction progresses.
> I will attempt to attach an Eclipse project; profiling (or even a few JStacks) will show that most of the time is spent scanning the cluttered and growing array for objects to remove.

-- 
This message is automatically generated by JIRA.
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] Commented: (DBCP-352) Repeated calls to getMetadata in a transaction leads to performance degredation

Posted by "Derek Hulley (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DBCP-352?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12989597#comment-12989597 ] 

Derek Hulley commented on DBCP-352:
-----------------------------------

Phil's suggested fix for DBCP-330 will also address this problem.

> Repeated calls to getMetadata in a transaction leads to performance degredation
> -------------------------------------------------------------------------------
>
>                 Key: DBCP-352
>                 URL: https://issues.apache.org/jira/browse/DBCP-352
>             Project: Commons Dbcp
>          Issue Type: Bug
>    Affects Versions: 1.2.2, 1.3.1, 1.4
>         Environment: PostgreSQL, MySQL, JDK 1.6
>            Reporter: Derek Hulley
>            Priority: Critical
>             Fix For: 1.3.1, 1.4.1
>
>         Attachments: DBCPMetadataTest.zip
>
>
> During long-running transactions that utilize conditional logic based on the database metadata, it is possible to get thousands of calls to Connection.getMetaData.  An ArrayList is built up containing objects which are never removed (this is the cause of DBCP-330).  However, the array is shared with all other PreparedStatements, so the array scan and modification time keeps rising as the transaction progresses.
> I will attempt to attach an Eclipse project; profiling (or even a few JStacks) will show that most of the time is spent scanning the cluttered and growing array for objects to remove.

-- 
This message is automatically generated by JIRA.
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] Commented: (DBCP-352) Repeated calls to getMetadata in a transaction leads to performance degredation

Posted by "Gary Gregory (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DBCP-352?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12989226#comment-12989226 ] 

Gary Gregory commented on DBCP-352:
-----------------------------------

If you can make your example use an H2 (or any) in-memory database, it will be easier to reproduce and test for anyone. I suppose Derby would do the trick as well but I know from experience that H2 works great for standalone unit tests.

> Repeated calls to getMetadata in a transaction leads to performance degredation
> -------------------------------------------------------------------------------
>
>                 Key: DBCP-352
>                 URL: https://issues.apache.org/jira/browse/DBCP-352
>             Project: Commons Dbcp
>          Issue Type: Bug
>    Affects Versions: 1.4
>         Environment: PostgreSQL, MySQL, JDK 1.6
>            Reporter: Derek Hulley
>            Priority: Critical
>         Attachments: DBCPMetadataTest.zip
>
>
> During long-running transactions that utilize conditional logic based on the database metadata, it is possible to get thousands of calls to Connection.getMetaData.  An ArrayList is built up containing objects which are never removed (this is the cause of DBCP-330).  However, the array is shared with all other PreparedStatements, so the array scan and modification time keeps rising as the transaction progresses.
> I will attempt to attach an Eclipse project; profiling (or even a few JStacks) will show that most of the time is spent scanning the cluttered and growing array for objects to remove.

-- 
This message is automatically generated by JIRA.
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] Commented: (DBCP-352) Repeated calls to getMetadata in a transaction leads to performance degredation

Posted by "Derek Hulley (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DBCP-352?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12989596#comment-12989596 ] 

Derek Hulley commented on DBCP-352:
-----------------------------------

The table is deliberately simple, so use your database of choice.

> Repeated calls to getMetadata in a transaction leads to performance degredation
> -------------------------------------------------------------------------------
>
>                 Key: DBCP-352
>                 URL: https://issues.apache.org/jira/browse/DBCP-352
>             Project: Commons Dbcp
>          Issue Type: Bug
>    Affects Versions: 1.2.2, 1.3.1, 1.4
>         Environment: PostgreSQL, MySQL, JDK 1.6
>            Reporter: Derek Hulley
>            Priority: Critical
>             Fix For: 1.3.1, 1.4.1
>
>         Attachments: DBCPMetadataTest.zip
>
>
> During long-running transactions that utilize conditional logic based on the database metadata, it is possible to get thousands of calls to Connection.getMetaData.  An ArrayList is built up containing objects which are never removed (this is the cause of DBCP-330).  However, the array is shared with all other PreparedStatements, so the array scan and modification time keeps rising as the transaction progresses.
> I will attempt to attach an Eclipse project; profiling (or even a few JStacks) will show that most of the time is spent scanning the cluttered and growing array for objects to remove.

-- 
This message is automatically generated by JIRA.
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] Commented: (DBCP-352) Repeated calls to getMetadata in a transaction leads to performance degredation

Posted by "Derek Hulley (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DBCP-352?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12993013#comment-12993013 ] 

Derek Hulley commented on DBCP-352:
-----------------------------------

Results of running DBCPMetadataTest before and after applying trivial patch:

Before:

Found table dbcp_test
Inserted 5000 rows with average of 0ms per row.  Issued 0 metadata queries per insert.
Inserted 10000 rows with average of 0ms per row.  Issued 0 metadata queries per insert.
Inserted 5000 rows with average of 2ms per row.  Issued 5 metadata queries per insert.
Inserted 10000 rows with average of 1ms per row.  Issued 5 metadata queries per insert.
Inserted 5000 rows with average of 5ms per row.  Issued 10 metadata queries per insert.
Inserted 10000 rows with average of 2ms per row.  Issued 10 metadata queries per insert.
Inserted 5000 rows with average of 8ms per row.  Issued 15 metadata queries per insert.
Inserted 10000 rows with average of 4ms per row.  Issued 15 metadata queries per insert.
Inserted 5000 rows with average of 11ms per row.  Issued 20 metadata queries per insert.
Inserted 10000 rows with average of 5ms per row.  Issued 20 metadata queries per insert.

After:

Found table dbcp_test
Inserted 5000 rows with average of 0ms per row.  Issued 0 metadata queries per insert.
Inserted 10000 rows with average of 0ms per row.  Issued 0 metadata queries per insert.
Inserted 5000 rows with average of 0ms per row.  Issued 5 metadata queries per insert.
Inserted 10000 rows with average of 0ms per row.  Issued 5 metadata queries per insert.
Inserted 5000 rows with average of 0ms per row.  Issued 10 metadata queries per insert.
Inserted 10000 rows with average of 0ms per row.  Issued 10 metadata queries per insert.
Inserted 5000 rows with average of 0ms per row.  Issued 15 metadata queries per insert.
Inserted 10000 rows with average of 0ms per row.  Issued 15 metadata queries per insert.
Inserted 5000 rows with average of 0ms per row.  Issued 20 metadata queries per insert.
Inserted 10000 rows with average of 0ms per row.  Issued 20 metadata queries per insert.

As is evident, the overhead of getMetadata() calls has disappeared.  The "memory leak" will have gone, too.
Similar results are obtained for other unit tests with long-running transactions.

> Repeated calls to getMetadata in a transaction leads to performance degredation
> -------------------------------------------------------------------------------
>
>                 Key: DBCP-352
>                 URL: https://issues.apache.org/jira/browse/DBCP-352
>             Project: Commons Dbcp
>          Issue Type: Bug
>    Affects Versions: 1.2.2, 1.3.1, 1.4
>         Environment: PostgreSQL, MySQL, JDK 1.6
>            Reporter: Derek Hulley
>            Priority: Critical
>             Fix For: 1.3.1, 1.4.1
>
>         Attachments: DBCPMetadataTest.zip, commons-dbcp-1.4-patched.diff
>
>
> During long-running transactions that utilize conditional logic based on the database metadata, it is possible to get thousands of calls to Connection.getMetaData.  An ArrayList is built up containing objects which are never removed (this is the cause of DBCP-330).  However, the array is shared with all other PreparedStatements, so the array scan and modification time keeps rising as the transaction progresses.
> I will attempt to attach an Eclipse project; profiling (or even a few JStacks) will show that most of the time is spent scanning the cluttered and growing array for objects to remove.

-- 
This message is automatically generated by JIRA.
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] Updated: (DBCP-352) Repeated calls to getMetadata in a transaction leads to performance degredation

Posted by "Phil Steitz (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DBCP-352?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Phil Steitz updated DBCP-352:
-----------------------------

    Affects Version/s: 1.3.1
                       1.2.2
        Fix Version/s: 1.4.1
                       1.3.1

> Repeated calls to getMetadata in a transaction leads to performance degredation
> -------------------------------------------------------------------------------
>
>                 Key: DBCP-352
>                 URL: https://issues.apache.org/jira/browse/DBCP-352
>             Project: Commons Dbcp
>          Issue Type: Bug
>    Affects Versions: 1.2.2, 1.3.1, 1.4
>         Environment: PostgreSQL, MySQL, JDK 1.6
>            Reporter: Derek Hulley
>            Priority: Critical
>             Fix For: 1.3.1, 1.4.1
>
>         Attachments: DBCPMetadataTest.zip
>
>
> During long-running transactions that utilize conditional logic based on the database metadata, it is possible to get thousands of calls to Connection.getMetaData.  An ArrayList is built up containing objects which are never removed (this is the cause of DBCP-330).  However, the array is shared with all other PreparedStatements, so the array scan and modification time keeps rising as the transaction progresses.
> I will attempt to attach an Eclipse project; profiling (or even a few JStacks) will show that most of the time is spent scanning the cluttered and growing array for objects to remove.

-- 
This message is automatically generated by JIRA.
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] Updated: (DBCP-352) Repeated calls to getMetadata in a transaction leads to performance degredation

Posted by "Derek Hulley (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/DBCP-352?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Derek Hulley updated DBCP-352:
------------------------------

    Attachment: commons-dbcp-1.4-patched.diff

Patch diff

> Repeated calls to getMetadata in a transaction leads to performance degredation
> -------------------------------------------------------------------------------
>
>                 Key: DBCP-352
>                 URL: https://issues.apache.org/jira/browse/DBCP-352
>             Project: Commons Dbcp
>          Issue Type: Bug
>    Affects Versions: 1.2.2, 1.3.1, 1.4
>         Environment: PostgreSQL, MySQL, JDK 1.6
>            Reporter: Derek Hulley
>            Priority: Critical
>             Fix For: 1.3.1, 1.4.1
>
>         Attachments: DBCPMetadataTest.zip, commons-dbcp-1.4-patched.diff
>
>
> During long-running transactions that utilize conditional logic based on the database metadata, it is possible to get thousands of calls to Connection.getMetaData.  An ArrayList is built up containing objects which are never removed (this is the cause of DBCP-330).  However, the array is shared with all other PreparedStatements, so the array scan and modification time keeps rising as the transaction progresses.
> I will attempt to attach an Eclipse project; profiling (or even a few JStacks) will show that most of the time is spent scanning the cluttered and growing array for objects to remove.

-- 
This message is automatically generated by JIRA.
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] Issue Comment Edited: (DBCP-352) Repeated calls to getMetadata in a transaction leads to performance degredation

Posted by "Derek Hulley (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/DBCP-352?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12989596#comment-12989596 ] 

Derek Hulley edited comment on DBCP-352 at 2/2/11 12:03 PM:
------------------------------------------------------------

The table is deliberately simple, so use your database of choice.  I'm not convinced that using an in-memory DB is the solution given that the test is designed to scale up to hundreds of thousands of insertions; it's probably better just to piggy back off a real DB.

      was (Author: derekhulley):
    The table is deliberately simple, so use your database of choice.
  
> Repeated calls to getMetadata in a transaction leads to performance degredation
> -------------------------------------------------------------------------------
>
>                 Key: DBCP-352
>                 URL: https://issues.apache.org/jira/browse/DBCP-352
>             Project: Commons Dbcp
>          Issue Type: Bug
>    Affects Versions: 1.2.2, 1.3.1, 1.4
>         Environment: PostgreSQL, MySQL, JDK 1.6
>            Reporter: Derek Hulley
>            Priority: Critical
>             Fix For: 1.3.1, 1.4.1
>
>         Attachments: DBCPMetadataTest.zip
>
>
> During long-running transactions that utilize conditional logic based on the database metadata, it is possible to get thousands of calls to Connection.getMetaData.  An ArrayList is built up containing objects which are never removed (this is the cause of DBCP-330).  However, the array is shared with all other PreparedStatements, so the array scan and modification time keeps rising as the transaction progresses.
> I will attempt to attach an Eclipse project; profiling (or even a few JStacks) will show that most of the time is spent scanning the cluttered and growing array for objects to remove.

-- 
This message is automatically generated by JIRA.
-
For more information on JIRA, see: http://www.atlassian.com/software/jira