Каталог решений - Пример поиска неоптимальности при загрузке SQL-сервера по CPU на 100%

 select 
      sql = cast(SUBSTRING( ST.text, (er.statement_start_offset/2) + 1,((CASE er.statement_end_offset WHEN -1 THEN DATALENGTH(ST.text) ELSE er.statement_end_offset END -   er.statement_start_offset)/2) + 1)as varchar(max)), 
      er.session_id, CPU     = cast( er.cpu_time as bigint), lReads  = er.logical_reads, lWrites = er.writes, fReads  = er.reads, Duration = cast( er.total_elapsed_time as bigint), er.start_time
  from     
      sys.dm_exec_requests AS er with(nolock)
      outer APPLY sys.dm_exec_sql_text(er.sql_handle) as ST
  where er.session_id > 50
  order by CPU desc

  exec sp_WhoIsActive @sort_order = '[CPU] DESC'

Большая часть запросов вида  INSERT INTO #tt5 (_Q_000_F_000,_Q_000_F_001RRef) VALUES(@P1,@P2)

Захожу в "консоль серверов 1С", в соединения соответствующей БД — оказыватся, полку "шелезяк" прибыло, появился новый вид фоновых  "ФормированиеЗаказа":

Эти новые фоновые CPU на sql-сервере скушали, и памяти на серверах кластера 1С нахватали от души.
Ищу документацию по "ФормированиеЗаказа", иду к соответствующему ведущему программисту.
Он и говорит : "да, вот две недели назад с понедельника потихонечку и запустили.. заказ в точку теперь с серверной стороны идет — расчет всякой красивой статистики, сезонность, мощный математический аппарат, все дела.. При тестировании все было отлично!".

Ладно, копаю дальше..
Коль работает две недели — глянем лидеров по CPU за две недели на сервере  (этим инструментом)

 
На первые места вылезли странные вставки во времянки
INSERT INTO #ttNN (VAL) VALUES(@P1)
и, ага, то самое
INSERT INTO #ttNN (VAL,VAL) VALUES(@P1,@P2)
Количество зафиксированных в sys.dm_exec_query_stats экземпляров запросов обоих видов — изрядно более обычного. В расшифровке видно, что и количество исполнений одного экземпляра — огромное. Миллионы вставок.

Постфактум посмотрел более короткий период — полчаса максимальной загрузки сервера по CPU, с 16:10 по 16:40 — тут еще более наглядно:

Попробую поймать контексты исполнения данного запроса
Несколько (15 штук) уже попались, это  

 ----------- вес контекста 15.00 ---------  
  ОбщийМодуль.Фоновые.Модуль : 2658 : Результат = Документы.ПулЗаказов.СозданиеЗаказовРозн(Параметры);
      Документ.ПулЗаказов.МодульМенеджера : 939 : Док.ЗаполнитьЗаказДанными();
          Документ.ЗаказТочки.МодульОбъекта : 3898 : Запрос = ПолучитьПолныйЗапрос(Открытие,ДляОтчета,Пересчет,СтруктураПараметров);
              Документ.ЗаказТочки.МодульОбъекта : 3437 : ТаблНастр =   Справочники.НастройкиЗаказаТочки.Определить...
                  Справочник.НастройкиЗаказаТочки.МодульМенеджера : 471 : ПолучитьСервисныеВременныеТаблицы(...);
                      Справочник.НастройкиЗаказаТочки.МодульМенеджера : 309 : Запрос.Выполнить();

для   INSERT INTO #ttXX (VAL) VALUES(@P1)
На фоне сотен запусков этого как-то маловато, да и контекст для  INSERT INTO #ttXX (VAL,VAL) VALUES(@P1,@P2) не определен.

Настраиваю техжурнал на серверах кластера, дополняя его вот такой конструкцией:
    <log history="1" location="Z:\Server1C\logsInsTMP">
      <event>
       <eq property="name" value="dbmssql"/>
       <like property="Sql" value="%INSERT INTO #tt%(%)%VALUES(%"/>
      </event>
      <property name="all"/>
    </log>
Жду.
Директории Z:\Server1C\logsInsTMP за 20 минут вырастают до 2 и 1,5Gb (два сервера к кластере).
Убираю настройку, смотрю содержимое части logsInsTMP (по UID rphost-ов отобрал пяток объемистых директорий) — группировка по контексту с выводом количества событий.

Картинка вот такая: 

7 729                     
INSERT INTO #ttNN (VAL,VAL) VALUES(?,?)
ОбщийМодуль.Фоновые.Модуль : 2658 : Результат = Документы.ПулЗаказов.СозданиеЗаказовРозн(Параметры);
    Документ.ПулЗаказов.МодульМенеджера : 939 : Док.ЗаполнитьЗаказДанными();
        Документ.ЗаказТочки.МодульОбъекта : 3898 : Запрос = ПолучитьПолныйЗапрос(Открытие,ДляОтчета,Пересчет,СтруктураПараметров);
            Документ.ЗаказТочки.МодульОбъекта : 3437 : ТаблНастр = Справочники.НастройкиЗаказаТочки.Определить...
                Справочник.НастройкиЗаказаТочки.МодульМенеджера : 470 : ПроверкаОграниченияТовары = Рез...
                    Справочник.НастройкиЗаказаТочки.МодульМенеджера : 269 : Возврат ПолучитьРезультатЗапрета(...);
                        Справочник.НастройкиЗаказаТочки.МодульМенеджера : 244 : Возврат Запрос.Выполнить().Выгрузить();
7 479
INSERT INTO #ttNN (VAL,VAL,VAL) VALUES(?,?,?)
ОбщийМодуль.Фоновые.Модуль : 2658 : Результат = Документы.ПулЗаказов.СозданиеЗаказовРозн(Параметры);
    Документ.ПулЗаказов.МодульМенеджера : 939 : Док.ЗаполнитьЗаказДанными();
        Документ.ЗаказТочки.МодульОбъекта : 3817 : Результат = Запрос.Выполнить();                                                                                              
4 839
INSERT INTO #ttNN (VAL,VAL) VALUES(?,?)
ОбщийМодуль.Фоновые.Модуль : 2658 : Результат = Документы.ПулЗаказов.СозданиеЗаказовРозн(Параметры);
    Документ.ПулЗаказов.МодульМенеджера : 939 : Док.ЗаполнитьЗаказДанными();
        Документ.ЗаказТочки.МодульОбъекта : 3898 : Запрос = ПолучитьПолныйЗапрос(Открытие,ДляОтчета,Пересчет,СтруктураПараметров);
            Документ.ЗаказТочки.МодульОбъекта : 3634 : ТаблЗап = Справочники.РазрешенияНаЗаказТовараВТочках.Определить...
                Справочник.РазрешенияНаЗаказТовараВТочках.МодульМенеджера : 315 : ПроверкаОграничения = ПолучитьРезультатЗапрета(...);
                    Справочник.РазрешенияНаЗаказТовараВТочках.МодульМенеджера : 239 : Возврат Запрос.Выполнить().Выгрузить();
566
INSERT INTO #ttNN (VAL) VALUES(?)
ОбщийМодуль.Фоновые.Модуль : 2658 : Результат = Документы.ПулЗаказов.СозданиеЗаказовРозн(Параметры);
    Документ.ПулЗаказов.МодульМенеджера : 1037 : Док.ЗаполнитьНачальныеНастройки_Модуль(Доформирование);
        Документ.ЗаказТочки.МодульОбъекта : 4482 : ТЗ = Справочники.НастройкиЗаказаТочки.ЗаполнитьНачальныеНастройкиЗак(...);
            Справочник.НастройкиЗаказаТочки.МодульМенеджера : 717 : ПроверкаОграничения = ПолучитьРезультатЗапрета(...);
                Справочник.НастройкиЗаказаТочки.МодульМенеджера : 244 : Возврат Запрос.Выполнить().Выгрузить();