Re: 'alter session set sql_trace=true' bug or feature ?

From: VC <boston103_at_hotmail.com>
Date: Tue, 23 Dec 2003 12:18:43 GMT
Message-ID: <DoWFb.624239$HS4.4571770@attbi_s01>

Hello Niall,

["Niall Litchfield" ]
> for l_record in (select sysdate from all_objects) loop
>
> null;
> end loop;
> dbms_output.put_line( (dbms_utility.get_time - l_start)/100
> ||'seconds....' );
> end;
> /

It it a joke ? What has measuring 'select sysdate from all_objects' performance got to do with my original test ? The original query performs a merge join on a real table and the trace(sql_trace) was supposed to show at what stage in the join Oracle spends most time.

I am sure that the test would perform beautifully if you removed the query entirely.

[VC]> > Lastly, I would not call this kind of behaviour 'overhead'. Would'nt you
> > agree that the tool, in its present state, is practically useless for
> > performance tuning ?
>

["Niall Litchfield" ]
> So I think that I disagree with your statement.

I wonder how one can disagree with facts. A simple merge join runs 7 times slower with tracing enabled. Of what use is the performance measurement tool causing this kind of 'overhead' ?

["Niall Litchfield" ]
> Where the impact is
> significant then the tool is unhelpful, however where the overhead is
> insignificant then it isn't.

Please elaborate on the cases where the tool can be helpful. You cannot seriously claim that the tool can be used only for simple full table scans. Even in this case, the difference is significant, although not as striking:

SQL> create table t1 as select * from all_objects;

Table created.

SQL> select count(*) from t1;

  COUNT(*)

---

     25330

SQL> set serverout on
SQL> declare
  2 l_start number;
  3 begin

  4     --execute immediate 'alter session set sql_trace=true';
  5     l_start :=  dbms_utility.get_time;
  6     for l_record in
  7        (select * from t1)  loop
  8         null;
  9     end loop;
 10     dbms_output.put_line( (dbms_utility.get_time - l_start)/100 ||
 11     'seconds....' );
 12     execute immediate 'alter session set sql_trace=false';

 13 end;
 14 /
.67seconds....

PL/SQL procedure successfully completed.

SQL> set serverout on
SQL> declare
  2 l_start number;
  3 begin

  4     execute immediate 'alter session set sql_trace=true';
  5     l_start :=  dbms_utility.get_time;
  6     for l_record in
  7        (select * from t1)  loop
  8         null;
  9     end loop;
 10     dbms_output.put_line( (dbms_utility.get_time - l_start)/100 ||
 11     'seconds....' );
 12     execute immediate 'alter session set sql_trace=false';

 13 end;
 14 /
1.25seconds....

PL/SQL procedure successfully completed.

SQL> We have 1.25 vs. 0.67 seconds. The 'overhead' is 'only' 100%.

Even for full table scans, the tool is hardly useful.

["Niall Litchfield" ]
> Having said all that some further digging on metalink suggests that there
is
> a bug 3009359 which has been filed against this issue against a forum
> thread you raised in June. Have you tried pushing Oracle for a status
update
> on this bug?

I have but to no avail.

VC Received on Tue Dec 23 2003 - 06:18:43 CST