Core: Handle security manager permission for deprecation log rolling (#37281)

When the deprecation log is written to within scripting support code
like ScriptDocValues, it runs under the reduces privileges of scripts.
Sometimes this can trigger log rolling, which then causes uncaught
security errors, as was handled in #28485. While doing individual
deprecation handling within each deprecation scripting location is
possible, there are a growing number of deprecations in scripts.

This commit wraps the logging call within the deprecation logger use a
doPrivileged block, just was we would within individual logging call
sites for scripting utilities.

qa/evil-tests/src/test/java/org/elasticsearch/common/logging/EvilLoggerTests.java

@@ -126,7 +126,7 @@ public class EvilLoggerTests extends ESTestCase {
             assertLogLine(
                     deprecationEvents.get(i),
                     Level.WARN,
-                    "org.elasticsearch.common.logging.DeprecationLogger.deprecated",
+                    "org.elasticsearch.common.logging.DeprecationLogger\\$2\\.run",
                     "This is a deprecation message");
         }
     }
@@ -200,7 +200,7 @@ public class EvilLoggerTests extends ESTestCase {
             assertLogLine(
                     deprecationEvents.get(i),
                     Level.WARN,
-                    "org.elasticsearch.common.logging.DeprecationLogger.deprecated",
+                    "org.elasticsearch.common.logging.DeprecationLogger\\$2\\.run",
                     "This is a maybe logged deprecation message" + i);
         }
 
@@ -242,13 +242,13 @@ public class EvilLoggerTests extends ESTestCase {
         assertLogLine(
                 deprecationEvents.get(0),
                 Level.WARN,
-                "org.elasticsearch.common.logging.DeprecationLogger.deprecated",
+                "org.elasticsearch.common.logging.DeprecationLogger\\$2\\.run",
                 "This is a maybe logged deprecation message");
         for (int k = 0; k < 128; k++) {
             assertLogLine(
                     deprecationEvents.get(1 + k),
                     Level.WARN,
-                    "org.elasticsearch.common.logging.DeprecationLogger.deprecated",
+                    "org.elasticsearch.common.logging.DeprecationLogger\\$2\\.run",
                     "This is a maybe logged deprecation message" + k);
         }
     }
@@ -276,7 +276,7 @@ public class EvilLoggerTests extends ESTestCase {
             assertLogLine(
                     deprecationEvents.get(0),
                     Level.WARN,
-                    "org.elasticsearch.common.logging.DeprecationLogger.deprecated",
+                    "org.elasticsearch.common.logging.DeprecationLogger\\$2\\.run",
                     "\\[deprecated.foo\\] setting was deprecated in Elasticsearch and will be removed in a future release! " +
                             "See the breaking changes documentation for the next major version.");
         }

server/src/main/java/org/elasticsearch/common/logging/DeprecationLogger.java

@@ -27,6 +27,8 @@ import org.elasticsearch.common.SuppressLoggerChecks;
 import org.elasticsearch.common.util.concurrent.ThreadContext;
 
 import java.nio.charset.Charset;
+import java.security.AccessController;
+import java.security.PrivilegedAction;
 import java.time.ZoneId;
 import java.time.ZonedDateTime;
 import java.time.format.DateTimeFormatter;
@@ -298,7 +300,7 @@ public class DeprecationLogger {
         deprecated(threadContexts, message, true, params);
     }
 
-    @SuppressLoggerChecks(reason = "safely delegates to logger")
+
     void deprecated(final Set<ThreadContext> threadContexts, final String message, final boolean log, final Object... params) {
         final Iterator<ThreadContext> iterator = threadContexts.iterator();
 
@@ -318,7 +320,14 @@ public class DeprecationLogger {
         }
 
         if (log) {
-            logger.warn(message, params);
+            AccessController.doPrivileged(new PrivilegedAction<Void>() {
+                @SuppressLoggerChecks(reason = "safely delegates to logger")
+                @Override
+                public Void run() {
+                    logger.warn(message, params);
+                    return null;
+                }
+            });
         }
     }
 

server/src/test/java/org/elasticsearch/common/logging/DeprecationLoggerTests.java

@@ -19,8 +19,13 @@
 package org.elasticsearch.common.logging;
 
 import com.carrotsearch.randomizedtesting.generators.CodepointSetGenerator;
-
 import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
+import org.apache.logging.log4j.simple.SimpleLoggerContext;
+import org.apache.logging.log4j.simple.SimpleLoggerContextFactory;
+import org.apache.logging.log4j.spi.ExtendedLogger;
+import org.apache.logging.log4j.spi.LoggerContext;
+import org.apache.logging.log4j.spi.LoggerContextFactory;
 import org.elasticsearch.common.settings.Settings;
 import org.elasticsearch.common.util.concurrent.ThreadContext;
 import org.elasticsearch.test.ESTestCase;
@@ -28,14 +33,21 @@ import org.elasticsearch.test.hamcrest.RegexMatcher;
 import org.hamcrest.core.IsSame;
 
 import java.io.IOException;
+import java.net.URI;
+import java.nio.charset.StandardCharsets;
+import java.security.AccessControlContext;
+import java.security.AccessController;
+import java.security.Permissions;
+import java.security.PrivilegedAction;
+import java.security.ProtectionDomain;
 import java.util.Collections;
 import java.util.HashSet;
 import java.util.List;
 import java.util.Locale;
 import java.util.Map;
 import java.util.Set;
+import java.util.concurrent.atomic.AtomicBoolean;
 import java.util.stream.IntStream;
-import java.nio.charset.StandardCharsets;
 
 import static org.elasticsearch.common.logging.DeprecationLogger.WARNING_HEADER_PATTERN;
 import static org.elasticsearch.test.hamcrest.RegexMatcher.matches;
@@ -43,6 +55,10 @@ import static org.hamcrest.Matchers.containsString;
 import static org.hamcrest.Matchers.equalTo;
 import static org.hamcrest.Matchers.hasSize;
 import static org.hamcrest.Matchers.not;
+import static org.hamcrest.core.Is.is;
+import static org.mockito.Mockito.doAnswer;
+import static org.mockito.Mockito.mock;
+import static org.mockito.Mockito.when;
 
 /**
  * Tests {@link DeprecationLogger}
@@ -303,6 +319,49 @@ public class DeprecationLoggerTests extends ESTestCase {
         }
     }
 
+    public void testLogPermissions() {
+        AtomicBoolean supplierCalled = new AtomicBoolean(false);
+
+        // mocking the logger used inside DeprecationLogger requires heavy hacking...
+        Logger parentLogger = mock(Logger.class);
+        when(parentLogger.getName()).thenReturn("logger");
+        ExtendedLogger mockLogger = mock(ExtendedLogger.class);
+        doAnswer(invocationOnMock -> {
+            supplierCalled.set(true);
+            createTempDir(); // trigger file permission, like rolling logs would
+            return null;
+        }).when(mockLogger).warn("foo", new Object[] {"bar"});
+        final LoggerContext context = new SimpleLoggerContext() {
+            @Override
+            public ExtendedLogger getLogger(String name) {
+                return mockLogger;
+            }
+        };
+
+        final LoggerContextFactory originalFactory = LogManager.getFactory();
+        try {
+            LogManager.setFactory(new SimpleLoggerContextFactory() {
+                @Override
+                public LoggerContext getContext(String fqcn, ClassLoader loader, Object externalContext, boolean currentContext,
+                                                URI configLocation, String name) {
+                    return context;
+                }
+            });
+            DeprecationLogger deprecationLogger = new DeprecationLogger(parentLogger);
+
+            AccessControlContext noPermissionsAcc = new AccessControlContext(
+                new ProtectionDomain[]{new ProtectionDomain(null, new Permissions())}
+            );
+            AccessController.doPrivileged((PrivilegedAction<Void>) () -> {
+                deprecationLogger.deprecated("foo", "bar");
+                return null;
+            }, noPermissionsAcc);
+            assertThat("supplier called", supplierCalled.get(), is(true));
+        } finally {
+            LogManager.setFactory(originalFactory);
+        }
+    }
+
     private String range(int lowerInclusive, int upperInclusive) {
         return IntStream
                 .range(lowerInclusive, upperInclusive + 1)