логи

backend/Tnsu.ApprovalRoute.Application/ListPartitioning/CreateNextListPartitionJob.cs

@@ -1,3 +1,4 @@
+using System.Diagnostics;
 using Hangfire;
 using Microsoft.EntityFrameworkCore;
 using Microsoft.Extensions.Logging;
@@ -83,15 +84,34 @@ public sealed class CreateNextListPartitionJob(
             var nextNumber = maxNumber + 1;
 
             logger.LogInformation(
-                "Создаю партицию №{Number} для типа заявок {RequestTypeId} по структуре {SourceListId}.",
-                nextNumber, requestTypeId, requestType.ListId);
+                "Создаю партицию №{Number} для типа заявок {RequestTypeId} ({RequestTypeName}) " +
+                "по структуре {SourceListId}.",
+                nextNumber, requestTypeId, requestType.Name, requestType.ListId);
 
-            // Партиция всегда создаётся на том же сайте, что и текущая (см. комментарий
-            // на RequestListPartition о недопустимости разъезда серии по сайтам) — сайт
-            // берём из RequestType, а не откуда-либо ещё, так что расхождение
-            // структурно невозможно.
-            var created = await provisioner.CreateNextListPairAsync(
-                requestType.SiteUrl, requestType.ListId, nextNumber, cancellationToken);
+            var stopwatch = Stopwatch.StartNew();
+            ProvisionedList created;
+            try
+            {
+                // Партиция всегда создаётся на том же сайте, что и текущая (см.
+                // комментарий на RequestListPartition о недопустимости разъезда серии
+                // по сайтам) — сайт берём из RequestType, а не откуда-либо ещё, так что
+                // расхождение структурно невозможно.
+                created = await provisioner.CreateNextListPairAsync(
+                    requestType.SiteUrl, requestType.ListId, nextNumber, cancellationToken);
+            }
+            catch (Exception ex)
+            {
+                // Логируем с контекстом (номер партиции, тип заявок) здесь, а не
+                // полагаемся только на то, что исключение долетит до лога Hangfire:
+                // там оно будет без этих подробностей, вперемешку с логами других задач.
+                // Дальше даём ему пойти в Hangfire как обычно — так сработает
+                // AutomaticRetry(Attempts = 3).
+                logger.LogError(
+                    ex,
+                    "Провижининг партиции №{Number} для типа заявок {RequestTypeId} не удался за {ElapsedMs} мс.",
+                    nextNumber, requestTypeId, stopwatch.ElapsedMilliseconds);
+                throw;
+            }
 
             // Реестр и переключение записи — одной транзакцией: иначе можно остаться
             // с записанной в реестр партицией, в которую никто не пишет, или наоборот.
@@ -112,8 +132,9 @@ public sealed class CreateNextListPartitionJob(
             await transaction.CommitAsync(cancellationToken);
 
             logger.LogInformation(
-                "Партиция №{Number} ({ListId}) создана, запись по типу заявок {RequestTypeId} переключена на неё.",
-                nextNumber, created.ListId, requestTypeId);
+                "Партиция №{Number} ({ListId}) создана за {ElapsedMs} мс, запись по типу заявок " +
+                "{RequestTypeId} переключена на неё.",
+                nextNumber, created.ListId, stopwatch.ElapsedMilliseconds, requestTypeId);
         }
         finally
         {

backend/Tnsu.ApprovalRoute.Infrastructure/SharePoint/SharePointListProvisioner.cs

@@ -1,3 +1,4 @@
+using System.Diagnostics;
 using Microsoft.Extensions.Logging;
 
 namespace Tnsu.ApprovalRoute.Infrastructure.SharePoint;
@@ -23,6 +24,11 @@ public sealed class SharePointListProvisioner(
         int number,
         CancellationToken cancellationToken)
     {
+        logger.LogInformation(
+            "Дублирую пару списков №{Number} на {SiteUrl} по образцу {SourceListId}.",
+            number, siteUrl, sourceDataListId);
+        var stopwatch = Stopwatch.StartNew();
+
         var sourceData = await sharePoint.GetListByUrlAsync(siteUrl, sourceDataListId, cancellationToken)
             ?? throw new InvalidOperationException(
                 $"Исходный список {sourceDataListId} не найден на {siteUrl} — дублировать нечего.");
@@ -31,11 +37,16 @@ public sealed class SharePointListProvisioner(
             siteUrl,
             sourceData,
             ListTitleConvention.WithNumber(sourceData.Title, number),
+            role: "данные",
             retarget: null,
             cancellationToken);
 
         await CloneApprovalPairAsync(siteUrl, sourceData, newData, number, cancellationToken);
 
+        logger.LogInformation(
+            "Пара списков №{Number} готова за {ElapsedMs} мс: данные «{Title}» ({ListId}).",
+            number, stopwatch.ElapsedMilliseconds, newData.Title, newData.ServerRelativeUrl);
+
         return new ProvisionedList(newData.ServerRelativeUrl, newData.Title);
     }
 
@@ -73,6 +84,7 @@ public sealed class SharePointListProvisioner(
             siteUrl,
             sourceApproval,
             ListTitleConvention.WithNumber(sourceApproval.Title, number),
+            role: "согласование",
             // Ticket списка согласования смотрит на список данных — в дубле он должен
             // смотреть на НОВЫЙ список данных, иначе строки маршрута новых заявок
             // будут ссылаться в старый список.
@@ -80,10 +92,15 @@ public sealed class SharePointListProvisioner(
             cancellationToken);
     }
 
+    /// <summary>
+    /// role — только для логов («данные»/«согласование»): по нему в логе видно, какую
+    /// половину пары обрабатывает конкретный вызов, не заглядывая в стек вызовов.
+    /// </summary>
     private async Task<SharePointListInfo> CloneAsync(
         string siteUrl,
         SharePointListInfo source,
         string newTitle,
+        string role,
         (Guid From, Guid To)? retarget,
         CancellationToken cancellationToken)
     {
@@ -91,13 +108,16 @@ public sealed class SharePointListProvisioner(
         var target = existing ?? await sharePoint.CreateListAsync(siteUrl, newTitle, cancellationToken);
 
         logger.LogInformation(
-            existing is null ? "Создан список «{Title}»." : "Список «{Title}» уже существует — дозаполняю колонки.",
-            newTitle);
+            existing is null
+                ? "Список {Role} «{Title}» создан."
+                : "Список {Role} «{Title}» уже существует — дозаполняю недостающие колонки.",
+            role, newTitle);
 
         var sourceFields = await sharePoint.GetCustomFieldsAsync(siteUrl, source.ServerRelativeUrl, cancellationToken);
         var targetFields = await sharePoint.GetCustomFieldsAsync(siteUrl, target.ServerRelativeUrl, cancellationToken);
         var alreadyThere = targetFields.Select(x => x.InternalName).ToHashSet(StringComparer.OrdinalIgnoreCase);
 
+        var copied = 0;
         foreach (var field in sourceFields)
         {
             if (alreadyThere.Contains(field.InternalName)) continue;
@@ -107,9 +127,19 @@ public sealed class SharePointListProvisioner(
                 : RetargetLookup(field.SchemaXml, retarget.Value.From, retarget.Value.To);
 
             await sharePoint.AddFieldFromXmlAsync(siteUrl, target.Id, schemaXml, cancellationToken);
-            logger.LogInformation("  колонка {InternalName} → «{Title}»", field.InternalName, newTitle);
+            copied++;
+
+            // По каждой колонке — только на Debug: при штатной первой партии их
+            // десятки на список, и на Information это был бы шум. Итог всё равно
+            // виден в сводке ниже.
+            logger.LogDebug(
+                "Список {Role} «{Title}»: скопирована колонка {InternalName}.", role, newTitle, field.InternalName);
         }
 
+        logger.LogInformation(
+            "Список {Role} «{Title}»: скопировано колонок {Copied}, уже было {AlreadyThere}.",
+            role, newTitle, copied, sourceFields.Count - copied);
+
         return target;
     }