native interop: fix syslog on Apple arm64, stop starting getprop

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

src/changelog/3.5.0/325-android-detection-without-getprop.xml

@@ -0,0 +1,12 @@
+<?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="changed">
+  <issue id="325" link="https://github.com/apache/logging-log4net/pull/325"/>
+  <description format="asciidoc">
+    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)
+  </description>
+</entry>

src/changelog/3.5.0/325-formatmessage-buffer-release.xml

@@ -0,0 +1,12 @@
+<?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="changed">
+  <issue id="325" link="https://github.com/apache/logging-log4net/pull/325"/>
+  <description format="asciidoc">
+    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)
+  </description>
+</entry>

src/changelog/3.5.0/325-syslog-apple-arm64.xml

@@ -0,0 +1,14 @@
+<?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="325" link="https://github.com/apache/logging-log4net/pull/325"/>
+  <description format="asciidoc">
+    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)
+  </description>
+</entry>

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" }));
 
+  /// <summary>
+  /// 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.
+  /// </summary>
+  [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));
+
+  /// <summary>A message without a percent sign takes the fast path and comes through untouched.</summary>
+  [Test]
+  public void MessagesWithoutPercentSignsAreUnchanged()
+    => Assert.That(EscapePercent("field=1 field=2"), Is.EqualTo("field=1 field=2"));
+
+  /// <summary>
+  /// 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.
+  /// </summary>
+  [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) }));
+  }
+
+  /// <summary>
+  /// Content that looks like a printf conversion reaches libc as the format string, so the
+  /// escaping has to hold on the real call.
+  /// </summary>
+  [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)!

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,15 +86,13 @@ public void UserLevelEnvironmentVariable()
   public void ProcessLevelEnvironmentVariable()
   {
     EnvironmentPatternConverter converter = new();
-    Environment.SetEnvironmentVariable(EnvironmentVariableName, ProcessLevelValue);
+    using AutoTempEnvironmentVariable variable = new(EnvironmentVariableName, ProcessLevelValue);
 
     converter.Option = EnvironmentVariableName;
 
     using StringWriter sw = new();
     converter.Convert(sw, null);
 
     Assert.That(sw.ToString(), Is.EqualTo(ProcessLevelValue), "Process level environment variable not expended correctly.");
-
-    Environment.SetEnvironmentVariable(EnvironmentVariableName, null);
   }
 }

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;
+
+/// <summary>
+/// Tests for <see cref="NativeError"/>, which formats a Win32 error code through
+/// <c>FormatMessage</c> and releases its buffer itself.
+/// </summary>
+[TestFixture]
+[Platform("Win")]
+public sealed class NativeErrorTest
+{
+  /// <summary>ERROR_FILE_NOT_FOUND, a code every Windows has a message for.</summary>
+  private const int FileNotFound = 2;
+
+  /// <summary>
+  /// 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.
+  /// </summary>
+  [Test]
+  public void TheMessageIsTheOneWindowsReports()
+    => Assert.That(NativeError.GetErrorMessage(FileNotFound)?.TrimEnd('.'),
+      Is.EqualTo(new Win32Exception(FileNotFound).Message.TrimEnd('.')));
+
+  /// <summary>The message arrives without the newlines <c>FormatMessage</c> appends.</summary>
+  [Test]
+  public void TheMessageCarriesNoTrailingNewLine()
+    => Assert.That(NativeError.GetErrorMessage(FileNotFound), Does.Not.Match("[\r\n]$"));
+
+  /// <summary>Zero is "no error", which has no message rather than an empty one.</summary>
+  [Test]
+  public void ThereIsNoMessageForErrorZero()
+    => Assert.That(NativeError.GetErrorMessage(0), Is.Null);
+
+  /// <summary>
+  /// Driven hard enough that a heap the wrong release had corrupted would show up here.
+  /// </summary>
+  [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);
+  }
+
+  /// <summary>The number and the message both reach the formatted text.</summary>
+  [Test]
+  public void ToStringCarriesTheNumberAndTheMessage()
+    => Assert.That(NativeError.GetError(FileNotFound).ToString(),
+      Is.EqualTo($"0x00000002: {NativeError.GetErrorMessage(FileNotFound)}"));
+}

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);
 
+  /// <summary>
+  /// Android is detected from the file system, not by starting <c>getprop</c> from <c>PATH</c>:
+  /// that spawned a process at type initialisation on every Unix host, and let the first match on
+  /// the path decide the answer.
+  /// </summary>
+  [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)

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));
   }
 
+  /// <summary>
+  /// Doubles every <c>%</c>, so that the record libc takes as a printf format string renders as
+  /// the text the layout produced.
+  /// </summary>
+  /// <param name="message">The rendered message.</param>
+  /// <returns>The message with every percent sign escaped.</returns>
+  private static string EscapePercent(string message)
+    => message.IndexOf('%') < 0 ? message : message.Replace("%", "%%");
+
   /// <summary>
   /// What to do with the newlines in logged content. Defaults to
   /// <see cref="SyslogNewLineHandling.Escape"/>.