@Thecentury11 авг 2014 в 11:42

Некоторые аспекты логирования ASP.NET-сайта

16 мин

22K

.NET * ASP *

+16

Комментарии 19

@lair 11 авг 2014 в 12:07

Подождите-подождите, логирование asp.net и не слова об ELMAH?

Часто рекомендуют вызывать асинхронные методы, настраивая awaiter, чтобы он не вызывал продолжение в том же контексте синхронизации, из которого он был вызван сам: это увеличивает производительность.

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

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

Какому именно коду-продолжению? Для кода в вашем собственном методе можно всю информацию захватить в его начале. Для кода вне вашего метода не имеет значение, как вы настраивали awaiter.

@Thecentury 11 авг 2014 в 12:17

Да, ни слова об ELMAH, потому что мы его не используем. Я рассказал о том, что используем мы.

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

Расскажете, каких ситуаций?

@lair 11 авг 2014 в 12:26

Да, ни слова об ELMAH, потому что мы его не используем. Я рассказал о том, что используем мы.

А почему вы его не используете?

Расскажете, каких ситуаций?

У вас есть некий обработчик верхнего уровня, который по каким-то причинам не использует async. В нем, соответственно, нижележеащий асинхронный метод вызывается через блаблаблаAsync().Result. В этот момент поток блокируется на контексте синхронизации asp.net (том самом, про который вы пишете. Если теперь в любом коде ниже вызвать .Result, .Wait или асинхронный метод без .ConfigureAwait(false), они встанут в блокировку на том же контексте синхронизации — и мы успешно получим дедлок. Подробности — у Стивена Клири.

@Thecentury 11 авг 2014 в 12:28

А, ясно. Такой блокировки у нас не будет, потому что к .Result мы не обращаемся, используем решение из http://stackoverflow.com/questions/5095183/how-would-i-run-an-async-taskt-method-synchronously

@lair 11 авг 2014 в 12:32

Вы уверены, что в коде уровне выше вашего обработчика никто и никогда не поставит блокирующий вызов? Проблема в том, что этот вид ошибки ловится только в рантайме.

А во-вторых, то ли я чего-то не понимаю, то ли приведенное вами решение выполняет метод не в текущем контексте синхронизации.

@Thecentury 11 авг 2014 в 12:41

Да, я в этом не уверен, и второе ваше замечание тоже верно, обдумаю, как мы можем это исправить.
Проблем не возникало, видимо, потому, что а) синхронно асинхронные методы мы вызываем мало; б) информация о пользователе захватывается в его начале и передается явно через параметры.

@lair 11 авг 2014 в 12:45

информация о пользователе захватывается в его начале и передается явно через параметры.

Вот поэтому я и не понимаю, какому коду-продолжению не будет доступна информация из контекста (цитата в первом комментарии).

@lair 11 авг 2014 в 12:44

Да, я прав: тот же самый Клири в комментариях к вашему решению пишет, что оно не работает там, где нужен asp-шный контекст синхронизации.

@Thecentury 11 авг 2014 в 12:31

А почему вы его не используете?

Видимо, пока ни разу не наткнулись на рекомендацию использовать его, когда искали, как решить ту или иную задачу. Для чего его используете вы? Он может решить что-то из того, что я описал?

@lair 11 авг 2014 в 12:34

Вообще-то, ELMAH упоминается почти на любом базовом докладе по asp.net. Он позволяет отлавливать «непойманные» ошибки в asp.net с адекватным логгированием и их отображением в дальнейшем.

@Thecentury 11 авг 2014 в 12:39

У меня есть ощущение, что он ортогонален тому, о чем рассказал я:)
Но спасибо за его упоминание, попробую понять, чем он может быть нам полезен.

@jonie 12 авг 2014 в 19:12

Какой адЪ написан для юзеров…

Уж ежели у вас нигде не используется ConfigureAwait(false) и используется await/async и у вас .net 4.5+ тогда вам просто надо было юзера вашего отнаследовать от IPrincipal, записать в Thread.CurrentIdentity и в HttpContext.Current.User в начале запроса (да хоть в OnBeginRequest в самом деле) и жить счастливо, т.к. AspNetSynchronizationContext будет вам сохранять HttpContext.Current (и юзера как его часть) до конца запроса благодаря введённому в .net45 так называемого task-friendly синхронизационного контекста (обязательно указание либо httpRuntime targetFramework=«4.5» в web.config либо aspnet:UseTaskFriendlySynchronizationContext в true в app.settings).

А ежели у вас .net4 и ниже, то использовать надобно LogicalCallContext, который есть часть ExecutionContext-та и сохранению которого наплевать на синхронизационный контекст (который пока что тоже вообще говоря часть ExecutionContext-та) в силу того что все методы, порождающие асинхронность (и Task-и в том числе) используют ExecutionContext.Run для исполнения делагата, который и является «телом» задачи (а нужно это для сохранения CAS правил, импресонализации и сохранения LogicalCallContext).

Короче надо бы как-нибудь просвятить местный народ касательно контекстов, async/await-тов и того как вообще работают Task-и, потоки и чем поток (thread) отличается от логического потока (control flow), а-то походу тут у многих в головах каша…

@Thecentury 13 авг 2014 в 06:57

Вы знаете, я не думаю, что концептуально наше решение отличается от предложенного вами. Пользователь в HttpContext.Current.Items так же, как и из CurrentIdentity, переезжает из потока в поток.

@jonie 13 авг 2014 в 07:01

Ну, пора начинать думать-то… Свой велосипед против готового и работающего из коробки, понятного всем? Так-то и нога ничем от руки концептуально не отличается…

@vba 13 авг 2014 в 06:51

Добрый день,

Подскажите пожалуйста, кто нибудь встречал открытые проекты подобные Logentries, желательно сделанные на платформе .NET, которые можно взять и поставить у себя на сервере?

@jonie 13 авг 2014 в 07:03

graylog2, logstash, splunk например. Иные подскажут опытные админы (им эта тема имхо ближе).

@ZetaTetra 18 авг 2014 в 11:38

А чем не устроили штатные Health Monitoring и System.Diagnostics.Trace?

@Thecentury 19 авг 2014 в 10:01

Не было с ними знакомства. Trace, насколько я знаю, даже по сигнатуре методов «логирования» сильно проигрывает NLog. Мы смогли бы с его помощью гибко настраивать, что логировать, данные, которые войдут в каждую запись, настраивать, в какие получатели будут отправлены записи? Смогли бы из коробки логировать в БД, на logentries? Хотя бы смогли бы писать логи в файлы, ротируя их каждые сутки?

Про штатный Health Monitoring вообще ничего не знаю, расскажите, пожалуйста.

@ZetaTetra 21 авг 2014 в 15:17

Не проблема :)
Основы тут:
msdn.microsoft.com/en-us/library/vstudio/bb398933%28v=vs.100%29.aspx
По умолчанию поддерживает следующие типы событий:
msdn.microsoft.com/en-us/library/system.web.management%28v=vs.110%29.aspx
Типы стандартных кодов событий описаны тут:
msdn.microsoft.com/en-us/library/system.web.management.webeventcodes%28v=vs.110%29.aspx

Из коробки поддерживаются следующие провайдеры событий:

EventLogWebEventProvider — По стандарту всё пишется в евентлог. Меняется в глобальном Web.config'е
SqlWebEventProvider — Пишет всё в MSSQL. Хранимки и таблицы ставлятся через aspnet_regiis
WmiWebEventProvider — Отправляет все события через WMI
SimpleMailWebEventProvider / TemplatedMailWebEventProvider — Отправляет мыло. Второй позволяет указать шаблон отправки
TraceWebEventProvider — Отправляет всё в System.Diagnostics.Trace

По умолчанию, пишет события в нечитабельном виде:

Пример события типа исключение в базовом варианте

Event message: An unhandled exception has occurred.
Event code: 3005
Event detail code: 0
Event time: 21.08.2014 18:21:05
Event ID: 1505644e-6d09-4c01-978e-e3250e964ce0
Event sequence: 388911
Event occurence: 2030

Application information:
  Machine name: AAA
  Application domain: AAA
  Trust level: Full
  Application Virtual Path: /
  Application Path: D:\www\AAA\
Process information:
  Process ID: 188364
  Process name: w3wp
  Accont name: 
Exception information:
  Exception type: NullReferenceException
  Exception message: Object reference not set to an instance of an object.
  Stack trace:

Request information:
  Request URL: http://aaa/default.aspx
  Request path: /default.aspx
  User host address: 192.168.1.1
  User: 
  Is authenticated: False

Немного поколдовав над выводом данных и добавив свой провайдер логирования на централизованный лог-сервер получил такой результат:

Пример события типа исключение в дописанном варианте

<?xml version="1.0" encoding="utf-16"?>
<Event>
 <Message>An unhandled exception has occurred.</Message>
 <EventId>1505644e-6d09-4c01-978e-e3250e964ce0</EventId>
 <Type>Error</Type>
 <Source>System.Web.HttpResponse</Source>
 <Code>3005</Code>
 <DetailCode>0</DetailCode>
 <Occurrence>2030</Occurrence>
 <Sequence>388911</Sequence>
 <TimeCreated>21.08.2014 18:21:05</TimeCreated>
 <Exception>
  <Type>NullReferenceException</Type>
  <Message>Object reference not set to an instance of an object.</Message>
  <StackTrace>AAA</StackTrace>
  <ExceptionString>AAA</ExceptionString>
 </Exception>
 <System>
  <MachineName>AAA</MachineName>
  <InstructionSet>X86</InstructionSet>
  <ApplicationName>AAA</ApplicationName>
  <DomainName>/LM/W3SVC/1/ROOT-4</DomainName>
  <Path>D:\www\AAA\</Path>
 </System>
 <Thread>
  <IsImpersonating>False</IsImpersonating>
  <ThreadId>63</ThreadId>
  <AccountName>NT AUTHORITY\NETWORK SERVICE</AccountName>
 </Thread>
 <Process>
  <ProcessId>188364</ProcessId>
  <CurrentProcessId>188364</CurrentProcessId>
  <ProcessName>w3wp</ProcessName>
  <AccountName />
 </Process>
 <Iis>
  <VirtualPath>/</VirtualPath>
  <TrustLevel>Full</TrustLevel>
  <Request>
   <Url>http://AAA/default.aspx</Url>
   <User Name="" AuthenticationType="" IsAuthenticated="False">System.Security.Principal.GenericIdentity</User>
   <RequestPath>/default.aspx</RequestPath>
   <UserHostAddress>192.168.1.1</UserHostAddress>
   <UserAgent>AAA</UserAgent>
  </Request>
 </Iis>
</Event>

Нашёл на хабре статью про внедрение HM (Возможно ещё есть. Первая на глаза попалась):
habrahabr.ru/post/27847/

Если будут ещё вопросы — спрашивайте. Буду рад помочь. :)

Зарегистрируйтесь на Хабре, чтобы оставить комментарий