Re: bug report: slow getColumnTypeName

From: Luis Flores <luiscamposflores(at)gmail(dot)com>
To: dmp <danap(at)ttc-cmc(dot)net>
Cc: Eyal Wilde <eyal(dot)wilde(at)gmail(dot)com>, PostgreSQL JDBC <pgsql-jdbc(at)postgresql(dot)org>
Subject: Re: bug report: slow getColumnTypeName
Date: 2012-10-10 22:10:34
Message-ID: CA+nXnG8thQTe6D-njQYqQUd-LuXD2--RBejCz6Oq7dtMUEEs=g@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-jdbc

I also confirm the performance regression.

Testing on Fedora17 64bit + PostgreSQL 9.1 + jdk 1.6.0_33, localhost
server, I get these numbers:
driver 802
getColumnType time (ms): 2777
getColumnTypeName time (ms): 1847
both time (ms): 1948

driver 903
getColumnType time (ms): 3044
getColumnTypeName time (ms): 27123
both time (ms): 25142

driver 1000
getColumnType time (ms): 2928
getColumnTypeName time (ms): 27214
both time (ms): 26407

During the getColumnTypeName tests postgresql daemon used 100% cpu time.

Here is the full test class:

import java.sql.Connection;
import java.sql.DriverManager;
import java.sql.ResultSet;
import java.sql.ResultSetMetaData;
import java.sql.Statement;

public class Main
{
public static void main( String arg[] )
throws Exception
{
Class.forName( "org.postgresql.Driver" );
Connection conn = DriverManager.getConnection(
"jdbc:postgresql://localhost/test", "postgres", "" );
Statement create = conn.createStatement();
create.execute( "CREATE TABLE t(id SERIAL, name VARCHAR);" );
create.close();
long l = System.currentTimeMillis();
for( int i = 0; i < 10000; ++i )
{
Statement stm = conn.createStatement();
stm.execute( "SELECT id, name FROM t;" );
ResultSet rs = stm.getResultSet();
ResultSetMetaData rsmd = rs.getMetaData();
rsmd.getColumnType( 1 );
// rsmd.getColumnTypeName( 1 );
rs.close();
stm.close();
}
System.out.println( "getColumnType time (ms): " + (
System.currentTimeMillis() - l ) );
l = System.currentTimeMillis();
for( int i = 0; i < 10000; ++i )
{
Statement stm = conn.createStatement();
stm.execute( "SELECT id, name FROM t;" );
ResultSet rs = stm.getResultSet();
ResultSetMetaData rsmd = rs.getMetaData();
// rsmd.getColumnType( 1 );
rsmd.getColumnTypeName( 1 );
rs.close();
stm.close();
}
System.out.println( "getColumnTypeName time (ms): " + (
System.currentTimeMillis() - l ) );
l = System.currentTimeMillis();
for( int i = 0; i < 10000; ++i )
{
Statement stm = conn.createStatement();
stm.execute( "SELECT id, name FROM t;" );
ResultSet rs = stm.getResultSet();
ResultSetMetaData rsmd = rs.getMetaData();
rsmd.getColumnType( 1 );
rsmd.getColumnTypeName( 1 );
rs.close();
stm.close();
}
System.out.println( "both time (ms): " + ( System.currentTimeMillis() - l ) );
Statement drop = conn.createStatement();
drop.execute( "DROP TABLE t;" );
drop.close();
conn.close();
}
}

Luis Flores

On Tue, Oct 9, 2012 at 5:48 PM, dmp <danap(at)ttc-cmc(dot)net> wrote:
> Eyal Wilde wrote:
>>
>> I verified with wireshark that getColumnTypeName indeed do a request to
>> the postgres server. This happens with 9.1-901 and 9.1-903 BUT NOT WITH
>> 9.0-801!!
>>
>> So, the reason for the slowness seems to be obviouse now.
>>
>> it will take me some time to wrap up it into a test case. I would realy
>> like to help, but please let me know if it's realy necessary.
>>
>> On Oct 5, 2012 1:07 AM, "Eyal Wilde" <eyal(at)impactsoft(dot)co(dot)il
>> <mailto:eyal(at)impactsoft(dot)co(dot)il>> wrote:
>>
>>
>> ResultSetMetaData __md = __rs.getMetaData();
>> //this is fine
>> String __sf1name = __md.getColumnName(1);
>> //this is fine
>> int __if1type = __md.getColumnType(1);
>> //this is fine
>> String __sf1type =
>> __md.getColumnTypeName(1); //this is SLOW!! ~15msec
>>
>> postgres server version is 9.1.5
>> jdbc version, i checked both 9.1-901 and 9.1-903
>> and... BTW, 9.0-801 works good (while connected pg9.1)!
>
>
> There does appear to be a change in the code that may have created the
> slowness that you are observing. Please try a a test case in which two
> back to back getColumnTypeName() calls are made. Is there a difference
> in time between the first and second and is there still on the second
> call a request to the postgres server.
>
> The code between 9.0-801 and later version does have a change in it
> that looks like for the caching for field metadata through
> fetchFieldMetaData().
> That method is called in the later versions for getColumnTypeName()
> with isAutoIncrement(), with was also added in later versions.
>
> danap.
>
>
>
>
> --
> Sent via pgsql-jdbc mailing list (pgsql-jdbc(at)postgresql(dot)org)
> To make changes to your subscription:
> http://www.postgresql.org/mailpref/pgsql-jdbc

In response to

Responses

Browse pgsql-jdbc by date

  From Date Subject
Next Message Luis Flores 2012-10-10 22:39:06 Re: bug report: slow getColumnTypeName
Previous Message David Johnston 2012-10-10 16:56:36 Re: Bug in AbstracJdbc2Statement.replaceProcessing when using dollar quoting?