Java Forum / Databases / August 2005
JDBC BUG? A Simple SELECT take too Much Time! Help!
etienno@gmail.com - 29 Jul 2005 20:12 GMT Hi,
I think I just got a jconnect BUG. I am doing a simple query on a Sybase Server on a table (AstAddress) having 1,545,282 rows. I have build an index on the primary key . (I have try clustered and non-clustered with the same result)
CREATE UNIQUE INDEX CLUSTERED PK_AstAddress on Corpo.dbo.AstAddress (astAddressId) with FILLFACTOR=100
This is the server specs: Adaptive Server Enterprise Adaptive Server Enterprise/12.5.2/EBF 11948 ESD#1/P/NT (IX86)/OS 4.0/ase1252/1838/32-bit/OPT/Sat May 29 03:34:29 2004 jConnect (TM) for JDBC (TM) jConnect (TM) for JDBC(TM)/5.5(Build 25100)/P/EBF9853/JDK12/Fri Oct 26 17:11:47 2001
These are the columns of the AstAddress, nothing unusual:
astAddressId (null) numeric 9 ossBranch (null) char 8 ossClient (null) char 20 ossAccount (null) char 18 astSubAccount (null) char 10 ossCountry (null) char 3 ossMajorSort (null) char 1 ossPostalCode (null) char 15 ossMunicipality (null) varchar 32 ossAddressLine1 (null) varchar 32 ossAddressLine2 (null) varchar 32 ossAddressLine3 (null) varchar 32 ossAddressLine4 (null) varchar 32 ossAddressLine5 (null) varchar 32 ossAddressLine6 (null) varchar 32 ossAddressLine7 (null) varchar 32 ossAddressLine8 (null) varchar 32 ossConfirmNumber (null) numeric 1 ossConfirmType (null) char 1 ossGetStatment1 (null) char 1 ossGetStatment2 (null) char 1 ossSupSpecialMsg1 (null) char 1 ossSupSpecialMsg2 (null) char 1 ossPrt8NaLines1 (null) char 1 ossPrt8Nalines2 (null) char 1 ossHoldMail1 (null) char 1 ossHoldMail2 (null) char 1 ossSupPrice1 (null) char 1 ossSupPrice2 (null) char 1 ossExtraCopie1 (null) numeric 2 ossExtraCopie2 (null) numeric 2 ossStatment61 (null) char 1 ossStatment62 (null) char 1 ossProvince (null) char 2 ossTypeAddressLine1 (null) char 1 ossTypeAddressLine2 (null) char 1 ossTypeAddressLine3 (null) char 1 ossTypeAddressLine4 (null) char 1 ossTypeAddressLine5 (null) char 1 ossTypeAddressLine6 (null) char 1 astLastMaintUser (null) char 10 astLastMaintType (null) char 1 astLastMaintJob (null) char 10 astLastMaintTime (null) numeric 6 astLastMaintDate (null) numeric 8
This is the query I am trying to run:
select astaddress0_.astAddressId as astAddre1_0_, astaddress0_.ossBranch as ossBranch25_0_ from Corpo.dbo.AstAddress astaddress0_ where astaddress0_.astAddressId=798957
The problem is when I am doing a prepare statement to take 2 rows, it take more than 1 minutes of processing, the cpu of Sybase is at 100%! It seems Sybase do not use the index to build its query plan! I try getting only the primary key, and it was much faster.
This code takes 1 minutes to run (I use Spring, and I get the same result with Hibernate!):
public List selectSqlPreparedStatement(String sql, Object id) { logger.debug("inside dao"); JdbcTemplate jdbcTemplate = new JdbcTemplate(dataSource); Object[] obj = new Object[1]; obj[0] = id; logger.debug("before the query"); List l = jdbcTemplate.queryForList(sql, obj); logger.debug("after the query"); // TAKE 1 minutes!! return l; }
And when I am executing the same query without any prepared statement, it only take 18 miliseconds!!
This code take 18 ms to run: public void selectSqlWHPS(String sql) throws SQLException { logger.debug("inside dao"); JdbcTemplate jdbcTemplate = new JdbcTemplate(dataSource); logger.debug("before the query"); Statement s = jdbcTemplate.getDataSource().getConnection().createStatement(); ResultSet rs = s.executeQuery(sql); rs.next(); int val = rs.getInt(1); logger.debug("int: " + val); rs.close(); s.close(); logger.debug("after the query"); // TAKE 18 ms!!
}
Am I missing something, or that is really a bug of Jconnect and Sybase?
Thanks,
Etienne Montreal
joeNOSPAM@BEA.com - 29 Jul 2005 21:01 GMT What's the actual SQL string? What happens if you run the same prepared statement a second time? Prepared statements do work to store the query plan, once. Joe
etienno@gmail.com - 29 Jul 2005 22:11 GMT I have change my code to make the same prepared statement 2 times. It seems that I have the same result.
It took 39,8 seconds for the first query, and 36,9 second for the second query.
This is the code I am using, I hope I am doing the thing correctly. I have log the SQL and the parameter. This function is simply load by a testCase.
public void selectSqlPSFine(String sql, int id) throws SQLException { Date d; logger.debug("inside dao"); logger.debug("SQL USED: " + sql); logger.debug("PARAMETER USED: " + id); JdbcTemplate jdbcTemplate = new JdbcTemplate(dataSource); Connection c = jdbcTemplate.getDataSource().getConnection();
logger.debug("First try: before the query"); d = new Date(); PreparedStatement s = c.prepareStatement(sql); s.setInt(1, id); ResultSet rs = s.executeQuery(); rs.next(); int val = rs.getInt(1); logger.debug("int: " + val); rs.close(); logger.debug("after the query: " + (System.currentTimeMillis()-d.getTime() + " ms"));
logger.debug("Second try: before the query"); d = new Date(); s.setInt(1, id); rs = s.executeQuery(); rs.next(); val = rs.getInt(1); logger.debug("int: " + val); rs.close();
logger.debug("after the query: " + (System.currentTimeMillis()-d.getTime()+ " ms")); s.close(); c.close(); }
2005-07-29 17:06:53,973 DEBUG [main] (SybaseDataAccessBean.java:97) - inside dao 2005-07-29 17:06:53,973 DEBUG [main] (SybaseDataAccessBean.java:98) - SQL USED: select astaddress0_.astAddressId as astAddre1_0_, astaddress0_.ossBranch as ossBranch25_0_ from Corpo.dbo.AstAddress astaddress0_ where astaddress0_.astAddressId=? 2005-07-29 17:06:53,973 DEBUG [main] (SybaseDataAccessBean.java:99) - PARAMETER USED: 798957 2005-07-29 17:06:54,036 DEBUG [main] (SybaseDataAccessBean.java:103) - First try: before the query 2005-07-29 17:07:33,875 DEBUG [main] (SybaseDataAccessBean.java:110) - int: 798957 2005-07-29 17:07:33,875 DEBUG [main] (SybaseDataAccessBean.java:112) - after the query: 39839 ms 2005-07-29 17:07:33,875 DEBUG [main] (SybaseDataAccessBean.java:114) - Second try: before the query 2005-07-29 17:08:10,777 DEBUG [main] (SybaseDataAccessBean.java:120) - int: 798957 2005-07-29 17:08:10,777 DEBUG [main] (SybaseDataAccessBean.java:123) - after the query: 36902 ms
joeNOSPAM@BEA.com - 30 Jul 2005 06:01 GMT Ok, now, just for fun. do the prepared statement with no parameter. Just use the same SQL as the statement, and also execute it twice.
Your results *are* unexpected. Actually, the int-to-numeric might be the issue. Try the SQL:
select astaddress0_.astAddressId as astAddre1_0_, astaddress0_.ossBranch as ossBranch25_0_ from Corpo.dbo.AstAddress astaddress0_ where astaddress0_.astAddressId= convert(numeric, ?)
Lastly, do your original SQL, but instead of setInt(1, ,,,); try setBigDecimal ( new BigDecimal("1") );
Just a few experiments... After collecting the info I would contact Sybase... Joe Weinstein at BEA
etienno@gmail.com - 01 Aug 2005 15:52 GMT Thanks Joe, it work with the BigDecimal change. But My problem now is that I use Hibernate and I cannot (At first glance) change the way the SQL is done. And I ratther prefer to change the driver, or any configuration, before changing this. ecause it might happen elsewhere.
What would be the other solutions? Is that frequent in Sybase to have this issue?
Thanks
Etienne.
etienno@gmail.com - 01 Aug 2005 16:54 GMT Here the patch I have done to correct the problem. I still don't know where the problem is really (is it a Sybase configuration problem, a table misconfiguration, a jdbc or Sybase bug?). I would like to know that to avoid any problem in the future. I still dont know if I will have the same bug in the production environnement (AIX Sybase versus Microsoft Sybase).
For the moment, in development, I will used an Hibernate UserType with these 2 methods:
public Object nullSafeGet(ResultSet rs, String[] names, Object owner) throws HibernateException, SQLException { int val = rs.getInt(names[0]); return new Integer(val); }
public void nullSafeSet(PreparedStatement st, Object value, int index) throws HibernateException, SQLException { st.setBigDecimal(index, new BigDecimal(((Integer)value).intValue())); }
Thanks all if you have any clue of this problem.
Etienne.
etienno@gmail.com - 01 Aug 2005 16:01 GMT This is the result for "convert(numeric, ?)". 45 sec et 39 sec.
005-08-01 10:21:37,974 DEBUG [main] (SybaseDataAccessBean.java:98) - inside dao 2005-08-01 10:21:37,974 DEBUG [main] (SybaseDataAccessBean.java:99) - SQL USED: select astaddress0_.astAddressId as astAddre1_0_, astaddress0_.ossBranch as ossBranch25_0_ from Corpo.dbo.AstAddress astaddress0_ where astaddress0_.astAddressId=convert(numeric, ?) 2005-08-01 10:21:37,974 DEBUG [main] (SybaseDataAccessBean.java:100) - PARAMETER USED: 798957 2005-08-01 10:21:38,037 DEBUG [main] (SybaseDataAccessBean.java:104) - First try: before the query 2005-08-01 10:22:23,288 DEBUG [main] (SybaseDataAccessBean.java:111) - int: 798957 2005-08-01 10:22:23,288 DEBUG [main] (SybaseDataAccessBean.java:113) - after the query: 45251 ms 2005-08-01 10:22:23,319 DEBUG [main] (SybaseDataAccessBean.java:115) - Second try: before the query 2005-08-01 10:23:02,524 DEBUG [main] (SybaseDataAccessBean.java:121) - int: 798957 2005-08-01 10:23:02,524 DEBUG [main] (SybaseDataAccessBean.java:124) - after the query: 39205 ms
But with the BigDecimal value, 32ms for the first result and 15 ms for the second one! I try that many time, and it works now!
2005-08-01 10:28:14,422 DEBUG [main] (SybaseDataAccessBean.java:99) - inside dao 2005-08-01 10:28:14,438 DEBUG [main] (SybaseDataAccessBean.java:100) - SQL USED: select astaddress0_.astAddressId as astAddre1_0_, astaddress0_.ossBranch as ossBranch25_0_ from Corpo.dbo.AstAddress astaddress0_ where astaddress0_.astAddressId=? 2005-08-01 10:28:14,438 DEBUG [main] (SybaseDataAccessBean.java:101) - PARAMETER USED: 798957 2005-08-01 10:28:14,453 DEBUG [main] (SybaseDataAccessBean.java:105) - First try: before the query 2005-08-01 10:28:14,485 DEBUG [main] (SybaseDataAccessBean.java:112) - int: 798957 2005-08-01 10:28:14,485 DEBUG [main] (SybaseDataAccessBean.java:114) - after the query: 32 ms 2005-08-01 10:28:14,485 DEBUG [main] (SybaseDataAccessBean.java:116) - Second try: before the query 2005-08-01 10:28:14,485 DEBUG [main] (SybaseDataAccessBean.java:122) - int: 798957 2005-08-01 10:28:14,500 DEBUG [main] (SybaseDataAccessBean.java:125) - after the query: 15 ms
Where do you think the problem is? Is this a bug in the JDBC driver, Sybase? A wrong configuration of the table-index? I didn't nothing different creating this table than for the 32 other ones in my DB.
The problem I have now is that I use Hibernate as my persistence layer. It might be difficult, at first glance, to control the jdbc that way.
What would be the other possibility to correct this problem?
Etienne.
joeNOSPAM@BEA.com - 01 Aug 2005 17:15 GMT Hi. It is something the driver could fix. When you use int, the drver is sending the value in a way which causes the DBMS to have to do a conversion, which means the DBMS will skip the indexes and do a full table scan. If you use BigDecimal, which is the appropriate type to match your table column, the data is sent in a way which is a direct comparator, so the index is used (fast). The bug is that for any int value, the driver could easily send the data like for BigDecimal. I would post this to the sybase jconnect newsgroup. Joe Weinstein at BEA
etienno@gmail.com - 01 Aug 2005 23:06 GMT Hi,
I have found some information about this issue at :
http://sybooks.sybase.com/onlinebooks/group-asarc/asg1200e/aseperf/@ebt-link;pt= 4128?target=%25N%14_5825_START_RESTART_N%25
Etienne.
Vladyslav Kosulin - 30 Jul 2005 21:44 GMT I had a similar case. For some of our queries PreparedStatement execution was much slower than regular Statement. Try to force index.
Regards, Vlad
> Hi, > [quoted text clipped - 118 lines] > Etienne > Montreal etienno@gmail.com - 31 Jul 2005 01:19 GMT Ok Joe, I will try what you told me, first thing, monday morning. Vlad, what do you mean by forcing the index?
Thanks.
Etienne.
Vladyslav Kosulin - 02 Aug 2005 00:13 GMT > Ok Joe, I will try what you told me, first thing, monday morning. > Vlad, what do you mean by forcing the index? For unknown reasons Sybase (jconn2.jar) did not use an appropriate index and performed a table scan for PreparedStatement while using index for the same Statement. Try to use Sybase SQL extension select my_column from my_table (index my_index)
Regards, Vlad
Free MagazinesGet these publications absolutely FREE for up to 12 months. There are no hidden fees and no obligation. Simply choose a title, complete the application form and submit it. Read more ...
|
|
|