logging-log4net-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From George Chung <geo...@glympse.com>
Subject Re: Proposed bug fix for AspNetRequestPatternConverter.Convert()
Date Sat, 31 Mar 2012 18:48:01 GMT
>
> And [th]e problem will still persist because outputting "not available"
> will not log anything useful to the user that will actuality be forced to
> move the log elsewhere to see it working.


But you do get the other non-asp.net logging such as %thread, %message,
%exception. NOTAVAILABLE is an useful output for those specific aspnet
variables when the HttpContext is...not available. NOTAVAILABLE for aspnet
variables combined with the other non-aspnet variables is eminently more
valuable than no logging at all (which is currently the case in
Application_Start with Integrated Pipeline).

What I'm saying is that from an architectural point of view is absolutely
> right for a class library to throw an exception if it's used in a wrong
> context and that this behavior should be maintained.


But the class library does NOT throw an exception if you do not reference
aspnet variables in your layout patterns. Are there other cases in log4net
where a specific layout pattern causes logging to abort depending on where
in your application code you call it from? I don't think so. I would argue
that behavior would not be the class library authors' intent. From reading
the existing code, I would argue that the authors tried to ensure the use
of aspnet variables to NOT cause logging to abort because of a "bad"
HttpContext.

In the link I posted before, you should find a piece of code that use the
> application_beginrequest to initialize the asp.net application using
> static objects. You should check it out. The problems I usually see is that
> the application_start is usually "overused"... Very little lines of code
> should go in the application start, in my humble opinion.... Logging is not
> usually one of those


ASP.NET MVC Visual Studio generated code and application samples from
Microsoft demonstrate a lot of stuff initializing in Application_Start. In
fact, you cannot setup MVC routes any other way except through
Application_Start. If any of these initialization steps fail, it's useful
to have a log message somewhere indicating why.

Cheers,
George

On Sat, Mar 31, 2012 at 3:18 AM, Alessandro Ghizzardi <box.mlist@phaseit.com
> wrote:

> Hi George,
>
> Just to clarify, I'm not in the log4net dev team, I'm just an asp.net MVP
> following this mailing list :)
> Checking for null and throwing an exception are two different behavior,
> the second one will be a lot more expensive from a performance point of
> view. And e problem will still persist because outputting "not available"
> will not log anything useful to the user that will actuality be forced to
> move the log elsewhere to see it working.
>
> What I'm saying is that from an architectural point of view is absolutely
> right for a class library to throw an exception if it's used in a wrong
> context and that this behavior should be maintained. The problem of who is
> going from classic mode to integrated mode and have this error is in the
> people itself :) changing from classic to integrated mode is not a matter
> of changing a drop down in IIS, is dealing with a completely new
> architecture.... And the developer should read a little more about it, in
> that way he'll be able to deal with such problems.
>
> In the link I posted before, you should find a piece of code that use the
> application_beginrequest to initialize the asp.net application using
> static objects. You should check it out. The problems I usually see is that
> the application_start is usually "overused"... Very little lines of code
> should go in the application start, in my humble opinion.... Logging is not
> usually one of those :)
>
> Best
>
> Sent from iPad
>
> Il giorno 31/mar/2012, alle ore 01:53, George Chung <george@glympse.com>
> ha scritto:
>
> Hi Alessandro,
> But you are already checking for a null HttpContext and outputting
> "NOTAVAILABLE" in that case, which means that the code was intended to deal
> with format layouts of %aspnet{xxx} and HttpContext's that were null.
>
> I'm simply suggesting that the code should ALSO deal with HttpContext's
> that have a bad Request property.
>
> As motivation for this change, you have people who are using log4net in
> Application_Start in Classic Mode and it works fine. The behavior that
> they'll see as they upgrade to the recommended Integrated Pipeline mode is
> that this logging will disappear mysteriously.
>
> Finally, there is no other place to initialize the ASP.NET application.
> The only place to do it is in the Application_Start(). So if they are using
> the %aspnet layout format in their logging, then they'll basically see no
> logging in this code path.
>
> It's not a huge issue, and I can live without it (or I can modify the code
> as I have), and I can see why you don't like the suggested fix, but again,
> I think the catch block will only fire very rarely in an application's
> lifetime and it will allow ASP.NET users who are currently using log4net
> from being confused as they upgrade to the Integrated Pipeline mode.
>
> Thanks for listening, and it has been very nice to see such prompt and
> thoughtful response from the log4net dev team. The product is great.
>
> Cheers,
> George
>
> On Fri, Mar 30, 2012 at 3:35 PM, Alessandro Ghizzardi <
> box.mlist@phaseit.com> wrote:
>
>> Yes that's exactly the point. If log4net need the request and you're
>> calling it in a scope that doesn't have it, catching the error in log4net
>> doesn't seem a viable solution for my point of view because it'll not work
>> as expected without request.
>>
>> Probably it's better to move the app initializiation code in a scope that
>> actually have the request available as you can read in the article.
>>
>> Best
>> Alessandro Ghizzardi
>> Moving...
>>
>> Il giorno 30/mar/2012, alle ore 23:54, "Johnson, Thomas" <
>> Thomas.Johnson@lpsvcs.com> ha scritto:
>>
>> It sounds like he’s suggesting you fix your site instead of the
>> codebase?  If there’s definitely a fix that needs to be in place, I would
>> explore the httpContext to see if you can infer whether get_Request would
>> throw an NRE and check that instead of try/catch – it’s just a code smell
>> everyone should try to avoid in general****
>>
>> ** **
>>
>> *From:* George Chung [mailto:george@glympse.com]
>> *Sent:* Friday, March 30, 2012 3:50 PM
>> *To:* Log4NET Dev
>> *Subject:* Re: Proposed bug fix for
>> AspNetRequestPatternConverter.Convert()****
>>
>> ** **
>>
>> Yes, that is exactly the issue. Just my humble opinion, but Log4Net would
>> only incur the try/catch perf penalty during user logging inside
>> Application_Start, which is a very tiny percentage of the lifetime of an
>> ASP.Net application.****
>>
>> ** **
>>
>> The issue for log4net is that people staticly define their layout
>> patterns that they want in the web.config. It's not obvious to me how they
>> could "instruct" log4net to ignore the aspnet layout patterns while inside
>> Application_Start.****
>>
>> ** **
>>
>> I don't know any other way to test the viability of calling through
>> get_Request() before the fact.****
>>
>> ** **
>>
>> Cheers,****
>>
>> George****
>>
>> On Fri, Mar 30, 2012 at 2:30 PM, Alessandro Ghizzardi <
>> box.mlist@phaseit.com> wrote:****
>>
>> Hi George,****
>>
>> ** **
>>
>> It  seems more like an architecture problem in logging that point,
>> instead of a bug. It used to work in older version, but probably you're
>> using IIS7 in integrated mode and request is not available anymore.****
>>
>> If you really need to log in application start probably this workaround
>> can help you****
>>
>> ** **
>>
>>
>> http://mvolo.com/blogs/serverside/archive/2007/11/10/Integrated-mode-Request-is-not-available-in-this-context-in-Application_5F00_Start.aspx
>> ****
>>
>> ** **
>>
>> Best
>> Alessandro Ghizzardi****
>>
>> Moving...****
>>
>>
>> Il giorno 30/mar/2012, alle ore 22:59, George Chung <george@glympse.com>
>> ha scritto:****
>>
>> The subtlety is that in Application_Startup(), httpContext is indeed not
>> null and httpContext.Request is really httpContext.get_Request().****
>>
>> ** **
>>
>> And it is the act of calling get_Request() that throws the HttpException.
>> ****
>>
>> On Fri, Mar 30, 2012 at 1:51 PM, Johnson, Thomas <
>> Thomas.Johnson@lpsvcs.com> wrote:****
>>
>> Sorry: if (httpContext != null && httpContext.Request != null)****
>>
>>  ****
>>
>> Since you’re in c# the second statement won’t be evaluated if the first
>> is false and you will avoid NRE****
>>
>>  ****
>>
>> *From:* Johnson, Thomas
>> *Sent:* Friday, March 30, 2012 2:50 PM
>> *To:* log4net-dev@logging.apache.org
>> *Subject:* RE: Proposed bug fix for
>> AspNetRequestPatternConverter.Convert()****
>>
>>  ****
>>
>> Typically you want to avoid code like this // maybe just do:  if (httpContext !=
null) { //the entirety of your method } else writer.Write(SystemInfo.NotAvailableText);****
>>
>>  ****
>>
>>             try****
>>
>>             {****
>>
>>                 request = httpContext.Request;****
>>
>>                 if (request == null)****
>>
>> ** **
>>
>>                     requestExists = false;****
>>
>>             }****
>>
>>             catch (System.Web.HttpException)****
>>
>> ** **
>>
>>             {****
>>
>>                 requestExists = false;****
>>
>>             }****
>>
>>  ****
>>
>>  ****
>>
>> *From:* George Chung [mailto:george@glympse.com] ****
>>
>> *Sent:* Friday, March 30, 2012 1:29 PM
>> *To:* log4net-dev@logging.apache.org
>> *Subject:* Proposed bug fix for AspNetRequestPatternConverter.Convert()**
>> **
>>
>>  ****
>>
>> Hello,****
>>
>> I'm new to this mailing list. Sorry if this is not the appropriate way to
>> report a bug fix. Dereferencing HttpContext.Request will throw an exception
>> if you call it in an Asp.net application's Application_Start().****
>>
>>  ****
>>
>> Thus, if you have log4net logging *and* you use a pattern layout format
>> like %aspnet-request{REMOTE_ADDR} *and* you call Log4net inside
>> Application_Start(), Log4net will throw an exception trying to log the
>> message. The stack will look like this:****
>>
>>  ****
>>
>> log4net:ERROR [RollingFileAppender] ErrorCode: GenericFailure. Failed in
>> DoAppend****
>>
>> System.Web.HttpException (0x80004005): Request is not available in this
>> context****
>>
>>    at System.Web.HttpContext.get_Request()****
>>
>>    at
>> log4net.Layout.Pattern.AspNetRequestPatternConverter.Convert(TextWriter
>> writer, LoggingEvent loggingEvent, HttpContext httpContext)****
>>
>>    at
>> log4net.Layout.Pattern.AspNetPatternLayoutConverter.Convert(TextWriter
>> writer, LoggingEvent loggingEvent)****
>>
>>    at log4net.Layout.Pattern.PatternLayoutConverter.Convert(TextWriter
>> writer, Object state)****
>>
>>    at log4net.Util.PatternConverter.Format(TextWriter writer, Object
>> state)****
>>
>>    at log4net.Layout.PatternLayout.Format(TextWriter writer, LoggingEvent
>> loggingEvent)****
>>
>>    at log4net.Layout.Layout2RawLayoutAdapter.Format(LoggingEvent
>> loggingEvent)****
>>
>>  ****
>>
>>  ****
>>
>> Here is my proposed fix:****
>>
>>  ****
>>
>>  ****
>>
>> internal sealed class AspNetRequestPatternConverter : AspNetPatternLayoutConverter****
>>
>>     {****
>>
>>         /// <summary>****
>>
>>         /// Write the ASP.Net Cache item to the output****
>>
>>         /// </summary>****
>>
>> ** **
>>
>>         /// <param name="writer"><see cref="TextWriter" /> that will
receive the formatted result.</param>****
>>
>>         /// <param name="loggingEvent">The <see cref="LoggingEvent" />
on which the pattern converter should be executed.</param>****
>>
>>         /// <param name="httpContext">The <see cref="HttpContext" />
under which the ASP.Net request is running.</param>****
>>
>>         /// <remarks>****
>>
>> ** **
>>
>>         /// <para>****
>>
>>         /// Writes out the value of a named property. The property name****
>>
>>         /// should be set in the <see cref="log4net.Util.PatternConverter.Option"/>****
>>
>>         /// property.****
>>
>>         /// </para>****
>>
>>         /// </remarks>****
>>
>> ** **
>>
>>         protected override void Convert(TextWriter writer, LoggingEvent loggingEvent,
HttpContext httpContext)****
>>
>>         {****
>>
>>             bool requestExists = true;****
>>
>>  ****
>>
>>             HttpRequest request = null;****
>>
>>             try****
>>
>>             {****
>>
>>                 request = httpContext.Request;****
>>
>>                 if (request == null)****
>>
>>                     requestExists = false;****
>>
>>             }****
>>
>>             catch (System.Web.HttpException)****
>>
>> ** **
>>
>>             {****
>>
>>                 requestExists = false;****
>>
>>             }****
>>
>>  ****
>>
>> ** **
>>
>>             if (requestExists)****
>>
>>             {****
>>
>>                 if (Option != null)****
>>
>> ** **
>>
>>                 {****
>>
>>                     WriteObject(writer, loggingEvent.Repository, request.Params[Option]);****
>>
>>                 }****
>>
>>                 else****
>>
>>                 {****
>>
>>                     WriteObject(writer, loggingEvent.Repository, request.Params);****
>>
>>                 }****
>>
>>             }****
>>
>> ** **
>>
>>             else****
>>
>>             {****
>>
>> ** **
>>
>>                 writer.Write(SystemInfo.NotAvailableText);****
>>
>>             }****
>>
>>         }****
>>
>>     }****
>>
>> The information contained in this message is proprietary and/or
>> confidential. If you are not the intended recipient, please: (i) delete the
>> message and all copies; (ii) do not disclose, distribute or use the message
>> in any manner; and (iii) notify the sender immediately. In addition, please
>> be aware that any message addressed to our domain is subject to archiving
>> and review by persons other than the intended recipient. Thank you.****
>>
>> ** **
>>
>> ** **
>> The information contained in this message is proprietary and/or
>> confidential. If you are not the intended recipient, please: (i) delete the
>> message and all copies; (ii) do not disclose, distribute or use the message
>> in any manner; and (iii) notify the sender immediately. In addition, please
>> be aware that any message addressed to our domain is subject to archiving
>> and review by persons other than the intended recipient. Thank you.
>>
>>
>

Mime
View raw message