JDK-8316113 : Infinite permission checking loop in java/net/spi/InetAddressResolverProvider/RuntimePermissionTest
  • Type: Bug
  • Component: core-libs
  • Sub-Component: java.net
  • Affected Version: 21,22
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2023-09-12
  • Updated: 2023-10-06
  • Resolved: 2023-09-12
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 21 JDK 22
21.0.2Fixed 22 b15Fixed
Related Reports
Duplicate :  
Relates :  
Relates :  
Description
I am seeing the following failure very intermittently:

```
===============================================
java/net/spi/InetAddressResolverProvider/RuntimePermissionTest.java
Total tests run: 2, Passes: 0, Failures: 2, Skips: 0
===============================================

STDERR:
Sep 12, 2023 11:08:33 AM RuntimePermissionTest$TestSecurityManager <init>
INFO: inetAddressResolverProvider permission is not granted
WARNING: A terminally deprecated method in java.lang.System has been called
WARNING: System::setSecurityManager has been called by RuntimePermissionTest (file:/local/home/shipilev/shipilev-jdk/build/linux-x86_64-server-fastdebug/test-support/jtreg_test_jdk_java_net_spi_InetAddressResolverProvider_RuntimePermissionTest_java/classes/0/java/net/spi/InetAddressResolverProvider/RuntimePermissionTest.d/)
WARNING: Please consider reporting this to the maintainers of RuntimePermissionTest
WARNING: System::setSecurityManager will be removed in a future release
Sep 12, 2023 11:08:33 AM RuntimePermissionTest$TestSecurityManager checkPermission
INFO: Checking RuntimePermission: ("java.lang.RuntimePermission" "getClassLoader")
Sep 12, 2023 11:08:33 AM RuntimePermissionTest$TestSecurityManager checkPermission
INFO: Checking RuntimePermission: ("java.lang.RuntimePermission" "getClassLoader")
Sep 12, 2023 11:08:33 AM RuntimePermissionTest$TestSecurityManager checkPermission
INFO: Checking RuntimePermission: ("java.lang.RuntimePermission" "getClassLoader")
java.lang.StackOverflowError
        at java.base/java.util.stream.AbstractPipeline.wrapSink(AbstractPipeline.java:547)
        at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
        at java.base/java.util.stream.FindOps$FindOp.evaluateSequential(FindOps.java:150)
        at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
        at java.base/java.util.stream.ReferencePipeline.findFirst(ReferencePipeline.java:647)
        at java.logging/java.util.logging.LogRecord$CallerFinder.lambda$get$1(LogRecord.java:784)
        at java.base/java.lang.StackStreamFactory$StackFrameTraverser.consumeFrames(StackStreamFactory.java:525)
        at java.base/java.lang.StackStreamFactory$AbstractStackWalker.doStackWalk(StackStreamFactory.java:328)
        at java.base/java.lang.StackStreamFactory$AbstractStackWalker.callStackWalk(Native Method)
        at java.base/java.lang.StackStreamFactory$AbstractStackWalker.beginStackWalk(StackStreamFactory.java:414)
        at java.base/java.lang.StackStreamFactory$AbstractStackWalker.walkHelper(StackStreamFactory.java:265)
        at java.base/java.lang.StackStreamFactory$AbstractStackWalker.walk(StackStreamFactory.java:257)
        at java.base/java.lang.StackWalker.walk(StackWalker.java:543)
        at java.logging/java.util.logging.LogRecord$CallerFinder.get(LogRecord.java:784)
        at java.logging/java.util.logging.LogRecord.inferCaller(LogRecord.java:757)
        at java.logging/java.util.logging.LogRecord.getSourceClassName(LogRecord.java:351)
        at java.logging/java.util.logging.SimpleFormatter.format(SimpleFormatter.java:163)
        at java.logging/java.util.logging.StreamHandler.publish0(StreamHandler.java:241)
        at java.logging/java.util.logging.StreamHandler.publish(StreamHandler.java:224)
        at java.logging/java.util.logging.ConsoleHandler.publish(ConsoleHandler.java:95)
```

The following part of the stack repeats often:

```
        at RuntimePermissionTest$TestSecurityManager.checkPermission(RuntimePermissionTest.java:88)
        at java.base/java.lang.Module.getClassLoader(Module.java:218)
        at java.base/java.security.AccessController.doPrivileged(AccessController.java:319)
        at java.base/java.lang.Class.forName(Class.java:622)
        at java.base/java.lang.Class.forName(Class.java:603)
        at java.base/sun.util.resources.Bundles.findBundleOf(Bundles.java:205)
        at java.base/sun.util.resources.Bundles.findBundleOf(Bundles.java:160)
        at java.base/sun.util.resources.Bundles.findBundleOf(Bundles.java:160)
        at java.base/sun.util.resources.Bundles.loadBundleOf(Bundles.java:145)
        at java.base/sun.util.resources.Bundles.of(Bundles.java:106)
        at java.base/sun.util.resources.LocaleData$1.run(LocaleData.java:185)
        at java.base/sun.util.resources.LocaleData$1.run(LocaleData.java:182)
        at java.base/java.security.AccessController.doPrivileged(AccessController.java:319)
        at java.base/sun.util.resources.LocaleData.getBundle(LocaleData.java:182)
        at java.base/sun.util.resources.LocaleData.getDateFormatData(LocaleData.java:145)
        at java.base/java.text.DateFormatSymbols.initializeData(DateFormatSymbols.java:745)
        at java.base/java.text.DateFormatSymbols.<init>(DateFormatSymbols.java:151)
        at java.base/sun.util.locale.provider.DateFormatSymbolsProviderImpl.getInstance(DateFormatSymbolsProviderImpl.java:85)
        at java.base/java.text.DateFormatSymbols.getProviderInstance(DateFormatSymbols.java:371)
        at java.base/java.text.DateFormatSymbols.getInstance(DateFormatSymbols.java:347)
        at java.base/java.util.Formatter$FormatSpecifier.print(Formatter.java:4411)
        at java.base/java.util.Formatter$FormatSpecifier.print(Formatter.java:4282)
        at java.base/java.util.Formatter$FormatSpecifier.printDateTime(Formatter.java:3105)
        at java.base/java.util.Formatter$FormatSpecifier.print(Formatter.java:3014)
        at java.base/java.util.Formatter.format(Formatter.java:2797)
        at java.base/java.util.Formatter.format(Formatter.java:2728)
        at java.base/java.lang.String.format(String.java:4386)
        at java.logging/java.util.logging.SimpleFormatter.format(SimpleFormatter.java:181)
        at java.logging/java.util.logging.StreamHandler.publish0(StreamHandler.java:241)
        at java.logging/java.util.logging.StreamHandler.publish(StreamHandler.java:224)
        at java.logging/java.util.logging.ConsoleHandler.publish(ConsoleHandler.java:95)
        at java.logging/java.util.logging.Logger.log(Logger.java:983)
        at java.logging/java.util.logging.Logger.doLog(Logger.java:1010)
        at java.logging/java.util.logging.Logger.log(Logger.java:1033)
        at java.logging/java.util.logging.Logger.info(Logger.java:1806)
        at RuntimePermissionTest$TestSecurityManager.checkPermission(RuntimePermissionTest.java:88)
```

...coming from here:

```

    static class TestSecurityManager extends SecurityManager {
        final boolean permitInetAddressResolver;

        public TestSecurityManager(boolean permitInetAddressResolver) {
            this.permitInetAddressResolver = permitInetAddressResolver;
            LOGGER.info("inetAddressResolverProvider permission is " +
                        (permitInetAddressResolver ? "granted" : "not granted"));
        }

        @Override
        public void checkPermission(Permission permission) {
            if (permission instanceof RuntimePermission) {
                LOGGER.info("Checking RuntimePermission: " + permission); // <---- !!!
                if (RUNTIME_PERMISSION_NAME.equals(permission.getName()) && !permitInetAddressResolver) {
                    LOGGER.info("Denying '" + RUNTIME_PERMISSION_NAME + "' permission");
                    throw new SecurityException("Access Denied: " + RUNTIME_PERMISSION_NAME);
                }
            }
        }
    }
```

So when we call for `LOGGER.info` from our custom security manager, it goes into formatter, which loads locale data, which causes class load, which goes back to this custom security manager, starting the loop again.

(It is confusing to see StackWalker at the top of the stack, but I suspect that is because we were able to recover from one SOE, and got hit by another.)
Comments
A pull request was submitted for review. URL: https://git.openjdk.org/jdk21u/pull/156 Date: 2023-09-13 07:26:57 +0000
13-09-2023

[jdk21u-fix-request] Approval Request from Aleksey Shipilëv
13-09-2023

Changeset: 947dee7f Author: Aleksey Shipilev <shade@openjdk.org> Date: 2023-09-12 18:13:55 +0000 URL: https://git.openjdk.org/jdk/commit/947dee7f2d5f7295ab7fc47c7823d0662d3c07ff
12-09-2023

A pull request was submitted for review. URL: https://git.openjdk.org/jdk/pull/15681 Date: 2023-09-12 11:32:46 +0000
12-09-2023

I believe this is the actual cause of JDK-8315640 now.
12-09-2023