偶發的儲存過程呼叫效能問題的一次調優過程

某儲存過程呼叫頻繁，絕大部分呼叫在1秒內結束。在每30分鐘內，有30到40次呼叫超過10秒。從業務上我們知道這個過程呼叫很頻繁，但到是什麼程度，我們還不清楚。另外，從執行計劃上來看，已經最優，沒有最佳化SQL的空間了。

下面是在這種情況下的調優過程。[@more@]

1. 系統檢測

（1）取系統等待並且阻塞的程式

SET NOCOUNT ON

SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED

GO

CREATE TABLE #block(

[current_time] [datetime] NOT NULL,

[resource_type] [nvarchar](60) NOT NULL,

[requested_object_name] [nvarchar](128) NULL,

[request_mode] [nvarchar](60) NOT NULL,

[request_status] [nvarchar](60) NOT NULL,

[resource_description] [nvarchar](2048) NULL,

[wait_duration_ms] [bigint] NULL,

[wait_type] [nvarchar](60) NULL,

[blocked_session_id] [smallint] NULL,

[blocked_start] [datetime] NOT NULL,

[blocked_command] [nvarchar](max) NULL,

[blocked_currentstat] [nvarchar](max) NULL,

[blocking_session_id] [smallint] NULL,

[blocking_start] [datetime] NULL,

[blocking_command] [nvarchar](max) NULL,

[blocking_currentstat] [nvarchar](max) NULL,

[blocking_wait_type] [nvarchar](60) NULL,

[blocking_wait_resource] [nvarchar](256) NULL,

[blocking_blocking] [smallint] NULL,

[blocking_wait_time] [int] NULL,

[open_transaction_count] [int] NULL,

[open_resultset_count] [int] NULL

)

GO

INSERT INTO #block

SELECT

GETDATE() AS [current_time]

,dtl.resource_type

,CASE

WHEN dtl.resource_type IN ('DATABASE', 'FILE', 'METADATA') THEN dtl.resource_type

WHEN dtl.resource_type = 'OBJECT' THEN OBJECT_NAME(dtl.resource_associated_entity_id)

WHEN dtl.resource_type IN ('KEY', 'PAGE', 'RID') THEN (

SELECT OBJECT_NAME([object_id])

FROM sys.partitions

WHERE sys.partitions.hobt_id = dtl.resource_associated_entity_id

)

ELSE 'Unidentified'

END AS requested_object_name

,dtl.request_mode

,dtl.request_status

,dowt.resource_description

,dowt.wait_duration_ms

,dowt.wait_type

,dowt.session_id AS [blocked_session_id]

,sp_blocked.start_time AS [blocked_start]

,desc_blocked.[text] AS [blocked_command]

,SUBSTRING(desc_blocked.[text], sp_blocked.statement_start_offset / 2,

( CASE WHEN sp_blocked.statement_end_offset = -1

THEN LEN(CONVERT(NVARCHAR(MAX), desc_blocked.[text])) * 2

ELSE sp_blocked.statement_end_offset

END - sp_blocked.statement_start_offset ) / 2) AS [blocked_currentstat]

,dowt.blocking_session_id

,sp_blocking.start_time AS [blocking_start]

,desc_blocking.[text] AS [blocking_command]

,SUBSTRING(desc_blocking.[text], sp_blocking.statement_start_offset / 2,

( CASE WHEN sp_blocking.statement_end_offset = -1

THEN LEN(CONVERT(NVARCHAR(MAX), desc_blocking.[text])) * 2

ELSE sp_blocking.statement_end_offset

END - sp_blocking.statement_start_offset ) / 2) AS [blocking_currentstat]

,sp_blocking.wait_type [blocking_wait_type]

,sp_blocking.wait_resource AS [blocking_wait_resource]

,sp_blocking.blocking_session_id AS [blocking_blocking]

,sp_blocking.wait_time AS [blocking_wait_time]

,sp_blocking.open_transaction_count

,sp_blocking.open_resultset_count

FROM sys.dm_tran_locks dtl

INNER JOIN sys.dm_os_waiting_tasks dowt

ON dtl.lock_owner_address = dowt.resource_address

INNER JOIN sys.dm_exec_requests sp_blocked

ON dowt.[session_id] = sp_blocked.session_id

LEFT JOIN sys.dm_exec_requests sp_blocking

ON dowt.[blocking_session_id] = sp_blocking.session_id

CROSS APPLY sys.[dm_exec_sql_text](sp_blocked.[sql_handle]) AS desc_blocked

OUTER APPLY sys.[dm_exec_sql_text](sp_blocking.[sql_handle]) AS desc_blocking

--WHERE dtl.[resource_database_id] = DB_ID()

IF @@ROWCOUNT > 0

SELECT * FROM #block

WAITFOR DELAY '00:00:02'

GO 1000

（2）監控效能計數器，檢視是否有過長的佇列或日誌更新

Disk	Displays
Avg. Disk Queue Length
Avg. Disk sec/Transfer
SQLServer: Database object counter
Log Bytes Per Flush	Number of bytes in the log buffer when the buffer is flushed.
Log Flushes/sec	Number of log flushes per second.
Log Flush Wait Time	Total wait time (milliseconds) to flush the log.
Log Flush Waits/sec	Number of commits per second that are waiting on log flush.

（3）查是否有掛起的IO請求

select

db_name(i.database_id) as db,

m.name,

m.physical_name,

i.io_stall as [user_waittime_for_io(ms)],

p.io_type,

p.io_pending_ms_ticks as [waittime_in_pending_queue]

from sys.dm_io_virtual_file_stats(NULL, NULL) as i

inner join sys.dm_io_pending_io_requests as p

on i.file_handle = p.io_handle

inner join sys.master_files as m

on m.database_id = i.database_id

and m.file_id = i.file_id

（4）檢視前15條呼叫最頻繁的儲存過程，或讀寫最多的儲存過程

SELECT TOP 15 a.object_id, a.database_id, OBJECT_NAME(object_id, database_id) 'proc name',

a.cached_time, a.last_execution_time, a.total_elapsed_time,

a.total_elapsed_time/a.execution_count AS [avg_elapsed_time],

a.execution_count,

a.execution_count/(datediff(ss, sqlserver_start_time, last_execution_time) ) as execution_count_per_second,

a.total_physical_reads/a.execution_count avg_physical_reads,

a.total_logical_writes,

a.total_logical_writes/ a.execution_count avg_logical_reads,

a.last_elapsed_time,

a.total_elapsed_time / a.execution_count avg_elapsed_time,

b.text,c.query_plan

FROM sys.dm_exec_procedure_stats AS a

CROSS APPLY sys.dm_exec_sql_text(a.sql_handle) as b

CROSS APPLY sys.dm_exec_query_plan(a.plan_handle) as c

cross join sys.dm_os_sys_info as d

ORDER BY [total_elapsed_time] DESC;

GO

2. 檢測結果

1）可以看到阻塞的源頭是WRITELOG；

（2）但windows的效能計數器磁碟佇列小於1，日誌更新的計數器也無特別異常；

（3）系統沒有掛起的IO請求；

（4）改儲存過程呼叫頻繁，每秒12次呼叫；用profiler可看到重複呼叫現象；

3. 調優方案

（1）報告應用端有重複呼叫現象；應用端修改重複呼叫；

（2）相關儲存過程可以使用nolock提示減低隔離級別；

（3）至此，效能應該有很大提高。但呼叫邏輯還可以進一步最佳化。如果效能再次成為問題的話，最佳化呼叫邏輯；