Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Bad PLAN generated for query on Firebird v3.0 [CORE5659] #5925

Closed
firebird-issue-importer opened this issue Nov 13, 2017 · 15 comments
Closed

Comments

@firebird-issue-importer

Submitted by: wesley blanco (wesleyblanco)

Relate to CORE5511

Attachments:
script.zip

Hi.

We are doing a migration process from firebird 2.5 to 3.0, and we found some points of slowness that did not exist.

We realize that it is only at a specific point, a type of join, that does not take any index in firebird 3 and the table is of almost 1mi of records.

We were able to create a script by extracting as few of these tables as possible from one of these points. I've attached the script.

I upload script on my DropBox: https://www.dropbox.com/s/x37rez36ot4jzd6/script.zip?dl=0

steps to reproduce:

1 - create database in version 2.5 and another in 3.0.
2 - run the attached script (isql.exe -> in 'C:\script.sql') on each of these databases.
3 - run select on each of the databases:

    SELECT A\.ID\_PEDIDO\_ITEM,
           C\.DESCRICAO
      FROM COM\_PEDIDO B
      JOIN COM\_PEDIDO\_ITEM A ON A\.ID\_PEDIDO = B\.ID\_PEDIDO
                         AND \(  NOT\(A\.ID\_PRODUTO =1 AND A\.ID\_PEDIDO\_ITEM\_PAI IS NOT NULL\)\)
      JOIN EST\_PRODUTO C ON C\.ID\_PRODUTO = A\.ID\_PRODUTO
     WHERE B\.DTH\_PEDIDO BETWEEN cast\('10\.12\.16 05:00:00' as timestamp\) AND cast\('10\.12\.16 20:00:00'  as timestamp\);

Total records: 107;

FB2.5.7 result:

Plan
------------------------------------------------
PLAN JOIN (B INDEX (COM_PEDIDO_IDX1), A INDEX (FK_COM_PEDIDO_ITEM_PEDIDO), C INDEX (RDB$PRIMARY1))

Adapted Plan
------------------------------------------------
PLAN JOIN (B INDEX (COM_PEDIDO_IDX1), A INDEX (FK_COM_PEDIDO_ITEM_PEDIDO), C INDEX (INTEG_6))

Query Time
------------------------------------------------
Prepare : 16,00 ms
Execute : 31,00 ms
Avg fetch time: 0,29 ms

Memory
------------------------------------------------
Current: 9.300.768
Max : 9.371.088
Buffers: 2.048

Operations
------------------------------------------------
Read : 58
Writes : 0
Fetches: 1.122
Marks : 0

Enchanced Info:
+-------------------------------+-----------+-----------+-------------+---------+---------+---------+----------+----------+----------+
| Table Name | Records | Indexed | Non-Indexed | Updates | Deletes | Inserts | Backouts | Purges | Expunges |
| | Total | reads | reads | | | | | | |
+-------------------------------+-----------+-----------+-------------+---------+---------+---------+----------+----------+----------+
|COM_PEDIDO | 0 | 58 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
|COM_PEDIDO_ITEM | 0 | 113 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
|EST_PRODUTO | 0 | 107 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
+-------------------------------+-----------+-----------+-------------+---------+---------+---------+----------+----------+----------+

Firebird 3.0.2 and 3.0.3.32829 result;

Plan
------------------------------------------------
PLAN JOIN (A NATURAL, C INDEX (RDB$PRIMARY1), B INDEX (PK_COM_PEDIDO))

Adapted Plan
------------------------------------------------
PLAN JOIN (A NATURAL, C INDEX (INTEG_6), B INDEX (PK_COM_PEDIDO))

Query Time
------------------------------------------------
Prepare : 31,00 ms
Execute : 8.766,00 ms
Avg fetch time: 81,93 ms

Memory
------------------------------------------------
Current: 10.233.800
Max : 10.506.880
Buffers: 2.048

Operations
------------------------------------------------
Read : 23.389
Writes : 1
Fetches: 9.867.285
Marks : 0

Enchanced Info:
+-------------------------------+-----------+-----------+-------------+---------+---------+---------+----------+----------+----------+
| Table Name | Records | Indexed | Non-Indexed | Updates | Deletes | Inserts | Backouts | Purges | Expunges |
| | Total | reads | reads | | | | | | |
+-------------------------------+-----------+-----------+-------------+---------+---------+---------+----------+----------+----------+
|COM_PEDIDO | 0 | 977872 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
|COM_PEDIDO_ITEM | 0 | 0 | 998548 | 0 | 0 | 0 | 0 | 0 | 0 |
|EST_PRODUTO | 0 | 977872 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
+-------------------------------+-----------+-----------+-------------+---------+---------+---------+----------+----------+----------+

As you can see, only COM_PEDIDO_ITEM NATURAL was used and the index COM_PEDIDO_IDX1 (COM_PEDIDO.DTH_PEDIDO) was not used.

For me to force the access plan on my system is a bit difficult, as I have this situation at various points in the system making migration difficult.

what justifies this slower behavior compared to 2.5?

Thanks!!

Commits: 3fb7558 8d3021e

@firebird-issue-importer
Copy link
Author

firebird-issue-importer commented Nov 13, 2017

Modified by: wesley blanco (wesleyblanco)

Attachment: script.zip [ 13183 ]

@firebird-issue-importer
Copy link
Author

firebird-issue-importer commented Nov 13, 2017

Commented by: wesley blanco (wesleyblanco)

Sorry my Bad english (translate by google)...

@firebird-issue-importer
Copy link
Author

firebird-issue-importer commented Nov 13, 2017

Modified by: wesley blanco (wesleyblanco)

Component: Engine [ 10000 ]

@firebird-issue-importer
Copy link
Author

firebird-issue-importer commented Nov 13, 2017

Commented by: Sean Leyne (seanleyne)

Removed the Query from the 2.5.7 and 3.x (for readability) since it was exactly the same as the one provided in basic details

@firebird-issue-importer
Copy link
Author

firebird-issue-importer commented Nov 13, 2017

Modified by: Sean Leyne (seanleyne)

description: Hi.

We are doing a migration process from firebird 2.5 to 3.0, and we found some points of slowness that did not exist.

We realize that it is only at a specific point, a type of join, that does not take any index in firebird 3 and the table is of almost 1mi of records.

We were able to create a script by extracting as few of these tables as possible from one of these points. I've attached the script.

I upload script on my DropBox: https://www.dropbox.com/s/x37rez36ot4jzd6/script.zip?dl=0

steps to reproduce:

1 - create database in version 2.5 and another in 3.0.
2 - run the attached script (isql.exe -> in 'C:\script.sql') on each of these databases.
3 - run select on each of the databases:

    SELECT A\.ID\_PEDIDO\_ITEM,
           C\.DESCRICAO
      FROM COM\_PEDIDO B
      JOIN COM\_PEDIDO\_ITEM A ON A\.ID\_PEDIDO = B\.ID\_PEDIDO
                         AND \(  NOT\(A\.ID\_PRODUTO =1 AND A\.ID\_PEDIDO\_ITEM\_PAI IS NOT NULL\)\)
      JOIN EST\_PRODUTO C ON C\.ID\_PRODUTO = A\.ID\_PRODUTO
     WHERE B\.DTH\_PEDIDO BETWEEN cast\('10\.12\.16 05:00:00' as timestamp\) AND cast\('10\.12\.16 20:00:00'  as timestamp\);

Total records: 107;

FB2.5.7 result:

Query
------------------------------------------------
SELECT A.ID_PEDIDO_ITEM,
C.DESCRICAO
FROM COM_PEDIDO B
JOIN COM_PEDIDO_ITEM A ON A.ID_PEDIDO = B.ID_PEDIDO
AND ( NOT(A.ID_PRODUTO =1 AND A.ID_PEDIDO_ITEM_PAI IS NOT NULL))
JOIN EST_PRODUTO C ON C.ID_PRODUTO = A.ID_PRODUTO
WHERE B.DTH_PEDIDO BETWEEN cast('10.12.16 05:00:00' as timestamp) AND cast('10.12.16 20:00:00' as timestamp)

Plan
------------------------------------------------
PLAN JOIN (B INDEX (COM_PEDIDO_IDX1), A INDEX (FK_COM_PEDIDO_ITEM_PEDIDO), C INDEX (RDB$PRIMARY1))

Adapted Plan
------------------------------------------------
PLAN JOIN (B INDEX (COM_PEDIDO_IDX1), A INDEX (FK_COM_PEDIDO_ITEM_PEDIDO), C INDEX (INTEG_6))

Query Time
------------------------------------------------
Prepare : 16,00 ms
Execute : 31,00 ms
Avg fetch time: 0,29 ms

Memory
------------------------------------------------
Current: 9.300.768
Max : 9.371.088
Buffers: 2.048

Operations
------------------------------------------------
Read : 58
Writes : 0
Fetches: 1.122
Marks : 0

Enchanced Info:
+-------------------------------+-----------+-----------+-------------+---------+---------+---------+----------+----------+----------+
| Table Name | Records | Indexed | Non-Indexed | Updates | Deletes | Inserts | Backouts | Purges | Expunges |
| | Total | reads | reads | | | | | | |
+-------------------------------+-----------+-----------+-------------+---------+---------+---------+----------+----------+----------+
|COM_PEDIDO | 0 | 58 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
|COM_PEDIDO_ITEM | 0 | 113 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
|EST_PRODUTO | 0 | 107 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
+-------------------------------+-----------+-----------+-------------+---------+---------+---------+----------+----------+----------+

Firebird 3.0.2 and 3.0.3.32829 result;

Query
------------------------------------------------

SELECT A\.ID\_PEDIDO\_ITEM,
           C\.DESCRICAO
      FROM COM\_PEDIDO B
      JOIN COM\_PEDIDO\_ITEM A ON A\.ID\_PEDIDO = B\.ID\_PEDIDO
                         AND \(  NOT\(A\.ID\_PRODUTO =1 AND A\.ID\_PEDIDO\_ITEM\_PAI IS NOT NULL\)\)
      JOIN EST\_PRODUTO C ON C\.ID\_PRODUTO = A\.ID\_PRODUTO
     WHERE B\.DTH\_PEDIDO BETWEEN cast\('10\.12\.16 05:00:00' as timestamp\) AND cast\('10\.12\.16 20:00:00'  as timestamp\)

Plan
------------------------------------------------
PLAN JOIN (A NATURAL, C INDEX (RDB$PRIMARY1), B INDEX (PK_COM_PEDIDO))

Adapted Plan
------------------------------------------------
PLAN JOIN (A NATURAL, C INDEX (INTEG_6), B INDEX (PK_COM_PEDIDO))

Query Time
------------------------------------------------
Prepare : 31,00 ms
Execute : 8.766,00 ms
Avg fetch time: 81,93 ms

Memory
------------------------------------------------
Current: 10.233.800
Max : 10.506.880
Buffers: 2.048

Operations
------------------------------------------------
Read : 23.389
Writes : 1
Fetches: 9.867.285
Marks : 0

Enchanced Info:
+-------------------------------+-----------+-----------+-------------+---------+---------+---------+----------+----------+----------+
| Table Name | Records | Indexed | Non-Indexed | Updates | Deletes | Inserts | Backouts | Purges | Expunges |
| | Total | reads | reads | | | | | | |
+-------------------------------+-----------+-----------+-------------+---------+---------+---------+----------+----------+----------+
|COM_PEDIDO | 0 | 977872 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
|COM_PEDIDO_ITEM | 0 | 0 | 998548 | 0 | 0 | 0 | 0 | 0 | 0 |
|EST_PRODUTO | 0 | 977872 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
+-------------------------------+-----------+-----------+-------------+---------+---------+---------+----------+----------+----------+

As you can see, only COM_PEDIDO_ITEM NATURAL was used and the index COM_PEDIDO_IDX1 (COM_PEDIDO.DTH_PEDIDO) was not used.

For me to force the access plan on my system is a bit difficult, as I have this situation at various points in the system making migration difficult.

what justifies this slower behavior compared to 2.5?

Thanks!!

=>

Hi.

We are doing a migration process from firebird 2.5 to 3.0, and we found some points of slowness that did not exist.

We realize that it is only at a specific point, a type of join, that does not take any index in firebird 3 and the table is of almost 1mi of records.

We were able to create a script by extracting as few of these tables as possible from one of these points. I've attached the script.

I upload script on my DropBox: https://www.dropbox.com/s/x37rez36ot4jzd6/script.zip?dl=0

steps to reproduce:

1 - create database in version 2.5 and another in 3.0.
2 - run the attached script (isql.exe -> in 'C:\script.sql') on each of these databases.
3 - run select on each of the databases:

    SELECT A\.ID\_PEDIDO\_ITEM,
           C\.DESCRICAO
      FROM COM\_PEDIDO B
      JOIN COM\_PEDIDO\_ITEM A ON A\.ID\_PEDIDO = B\.ID\_PEDIDO
                         AND \(  NOT\(A\.ID\_PRODUTO =1 AND A\.ID\_PEDIDO\_ITEM\_PAI IS NOT NULL\)\)
      JOIN EST\_PRODUTO C ON C\.ID\_PRODUTO = A\.ID\_PRODUTO
     WHERE B\.DTH\_PEDIDO BETWEEN cast\('10\.12\.16 05:00:00' as timestamp\) AND cast\('10\.12\.16 20:00:00'  as timestamp\);

Total records: 107;

FB2.5.7 result:

Plan
------------------------------------------------
PLAN JOIN (B INDEX (COM_PEDIDO_IDX1), A INDEX (FK_COM_PEDIDO_ITEM_PEDIDO), C INDEX (RDB$PRIMARY1))

Adapted Plan
------------------------------------------------
PLAN JOIN (B INDEX (COM_PEDIDO_IDX1), A INDEX (FK_COM_PEDIDO_ITEM_PEDIDO), C INDEX (INTEG_6))

Query Time
------------------------------------------------
Prepare : 16,00 ms
Execute : 31,00 ms
Avg fetch time: 0,29 ms

Memory
------------------------------------------------
Current: 9.300.768
Max : 9.371.088
Buffers: 2.048

Operations
------------------------------------------------
Read : 58
Writes : 0
Fetches: 1.122
Marks : 0

Enchanced Info:
+-------------------------------+-----------+-----------+-------------+---------+---------+---------+----------+----------+----------+
| Table Name | Records | Indexed | Non-Indexed | Updates | Deletes | Inserts | Backouts | Purges | Expunges |
| | Total | reads | reads | | | | | | |
+-------------------------------+-----------+-----------+-------------+---------+---------+---------+----------+----------+----------+
|COM_PEDIDO | 0 | 58 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
|COM_PEDIDO_ITEM | 0 | 113 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
|EST_PRODUTO | 0 | 107 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
+-------------------------------+-----------+-----------+-------------+---------+---------+---------+----------+----------+----------+

Firebird 3.0.2 and 3.0.3.32829 result;

Plan
------------------------------------------------
PLAN JOIN (A NATURAL, C INDEX (RDB$PRIMARY1), B INDEX (PK_COM_PEDIDO))

Adapted Plan
------------------------------------------------
PLAN JOIN (A NATURAL, C INDEX (INTEG_6), B INDEX (PK_COM_PEDIDO))

Query Time
------------------------------------------------
Prepare : 31,00 ms
Execute : 8.766,00 ms
Avg fetch time: 81,93 ms

Memory
------------------------------------------------
Current: 10.233.800
Max : 10.506.880
Buffers: 2.048

Operations
------------------------------------------------
Read : 23.389
Writes : 1
Fetches: 9.867.285
Marks : 0

Enchanced Info:
+-------------------------------+-----------+-----------+-------------+---------+---------+---------+----------+----------+----------+
| Table Name | Records | Indexed | Non-Indexed | Updates | Deletes | Inserts | Backouts | Purges | Expunges |
| | Total | reads | reads | | | | | | |
+-------------------------------+-----------+-----------+-------------+---------+---------+---------+----------+----------+----------+
|COM_PEDIDO | 0 | 977872 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
|COM_PEDIDO_ITEM | 0 | 0 | 998548 | 0 | 0 | 0 | 0 | 0 | 0 |
|EST_PRODUTO | 0 | 977872 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
+-------------------------------+-----------+-----------+-------------+---------+---------+---------+----------+----------+----------+

As you can see, only COM_PEDIDO_ITEM NATURAL was used and the index COM_PEDIDO_IDX1 (COM_PEDIDO.DTH_PEDIDO) was not used.

For me to force the access plan on my system is a bit difficult, as I have this situation at various points in the system making migration difficult.

what justifies this slower behavior compared to 2.5?

Thanks!!

@firebird-issue-importer
Copy link
Author

firebird-issue-importer commented Nov 13, 2017

Commented by: @livius2

Interesting that this is affected because of not null testing (ID_PEDIDO_ITEM_PAI IS NOT NULL)
adding +0

---------------------------------------

SELECT A.ID_PEDIDO_ITEM,
C.DESCRICAO

FROM
COM_PEDIDO B
INNER JOIN COM_PEDIDO_ITEM A ON A.ID_PEDIDO = B.ID_PEDIDO AND ( NOT(A.ID_PRODUTO =1 AND A.ID_PEDIDO_ITEM_PAI+0 IS NOT NULL))
INNER JOIN EST_PRODUTO C ON C.ID_PRODUTO = A.ID_PRODUTO
WHERE
B.DTH_PEDIDO BETWEEN cast('10.12.16 05:00:00' as timestamp) AND cast('10.12.16 20:00:00' as timestamp)

---------------------------------------

cause
PLAN JOIN (B INDEX (COM_PEDIDO_IDX1), A INDEX (FK_COM_PEDIDO_ITEM_PEDIDO), C INDEX (RDB$PRIMARY1))

@firebird-issue-importer
Copy link
Author

firebird-issue-importer commented Nov 14, 2017

Modified by: @dyemanov

assignee: Dmitry Yemanov [ dimitr ]

@firebird-issue-importer
Copy link
Author

firebird-issue-importer commented Nov 14, 2017

Commented by: wesley blanco (wesleyblanco)

Interesting
i've tested using CAST(a.ID_PEDIDO_ITEM_PAI as integer) and works fine too.

======
SELECT A.ID_PEDIDO_ITEM,
C.DESCRICAO
FROM COM_PEDIDO B
JOIN COM_PEDIDO_ITEM A ON A.ID_PEDIDO = B.ID_PEDIDO
and (not(( A.id_produto = 1 ) and cast(A.ID_PEDIDO_ITEM_PAI as integer) IS not NULL))
JOIN EST_PRODUTO C ON C.ID_PRODUTO = A.ID_PRODUTO
WHERE B.DTH_PEDIDO BETWEEN cast('10.12.16 05:00:00' as timestamp) AND cast('10.12.16 20:00:00' as timestamp)

====
Plan
PLAN JOIN (B INDEX (COM_PEDIDO_IDX1), A INDEX (FK_COM_PEDIDO_ITEM_PEDIDO), C INDEX (RDB$PRIMARY1))

Adapted Plan
PLAN JOIN (B INDEX (COM_PEDIDO_IDX1), A INDEX (FK_COM_PEDIDO_ITEM_PEDIDO), C INDEX (INTEG_6))

@firebird-issue-importer
Copy link
Author

firebird-issue-importer commented Nov 14, 2017

Commented by: @livius2

@wesley blanco
Cast is here same as +0 so no surprise

@firebird-issue-importer
Copy link
Author

firebird-issue-importer commented Nov 14, 2017

Modified by: @dyemanov

summary: Bad acess plan on firebird 3.0 => Bad access plan on firebird 3.0

@firebird-issue-importer
Copy link
Author

firebird-issue-importer commented Nov 14, 2017

Modified by: Sean Leyne (seanleyne)

summary: Bad access plan on firebird 3.0 => Bad PLAN generated for query on Firebird v3.0

@firebird-issue-importer
Copy link
Author

firebird-issue-importer commented Nov 20, 2017

Modified by: @dyemanov

status: Open [ 1 ] => Resolved [ 5 ]

resolution: Fixed [ 1 ]

Fix Version: 3.0.3 [ 10810 ]

Fix Version: 4.0 Beta 1 [ 10750 ]

@firebird-issue-importer
Copy link
Author

firebird-issue-importer commented Nov 20, 2017

Modified by: @dyemanov

Link: This issue relate to CORE5511 [ CORE5511 ]

@firebird-issue-importer
Copy link
Author

firebird-issue-importer commented Nov 21, 2017

Modified by: @pavel-zotov

status: Resolved [ 5 ] => Resolved [ 5 ]

QA Status: No test => Done successfully

@firebird-issue-importer
Copy link
Author

firebird-issue-importer commented Nov 21, 2017

Modified by: @pavel-zotov

status: Resolved [ 5 ] => Closed [ 6 ]

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants