Database performance Optimization Analysis Case---Solving the problem of excessive CPU consumption in SQL statements

Source: Internet
Author: User
Tags count create index execution connect sql sleep sort sorts
Solution | data | database | problem | performance | optimization | statement
Problem Description:
October 25 Morning Binzhou Netcom's Engineers report OSS application system running slowly, the specific operation is through the OSS system query, a long time to return results, seriously affecting the normal use of customers.

Problem handling:
1. Login to the database host, with SAR command to see the value of idle continued to 0,cpu resources have been depleted:

bz_db1# SAR 2 4

SunOS kest 5.8 generic_108528-19 sun4u 10/26/04

10:56:46%usr%sys%wio%idle
10:56:48 1 4 95 0
10:56:50 1 5 94 0
10:56:52 0 6 93 0
10:56:54 1 6 93 0

Average 1 5 94 0


2. Use the top command to see two processes that are significantly CPU-intensive, following the results of the top command:

bz_db1# Top

Last Pid:1664;load averages:3.26, 3.24, 3.69
159 processes:152 sleeping, 2 running, 2 Zombie, 1 stopped, 2 on CPU
CPU states:1.5% Idle, 72.5% user, 17.9% kernel, 8.0% iowait, 0.0% swap
memory:2.0g Real, 233M free, 2.0G swap with use, 3.4G swap free

PID USERNAME THR PR NCE SIZE RES State time Flts CPU COMMAND
27420 Oracle 1 0 1.3G 1.2G cpu01 22.9H 2 31.94% Oracle
27418 Oracle 1 0 1.3G 1.2G run 23.0H 6 26.86% Oracle
5943 Oracle 1 0 1.3G 1.2G sleep 25:26 notoginseng 4.92% Oracle
6295 Oracle 1 0 1.3G 1.2G run 25:14 4.90% Oracle
7778 Oracle 1 0 1.3G 1.2G sleep 11:43 4.86% Oracle
13270 Oracle 1 0 1.3G 1.2G sleep 210.6H 0 0.96% Oracle
13056 Oracle 1 0 1.3G 1.2G sleep 303:30 0 0.37% Oracle
10653 Root 1 0 2560K 1624K cpu00 0:00 0 0.32% Top
18827 Oracle 1 0 1.3G 1.2G sleep 18.4H 0 0.31% Oracle
12748 Oracle 258 0 1.3G 1.2G sleep 555:14 0 0.21% Oracle
10634 Oracle 1 0 1.3G 1.2G sleep 0:01 0 0.21% Oracle
28458 Oracle 1 0 1.3G 1.2G sleep 535:02 0 0.18% Oracle
13075 Oracle 1 0 1.3G 1.2G sleep 326:33 0 0.15% Oracle
13173 Oracle 1 0 1.3G 1.2G sleep 593:07 0 0.13% Oracle
4927 Oracle 1 0 1.3G 1.2G sleep 33.4H 0 0.11% Oracle

You can see that the two process numbers are 27420 and 27418, respectively.

3. Capture SQL statements that consume high CPU utilization:

Here's a summary of my SQL statement:

Sql>set Line 240
Sql>set Verify off
Sql>column SID Format 999
Sql>column PID Format 999
Sql>column s_# Format 999
Sql>column username format A9 heading "ORA User"
Sql>column Program Format A29
Sql>column SQL Format A60
Sql>column osname format A9 Heading "OS User"
Sql>select p.pid pid,s.sid sid,p.spid spid,s.username username,
S.osuser osname,p.serial# S_#,p.terminal,p.program Program,
P.background,s.status,rtrim (SUBSTR (A.sql_text, 1)) SQL
From V$process P, v$session s,v$sqlarea A WHERE p.addr = s.paddr
and s.sql_address = a.address (+) and p.spid like '%&1% ';

Enter value for 1:27,420 (note that the PID for the highest CPU process should be entered here)

Get the following SQL statement:

Select NVL (SUM (localcharge), 0), NVL (sum (usage), 0) from Localusage where To_char (Endtime, ' YYYYMMDD ') =20041016
and localcharge>0 and caller like ' 543,886% ';

The 27418 process corresponds to the following SQL statement:
Select NVL (SUM (localcharge), 0) from Localusage where To_char (Endtime, ' YYYYMMDD ') =20041016 and caller like ' 543,888% ';


4. Use the relevant user to connect to the database and check its execution plan:
Sql>connect Wacos/oss
Connected.

Sql>@?/rdbms/admin/utlxplan.sql
Table created.

Sql>set Autotrace on

Sql>set Timing on

Sql>select NVL (SUM (localcharge), 0), NVL (sum (usage), 0) from Localusage where To_char (Endtime, ' YYYYMMDD ') =20041016
and localcharge>0 and caller like ' 543,886% ';

NVL (sum (localcharge), 0) NVL (sum (USAGE), 0)
----------------------- -----------------
0 0

elapsed:00:02:56.37

Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT optimizer=choose (cost=13435 card=1 bytes=5
3)

1 0 SORT (AGGREGATE)
2 1 PARTITION RANGE (All)
3 2 TABLE ACCESS (full) ' Localusage ' (cost=13435 card=1
Bayi bytes=9593)

Statistics
----------------------------------------------------------
258 Recursive calls
0 db Block gets
88739 consistent gets
15705 Physical Reads
0 Redo Size
580 Bytes sent via sql*net to client
651 Bytes received via sql*net from client
2 sql*net roundtrips To/from Client
8 Sorts (memory)
0 Sorts (disk)
1 rows processed

found that the Localusage table did a full table scan, what records also did not return to actually use more than 2 minutes.

sql> Select NVL (SUM (localcharge), 0) from Localusage where To_char (Endtime, ' YYYYMMDD ') =20040816 and caller like ' 543,888% ';

NVL (SUM (Localcharge), 0)
-----------------------
27.6

elapsed:00:03:56.46

Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT optimizer=choose (cost=13435 card=1 bytes=4
0)

1 0 SORT (AGGREGATE)
2 1 PARTITION RANGE (All)
3 2 TABLE ACCESS (full) ' Localusage ' (cost=13435 card=3
615 bytes=144600)

Statistics
----------------------------------------------------------
0 Recursive calls
0 db Block gets
88588 consistent gets
15615 Physical Reads
0 Redo Size
507 Bytes sent via sql*net to client
651 Bytes received via sql*net from client
2 sql*net roundtrips To/from Client
0 Sorts (memory)
0 Sorts (disk)
1 rows processed

This SQL statement has results returned, and found that the Localusage table did a full table scan, but the speed is very slow, with more than 3 minutes.

Sql> Select COUNT (*) from Localusage;

COUNT (*)
----------
5793776

The table has more than 5.79 million records, a large amount of data, full table scanning is no longer suitable.

5. Check the type of the table:

Sql> SELECT index_name, TABLE_NAME, STATUS, partitioned from user_indexes WHERE table_name= ' localusage ';

INDEX_NAME table_name STATUS PAR
------------------------------ ------------------------------ -------- ---
I_localusage_sid localusage N/a YES
UI_LOCALUSAGE_ST_SEQ localusage N/a YES

Sql> SELECT index_name,table_name,locality from user_part_indexes where table_name= ' localusage ';

INDEX_NAME table_name Locali
------------------------------ ------------------------------ ------
I_localusage_sid Localusage Local
Ui_localusage_st_seq Localusage Local

The table was found to be a partitioned table and a partitioned index was established on the Serviceid,startime and Cdrsequence columns, with the index type being a local index.

6. View index key values for partitioned indexes:

Sql> Select Index_name,column_name,index_owner from dba_ind_columns where table_name= ' localusage ';

Index_name column_name Index_owner
-------------------- -------------------- ------------------------------
I_localusage_sid Serviceid Wacos
Ui_localusage_st_seq StartTime Wacos
Ui_localusage_st_seq cdrsequence Wacos

It was found that no index was established on both the Endtime and caller columns, which was the ultimate cause of the full table scan of the SQL statement.

7. Decide to create a new partitioned index to eliminate the full table scan:

(1). First View Localusage table partitioning:

Sql> Select Partition_name,tablespace_name from user_tab_partitions where table_name= ' localusage ';

Partition_name Tablespace_name
------------------------------ ------------------------------
localusage_200312 Wacos
localusage_200401 Wacos
localusage_200402 Wacos
localusage_200404 Wacos
localusage_200405 Wacos
localusage_200406 Wacos
localusage_200407 Wacos
localusage_200409 Wacos
localusage_200410 Wacos
localusage_200411 Wacos
localusage_200403 Wacos
localusage_200408 Wacos
localusage_200412 Wacos

Rows selected.

(2). Create a local partition index on the caller column:
Sql>set Timing on
Sql>create index I_localusage_caller on localusage (CALLER)
Local
(
PARTITION localusage_200312,
PARTITION localusage_200401,
PARTITION localusage_200402,
PARTITION localusage_200404,
PARTITION localusage_200405,
PARTITION localusage_200406,
PARTITION localusage_200407,
PARTITION localusage_200409,
PARTITION localusage_200410,
PARTITION localusage_200411,
PARTITION localusage_200403,
PARTITION localusage_200408,
PARTITION localusage_200412
)
Tablespace Wacos
STORAGE (
INITIAL 6553600
NEXT 6553600
Maxextents Unlimited
Pctincrease 0)
PCTFREE 5
nologging;

Index created.

elapsed:00:06:27.90 (6 minutes due to large data volume)

8. View the execution plan again:
Sql>select NVL (SUM (localcharge), 0), NVL (sum (usage), 0) from Localusage where To_char (Endtime, ' YYYYMMDD ') =20041016
and localcharge>0 and caller like ' 543,886% ';

NVL (sum (localcharge), 0) NVL (sum (USAGE), 0)
----------------------- -----------------
0 0

elapsed:00:00:03.00

Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT optimizer=choose (cost=22 card=1 bytes=53)
1 0 SORT (AGGREGATE)
2 1 PARTITION RANGE (All)
3 2 TABLE ACCESS (by the local INDEX ROWID) of ' Localusage ' (cost=22 card=181 bytes=9593)
4 3 INDEX (RANGE SCAN) of ' I_localusage_caller ' (non-unique) (cost=14 card=65063)

Statistics
----------------------------------------------------------
0 Recursive calls
0 db Block gets
16813 consistent gets
569 physical Reads
0 Redo Size
580 Bytes sent via sql*net to client
651 Bytes received via sql*net from client
2 sql*net roundtrips To/from Client
0 Sorts (memory)
0 Sorts (disk)
1 rows processed

This time after the index is significantly faster than the speed, in 3 seconds to return the results.

Sql>select NVL (SUM (localcharge), 0) from Localusage where To_char (Endtime, ' YYYYMMDD ') =20040816 and caller like ' 543,888% ';

NVL (SUM (Localcharge), 0)
-----------------------
27.6

elapsed:00:00:24.73

Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT optimizer=choose (cost=22 card=1 bytes=40)
1 0 SORT (AGGREGATE)
2 1 PARTITION RANGE (All)
3 2 TABLE ACCESS (by the local INDEX ROWID) of ' Localusage ' (cost=22 card=3615 bytes=144600)
4 3 INDEX (RANGE SCAN) of ' I_localusage_caller ' (non-unique) (cost=14 card=65063)

Statistics
----------------------------------------------------------
0 Recursive calls
0 db Block gets
129336 consistent gets
7241 Physical Reads
0 Redo Size
507 Bytes sent via sql*net to client
651 Bytes received via sql*net from client
2 sql*net roundtrips To/from Client
0 Sorts (memory)
0 Sorts (disk)
1 rows processed

This SQL statement went through the index, with 24 seconds to return the result, performance significantly improved a lot.



Contact Us

The content source of this page is from Internet, which doesn't represent Alibaba Cloud's opinion; products and services mentioned on that page don't have any relationship with Alibaba Cloud. If the content of the page makes you feel confusing, please write us an email, we will handle the problem within 5 days after receiving your email.

If you find any instances of plagiarism from the community, please send an email to: info-contact@alibabacloud.com and provide relevant evidence. A staff member will contact you within 5 working days.

A Free Trial That Lets You Build Big!

Start building with 50+ products and up to 12 months usage for Elastic Compute Service

  • Sales Support

    1 on 1 presale consultation

  • After-Sales Support

    24/7 Technical Support 6 Free Tickets per Quarter Faster Response

  • Alibaba Cloud offers highly flexible support services tailored to meet your exact needs.