vertica jdbc connection performance issue

Hi
From the DAO log its seems like you spending most of  the time of data fetch  and not on the connect method ,  data fetch   can be directly related to network or prefetch  attribute low value .

Do I miss something ?

Hi Eli,

sorry my post might be confusing

Time: 2014-09-09_16:51:26.166 Class: TestDaoImpl Message: START getResultList
Time: 2014-09-09_16:51:56.216 Class: TestDaoImpl Message: END getResultList

this just means that it is during this time that the actual connection call to vertica db is issued.
the log 'getResultList' might be misleading...

Thanks

Hi ,
Its hard to help , you need to share your code , do you able to do so ? 
Do you try to profile this method , to know in which connection method you spend your time ?

Please check your connection time using vsql utility ,  from the web server , this will help to figure if its jdbc or general connection problem .

Hi Eli,

we tried using vsql...it is fast....

here is the sample testing code we used:
==================
import java.sql.Connection;
import java.sql.DriverManager;
import java.sql.ResultSet;
import java.sql.Statement;
import java.text.DateFormat;
import java.text.SimpleDateFormat;
import java.util.Date;

public class JavaMysql {

        public static void main(String[] args) {
                DateFormat dateFormat = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS");
                Date date = new Date();
                String url = "jdbc:vertica://192.36.253.114:5433/testdb";
                String driver = "com.vertica.jdbc.Driver";
                String userName = "dbadmin";
                String password = "test";
                try {
                        Class.forName(driver);
                        date.getTime();
                        System.out.println("BEFORE CONNECTION: " + dateFormat.format(date));
                        Connection conn = DriverManager.getConnection(url, userName,
                                        password);
                        date = new Date();
                        date.getTime();
                        System.out.println("AFTER CONNECTION: " + dateFormat.format(date));
                        Statement st = conn.createStatement();
                        date = new Date();
                        date.getTime();
                        System.out.println("BEFORE QUERY: " + dateFormat.format(date));
                        ResultSet res = st
                                        .executeQuery("SELECT * FROM  TTEST WHERE FTEST=1");
                        date = new Date();
                        date.getTime();
                        System.out.println("AFTER QUERY: " + dateFormat.format(date));
                        while (res.next()) {
                                String username = res.getString("FTEST");
                                System.out.println(username);
                        }
                        conn.close();
                        date = new Date();
                        date.getTime();
                        System.out.println("AFTER CLOSE: " + dateFormat.format(date));
                } catch (Exception e) {
                        e.printStackTrace();
                }
        }

==================

here is the sample result:
    BEFORE CONNECTION: 2014-09-11 10:39:37.993
    AFTER CONNECTION: 2014-09-11 10:39:43.649
    BEFORE QUERY: 2014-09-11 10:39:43.652
    AFTER QUERY: 2014-09-11 10:39:43.679
    00001
    00003
    00005
    00006
    00007
    00002
    99999
    12345
    AFTER CLOSE: 2014-09-11 10:39:43.695
===================

as you can see..connection take around 6 seconds...
any help is appreciated...

Thanks

Mmm ...
Check your  vertica.log file for “Connection received:” pattern  and then refer  to the fourth column , this column include the connection sessionId (example - Session:0x7ffb5800e9e0)  , use this sessionId   and try to find  on the load reference lines of it , each line has a timestamp , it may help you to investigate the root cause   .

 

You can also try to  use an older JDBC  driver I locally use JDBC  driver 6.1.3 without any issues , so it may related to the JDBC  driver  you are using .

Thanks 

Hi Eli,
Thank you for your reply.

we tried using the 6.1.3 driver and it still is slow.

update:
we isolated the 2 server pc and made a cross cable connection between them...
ran the test code and it works fine.

we are now very confused...
is the issue in our local network?
we also have a network firewall that both server goes through, does this matter?

any more suggestion what to do next?

Thank You

Hi!

1. May be its a LOAD BALANCER? Is it enabled or disabled?
2. Can you post vertica.log while you trying to connect with JDBC?
3. Did you tried connection pooling?
4. Can you try to load the driver class in the Static Initialization Block?

com.vertica.jdbc.Driver"); }static{     Class.forName("

 

Firewall , can be your issue , try to disable it and run the test .

Hi Eli,

update2:
isolated the webserver and the dbserver using a HUB.
this time connection is very slow.

Thanks

Hi I see, but you not provid any vertica log reference , that covering the connection sessionid ( i guid you above about it) . this may provid addtion view that can help to solve your problem.

Hi Eli,

found the vertica.log here are the log portion between webserver and dbserver

---------------------------
2014-09-11 11:04:14.991 Init Session:0x7fd0dc0164c0 <LOG> @v_testdb_node0001: 00000/2705: Connection received: host=192.36.252.102 port=59633 (connCnt 22)

2014-09-11 11:04:20.002 Init Session:0x7fd0dc0164c0 <LOG> @v_testdb_node0001: 00000/4686: sendAuthRequest: user=dbadmin database=testdb host=192.36.252.102 authType=3

2014-09-11 11:04:20.005 Init Session:0x7fd0dc0164c0-a000000028cd73 [Txn] <INFO> Begin Txn: a000000028cd73 'check_login_history'

2014-09-11 11:04:20.005 Init Session:0x7fd0dc0164c0-a000000028cd73 [Txn] <INFO> Rollback Txn: a000000028cd73 'check_login_history'

2014-09-11 11:04:20.005 Init Session:0x7fd0dc0164c0 <LOG> @v_testdb_node0001: 00000/4686: sendAuthRequest: user=dbadmin database=testdb host=192.36.252.102 authType=0

2014-09-11 11:04:20.005 Init Session:0x7fd0dc0164c0 <LOG> @v_testdb_node0001: 00000/2703: Connection authenticated: user=dbadmin database=testdb host=192.36.252.102

2014-09-11 11:04:20.005 Init Session:0x7fd0dc0164c0 <LOG> @v_testdb_node0001: 00000/2609: Client pid: 32443

2014-09-11 11:04:20.005 Init Session:0x7fd0dc0164c0 <LOG> @v_testdb_node0001: 00000/2608: Client label: jdbc-07.00.0100-e9f22251-5941-4c82-a43d-34d9d95a1034

2014-09-11 11:04:20.036 Init Session:0x7fd0dc0164c0 [Session] <INFO> [Query] TX:0(localhost.localdoma-16404:0x27fee8) set session autocommit to on

2014-09-11 11:04:20.049 Init Session:0x7fd0dc0164c0 [Session] <INFO> [PQuery] TX:0(localhost.localdoma-16404:0x27fee8) SELECT * FROM TTEST  WHERE FTEST=1

2014-09-11 11:04:20.050 Init Session:0x7fd0dc0164c0 [Session] <INFO> [Query] TX:0(localhost.localdoma-16404:0x27fee8) SELECT * FROM TTEST  WHERE FTEST=1

2014-09-11 11:04:20.051 Init Session:0x7fd0dc0164c0-a000000028cd74 [Txn] <INFO> Begin Txn: a000000028cd74 'SELECT * FROM TTEST  WHERE FTEST=1'

2014-09-11 11:04:20.058 Init Session:0x7fd0dc0164c0-a000000028cd74 [Txn] <INFO> Starting Commit: Txn: a000000028cd74 'SELECT * FROM TTEST  WHERE FFTEST=1'

2014-09-11 11:04:20.058 Init Session:0x7fd0dc0164c0 [Txn] <INFO> Commit Complete: Txn: a000000028cd74 at epoch 0x92e

2014-09-11 11:04:20.088 Init Session:0x7fd0dc0164c0 <LOG> @v_testdb_node0001: 00000/4719: Session localhost.localdoma-16404:0x27fee8 ended; closing connection (connCnt 22)
---------------------------

its slow in the 1st two lines...
from 'Connection received:' to 'sendAuthRequest'

Thanks

Ok, Now send the same log content when you connect via vsql from the webserver to the db server.

Hi Eli,

here are the log earlier using vsql

--------------------------------
2014-09-11 10:36:41.776 Init Session:0x7fd0dc015240 <LOG> @v_testdb_node0001: 00000/2705: Connection received: host=192.36.252.102 port=59626 (connCnt 13)

2014-09-11 10:36:41.776 Init Session:0x7fd0dc015240 <LOG> @v_testdb_node0001: 00000/4540: Received SSL negotiation startup packet

2014-09-11 10:36:41.776 Init Session:0x7fd0dc015240 <LOG> @v_testdb_node0001: 00000/4691: Sending SSL negotiation response 'N'

2014-09-11 10:36:41.778 Init Session:0x7fd0dc015240 <LOG> @v_testdb_node0001: 00000/4686: sendAuthRequest: user=dbadmin database=testdb host=192.36.252.102 authType=3

2014-09-11 10:36:41.778 Init Session:0x7fd0dc015240-a000000028a75d [Txn] <INFO> Begin Txn: a000000028a75d 'check_login_history'

2014-09-11 10:36:41.778 Init Session:0x7fd0dc015240-a000000028a75d [Txn] <INFO> Rollback Txn: a000000028a75d 'check_login_history'

2014-09-11 10:36:41.778 Init Session:0x7fd0dc015240 <LOG> @v_testdb_node0001: 00000/4686: sendAuthRequest: user=dbadmin database=testdb host=192.36.252.102 authType=0

2014-09-11 10:36:41.778 Init Session:0x7fd0dc015240 <LOG> @v_testdb_node0001: 00000/2703: Connection authenticated: user=dbadmin database=testdb host=192.36.252.102

2014-09-11 10:36:41.778 Init Session:0x7fd0dc015240 <LOG> @v_testdb_node0001: 00000/2609: Client pid: 32025
2014-09-11 10:36:55.894 Init Session:0x7fd0dc015240 [Session] <INFO> [Query] TX:0(localhost.localdoma-16404:0x27f846) select * from TTEST;

2014-09-11 10:36:55.894 Init Session:0x7fd0dc015240-a000000028a763 [Txn] <INFO> Begin Txn: a000000028a763 'select * from TTEST;'
--------------------------------

Thanks

Hi I see that on jdbc option you have 22 active connection, however in vsql only 13, you sure you share all the story ?

Hi,

update
we finally found a way to make the connection fast.

both web server and db server must have a static ip address. ( previous was via dhcp ).
after setting both with a static ip, the connection was fast.

does someone know why?

Thanks in advance