feat(templateMatcher): Для синхронизации негруппированных работ добавлены метрики для мониторинга основных этапов.

2026-06-10 12:08:07 +10:00
parent 535e87ec21
commit a64ab59de1
3 changed files with 188 additions and 102 deletions
--- a/PARR.TemplateMatcher/PARR.TemplateMatcher.csproj
+++ b/PARR.TemplateMatcher/PARR.TemplateMatcher.csproj
@@ -1,21 +1,28 @@
 <Project Sdk="Microsoft.NET.Sdk">

-  <PropertyGroup>
-    <TargetFramework>net9.0</TargetFramework>
-    <ImplicitUsings>enable</ImplicitUsings>
-    <Nullable>enable</Nullable>
-  </PropertyGroup>
+	<PropertyGroup>
+		<TargetFramework>net9.0</TargetFramework>
+		<ImplicitUsings>enable</ImplicitUsings>
+		<Nullable>enable</Nullable>
+	</PropertyGroup>

-  <ItemGroup>
-    <ProjectReference Include="..\PARR.DAL\PARR.DAL.csproj" />
-    <ProjectReference Include="..\PARR.Domain\PARR.Domain.csproj" />
-    <ProjectReference Include="..\PARR.Infrastructure\PARR.Infrastructure.csproj" />
-  </ItemGroup>
+	<ItemGroup>
+		<ProjectReference Include="..\PARR.DAL\PARR.DAL.csproj" />
+		<ProjectReference Include="..\PARR.Domain\PARR.Domain.csproj" />
+		<ProjectReference Include="..\PARR.Infrastructure\PARR.Infrastructure.csproj" />
+	</ItemGroup>

-  <ItemGroup>
-    <Reference Include="PARR.Core">
-      <HintPath>..\PARR.Core\obj\Debug\net9.0\ref\PARR.Core.dll</HintPath>
-    </Reference>
-  </ItemGroup>
+	<ItemGroup>
+		<Reference Include="PARR.Core">
+			<HintPath>..\PARR.Core\obj\Debug\net9.0\ref\PARR.Core.dll</HintPath>
+		</Reference>
+	</ItemGroup>
+
+	<ItemGroup>
+		<!-- Разрешаем тестовой сборке видеть internal классы PARR.Core -->
+		<InternalsVisibleTo Include="PARR.Test" />
+		<!-- Разрешаем Castle DynamicProxy (Moq / NSubstitute) видеть internal классы PARR.Core -->
+		<InternalsVisibleTo Include="DynamicProxyGenAssembly2" />
+	</ItemGroup>

 </Project>
--- a/PARR.TemplateMatcher/Services/Implementations/SimpleTemplateSynchronizer.cs
+++ b/PARR.TemplateMatcher/Services/Implementations/SimpleTemplateSynchronizer.cs
@@ -18,6 +18,7 @@ using PARR.Domain.Settings;
 using PARR.TemplateMatcher.Models;
 using PARR.TemplateMatcher.Services.Interfaces;
 using PARR.TemplateMatcher.Settings;
+using System.Diagnostics;

 namespace PARR.TemplateMatcher.Services.Implementations;

@@ -99,8 +100,8 @@ internal class SimpleTemplateSynchronizer : ITemplateSynchronizer
            return;
        }

-        // === Обычная логика для всех остальных Job ===
-        logger.LogDebug("Начало синхронизации шаблонов для Job {JobId}", jobId);
+        var totalSw = Stopwatch.StartNew();
+        logger.LogInformation("Начало синхронизации шаблонов для Job {JobId}", jobId);

        // === Проверка: уже запущена? ===
        var existingStatus = await matchingStatusService.GetStatusAsync(jobId, SyncTaskEntityTypeEnum.Job);
@@ -126,6 +127,8 @@ internal class SimpleTemplateSynchronizer : ITemplateSynchronizer

        try
        {
+            // === ЭТАП 1: Загрузка Job ===
+            var stageSw = Stopwatch.StartNew();
            var job = await jobService.Get()
                .AsNoTracking()
                .Include(j => j.AutoControl)
@@ -142,48 +145,22 @@ internal class SimpleTemplateSynchronizer : ITemplateSynchronizer
                await UpdateMatchingStatusAsync(jobId, "Job не найден");
                return;
            }
+            stageSw.Stop();
+            logger.LogDebug("[Perf] Job {JobId} | Этап: Загрузка Job | Время: {Ms} мс",
+                jobId, stageSw.ElapsedMilliseconds);

-            // === Получение отфильтрованных юнитов с полной информацией ===
+            // === ЭТАП 2: Фильтрация юнитов ===
+            stageSw.Restart();
            var filteredUnits = await unitFilterService.GetUnitsByJobFilterAsync(jobId);
-            if (filteredUnits == null || !filteredUnits.Any())
-            {
-                logger.LogInformation("Для Job {JobId} фильтры не дали Unit'ов.", jobId);
+            stageSw.Stop();
+            var filterCount = filteredUnits?.Count() ?? 0;
+            logger.LogDebug("[Perf] Job {JobId} | Этап: Фильтрация юнитов | Время: {Ms} мс | Результат: {Count}",
+                jobId, stageSw.ElapsedMilliseconds, filterCount);

-                var existingTemplatesForDeactivation = await templateService.Get()
-                    .AsNoTracking()
-                    .Include(t => t.UnitsInTemplate)
-                    .Where(t => t.JobId == jobId && t.StatusTypeId == TemplateStatusTypeEnum.Used)
-                    .ToListAsync();
-
-                await UpdateMatchingStatusAsync(jobId, $"Нет Unit'ов. Деактивация {existingTemplatesForDeactivation.Count} шаблонов...");
-
-                foreach (var unusedTemplate in existingTemplatesForDeactivation)
-                {
-                    logger.LogInformation("Деактивация лишнего шаблона {TemplateId} (Job {JobId}, UnitId {UnitId}).", unusedTemplate.Id, jobId, unusedTemplate.UnitId);
-                    await templateDeactivator.DeactivateTemplateAsync(unusedTemplate, initiator);
-                }
-
-                await UpdateMatchingStatusAsync(jobId, "Синхронизация завершена: нет Unit'ов");
-                await matchingStatusService.DeleteMatchingStatusAsync(jobId, SyncTaskEntityTypeEnum.Job);
-                logger.LogInformation("Синхронизация шаблонов завершена для Job {JobId}.", jobId);
-                return;
-            }
-
-            // Извлекаем ID юнитов для последующих операций
-            var unitIds = filteredUnits.Select(u => u.Id).ToList();
-
-#if DEBUG
-            // Отладка: проверить, есть ли юнит в unitIds
-            if (unitIds.Contains(targetUnitId))
-            {
-                logger.LogDebug("Юнит {TargetUnitId} найден в unitIds.", targetUnitId);
-            }
-            else
-            {
-                logger.LogDebug("Юнит {TargetUnitId} НЕ найден в unitIds.", targetUnitId);
-            }
-#endif
+            var unitIds = filteredUnits?.Select(u => u.Id).ToHashSet() ?? new HashSet<Guid>();

+            // === ЭТАП 3: Загрузка существующих шаблонов ===
+            stageSw.Restart();
            var existingTemplates = await templateService.Get()
                .Include(t => t.UnitsInTemplate)
                .Include(t => t.Job)
@@ -199,25 +176,48 @@ internal class SimpleTemplateSynchronizer : ITemplateSynchronizer
                .Where(t => t.StatusTypeId == TemplateStatusTypeEnum.Used)
                .ToList();

-            var existingUnitIds = existingUsedTemplates
-                .Select(t => t.UnitId)
-                .ToHashSet();
+            var existingUnitIds = existingUsedTemplates.Select(t => t.UnitId).ToHashSet();
+            stageSw.Stop();
+            logger.LogDebug("[Perf] Job {JobId} | Этап: Загрузка шаблонов | Время: {Ms} мс | Используется: {Count}",
+                jobId, stageSw.ElapsedMilliseconds, existingUsedTemplates.Count);
+
+            // === ЭТАП 4: Расчёт диффа (создание / деактивация / переименование) ===
+            stageSw.Restart();

            var newUnitIds = unitIds.Except(existingUnitIds).ToList();
            var unusedTemplates = existingUsedTemplates
                .Where(t => !unitIds.Contains(t.UnitId))
                .ToList();

+            // Проверка имён существующих шаблонов
+            var templatesToRename = new List<(Template Template, string ExpectedName)>();
+            foreach (var template in existingUsedTemplates)
+            {
+                if (!unitIds.Contains(template.UnitId))
+                    continue;
+
+                var expectedName = await templateNameNormalizer.GetNormalizedTemplateNameAsync(template);
+                if (!string.Equals(template.Name, expectedName, StringComparison.OrdinalIgnoreCase))
+                {
+                    templatesToRename.Add((template, expectedName));
+                }
+            }
+
+            stageSw.Stop();
+            logger.LogDebug("[Perf] Job {JobId} | Этап: Расчёт диффа | Время: {Ms} мс | Создать: {Create}, Деактивировать: {Deactivate}, Переименовать: {Rename}",
+                jobId, stageSw.ElapsedMilliseconds, newUnitIds.Count, unusedTemplates.Count, templatesToRename.Count);
+
+            // === ЭТАП 5: Создание новых шаблонов ===
+            stageSw.Restart();
            foreach (var unitId in newUnitIds)
            {
-                // Вычисляем флаги активности из конфигурации автоконтрола
                var isActiveTemplate = job.AutoControl?.InitUsedTemplateState ?? DefaultUsedTemplateState;
                var isActiveSchedule = job.AutoControl?.InitUsedScheduleState ?? DefaultUsedScheduleState;

                var request = new TemplateAllocationRequest(
                    TargetJob: job,
                    TargetUnitId: unitId,
-                    TargetUnit: null, // Для простого шаблона не критично, нормализатор загрузит при необходимости
+                    TargetUnit: null,
                    Index: null,
                    UnitsInTemplate: new List<UnitInTemplateMessage>(),
                    IsActiveTemplate: isActiveTemplate,
@@ -226,58 +226,68 @@ internal class SimpleTemplateSynchronizer : ITemplateSynchronizer

                await templateAllocationService.AllocateAsync(request);
            }
+            stageSw.Stop();
+            logger.LogDebug("[Perf] Job {JobId} | Этап: Создание шаблонов | Время: {Ms} мс | Количество: {Count}",
+                jobId, stageSw.ElapsedMilliseconds, newUnitIds.Count);

-            // === Обработка существующих шаблонов (проверка имени) ===
-            foreach (var template in existingUsedTemplates)
+            // === ЭТАП 6: Обновление имён существующих шаблонов ===
+            stageSw.Restart();
+            foreach (var (template, expectedName) in templatesToRename)
            {
-                if (unitIds.Contains(template.UnitId))
+                logger.LogDebug("Шаблон {TemplateId} требует обновления имени: '{OldName}' → '{NewName}'",
+                    template.Id, template.Name, expectedName);
+
+                var updateRequest = new TemplateUpdaterMessage
                {
-                    var expectedName = await templateNameNormalizer.GetNormalizedTemplateNameAsync(template);
-                    if (!string.Equals(template.Name, expectedName, StringComparison.OrdinalIgnoreCase))
-                    {
-                        logger.LogDebug("Шаблон {TemplateId} требует обновления имени: старое = '{OldName}', новое = '{NewName}'", template.Id, template.Name, expectedName);
+                    TemplateId = template.Id,
+                    JobId = jobId,
+                    UnitId = template.UnitId,
+                    Name = expectedName,
+                    IsActiveTemplate = template.IsActiveTemplate,
+                    IsActiveSchedule = template.IsActiveSchedule,
+                    IsNew = false,
+                    Index = template.Index,
+                    StatusTypeId = TemplateStatusTypeEnum.Used,
+                    Initiator = initiator,
+                    UnitsInTemplate = new List<UnitInTemplateMessage>()
+                };

-
-                        var updateRequest = new TemplateUpdaterMessage
-                        {
-                            TemplateId = template.Id,
-                            JobId = jobId,
-                            UnitId = template.UnitId,
-                            Name = expectedName,
-                            IsActiveTemplate = template.IsActiveTemplate,
-                            IsActiveSchedule = template.IsActiveSchedule,
-                            IsNew = false,
-                            Index = template.Index,
-                            StatusTypeId = TemplateStatusTypeEnum.Used,
-                            Initiator = initiator,
-                            UnitsInTemplate = new List<UnitInTemplateMessage>() // для простого шаблона
-                        };
-
-                        await templateMqPublisher.PublishUpdateAsync(updateRequest);
-                    }
-                }
+                await templateMqPublisher.PublishUpdateAsync(updateRequest);
            }
+            stageSw.Stop();
+            logger.LogDebug("[Perf] Job {JobId} | Этап: Обновление имён | Время: {Ms} мс | Количество: {Count}",
+                jobId, stageSw.ElapsedMilliseconds, templatesToRename.Count);

-            // === Деактивация лишних шаблонов ===
+            // === ЭТАП 7: Деактивация лишних шаблонов ===
+            stageSw.Restart();
            foreach (var unusedTemplate in unusedTemplates)
            {
-                logger.LogInformation("Деактивация лишнего шаблона {TemplateId} (Job {JobId}, UnitId {UnitId}).", unusedTemplate.Id, jobId, unusedTemplate.UnitId);
+                logger.LogInformation("Деактивация лишнего шаблона {TemplateId} (Job {JobId}, UnitId {UnitId}).",
+                    unusedTemplate.Id, jobId, unusedTemplate.UnitId);
                await templateDeactivator.DeactivateTemplateAsync(unusedTemplate, initiator);
            }
+            stageSw.Stop();
+            logger.LogDebug("[Perf] Job {JobId} | Этап: Деактивация | Время: {Ms} мс | Количество: {Count}",
+                jobId, stageSw.ElapsedMilliseconds, unusedTemplates.Count);
+
+            // === ИТОГО ===
+            totalSw.Stop();
+            logger.LogInformation("[Perf] Job {JobId} | ИТОГО: {TotalMs} мс", jobId, totalSw.ElapsedMilliseconds);

-            // === Успешное завершение ===
            await UpdateMatchingStatusAsync(jobId, "Синхронизация завершена успешно");
            await matchingStatusService.DeleteMatchingStatusAsync(jobId, SyncTaskEntityTypeEnum.Job);
            logger.LogInformation("Синхронизация шаблонов завершена для Job {JobId}.", jobId);
        }
        catch (Exception ex)
        {
-            logger.LogError(ex, "Ошибка при синхронизации Job {JobId}", jobId);
+            totalSw.Stop();
+            logger.LogError(ex, "Ошибка при синхронизации Job {JobId} через {ElapsedMs} мс", jobId, totalSw.ElapsedMilliseconds);
            await UpdateMatchingStatusAsync(jobId, $"Ошибка: {ex.Message}");
            throw;
        }
    }

+
    public async Task SyncTemplatesForJobGroupAsync(Guid jobGroupId, HistoryInitiator initiator)
    {
        logger.LogWarning("SimpleTemplateSynchronizer: SyncTemplatesForJobGroup вызван для JobGroup {JobGroupId}. Это не поддерживаемая операция.", jobGroupId);