Самый эффективный способ установить отношения в таблице записей журнала?

Question

Я уже задал похожий вопрос, и Ян Питерс и Ник Шеной предоставили отличные решения , но я забыл упомянуть, что производительность - очень интересный аспект.Поэтому я решил задать новый вопрос, предоставив некоторые дополнительные сведения.

Я поддерживаю приложение, которое позволяет визуально анализировать файлы журналов определенного вида.Обработка записей журнала в основном определяется хранимыми процедурами в базе данных SQL Server.Один из этапов этой обработки состоит в том, чтобы связать записи журнала с соответствующими рабочими и рабочими шагами и узнать, когда этот рабочий экземпляр был выполнен в последний раз.

Вот пример таблицы, содержащей записи журнала:

Id , Time, LogCategory      , LogMessage
1  , 100 , WORKER_START     , Started worker
2  , 110 , WORKER_STEP_START, Entered Step 1
3  , 120 , SOMETHING_ELSE   , Do cool stuff
4  , 130 , WORKER_STEP_END  , Exited Step 1
5  , 140 , SOMETHING_ELSE   , Some event here
6  , 150 , WORKER_START     , Started worker
7  , 160 , SOMETHING_ELSE   , Do more cool stuff
8  , 170 , WORKER_STEP_START, Entered Step 1
9  , 180 , SOMETHING_ELSE   , Do cool stuff
10 , 190 , WORKER_STEP_END  , Exited Step 1
11 , 200 , SOMETHING_ELSE   , Bad event, exit worker
12 , 210 , WORKER_END       , Exited worker
13 , 220 , WORKER_STEP_START, Entered Step 2
14 , 230 , SOMETHING_ELSE   , Do further cool stuff
15 , 240 , WORKER_STEP_END  , Exited Step 2
16 , 250 , WORKER_END       , Exited worker

Я хочу

• добавить идентификатор записи работника, эта запись соответствует
• добавить идентификатор записи шага работника, эта запись соответствует
• обновить запись WORKER_START и установить максимальную метку времени записей, принадлежащих этому работнику.

Это приведет к:

Id , Time, LogCategory      , LogMessage             , Worker, Step  , LastUpdate
1  , 100 , WORKER_START     , Started worker         , 1     , null  , 250
2  , 110 , WORKER_STEP_START, Entered Step 1         , 1     , 2     , null
3  , 120 , SOMETHING_ELSE   , Do cool stuff          , 1     , 2     , null
4  , 130 , WORKER_STEP_END  , Exited Step 1          , 1     , 2     , null
5  , 140 , SOMETHING_ELSE   , Some event here        , 1     , null  , null
6  , 150 , WORKER_START     , Started worker         , 6     , null  , 210
7  , 160 , SOMETHING_ELSE   , Do more cool stuff     , 6     , null  , null
8  , 170 , WORKER_STEP_START, Entered Step 1         , 6     , 8     , null
9  , 180 , SOMETHING_ELSE   , Do cool stuff          , 6     , 8     , null
10 , 190 , WORKER_STEP_END  , Exited Step 1          , 6     , 8     , null
11 , 200 , SOMETHING_ELSE   , Bad event, exit worker , 6     , null  , null
12 , 210 , WORKER_END       , Exited worker          , 6     , null  , null
13 , 220 , WORKER_STEP_START, Entered Step 2         , 1     , 13    , null
14 , 230 , SOMETHING_ELSE   , Do further cool stuff  , 1     , 13    , null
15 , 240 , WORKER_STEP_END  , Exited Step 2          , 1     , 13    , null
16 , 250 , WORKER_END       , Exited worker          , 1     , null  , null

В настоящее время я делаю этовыполняя эту хранимую процедуру:

CREATE PROCEDURE CalculateRelations
AS
BEGIN
    DECLARE entries_cur CURSOR FOR
      SELECT Id, LogCategory
      FROM LogEntries
      ORDER BY Id;

    DECLARE @Id BIGINT;
    DECLARE @LogCategory VARCHAR(128);
    DECLARE @Worker BIGINT;
    DECLARE @WorkerStack VARCHAR(MAX) = '';
    DECLARE @Step BIGINT;
    DECLARE @StepStack VARCHAR(MAX) = '';

    OPEN entries_cur;
    FETCH NEXT FROM entries_cur INTO @Id, @LogCategory;

    WHILE @@FETCH_STATUS = 0
    BEGIN
        EXEC dbo.GetParentWorker @WorkerStack OUT, @Id, @LogCategory, @Worker OUT;
        EXEC dbo.GetParentStep @StepStack OUT, @Id, @LogCategory, @Step OUT;

        UPDATE LogEntries
        SET
          Worker = @Worker,
          Step = @Step
        WHERE Id = @Id;

        UPDATE LogEntries
           SET LastUpdate = @Time
           WHERE Id = @Worker;

        FETCH NEXT FROM entries_cur INTO @Id, @LogCategory;
    END;

    CLOSE entries_cur;
    DEALLOCATE entries_cur;
END;

GetParentWorker и GetParentStep являются хранимыми процедурами, использующими заданные VARCHAR переменные WorkerStack и StepStack в качестве стека.Это означает, что запись

• "WORKER_START" / "WORKER_STEP_START" приводит к добавлению (push) идентификатора к этой записи VARCHAR
• "WORKER_END" / "WORKER_STEP_END", что приводит к удалению и возврату (pop) последний идентификатор из этого VARCHAR
• , все остальные записи приводят к тому, что он просто возвращает (читает) последний идентификатор из этого VARCHAR без его изменения.

Эта процедура выполняется для записей ~ 850kчерез 24 минуты и 33 секунды.Я также попытался немного изменить эту хранимую процедуру.Там я переключился с обычного курсора на курсор обновления и ввел временную таблицу для вычисления LastUpdate работника:

CREATE PROCEDURE CalculateRelations
AS
BEGIN
    DECLARE entries_cur CURSOR FOR
      SELECT Id, LogCategory
      FROM LogEntries
      ORDER BY Id
      FOR UPDATE OF Worker, Step;

    DECLARE @Id BIGINT;
    DECLARE @LogCategory VARCHAR(128);
    DECLARE @Worker BIGINT;
    DECLARE @WorkerStack VARCHAR(MAX) = '';
    DECLARE @Step BIGINT;
    DECLARE @StepStack VARCHAR(MAX) = '';

    TRUNCATE TABLE LogEntries_LastUpdate;

    OPEN entries_cur;
    FETCH NEXT FROM entries_cur INTO @Id, @LogCategory;

    WHILE @@FETCH_STATUS = 0
    BEGIN
        EXEC dbo.GetParentWorker @WorkerStack OUT, @Id, @LogCategory, @Worker OUT;
        EXEC dbo.GetParentStep @StepStack OUT, @Id, @LogCategory, @Step OUT;

        UPDATE LogEntries
        SET
          Worker = @Worker,
          Step = @Step
        WHERE CURRENT OF entries_cur;

        INSERT INTO LogEntries_LastUpdate(Id, Time)
        VALUES (@Worker, @Time);

        FETCH NEXT FROM entries_cur INTO @Id, @LogCategory;
    END;

    CLOSE entries_cur;
    DEALLOCATE entries_cur;

    UPDATE le
    SET le.LastUpdate = CAST(0.5 * (CAST(le.LastUpdate AS numeric(12,1)) + CAST(lelu.Time AS numeric(12,1)) + ABS(le.LastUpdate - lelu.Time)) AS int)
    FROM LogEntries le
      JOIN (
        SELECT Id=ilelu.Id, Time=MAX(ilelu.Time)
        FROM LogEntries_LastUpdate ilelu
        GROUP BY ilelu.Id) lelu
      ON lelu.Id = le.Id;
END;

Эта модификация занимает больше времени, чем первая использованная мной версия, что было довольно удивительно,Поэтому я подумал, что нужно найти решение без курсора, и Ян Питерс и Ник Шеной придумали что-то вроде этого:

WITH LogWithWorkerLevel AS (
  SELECT LogEntries.*
    , SUM(CASE LogCategory WHEN 'WORKER_START' THEN 1 
                           WHEN 'WORKER_END' THEN -1
                           ELSE 0 END)
        OVER (ORDER BY Id ROWS BETWEEN UNBOUNDED PRECEDING AND CURRENT ROW)
      + CASE LogCategory WHEN 'WORKER_END' THEN 1 ELSE 0 END AS [WorkerLevel]
    , SUM(CASE LogCategory WHEN 'WORKER_STEP_START' THEN 1 
                           WHEN 'WORKER_STEP_END' THEN -1
                           ELSE 0 END)
      OVER (ORDER BY Id ROWS BETWEEN UNBOUNDED PRECEDING AND CURRENT ROW)
      + CASE LogCategory WHEN 'WORKER_STEP_END' THEN 1 ELSE 0 END AS [StepLevel]
  FROM LogEntries
)
UPDATE LogWithWorkerLevel
SET
  Worker = (
    SELECT TOP 1 Id 
    FROM LogWithWorkerLevel AS Lookup 
    WHERE 
      Lookup.Id <= LogWithWorkerLevel.Id 
      AND Lookup.WorkerLevel = LogWithWorkerLevel.WorkerLevel
      AND Lookup.LogCategory = 'WORKER_START'
    ORDER BY Id DESC)
  , Step = (
    SELECT TOP 1 Id 
    FROM LogWithWorkerLevel AS Lookup 
    WHERE 
      Lookup.Id <= LogWithWorkerLevel.Id 
      AND Lookup.StepLevel = LogWithWorkerLevel.StepLevel
      AND Lookup.LogCategory = 'WORKER_STEP_START'
    ORDER BY Id DESC);

Здесь нас не волнует LastUpdate, так как это всего лишь идеясейчас.В то время как оператор SELECT временной таблицы LogWithWorkerLevel работает очень быстро (9 секунд), оператор UPDATE занимает довольно много времени, дольше, чем курсор, с которого я начинал.

Извините за длинное объяснениеПриходите к этому короткому вопросу: видите ли вы способ повысить производительность этой обработки с помощью хранимой процедуры?

Заранее спасибо!

ОБНОВЛЕНИЕ Вот таблицаDDL:

CREATE TABLE LogEntries (
    Id int,
    Time int,
    LogCategory varchar (128),
    LogType varchar (128),
    Worker int NULL,
    Step int NULL,
    LastUpdate int NULL,
    CONSTRAINT PK_le_Id PRIMARY KEY(Id)
);
CREATE INDEX IDX_le_LogDomain ON LogEntries(LogDomain);
CREATE INDEX IDX_le_Worker ON LogEntries(Worker);
CREATE INDEX IDX_le_Step ON LogEntries(Step);

В соответствии с планом выполнения: для получения фактически выполненного плана выполнения требуется довольно много времени (4+ часа).Итак, я взгляну на примерный план выполнения (если он так называется на английском, моя SSMS говорит по-немецки):

• В общей сложности 55% затрат идет на создание курсора.Кажется, что это «динамический» курсор, а самые дорогие операции - «Вставка кластерного индекса» (29%) и «Поиск кластерного индекса» (25%)
  • Еще 23% идут на «Кластерный индекс»Обновить ", где я установил Worker и Step записи в журнале.
  • В общей сложности 17% идут на ОБНОВЛЕНИЕ LastUpdate.

Вот план выполнения:

ОБНОВЛЕНИЕ 2

Через четыре дня и восемь часовзапрос (включая создание точного плана выполнения) был успешно выполнен:

(Если вас интересует сам план выполнения,просто дайте мне знать.)

Итак, есть две основные причины такой длительности:

• Узлы фильтра в двух нижних ветвях получают 12-значное число строк.
• Некоторые узлы сортировки, кажется, вызывают переполнение данных в базе данных tempdb.

Я не уверен, что это можно исправить.

Я также изменил курсор для условного выполнения операторов UPDATE.Поэтому я вставил оператор IF.И это увеличило запрос с 24 минут до 3 минут.