Merge with a WINDOW SORT PUSHED RANK in the execution plan can perform drastically worse in Oracle 21c than in 19c (tested on 21.6 and 19.15, respectively).<\/p>\n
Here’s the test case:<\/p>\n
create table t1 (n1 number, c1 varchar2(10)) ;\ncreate table t2 (n1 number, c1 varchar2(10), n2 number) ;\n\ninsert into t1 select level, null from dual connect by level <= 5*1e5 ;\ninsert into t2 select 5*1e5 + level, 'X', 1 from dual connect by level <= 4*1e5 ;\ncommit ;\n\nexec dbms_stats.gather_table_stats(null, 'T1');\nexec dbms_stats.gather_table_stats(null, 'T2');\n\nset timing on \n\nmerge \/*+ gather_plan_statistics monitor *\/ --nenad\ninto t1 using\n( select n1,c1 from \n ( select n1,c1, \n row_number() over (partition by n1 order by n2 desc) rn\n\tfrom t2\n ) where rn = 1\n) v1\non ( v1.n1 = t1.n1 )\nwhen matched then \nupdate set t1.c1 = v1.c1 ;<\/code><\/pre>\nOn 19c, merge took less than a second to complete:<\/p>\n
Global Stats\n=========================================\n| Elapsed | Cpu | Other | Buffer |\n| Time(s) | Time(s) | Waits(s) | Gets |\n=========================================\n| 0.41<\/span> | 0.40 | 0.01 | 1683 |\n=========================================\n\nSQL Plan Monitoring Details (Plan Hash Value=3917951292)\n===========================================================================================================================================\n| Id | Operation | Name | Rows | Cost | Time | Start | Execs | Rows | Mem | Activity | Activity Detail |\n| | | | (Estim) | | Active(s) | Active | | (Actual) | (Max) | (%) | (# samples) |\n===========================================================================================================================================\n| 0 | MERGE STATEMENT | | | | 1 | +1 | 1 | 1 | . | | |\n| 1 | MERGE | T1 | | | 1 | +1 | 1 | 1 | . | | |\n| 2 | VIEW | | | | | | 1 | | . | | |\n| 3 | HASH JOIN | | 1 | 3161 | 1 | +1 | 1 | 0 | 32MB | | |\n| 4 | TABLE ACCESS FULL | T1 | 500K | 155 | 1 | +1 | 1 | 500K | . | | |\n| 5 | VIEW | | 400K | 1750 | 1 | +1 | 1 | 400K | . | | |\n| 6 | WINDOW SORT PUSHED RANK | | 400K | 1750 | 1 | +1 | 1 | 400K | 23MB | | |\n| 7 | TABLE ACCESS FULL | T2 | 400K | 155 | 1 | +1 | 1 | 400K | . | | |\n===========================================================================================================================================<\/code><\/pre>\nOn 21c, the identical execution plan took 185s, mostly on CPU:<\/p>\n
Global Stats\n=========================================\n| Elapsed | Cpu | Other | Buffer |\n| Time(s) | Time(s) | Waits(s) | Gets |\n=========================================\n| 185<\/span> | 180 | 4.55 | 1639 |\n=========================================\n\nSQL Plan Monitoring Details (Plan Hash Value=3917951292)\n===========================================================================================================================================\n| Id | Operation | Name | Rows | Cost | Time | Start | Execs | Rows | Mem | Activity | Activity Detail |\n| | | | (Estim) | | Active(s) | Active | | (Actual) | (Max) | (%) | (# samples) |\n===========================================================================================================================================\n| 0 | MERGE STATEMENT | | | | 1 | +184 | 1 | 1 | . | | |\n| 1 | MERGE | T1 | | | 1 | +184 | 1 | 1 | . | | |\n| 2 | VIEW | | | | | | 1 | | . | | |\n| 3 | HASH JOIN | | 1 | 3161 | 183 | +2 | 1 | 0 | 32MB | | |\n| 4 | TABLE ACCESS FULL | T1 | 500K | 155 | 1 | +2 | 1 | 500K | . | | |\n| 5 | VIEW | | 400K | 1750 | 183 | +2 | 1 | 400K | . | | |\n| 6 | WINDOW SORT PUSHED RANK<\/span> | | 400K | 1750 | 184<\/span> | +1 | 1 | 400K | 23MB | | |\n| 7 | TABLE ACCESS FULL | T2 | 400K | 155 | 1 | +2 | 1 | 400K | . | | |\n===========================================================================================================================================<\/code><\/pre>\nIn spite of the identical execution plan and the same number of logical reads, the execution was much longer in 21c. All the extra time was spent in the WINDOW SORT PUSHED RANK<\/span> step. In particular, the profiled execution shows that the most of the time was spent in the Oracle C function smbgetqbPart<\/span>:<\/p>\nexport BPFTRACE_CACHE_USER_SYMBOLS=1\nbpftrace -e 'profile:hz:99 \n\/ pid == 2990815 \/ \n{ \n @[ustack()] = count(); \n}'\n\n@[\nsmbgetqbPart<\/span>+477\nsorgetqbf+599\nqerwnFetch+718\nqerstFetch+534\nqervwFetch+163\nqerstFetch+534\nrwsfcd+151\nqerstFetch+534\nqerhnFetch+6565\nqerstFetch+534\nqervwFetch+163\nqerstFetch+534\nrwsfcd+151\nqerstFetch+534\nqerusFetch+685\nqerstFetch+534\nupdaul+3457\nupdThreePhaseExe+325\nupsexe+1024\nopiexe+12237\nkpoal8+2239\nopiodr+1256\nttcpip+1257\nopitsk+1906\nopiino+1008\nopiodr+1256\nopidrv+1067\nsou2o+165\nopimai_real+400\nssthrdmain+412\nmain+292\n__libc_start_main+243\n0x5541f689495641d7\n]: 1886<\/code><\/pre>\nBased on the naming, I’m guessing that the function smbgetqbPart<\/span> gets the query block window partition. The problem is a very high number of executions (800001<\/span>), which, intuitively, seems unnecessary:<\/p>\nbpftrace -e 'uprobe:\/u00\/oracle\/orabase\/product\/21.6.0.0.220419_b\/bin\/oracle:smbgetqbPart+2\n\/ pid == 2990815 \/ \n{ \n @ = count(); \n}'\n\n@: 800001<\/span><\/code><\/pre>\nIn contrast, in 19c the function hasn’t been executed at all:<\/p>\n
bpftrace -e 'uprobe:\/u00\/oracle\/orabase\/product\/19.15.0.0.220419_a\/bin\/oracle:smbgetqbPart+2\n\/ pid == 3139940 \/ \n{ \n @ = count(); \n}'\n\n@: 0<\/span><\/code><\/pre>\nSimply put, the window partitioning execution changed between two releases. In particular, the following optimization introduced the problem:<\/p>\n
select bugno, value, sql_feature, description, optimizer_feature_enable \n from v$system_fix_control \n where lower(description) like '%pushed rank%' ;\n\n BUGNO VALUE\n---------- ----------\nSQL_FEATURE\n----------------------------------------------------------------\nDESCRIPTION\n----------------------------------------------------------------\nOPTIMIZER_FEATURE_ENABLE\n-------------------------\n 30822446 1\nQKSFM_EXECUTION_30822446\nenable window pushed rank optimization with partition by keys\n21.1.0<\/code><\/pre>\nAfter switching off the bug fix:<\/p>\n
alter session set \"_FIX_CONTROL\"='30822446:OFF' ;<\/code><\/pre>\nthe execution time reduced to the normal levels:<\/p>\n
Elapsed: 00:00:00.40<\/code><\/pre>\nAlso, the function smbgetqbPart isn’t being executed anymore:<\/p>\n
bpftrace -e 'uprobe:\/u00\/oracle\/orabase\/product\/21.6.0.0.220419_b\/bin\/oracle:smbgetqbPart+2\n\/ pid == 3154842 \/ \n{ \n @ = count(); \n}'\n\n@: 0<\/code><\/pre>\nIn conclusion, the new window pushed rank optimization can cause a severe performance degradation in Oracle 21c. Fortunately, the change can be switched off with the fix control (not documented in the Oracle support database).<\/p>\n
Update on January 18, 2023<\/h1>\n
Oracle released the patch “34381258 MERGE PERFORMANCE ISSUE AFTER BUG FIX 30822446” to fix the problem. Thanks to Martin Decker for mentioning this in the comment<\/a>. The patch is currently available for 19c but not for 21c. I tested it on top of 19.17.<\/p>\n","protected":false},"excerpt":{"rendered":"New optimization causing severe performance degradation. It can be switched off with the fix control. Continue Reading