This is an automated email from the ASF dual-hosted git repository. FreeAndNil pushed a commit to branch Feature/316-content-loss in repository https://gitbox.apache.org/repos/asf/logging-log4net.git
commit 145203420c579a703008b4b723b6a080757f4964 Author: Jan Friedrich <[email protected]> AuthorDate: Thu Sep 3 23:21:08 2026 +0200 stop the aspnet-request converter dropping events with rejected content #316 - Reading HttpRequest.Params validates the query string, form and cookies on first access, so a request carrying <script> threw inside the layout and AppenderSkeleton discarded the whole event: a sender could suppress the log record of their own request. - The converter now reads through HttpRequest.Unvalidated, so the content is kept rather than replaced by the not-available marker. - The try now also covers the body parse and ServerVariables, which throw on an oversized body or a lost client. Verified on Windows: with no worker request behind it, ServerVariables is empty rather than throwing. - Five tests, net462 only, so they run on the Windows leg alone. Reverting the fix fails exactly the two that assert the content survives. audit da18b6fd-f019 --- .../3.5.0/316-aspnet-request-event-loss.xml | 13 ++ .../Pattern/AspNetRequestPatternConverterTest.cs | 147 +++++++++++++++++++++ src/log4net.Tests/log4net.Tests.csproj | 1 + .../Pattern/AspNetRequestPatternConverter.cs | 45 ++++--- 4 files changed, 187 insertions(+), 19 deletions(-) diff --git a/src/changelog/3.5.0/316-aspnet-request-event-loss.xml b/src/changelog/3.5.0/316-aspnet-request-event-loss.xml new file mode 100644 index 00000000..39dd62fc --- /dev/null +++ b/src/changelog/3.5.0/316-aspnet-request-event-loss.xml @@ -0,0 +1,13 @@ +<?xml version="1.0" encoding="UTF-8"?> +<entry xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" + xmlns="https://logging.apache.org/xml/ns" + xsi:schemaLocation="https://logging.apache.org/xml/ns https://logging.apache.org/xml/ns/log4j-changelog-0.xsd" + type="fixed"> + <issue id="316" link="https://github.com/apache/logging-log4net/pull/316"/> + <description format="asciidoc">Stop `%aspnet-request` losing the whole event for a request that fails + ASP.NET request validation. Reading `HttpRequest.Params` validates the query string, form and + cookies on first access, so a request carrying `<script>` threw inside the layout and the + appender discarded the event: a sender could suppress the log record of their own request. The + converter now reads through `HttpRequest.Unvalidated`, which keeps the content instead of + dropping it (audit da18b6fd-f019, fixed by @FreeAndNil)</description> +</entry> diff --git a/src/log4net.Tests/Layout/Pattern/AspNetRequestPatternConverterTest.cs b/src/log4net.Tests/Layout/Pattern/AspNetRequestPatternConverterTest.cs new file mode 100644 index 00000000..115e164e --- /dev/null +++ b/src/log4net.Tests/Layout/Pattern/AspNetRequestPatternConverterTest.cs @@ -0,0 +1,147 @@ +#region Apache License +// +// Licensed to the Apache Software Foundation (ASF) under one or more +// contributor license agreements. See the NOTICE file distributed with +// this work for additional information regarding copyright ownership. +// The ASF licenses this file to you under the Apache License, Version 2.0 +// (the "License"); you may not use this file except in compliance with +// the License. You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +// +#endregion + +// netstandard has no System.Web +#if NET462_OR_GREATER + +using System; +using System.IO; +using System.Web; + +using log4net.Config; +using log4net.Layout; +using log4net.Repository; +using log4net.Tests.Appender; +using log4net.Util; + +using NUnit.Framework; + +namespace log4net.Tests.Layout.Pattern; + +/// <summary> +/// Tests that <c>%aspnet-request</c> survives content ASP.NET request validation rejects. +/// </summary> +[TestFixture] +public sealed class AspNetRequestPatternConverterTest +{ + private const string Payload = "<script>"; + + /// <summary> + /// Detaches the hand-built request from the thread again. + /// </summary> + [TearDown] + public void TearDown() => HttpContext.Current = null; + + /// <summary> + /// Guards the other tests: if request validation does not fire here, they pass vacuously. + /// </summary> + [Test] + [NonParallelizable] + public void TheRequestUsedByTheseTestsDoesFailValidation() + { + HttpRequest request = CurrentRequest("q=%3Cscript%3E"); + + Assert.Throws<HttpRequestValidationException>(() => _ = request.Params); + } + + /// <summary> + /// Reading a named field of a request that fails validation once threw inside the layout, and + /// the appender discarded the whole event, letting a sender suppress the record of their own + /// request. + /// </summary> + [Test] + [NonParallelizable] + public void ARejectedNamedFieldKeepsItsContent() + { + CurrentRequest("q=%3Cscript%3E"); + + string rendered = Render("%aspnet-request{q}|%message"); + + Assert.That(rendered, Is.EqualTo(Payload + "|TestMessage")); + } + + /// <summary> + /// The same for the whole collection, which has no unvalidated counterpart and is rebuilt. + /// </summary> + [Test] + [NonParallelizable] + public void ARejectedRequestStillWritesTheEvent() + { + CurrentRequest("q=%3Cscript%3E"); + + string rendered = Render("%aspnet-request|%message"); + + Assert.That(rendered, Does.EndWith("|TestMessage")); + } + + /// <summary> + /// A benign request is unchanged, so the paths above are not hiding a broken happy path. + /// </summary> + [Test] + [NonParallelizable] + public void ABenignNamedFieldIsUnchanged() + { + CurrentRequest("name=value"); + + string rendered = Render("%aspnet-request{name}|%message"); + + Assert.That(rendered, Is.EqualTo("value|TestMessage")); + } + + /// <summary> + /// Without a request the converter writes the not-available marker rather than failing. + /// </summary> + [Test] + [NonParallelizable] + public void NoHttpContextWritesTheNotAvailableMarker() + { + HttpContext.Current = null; + + string rendered = Render("%aspnet-request{q}|%message"); + + Assert.That(rendered, Is.EqualTo(SystemInfo.NotAvailableText + "|TestMessage")); + } + + /// <summary> + /// Publishes a request carrying <paramref name="queryString"/> and opts it into validation. + /// </summary> + private static HttpRequest CurrentRequest(string queryString) + { + HttpRequest request = new("page.aspx", "http://localhost/page.aspx", queryString); + HttpContext.Current = new(request, new HttpResponse(TextWriter.Null)); + // The runtime does this for a real request; the first Params read then validates. + request.ValidateInput(); + return request; + } + + /// <summary> + /// Logs one event through <paramref name="pattern"/> and returns what the appender received. + /// </summary> + private static string Render(string pattern) + { + StringAppender appender = new() { Layout = new PatternLayout(pattern) }; + ILoggerRepository repository = LogManager.CreateRepository(Guid.NewGuid().ToString()); + BasicConfigurator.Configure(repository, appender); + LogManager.GetLogger(repository.Name, nameof(AspNetRequestPatternConverterTest)) + .Info("TestMessage"); + return appender.GetString(); + } +} + +#endif // NET462_OR_GREATER diff --git a/src/log4net.Tests/log4net.Tests.csproj b/src/log4net.Tests/log4net.Tests.csproj index 50ee6553..851af72e 100644 --- a/src/log4net.Tests/log4net.Tests.csproj +++ b/src/log4net.Tests/log4net.Tests.csproj @@ -38,6 +38,7 @@ <ItemGroup Condition="'$(TargetFramework)'=='net462'"> <Reference Include="System.Configuration" /> <Reference Include="System.Runtime.Remoting" /> + <Reference Include="System.Web" /> </ItemGroup> <ItemGroup Condition="'$(TargetFramework)'=='net10.0'"> <PackageReference Include="Microsoft.NET.Test.Sdk" Version="$(MicrosoftNetTestSdkPackageVersion)" /> diff --git a/src/log4net/Layout/Pattern/AspNetRequestPatternConverter.cs b/src/log4net/Layout/Pattern/AspNetRequestPatternConverter.cs index 881911fa..7b0d223a 100644 --- a/src/log4net/Layout/Pattern/AspNetRequestPatternConverter.cs +++ b/src/log4net/Layout/Pattern/AspNetRequestPatternConverter.cs @@ -18,6 +18,7 @@ // #endregion +using System.Collections.Specialized; using System.Diagnostics.CodeAnalysis; using System.IO; using System.Web; @@ -53,34 +54,40 @@ internal sealed class AspNetRequestPatternConverter : AspNetPatternLayoutConvert /// </remarks> protected override void Convert(TextWriter writer, LoggingEvent loggingEvent, HttpContext httpContext) { - HttpRequest? request = null; + object? value; try { - request = httpContext.Request; + HttpRequest request = httpContext.Request; + // Unvalidated reads past ASP.NET request validation, which throws on content like "<script>". + value = Option is null ? GetParameters(request) : request.Unvalidated[Option]; } catch (HttpException) { - // likely a case of running in IIS integrated mode - // when inside an Application_Start event. - // treat it like a case of the Request - // property returning null + // No readable request: IIS integrated mode during Application_Start, an oversized body, + // or a client that went away. + writer.Write(SystemInfo.NotAvailableText); + return; } - if (request is not null) - { - if (Option is not null) - { - WriteObject(writer, loggingEvent.Repository, httpContext.Request.Params[Option]); - } - else - { - WriteObject(writer, loggingEvent.Repository, httpContext.Request.Params); - } - } - else + WriteObject(writer, loggingEvent.Repository, value); + } + + /// <summary> + /// Rebuilds <see cref="HttpRequest.Params"/> from the unvalidated values. + /// </summary> + private static NameValueCollection GetParameters(HttpRequest request) + { + UnvalidatedRequestValues unvalidated = request.Unvalidated; + NameValueCollection parameters = new(); + parameters.Add(unvalidated.QueryString); + parameters.Add(unvalidated.Form); + HttpCookieCollection cookies = unvalidated.Cookies; + foreach (string name in cookies.AllKeys) { - writer.Write(SystemInfo.NotAvailableText); + parameters.Add(name, cookies[name]?.Value); } + parameters.Add(request.ServerVariables); + return parameters; } }
