Thecentury Aug 11 2014 at 15:42

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

16 min

21K

.NET*ASP*

+17

Comments 19

lair Aug 11 2014 at 16:07

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

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

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

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

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

Thecentury Aug 11 2014 at 16:17

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

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

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

lair Aug 11 2014 at 16:26

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

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

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

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

-2

Thecentury Aug 11 2014 at 16:28

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

lair Aug 11 2014 at 16:32

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

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

Thecentury Aug 11 2014 at 16:41

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

lair Aug 11 2014 at 16:45

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

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

lair Aug 11 2014 at 16:44

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

Thecentury Aug 11 2014 at 16:31

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

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

lair Aug 11 2014 at 16:34

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

-3

Thecentury Aug 11 2014 at 16:39

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

jonie Aug 12 2014 at 23: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 Aug 13 2014 at 10:57

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

jonie Aug 13 2014 at 11:01

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

vba Aug 13 2014 at 10:51

Добрый день,

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

jonie Aug 13 2014 at 11:03

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

ZetaTetra Aug 18 2014 at 15:38

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

Thecentury Aug 19 2014 at 14:01

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

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

ZetaTetra Aug 21 2014 at 19: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/

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

Show the best of all time