JDK-8205507 : jdk/javax/xml/crypto/dsig/GenerationTests.java timed out
  • Type: Enhancement
  • Component: security-libs
  • Sub-Component: javax.xml.crypto
  • Affected Version: 8,11
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • OS: solaris
  • CPU: sparc
  • Submitted: 2018-06-22
  • Updated: 2020-11-25
  • Resolved: 2018-09-11
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 11 JDK 12 JDK 8 Other
11.0.2Fixed 12 b11Fixed 8u231Fixed openjdk8u282Fixed
Related Reports
Relates :  
JDK-8235603 - 8u231 Transform of DOM to byte array adds ASCII carriage return to signed XML
Sub Tasks
JDK-8210338 :  
Better output for GenerationTests.java - Resolved
Description
The test timed out in a recent CI job (3100+ seconds for a single test seems excessive):

ACTION: main -- Error. Program `jdk-11/bin/java' timed out (timeout set to 3000000ms, elapsed time including timeout handling was 3106779ms).
REASON: User specified action: run main/othervm/timeout=300 GenerationTests 
TIME:   3106.804 seconds
messages:
command: main GenerationTests
reason: User specified action: run main/othervm/timeout=300 GenerationTests 
Mode: othervm [/othervm specified]
Additional options from @modules: --add-modules java.base,java.xml.crypto,jdk.httpserver --add-exports java.base/sun.security.util=ALL-UNNAMED --add-exports java.base/sun.security.x509=ALL-UNNAMED --add-exports java.xml.crypto/org.jcp.xml.dsig.internal.dom=ALL-UNNAMED --add-exports jdk.httpserver/com.sun.net.httpserver=ALL-UNNAMED
Timeout information:
--- Timeout information end.
elapsed time (seconds): 3106.804
Comments
8u review approval: https://mail.openjdk.java.net/pipermail/jdk8u-dev/2020-November/013084.html.
25-11-2020
JDK-8177334 has been backported to 8u, see JDK-8251911. Continuation review thread: https://mail.openjdk.java.net/pipermail/jdk8u-dev/2020-November/013059.html
25-11-2020
While I agree they should ideally not be flagged until after review, going around removing them all isn't helpful. Restored.
22-07-2020
Removing the jdk8u-fix-request label until JDK-8177334 is integrated. Feel free to re-apply the label when that's the case. It makes looking at the approval queue easier.
21-07-2020
Depends on JDK-8177334
18-02-2020
Fix Request (jdk8u) I'd like to request an approval for the jdk8u backport of this enhancement. Low risk (test only). Patch does not apply cleanly but a review has been requested at https://mail.openjdk.java.net/pipermail/jdk8u-dev/2019-August/009946.html
05-08-2019
Ohh! Yeah, I missed that one. Thanks for pointing that out.
19-09-2018
Sorry, I might not be clear enough. The "updated again" meant fix for JDK-8210736.
19-09-2018
Here are 3 previous runs without the patch that passed: -------------------------------------------------- TEST: javax/xml/crypto/dsig/GenerationTests.java compile: 0.268 seconds build: 0.0 seconds main: 1138.369 seconds TEST RESULT: Passed. Execution successful -------------------------------------------------- -------------------------------------------------- TEST: javax/xml/crypto/dsig/GenerationTests.java compile: 0.284 seconds build: 0.0 seconds main: 1133.436 seconds TEST RESULT: Passed. Execution successful -------------------------------------------------- -------------------------------------------------- TEST: javax/xml/crypto/dsig/GenerationTests.java compile: 0.213 seconds build: 0.0 seconds main: 1135.764 seconds TEST RESULT: Passed. Execution successful -------------------------------------------------- So we barely make it. I'll backport the patch because it seems to help.
19-09-2018
I ran 3 more CI jobs with this patch and all 3 passed: -------------------------------------------------- TEST: javax/xml/crypto/dsig/GenerationTests.java compile: 0.285 seconds build: 0.0 seconds main: 1009.584 seconds TEST RESULT: Passed. Execution successful -------------------------------------------------- -------------------------------------------------- TEST: javax/xml/crypto/dsig/GenerationTests.java compile: 0.252 seconds build: 0.0 seconds main: 1008.819 seconds TEST RESULT: Passed. Execution successful -------------------------------------------------- -------------------------------------------------- TEST: javax/xml/crypto/dsig/GenerationTests.java compile: 0.289 seconds build: 0.0 seconds main: 1010.336 seconds TEST RESULT: Passed. Execution successful -------------------------------------------------- But that's far away from 3-4 minutes. Note that we are talking about fastdebug builds here. Here is one run without the patch that failed: ACTION: main -- Error. Program `/data/jenkins/workspace/jdk11-nightly-centos7-fastdebug-c2/usr/lib/jvm/java-fastdebug-11-twitter/bin/java' timed out (timeout set to 1200000ms, elapsed time including timeout handling was 1266969ms). REASON: User specified action: run main/othervm/timeout=300 GenerationTests TIME: 1266.972 seconds
19-09-2018
[~twisti] I've updated the test again and now it runs fast on Linux also. On all platforms, it should finish within 3~4 minutes.
17-09-2018
No, not in a submit job but in our Twitter nightly test runs.
17-09-2018
But it shows "STATUS: Passed". Maybe jtreg sees the timeout and decide to kill it but it still has time to finish itself but jtreg didn't notice it? Anyway, did you see this in a submit job? Is there a job id?
11-09-2018
Oh, and no, the test does not pass.
10-09-2018
Yes, the warning is fine. I *think* the actual problem is the: Timeout refired 1200 times
10-09-2018
[~twisti] The test run succeeds. The "[Fatal Error]" line is expected. I haven't seen the VM warning before. It's just a warning, right? No sure what "Timeout refired 1200 times" means.
10-09-2018
What's the error message? We are seeing something like this: * Generating signature-reference-dependency.xml * Generating signature-with-attr-in-no-namespace.xml * Generating signature-with-empty-id.xml Timeout refired 1200 times -SV-SV-SV... <thousands of these SV> ...-SV-SV-SV-S-S-S-S-S-S STDERR: OpenJDK 64-Bit Server VM warning: Option UseConcMarkSweepGC was deprecated in version 9.0 and will likely be removed in a future release. OpenJDK 64-Bit Server VM warning: Option UseConcMarkSweepGC was deprecated in version 9.0 and will likely be removed in a future release. [Fatal Error] :1:1: Content is not allowed in prolog. STATUS:Passed.
10-09-2018
Cached the keys (not hardcoded). Looks much better. Code review requested at http://mail.openjdk.java.net/pipermail/security-dev/2018-September/018130.html.
08-09-2018
I can see 3 possible reasons: 1. entropy exhaustion: Try to reimplement the SecureRandom to something fast. For example, based on java.math.Random. 2. key generation slowness: in test_create_detached_signature0(), consider using hardcoded keys like those getXXXKey() methods. 3. network blocking at "try (Http server = Http.startServer())". Not sure why but I do see logs stuck here with a timeout. Maybe just try one by one and see if any can solve the issue.
28-08-2018