on 2014 Oct 30 8:27 AM
Update: The attached files can be viewed with ISQL version 11 (don't try using ISQL from version 16)...
fast-job5.saplan - the fast query that uses JOB_NO=5
slow-job4.saplan - the slow query that uses JOB_NO=4
Some of the text below has been edited to add line breaks to reduce the need to scroll left-right.
Breck
Using SQL Anywhere 11.0.1:
-- first list CALL SA_FLUSH_CACHE(); SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE='DR' AND JOB_NO=5 ORDER BY AUTOKEY takes 1.86 seconds to return 1,378 rows-- second list CALL SA_FLUSH_CACHE(); SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE='DR' AND JOB_NO=4 ORDER BY AUTOKEY takes 287.37 seconds to return 6,207 rows
-- table details SELECT COUNT(*) FROM event_trans gives 9,366,023 rows
SELECT row_value FROM sa_split_list( sa_get_table_definition('DBA','event_trans'), CHAR(10) ) gives CREATE TABLE "DBA"."EVENT_TRANS" ( "AUTOKEY" integer NOT NULL ,"EVENT_HISTORY" integer NOT NULL ,"PROCEDURE_CODE" varchar(3) NOT NULL ,"JOB_NO" integer NOT NULL ,"REFERENCE" varchar(25) NULL ,"NARRATIVE" varchar(45) NOT NULL ,"DEBIT" numeric(18,2) NULL ,"CREDIT" numeric(18,2) NULL ,"TRANS_TYPE" varchar(3) NOT NULL ,"NEW_BALANCE" "money" NULL ,"ALLOC_METHOD_USED" varchar(3) NULL ,"PAYMENT_TYPE" varchar(4) NULL DEFAULT 'U' ,"SOURCE_CURRENCY" varchar(3) NULL ,"SOURCE_DEBIT" "money" NULL DEFAULT 0 ,"SOURCE_CREDIT" "money" NULL DEFAULT 0 ,"TIMESTAMP" timestamp NULL DEFAULT timestamp ,"PRINCIPAL_BALANCE" "money" NULL ,"FEES_BALANCE" "money" NULL ,"COSTS_BALANCE" "money" NULL ,"INTEREST_BALANCE" "money" NULL ,"EXCHANGE_RATE" numeric(18,6) NULL ,"SORT_CODE" varchar(8) NULL ,"BANK_ACCOUNT" varchar(8) NULL ,"ALLOCATION_DONE" "boolean" NULL ,"IMPORT_EXPORT_STATUS" varchar(1) NULL ,"PAYER_NAME" varchar(30) NULL ,"PAYMENT_IN_FULL" "boolean" NULL ,"EFFECTIVE_DATE" date NULL ,"SOURCE_ITEM_ID" integer NULL ,"APPLY_TO" integer NULL ,"INVOICE_DATE" date NULL ,"CREDIT_TO_TRANS_TYPE" varchar(3) NULL ,"DISPUTED" "boolean" NULL ,"CREATE_NEW_GROUP" varchar(1) NULL ,"REMIT_DONE" "boolean" NULL ,"REMIT_COMMISSIONABLE" "money" NULL ,"REMIT_COMMISSION_RATE" numeric(18,2) NULL ,"REMIT_DATE" date NULL ,"REMIT_COMMISSION" "money" NULL ,"REMIT_AMOUNT" "money" NULL ,"REMIT_RUN_ID" integer NULL ,"REMIT_VAT_RATE" numeric(18,2) NULL ,"REMIT_VAT_ON_COMMISSION" "money" NULL ,"REMIT_AMOUNT_GROSS" "money" NULL ,"REMIT_AMOUNT_NET" "money" NULL ,"REMIT_RESIDUAL_INVOICE" "money" NULL ,"MANUALLY_ALLOCATED" "boolean" NULL ,"SKIP_BILL_CHARGES" "boolean" NULL ,"INPUT_TRANS_ID" integer NULL ,"INCLUDES_VAT_RATE" numeric(18,2) NULL DEFAULT 0 ,"INCLUDES_VAT_AMOUNT" "money" NULL DEFAULT 0 ,"INTEREST_RATE_CODE" varchar(5) NULL ,"COLLECTIONS_ONLY_FLAG" "boolean" NULL ,"LAST_COLLECTOR" varchar(3) NULL ,"LAST_COLLECTOR_ACTION_DATE" date NULL ,PRIMARY KEY ("AUTOKEY") );
ALTER TABLE "DBA"."EVENT_TRANS" ADD NOT NULL FOREIGN KEY "JOB" ("PROCEDURE_CODE","JOB_NO") REFERENCES "DBA"."JOB" ("PROCEDURE_CODE","JOB_NO") ON UPDATE CASCADE ON DELETE CASCADE; ALTER TABLE "DBA"."EVENT_TRANS" ADD NOT NULL FOREIGN KEY "EVENT_HISTORY" ("EVENT_HISTORY") REFERENCES "DBA"."EVENT_HISTORY" ("AUTOKEY") ON UPDATE CASCADE ON DELETE CASCADE; CREATE INDEX "I_REMIT_DONE" ON "DBA"."EVENT_TRANS" ( "REMIT_DONE" ); CREATE INDEX "I_SOURCE_ITEM_ID" ON "DBA"."EVENT_TRANS" ( "SOURCE_ITEM_ID" ); CREATE INDEX "I_REFERENCE" ON "DBA"."EVENT_TRANS"( "REFERENCE" ); CREATE INDEX "I_REMIT_RUN_ID" ON "DBA"."EVENT_TRANS"( "REMIT_RUN_ID" ); CREATE INDEX "I_REMITDATE_TYPE" ON "DBA"."EVENT_TRANS"( "REMIT_DATE","TRANS_TYPE" ); CREATE INDEX "I_TRANSACTION_TYPE" ON "DBA"."EVENT_TRANS"( "TRANS_TYPE","LAST_COLLECTOR" );
Here are the outputs from the PLAN function (I can't attach the .saplan files): -- first plan SELECT PLAN('SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE='DR' AND JOB_NO=5 ORDER BY AUTOKEY','','READ-ONLY') ( Plan [ Total Cost Estimate: 0.0845, Costed Best Plans: 3, Costed Plans: 9, Optimization Time: 0.00050279, Estimated Cache Pages: 263447 ] ( WorkTable ( Sort ( IndexScan EVENT_TRANS JOB[ ( EVENT_TRANS.PROCEDURE_CODE = 'DR' : 100% Statistics ) AND ( EVENT_TRANS.JOB_NO = 5 : 0.014711% Statistics ) ] ) ) ) ) )
-- second plan SELECT PLAN('SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE=''DR'' AND JOB_NO=4 ORDER BY AUTOKEY','','READ-ONLY') ( Plan [ Total Cost Estimate: 23.415, Costed Best Plans: 1, Costed Plans: 7, Optimization Time: 0.00039104, Estimated Cache Pages: 263447 ] ( IndexScan EVENT_TRANS EVENT_TRANS**[ ( EVENT_TRANS.PROCEDURE_CODE = 'DR' : 100% Statistics ) AND ( EVENT_TRANS.JOB_NO = 4 : 0.066249% Statistics ) ] ) )
Obvious difference is first plan uses a work table and sort but I don't know why...and also why it takes SO LONG!
Request clarification before answering.
This is a great example of one of my tips from the Performance and Tuning talk at the #SQLAnySummit2014. The optimization_goal option is set to 'First-row' for both plans. The optimizer is trying hard to pick a plan that will let you pick the first few rows quickly from a cursor, but not to fetch all of the rows through the cursor.
The "slow" plan has a first row returned in 0.22661 seconds while the "fast" plan is 2.5468 seconds. Since you are optimizing for first-row instead of all-rows, this the "slow" plan is actually better at meeting the goal.
This is also a nice example of a query where Optimization Method is "Bypassed then optimized". The statement is simple enough to qualify for "bypass costed" but the overall cost was found to be higher than the cutoff, so the query was optimized using the full blown optimizer.
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
The optimization_goal option is set to 'First-row'...
Ah, that's what I (and possibly Breck?) have missed - no need to add indexes or change FK definitions, no need to rewrite queries with ugly index hints or user estimates, no need for refreshed statistics - just put that option to its default "All-rows" - and trust that Watcom Rule. And I think the option's explanation in the docs does really tell why the current option may lead to the noticed behaviour.
(That's my guess, since apparently @da69plc will have to test the results...)
The fast plan uses the JOB index to find all the rows with JOB_NO=5, then sorts them to satisfy the ORDER BY AUTOKEY.
The slow plan does not use the JOB index, presumably because the higher percentage 0.062254% meant there would be a larger number of rows with JOB_NO=4 (which there were) and that it would be inefficient to put those rows in a work table and sort them. Instead, the slow plan processes all the rows in AUTOKEY order (the primary key index) and keeps the ones with JOB_NO=4.
You have already tried forcing the statistics to be updated, but that might not have helped because 0.062254% looks about right (6207 / 9366023 rows = 0.0663%).
You could also try using a very small (small is good) explicit selectivity estimate to force SQL Anywhere 11 to use the JOB index; the following code has not been tested:
SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE='DR' AND ( JOB_NO=4, 0.00001 ) ORDER BY AUTOKEY
SQL Anywhere 11 also supports index hints in the FROM clause (FORCE INDEX etcetera).
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
I've just tried the SQL statement above and it still took 186 seconds to return 6k of rows. As per comment 23304, I have tried adding a simple index on just JOB_NO and that didn't work either. I'm gonna be bald at this rate.
NB. Why is 0.06% / 6000 considered a large number of rows when a. the table contains approx 10 million rows and b. 6000 rows isn't really a large number of rows?
Is there a server setting I can use along the lines of "don't be stupid and perform a table scan/process using the primary key index (which will be ALL rows) whenever you have an index that can be used regardless of statistics"?
> I've just tried the SQL statement above and it still took 186 seconds to return 6k of rows.
That may not be perfect, but it is twice as fast as before.
What is the plan for that query?
Minor changes can cause huge changes in the plan... even the passing of time can cause changes if the environment changes (cache populated, rows inserted, and so on). Without looking at the plan at each step along the way, no new understanding is gained.
> As per comment 23304, I have tried adding a simple index on just JOB_NO and that didn't work either.
When making changes, please show the exact change, and the resulting plan. Query optimization can be hard work, and attention to detail is critical. Phrases like "that didn't work" do not provide much information, whereas it might be very useful to investigate WHY it didn't work... experiments that fail often provide more valuable information that ones which succeed.
> Why is 0.06% / 6000 considered a large number of rows when a. the table contains approx 10 million rows and b. 6000 rows isn't really a large number of rows?
It is 500% larger than the number of rows than the other query had to deal with. Point 1: Full table scans are more efficient than indexes in some surprising situations. Point 2: Performance is hard to analyze and completely impossible to predict. Point 3: It is pointless to anthropomorphize the query engine, it is not human, what it finds easy and hard is almost never the same as what might seem easy or hard for us.
Sorry for the delay, I have been testing out EBF3158 on my pc and have since upgraded the live server.
I apologise if I am appearing an arse. I am frustrated that having used lots of different DB servers over the years (MySQL, MSSQL, Advantage, FlashFiler, SQLite), I have never experienced such drastic performance impairment from such a simple query!!
So, using live server/training DB/no SA_FLUSH_CACHE(), here are timings:
query #1 SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE='DR' AND JOB_NO=4 ORDER BY AUTOKEY -- takes 347.46 seconds for 6,255 rows query #2 SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE='DR' AND JOB_NO=4 ORDER BY AUTOKEY DESC -- takes 2.26 seconds for 6,255 rows query #3 SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE='DR' AND JOB_NO=4 ORDER BY AUTOKEY -- takes 93.54 seconds for 6,255 rows query #4 SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE='DR' AND JOB_NO=4 ORDER BY AUTOKEY DESC -- takes 0.16 seconds for 6,255 rows query #5 SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE='DR' AND JOB_NO=4 ORDER BY AUTOKEY -- takes 79.16 seconds for 6,255 rows query #6 SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE='DR' AND JOB_NO=4 ORDER BY AUTOKEY DESC -- takes 0.08 seconds for 6,255 rows query #7 SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE='DR' AND JOB_NO=4 -- takes 0.16 seconds for 6,255 rows query #7
I have emailed Breck the graphic plans.
How can I make the setting permanent?
As with any option. If you want to change the general (aka not user-specific) setting, use
SET OPTION PUBLIC.optimization_goal = 'All-rows';
You can check whether there are user-specific settings via:
select * from sysoption where "option" = 'optimization_goal';
If there are, you may want to delete them or change them as well.
The following plans were sent to me Fri, Nov 7, 2014 at 5:07 AM
They can be viewed by opening them in V1 ISQL.
If you don't rename the files to *.saplan, you will have to click on "SQL Anywhere plan" when ISQL asks "what is this thing you want me to display?"
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
Here goes...
The two queries probably run at different speeds because the plans are quite different.
The text plan doesn't give as much information as the graphical plan so it is difficult to tell exactly why the plans are different, but huge difference in statistics may have something to do with it...
( EVENT_TRANS.JOB_NO = 5 : 0.014711% Statistics )
( EVENT_TRANS.JOB_NO = 4 : 0.066249% Statistics )
The statistics may be wrong, or SQL Anywhere may be making a bad decision, or something else... please send me the Graphical Plan With Statistic *.saplan (the WITH STATISTICS part is very important) so I can post them for you, and we can all have a look.
...or, we can all keep guessing about what is happening 🙂
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
(again in the training area) I've executed a: CREATE STATISTICS ON EVENT_TRANS;
CALL SA_FLUSH_CACHE(); SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE='DR' AND JOB_NO=5 ORDER BY AUTOKEY -- 1427 rows in 2.59 seconds
CALL SA_FLUSH_CACHE(); SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE='DR' AND JOB_NO=4 ORDER BY AUTOKEY -- 6255 rows in 355.45 seconds
Breck, I've emailed you @ gmail the saplan files...
Note, both queries are not identical because the JOB_NO in the WHERE clause is different (which you are aware of, of course, but it's worth stating...). As such, and because both values have different estimates, I would think it's not unexpected that different cardinalities can (and possibly should) lead to different access plans. Needless to say, they should not lead to poor performance in one case...
In case the PROCEDURE_CODE is always the same for the given JOB_NOs (if I understand the plan statistics correctly), it might be helpful to add a particular index just on the JOB_NO instead of relying on the index created on the FK.
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
As the queries are not exactly the same, that's why I included the row counts...the different cardinalities shouldn't make such a BIG difference to the timings...
The procedure code is down to what the user enters in and could be COL or DR.
How about these timings then for the SAME data with ONLY a different sort direction (each executed one-after-the-other in the order listed)!
CALL SA_FLUSH_CACHE(); SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE='DR' AND JOB_NO=4 ORDER BY AUTOKEY DESC -- takes 8.43 seconds to return 6,207 rowsCALL SA_FLUSH_CACHE(); SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE='DR' AND JOB_NO=4 ORDER BY AUTOKEY -- takes 311.46 seconds to return 6,207 rows
CALL SA_FLUSH_CACHE(); SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE='DR' AND JOB_NO=5 ORDER BY AUTOKEY DESC -- takes 1.89 seconds to return 1,378 rows
CALL SA_FLUSH_CACHE(); SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE='DR' AND JOB_NO=5 ORDER BY AUTOKEY -- takes 2.00 seconds to return 1,378 rows
Also we have lots of tables that are indexed (or have foreign key indexes) on PROCEDURE_CODE+JOB_NO...
When you use a composite foreign key and therefore the engine creates a composite index, it's always helpful to have the "most-searched" column as the first column, cf. this explanation from the docs. The same will hold when one of the columns has only a few distinct values and the other(s) do not - then it should be put behind columns with more distinct values in the FK declaration.
In case the PROCEDURE_CODE has just 2 distinct values, an index on that won't help much, so I suggest to
and try those queries again.
The difference between sorting in ascending and descending order in your first two samples might also hint at an only partially useable composite index. In general, sorting should be equally fast in both directions, as an index can be used for both directions, as Mark has explained in this FAQ: "Is it useful to have ascending + descending index?".
Firstly I took the reverse FK option as I thought it would be better than the table having another index to maintain, so I: a. disabled materialized views b. changed the foreign key columns around, ie. JOB_NO+PROCEDURE_CODE c. re-built mat views and tried again. It still took the same length of time.
I tried the second option, by adding a simple index: CREATE INDEX ixJOB_NO ON event_trans (JOB_NO) which took ONLY 57 seconds to create for 9,366,023 rows!!
The query... CALL SA_FLUSH_CACHE(); SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE='DR' AND JOB_NO=4 ORDER BY AUTOKEY ...took 312 seconds to run!
disabled materialized views
So there are materialized views dependent on this table? May it be they come in here automagically (i.e. without explicitly called by you) and they may have an impact (I'm not sure how they will be noticeable within a plan)?
As to the still slow query: How do the times differ when repeating the query without flushing the cache and when using different JOB_NOs? (Within production use, you won't have an emptied cache, so these timings may be reproducable but not realistic.)
I am running the queries on our "training" database. I have disabled access to the training database for my tests so as not to influence the time taken with other selects / inserts / updates. This is the same physical server running a separate TRAINING service instance on a copy of the live database from last week. Both services' report a server version of 11.0.1.2661. I have also DROPPED all the materialized views that used EVENT_TRANS!
I am investigating this as a user reported (on live server) that account "5" was taking a long time to display on the screen. I tried accounts 1, 2, 3, 4 and 5 and found that only 5 took a noticeably longer time to display on screen (from within our software).
But a test application (Delphi/UNIDAC/ODBC) shows account 5 to be one of the fastest - while the others are slower?!
** tests (I don't understand the huge slowdown in timings for less rows?)
if flushing, I use CALL SA_FLUSH_CACHE() before the SELECT AUTOKEY FROM EVENT_TRANS WHERE PROCEDURE_CODE='DR' AND JOB_NO=? ORDER BY AUTOKEYflush where job = 1 -- 340.06 seconds to return 5636 rows no flush where job = 1 -- 134.12 seconds to return 5636 rows
flush where job = 2 -- 5.80 seconds to return 6186 rows no flush where job = 2 -- 0.08 seconds to return 6186 rows
flushed where job=3 -- 5.72 seconds to return 4586 rows not flushed where job=3 -- 0.06 seconds to return 4586 rows
flushed where job=4 -- 307.49 seconds to return 6207 rows not flushed where job=4 -- 31.36 seconds to return 6207 rows
flushed where job=5 -- 1.89 seconds to return 1378 rows not flushed where job=5 -- 0.02 seconds to return 1378 rows
Also I have a proxy table C_EVENT_TRANS which points to the same table definition but in an external mysql database/INNODB table and the query only takes 3.48 seconds to return 5636 rows.
I need to get the performance of this fixed as this table is only going to get bigger!
server version of 11.0.1.2661
Note, there have been several 11.0.1 EBFs after that and before it has been EOL'ed in May, the last one (on Windows) is 11.0.1.3158, according to Breck himself. So in general, trying with the newest EBF might also be recommended. (Note, I do not know whether that will help with your particular query problem, it's just a general hint.)
User | Count |
---|---|
76 | |
30 | |
10 | |
8 | |
8 | |
7 | |
7 | |
5 | |
4 | |
4 |
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.