Re: bug report: slow getColumnTypeName

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@ttc-cmc.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@impactsoft.co.il
>> <mailto:eyal@impactsoft.co.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@postgresql.org)
> To make changes to your subscription:
> http://www.postgresql.org/mailpref/pgsql-jdbc