[CI] Java 11 access denied ("java.lang.RuntimePermission" "accessDeclaredMembers") #62143

ywangd · 2020-09-09T04:52:18Z

Build scan:

https://gradle-enterprise.elastic.co/s/z7fblrycg74eg
https://gradle-enterprise.elastic.co/s/yuuetchn2vphe
https://gradle-enterprise.elastic.co/s/4ny7cszczftjg
https://gradle-enterprise.elastic.co/s/sk567oqltygnu
And many more that uses different variants of JDK 11.

Repro line:

./gradlew ':server:test' --tests "org.elasticsearch.index.codec.CodecTests.testBestCompression" -Dtests.seed=7E21C06936079E14 -Dtests.security.manager=true -Dtests.locale=is -Dtests.timezone=America/Ensenada -Druntime.java=11

Reproduces locally?:
Yes. There are more than 90 failed tests for each build scan. So muting is not an option. The failure is JDK 11 specific, i.e. if removing -Druntime.java=11 from the reproduction line, the test works.

Applicable branches:
master and 7.x

Failure history:
It just started to happen since 2020-09-05

Failure excerpt:

java.security.AccessControlException: access denied ("java.lang.RuntimePermission" "accessDeclaredMembers") |  

at __randomizedtesting.SeedInfo.seed([7E21C06936079E14:4A7EB7FED693B2BB]:0) |  
-- | --
  |   | at java.security.AccessControlContext.checkPermission(AccessControlContext.java:472) |  
  |   | at java.security.AccessController.checkPermission(AccessController.java:897) |  
  |   | at java.lang.SecurityManager.checkPermission(SecurityManager.java:322) |  
  |   | at java.lang.Class.checkMemberAccess(Class.java:2847) |  
  |   | at java.lang.Class.getDeclaredMethod(Class.java:2471) |  
  |   | at java.util.zip.Deflater$DeflaterZStreamRef.get(Deflater.java:991) |  
  |   | at java.util.zip.Deflater.<init>(Deflater.java:207) |  
  |   | at org.apache.lucene.codecs.lucene87.BugfixDeflater_JDK8252739.<init>(BugfixDeflater_JDK8252739.java:53) |  
  |   | at org.apache.lucene.codecs.lucene87.BugfixDeflater_JDK8252739.createDeflaterInstance(BugfixDeflater_JDK8252739.java:43) |  
  |   | at org.apache.lucene.codecs.lucene87.DeflateWithPresetDictCompressionMode$DeflateWithPresetDictCompressor.<init>(DeflateWithPresetDictCompressionMode.java:164) |  
  |   | at org.apache.lucene.codecs.lucene87.DeflateWithPresetDictCompressionMode.newCompressor(DeflateWithPresetDictCompressionMode.java:55) |  
  |   | at org.apache.lucene.codecs.compressing.CompressingStoredFieldsWriter.<init>(CompressingStoredFieldsWriter.java:107) |  
  |   | at org.apache.lucene.codecs.compressing.CompressingStoredFieldsFormat.fieldsWriter(CompressingStoredFieldsFormat.java:130) |  
  |   | at org.apache.lucene.codecs.lucene87.Lucene87StoredFieldsFormat.fieldsWriter(Lucene87StoredFieldsFormat.java:141) |  
  |   | at org.apache.lucene.index.StoredFieldsConsumer.initStoredFieldsWriter(StoredFieldsConsumer.java:39) |  
  |   | at org.apache.lucene.index.StoredFieldsConsumer.startDocument(StoredFieldsConsumer.java:46) |  
  |   | at org.apache.lucene.index.DefaultIndexingChain.startStoredFields(DefaultIndexingChain.java:426) |  
  |   | at org.apache.lucene.index.DefaultIndexingChain.processDocument(DefaultIndexingChain.java:462) |  
  |   | at org.apache.lucene.index.DocumentsWriterPerThread.updateDocuments(DocumentsWriterPerThread.java:233) |  
  |   | at org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:419) |  
  |   | at org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:1470) |  
  |   | at org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:1756) |  
  |   | at org.apache.lucene.index.IndexWriter.addDocument(IndexWriter.java:1399) |  
  |   | at org.elasticsearch.index.codec.CodecTests.assertCompressionEquals(CodecTests.java:76) |  
  |   | at org.elasticsearch.index.codec.CodecTests.testBestCompression(CodecTests.java:67) |  
  |   | at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) |  
  |   | at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) |  
  |   | at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) |  
  |   | at java.lang.reflect.Method.invoke(Method.java:566) |  
  |   | at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1758) |  
  |   | at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:946) |  
  |   | at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:982) |  
  |   | at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:996) |  
  |   | at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) |  
  |   | at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) |  
  |   | at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) |  
  |   | at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) |  
  |   | at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) |  
  |   | at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) |  
  |   | at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) |  
  |   | at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:375) |  
  |   | at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:824) |  
  |   | at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:475) |  
  |   | at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:955) |  
  |   | at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:840) |  
  |   | at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:891) |  
  |   | at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:902) |  
  |   | at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) |  
  |   | at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) |  
  |   | at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) |  
  |   | at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) |  
  |   | at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) |  
  |   | at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) |  
  |   | at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) |  
  |   | at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) |  
  |   | at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) |  
  |   | at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) |  
  |   | at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) |  
  |   | at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) |  
  |   | at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:375) |  
  |   | at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:831) |  
  |   | at java.lang.Thread.run(Thread.java:834)

The text was updated successfully, but these errors were encountered:

elasticmachine · 2020-09-09T04:52:19Z

Pinging @elastic/es-core-infra (:Core/Infra/Core)

ywangd · 2020-09-09T05:14:18Z

@iverase Git bisect shows that the issue in introduced by the Lucene version upgrade with commit e236054

ywangd · 2020-09-09T05:41:51Z

Some more digging based on the stacktrace:

Lucene Apache Lucene recently changed in its master branch to use Inflater/Deflater's ability to provide a custom dictionary.
Deflater code in Java 11 internally uses reflection. This code is introduced since JDK 10.
Since JDK 12, the above usage of reflection is removed.

So in theory, this error should happen for both JDK 10 and 11. But somehow, the tests do not fail for JDK 10. Only JDK 11 has this problem. I guess a possible fix is grant lucene code more security permissions. I could use help from Lucene experts to comment on this.

iverase · 2020-09-09T05:58:33Z

Thanks @ywangd for the investigation. The piece of code that is hitting the error was newly introduced as a work around of a Java bug. The Lucene issue is here:

https://issues.apache.org/jira/browse/LUCENE-9500

And the java bug is here:

https://bugs.openjdk.java.net/browse/JDK-8252739

It makes sense that it fails in JDK11 but not in JDK10 because the bug is only present in 11 (and not all versions). So it seems the error happens when trying to initialise the BugfixDeflater_JDK8252739 class.

iverase · 2020-09-09T08:57:33Z

One thing I notice is that if I add the following line to the security.policy:

//// Everything else:

grant {
  permission java.lang.RuntimePermission "accessDeclaredMembers";
  ....

The error goes away. On the other hand my expectations is that the following block should fix it:

grant codeBase "${codebase.lucene-core}" {
  // needed to allow MMapDirectory's "unmap hack" (die unmap hack, die)
  // java 8 package
  permission java.lang.RuntimePermission "accessClassInPackage.sun.misc";
  // java 9 "package"
  permission java.lang.RuntimePermission "accessClassInPackage.jdk.internal.ref";
  permission java.lang.reflect.ReflectPermission "suppressAccessChecks";
  // NOTE: also needed for RAMUsageEstimator size calculations
  permission java.lang.RuntimePermission "accessDeclaredMembers";
};

As it is granting the permission to the Lucene-core jar, but not sure if I am reading this correctly.

iverase · 2020-09-09T10:08:43Z

This seems to be a Lucene bug. We open:

https://issues.apache.org/jira/browse/LUCENE-9517

ywangd · 2020-09-09T13:56:39Z

This seems to be a Lucene bug. We open:

https://issues.apache.org/jira/browse/LUCENE-9517

Thanks! I know close to nothing about Lucene, but now I believe this is the right fix. Without a doPrivileged block, the permission check is performed across the whole call stack. This basically means that you have to grant accessDeclaredMembers to everything to make it work as shown in your previous comment and it feels wrong.

ywangd added :Core/Infra/Core Core issues without another label >test-failure Triaged test failures from CI labels Sep 9, 2020

elasticmachine added the Team:Core/Infra Meta label for core/infra team label Sep 9, 2020

ywangd assigned iverase and unassigned iverase Sep 9, 2020

ywangd mentioned this issue Sep 9, 2020

[CI] FollowIndexIT.testFollowIndex and AutoFollowIT.testAutoFollowPatterns failures #62142

Closed

ywangd assigned iverase Sep 9, 2020

iverase mentioned this issue Sep 10, 2020

upgrade to lucene-8.7.0-snapshot-b313618cc1d #62213

Merged

iverase closed this as completed in #62213 Sep 10, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[CI] Java 11 access denied ("java.lang.RuntimePermission" "accessDeclaredMembers") #62143

[CI] Java 11 access denied ("java.lang.RuntimePermission" "accessDeclaredMembers") #62143

ywangd commented Sep 9, 2020 •

edited

Loading

elasticmachine commented Sep 9, 2020

ywangd commented Sep 9, 2020

ywangd commented Sep 9, 2020

iverase commented Sep 9, 2020 •

edited

Loading

iverase commented Sep 9, 2020 •

edited

Loading

iverase commented Sep 9, 2020

ywangd commented Sep 9, 2020

[CI] Java 11 access denied ("java.lang.RuntimePermission" "accessDeclaredMembers") #62143

[CI] Java 11 access denied ("java.lang.RuntimePermission" "accessDeclaredMembers") #62143

Comments

ywangd commented Sep 9, 2020 • edited Loading

elasticmachine commented Sep 9, 2020

ywangd commented Sep 9, 2020

ywangd commented Sep 9, 2020

iverase commented Sep 9, 2020 • edited Loading

iverase commented Sep 9, 2020 • edited Loading

iverase commented Sep 9, 2020

ywangd commented Sep 9, 2020

ywangd commented Sep 9, 2020 •

edited

Loading

iverase commented Sep 9, 2020 •

edited

Loading

iverase commented Sep 9, 2020 •

edited

Loading