Tell me more ×
Database Administrators Stack Exchange is a question and answer site for database professionals who wish to improve their database skills and learn from others in the community. It's 100% free, no registration required.

We have an Oracle 11g2 installation. I have a query which joins four tables of approx. 30,000 rows each. The join conditions mostly are simple equalities. There are some NOT LIKE on strings and some >= and <= on dates. The result is about 5,000 records.

When I run this query in one particular schema, the response either comes in 5 seconds, or takes over 1,000 seconds. It alternates back and forth between these two times, so if I run the query 20 times sequentially, four or five of the runs take 5 seconds and the others take a little more than 1,000 seconds.

Additionally, when the response takes 1,000 seconds, the first 1,000 records fetch in about 2 seconds, records 1,000-2,000 take about 30 seconds, 2,000-3,000 take about 90 seconds and so on.

The two NOT LIKEs are performed on the primary key column of one the tables in the join. If I instead do the same two NOT LIKEs on the referencing column, the query always takes 4 seconds. So SELECT a.id FROM a, b WHERE a.id=b.id AND a.id NOT LIKE 'ptn%' takes around 1,000 seconds, whereas SELECT a.id FROM a, b WHERE a.id=b.id AND b.id NOT LIKE 'ptn%' takes 4 seconds.

We have traced the execution, and noticed that Oracle is using two entirely different execution plans, one of them matching 4 seconds and one matching 1,000 seconds.

Can anyone give any advice what might cause an Oracle query to alternate seemingly randomly back and forth between execution times of 4 seconds and 1,000 seconds - and what can be done to avoid this?

The query that alternates between taking 4 seconds and 1,000 seconds:

select g.ucid, a.ucid
from account a, groups g, group_members gm, group_groups_flat ggf
where a.ucid = gm.ucid_member
    and gm.ucid_group = ggf.ucid_member
    and ggf.ucid_group = g.ucid
    and a.status = 'active'
    and g.unix_gid is not null
    and (g.valid_to is null or g.valid_to > sysdate)
    and g.sql is null
    and gm.valid_from <= sysdate
    and gm.valid_to >= sysdate
    and g.ucid not like '$_%' escape '$'
    and g.ucid not like 's$_%' escape '$'
    and gm.ucid_group not like '_agreement_%'
    and gm.ucid_group not like '_pdb_email_%'
    and gm.ucid_group <> '_relation_others_grace'

[EDIT: removed a second query that worked, since it did not add value to the question but was confusing what the problem regarded. Also added the logging output with the two distinct execution plans]

Here is the log output when the query runs fast:

select g.ucid, a.ucid
from account a, groups g, group_members gm, group_groups_flat ggf
where a.ucid = gm.ucid_member
    and gm.ucid_group = ggf.ucid_member
    and ggf.ucid_group = g.ucid
    and a.status = 'active'
    and g.unix_gid is not null
    and (g.valid_to is null or g.valid_to > sysdate)
    and g.sql is null
    and gm.valid_from <= sysdate
    and gm.valid_to >= sysdate
    and g.ucid not like '$_%' escape '$'
    and g.ucid not like 's$_%' escape '$'
    and gm.ucid_group not like '_agreement_%'
    and gm.ucid_group not like '_pdb_email_%'
    and gm.ucid_group <> '_relation_others_grace'

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch      111      0.45       1.01      10536      15663          0        5455
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total      113      0.46       1.02      10536      15663          0        5455

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 88  
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
  5455       5455       5455  HASH JOIN  (cr=15663 pr=10536 pw=0 time=855673 us cost=82273 size=2707430769293 card=14028138701)
 79272      79272      79272   TABLE ACCESS FULL GROUPS (cr=1008 pr=0 pw=0 time=22154 us cost=277 size=10693 card=289)
385836     385836     385836   HASH JOIN  (cr=14655 pr=10536 pw=0 time=1019103 us cost=15581 size=334082015904 card=2141551384)
 36817      36817      36817    HASH JOIN  (cr=10766 pr=10536 pw=0 time=203303 us cost=2921 size=1584289 card=17801)
  6540       6540       6540     TABLE ACCESS FULL ACCOUNT (cr=630 pr=479 pw=0 time=19492 us cost=173 size=111180 card=6540)
163407     163407     163407     INDEX FAST FULL SCAN IDX_GROUP_MEMBERS (cr=10136 pr=10057 pw=0 time=1285634 us cost=2747 size=14434848 card=200484)(object id 118047)
375411     375411     375411    TABLE ACCESS FULL GROUP_GROUPS_FLAT (cr=3889 pr=0 pw=0 time=58535 us cost=1029 size=25152738 card=375414)

And from a slow run:

select g.ucid, a.ucid
from account a, groups g, group_members gm, group_groups_flat ggf
where a.ucid = gm.ucid_member
    and gm.ucid_group = ggf.ucid_member
    and ggf.ucid_group = g.ucid
    and a.status = 'active'
    and g.unix_gid is not null
    and (g.valid_to is null or g.valid_to > sysdate)
    and g.sql is null
    and gm.valid_from <= sysdate
    and gm.valid_to >= sysdate
    and g.ucid not like '$_%' escape '$'
    and g.ucid not like 's$_%' escape '$'
    and gm.ucid_group not like '_agreement_%'
    and gm.ucid_group not like '_pdb_email_%'
    and gm.ucid_group <> '_relation_others_grace'

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        9      0.00       0.00          0          0          0           0
Execute      9      0.00       0.00          0          0          0           0
Fetch     1072   9440.36    9694.78      20406     141617          0       52699
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total     1090   9440.37    9694.79      20406     141617          0       52699

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 88  
Number of plan statistics captured: 3

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
       5455       5455       5455  HASH JOIN  (cr=15664 pr=0 pw=0 time=778178696 us cost=30838477 size=741611997206725 card=3842549208325)
    375411     375411     375411   TABLE ACCESS FULL GROUP_GROUPS_FLAT (cr=3782 pr=0 pw=0 time=51533 us cost=1029 size=25152738 card=375414)
2918557224   55245693 2918557224   HASH JOIN  (cr=11882 pr=0 pw=0 time=778554141 us cost=3430847 size=177798827178 card=1411101803)
    163407     163407     163407    INDEX FAST FULL SCAN IDX_GROUP_MEMBERS (cr=10136 pr=0 pw=0 time=148427 us cost=2747 size=14434848 card=200484)(object id 118047)
 518438880  518438880  518438880    MERGE JOIN CARTESIAN (cr=1746 pr=0 pw=0 time=142455288 us cost=1800499 size=27995699520 card=518438880)
      6540       6540       6540     TABLE ACCESS FULL ACCOUNT (cr=738 pr=0 pw=0 time=49324 us cost=173 size=111180 card=6540)
 518438880  518438880  518438880     BUFFER SORT (cr=1008 pr=0 pw=0 time=69843749 us cost=1800326 size=2933064 card=79272)
     79272      79272      79272      TABLE ACCESS FULL GROUPS (cr=1008 pr=0 pw=0 time=25244 us cost=275 size=2933064 card=79272)

On 20 sequential runs, where I just restart an identical query, about 4 or 5 use the fast execution plan while the others use the slow one.

share|improve this question
2  
You're saying you have a query, but you actually have 2 queries. If the AND a.id NOT LIKE 'ptn%' query is slow, and the AND b.id NOT LIKE 'ptn%' is fast, have you checked that there is an equivalent index on a that already exists on b? – Phil Mar 30 '12 at 13:46
Comment added as answer. – Phil Mar 30 '12 at 15:09
Your lower queries are not semantically identical. The first does NOT LIKEs against the groups table while the second does NOT LIKESs against the group_groups_flat table. I realize that these are inner joined, but the query optimizer may be using them differently. Unfortunately that does not explain why your first query would alternate timings. – Leigh Riffel Mar 30 '12 at 15:36
Please can we discuss this in chat? – Jack Douglas Apr 2 '12 at 11:51
Are you executing the query with the same inputs each time when testing? – Phil Apr 2 '12 at 16:20
show 1 more comment

Know someone who can answer? Share a link to this question via email, Google+, Twitter, or Facebook.

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Browse other questions tagged or ask your own question.