Bouncycastle JSSE native IT test fails with latest Mandrel master #32680

jerboaa · 2023-04-17T12:48:25Z

Describe the bug

The bouncycastle JSSE integration test fails generating the native image due to a filedescriptor leak:

========================================================================================================================
GraalVM Native Image: Generating 'quarkus-integration-test-bouncycastle-jsse-999-SNAPSHOT-runner' (executable)...
========================================================================================================================
10:40:38,794 INFO  [org.bou.jss.pro.PropertyUtils] Found boolean security property [keystore.type.compat]: true
[1/8] Initializing...                                                                                    (9.5s @ 0.22GB)
 Java version: 17.0.7-beta+6-202304112331, vendor version: Mandrel-23.1.0-dev52226e97
 Graal compiler: optimization level: '2', target machine: 'x86-64-v3'
 C compiler: gcc (linux, x86_64, 11.3.0)
 Garbage collector: Serial GC (max heap size: 80% of RAM)
 4 user-specific feature(s)
 - io.quarkus.runner.Feature: Auto-generated class by Quarkus from the existing extensions
 - io.quarkus.runtime.graal.DisableLoggingFeature: Disables INFO logging during the analysis phase
 - io.quarkus.security.BouncyCastleFeature
 - org.eclipse.angus.activation.nativeimage.AngusActivationFeature
10:40:40,333 INFO  [org.bou.jss.pro.PropertyUtils] Found string system property [java.home]: /home/runner/work/mandrel/mandrel/openjdk
10:41:00,986 INFO  [org.bou.jss.pro.PropertyUtils] Found string security property [jdk.tls.disabledAlgorithms]: SSLv3, TLSv1, TLSv1.1, RC4, DES, MD5withRSA, DH keySize < 1024, EC keySize < 224, 3DES_EDE_CBC, anon, NULL
10:41:00,987 INFO  [org.bou.jss.pro.PropertyUtils] Found string security property [jdk.certpath.disabledAlgorithms]: MD2, MD5, SHA1 jdkCA & usage TLSServer, RSA keySize < 1024, DSA keySize < 1024, EC keySize < 224, SHA1 usage SignedJAR & denyAfter 2019-01-01
10:41:00,987 WARNING [org.bou.jss.pro.DisabledAlgorithmConstraints] Ignoring unsupported entry in 'jdk.certpath.disabledAlgorithms': SHA1 jdkCA & usage TLSServer
10:41:00,988 WARNING [org.bou.jss.pro.DisabledAlgorithmConstraints] Ignoring unsupported entry in 'jdk.certpath.disabledAlgorithms': SHA1 usage SignedJAR & denyAfter 2019-01-01
10:41:50,938 INFO  [org.bou.jss.pro.PropertyUtils] Found string system property [java.home]: /home/runner/work/mandrel/mandrel/openjdk
10:41:50,995 INFO  [org.bou.jss.pro.PropertyUtils] Found string system property [java.home]: /home/runner/work/mandrel/mandrel/openjdk
10:41:51,054 INFO  [org.bou.jss.pro.PropertyUtils] Found string system property [java.home]: /home/runner/work/mandrel/mandrel/openjdk
[2/8] Performing analysis...  [******]                                                                  (99.7s @ 2.15GB)
  14,875 (88.79%) of 16,753 types reachable
  22,531 (62.50%) of 36,049 fields reachable
  75,322 (59.60%) of 126,371 methods reachable
   5,159 types,   187 fields, and 3,639 methods registered for reflection
      63 types,    68 fields, and    55 methods registered for JNI access
       4 native libraries: dl, pthread, rt, z

Error: Detected a FileDescriptor in the image heap. File descriptors opened during image generation are no longer open at image runtime, and the files might not even be present anymore at image runtime.  To see how this object got instantiated use --trace-object-instantiation=java.io.FileDescriptor. The object was probably created by a class initializer and is reachable from a static field. You can request class initialization at image runtime by using the option --initialize-at-run-time=<class-name>. Or you can write your own initialization methods and call them explicitly from your main entry point.
Detailed message:
Trace: Object was reached by
------------------------------------------------------------------------------------------------------------------------
  reading field java.io.FileInputStream.fd of constant 
    java.io.FileInputStream@16df1296: java.io.FileInputStream@16df1296
                        6.6s (6.0% of total time) in 29 GCs | Peak RSS: 3.02GB | CPU load: 1.97
------------------------------------------------------------------------------------------------------------------------
Produced artifacts:
 /home/runner/work/mandrel/mandrel/quarkus/integration-tests/bouncycastle-jsse/target/quarkus-integration-test-bouncycastle-jsse-999-SNAPSHOT-native-image-source-jar/quarkus-integration-test-bouncycastle-jsse-999-SNAPSHOT-runner-build-output-stats.json (build_info)
========================================================================================================================
Finished generating 'quarkus-integration-test-bouncycastle-jsse-999-SNAPSHOT-runner' in 1m 49s.
  reading field java.io.FilterInputStream.in of constant 
    java.io.BufferedInputStream@293aa06e: java.io.BufferedInputStream@293aa06e
  reading field org.bouncycastle.jcajce.provider.drbg.DRBG$URLSeededEntropySourceProvider.seedStream of constant 
    org.bouncycastle.jcajce.provider.drbg.DRBG$URLSeededEntropySourceProvider@1fc5c44a: org.bouncycastle.jcajce.provider.drbg.DRBG$URLSeededEntropySourceProvider@1fc5c4...
  reading field org.bouncycastle.jcajce.provider.drbg.DRBG$URLSeededEntropySourceProvider$3.this$0 of constant 
    org.bouncycastle.jcajce.provider.drbg.DRBG$URLSeededEntropySourceProvider$3@2c8e24e4: org.bouncycastle.jcajce.provider.drbg.DRBG$URLSeededEntropySourceProvider$3@2c8e...
  reading field org.bouncycastle.jcajce.provider.drbg.DRBG$HybridEntropySource$SignallingEntropySource$EntropyGatherer.baseRandom of constant 
    org.bouncycastle.jcajce.provider.drbg.DRBG$HybridEntropySource$SignallingEntropySource$EntropyGatherer@50530460: org.bouncycastle.jcajce.provider.drbg.DRBG$HybridEntropySource$SignallingEntropy...
  reading field java.util.concurrent.ConcurrentLinkedDeque$Node.item of constant 
    java.util.concurrent.ConcurrentLinkedDeque$Node@7acc2c7f: java.util.concurrent.ConcurrentLinkedDeque$Node@7acc2c7f
  reading field java.util.concurrent.ConcurrentLinkedDeque.tail of constant 
    java.util.concurrent.ConcurrentLinkedDeque@251ed6ca: []
  reading field org.bouncycastle.jcajce.provider.drbg.DRBG$EntropyDaemon.tasks of constant 
    org.bouncycastle.jcajce.provider.drbg.DRBG$EntropyDaemon@5234afd: org.bouncycastle.jcajce.provider.drbg.DRBG$EntropyDaemon@5234afd
  reading static field org.bouncycastle.jcajce.provider.drbg.DRBG.entropyDaemon
    at org.bouncycastle.jcajce.provider.drbg.DRBG.createBaseRandom(Unknown Source)
  parsing method org.bouncycastle.jcajce.provider.drbg.DRBG.createBaseRandom(Unknown Source) reachable via the parsing context
    at org.bouncycastle.jcajce.provider.drbg.DRBG$Default.<clinit>(Unknown Source)
    at static root method.(Unknown Source)


com.oracle.svm.core.util.UserError$UserException: Detected a FileDescriptor in the image heap. File descriptors opened during image generation are no longer open at image runtime, and the files might not even be present anymore at image runtime.  To see how this object got instantiated use --trace-object-instantiation=java.io.FileDescriptor. The object was probably created by a class initializer and is reachable from a static field. You can request class initialization at image runtime by using the option --initialize-at-run-time=<class-name>. Or you can write your own initialization methods and call them explicitly from your main entry point.
Detailed message:
Trace: Object was reached by
  reading field java.io.FileInputStream.fd of constant 
    java.io.FileInputStream@16df1296: java.io.FileInputStream@16df1296
  reading field java.io.FilterInputStream.in of constant 
    java.io.BufferedInputStream@293aa06e: java.io.BufferedInputStream@293aa06e
  reading field org.bouncycastle.jcajce.provider.drbg.DRBG$URLSeededEntropySourceProvider.seedStream of constant 
    org.bouncycastle.jcajce.provider.drbg.DRBG$URLSeededEntropySourceProvider@1fc5c44a: org.bouncycastle.jcajce.provider.drbg.DRBG$URLSeededEntropySourceProvider@1fc5c4...
  reading field org.bouncycastle.jcajce.provider.drbg.DRBG$URLSeededEntropySourceProvider$3.this$0 of constant 
    org.bouncycastle.jcajce.provider.drbg.DRBG$URLSeededEntropySourceProvider$3@2c8e24e4: org.bouncycastle.jcajce.provider.drbg.DRBG$URLSeededEntropySourceProvider$3@2c8e...
  reading field org.bouncycastle.jcajce.provider.drbg.DRBG$HybridEntropySource$SignallingEntropySource$EntropyGatherer.baseRandom of constant 
    org.bouncycastle.jcajce.provider.drbg.DRBG$HybridEntropySource$SignallingEntropySource$EntropyGatherer@50530460: org.bouncycastle.jcajce.provider.drbg.DRBG$HybridEntropySource$SignallingEntropy...
  reading field java.util.concurrent.ConcurrentLinkedDeque$Node.item of constant 
    java.util.concurrent.ConcurrentLinkedDeque$Node@7acc2c7f: java.util.concurrent.ConcurrentLinkedDeque$Node@7acc2c7f
  reading field java.util.concurrent.ConcurrentLinkedDeque.tail of constant 
    java.util.concurrent.ConcurrentLinkedDeque@251ed6ca: []
  reading field org.bouncycastle.jcajce.provider.drbg.DRBG$EntropyDaemon.tasks of constant 
    org.bouncycastle.jcajce.provider.drbg.DRBG$EntropyDaemon@5234afd: org.bouncycastle.jcajce.provider.drbg.DRBG$EntropyDaemon@5234afd
  reading static field org.bouncycastle.jcajce.provider.drbg.DRBG.entropyDaemon
    at org.bouncycastle.jcajce.provider.drbg.DRBG.createBaseRandom(Unknown Source)
  parsing method org.bouncycastle.jcajce.provider.drbg.DRBG.createBaseRandom(Unknown Source) reachable via the parsing context
    at org.bouncycastle.jcajce.provider.drbg.DRBG$Default.<clinit>(Unknown Source)
    at static root method.(Unknown Source)


	at org.graalvm.nativeimage.builder/com.oracle.svm.core.util.UserError.abort(UserError.java:85)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.FallbackFeature.reportAsFallback(FallbackFeature.java:248)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator.runPointsToAnalysis(NativeImageGenerator.java:803)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator.doRun(NativeImageGenerator.java:582)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator.run(NativeImageGenerator.java:539)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGeneratorRunner.buildImage(NativeImageGeneratorRunner.java:407)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGeneratorRunner.build(NativeImageGeneratorRunner.java:611)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGeneratorRunner.start(NativeImageGeneratorRunner.java:133)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGeneratorRunner.main(NativeImageGeneratorRunner.java:93)
Caused by: com.oracle.graal.pointsto.constraints.UnsupportedFeatureException: Detected a FileDescriptor in the image heap. File descriptors opened during image generation are no longer open at image runtime, and the files might not even be present anymore at image runtime.  To see how this object got instantiated use --trace-object-instantiation=java.io.FileDescriptor. The object was probably created by a class initializer and is reachable from a static field. You can request class initialization at image runtime by using the option --initialize-at-run-time=<class-name>. Or you can write your own initialization methods and call them explicitly from your main entry point.
Detailed message:
Trace: Object was reached by
  reading field java.io.FileInputStream.fd of constant 
    java.io.FileInputStream@16df1296: java.io.FileInputStream@16df1296
  reading field java.io.FilterInputStream.in of constant 
    java.io.BufferedInputStream@293aa06e: java.io.BufferedInputStream@293aa06e
  reading field org.bouncycastle.jcajce.provider.drbg.DRBG$URLSeededEntropySourceProvider.seedStream of constant 
    org.bouncycastle.jcajce.provider.drbg.DRBG$URLSeededEntropySourceProvider@1fc5c44a: org.bouncycastle.jcajce.provider.drbg.DRBG$URLSeededEntropySourceProvider@1fc5c4...
  reading field org.bouncycastle.jcajce.provider.drbg.DRBG$URLSeededEntropySourceProvider$3.this$0 of constant 
    org.bouncycastle.jcajce.provider.drbg.DRBG$URLSeededEntropySourceProvider$3@2c8e24e4: org.bouncycastle.jcajce.provider.drbg.DRBG$URLSeededEntropySourceProvider$3@2c8e...
  reading field org.bouncycastle.jcajce.provider.drbg.DRBG$HybridEntropySource$SignallingEntropySource$EntropyGatherer.baseRandom of constant 
    org.bouncycastle.jcajce.provider.drbg.DRBG$HybridEntropySource$SignallingEntropySource$EntropyGatherer@50530460: org.bouncycastle.jcajce.provider.drbg.DRBG$HybridEntropySource$SignallingEntropy...
  reading field java.util.concurrent.ConcurrentLinkedDeque$Node.item of constant 
    java.util.concurrent.ConcurrentLinkedDeque$Node@7acc2c7f: java.util.concurrent.ConcurrentLinkedDeque$Node@7acc2c7f
  reading field java.util.concurrent.ConcurrentLinkedDeque.tail of constant 
    java.util.concurrent.ConcurrentLinkedDeque@251ed6ca: []
  reading field org.bouncycastle.jcajce.provider.drbg.DRBG$EntropyDaemon.tasks of constant 
    org.bouncycastle.jcajce.provider.drbg.DRBG$EntropyDaemon@5234afd: org.bouncycastle.jcajce.provider.drbg.DRBG$EntropyDaemon@5234afd
  reading static field org.bouncycastle.jcajce.provider.drbg.DRBG.entropyDaemon
    at org.bouncycastle.jcajce.provider.drbg.DRBG.createBaseRandom(Unknown Source)
  parsing method org.bouncycastle.jcajce.provider.drbg.DRBG.createBaseRandom(Unknown Source) reachable via the parsing context
    at org.bouncycastle.jcajce.provider.drbg.DRBG$Default.<clinit>(Unknown Source)
    at static root method.(Unknown Source)


	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.constraints.UnsupportedFeatures.report(UnsupportedFeatures.java:126)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator.runPointsToAnalysis(NativeImageGenerator.java:798)
	... 6 more

Expected behavior

Native image generation passes

Actual behavior

Fails due to a file descriptor leak

How to Reproduce?

Run the bouncycastle-jsse integration test from quarkus in native mode.

Output of `uname -a` or `ver`

No response

Output of `java -version`

No response

GraalVM version (if different from Java)

graalvm master

Quarkus version or git rev

main

Build tool (ie. output of `mvnw --version` or `gradlew --version`)

No response

Additional information

See the CI failure here:
https://github.com/graalvm/mandrel/actions/runs/4719124540/jobs/8370028509#step:11:481

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

quarkus-bot · 2023-04-17T12:48:28Z

/cc @Karm (mandrel), @galderz (mandrel), @zakkak (mandrel)

jerboaa · 2023-04-17T12:49:23Z

/cc @sberyozkin

sberyozkin · 2023-04-17T13:09:22Z

This DRBG class has

private static EntropySourceProvider createCoreEntropySourceProvider()
    {
        if (Security.getProperty("securerandom.source") == null)
        {
            return createInitialEntropySource();
        }
        else
        {
            try
            {
                String source = Security.getProperty("securerandom.source");

                return new URLSeededEntropySourceProvider(new URL(source));
            }
            catch (Exception e)
            {
                return createInitialEntropySource();
            }
        }
    }

where URLSeededEntropySourceProvider has an InputStream var.

I guess we can fix it with a substitution like this:

private static EntropySourceProvider createCoreEntropySourceProvider()
    {
        String source = Security.getProperty("securerandom.source");
        if (source != null) {
            // throw exception - the custom random source is not supported
        }
        return createInitialEntropySource();
    }

I can give it a try if it makes sense

jerboaa · 2023-04-17T13:18:57Z

Or make URLSeededEntropySourceProvider runtime-initialized. Not sure how feasible that is.

jerboaa · 2023-04-17T16:26:33Z

We only see this occasionally in CI, which seems to indicate that it's entropy availability related. Would that make sense, @sberyozkin ?

Fails:
https://github.com/graalvm/mandrel/actions/runs/4642679968/jobs/8283780013#step:11:522
https://github.com/graalvm/mandrel/actions/runs/4719124540/jobs/8370028509#step:11:481

Pass:
https://github.com/graalvm/mandrel/actions/runs/4705326599/jobs/8345995601#step:11:452

sberyozkin · 2023-04-17T16:33:34Z

Hi @jerboaa Interesting, it would explain the randomness

jerboaa · 2023-04-18T18:14:31Z

Should be fixed with: #32683

jerboaa added the kind/bug Something isn't working label Apr 17, 2023

quarkus-bot bot added the area/mandrel label Apr 17, 2023

jerboaa mentioned this issue Apr 17, 2023

[CI] Quarkus main fails with Java 17 mandrel build of graal/master on Linux graalvm/mandrel#399

Closed

jerboaa mentioned this issue Apr 17, 2023

Reinitialize BouncyCastle DRBG URLSeededEntropySourceProvider at runtime #32683

Merged

jerboaa closed this as completed Apr 18, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Bouncycastle JSSE native IT test fails with latest Mandrel master #32680

Bouncycastle JSSE native IT test fails with latest Mandrel master #32680

jerboaa commented Apr 17, 2023

quarkus-bot bot commented Apr 17, 2023

jerboaa commented Apr 17, 2023

sberyozkin commented Apr 17, 2023

jerboaa commented Apr 17, 2023

jerboaa commented Apr 17, 2023

sberyozkin commented Apr 17, 2023

jerboaa commented Apr 18, 2023

Bouncycastle JSSE native IT test fails with latest Mandrel master #32680

Bouncycastle JSSE native IT test fails with latest Mandrel master #32680

Comments

jerboaa commented Apr 17, 2023

Describe the bug

Expected behavior

Actual behavior

How to Reproduce?

Output of uname -a or ver

Output of java -version

GraalVM version (if different from Java)

Quarkus version or git rev

Build tool (ie. output of mvnw --version or gradlew --version)

Additional information

quarkus-bot bot commented Apr 17, 2023

jerboaa commented Apr 17, 2023

sberyozkin commented Apr 17, 2023

jerboaa commented Apr 17, 2023

jerboaa commented Apr 17, 2023

sberyozkin commented Apr 17, 2023

jerboaa commented Apr 18, 2023

Output of `uname -a` or `ver`

Output of `java -version`

Build tool (ie. output of `mvnw --version` or `gradlew --version`)