Different behaviour in TOAD than in SQLPlus?

Toad for Oracle & DevOps Toolkit
1

Hi,

We had a few cases now where we experienced the following:

  • Our programs run a query on the database that suddenly takes ages.

  • We use TOAD to identify the statement in question

  • The statement runs fast in TOAD (but not in our program)

  • We run the statement in sqlplus.exe, where it is slow (same behaviour as in our program)

Adaptive Features are off, so every session should use the same explain plan. Also the bind variable for each test are of course the same.

I have no explanation for this, except that TOAD could set certain parameters open connecting to the database that then affect the behaviour and performance.

Is there anything like that? Or any other idea, why the same statement uses different plans and results in different performance when executed in TOAD, compared to when executed in sqlplus.exe?

Thank you!

2

The only thing that I can think of that Toad is doing is setting the OCI array buffer size. But that wouldn’t affect execution, just fetch.

Try tracing the sessions. If you have DBA Module, the Trace File Browser might show different EPs for each. Or some other difference. TKProf will show that info too, just not as easy to read.

3

Thank you, will do. We also noticed that when we change the statement slightly, execution time changes dramatically, which would indicate that the statement is parsed again and a new execution plan is chosen. Maybe TOAD slightly alters the statement (e.g. with a comment)…

4

Actually it’s even weirder.

Imagine the statement like this (obviously that’s not the actual statement):

variable var1 number;

begin
:var1 = 123;
end;
/

select x from y where field=:var1;

If I run this as a script (F5), so it runs like it would in SQLPlus, it’s slow (>6 minutes).

If I only run the sql statement (F9) and pass the bind variables through TOADs bind variable dialog, it’s fast (~1 second).

So the question is not “what does TOAD different from SQLPlus”, it’s “what does TOAD different when executing statements as a script”.

5

When doing a select using F9, it doesn’t return the entire data set immediately. What it’s doing is getting what can be stored in the OCI buffer and displaying that. Each time you scroll down on the data grid, it can grab more data as needed.

Using F5, the entire data set has to be returned. This is designed to emulate the functionality of SQL*Plus as closely as possible. If you think about running a script, there are many things in SQL that can change how the output looks (COL, LINESIZE, …).

For your situation, you want to run F5 to emulate what you’re seeing outside of Toad.

6

The default buffer size is 500 rows. The statement returns 90 rows, in both cases all rows are returned. I can also change the select clause to “count (*)” which means the statement only returns one row with one column, and the performance issue persists.

It also doesn’t matter to me how the output looks. It matters to me how the performance differs between 1 second and >6 minutes, even though it’s the same select statement with the same bind variables.

We are developing, optimising and debugging complex statements in TOAD. How can we continue to do this if they don’t behave the same way they behave outside of TOAD?

7

I observed such differing behavior with rarely dramatic changes execution times too.

To me it seemed that sqlplus.exe always was similar to our Automatic Job execution, but sometimes different than Toad. Though the side that runs faster is not always the same, so it can be tricky to develope OLTP/Batch queries with the best performance.

Also I remember one rather short query, that was even illegally transformed (concerning joins) on one side and could not run, as it went smoothly on the other side, so I had to force NO_QUERY_TRANSFORMATION hint. Sadly I don’t recall which side was Toad.

8

if you want to see how it’s going to behave outside of Toad, then you should be using F5 for this. This is evident when you say that F5 and SQL*Plus are acting the same way.

To optimize, I would also recommend using SQL Optimizer to see if the performance can be improved. Also look at the explain plan to see where your bottleneck is.

9

Gregory, that’s going in circles. The question is WHY does the same statement, with the same bind variables, perform vastly different in TOAD when executed as a query, compared to when executed as a script (or when executed outside of TOAD)? There has to be a logical explanation for this, it’s not magic.

I can’t go and tell 20 developers “from now on, only run your queries with F5”. They’re not going to do it, because 99% of the time you need to actually be able to actually read the output. Script execution via F5 is for running scripts (e.g. a series of update statements), it’s not optimal for working with a single select statement.

10

What you need to tell your developers is that if they want to emulate how a query will work in an outside environment, then they need to use F5 because that’s going to mimic that behavior

F9 is designed to give you a small subsection of your output in grid format. It’s not designed to give you the entire data set at once. F5 (and SQL*Plus) also has to allocate enough memory to accommodate the maximum amount of data for a row. If you have a bunch of VARCAR2(4000) columns, that total amount of space has to be allocated. F9 optimizes that as much as possible.

F9 - designed to get data as quickly as possible into the IDE grid

F5 - SQL*Plus and outside app emulation.

They are designed for different purposes so in your case, you need to tell the devs to use correct tool for the job that they’re trying to accomplish. Yes it’s called script execution but it’s also the way external apps are going to behave.

From: techsupport_93676 bounce-techsupport_93676@toadworld.com

Reply-To: "toadoracle@toadworld.com" toadoracle@toadworld.com

Date: Monday, January 29, 2018 at 8:50 AM

To: "toadoracle@toadworld.com" toadoracle@toadworld.com

Subject: RE: [Toad for Oracle - Discussion Forum] Different behaviour in TOAD than in SQLPlus?

** RE: Different behaviour in TOAD than in SQLPlus?**

Reply by techsupport_93676

Gregory, that’s going in circles. The question is WHY does the same statement, with the same bind variables, perform vastly different in TOAD when executed as a query, compared to when executed as a script (or when executed outside of TOAD)? There has to be a logical explanation for this, it’s not magic.

I can’t go and tell 20 developers “from now on, only run your queries with F5”. They’re not going to do it, because 99% of the time you need to actually be able to actually read the output. Script execution via F5 is for running scripts (e.g. a series of update statements), it’s not optimal for working with a single select statement.

To reply, please reply-all to this email.

Stop receiving emails
on this subject.

Or Unsubscribe from Toad for Oracle Forum
notifications altogether.

Toad for Oracle - Discussion Forum

Flag
this post as spam/abuse.

11

Did tracing of the sessions reveal anything? If you aren’t sure, post the trace files.

If they are too big to post, zip them up and email them to me. john.dorlon@quest.com

12

John, the issue was in the meanwhile “fixed” by re-analyzing all tables involved. It’s now fast no matter what way we execute the query. So sadly I can’t reproduce the issue anymore and therefore I’m unable to provide traces :frowning:

But I still have to follow up the issue with the different execution times. Gregory says that “execute single statement” behaves fundamentally different from “execute as script”. I’m not happy with that, but if that is the case we’ll have to accept that and draw our conclusions from it. However you said earlier that you can’t think of any difference apart from the array buffer size. Those two statements are conflicting.

Again: If the bottom line is that quest has optimized the “execute single statement” so well that it’s able to fetch data > 300x quicker (in some cases, like the one at hand) then I can’t do much but congratulate you and move on. But if the root difference is that for example the optimizer is parameterized differently in F9-mode, I’d like to know.

13

John, the issue was in the meanwhile "fixed" by re-analyzing all tables involved.

Ah-hah! Well, clearly then, the two different ways of executing the query produced different execution plans. That's the difference.

The optimizations that Greg was talking about refers to fetching and presenting the data after the query is executed. I don't think that was the key difference here (especially since you said the problem still happened when you did a "select count(*)" instead of fetching all rows). Oracle is in charge of the execution of the query, not Toad. Some difference (maybe just some small whitespace difference, maybe the way a variable was handled) caused Oracle to create a new execution plan, and because of out-of-date table statistics, the execution plan was inefficient.

Even if the two methods are now producing the same EP, you could still perhaps gain some insight as to what is different by tracing the session. I just did a quick test and got the same SQLID when run with F5 compared to F9, but I don't think that was the case for you.

-John

14

That makes sense. I do see one difference: When executing the statements with F5, I declare one variable as NUMBER and one as VARCHAR2(100):

variable firmanr number;
variable id varchar2(100);

begin
:firmanr:=11;
:id:=‘TAKS12145.0’;
end;
/

select …

When executing the query with F9, in the bind variable pop up, both variables are declared as VARCHAR2.

However, I just traced TOADs execution of the query, and in both cases (F9 or F5 execution) ended up with the same SQLID. The different data types of the bind variables do not seem to force a different SQLID. So whatever effect caused a different execution plan before does not seem to happen anymore.

The bottom line is TOAD doesn’t really do anything different when executing statements via F9 or F5, but we still ended up with a different plan. The reason for that can’t be explained, because we can’t reproduce it now that the tables are re-analyzed and the underlying issue is fixed.

I’ll look into this some more if we have this effect again, and that time take the traces before fixing/working around the underlying issue (urgency permitting), maybe we’ll find the problem then.

Thank you for your help!

15

Afternoon all.

Did someone mention trace files? :wink:

I think, from the “reanalyse fixing stuff”, that the problem might have been the gathering of dynamic stats while executing one version of the statement.

I’ve seen this before when a simple select took many minutes. Tracing showed a lot of full scan sql statements that were running as sys and were indeed dynamically gathering stats.

Gathering table stats resolved the problem.

Cheers,

Norm. [TeamT]

–

Sent from my Android device with K-9 Mail. Please excuse my brevity.