locked
Can't get log4net to properly filter my logs RRS feed

  • Question

  • User-2147270405 posted

    I'm currently getting reacquainted with log4Net configuration after a few years of it "just working", and I'm running into an issue while working in Visual Studio 2019 with ASP.NET Core. Any help figuring this out would be appreciated.

    I have the following filter and level settings, but my log file STILL ends up with all the "Chatter" that goes in the debug window of the IDE. As you can see, I've set the level to "INFO" and above, and then tried to filter out "noise" containing "Microsoft.AspNetCore" but no luck. I've researched how to do filtering and THINK I've done it right, but it's not filtering ANYTHING.

    <?xml version="1.0" encoding="utf-8" ?>
    <log4net>
      <appender name="DebugAppender" type="log4net.Appender.DebugAppender" >
        <layout type="log4net.Layout.PatternLayout">
          <conversionPattern value="%date [%thread] %-5level %logger - %message%newline" />
        </layout>
      </appender>
      <appender name="RollingFile" type="log4net.Appender.RollingFileAppender">
        <file value="SDPerf.log" />
        <appendToFile value="true" />
        <maximumFileSize value="100KB" />
        <maxSizeRollBackups value="2" />
        <layout type="log4net.Layout.PatternLayout">
          <conversionPattern value="%date %5level %logger.%method [%line] - MESSAGE: %message%newline %exception" />
        </layout>
        <filter type="log4net.Filter.StringMatchFilter">
          <stringToMatch value="Microsoft.AspNetCore"/>
          <acceptOnMatch value="false"/>
        </filter>
      </appender>
      <root>
        <level value="INFO"/>
        <appender-ref ref="RollingFile" />
      </root>
    </log4net>

    and here's a snip from the log file, where I want to ONLY see the last 2 lines of this snip:

    2021-05-21 15:50:01,744  INFO Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.? [?] - MESSAGE: Executing action method LongRunningTask.Controllers.HomeController.Test2 (LongRunningTask) - Validation state: Valid
     2021-05-21 15:50:01,754  INFO Microsoft.AspNetCore.Mvc.ViewFeatures.PartialViewResultExecutor.? [?] - MESSAGE: Executing PartialViewResult, running view Jobs.
     2021-05-21 15:50:01,762  INFO Microsoft.AspNetCore.Mvc.ViewFeatures.PartialViewResultExecutor.? [?] - MESSAGE: Executed PartialViewResult - view Jobs executed in 7.4295ms.
     2021-05-21 15:50:01,768  INFO Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.? [?] - MESSAGE: Executed action LongRunningTask.Controllers.HomeController.Test2 (LongRunningTask) in 43.365ms
     2021-05-21 15:50:01,772  INFO Microsoft.AspNetCore.Routing.EndpointMiddleware.? [?] - MESSAGE: Executed endpoint 'LongRunningTask.Controllers.HomeController.Test2 (LongRunningTask)'
     2021-05-21 15:50:01,776  INFO Microsoft.AspNetCore.Hosting.Diagnostics.? [?] - MESSAGE: Request finished in 71.9539ms 200 text/html; charset=utf-8
     2021-05-21 15:50:03,561  INFO Microsoft.AspNetCore.Hosting.Diagnostics.? [?] - MESSAGE: Request starting HTTP/2.0 GET https://localhost:44345/Home/ProcessJob  
     2021-05-21 15:50:03,567  INFO Microsoft.AspNetCore.Routing.EndpointMiddleware.? [?] - MESSAGE: Executing endpoint 'LongRunningTask.Controllers.HomeController.ProcessJob (LongRunningTask)'
     2021-05-21 15:50:03,588  INFO Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.? [?] - MESSAGE: Executing action method LongRunningTask.Controllers.HomeController.ProcessJob (LongRunningTask) - Validation state: Valid
     2021-05-21 15:50:03,592  INFO SDPerf..ctor [24] - MESSAGE: Starting Task calls
     2021-05-21 15:50:03,602  INFO SDPerf.NewMethod [51] - MESSAGE: Starting iterations for method '2'
     2021-05-21 15:50:03,606  INFO SDPerf.NewMethod [51] - MESSAGE: Starting iterations for method '3'
     

    Based on some online info (SO mostly), I went a step further and tried the following changes. I changed the filter to a positive one (i.e. stated the value I wanted and changed the 'acceptOnMatch' to True and then added a 'DenyAllFilter' setting. ) I now get ZERO log entries, as the DenyAllFilter is denying everything it seems.   TBH, it seems like the filtering config is TOTALLY counter-intuitive.

    Monday, May 24, 2021 4:11 PM

Answers

  • User-2147270405 posted

    Solved - While I never found any documentation with decent examples, I eventually figured out that "StringMatchFilter' only operates on the textual message itself, NOT the part of the actual log entry that contains Assembly, etc. 

    • Marked as answer by Anonymous Thursday, October 7, 2021 12:00 AM
    Tuesday, May 25, 2021 12:54 AM