Добро пожаловать в форум, Guest  >>   Войти | Регистрация | Поиск | Правила | В избранное | Подписаться
Все форумы / Microsoft SQL Server Новый топик    Ответить
 Поиск причин снижения производительности  [new]
1klassNick
Member

Откуда:
Сообщений: 24
Dell PowerEdge 2950, RAM 16G, 2-Xeon quad 2.66Gh
RAID 10 - 4 диска (72G, 12000rpm): 2 базы по 10 G (Recovery:full), tempdb и логи все на одном диске
RAID 1 - OS
SQL: Microsoft SQL Server 2005 - 9.00.4035.00 (X64) Nov 24 2008 16:17:31 Copyright (c) 1988-2005 Microsoft Corporation Enterprise Edition (64-bit) on Windows NT 5.2 (Build 3790: Service Pack 2)

Есть набор процедур, каждая вызывается в течении суток порядка 2000 раз.
Ведется трассировка всех запросов к БД. Maintenance 1 раз в сутки с перестроением индексов.
В 15 % случаев время выполнения увеличивается в 10 раз.
Как можно определить причины увеличения времени выполнения.
Хотелось бы создать план "разбора полета" чтобы можно было сказать:
"что такая-то хранимая процедура выполнилась долго в такое-то время из-за...
17 июн 09, 20:55    [7312890]     Ответить | Цитировать Сообщить модератору
 Re: Поиск причин снижения производительности  [new]
Glamorama
Member

Откуда:
Сообщений: 152
Субъективно - нельзя такой статистики собрать, потому как время исполнения процедуру зависит много от чего и замониторить это "много чего" через скуль не всегда можно (имею в виду загрузку проца, очереди на дисках, кол-во и качество запросов).
И вообще, каким образом Вы пришли к выводу о периодическом существенном ускорении запросов??


Первое, что приходит на ум в вашем случае - помониторьте профайлером, возможно у Вас часто рекомпилируются процедуры.
Второе - может быть у Вас есть таблицы, в которые вставляется большое кол-во данных из-за чего статистика и соотвественно планы запросов становятся не актуальны.
Третье - 15% слишком маленькая величина, смахивает на какой-то разгрузочный день.
17 июн 09, 22:38    [7313080]     Ответить | Цитировать Сообщить модератору
 Re: Поиск причин снижения производительности  [new]
komrad
Member

Откуда: Msk -> Utrecht
Сообщений: 5189
1klassNick

В 15 % случаев время выполнения увеличивается в 10 раз.

на вскидку - автоматический апдейт статистики?
18 июн 09, 02:40    [7313547]     Ответить | Цитировать Сообщить модератору
 Re: Поиск причин снижения производительности  [new]
1klassNick
Member

Откуда:
Сообщений: 24
Рассматриваемые процедуры не рекомпиляться - счетчик использования непрерывно растет.
Вставок и обновлений в таблицы, которые используются этими ХП, мало, (20% набегает раз в полгода) автоматическое обновление статистики поэтому бывает редко,
и этот случай легко вычисляется профайлером.
В ХП используются временные таблицы.
Раз в неделю проводяться апдейты, добавляются новые процедуры в основном отчетного характера.
Анализируемый набор процедур при этом не меняется, уровень изоляции в них read uncommitted, данные только извлекаются ( данные для формирования страниц сайта).

Выполнил:

select wait_type, waiting_tasks_count, wait_time_ms, signal_wait_time_ms, k=wait_time_ms / waiting_tasks_count
from sys.dm_os_wait_stats  
where wait_type like 'PAGEIOLATCH%' and waiting_tasks_count > 0
order by wait_type

Результат:

wait_type waiting_tasks_count wait_time_ms signal_wait_time_ms k
PAGEIOLATCH_EX 198366 663531 2140 3
PAGEIOLATCH_SH 133199 1454234 11921 10
PAGEIOLATCH_UP 60594 166437 41593 2


Выполнил:

SELECT DB_NAME(saf.dbid) AS [DB]
, saf.name AS [FName]
, vfs.BytesRead/1048576 AS [Read(MB)]
, vfs.BytesWritten/1048576 AS [Write(MB)]
FROM sysaltfiles AS saf
JOIN :: fn_virtualfilestats(NULL,NULL) AS vfs
ON vfs.dbid = saf.dbid
AND vfs.fileid = saf.fileid
AND saf.dbid NOT IN (1,3,4)
ORDER BY vfs.BytesRead/1048576 + BytesWritten/1048576 DESC

Результат:

DB FName Read(MB) Write(MB)
tempdb tempdev 2728168 2785388
tempdb templog 81 1801634
TP TP_Data 237535 20183
ST Store_Data 227814 12462
ST Store_Log 11512 11597
Trace Trace_log 1 16346
Trace Trace 4093 11081
TP TP_Log 4 9327


Мои "подозрения":
- диски
- tempdb на общем диске
- конкуренция за процессор
- блокировки
18 июн 09, 16:45    [7316614]     Ответить | Цитировать Сообщить модератору
 Re: Поиск причин снижения производительности  [new]
Glamorama
Member

Откуда:
Сообщений: 152
простой вопрос на который сложно получить ответ (разве что ручками данные собирать) -
как у Вас соотносятся эти ускорения с загрузкой сервера (процессор/очереди на дисках/кол-во активных пользователей)??
18 июн 09, 18:15    [7317336]     Ответить | Цитировать Сообщить модератору
 Re: Поиск причин снижения производительности  [new]
1klassNick
Member

Откуда:
Сообщений: 24
Glamorama

как у Вас соотносятся эти ускорения с загрузкой сервера (процессор/очереди на дисках/кол-во активных пользователей)??


Ускорений как раз то и нет, есть замедления в 15 % случаев вызовов процедур.
18 июн 09, 18:36    [7317429]     Ответить | Цитировать Сообщить модератору
 Re: Поиск причин снижения производительности  [new]
1klassNick
Member

Откуда:
Сообщений: 24
Посетителей сайта от 300 до 1200 (среднее значение 570). График - плавный горб.
Число постоянных подключений сайта к базе не превышает 10 (.Net SqlClient) .
Корреляции замедления от числа посетителей не наблюдается.
Процессоров 4 : средняя загрузка по ним: 10%, 1%, 1%, 1%
Есть пики : 50%,7%,7%,7%, но они не продолжительные.
Про очереди к дискам пока ничего не могу сказать...
18 июн 09, 18:56    [7317515]     Ответить | Цитировать Сообщить модератору
 Re: Поиск причин снижения производительности  [new]
1klassNick
Member

Откуда:
Сообщений: 24
Выполнил:

WITH ByWaitTypes([Тип ожидания], [ожидания сигнала %], [ожидания ресурса %], [ожидания ms]) AS
(
SELECT TOP 20 wait_type
   , cast(100.0 * sum(signal_wait_time_ms)/sum(wait_time_ms) AS NUMERIC (20,2))
   , cast(100.0 * sum(wait_time_ms - signal_wait_time_ms)/sum(wait_time_ms) AS NUMERIC(20,2))
   , sum(wait_time_ms)
FROM sys.dm_os_wait_stats
WHERE wait_time_ms <> 0
GROUP BY wait_type
ORDER BY sum(wait_time_ms) DESC
)
SELECT TOP 1 [Тип ожидания] = N'BCE!'
   , [ожидания сигнала %] = (SELECT cast(100.0 * sum(signal_wait_time_ms)/
    sum (wait_time_ms) AS NUMERIC (20,2)) FROM sys.dm_os_wait_stats)
   , [ожидания ресурса %] =(SELECT cast(100.0 * sum(wait_time_ms - signal_wait_time_ms)/
    sum(wait_time_ms) AS NUMERIC(20,2)) FROM sys.dm_os_wait_stats)
   , [ожидания ms] =(SELECT sum(wait_time_ms) FROM sys.dm_os_wait_stats)
FROM sys.dm_os_wait_stats
UNION
SELECT [Тип ожидания], [ожидания сигнала %], [ожидания ресурса %], [ожидания ms]
FROM ByWaitTypes
ORDER BY [ожидания ms] DESC

Результат:

[Тип ожидания] [ожидания сигнала %] [ожидания ресурса %] [ожидания ms]
BCE! 0.13 99.87 19413365701
LAZYWRITER_SLEEP 0.01 99.99 6227846031
SQLTRACE_BUFFER_FLUSH 0.00 100.00 6227180125
OLEDB 0.00 100.00 6169222328
SLEEP_TASK 0.65 99.35 538197218
CXPACKET 7.09 92.91 165990468
ASYNC_NETWORK_IO 0.34 99.66 23205843
SOS_SCHEDULER_YIELD 94.12 5.88 8819953
LCK_M_IS 0.06 99.94 8420765
MSSEARCH 0.00 100.00 7732406
ASYNC_IO_COMPLETION 0.00 100.00 6851875
BACKUPBUFFER 0.19 99.81 6766156
WRITELOG 7.90 92.10 3994625
LATCH_EX 14.17 85.83 2917812
MSQL_DQ 0.00 100.00 2289390
BACKUPIO 0.16 99.84 1883843
SLEEP_BPOOL_FLUSH 2.59 97.41 1578640
PAGEIOLATCH_SH 0.82 99.18 1454656
BACKUPTHREAD 0.00 100.00 1445312
WAITFOR 0.00 100.00 1211234
SQLTRACE_LOCK 0.06 99.94 1183125
18 июн 09, 20:19    [7317749]     Ответить | Цитировать Сообщить модератору
 Re: Поиск причин снижения производительности  [new]
flexgen
Member

Откуда: Город на песке
Сообщений: 765
1klassNick
Есть набор процедур, каждая вызывается в течении суток порядка 2000 раз.


автор

DB FName Read(MB) Write(MB)
tempdb tempdev 2728168 2785388
tempdb templog 81 1801634


Могу предположить что в процедурах постоянно создаются и удаляются временные таблицы. Так же возможно что эти таблицы являются источником данных для курсоров. Так же возможно что эти процедуры выполняют DML-операторы в цикле курсора. 2000 вызовов за 24 часа - приблизительно каждые 43 секунды вызывается процедура, а она не одна, их целый набор. А каково приблизительное время выполнения одной процедуры? А всего набора? Наличие дедлоков проверял? Я это говорю к тому что сам столкнулся с такой же примерно проблемой. Основная причина - выполнение DML-операторов в курсоре в локальной базе и удаленной базе с применением OPENDATASOURCE. На обработку одной записи уходит минута. Весь процесс придется переписывать заново.
19 июн 09, 02:11    [7318458]     Ответить | Цитировать Сообщить модератору
 Re: Поиск причин снижения производительности  [new]
Glamorama
Member

Откуда:
Сообщений: 152
а нет ли у Вас зависимости между тормозами и чем-нибудь из этого списка:
- бекапы лога или всей базы;
- выполнение каких-нибудь джобов;
- рост файлов базы?

Есть ли статистика по изменению показателей CPU,Reads,Writes для тормозящих запросов?
19 июн 09, 12:01    [7319827]     Ответить | Цитировать Сообщить модератору
 Re: Поиск причин снижения производительности  [new]
1klassNick
Member

Откуда:
Сообщений: 24
flexgen
1klassNick
Есть набор процедур, каждая вызывается в течении суток порядка 2000 раз.


автор

DB FName Read(MB) Write(MB)
tempdb tempdev 2728168 2785388
tempdb templog 81 1801634


Могу предположить что в процедурах постоянно создаются и удаляются временные таблицы...

А каково приблизительное время выполнения одной процедуры?.


Да, точно, временные таблицы создаются. Курсоров нет. DML операторы отсутствуют. Дедлоки мониторяться и пока не случались.
Набор процедур не связан между собой. Под набором я имел в виду семейство похожих процедур для выборки данных для страниц сайта.
Разные страницы - разные процедуры.
И в этих процедурах используются только селекты, подселекты и временные таблицы, также для малых объемов (до 100 строк) используются таблицы-переменные.
Из функций используются стандартные агрегаты.
Время выполнения одной процедуры порядка 150 ms.
В "плохие" моменты увеличиваетя до 2-3 секунд.
Раз в неделю в случайное время вообще до 25 секунд на промежутке времени в 2-3 минуты.

зы:
Теперь под подозрением задача профилирования.
19 июн 09, 12:10    [7319876]     Ответить | Цитировать Сообщить модератору
 Re: Поиск причин снижения производительности  [new]
1klassNick
Member

Откуда:
Сообщений: 24
Glamorama
а нет ли у Вас зависимости между тормозами и чем-нибудь из этого списка:
- бекапы лога или всей базы;
- выполнение каких-нибудь джобов;
- рост файлов базы?

Есть ли статистика по изменению показателей CPU,Reads,Writes для тормозящих запросов?


Время выполнения бэкапов, джобов известно, в это время тормоза с запросами не рассматриваются.
Рост файлов базы не допускается - файлы на диске выделены с запасом свободного пространства. Чистка данных - 1 раз в год.
Прирост данных 100M в месяц, на диске место есть.

Спасибо за подсказку насчет показателей.

Вот результат статистики...

ХП1:
CPU Reads Writes Duration StartTime EndTime
594 22355 0 595703 2009-06-16 19:34:36.500 2009-06-16 19:34:37.093
578 22325 0 582031 2009-06-16 14:47:56.303 2009-06-16 14:47:56.887
------
63 10934 0 208984 2009-06-18 19:20:18.563 2009-06-18 19:20:18.770
78 10988 0 208984 2009-06-18 17:53:31.703 2009-06-18 17:53:31.913


ХП2:
CPU Reads Writes Duration StartTime EndTime
2000 59378 0 2054687 2009-06-16 21:30:29.240 2009-06-16 21:30:31.290
2078 59449 0 2050781 2009-06-16 02:18:14.650 2009-06-16 02:18:16.703
1984 76741 0 1993164 2009-06-16 10:35:33.747 2009-06-16 10:35:35.750
1954 59351 0 1985351 2009-06-16 18:16:43.750 2009-06-16 18:16:45.740
------
656 28093 0 686523 2009-06-18 02:24:01.393 2009-06-18 02:24:02.080
672 28125 0 682617 2009-06-18 19:34:48.900 2009-06-18 19:34:49.580
625 28107 0 680664 2009-06-18 13:39:46.407 2009-06-18 13:39:47.093


ХП3:
CPU Reads Writes Duration StartTime EndTime
1984 59769 0 1977539 2009-06-16 23:01:20.633 2009-06-16 23:01:22.610
1969 59375 0 1954101 2009-06-16 18:48:55.953 2009-06-16 18:48:57.913
------
656 28119 0 687500 2009-06-17 18:40:48.340 2009-06-17 18:40:49.023
656 28117 0 685546 2009-06-18 21:54:11.877 2009-06-18 21:54:12.563


ХП4:
CPU Reads Writes Duration StartTime EndTime
1765 57553 0 1776367 2009-06-17 01:37:43.483 2009-06-17 01:37:45.250
1766 57919 0 1762695 2009-06-17 01:41:09.990 2009-06-17 01:41:11.750
------
579 30448 0 616210 2009-06-17 18:24:26.733 2009-06-17 18:24:27.350
594 30468 0 615234 2009-06-18 11:01:02.457 2009-06-18 11:01:03.070


ХП5:
CPU Reads Writes Duration StartTime EndTime
1875 54959 0 1873046 2009-06-16 21:30:55.313 2009-06-16 21:30:57.177
------
657 27677 0 698242 2009-06-18 17:03:35.107 2009-06-18 17:03:35.817
625 30423 0 678711 2009-06-17 22:25:34.420 2009-06-17 22:25:35.097


ХП6:
CPU Reads Writes Duration StartTime EndTime
797 23888 0 776367 2009-06-17 00:39:56.190 2009-06-17 00:39:56.967
734 24045 2 769531 2009-06-16 13:14:39.207 2009-06-16 13:14:39.977
------
63 9004 0 211914 2009-06-17 19:49:31.600 2009-06-17 19:49:31.810
47 8948 0 211914 2009-06-19 00:37:05.560 2009-06-19 00:37:05.773


ХП7:
CPU Reads Writes Duration StartTime EndTime
719 23789 0 724609 2009-06-17 00:46:49.070 2009-06-17 00:46:49.793
------
47 9008 0 216796 2009-06-19 01:26:29.110 2009-06-19 01:26:29.327
63 8819 0 215820 2009-06-17 19:53:07.403 2009-06-17 19:53:07.620
63 8901 0 215820 2009-06-18 07:53:10.393 2009-06-18 07:53:10.610


ХП8:
CPU Reads Writes Duration StartTime EndTime
1688 50011 0 1698242 2009-06-16 03:36:12.520 2009-06-16 03:36:14.227
------
78 14805 0 273437 2009-06-18 12:59:59.967 2009-06-18 13:00:00.233


ХП9:
CPU Reads Writes Duration StartTime EndTime
1000 33347 0 1001953 2009-06-17 11:03:31.180 2009-06-17 11:03:32.193
------
63 9927 0 206054 2009-06-17 12:59:33.287 2009-06-17 12:59:33.493


ХП10:
CPU Reads Writes Duration StartTime EndTime
625 27926 0 616210 2009-06-16 14:40:11.923 2009-06-16 14:40:12.540
610 25962 0 612304 2009-06-16 14:23:01.133 2009-06-16 14:23:01.747
------
297 11302 0 305664 2009-06-17 10:48:23.593 2009-06-17 10:48:23.897
313 11069 0 301757 2009-06-17 09:24:20.873 2009-06-17 09:24:21.177


ХП11:
CPU Reads Writes Duration StartTime EndTime
313 11385 0 571289 2009-06-16 10:09:59.760 2009-06-16 10:10:00.333
312 11038 0 303710 2009-06-17 09:11:48.447 2009-06-17 09:11:48.750
297 11072 0 302734 2009-06-17 08:37:16.937 2009-06-17 08:37:17.233
19 июн 09, 14:16    [7320765]     Ответить | Цитировать Сообщить модератору
 Re: Поиск причин снижения производительности  [new]
Glamorama
Member

Откуда:
Сообщений: 152
1. попробуйте все-таки помониторить планы тормозящих процедур. Конечно не похоже, но вдруг?
2. проанализируйте параметры вызова. Может быть тормоза являются следствием объективных причин (выбирается в разы больше данных или распределение значений в индексируемых столбцах слишком неравномерно)?
19 июн 09, 22:55    [7323370]     Ответить | Цитировать Сообщить модератору
 Re: Поиск причин снижения производительности  [new]
Crimean
Member

Откуда:
Сообщений: 13148
не проверено оборудование
не найдена причина
лечим / смотрим без диагноза, без версий
стремно

раз трас пишется - начать с его анализа и с сопоставлением результатов анализа с данными мониторинга оборудования. а то может у вас бакап по сети копируется и из-за проседания сетки все тормозить начинает. или еще какой курьез
22 июн 09, 11:03    [7326756]     Ответить | Цитировать Сообщить модератору
Все форумы / Microsoft SQL Server Ответить