[9.0] Reduce noise from NotEntitledException logging (#124511)

libs/entitlement/src/main/java/org/elasticsearch/entitlement/runtime/policy/PolicyManager.java

@@ -247,15 +247,17 @@ private void neverEntitled(Class<?> callerClass, Supplier<String> operationDescr
             return;
         }
 
+        String componentName = getEntitlements(requestingClass).componentName();
         notEntitled(
             Strings.format(
-                "Not entitled: component [%s], module [%s], class [%s], operation [%s]",
-                getEntitlements(requestingClass).componentName(),
+                "component [%s], module [%s], class [%s], operation [%s]",
+                componentName,
                 requestingClass.getModule().getName(),
                 requestingClass,
                 operationDescription.get()
             ),
-            callerClass
+            callerClass,
+            componentName
         );
     }
 
@@ -366,13 +368,14 @@ public void checkFileRead(Class<?> callerClass, Path path, boolean followLinks)
         if (canRead == false) {
             notEntitled(
                 Strings.format(
-                    "Not entitled: component [%s], module [%s], class [%s], entitlement [file], operation [read], path [%s]",
+                    "component [%s], module [%s], class [%s], entitlement [file], operation [read], path [%s]",
                     entitlements.componentName(),
                     requestingClass.getModule().getName(),
                     requestingClass,
                     realPath == null ? path : Strings.format("%s -> %s", path, realPath)
                 ),
-                callerClass
+                callerClass,
+                entitlements.componentName()
             );
         }
     }
@@ -395,13 +398,14 @@ public void checkFileWrite(Class<?> callerClass, Path path) {
         if (entitlements.fileAccess().canWrite(path) == false) {
             notEntitled(
                 Strings.format(
-                    "Not entitled: component [%s], module [%s], class [%s], entitlement [file], operation [write], path [%s]",
+                    "component [%s], module [%s], class [%s], entitlement [file], operation [write], path [%s]",
                     entitlements.componentName(),
                     requestingClass.getModule().getName(),
                     requestingClass,
                     path
                 ),
-                callerClass
+                callerClass,
+                entitlements.componentName()
             );
         }
     }
@@ -483,13 +487,14 @@ private void checkFlagEntitlement(
         if (classEntitlements.hasEntitlement(entitlementClass) == false) {
             notEntitled(
                 Strings.format(
-                    "Not entitled: component [%s], module [%s], class [%s], entitlement [%s]",
+                    "component [%s], module [%s], class [%s], entitlement [%s]",
                     classEntitlements.componentName(),
                     requestingClass.getModule().getName(),
                     requestingClass,
                     PolicyParser.getEntitlementTypeName(entitlementClass)
                 ),
-                callerClass
+                callerClass,
+                classEntitlements.componentName()
             );
         }
         logger.debug(
@@ -524,21 +529,29 @@ public void checkWriteProperty(Class<?> callerClass, String property) {
         }
         notEntitled(
             Strings.format(
-                "Not entitled: component [%s], module [%s], class [%s], entitlement [write_system_properties], property [%s]",
+                "component [%s], module [%s], class [%s], entitlement [write_system_properties], property [%s]",
                 entitlements.componentName(),
                 requestingClass.getModule().getName(),
                 requestingClass,
                 property
             ),
-            callerClass
+            callerClass,
+            entitlements.componentName()
         );
     }
 
-    private void notEntitled(String message, Class<?> callerClass) {
+    private void notEntitled(String message, Class<?> callerClass, String componentName) {
         var exception = new NotEntitledException(message);
         // Don't emit a log for muted classes, e.g. classes containing self tests
         if (mutedClasses.contains(callerClass) == false) {
-            logger.warn(message, exception);
+            var moduleName = callerClass.getModule().getName();
+            var loggerSuffix = "." + componentName + "." + ((moduleName == null) ? ALL_UNNAMED : moduleName);
+            var notEntitledLogger = LogManager.getLogger(PolicyManager.class.getName() + loggerSuffix);
+            String frameInfoSuffix = StackWalker.getInstance(RETAIN_CLASS_REFERENCE)
+                .walk(this::findRequestingFrame)
+                .map(frame -> "\n\tat " + frame)
+                .orElse("");
+            notEntitledLogger.warn("Not entitled: " + message + frameInfoSuffix);
         }
         throw exception;
     }
@@ -658,19 +671,18 @@ Class<?> requestingClass(Class<?> callerClass) {
             return callerClass;
         }
         Optional<Class<?>> result = StackWalker.getInstance(RETAIN_CLASS_REFERENCE)
-            .walk(frames -> findRequestingClass(frames.map(StackFrame::getDeclaringClass)));
+            .walk(frames -> findRequestingFrame(frames).map(StackFrame::getDeclaringClass));
         return result.orElse(null);
     }
 
     /**
-     * Given a stream of classes corresponding to the frames from a {@link StackWalker},
-     * returns the module whose entitlements should be checked.
+     * Given a stream of {@link StackFrame}s, identify the one whose entitlements should be checked.
      *
      * @throws NullPointerException if the requesting module is {@code null}
      */
-    Optional<Class<?>> findRequestingClass(Stream<Class<?>> classes) {
-        return classes.filter(c -> c.getModule() != entitlementsModule)  // Ignore the entitlements library
-            .skip(1)                                           // Skip the sensitive caller method
+    Optional<StackFrame> findRequestingFrame(Stream<StackFrame> frames) {
+        return frames.filter(f -> f.getDeclaringClass().getModule() != entitlementsModule) // ignore entitlements library
+            .skip(1) // Skip the sensitive caller method
             .findFirst();
     }
 

libs/entitlement/src/test/java/org/elasticsearch/entitlement/runtime/policy/PolicyManagerTests.java

@@ -23,6 +23,7 @@
 import org.junit.BeforeClass;
 
 import java.io.IOException;
+import java.lang.StackWalker.StackFrame;
 import java.lang.module.Configuration;
 import java.lang.module.ModuleFinder;
 import java.net.URL;
@@ -320,18 +321,21 @@ public void testRequestingModuleWithStackWalk() throws IOException, ClassNotFoun
         assertEquals(
             "Skip entitlement library and the instrumented method",
             requestingClass,
-            policyManager.findRequestingClass(Stream.of(entitlementsClass, instrumentedClass, requestingClass, ignorableClass)).orElse(null)
+            policyManager.findRequestingFrame(
+                Stream.of(entitlementsClass, instrumentedClass, requestingClass, ignorableClass).map(MockFrame::new)
+            ).map(StackFrame::getDeclaringClass).orElse(null)
         );
         assertEquals(
             "Skip multiple library frames",
             requestingClass,
-            policyManager.findRequestingClass(Stream.of(entitlementsClass, entitlementsClass, instrumentedClass, requestingClass))
-                .orElse(null)
+            policyManager.findRequestingFrame(
+                Stream.of(entitlementsClass, entitlementsClass, instrumentedClass, requestingClass).map(MockFrame::new)
+            ).map(StackFrame::getDeclaringClass).orElse(null)
         );
         assertThrows(
             "Non-modular caller frames are not supported",
             NullPointerException.class,
-            () -> policyManager.findRequestingClass(Stream.of(entitlementsClass, null))
+            () -> policyManager.findRequestingFrame(Stream.of(entitlementsClass, null).map(MockFrame::new))
         );
     }
 
@@ -657,4 +661,47 @@ private static ModuleLayer createLayerForJar(Path jar, String moduleName) {
         );
         return moduleController.layer();
     }
+
+    record MockFrame(Class<?> declaringClass) implements StackFrame {
+        @Override
+        public String getClassName() {
+            return getDeclaringClass().getName();
+        }
+
+        @Override
+        public String getMethodName() {
+            throw new UnsupportedOperationException();
+        }
+
+        @Override
+        public Class<?> getDeclaringClass() {
+            return declaringClass;
+        }
+
+        @Override
+        public int getByteCodeIndex() {
+            throw new UnsupportedOperationException();
+        }
+
+        @Override
+        public String getFileName() {
+            throw new UnsupportedOperationException();
+        }
+
+        @Override
+        public int getLineNumber() {
+            throw new UnsupportedOperationException();
+        }
+
+        @Override
+        public boolean isNativeMethod() {
+            throw new UnsupportedOperationException();
+        }
+
+        @Override
+        public StackTraceElement toStackTraceElement() {
+            throw new UnsupportedOperationException();
+        }
+    }
+
 }

modules/repository-gcs/src/main/config/log4j2.properties

@@ -0,0 +1,3 @@
+logger.org_elasticsearch_entitlement_runtime_policy_PolicyManager.name = org.elasticsearch.entitlement.runtime.policy.PolicyManager.repository-gcs.ALL-UNNAMED
+logger.org_elasticsearch_entitlement_runtime_policy_PolicyManager.level = error
+

modules/repository-s3/src/main/config/log4j2.properties

@@ -12,3 +12,7 @@ logger.com_amazonaws_auth_profile_internal_BasicProfileConfigFileLoader.level =
 
 logger.com_amazonaws_services_s3_internal_UseArnRegionResolver.name = com.amazonaws.services.s3.internal.UseArnRegionResolver
 logger.com_amazonaws_services_s3_internal_UseArnRegionResolver.level = error
+
+logger.org_elasticsearch_entitlement_runtime_policy_PolicyManager.name = org.elasticsearch.entitlement.runtime.policy.PolicyManager.repository-s3.software.amazon.awssdk.profiles
+logger.org_elasticsearch_entitlement_runtime_policy_PolicyManager.level = error
+