Slow Select Statement

Thread view:

Enable EMail Alerts

Start New Thread

Thread rating:

Paul Hutchinson - 13 Aug 2004 12:55 GMT

Hello folks

I have a problem with a SELECT statement that's running much too
slowly. It's holding up an overnight batch job that normally takes an
hour so that its taking over 24 hours.

The system in question runs on 5 separate regional databases, each
with their own DBMS server. The SELECT in question runs fine on 4 of
the 5 databases, but is taking forever on the 5th database. I've
attached two QEPs one for the poorly performing database, and one
for a normal database. The QEPs both look okay to me but I can't
understand why it would take 6 mins to retrieve 1783 rows on the
normal database, and 100 mins to retrieve no rows on the slow
database. The QE90 output shows a big difference between estimated and
actuals for the joins, but I don't know why this is.

Does anyone have any suggestions where the problem might lie here? The
tables look normal (in terms of statistics, overflow, indexes etc).

Thanks in advance

Paul Hutchinson

INGRES TERMINAL MONITOR Copyright (c) 1981, 1998 Computer Associates
Intl, Inc. Ingres PTX Version II 2.0/0001 (sqs.ptx/00) login
Fri Aug 13 10:21:49 2004

continue
* * /* SQL Startup File */
commit;
Executing . . .

continue
* * set lockmode session where readlock = nolock;
Executing . . .

continue
* * select date('now');
Executing . . .

+-------------------------+

|col1 |

+-------------------------+

|13-aug-2004 10:21:49 |

+-------------------------+
(1 row)
continue
* * *
set qep;
Executing . . .

continue
* * *
set trace point qe90;
Executing . . .

continue
* * * * * * * * * * * * * * * *
select distinct account.account_ref, 'RR', date('today'),
account.last_action_number+1, 166, date('now'), 166, date('now'),
'AMIS'
from
t_prop_rev_charge, account, t_hb_payment, tenants_link_to_tenancy
where t_prop_rev_charge.set_id=60353
and t_hb_payment.set_id=t_prop_rev_charge.set_id
and account.property_ref=t_prop_rev_charge.property_ref
and account.account_ref=t_hb_payment.account_ref
and account.account_type='RR'
and tenants_link_to_tenancy.account_ref=account.account_ref
and tenants_link_to_tenancy.direct_payment_indicator='Y'
;
Executing . . .

********************************************************************
!!SLOW DATABASE QEP!!
---------------------
QUERY PLAN 6,1, no timeout, of main query

Sort
Unique
Pages 1
Tups 1
D12.469
C15.761

/
K
Join(CO)(account_ref)
Heap
Pages 1 Tups 1
D12.469 C15.691
/ \
K Join(account_ref)
tenants_link_to_tenancy
Heap
Isam(account_ref)
Pages 1 Tups 1 Pages 2675
Tups 84601
D10.969 C15.523
/ \
Cart-Prod account
Heap B-Tree(account_ref)
Pages 1 Tups 15 Pages 43085 Tups
124394
D7.969 C15.225
/ \
Proj-rest Proj-rest
Heap Heap
Pages 1 Tups 15 Pages 1 Tups 1
D6.250 C14.900 D1.719 C0.017
/ /
t_prop_rev_charge t_hb_payment
Heap Hashed(set_id)
Pages 25 Tups 1490 Pages 220 Tups 2271

********************************************************************

+-------+------+-------------------------+-------------+------+-------------------------+------+-------------------------+------+

|account|col2 |col3 |col4 |col5 |col6

|col7 |col8 |col9 |
+-------+------+-------------------------+-------------+------+-------------------------+------+-------------------------+------+

********************************************************************

----------
TSORT
at 0
et 1

ad 969964
ed 12

ac 258309
ec 1576

et 6047
----------
/
----------
KJOIN
at 0
et 1

ad 969964
ed 12

ac 258309
ec 1569

et 6047
----------
/
----------
KJOIN
at 0
et 1

ad 969964
ed 10

ac 258309
ec 1552

et 6047
----------
/
----------
CPJOIN
at 0
et 14

ad 96
ed 7

ac 2649
ec 1522

et 10
----------
/ \
---------- ----------
ORIG ORIG
at 377 at 2271
et 14 et 1

ad 6 ad 91
ed 6 ed 1

ac 8 ac 38
ec 1490 ec 1

et 0 et 1
---------- ----------

********************************************************************
+-------+------+-------------------------+-------------+------+-------------------------+------+-------------------------+------+
(0 rows)
continue
* * * * *

select date('now');
Executing . . .

+-------------------------+

|col1 |

+-------------------------+

|13-aug-2004 12:02:36 |

+-------------------------+
(1 row)
continue
* *
Your SQL statement(s) have been committed.

Ingres Version II 2.0/0001 (sqs.ptx/00) logout
Fri Aug 13 12:02:36 2004
elvis icl-BE> cat qep.log5
INGRES TERMINAL MONITOR Copyright (c) 1981, 1998 Computer Associates
Intl, Inc. Ingres PTX Version II 2.0/0001 (sqs.ptx/00) login
Fri Aug 13 12:14:11 2004

continue
* * /* SQL Startup File */
commit;
Executing . . .

continue
* * set lockmode session where readlock = nolock;
Executing . . .

continue
* * select date('now');
Executing . . .

+-------------------------+

|col1 |

+-------------------------+

|13-aug-2004 12:14:11 |

+-------------------------+
(1 row)
continue
* * *
set qep;
Executing . . .

continue
* * *
set trace point qe90;
Executing . . .

continue
* * * * * * * * * * * * * * * *
select distinct account.account_ref, 'RR', date('today'),
account.last_action_number+1, 166, date('now'), 166, date('now'),
'AMIS'
from
t_prop_rev_charge, account, t_hb_payment, tenants_link_to_tenancy
where t_prop_rev_charge.set_id=60353
and t_hb_payment.set_id=t_prop_rev_charge.set_id
and account.property_ref=t_prop_rev_charge.property_ref
and account.account_ref=t_hb_payment.account_ref
and account.account_type='RR'
and tenants_link_to_tenancy.account_ref=account.account_ref
and tenants_link_to_tenancy.direct_payment_indicator='Y'
;
Executing . . .

********************************************************************
!!NORMAL DATABASE QEP!!
-----------------------
QUERY PLAN 8,1, no timeout, of main query

Sort Unique

Pages 0 Tups 1

D59.500 C19.943

/
K
Join(CO)(account_ref)
Heap
Pages 0
Tups 1
D59.500
C19.873
/
\
FSM
Join(CO)(property_retenants_link_to_tenancy
Sorted(NU)
Isam(account_ref)
Pages 1 Tups 1
Pages 3622 Tups 114573
D58.000 C19.705
/
\
K Join(account_ref)
Proj-rest
SortU on(property_ref)
SortU on(property_ref)
Pages 1 Tups 1
Pages 1 Tups 18
D50.250 C0.493
D7.750 C18.130
/ \ /
Proj-rest account
t_prop_rev_charge
Heap B-Tree(account_ref) Heap
Pages 1 Tups 1 Pages 65408 Tups 188811 Pages 31
Tups 1813
D47.250 C0.472
/
t_hb_payment
Hashed(set_id)
Pages 756 Tups 18425

********************************************************************

+-------+------+-------------------------+-------------+------+-------------------------+------+-------------------------+------+

|account|col2 |col3 |col4 |col5 |col6

|col7 |col8 |col9 |
+-------+------+-------------------------+-------------+------+-------------------------+------+-------------------------+------+
(data removed)
********************************************************************

----------
TSORT
at 1783
et 1

ad 22146
ed 59

ac 12111
ec 1994

et 352
----------
/
----------
KJOIN
at 1783
et 1

ad 22111
ed 59

ac 11961
ec 1987

et 352
----------
/
----------
FSMJOIN
at 1813
et 1

ad 19215
ed 58

ac 10170
ec 1970

et 308
----------
/ \
---------- ----------
TSORT SORT
at 18425
et 1

ad 19207 ad 8
ed 50 ed 7

ac 9887 ac 49
ec 49 ec 1813

et 307 et 1
---------- ----------
/ /
---------- ----------
KJOIN ORIG
at 18425 at 1813
et 1 et 18

ad 18852 ad 8
ed 50 ed 7

ac 8677 ac 20
ec 49 ec 1813

et 302 et 0
---------- ----------
/
----------
ORIG
at 18425
et 1

ad 739
ed 47

ac 467
ec 47

et 15
----------

********************************************************************
+-------+------+-------------------------+-------------+------+-------------------------+------+-------------------------+------+
(1783 rows)
continue
* * * * *

select date('now');
Executing . . .

+-------------------------+

|col1 |

+-------------------------+

|13-aug-2004 12:20:04 |

+-------------------------+
(1 row)
continue
* *
Your SQL statement(s) have been committed.

Ingres Version II 2.0/0001 (sqs.ptx/00) logout
Fri Aug 13 12:20:04 2004

Reply to this Message

Karl & Betty Schendel - 13 Aug 2004 15:29 GMT

>Hello folks
>
[quoted text clipped - 3 lines]
>
>[snip]

I don't know why the two QEP's are different, but the problem with the
slow one is the cart-prod as the first join. For some reason, the
optimizer thinks that one row will emerge from an orig like:
select * from t_hb_payment where set_id = 60353
which is apparently false in both cases. But for whatever reason,
in the slow case Ingres decides to be cute and generate a cart-prod,
"knowing" that one side is only supplying one row. Unfortunately,
when it supplies 2271 rows according to the qe90, the cart-prod is
going to take forever. Look up one level to see the effects:
the cart-prod took 6037 seconds, yep about 100 minutes.

You can quick-fix it by setting the trace point that tells Ingres to
not generate non-required cart-prods; I think it's OP187, but you might
want to double check that against the tracepoint list. Longer
term you might want to make sure that the stats for t_hb_payment.set_id
are correct.

Karl

Reply to this Message

Paul Hutchinson - 17 Aug 2004 10:51 GMT

Thanks Karl

Right enough, the cartesian product does look pretty ugly. I was
confused that the estimates and the actuals weren't that far off in
the QE90 at that step, but were much further out further up the plan.

I'll try the trace point next weekend (the query is within a weekend
batch job) - I'm not sure what has happened to cause this, tho. The
optimizer doesn't use statistics on t_hb_payment or t_prop_rev_charge,
since these are temporary tables, and the data in the them will change
completely from run to run.

Thanks for your help

Paul

Reply to this Message