Analysis of the reasons for the slow execution of sql statements
This article mainly introduces "reason analysis of slow execution of sql statements". In daily operation, I believe that many people have doubts about the cause analysis of slow execution of sql statements. The editor consulted all kinds of data and sorted out simple and easy-to-use operation methods. I hope it will be helpful to answer the doubts of "reason analysis of slow execution of sql statements". Next, please follow the editor to study!
1. Environment:
Zzzzzz > @ ver1
PORT_STRING VERSION BANNER
X86_64/Linux 2.4.xx 11.2.0.3.0 Oracle Database 11g Enterprise Edition Release 11.2.0.3.0-64bit Production
two。 The execution script is as follows:
$cat a.txt
SELECT / * + & & 2 * / owner
Index_name
-- index_type
Table_NAME
COMPRESSION
UNIQUENESS
Distinct_keys
AVG_LEAF_blocks_per_key
AVG_DATA_BLOCKS_PER_KEY
Blevel
Leaf_blocks
Clustering_factor
Status
Num_rows
Sample_size
Last_analyzed
FROM dba_indexes
WHERE owner LIKE 'XXXXXX_YYY'
AND table_name = UPPER ('& & 1')
AND (owner, index_name) IN (SELECT owner, index_name)
FROM dba_indexes
WHERE owner LIKE 'XXXXXX_YYY'
AND index_type 'LOB'
MINUS
(SELECT object_owner, object_name
FROM v$sql_plan
WHERE object_type = 'INDEX'
AND object_owner LIKE 'XXXXXX_YYY'
UNION
SELECT object_owner, object_name
FROM dba_hist_sql_plan
WHERE object_type = 'INDEX'
AND object_owner LIKE 'XXXXXX_YYY')
MINUS
(SELECT owner, constraint_name
FROM dba_constraints
WHERE owner LIKE 'XXXXXX_YYY'
AND constraint_type IN ('P'
'U'
'R')
-- / / the main purpose is to exclude some indexes that are now in use.
3. Execute:
-/ / session 1:
Zzzzzz > alter session set statistics_level=all
Session altered.
Zzzzzz > @ a.txt MS_CF01 aaa
...
-/ / slow. Wait for...
-- / / session 1. Press ctrl+c to interrupt execution, but the execution is not actually completed:
Zzzzzz > @ dpc''
PLAN_TABLE_OUTPUT
-
SQL_ID frzb5c8tjx9wz, child number 0
...
Plan hash value: 2331593202
-
| | Id | Operation | Name | Starts | E-Rows | E-Bytes | Cost (% CPU) | E-Time | A-Rows | A-Time | Buffers | Reads | OMem | 1Mem | Used-Mem |
-
| | 0 | SELECT STATEMENT | | 1 | 485 (100) | | 1 | 00VO1Suzhou 42.24 | 2568K | 93 |
| | 1 | NESTED LOOPS OUTER | | 1 | 1 | 179 | 145 (0) | 00:00:02 | 1 | 00 01purl 42.24 | 2568K | 93 |
| | 2 | NESTED LOOPS OUTER | | 1 | 1 | 168 | 14444 (0) | 00:00:02 | 1 | 00 01purl 42.24 | 2568K | 93 |
| | 3 | NESTED LOOPS OUTER | | 1 | 1 | 1 | 1 | 143 (0) | 00:00:02 | 1 | 00 01purl 42.24 | 2568K | 93 |
... It's too long.
| | 38 | SORT UNIQUE | | 3490 | 1 | 375 | 340 (97) | 00:00:05 | 126 | 00VO3RAR 18.78 | 4909K | 15 | 2048 | 2048 |
| | 39 | UNION-ALL | | 3490 | 1461 | 00VERV 03VERV 18.73 | 4909K | 15 |
| | * 40 | FIXED TABLE FULL | X$KQLFXPL | 3490 | 1 | 22 | 3 (100,100) | 00:00:01 | 02600 | 02 | 0 | 0 |
| | * 41 | TABLE ACCESS FULL | WRH$_SQL_PLAN | 3489 | 1 | 17 | 308 (1) | 00:00:04 | 635 | 00lv 20.08 | 4909K | 15 | |
-- / / it is obvious that the main slow is ID=40,41, but in fact it is mainly the number of 3490 loops that leads to slow execution.
-- / / it's strange that I finished it very quickly under toad. The first execution needs to be actually a little longer, and it will be very soon after that. View the execution plan again
-- / / Note you can't look under toad. Toad can only see the execution plan of child_number=0.
Zzzzzz > @ dpc frzb5c8tjx9wz''
....
SQL_ID frzb5c8tjx9wz, child number 1
-
Plan hash value: 1956464785
- -
| | Id | Operation | Name | E-Rows | E-Bytes | Cost (% CPU) | E-Time | OMem | 1Mem | Used-Mem |
- -
| | 0 | SELECT STATEMENT | 570,100 | | |
| | * 1 | FILTER |
| | 2 | NESTED LOOPS OUTER | | 1 | 179 | 230 (0) | 00:00:03 |
| | 3 | NESTED LOOPS OUTER | | 1 | 168 | 229 (0) | 00:00:03 |
| | 4 | NESTED LOOPS OUTER | | 1 | 164,228 (0) | 00:00:03 |
| | 5 | NESTED LOOPS | | 1 | 156 | 227 (0) | 00:00:03 |
....
| | 50 | UNION-ALL |
| | * 51 | FIXED TABLE FULL | X$KQLFXPL | 1 | 22 | 3 (100) | 00:00:01 |
| | * 52 | TABLE ACCESS FULL | WRH$_SQL_PLAN | 1 | 17 | 308 (1) | 00:00:04 |
| | 53 | SORT UNIQUE NOSORT | | 1 | 211 | 15 (7) | 00:00:01 |
-- / / it was normal at first, because I set alter session set statistics_level=all;. under sqlplus But look carefully and plan carefully for the operation id is different, and the Plan hash value is also different.
-- / / I also try to add alter session set statistics_level=all; under toad and press F 9 to execute slowly.
Zzzzzz > @ share frzb5c8tjx9wz
SQL_TEXT = SELECT / * + aaa * / owner, index_name,-- index_type, table_NAME, COMPRESSION, UNIQUENESS, distinct_keys, AVG_LEAF_blocks_per_key, AVG_DATA_BLOCKS_PER_KEY
Blevel, leaf_blocks, clustering_factor, status, num_rows, sample_size, last_analyzed FROM dba_indexes WHERE owner LIKE: "SYS_B_00" AND table_name = UPPER (: "SYS_B_01") AND
Index_name) IN (SELECT owner, index_name FROM dba_indexes WHERE owner LIKE: "SYS_B_02" AND index_type: "SYS_B_03"
MINUS (SELECT object_owner, object_name FROM v$sql_plan WHERE object_type =: "SYS_B_04" AND
Object_owner LIK
SQL_ID = frzb5c8tjx9wz
ADDRESS = 00000000AA459A38
CHILD_ADDRESS = 00000000AB1E7238
CHILD_NUMBER = 0
REASON = 045NLS
Settings (0) 2x40003Optimizer
Mismatch (12) 2x216 all typical
SQL_TEXT = SELECT / * + aaa * / owner, index_name,-- index_type, table_NAME, COMPRESSION, UNIQUENESS, distinct_keys, AVG_LEAF_blocks_per_key, AVG_DATA_BLOCKS_PER_KEY
Blevel, leaf_blocks, clustering_factor, status, num_rows, sample_size, last_analyzed FROM dba_indexes WHERE owner LIKE: "SYS_B_00" AND table_name = UPPER (: "SYS_B_01") AND
Index_name) IN (SELECT owner, index_name FROM dba_indexes WHERE owner LIKE: "SYS_B_02" AND index_type: "SYS_B_03"
MINUS (SELECT object_owner, object_name FROM v$sql_plan WHERE object_type =: "SYS_B_04" AND
Object_owner LIK
SQL_ID = frzb5c8tjx9wz
ADDRESS = 00000000AA459A38
CHILD_ADDRESS = 00000000AB3775D8
CHILD_NUMBER = 1
OPTIMIZER_MISMATCH = Y
REASON = 13Optimizer mismatch (12) 2x216 typical all
-- / / I found a strange situation in which statements executed by sqlplus and statements executed under toad could not be shared, prompting LANGUAGE_MISMATCH= Y.
Zzzzzz > select sql_id,child_number,PLAN_HASH_VALUE,buffer_gets,executions,ELAPSED_TIME from v$sql where sql_id='frzb5c8tjx9wz'
SQL_ID CHILD_NUMBER PLAN_HASH_VALUE BUFFER_GETS EXECUTIONS ELAPSED_TIME
--
Frzb5c8tjx9wz 0 2331593202 4978087 1 201931031
Frzb5c8tjx9wz 1 1956464785 30458 2 1486831
-/ / compare the NLS* environments of the two:
Zzzzzz > select * from nls_session_parameters
PARAMETER VALUE
NLS_LANGUAGE AMERICAN
NLS_TERRITORY AMERICA
NLS_CURRENCY $
NLS_ISO_CURRENCY AMERICA
NLS_NUMERIC_CHARACTERS.
NLS_CALENDAR GREGORIAN
NLS_DATE_FORMAT YYYY-MM-DD HH24:MI:SS
NLS_DATE_LANGUAGE AMERICAN
NLS_SORT BINARY
NLS_TIME_FORMAT HH.MI.SSXFF AM
NLS_TIMESTAMP_FORMAT YYYY-MM-DD HH24:MI:SS.FF
NLS_TIME_TZ_FORMAT HH24.MI.SSXFF TZH:TZM
~ ~ ~
NLS_TIMESTAMP_TZ_FORMAT YYYY-MM-DD HH24:MI:SS.FF TZH:TZM
NLS_DUAL_CURRENCY $
NLS_COMP BINARY
NLS_LENGTH_SEMANTICS BYTE
NLS_NCHAR_CONV_EXCP FALSE
17 rows selected.
-- / / execute under toad:
Select * from nls_session_parameters
PARAMETER,VALUE
NLS_LANGUAGE,AMERICAN
NLS_TERRITORY,AMERICA
NLS_CURRENCY,$
NLS_ISO_CURRENCY,AMERICA
NLS_NUMERIC_CHARACTERS,.
NLS_CALENDAR,GREGORIAN
NLS_DATE_FORMAT,YYYY-MM-DD HH24:MI:SS
NLS_DATE_LANGUAGE,AMERICAN
NLS_SORT,BINARY
NLS_TIME_FORMAT,HH.MI.SSXFF AM
NLS_TIMESTAMP_FORMAT,YYYY-MM-DD HH24:MI:SS.FF
NLS_TIME_TZ_FORMAT,HH.MI.SSXFF AM TZR
~ ~
NLS_TIMESTAMP_TZ_FORMAT,YYYY-MM-DD HH24:MI:SS.FF TZH:TZM
NLS_DUAL_CURRENCY,$
NLS_COMP,BINARY
NLS_LENGTH_SEMANTICS,BYTE
NLS_NCHAR_CONV_EXCP,FALSE
-- / / pay attention to the underscore, only the parameter NLS_TIME_TZ_FORMAT is different.
$export NLS_TIME_TZ_FORMAT='HH.MI.SSXFF AM TZR'
Log in again and the problem disappears.
Alter session set statistics_level=all
@ a.txt MS_CF01 aaa
-- / / very slow. Execute after login:
@ a.txt MS_CF01 aaa
-- / / can be found very quickly, because I have already executed it once under toad.
-- / / I really didn't expect this parameter to cause such a strange problem.
-- / / additional explanation:
-- / / if it is written as' HH24.MI.SSXFF AM TZR', calls sqlplus to report an error.
$export NLS_TIME_TZ_FORMAT='HH24.MI.SSXFF AM TZR'
$rlsql system/test12@192.168.31.8:1521/hrp430
ERROR:
ORA-01818: 'HH24' precludes use of meridian indicator
SP2-0152: ORACLE may not be functioning properly
ORA-24550: signal received: [si_signo=11] [si_errno=0] [si_code=1] [si_int=0] [si_ptr= (nil)] [si_addr=0x10]
Kpedbg_dmp_stack () + 362,
