dbTalk Databases Forums  

query plan: Optimized using the forced options (internally generated Abstract Plan)

comp.databases.sybase comp.databases.sybase


Discuss query plan: Optimized using the forced options (internally generated Abstract Plan) in the comp.databases.sybase forum.



Reply
 
Thread Tools Display Modes
  #1  
Old   
rebelde
 
Posts: n/a

Default query plan: Optimized using the forced options (internally generated Abstract Plan) - 10-14-2011 , 07:04 AM






Hello,

We moved recently a lot of our installations at customer side from ASE 12.5.4 to ASE 15.0.3 ESD#4
(on Solaris SPARC or SuSE SLES11). All customers complain about some kind of performance degree,
especially while unloading large amount of rows with some ESQL/C application to file system.

At the beginning of this migration phase early this year, this was even more dramatically,
until we learned that for our ESQL/C application we must use some kind of Optimizer fallback to 12.5 as

sp_configure "optimization goal", 0, allrows_oltp
sp_configure 'enable compatibility mode', 1

This made production again possible, but the complaint about for example "unloading takes
twice as much as before in 12.5" remained; we now digged deeper into this and it turned
out that the rumor is true; we installed both (12.5 and 15.0.3) on the same idle Linux server
and with the same databases and can measure that

1. unloading 1000 rows does take twice as the time before, even if all rows are in cache
(because we repeat the unload)

2. the ESQL/C client is waiting in poll(2) for the ASE response; here is was happens
on syscall level for unloading one row (by a SELECT based on a Index), note the 1 ms sleep
in poll marked with ^^^^^^^^^):

0.000204 send(5, "\17\1\0\317\0\0\0\0b\302\0\0\0\1\0\rsid_koe_daten \256\0\0\0create proc sid_koe_daten as SELECT SYB_IDENTITY_C
OL,*,datalength(nettodaten) FROM koe_daten (i"..., 207, 0) = 207
0.001053 read(5, "\4\1\1\213\0\0\0\0", 8) = 8
0.000048 read(5, "b\20\0\0\0 \0\rsid_koe_daten \r\0\0\0\1\0\0\0\0\0\0\0\0\0\0008\0aN\1\0\0\10\0\0 \5amper\5sisis\tkoe_daten\20SY
B_IDENTITY_COL@\0\0\0\n\0\0\0l\6\n\0\0\0\5amper\5s isis\tkoe_daten\6katke"..., 387) = 387
0.000165 send(5, "\17\1\0000\0\0\0\0##\0\0\0\rkoe_daten_seq\10\0\r\ 0\0\0sid_koe_daten\0\0", 48, 0) = 48
0.000126 read(5, "\4\1\0\33\0\0\0\0", 8) = 8
0.000052 read(5, "\203\7\0\1\0\20\0\3\25\0\375\0\0\2\0\0\0\0\0" , 19) = 19
0.000102 send(5, "\17\1\0)\0\0\0\0\204\5\0\1\0\20\0\1 \16\0\0\0\1\0\0\0\0\0\0\0\0\0\0&\4\0\327\4\1\0\0\0 ", 41, 0) = 41
0.000910 read(5, 0x806753c, 8) = -1 EAGAIN (Resource temporarily unavailable)
0.000062 poll([{fd=5, events=POLLIN, revents=POLLIN}], 1, 1000) = 1
^^^^^^^^^^^^^
0.001109 read(5, "\4\1\1y\0\0\0\0", 8) = 8
^^^^^^^^^^^^^
0.000065 read(5, "aN\1\0\0\10\0\0\5amper\5sisis\tkoe_daten\20SYB_ID ENTITY_COL@\0\0\0\n\0\0\0l\6\n\0\0\0\5amper\5sisis \tkoe_date
n\6katkey \0\0\0\7\0\0\0&\4\0\0\5amper\5sisis\tkoe_daten\6ak t"..., 369) = 369
0.000281 send(5, "\17\1\0\20\0\0\0\0\202\5\0\1\0\20\0\1", 16, 0) = 16
0.000088 read(5, 0x806753c, 8) = -1 EAGAIN (Resource temporarily unavailable)
0.000053 poll([{fd=5, events=POLLIN, revents=POLLIN}], 1, 1000) = 1
0.000091 read(5, "\4\1\0\312\0\0\0\0", 8) = 8
0.000059 read(5, "\321\6\0\0\0\0\r1\4\1\0\0\0\2\0\0\1 \nX820086590,ABSATZWIRTSCHAFTLICHE GESELLSCHAFT NUERNBERG\20\262\7\0\0\0\
0\0\0\0\0\0\0v\251!\3\0\0\0\0\3\331\\\245M\0\0\0\0 \1\0- Absatzwirtschaftlich"..., 194) = 194

using the 12.5 ASE this poll(2) is not there and it continues just with read(2)
reading the ASE response from socket;

3. while simulating a single SELECT with isql it turned out that there is an important
difference between the showplan of 12.5 and 15.0.3; this is for 15.0.3 here:

1> begin transaction
1> set showplan on

1> DECLARE koe_daten_seq CURSOR FOR SELECT SYB_IDENTITY_COL,* FROM koe_daten (index koe_katkey) WHERE katkey=1

QUERY PLAN FOR STATEMENT 1 (at line 1).


STEP 1
The type of query is DECLARE CURSOR.

1> open koe_daten_seq

QUERY PLAN FOR STATEMENT 1 (at line 1).


STEP 1
The type of query is OPEN CURSOR koe_daten_seq.


QUERY PLAN FOR STATEMENT 1 (at line 1).
Optimized using the forced options (internally generated Abstract Plan).
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ ^^^^^^^^^^^^^^^^^^^^^^


STEP 1
The type of query is DECLARE CURSOR.
^^^^^^^^^^^^^^^^^^^^^^^^

the 12.5 does not contain the marked lines, but just

....
1> open koe_daten_seq

QUERY PLAN FOR STATEMENT 1 (at line 1).


STEP 1
The type of query is OPEN CURSOR koe_daten_seq.


QUERY PLAN FOR STATEMENT 1 (at line 1).


STEP 1
The type of query is SELECT.

FROM TABLE
koe_daten
Nested iteration.
Index : koe_katkey


The "Statement-level output" chapture of ASE explains the message of
"Optimized using the forced options (internally generated Abstract Plan)"
only for 'alter table' or 'reorg commands' (page 44).

What does this mean? Thanks in advance

matthias

Reply With Quote
  #2  
Old   
Derek Asirvadem
 
Posts: n/a

Default Re: query plan: Optimized using the forced options (internallygenerated Abstract Plan) - 10-14-2011 , 09:04 AM






On Oct 14, 11:04*pm, rebelde <g... (AT) unixarea (DOT) de> wrote:
Quote:
What does this mean? Thanks in advance
a. The AQP is generated internally, to override the normal QP,
because you have specified:
___(INDEX koe_katkey)
normally called "force index" or "index hints", and the way that is
expedited, is to generate an AQP. Nothing surprising about that. the
optimiser was rewritten in 15.0, so there are many things in it, and
in its showplans, that will not be found in 12.5. The underlined
lines are to be expected, that is not what is keeping this slow.

b. I do not understand why you expect 12.5 and 15.0 binaries to match,
syscall for syscall. Forget about that. Then you need to consider
that ASE was very nicely bound to Sun/SPARC, you cannot expect the
same from little old Suse, all the drivers are different.

c. That (@3) is not a "single SELECT", it is a cursor, that fetches
one row. A cursor is a particularly slow method of interacting with
ASE. It is a set-oriented engine, not a row-processor. Even if you
tweaked the configuration, it would not help an app that is sitting
there, calling for one row at a time, processing it, calling for the
next row.

d. Although there have been many enhancements recently, to move large
amounts of rows via client-side apps (eg. bulk-copy; arrays), (i) I
doubt that ESQL/C was enhanced and (ii) you would have to change a
little code to take advantage of such. So right now, you are
executing row-processing commands, on the slowest CT-Lib library,
without any code changes to take advantage of the new facilities. On
a new smaller box. Using massively changed ASE.

e. Why, exactly, are you using ESQL/C (or any client-side program for
that matter), to unload large volumes of data, to a file system
file ? Do you know, there are server-side utilities that perform that
task 1,000s of times faster, and do not use the network ? If you must
transfer data across the network, there are client-side utilities that
perform that task 100s of times faster.

Reply With Quote
  #3  
Old   
rebelde
 
Posts: n/a

Default Re: query plan: Optimized using the forced options (internally generated Abstract Plan) - 10-14-2011 , 09:31 AM



Firts of all, thanks for your fast and detailed answer.

Derek Asirvadem wrote:

Quote:
On Oct 14, 11:04*pm, rebelde <g... (AT) unixarea (DOT) de> wrote:

What does this mean? Thanks in advance

a. The AQP is generated internally, to override the normal QP,
because you have specified:
___(INDEX koe_katkey)
normally called "force index" or "index hints", and the way that is
expedited, is to generate an AQP. Nothing surprising about that. the
optimiser was rewritten in 15.0, so there are many things in it, and
in its showplans, that will not be found in 12.5. The underlined
lines are to be expected, that is not what is keeping this slow.
I understand, and deleting '(INDEX koe_katkey)' let go away the line
about 'Optimized AP' from the showplan output; but it continues to say:

1> open koe_daten_seq

QUERY PLAN FOR STATEMENT 1 (at line 1).


STEP 1
The type of query is OPEN CURSOR koe_daten_seq.


QUERY PLAN FOR STATEMENT 1 (at line 1).


STEP 1
The type of query is DECLARE CURSOR.
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

whiloe in 12.5.4 it says:

1> open koe_daten_seq

QUERY PLAN FOR STATEMENT 1 (at line 1).


STEP 1
The type of query is OPEN CURSOR koe_daten_seq.


QUERY PLAN FOR STATEMENT 1 (at line 1).


STEP 1
The type of query is SELECT.
^^^^^^^^^^^^^^^^^^^^^^^^^^^^

i.e. in 12.5.3 it says 'query is SELECT' and in 15.0.3 it declares a new
CURSOR: 'query is DECLARE CURSOR'; why?

Quote:
b. I do not understand why you expect 12.5 and 15.0 binaries to match,
syscall for syscall. Forget about that. Then you need to consider
that ASE was very nicely bound to Sun/SPARC, you cannot expect the
same from little old Suse, all the drivers are different.
I do not expect that syscalls match, but I see the 0.0011 sec delay (spent
in poll(2)) which underpins that 15.x ASE needs longer at this point;

Quote:
c. That (@3) is not a "single SELECT", it is a cursor, that fetches
one row. A cursor is a particularly slow method of interacting with
ASE. It is a set-oriented engine, not a row-processor. Even if you
tweaked the configuration, it would not help an app that is sitting
there, calling for one row at a time, processing it, calling for the
next row.
Normally the hit list of the SELECT is not only one row, but thousands; and
it must be a CURSOR in the app to move back and forth (think in paging back
and forth in some kind of sorted dictionary);

Quote:
d. Although there have been many enhancements recently, to move large
amounts of rows via client-side apps (eg. bulk-copy; arrays), (i) I
doubt that ESQL/C was enhanced and (ii) you would have to change a
little code to take advantage of such. So right now, you are
executing row-processing commands, on the slowest CT-Lib library,
without any code changes to take advantage of the new facilities. On
a new smaller box. Using massively changed ASE.
We are talking about a high complex Library Management System with some 500
tables, written in C and ESQL/C and we can't so easy adopt on new
Optimizer. At least we expect to get the old performance with the new ASE.
Is this to much expectation? :-)


Quote:
e. Why, exactly, are you using ESQL/C (or any client-side program for
that matter), to unload large volumes of data, to a file system
file ?
Because the netto data is stored in BLOBS which must be read and interpreted
by the application; and: this (unloading) is only an example where the
performance degree is easy to proof. In the dialog oriented part of the
apps using the same interface it is only to 'feel' but not so easy to
proof; that's why I picked this up;


Quote:
Do you know, there are server-side utilities that perform that
task 1,000s of times faster, and do not use the network ? If you must
transfer data across the network, there are client-side utilities that
perform that task 100s of times faster.
I know, but this does not help here.

The main question is: why is the same ESQL/C app with 15.0.3 twice as time
slower reading rows as 12.5.4?

Thanks

matthias

Reply With Quote
  #4  
Old   
Derek Asirvadem
 
Posts: n/a

Default Re: query plan: Optimized using the forced options (internallygenerated Abstract Plan) - 10-14-2011 , 11:32 PM



On Oct 15, 1:31*am, rebelde <g... (AT) unixarea (DOT) de> wrote:
Quote:
Firts of all, thanks for your fast and detailed answer.
My pleasure.

12.5.4:

Quote:
* * * * The type of query is DECLARE CURSOR.
* * * * ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
vs 15.0.3:

Quote:
* * * * The type of query is OPEN CURSOR koe_daten_seq.

* * * * The type of query is SELECT.
* * * * ^^^^^^^^^^^^^^^^^^^^^^^^^^^^

i.e. in 12.5.3 it says 'query is SELECT' and in 15.0.3 it declares a new
CURSOR: 'query is DECLARE CURSOR'; why?
I think I mentioned, there is no possibility of matching either the
QP, or the ShowPlan of the QP, line by line. All this Showplan shows,
is that 15.x produces two separate notices in the ShowPlan, where
12.5.3 produces one notice. There is no "new" or second cursor, it is
notifying the OPEN as well as the DECLARE.

Every command submitted to ASE is a "query". Every new command starts
a STEP 1.

There are many diffs between the Showplans. Some are definitely worth
investigation, but you must use a context, a view from 1,000 metres,
and examine the Showplan for the actual SELECT, etc, which is the
operative part of the Showplan. What you are doing here, is examining
the hair of the beast with a magnifying glass, and worrying about the
observation that the hair is a different colour. That observation,
while correct, is irrelevant. We want the flesh of the deer, not the
hair.

Now if you find a difference (not in no of logged entries, but a
material difference) in the two ShowPlans re the two SELECTS within
the cursor, that is worth discussing.

Quote:
I do not expect that syscalls match, but I see the 0.0011 sec delay (spent
in poll(2)) which underpins that 15.x ASE needs longer at this point;
Two answers.

1. So ?

An XYZ binary written in 1994 (plus 15 years of patches) goes through
one code path on a Sun/SPARC, and a PQR binary written in 2007 goes
through another code path on an Intel. So ? Both will achieve the
same functional result. There is no basis to compare them.

2. If you forget about comparing the two, and just look at the problem
you have on the new box, there may be some work to do. The WAIT, is
because every time the app calls for one row, and then ASE furnishes
it to the app, ASE correctly identifies that the batch is complete,
takes the process off the RUN queue, and places it in the SLEEP
queue. Then it waits around for the app to to wake up, process the
single row, send ASE another batch (of SELECT one row). During that
time (which is very long when cursors are used), if ASE is idle, it
will itself go to SLEEP, and need to be woken up. You may well have
determined that ASE takes 0.0011 sec delay to wake up and process the
new batch.

2.1 Excellent. Go and do something about it. Change Linux to treat
ASE like a server and give it priority, allocated memory, never to
swap out, etc.

2.2 But do you want to change the config of ASE ? On the basis of one
stupid cursor ? Performance tuning has to take consideration of the
whole load; all the spids; and divide resources accordingly. If you
change config based on one or the other single event, the whole is
likely to suffer bad performance. Therefore if you want to look at
this, you need to look at the overall performance and the overall
config of ASE, not the performance of one spid or where it is getting
stuck.

The old transport is the ICE from Ulm to Frankfurt in 2 hours 40 mins,
it is designed to move 1,000 people. You want one person to fly.
Sure, that can be done, but you need to make arrangements at
Weisbaden, the usual arrangements at the Hauptbahnhof will not do.

2.3 Also note that you are not looking at the action of the spid and
ASE from 1,000 metres or 10,000 metres, you are using a magnifying
glass. That will result in you concentrating on specifics, while
missing the whole context.

2.4 15.x has 250 config parms, they are inter-related. Additionally
almost every system resource can be configured. You should not expect
to tweak one or the other config parm without affecting the related
parms, the related parms should be changed in concert.

2.5 I am assuming you have read the Sybase literature on Migration
from 12.x to 15.x, and you have set the config accordingly. Also that
it is configured to take full advantage of the resources available on
the SuSe box, not configured for the old Sun.

2.6 Have you read that you should set:

____EXEC sp_configure "runnable process search count", 50 -- not 5,
not 2000

This will affect all spids, not just the cursor spid. Test the hell
out of it, and adjust accordingly.

2.7 To close this 0.0011 sec delay item, sure, chase it down. But do
not be surprised if it does not help the cursor spid that much.

Quote:
Normally the hit list of the SELECT is not only one row, but thousands; and
it must be a CURSOR in the app to move back and forth (think in paging back
and forth in some kind of sorted dictionary);
Yes, but it is "paging back and forth" one row at a time. You are
processing thousands of calls for a single row each time; set-
processing means one single call which processes thousands of rows.

Send me (via email, do not post here) the SELECTs (both the outer
SELECT for the CURSOR, and the inner SELECT for the paging-back-and-
forth, plus the DDL for each table referenced, and I will return a set-
processing single SELECT.

Quote:
We are talking about a high complex Library Management System with some 500
tables, written in C and ESQL/C and we can't so easy adopt on new
Optimizer. At least we expect to get the old performance with the new ASE..
Is this to much expectation? :-)
Absolutely not. I have performed quite a few benchmarks, and have
quite "complex" databases. My clients have some very badly designed
databases. ASE 15.x is much, much faster than 12.5. But, guess what,
it is no faster on a badly designed db, or on poor SQL code. The more
normalised your db, the cleaner your code, the faster ASE 15.x will
be. I have never seen it slower than 12.5, but then, I have never
written a cursor in my life (I have examined and replaced hundreds).

New Optimiser. This is where the problem is. Again, clean code and a
decent db result in no problems whatsoever. Either poor code or
monster of a db, and the new Optimiser will make incorrect decisions,
or take mins evaluating thousands of possible plans. Both of which
can be reined in with "optimization timeout limit", etc.

But since you are running with "enable compatibility mode", you are
not getting most of the 15.5 features, you are operating as close to
12.5 operation that the 15.x binary can give you. You have taken the
flight option, but you insist on having full dinner service before
landing, so live with the fact that you will be circling for half an
hour before landing.

Complex dbs are no problem. Sybase excels with highly complex dbs.
Complex code is no problem. Bad code, poorly designed code, overuse
of temp tables, they are the problems, and they will be exposed during
any migration to any major release. Cursor code is limited to single
row processing, so it doesn't matter how fast or faster the engine is,
you are operating at the speed of moving X thousand rows across the I/
O subsystem and across the network, one row/packet at a time.

Having an app, with SQL code, such that it is glued at the hip to a
particular optimiser, is a problem. That your company invested so
much money in an app, which is now tied to a platform that is no
longer being maintained, and cannot move to the new (faster, better,
more features) maintained binary, *is* a problem.

Quote:
e. *Why, exactly, are you using ESQL/C ... cursor ...

Because the netto data is stored in BLOBS which must be read and interpreted
by the application; and: this (unloading) is only an example where the
performance degree is easy to proof. In the dialog oriented part of the
apps using the same interface it is only to 'feel' but not so easy to
proof; that's why I picked this up;
e.1 I am not at all convinced that you can't extract all the affected
rows (including the blobs), and process them once, in a stream; that
you have to go through the entire process one row at a time.

e.2 You may find the Full Text Search Option of benefit to you, it is
perfect for a library system, and for searching the content of Text
columns.

Quote:
... server-side utilities ... client-side utilities ... 100s of times faster.

I know, but this does not help here.
Of course. But for the future, for the next version of the app (there
will be one, it isn't going to sit at 15-year-old code, unchanged,
no ?), you might want to take note of that, and write functions that
stream the data, 1,000 rows, once, rather than execute 1,000 loops/
processes on the data, one row at a time. Good design is about using
the Right Tool for the Job, and using appropriate tools in combination
to get the desired result. It is not about using SQL only, via a C
program only; that is Maslow's Hammer.

Quote:
The main question is: why is the same ESQL/C app with 15.0.3 twice as time
slower reading rows as 12.5.4?
I do not understand why/how you suggest you have "proved" anything of
the sort. You are comparing apples and oranges, actually stale, hard
apples from Spain with stale, soft oranges from Brazil.

If you want to run a reasonable test, to prove anything, you need to:
- install ASE 12.5.4 on the SuSe box
- configure it properly (55 parms + resources) for the SuSe box
- dump/load the db from the SPARC to the Suse; or bcp-out/in and
rebuild all DataStructures
- verify that timings of the app are as expected/better/worse; resolve
those issues
- *now* you have a benchmark against which you can test or prove
something related to the conclusion you suggest

Then:
- install ASE 15.0.3 on the SuSe box
- ensure you are using the same edition: either Enterprise or Small
Business
- configure it properly (250 parms + resources) for the SuSe box
- ensure that the 15.0.3 config is intentionally the same as the
12.5.4 config, that there is no bias XOR that you are taking advantage
of new features, and make a declaration re the specifics of that
- ensure you have the same named caches, and cache settings,
parallelism, etc
- ensure you have followed the Migration Guidelines reasonably (not
perfectly, but do not miss the important steps)
- ensure you are using memory and the I/O subsystem exactly the same
way (/ufs, raw partitions, SAN LVs, etc)
- personally, I do not care if you use the "build new server" or the
"upgrade server in place" method; I care that you have done it
correctly and *verified it is correct*
- personally, I do not care if you use the "dump/load database" or
the "upgrade database in place" method; I care that you have done it
correctly and *verified it is correct*
- ensure you have rebuilt all 12.0 Index Structures to 15.x Index
Structures (you may even have the TextChains sitting at 11.9
DataStructures)
- verified all that
- run the app code up and test the hell out of it, as per documented
requirement; take note of the completely re-written Optimiser;
identify all issues; resolve them
- now run the same benchmark

- if one of your issues is that you can't use the 15.0 Optimiser, that
you must use "enable compatibility mode", then you will never be able
to compare 12.5.4 apples with 15.0.3 apples; you are comparing 12.5.4
apples with 15.0.3 tinned apples. The syrup is sweet but the apples
are devoid of substance. You can draw some conclusions, but only on
that declared basis (12.5.4 vs 15.0.3 Compatibility Mode). I can tell
you from experience of scores of Migrations, before you spend any time
on a proper test:
____ (a) bad code, if it runs unchanged, will run *slightly* faster in
15.0.x native mode
____ (b) may need changes, to run at all
____ (c) no idea of compatibility mode, because most people (at least
my customers) are ready to change code in order to obtain the 15.0.x
speed, and
____ (d) good code will run unchanged, completely free of new
Optimiser "issues", at least 10, maybe 20 times faster.
I have not changed one single line in our 700 table, 1.2TB database,
Migration was effortless. We changed a little bit of code *after*
migration to take advantage of new features. It is a different story
with customers, whose code is of varying quality.

- one day, when you overcome the requirement to run in compatibility
mode, then you can compare 12.5.4 apples with 15.0.3 apples, and then
you can draw some conclusions, and make some claims, such as you have
made. The fact that you require compatibility mode, places your code
(most of it ?) squarely in the poor code category.

3. Do me a personal favour and execute this code in your 15.0.3
subject database, then post the results.

SELECT OBJECT_NAME(id),
________name,
________"Suspect DataStructure"
____FROM sysindexes
____WHERE status & 32768 = 32768
UNION
SELECT OBJECT_NAME(id),
________"",
________"11.9 Table"
____FROM sysobjects
____WHERE type = "U"
____AND sysstat2 & 65536 = 0
ORDER BY 1, 2

4. Other.
ASE 15.0.3 has a totally re-written Optimiser; it took a while to bed
it down. The 12.5.x End of Life Notice coincided with the release of
15.5. I never certified *any* 15.0.x release, they were all
horrible. ASE 15.5 is good. Do not waste time going from 12.5.4 to
15.0.3 to 15.5; go directly to 15.5.

5. Attitude.
You appear to be very app-centric, not at all friendly with ASE,
expecting new binaries to service your app exactly the same as your 15-
year-old out-of-date end-of-lifed binary. That may not be the best
way to serve your employer. They made an investment in a Sybase
Licence, that progresses with the times, not in a binary that will not
change. The 12.5.4 King is Dead, Long Live the 15.0 King ! Release
your happy past with the old king, get friendly with the new majesty,
learn about it. Refuse to do that, and you will never get over the
grief. I can assure you the new one will serve you at least as well
as the old one, and definitely better if you get friendly with it.

Further, you will get far more performance out of your app, if you get
to know ASE (old or new), and design the app for ASE, rather than in
isolation from it. I can guarantee at least 100 times better
performance for each cursor that you replace with set-processing code,
but that will only be attractive to you if you release your app-
centrism, and wish to take advantage of the librarys Sybase Licence
investment.

Regards
Derek

Reply With Quote
  #5  
Old   
rebelde
 
Posts: n/a

Default Re: query plan: Optimized using the forced options (internally generated Abstract Plan) - 10-18-2011 , 03:18 AM



Derek Asirvadem wrote:

Quote:
4. Other.
ASE 15.0.3 has a totally re-written Optimiser; it took a while to bed
it down. *The 12.5.x End of Life Notice coincided with the release of
15.5. *I never certified any 15.0.x release, they were all
horrible. *ASE 15.5 is good. *Do not waste time going from 12.5.4 to
15.0.3 to 15.5; go directly to 15.5.

5. Attitude.
You appear to be very app-centric, not at all friendly with ASE,
expecting new binaries to service your app exactly the same as your 15-
year-old out-of-date end-of-lifed binary. *That may not be the best
way to serve your employer. *They made an investment in a Sybase
Licence, that progresses with the times, not in a binary that will not
change. *The 12.5.4 King is Dead, Long Live the 15.0 King ! *Release
your happy past with the old king, get friendly with the new majesty,
learn about it. Refuse to do that, and you will never get over the
grief. *I can assure you the new one will serve you at least as well
as the old one, and definitely better if you get friendly with it.

Further, you will get far more performance out of your app, if you get
to know ASE (old or new), and design the app for ASE, rather than in
isolation from it. *I can guarantee at least 100 times better
performance for each cursor that you replace with set-processing code,
but that will only be attractive to you if you release your app-
centrism, and wish to take advantage of the librarys Sybase Licence
investment.

Hi Derek,

I did what you suggest and stopped thinking about my apps, but watching what ASE 15.x
is doing after receiving the few SQL statements of

begin transaction
go
DECLARE koe_daten_seq CURSOR FOR SELECT SYB_IDENTITY_COL,* FROM koe_daten WHERE katkey=1
go
open koe_daten_seq
go
fetch koe_daten_seq
go
rollback
go

the ASE is idle, that's why it is easy to watch with strace(1), here is what the King is doing:

0.000083 recv(25, "\17\1\0 \0\0\0\0!\23\0\0\0\0begin transaction\n", 2048, 0) = 32
0.000136 send(25, "\4\1\0\21\0\0\0\0\375\4\0\1\0\0\0\0\0", 17, 0) = 17
0.000081 select(26, [24 25], NULL, NULL, {0, 0}) = 0 (Timeout)
0.000063 select(26, [24 25], NULL, NULL, {0, 0}) = 1 (in [25], left {0, 0})
0.000081 recv(25, "\17\1\0h\0\0\0\0![\0\0\0\0DECLARE koe_daten_"..., 2048, 0) = 104
0.000470 send(25, "\4\1\0\21\0\0\0\0\375\4\0\1\0\0\0\0\0", 17, 0) = 17
0.000081 select(26, [24 25], NULL, NULL, {0, 0}) = 0 (Timeout)
0.000068 select(26, [24 25], NULL, NULL, {0, 0}) = 1 (in [25], left {0, 0})
0.000085 recv(25, "\17\1\0!\0\0\0\0!\24\0\0\0\0open koe_daten_seq"..., 2048, 0) = 33
0.000202 gettimeofday({1318924357, 741825}, NULL) = 0
0.001216 gettimeofday({1318924357, 743042}, NULL) = 0
0.000392 send(25, "\4\1\0\21\0\0\0\0\375\4\0\1\0\0\0\0\0", 17, 0) = 17
0.000097 select(26, [24 25], NULL, NULL, {0, 0}) = 0 (Timeout)
0.000065 select(26, [24 25], NULL, NULL, {0, 0}) = 0 (Timeout)
0.000070 select(26, [24 25], NULL, NULL, {0, 0}) = 1 (in [25], left {0, 0})
0.000078 recv(25, "\17\1\0\"\0\0\0\0!\25\0\0\0\0fetch koe_daten_se"..., 2048, 0) = 34
0.000338 send(25, "\4\1\2\22\0\0\0\0a>\1\0\0\7\0\0\5amper\5sisis\tko e"..., 530, 0) = 530
0.000084 select(26, [24 25], NULL, NULL, {0, 0}) = 0 (Timeout)
0.000062 select(26, [24 25], NULL, NULL, {0, 0}) = 0 (Timeout)
0.000068 select(26, [24 25], NULL, NULL, {0, 0}) = 0 (Timeout)
0.000055 select(26, [24 25], NULL, NULL, {0, 16666}) = 1 (in [25], left {0, 17000})
0.000354 recv(25, "\17\1\0\27\0\0\0\0!\n\0\0\0\0rollback\n", 2048, 0) = 23

Do you see the problem? I do :-)

between receiving 'open koe_daten_seq' and sending the response to ISQL there is:

-- NO disk i/o
-- NO further syscall than gettimeofday() and the second one with a delay of 1.216ms

that means that the time is spent in CPU cycles within ASE! The King is thinking.

Thanks

matthias

Reply With Quote
  #6  
Old   
rebelde
 
Posts: n/a

Default Re: query plan: Optimized using the forced options (internally generated Abstract Plan) - 10-18-2011 , 05:16 AM



rebelde wrote:

Quote:
0.000085 recv(25, "\17\1\0!\0\0\0\0!\24\0\0\0\0open koe_daten_seq"...,2048, 0) = 33
0.000202 gettimeofday({1318924357, 741825}, NULL) = 0
0.001216 gettimeofday({1318924357, 743042}, NULL) = 0
0.000392 send(25, "\4\1\0\21\0\0\0\0\375\4\0\1\0\0\0\0\0", 17, 0) = 17
the same situation in a server ASE 12.5.x is:

0.000079 recv(48, "\17\1\0!\0\0\0\0!\24\0\0\0\0open koe_daten_seq"..., 512, 0) = 33
0.000542 gettimeofday({1318930882, 566}, NULL) = 0
0.000084 send(48, "\4\1\0\21\0\0\0\0\375\4\0\1\0\0\0\0\0", 17, 0) = 17

so, we now know where the time in 15.x is spent: in CPU cycles, twice as much as
in 12.x in this case of OPEN CURSOR

matthias

Reply With Quote
  #7  
Old   
Derek Asirvadem
 
Posts: n/a

Default Re: query plan: Optimized using the forced options (internallygenerated Abstract Plan) - 10-18-2011 , 10:31 AM



On Oct 18, 9:16*pm, rebelde <g... (AT) unixarea (DOT) de> wrote:

Matthias

That is excellent work.

I am not ready to agree/disagree with this statement:
Quote:
so, we now know where the time in 15.x is
spent: in CPU cycles, twice as much as
in 12.x in this case of OPEN CURSOR
You have one bad experience with ASE 15, one cursor, one conclusion.
I have about good expereince with about 35 ASE 15s (with the details
noted above), quite a different conclusion. ASE 15 does have specific
enhancements for cursors. Please read, you can restore 12.5 operation
for cursor sensitivity (I am not recommending that, only that you
should be aware of it). There is also a CR for a known bug but I am
pretty sure it is fixed in ESD#4. I will check tomorrow.

But the diagnosis is not complete yet. We have to figure out (a) why
the King is not being woken up when the I/O has completed and (b) what
the hell He is doing so much thinking for. I have never had to go
down to the level of strace to figure out an ASE performance problem,
so I am relying on you to interpret the report correctly.

Have you noted [2.6] above, what is your RPSC ?

3.1 How many engines ?

3.2 How many CPU/cores/threads on the box ?

3.3 What is the CPU/I.O/Idle from sp_symon (of at least one hour,
including the cursor operating somewhere in this duration) ?

3.4 Please confirm, you are running nothing but ASE on this box..

Regards
Derek

Reply With Quote
  #8  
Old   
rebelde
 
Posts: n/a

Default Re: query plan: Optimized using the forced options (internally generated Abstract Plan) - 10-19-2011 , 02:57 AM



Derek Asirvadem wrote:

Quote:
Have you noted [2.6] above, what is your RPSC ?
Yes. We stumbled about this parameter already years ago (search in c.d.s.
for my name :-) and got to know that 2000 is a bad value; even 50 is bad
because it let cycle ASE dataservers to much in poll(2) syscalls until
giving up the CPU; normaly we set it to 5 or even below to 2; we run around
100 12.5.x installations at customer sides, i.e. we are not newbies :-)
in the ASE 15.x in our case RPSC is set to 5:

$ fgrep runnab /opt/syb154/ASE-15_0/oclcSYB.cfg
runnable process search count = 5

Quote:
3.1 How many engines ?
the ASE 12.5 and 15.x have each only one dataserver:

$ ps ax | fgrep dataserver
4569 ? Ss
388:50 /opt/syb154/ASE-15_0/bin/dataserver -d/opt/syb154/data/master.dat -e/var/spool/sybase/oclcSYB.log -c/opt/syb154/ASE-15_0/oclcSYB.cfg
-M/opt/syb154/ASE-15_0 -soclcSYB
6709 ? Ss
55:57 /opt/sybase/ASE-12_5/bin/dataserver -d/database/sybase/1252/master.dat -e/var/spool/sybase/sisisSYB.log -c/opt/sybase/ASE-12_5/sisisS
YB.cfg -M/opt/sybase/ASE-12_5 -ssisisSYB


Quote:
3.2 How many CPU/cores/threads on the box ?
SLES sees 4 CPU's:

$ dmesg | egrep -i 'CPU[0-9]'
CPU0: Intel(R) Xeon(TM) CPU 3.20GHz stepping 03
CPU1: Intel(R) Xeon(TM) CPU 3.20GHz stepping 03
CPU2: Intel(R) Xeon(TM) CPU 3.20GHz stepping 03
CPU3: Intel(R) Xeon(TM) CPU 3.20GHz stepping 03

Quote:
3.3 What is the CPU/I.O/Idle from sp_symon (of at least one hour,
including the cursor operating somewhere in this duration) ?
the two ASE on this box (a test server) are idle, i.e. no other connections
to the port 4000 and 5000:

$ netstat -an | egrep '4000|5000'
tcp 0 0 10.49.92.18:4000 0.0.0.0:* LISTEN
tcp 0 0 10.49.92.18:5000 0.0.0.0:* LISTEN

Quote:
3.4 Please confirm, you are running nothing but ASE on this box..
ACK; only the two dataserver, ssh login and the ISQL tests with this 10
lines of SQL.

matthias

Reply With Quote
  #9  
Old   
rebelde
 
Posts: n/a

Default Re: query plan: Optimized using the forced options (internally generated Abstract Plan) - 10-31-2011 , 07:06 AM



Derek Asirvadem wrote:

Quote:
12.5.4:

The type of query is DECLARE CURSOR.
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

vs 15.0.3:

The type of query is OPEN CURSOR koe_daten_seq.

The type of query is SELECT.
^^^^^^^^^^^^^^^^^^^^^^^^^^^^

i.e. in 12.5.3 it says 'query is SELECT' and in 15.0.3 it declares a new
CURSOR: 'query is DECLARE CURSOR'; why?

I think I mentioned, there is no possibility of matching either the
QP, or the ShowPlan of the QP, line by line. *All this Showplan shows,
is that 15.x produces two separate notices in the ShowPlan, where
12.5.3 produces one notice. *There is no "new" or second cursor, it is
notifying the OPEN as well as the DECLARE.

After further investigations of the difference between 12.5.4 and 15.0.3 of
the performance of the query for a given table, it turned out that this
(the difference) is depending of the fact that the table contains a BLOB
field or does not contain such BLOB. For tables without a BLOB the
difference is marginal, for tables containing a BLOB the difference is a
factor of 2.

More: Even the SHOWPLAN shows that difference in SELECT'ing one row. The
first example is one of a table with a BLOB, the second is one of a table
without a BLOB; the diff is marked with ^^^^^^^^^^^^.

Any comments on this?

,----[ /usr/home/guru/show1.txt ]
Quote:
SYBASE: /opt/sybase/15.0.3 DATABASE: sisis DSQUERY: sisisSYB
1> select @@version
Adaptive Server Enterprise/15.0.3/EBF 17777 ESD#4/P/Sun_svr4/OS
5.8/ase1503/276
8/32-bit/FBO/Thu Aug 26 12:39:12 2010

(1 row affected)
1> set showplan on

1> DECLARE koe_daten_seq CURSOR FOR SELECT SYB_IDENTITY_COL,* FROM
koe_daten WHERE katkey=1

QUERY PLAN FOR STATEMENT 1 (at line 1).


STEP 1
The type of query is DECLARE CURSOR.

1> open koe_daten_seq

QUERY PLAN FOR STATEMENT 1 (at line 1).


STEP 1
The type of query is OPEN CURSOR koe_daten_seq.


QUERY PLAN FOR STATEMENT 1 (at line 1).


STEP 1
The type of query is DECLARE CURSOR.
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

1 operator(s) under root

|ROOT:EMIT Operator (VA = 1)
|
| |SCAN Operator (VA = 0)
| | FROM TABLE
| | koe_daten
| | Index : koe_katkey
| | Forward Scan.
| | Positioning by key.
| | Keys are:
| | katkey ASC
| | Using I/O Size 4 Kbytes for index leaf pages.
| | With LRU Buffer Replacement Strategy for index leaf pages.
| | Using I/O Size 4 Kbytes for data pages.
| | With LRU Buffer Replacement Strategy for data pages.


1> fetch koe_daten_seq

QUERY PLAN FOR STATEMENT 1 (at line 1).


STEP 1
The type of query is FETCH CURSOR koe_daten_seq.

( record deleted from log )

(1 row affected)
1> close koe_daten_seq

QUERY PLAN FOR STATEMENT 1 (at line 1).


STEP 1
The type of query is CLOSE CURSOR koe_daten_seq.


`----

,----[ /usr/home/guru/show2.txt ]
Quote:
SYBASE: /opt/sybase/15.0.3 DATABASE: sisis DSQUERY: sisisSYB
1> select @@version
Adaptive Server Enterprise/15.0.3/EBF 17777 ESD#4/P/Sun_svr4/OS
5.8/ase1503/276
8/32-bit/FBO/Thu Aug 26 12:39:12 2010

(1 row affected)
1> set showplan on

1> DECLARE d01buch_seq CURSOR FOR SELECT SYB_IDENTITY_COL,* FROM d01buch
WHERE d01gsi="TEMP154742"

QUERY PLAN FOR STATEMENT 1 (at line 1).


STEP 1
The type of query is DECLARE CURSOR.

1> open d01buch_seq

QUERY PLAN FOR STATEMENT 1 (at line 1).


STEP 1
The type of query is OPEN CURSOR d01buch_seq.


QUERY PLAN FOR STATEMENT 1 (at line 1).


STEP 1
The type of query is SELECT.
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

FROM TABLE
d01buch
Nested iteration.
Index : d01sig
Forward Scan.
Positioning by key.
Keys are:
d01gsi ASC
Using I/O Size 4 Kbytes for index leaf pages.
With LRU Buffer Replacement Strategy for index leaf pages.
Using I/O Size 4 Kbytes for data pages.
With LRU Buffer Replacement Strategy for data pages.

1> fetch d01buch_seq

QUERY PLAN FOR STATEMENT 1 (at line 1).


STEP 1
The type of query is FETCH CURSOR d01buch_seq.

( record deleted from log )

(1 row affected)
1> close d01buch_seq

QUERY PLAN FOR STATEMENT 1 (at line 1).


STEP 1
The type of query is CLOSE CURSOR d01buch_seq.

`----

Reply With Quote
  #10  
Old   
Derek Asirvadem
 
Posts: n/a

Default Re: query plan: Optimized using the forced options (internallygenerated Abstract Plan) - 11-03-2011 , 03:17 PM



Matthias

On Nov 1, 12:06*am, rebelde <g... (AT) unixarea (DOT) de> wrote:

Quote:
Any comments on this?
Sure.

1. Ok, so you have not taken up my offer of a flight.

2. The question is completely different. As stated previously, if
you post the SHOWPLAN, we need the full DDL for the tables concerned.

3. What results (at all levels of inspection) do you get for:

DECLARE koe_daten_seq CURSOR FOR
SELECT SYB_IDENTITY_COL,
<column_list>
FROM koe_daten
WHERE katkey=1

And exclude all blobs from <column_list>.

As I am sure you are aware, you can't load * into a @variable; in the
normal circumstance, the cursor would load each column into a separate
variable; * cannot be used; it is only useful for testing purposes.

4. Can you please run this code on the 15.0.3 database that koe_daten
resides, and post the results.

SELECT [Pre-11.9 Structure] = name
FROM sysobjects
WHERE type = "U"
AND sysstat2 & 65536 = 0
ORDER BY 1

5. If you have not done so, execute:

DBCC REBUILD_TEXT( table_name)

On all tables that have blobs.

You can fix up a little bit here and a little bit there, but if you
have not unloaded/reloaded (via bcp out/in) your large tables,
especially those with blobs, in a long time, then it is much better to
do that. ASE 11.9 introduced far more efficient DataStructures for
NCIs and blobs. Take advantage of everything you have learned since
the database was first deployed, use Segments, distribute the tables,
distribute the DataStructures-of-tables, separate NCIs from the CI/
Heaps, etc. You can eliminate Level I Fragmentation while you are at
it (unloading/reloading tables in place will remove Level II but not
Level I).

Regards
Derek

Reply With Quote
Reply




Thread Tools
Display Modes

Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

vB code is On
Smilies are On
[IMG] code is On
HTML code is Off



Powered by vBulletin Version 3.5.3
Copyright ©2000 - 2012, Jelsoft Enterprises Ltd.