Anonymous | Login
Project:
RSS
  
News | My View | View Issues | Roadmap | Summary

View Issue Details[ Jump to Notes ] [ Issue History ] [ Print ]
ID
0010318
TypeCategorySeverityReproducibilityDate SubmittedLast Update
defect[Openbravo ERP] I. Performancemajoralways2009-08-18 16:232009-10-06 11:09
ReporterklawandronicView Statuspublic 
Assigned Toshuehner 
PriorityhighResolutionfixedFixed in Version2.50MP6
StatusclosedFix in branchFixed in SCM revision86cfdaef6038
ProjectionnoneETAnoneTarget Version
OSAnyDatabasePostgreSQLJava versionany
OS VersionanyDatabase versionanyAnt versionany
Product Version2.40MP8SCM revisionany 
Review Assigned To
Web browser
ModulesCore
Regression level
Regression date
Regression introduced in release
Regression introduced by commit
Triggers an Emergency PackNo
Summary

0010318: Big performance issue on PostgreSQL with large table data

DescriptionWe've spotted a problem in Openbravo that it's not a blocker, but it's definetely a pain when working on tables with a lot of records.
We only noticed this issue with PostgreSQL.

The problem is like this, on certain pages if you have something like 200K records in the corresponding table(for example Sales Order, Business Partner, User, etc.) then the edit page takes something like 15 seconds to load.
At first we couldn't believe that the number of records can influence the application like this so we started profiling.
All the test showed us that all the extra time was spent on some small selects(for example SalesOrder.HeaderData.selectDef2166_0();).

Using Openbravo, the query took 2 ms on the Openbravo sample database(~0 records in the table) which is comparable to PgAdmin's 1ms response time.
When doing the same query on 200K records database, the Openbravo query took 1700ms in comparison to PgAdmin's 2ms.
Have a few of this when loading a page and you will notice a real delay.
Steps To ReproduceThis is the query:

<SqlMethod name="selectDef2166_0" type="preparedStatement" return="String" default="">
    <SqlMethodComment>Select for auxiliar field</SqlMethodComment>
    <Sql><![CDATA[
            SELECT ( COALESCE(TO_CHAR(table1.Name), '') ) as CreatedBy FROM AD_User table1 WHERE table1.isActive='Y' AND table1.AD_User_ID = ?
        ]]></Sql>
    <Parameter name="CreatedByR" />
</SqlMethod>

It looks OK, and if you test it using PgAdmin you won't be able to reproduce the slow response; not even with JDBC if you don't know what the problem is.
This is where we got lucky <http://www.ilyasterin.com/blog/2009/05/postgres-prepared-statements-gotcha.html> [^]
Proposed SolutionThis is the explanation:
- each time you send a bad parameter type to PostgreSQL it first tries to match a propper type to that parameter instead of throwing an error
- in this case the parameter type should be Int but Openbravo sets it as String
- for each row in the table PostgreSQL is trying the type match
- thus for small tables you won't see any delay but for large tables the delay grows exponentialy
- so, the more records you have in a table, the longer it will take to retrieve one
- the problem is reproducible with JDBC if you use the above query and set the parameter using preparedStatement.setString() instead of preparedStatement.setInt()


This is the Openbravo Bug:
- when generating combo boxes selects, use int for the xsql parameter type OR
- generate a TO_NUMBER(?) instead of ? in the prepared statement string

As PostgreSQL is more and more accepted as an Enterprise RDBMS, more and more Openbravo partners will face this problem.
TagsNo tags attached.
Attached Filesdiff file icon wad-tonumber.diff [^] (2,279 bytes) 2009-08-31 17:56 [Show Content]

- Relationships [ Relation Graph ] [ Dependency Graph ]
related to defect 0010344 closedshuehner org.openbravo.erpCommon.utility.ComboTableData performance issue on PostgreSQL 
related to backport 00115302.40MP12 closedshuehner Time response of query generated by WAD is very high 
blocks defect 0004038 closedshuehner Slow compilation in sqlC part due to high amount of data 

-  Notes
(0019010)
rafaroda (developer)
2009-08-18 16:51

 Stefan,

Could you please comment on this performance issue?

Thank you.
(0019013)
villind (developer)
2009-08-18 18:08

 One other possible solution would be fixing the following method:

org.openbravo.data.UtilSql.setValue(PreparedStatement ps, int posicion, int tipo, String strDefault, String strValor)

Instead of the current type binding the correct type binding can requested from the PreparedStatement metadata.
(0019014)
shuehner (administrator)
2009-08-18 19:34

 Hi villind,

this does unfortunately not work on oracle as getPreparedStatement metadata there is not implemented, so the only way to get the needed parameter datatype information would be to add it as an attribute to the sqlc parameter definition.

This was checked when the postgres 8.3 support was done and decided against it. Instead the to_number casts were introduced to do the needed typecasts.

However, i am not yet convinced that these sql is the performance culprit for klawandronic, as the select shown filter by the tables primary key. I'll need to work with him to verify this claim, or find another cause.
(0019032)
klawandronic (reporter)
2009-08-19 08:02

 Hi shuehner,

Just for the record, Ville is one of the guys helping us identify this issue.

The UtilSql.setValue(PreparedStatement ps, int posicion, int tipo, String strDefault, String strValor) method could do it, but in order for the "tipo" parameter to be set correctly, the "type" argument in the sqlc paramater tag must be set. We tried to find an example on this one, even tried to use type="22", type="long", type="0", etc. with no result. Now I can see that you gave up on the usage of this parameter, so that's no use. We're stuck with generating TO_NUMBER(?).

Let me know what info can I provide to help you get to the conclusion that this is the issue behind the bad performance.

We were able to get to this conclusion after we've created a new java project and performing the same query(without TO_NUMBER) on the large database with different prepared statement set methods. These are the results:

- preparedStatement.setInt(1, 1000039); // as type should be
the response time was 27ms

- preparedStatement.setObject(1, "1000039"); // as stated in the link provided above
the response time was 2921ms

- preparedStatement.setString(1, "1000039"); // as generated by Openbravo
the response time was 2259ms

If we use the same query but with TO_NUMBER then

- preparedStatement.setString(1, "1000039"); // as generated by Openbravo
the response time was 29ms

Thus the conclusion that TO_NUMBER(?) must be used ... as long as there is no way to do the correct type cast in UtilSql.setValue(...)

I have the same skype/ymess/gtalk ids if you want to contact me directly for additional info.

Regards,
Viorel
(0019033)
villind (developer)
2009-08-19 08:09

 To reproduce the same/similar issue with pgadmin/psql

1. Correct data types -> index is used
explain
SELECT ( COALESCE(TO_CHAR(table1.Name), '') ) as BM_Delivery_Bpartner_ID
FROM C_BPartner table1
WHERE table1.isActive='Y' AND table1.C_BPartner_ID = 1000039

2. Incorrect datatypes -> no index is used
explain
SELECT ( COALESCE(TO_CHAR(table1.Name), '') ) as BM_Delivery_Bpartner_ID
FROM C_BPartner table1
WHERE table1.isActive='Y' AND to_char(table1.C_BPartner_ID) = '1000039'
(0019038)
shuehner (administrator)
2009-08-19 09:29

 klawandronic: The code in Sqlc is not complete regarding the use of a datatype for setValue. Part of the infrastructure is there as you found, but not type attribute for the Parameter tag is parsed, so you cannot specify a type. Which leads to the not working which you see.
(0019039)
shuehner (administrator)
2009-08-19 09:32

 villind: Thanks for rechecking, We have one more reason to change this even. Which 8.3 postgres did remove most of the automatic type-cast completely so a to_number (or usage of correct jdbc-type) is needed in nearly all cases passing parameters, which leads to the general rule of always doing (in 2.40 only) the to_number call around preparedStatement argumentss for id-values. The rule seems to be missed here, i'll take a look to reproduce locally and fix.
(0019041)
klawandronic (reporter)
2009-08-19 10:10

 I think I found a dirty fix.

In Wad.java, method private void processTabXSQL( ... ), in the default fields section(see comment in code) replace

fields.append( " AND table1." + fieldsDef[i].name + " = ? " );

with

if( fieldsDef[i].name.indexOf( "_ID" ) > 0 || fieldsDef[i].name.indexOf( "_id" ) > 0 )
                        fields.append( " AND table1." + fieldsDef[i].name + " = TO_NUMBER(?) " );
                    else
                        fields.append( " AND table1." + fieldsDef[i].name + " = ? " );

I cannot tell the line number because I've reformatted the code.

Anyway this is a dirty fix, please let me know if there is a cleaner way to do it.

Regards,
Viorel
(0019047)
klawandronic (reporter)
2009-08-19 11:00

 The bigger problem is that Openbravo is missing type casts in more than one place.

After eliminating the problem in combo-boxes with the above fix, at least the following method is also running slow

org.openbravo.erpCommon.utility.ComboTableData.select(boolean);

with the same issue.
(0019354)
villind (developer)
2009-08-31 17:57

 Attached cleaner patch to work around this issue.
(0019929)
shuehner (administrator)
2009-09-14 19:05

 Status: The patch provided by villind is committed 2.40 branch. Thanks villind!)

Nice side-effect: This speeds up the srcAD part of Sqlc at compile time by about 15s (50%) in a local testcase.
(0020081)
hgbot (developer)
2009-09-15 17:53

 Repository: erp/stable/2.40
Changeset: 86cfdaef60381370572dc4904a7446c567330c37
Author: Stefan Hühner <stefan.huehner <at> openbravo.com>
Date: Mon Sep 14 19:01:38 2009 +0200
URL: http://code.openbravo.com/erp/stable/2.40/rev/86cfdaef60381370572dc4904a7446c567330c37 [^]

Fixed 10318: Improve performance of generated windows on postgres >=8.3
Committed patch written by Ville Lindfors.
The xsql files for the generated windows was missing some to_number calls,
which in this case was syntactically ok but lead to bad performance as
only SeqScans were used as a result of the missing to_number calls.

---
M src-wad/src/org/openbravo/wad/Wad.java
---
(0020435)
hgbot (developer)
2009-09-29 12:02

 Repository: erp/stable/2.40_pageddatagrid
Changeset: 86cfdaef60381370572dc4904a7446c567330c37
Author: Stefan Hühner <stefan.huehner <at> openbravo.com>
Date: Mon Sep 14 19:01:38 2009 +0200
URL: http://code.openbravo.com/erp/stable/2.40_pageddatagrid/rev/86cfdaef60381370572dc4904a7446c567330c37 [^]

Fixed 10318: Improve performance of generated windows on postgres >=8.3
Committed patch written by Ville Lindfors.
The xsql files for the generated windows was missing some to_number calls,
which in this case was syntactically ok but lead to bad performance as
only SeqScans were used as a result of the missing to_number calls.

---
M src-wad/src/org/openbravo/wad/Wad.java
---
(0020740)
psarobe (manager)
2009-10-06 11:09

 Closed again because hudson has reopened without no reason

- Issue History
Date Modified Username Field Change
2009-08-18 16:23 klawandronic New Issue
2009-08-18 16:23 klawandronic Assigned To => rafaroda
2009-08-18 16:25 klawandronic Issue Monitored: klawandronic
2009-08-18 16:51 rafaroda Note Added: 0019010
2009-08-18 16:51 rafaroda Assigned To rafaroda => shuehner
2009-08-18 16:51 rafaroda Priority normal => urgent
2009-08-18 16:51 rafaroda Severity critical => major
2009-08-18 16:51 rafaroda Status new => acknowledged
2009-08-18 17:57 villind Issue Monitored: villind
2009-08-18 18:03 shuehner Priority urgent => high
2009-08-18 18:08 villind Note Added: 0019013
2009-08-18 19:34 shuehner Note Added: 0019014
2009-08-19 08:02 klawandronic Note Added: 0019032
2009-08-19 08:09 villind Note Added: 0019033
2009-08-19 09:29 shuehner Note Added: 0019038
2009-08-19 09:32 shuehner Note Added: 0019039
2009-08-19 10:10 klawandronic Note Added: 0019041
2009-08-19 11:00 klawandronic Note Added: 0019047
2009-08-20 06:38 rafaroda Relationship added related to 0010344
2009-08-31 17:56 villind File Added: wad-tonumber.diff
2009-08-31 17:57 villind Note Added: 0019354
2009-09-14 19:05 shuehner Note Added: 0019929
2009-09-14 19:21 shuehner Relationship added blocks 0004038
2009-09-15 17:53 hgbot Checkin
2009-09-15 17:53 hgbot Note Added: 0020081
2009-09-15 17:53 hgbot Status acknowledged => resolved
2009-09-15 17:53 hgbot Resolution open => fixed
2009-09-15 17:53 hgbot Fixed in SCM revision => http://code.openbravo.com/erp/stable/2.40/rev/86cfdaef60381370572dc4904a7446c567330c37 [^]
2009-09-18 13:23 psarobe Status resolved => closed
2009-09-18 13:23 psarobe Fixed in Version => 2.50MP6
2009-09-19 00:00 anonymous sf_bug_id 0 => 2861726
2009-09-23 15:39 shuehner Relationship added related to 0010715
2009-09-23 15:40 shuehner Relationship deleted related to 0010715
2009-09-29 12:02 hgbot Checkin
2009-09-29 12:02 hgbot Note Added: 0020435
2009-09-29 12:02 hgbot Status closed => resolved
2009-09-29 12:02 hgbot Fixed in SCM revision http://code.openbravo.com/erp/stable/2.40/rev/86cfdaef60381370572dc4904a7446c567330c37 [^] => http://code.openbravo.com/erp/stable/2.40_pageddatagrid/rev/86cfdaef60381370572dc4904a7446c567330c37 [^]
2009-10-06 11:09 psarobe Status resolved => closed
2009-10-06 11:09 psarobe Note Added: 0020740
2009-12-14 22:05 shuehner Relationship added related to 0011530

Copyright © 2000 - 2009 MantisBT Group
Powered by Mantis Bugtracker