diff --git a/CLAUDE.md b/CLAUDE.md index 793fa4f7..8792b2c3 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -171,6 +171,11 @@ almost always be doing. `PeanutButter.Utils`**, as a local in the test method rather than a fixture field. It creates the folder and deletes it on dispose, so no `[SetUp]`/`[TearDown]` pair and no NUnit1032. Close the repository or appender before the scope ends, or the delete fails on Windows. +- **A test that changes an environment variable takes `using AutoTempEnvironmentVariable v = + new("NAME", "value");`** from the same package, again as a local. It restores the previous value, + or removes the variable if there was none, on dispose, so no `try`/`finally` around the + assertions. Only the process level, so a test that needs `EnvironmentVariableTarget.User` or + `.Machine` still cleans up itself. - Mark a test `[NonParallelizable]` when it mutates static state (`LogLog.InternalDebugging`, a static field on a test double, a process-wide native registration). - Wrap expected internal logging in `LogLog.ExecuteWithoutEmittingInternalMessages(...)` and capture diff --git a/src/changelog/3.5.0/325-android-detection-without-getprop.xml b/src/changelog/3.5.0/325-android-detection-without-getprop.xml new file mode 100644 index 00000000..f59d8903 --- /dev/null +++ b/src/changelog/3.5.0/325-android-detection-without-getprop.xml @@ -0,0 +1,12 @@ + + + + + detect Android from the file system instead of starting `getprop`, which `SystemInfo` ran on + every Unix host, resolved through `PATH`, so the first match there decided the answer (audit + da18b6fd-f048, fixed by @FreeAndNil) + + diff --git a/src/changelog/3.5.0/325-formatmessage-buffer-release.xml b/src/changelog/3.5.0/325-formatmessage-buffer-release.xml new file mode 100644 index 00000000..1df7cb8a --- /dev/null +++ b/src/changelog/3.5.0/325-formatmessage-buffer-release.xml @@ -0,0 +1,12 @@ + + + + + release the `FormatMessage` buffer in `NativeError` with `LocalFree`, the allocator that API + uses, instead of letting the marshaller free it as COM task memory. Both hit the process heap on + current Windows, so this is hygiene rather than a fix (audit da18b6fd-f045, fixed by @FreeAndNil) + + diff --git a/src/changelog/3.5.0/325-syslog-apple-arm64.xml b/src/changelog/3.5.0/325-syslog-apple-arm64.xml new file mode 100644 index 00000000..87fc20c1 --- /dev/null +++ b/src/changelog/3.5.0/325-syslog-apple-arm64.xml @@ -0,0 +1,14 @@ + + + + + stop `LocalSyslogAppender` passing a variadic argument to `syslog(3)`, which on Apple arm64 + travels differently from a fixed one, so the callee read a pointer the runtime never wrote there + and logged stack bytes or crashed. Only the two fixed parameters are declared now, and the record + is passed as the format string with its percent signs escaped. The logged text is unchanged + (audit da18b6fd-f046, fixed by @FreeAndNil) + + diff --git a/src/log4net.Tests/Appender/LocalSyslogAppenderTest.cs b/src/log4net.Tests/Appender/LocalSyslogAppenderTest.cs index cd921030..4efa467f 100644 --- a/src/log4net.Tests/Appender/LocalSyslogAppenderTest.cs +++ b/src/log4net.Tests/Appender/LocalSyslogAppenderTest.cs @@ -20,7 +20,10 @@ using System; using System.Reflection; +using System.Linq; + using log4net.Appender; +using log4net.Core; using log4net.Layout; using NUnit.Framework; @@ -145,6 +148,68 @@ public void NewLineHandlingDefaultsToEscape() public void SplittingDropsTheEmptyLines() => Assert.That(SplitLines("first\r\nsecond\n\nthird\r"), Is.EqualTo(new[] { "first", "second", "third" })); + /// + /// The record is the printf format string libc parses, so a percent sign in content would make + /// the callee read an argument that was never passed. + /// + [TestCase("%s", "%%s")] + [TestCase("100%", "100%%")] + [TestCase("%d%n", "%%d%%n")] + [TestCase("rate=%s of %d", "rate=%%s of %%d")] + public void EveryPercentSignIsEscaped(string message, string expected) + => Assert.That(EscapePercent(message), Is.EqualTo(expected)); + + /// A message without a percent sign takes the fast path and comes through untouched. + [Test] + public void MessagesWithoutPercentSignsAreUnchanged() + => Assert.That(EscapePercent("field=1 field=2"), Is.EqualTo("field=1 field=2")); + + /// + /// Only the two fixed parameters of the variadic libc function may be declared. A variadic + /// argument travels differently from a fixed one on Apple arm64, where the callee then reads the + /// wrong slot. + /// + [Test] + public void TheSyslogDeclarationPassesNoVariadicArgument() + { + MethodInfo syslog = typeof(LocalSyslogAppender).Assembly + .GetType("log4net.Util.NativeMethods")! + .GetMethod("syslog", BindingFlags.Static | BindingFlags.NonPublic) + ?? throw new InvalidOperationException("NativeMethods.syslog no longer exists - update this test along with it."); + + Assert.That(syslog.GetParameters().Select(parameter => parameter.ParameterType), + Is.EqualTo(new[] { typeof(int), typeof(string) })); + } + + /// + /// Content that looks like a printf conversion reaches libc as the format string, so the + /// escaping has to hold on the real call. + /// + [Test] + [Platform("Linux")] + [NonParallelizable] + public void ContentThatLooksLikeAFormatStringIsLogged() + { + LocalSyslogAppender appender = new() + { + Identity = "log4net-test-format", + Layout = new PatternLayout("%message") + }; + appender.ActivateOptions(); + + Assert.DoesNotThrow(() => appender.DoAppend(new LoggingEvent(new LoggingEventData + { + Level = Level.Info, + Message = "%s %n %x %99999$s", + LoggerName = "FormatString" + }))); + } + + private static string EscapePercent(string message) + => (string)typeof(LocalSyslogAppender) + .GetMethod("EscapePercent", BindingFlags.Static | BindingFlags.NonPublic)! + .Invoke(null, [message])!; + private static string EscapeNewLines(string message) => (string)typeof(LocalSyslogAppender) .GetMethod("EscapeNewLines", BindingFlags.Static | BindingFlags.NonPublic)! diff --git a/src/log4net.Tests/Util/EnvironmentPatternConverterTest.cs b/src/log4net.Tests/Util/EnvironmentPatternConverterTest.cs index f8008118..0b71b6b4 100644 --- a/src/log4net.Tests/Util/EnvironmentPatternConverterTest.cs +++ b/src/log4net.Tests/Util/EnvironmentPatternConverterTest.cs @@ -23,6 +23,7 @@ using System.IO; using log4net.Util.PatternStringConverters; using NUnit.Framework; +using PeanutButter.Utils; namespace log4net.Tests.Util; @@ -85,7 +86,7 @@ public void UserLevelEnvironmentVariable() public void ProcessLevelEnvironmentVariable() { EnvironmentPatternConverter converter = new(); - Environment.SetEnvironmentVariable(EnvironmentVariableName, ProcessLevelValue); + using AutoTempEnvironmentVariable variable = new(EnvironmentVariableName, ProcessLevelValue); converter.Option = EnvironmentVariableName; @@ -93,7 +94,5 @@ public void ProcessLevelEnvironmentVariable() converter.Convert(sw, null); Assert.That(sw.ToString(), Is.EqualTo(ProcessLevelValue), "Process level environment variable not expended correctly."); - - Environment.SetEnvironmentVariable(EnvironmentVariableName, null); } } \ No newline at end of file diff --git a/src/log4net.Tests/Util/NativeErrorTest.cs b/src/log4net.Tests/Util/NativeErrorTest.cs new file mode 100644 index 00000000..624112d7 --- /dev/null +++ b/src/log4net.Tests/Util/NativeErrorTest.cs @@ -0,0 +1,79 @@ +#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 + +using System.ComponentModel; + +using log4net.Util; + +using NUnit.Framework; + +namespace log4net.Tests.Util; + +/// +/// Tests for , which formats a Win32 error code through +/// FormatMessage and releases its buffer itself. +/// +[TestFixture] +[Platform("Win")] +public sealed class NativeErrorTest +{ + /// ERROR_FILE_NOT_FOUND, a code every Windows has a message for. + private const int FileNotFound = 2; + + /// + /// The framework formats the same code through the same API, so it is the text oracle. Only the + /// trailing period differs: .NET Framework strips it, log4net and .NET do not. + /// + [Test] + public void TheMessageIsTheOneWindowsReports() + => Assert.That(NativeError.GetErrorMessage(FileNotFound)?.TrimEnd('.'), + Is.EqualTo(new Win32Exception(FileNotFound).Message.TrimEnd('.'))); + + /// The message arrives without the newlines FormatMessage appends. + [Test] + public void TheMessageCarriesNoTrailingNewLine() + => Assert.That(NativeError.GetErrorMessage(FileNotFound), Does.Not.Match("[\r\n]$")); + + /// Zero is "no error", which has no message rather than an empty one. + [Test] + public void ThereIsNoMessageForErrorZero() + => Assert.That(NativeError.GetErrorMessage(0), Is.Null); + + /// + /// Driven hard enough that a heap the wrong release had corrupted would show up here. + /// + [Test] + public void RepeatedUseKeepsReturningTheSameMessage() + { + string? first = NativeError.GetErrorMessage(FileNotFound); + + for (int i = 0; i < 500; i++) + { + Assert.That(NativeError.GetErrorMessage(FileNotFound), Is.EqualTo(first)); + } + + Assert.That(first, Is.Not.Null.And.Not.Empty); + } + + /// The number and the message both reach the formatted text. + [Test] + public void ToStringCarriesTheNumberAndTheMessage() + => Assert.That(NativeError.GetError(FileNotFound).ToString(), + Is.EqualTo($"0x00000002: {NativeError.GetErrorMessage(FileNotFound)}")); +} diff --git a/src/log4net.Tests/Util/SystemInfoTest.cs b/src/log4net.Tests/Util/SystemInfoTest.cs index ebf3a72f..daed5e11 100644 --- a/src/log4net.Tests/Util/SystemInfoTest.cs +++ b/src/log4net.Tests/Util/SystemInfoTest.cs @@ -23,6 +23,8 @@ using NUnit.Framework; +using PeanutButter.Utils; + using System.Configuration; using System.IO; using System.Linq.Expressions; @@ -196,7 +198,7 @@ public void GetAppSettingFallsBackToTheEnvironmentOnceConfigurationIsUnavailable FieldInfo latch = AppSettingsUnavailableLatch(); bool originalLatch = (bool)latch.GetValue(null)!; - Environment.SetEnvironmentVariable(Key, Value); + using AutoTempEnvironmentVariable variable = new(Key, Value); try { latch.SetValue(null, false); @@ -208,7 +210,6 @@ public void GetAppSettingFallsBackToTheEnvironmentOnceConfigurationIsUnavailable finally { latch.SetValue(null, originalLatch); - Environment.SetEnvironmentVariable(Key, null); } } @@ -287,6 +288,40 @@ public void NativeHostExceptionIsRecognised() new PlatformNotSupportedException("Operation is not supported on this platform."))), Is.True); + /// + /// Android is detected from the file system, not by starting getprop from PATH: + /// that spawned a process at type initialisation on every Unix host, and let the first match on + /// the path decide the answer. + /// + [Test] + [Platform("Linux,MacOsX")] + [NonParallelizable] + public void AndroidDetectionDoesNotRunGetpropFromThePath() + { + using AutoTempFolder folder = new(); + string marker = Path.Combine(folder.Path, "marker"); + string getprop = Path.Combine(folder.Path, "getprop"); + File.WriteAllText(getprop, $"#!/bin/sh\ntouch '{marker}'\necho ro.build.user\n"); +#if NET + if (!OperatingSystem.IsWindows()) + { + File.SetUnixFileMode(getprop, UnixFileMode.UserRead | UnixFileMode.UserExecute); + } +#endif + using AutoTempEnvironmentVariable path = new("PATH", + folder.Path + Path.PathSeparator + Environment.GetEnvironmentVariable("PATH")); + + Assert.That(IsAndroidCore(), Is.False); + Assert.That(File.Exists(marker), Is.False, "getprop was started from PATH"); + } + + private static bool IsAndroidCore() + { + MethodInfo method = typeof(SystemInfo).GetMethod("IsAndroidCore", BindingFlags.Static | BindingFlags.NonPublic) + ?? throw new InvalidOperationException("SystemInfo.IsAndroidCore no longer exists - update this test along with it."); + return (bool)method.Invoke(null, [])!; + } + private static bool IsMissingConfigurationSystem(Exception exception) { MethodInfo method = typeof(SystemInfo).GetMethod("IsMissingConfigurationSystem", BindingFlags.Static | BindingFlags.NonPublic) diff --git a/src/log4net/Appender/LocalSyslogAppender.cs b/src/log4net/Appender/LocalSyslogAppender.cs index dae7f505..365f57dc 100644 --- a/src/log4net/Appender/LocalSyslogAppender.cs +++ b/src/log4net/Appender/LocalSyslogAppender.cs @@ -356,12 +356,11 @@ protected override void Append(LoggingEvent loggingEvent) int priority = GeneratePriority(Facility, GetSeverity(loggingEvent.EnsureNotNull().Level)); string message = ContentEscape.EscapeNulCharacters(RenderLoggingEvent(loggingEvent)); - // The second argument is a printf style format string. if (NewLineHandling == SyslogNewLineHandling.Split) { foreach (string line in SplitLines(message)) { - NativeMethods.syslog(priority, "%s", line); + NativeMethods.syslog(priority, EscapePercent(line)); } return; @@ -372,9 +371,18 @@ protected override void Append(LoggingEvent loggingEvent) message = EscapeNewLines(message); } - NativeMethods.syslog(priority, "%s", message); + NativeMethods.syslog(priority, EscapePercent(message)); } + /// + /// Doubles every %, so that the record libc takes as a printf format string renders as + /// the text the layout produced. + /// + /// The rendered message. + /// The message with every percent sign escaped. + private static string EscapePercent(string message) + => message.IndexOf('%') < 0 ? message : message.Replace("%", "%%"); + /// /// What to do with the newlines in logged content. Defaults to /// . diff --git a/src/log4net/Util/NativeError.cs b/src/log4net/Util/NativeError.cs index 53479efb..a467a569 100644 --- a/src/log4net/Util/NativeError.cs +++ b/src/log4net/Util/NativeError.cs @@ -118,39 +118,41 @@ public static NativeError GetLastError() int formatMessageIgnoreInserts = 0x00000200; // Insert sequences in the message definition are to be ignored int formatMessageFromSystem = 0x00001000; // The function should search the system message-table resource(s) for the requested message - string? msgBuf = ""; // buffer that will receive the message - IntPtr sourcePtr = new(); // Location of the message definition, will be ignored - IntPtr argumentsPtr = new(); // Pointer to array of values to insert, not supported as it requires unsafe code + if (messageId == 0) + { + return null; + } - if (messageId != 0) + IntPtr messageBuffer = IntPtr.Zero; + try { // If the function succeeds, the return value is the number of TCHARs stored in the output buffer, excluding the terminating null character - int messageSize = NativeMethods.FormatMessage( + int messageSize = NativeMethods.FormatMessage( formatMessageAllocateBuffer | formatMessageFromSystem | formatMessageIgnoreInserts, - ref sourcePtr, + IntPtr.Zero, // Location of the message definition, will be ignored messageId, 0, - ref msgBuf, + out messageBuffer, 255, - argumentsPtr); + IntPtr.Zero); // Pointer to array of values to insert, not supported as it requires unsafe code - if (messageSize > 0) - { - // Remove trailing null-terminating characters (\r\n) from the message - msgBuf = msgBuf.TrimEnd(_newlines); - } - else + // A message could not be located. + if (messageSize <= 0) { - // A message could not be located. - msgBuf = null; + return null; } + + // Remove trailing null-terminating characters (\r\n) from the message + return Marshal.PtrToStringUni(messageBuffer, messageSize)?.TrimEnd(_newlines); } - else + finally { - msgBuf = null; + // FormatMessage allocated it with LocalAlloc, so it is not the marshaller's to release. + if (messageBuffer != IntPtr.Zero) + { + NativeMethods.LocalFree(messageBuffer); + } } - - return msgBuf; } /// diff --git a/src/log4net/Util/NativeMethods.cs b/src/log4net/Util/NativeMethods.cs index 96ca8918..1833b845 100644 --- a/src/log4net/Util/NativeMethods.cs +++ b/src/log4net/Util/NativeMethods.cs @@ -97,7 +97,7 @@ internal struct ConsoleScreenBufferInfo /// Location of the message definition. /// Message identifier for the requested message. /// Language identifier for the requested message. - /// If includes FORMAT_MESSAGE_ALLOCATE_BUFFER, the function allocates a buffer using the LocalAlloc function, and places the pointer to the buffer at the address specified in . + /// If includes FORMAT_MESSAGE_ALLOCATE_BUFFER, the function allocates a buffer using the LocalAlloc function and returns it here, so the caller has to release it with . /// If the FORMAT_MESSAGE_ALLOCATE_BUFFER flag is not set, this parameter specifies the maximum number of TCHARs that can be stored in the output buffer. If FORMAT_MESSAGE_ALLOCATE_BUFFER is set, this parameter specifies the minimum number of TCHARs to allocate for an output buffer. /// Pointer to an array of values that are used as insert values in the formatted message. /// @@ -128,13 +128,22 @@ internal struct ConsoleScreenBufferInfo [DefaultDllImportSearchPaths(DllImportSearchPath.System32)] internal static extern int FormatMessage( int dwFlags, - ref IntPtr lpSource, + IntPtr lpSource, int dwMessageId, int dwLanguageId, - ref string lpBuffer, + out IntPtr lpBuffer, int nSize, IntPtr arguments); + /// + /// Frees a local memory object, as allocated by . + /// + /// Handle to the object. + /// if the object was freed. + [DllImport("Kernel32.dll", SetLastError = true)] + [DefaultDllImportSearchPaths(DllImportSearchPath.System32)] + internal static extern IntPtr LocalFree(IntPtr memory); + /// /// Stub for OutputDebugString native method /// @@ -156,16 +165,15 @@ internal static extern int FormatMessage( /// /// /// - /// The libc syslog method takes a format string and a variable argument list similar - /// to the classic printf function. As this type of vararg list is not supported - /// by C# we need to specify the arguments explicitly. Here we have specified the - /// format string with a single message argument. The caller must set the format - /// string to "%s". + /// Only the two fixed parameters of the variadic libc function are declared, because a + /// variadic argument is passed differently from a fixed one on Apple arm64 and the callee then + /// reads the wrong slot. The caller passes the record as the format string and must therefore + /// double every % in it. /// /// [DllImport("libc", CharSet = CharSet.Ansi, CallingConvention = CallingConvention.Cdecl)] [System.Diagnostics.CodeAnalysis.SuppressMessage("Security", "CA5392:Use DefaultDllImportSearchPaths attribute for P/Invokes", Justification = "Only Linux")] - internal static extern void syslog(int priority, string format, string message); + internal static extern void syslog(int priority, string format); /// /// Close descriptor used to write to system logger. diff --git a/src/log4net/Util/SystemInfo.cs b/src/log4net/Util/SystemInfo.cs index 5da9adb7..d121e594 100644 --- a/src/log4net/Util/SystemInfo.cs +++ b/src/log4net/Util/SystemInfo.cs @@ -86,32 +86,41 @@ static SystemInfo() NullText = nullText; } - private static bool IsAndroidCore() // https://stackoverflow.com/questions/47521008/how-can-i-distinguish-between-unix-and-android-on-netstandard-2-0 + /// + /// Decides whether this is Android, without starting a process. + /// + private static bool IsAndroidCore() { if (Environment.OSVersion.Platform != PlatformID.Unix) + { return false; - using System.Diagnostics.Process process = new() + } + + // A file Android always has, asked first because it cannot throw. + if (File.Exists("/system/bin/getprop")) { - StartInfo = new() - { - FileName = "getprop", - Arguments = "ro.build.user", - RedirectStandardOutput = true, - UseShellExecute = false, - CreateNoWindow = true - } - }; + return true; + } +#if NET + // How .NET reports Android from .NET 5 on. + return OperatingSystem.IsAndroid(); +#elif NETFRAMEWORK + // RuntimeInformation is not in net462, and Android does not run that asset. + return false; +#else try { - process.Start(); - string output = process.StandardOutput.ReadToEnd(); - return !string.IsNullOrEmpty(output); + // The same answer for netstandard2.0. + return System.Runtime.InteropServices.RuntimeInformation.IsOSPlatform( + System.Runtime.InteropServices.OSPlatform.Create("ANDROID")); } - catch (Exception ex) when (!ex.IsFatal()) + catch (Exception e) when (!e.IsFatal()) { + // IsOSPlatform throws below net471. return false; } +#endif } ///