Skip to content

Latest commit

 

History

History
39 lines (28 loc) · 5.32 KB

0012.request-scope.md

File metadata and controls

39 lines (28 loc) · 5.32 KB
Raw

Как обогощать логи информацией из запросов (например, UserId)

Допустим, есть пользователи и заказы. Некоторые действия могут совершаться в контексте пользователя – например, «посмотреть список доступных пользователю заказов» или «начать/закончить перерыв», а некоторые в контексте заказа – например, «взять заказ в работу» или «отметить заказ выполненным».

Хочется логировать все действия, совершаемые в рамках контекста. Например, если пользователь пришёл за списком заказов, то в лог должны упасть записи вида

{
  "@mt": "orders list requested",
  "SourceContext": "WebApplication1.Controllers.OrdersListController",
  "UserId": "3fa85f64-5717-4562-b3fc-2c963f66afa6"
}

и

{
  "@mt": "GetOrders invoked",
  "SourceContext": "WebApplication1.Repositories.OrdersRepository",
  "UserId": "3fa85f64-5717-4562-b3fc-2c963f66afa6"
}

– одна запись с уровня контроллера, вторая с уровня репозитория, который был вызван контроллером

Решение в лоб – logger.BeginScope в начале каждого запроса.

Но в каждом экшене каждого контроллера такое писать некомильфо, поэтому делаем IActionFilter, который разбирает аргументы, выуживает из них UserId и складывает в скоуп.

Но не так всё просто – если происходит исключение, то скоуп теряется (в первой записи есть Scope с UserId, в записи с исключением UserId нет)

Можно использовать Activity.Current?.AddTag и Serilog.Enrichers.ActivityTags

Можно использовать мидлварю, складывающую всё в скоуп, потом вызывающую next, обернутый в try-catch, но я не придумал как на уровне мидлвари выуживать userId из запроса

Пробую вложенный скоуп. Выглядит неплохо – даже внешняя лог-запись содержит информацию из внутреннего скоупа. Это странно, на самом деле. И тут внимательный читатель воскликнет «Эй, а почему ты не доспоузишь скоуп?».

Использую using, всё встаёт на свои места – внешняя лог-запись не содержит информацию из внутреннего скоупа.

Почитав блог Andrew Lock, экспериментирую с фильтром исключений – в SourceContext: "WebApplication1.Controllers.OrdersListController" появилось "UserId_scope": "3fa85f64-5717-4562-b3fc-2c963f66afa6"

Но в целом это хрупкая штука – если где-нибудь по пути из глубин стека вызовов сделать catch-throw, то изначальный контекст исключения будет потерян – так SourceContext: "WebApplication1.Controllers.OrdersListController" не содержит inner_scope_id, даже если фильтр исключений применять на всех уровнях.