Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-8321276

runtime/cds/appcds/dynamicArchive/DynamicSharedSymbols.java failed with "'17 2: jdk/test/lib/apps ' missing from stdout/stderr"

XMLWordPrintable

    • b27
    • generic
    • generic
    • Verified

        The following test failed in the JDK22 CI:

        runtime/cds/appcds/dynamicArchive/DynamicSharedSymbols.java

        Here's a snippet from the log file:

        #section:main
        ----------messages:(6/420)----------
        command: main -XX:+UnlockDiagnosticVMOptions -XX:+WhiteBoxAPI -Xbootclasspath/a:./WhiteBox.jar DynamicSharedSymbols
        reason: User specified action: run main/othervm/timeout=500 -XX:+UnlockDiagnosticVMOptions -XX:+WhiteBoxAPI -Xbootclasspath/a:./WhiteBox.jar DynamicSharedSymbols
        started: Mon Dec 04 13:31:01 UTC 2023
        Mode: othervm [/othervm specified]
        finished: Mon Dec 04 13:31:06 UTC 2023
        elapsed time (seconds): 5.78
        ----------configuration:(0/0)----------
        ----------System.out:(99/10964)----------
        Command line: ['/opt/mach5/mesos/work_dir/jib-master/install/jdk-22+27-2180/linux-x64-debug.jdk/jdk-22/fastdebug/bin/java' '-XX:MaxRAMPercentage=4.16667' '-Dtest.boot.jdk=/opt/mach5/mesos/work_dir/jib-master/install/jdk/21/35/bundles/linux-x64/jdk-21_linux-x64_bin.tar.gz/jdk-21' '-Djava.io.tmpdir=/opt/mach5/mesos/work_dir/slaves/afbc6042-3a24-4198-9369-18c663a3f74c-S21881/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/cd54aced-0e33-4a0f-a255-f1fd56fccb9c/runs/9d82a49e-b64d-4c3a-b4db-9bf2bae87dff/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_tier2_runtime/tmp' '-XX:ArchiveClassesAtExit=/opt/mach5/mesos/work_dir/slaves/afbc6042-3a24-4198-9369-18c663a3f74c-S21881/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/cd54aced-0e33-4a0f-a255-f1fd56fccb9c/runs/9d82a49e-b64d-4c3a-b4db-9bf2bae87dff/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_tier2_runtime/scratch/0/top-13h31m01s785.jsa' '-Xlog:cds,cds+dynamic=info' '-cp' '/opt/mach5/mesos/work_dir/slaves/afbc6042-3a24-4198-9369-18c663a3f74c-S21881/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/cd54aced-0e33-4a0f-a255-f1fd56fccb9c/runs/9d82a49e-b64d-4c3a-b4db-9bf2bae87dff/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_tier2_runtime/scratch/0/loadclass.jar' 'JCmdTestLingeredApp' '563c8be6-3359-499f-b6cb-c91a0eb51391.lck']
        LingeredApp startup took 1231ms
        Check for hs_err_pid/core/mdmp files:
        None.
         LingeredApp stdout: [[0.059s][info][cds] trying to map /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+27-2180/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/classes.jsa
        [0.059s][info][cds] Opened archive /opt/mach5/mesos/work_dir/jib-master/install/jdk-22+27-2180/linux-x64-debug.jdk/jdk-22/fastdebug/lib/server/classes.jsa.
        [0.059s][info][cds] Archive was created with UseCompressedOops = 1, UseCompressedClassPointers = 1
        [0.059s][info][cds] Core region alignment: 4096
        [0.059s][info][cds] Reserved archive_space_rs [0x0000000800000000 - 0x0000000801000000] (16777216) bytes
        [0.059s][info][cds] Reserved class_space_rs [0x0000000801000000 - 0x0000000841000000] (1073741824) bytes
        [0.059s][info][cds] Mapped static region #0 at base 0x0000000800000000 top 0x000000080050e000 (ReadWrite)
        [0.059s][info][cds] Mapped static region #1 at base 0x000000080050e000 top 0x0000000800d40000 (ReadOnly)
        [0.059s][info][cds] ArchiveRelocationMode == 1: always map archive(s) at an alternative address
        [0.059s][info][cds] Unmapping region #0 at base 0x0000000800000000 (ReadWrite)
        [0.059s][info][cds] Unmapping region #1 at base 0x000000080050e000 (ReadOnly)
        [0.060s][info][cds] Try to map archive(s) at an alternative address
        [0.060s][info][cds] Reserved archive_space_rs [0x00007f50f2000000 - 0x00007f50f3000000] (16777216) bytes
        [0.060s][info][cds] Reserved class_space_rs [0x00007f50f3000000 - 0x00007f5133000000] (1073741824) bytes
        [0.060s][info][cds] Mapped static region #0 at base 0x00007f50f2000000 top 0x00007f50f250e000 (ReadWrite)
        [0.060s][info][cds] Mapped static region #1 at base 0x00007f50f250e000 top 0x00007f50f2d40000 (ReadOnly)
        [0.060s][info][cds] Mapped static region #2 at base 0x00007f516c11d000 top 0x00007f516c15e000 (Bitmap)
        [0.081s][info][cds] CDS archive was created with max heap size = 128M, and the following configuration:
        [0.081s][info][cds] narrow_klass_base at mapping start address, narrow_klass_shift = 0
        [0.081s][info][cds] narrow_oop_mode = 0, narrow_oop_base = 0x0000000000000000, narrow_oop_shift = 0
        [0.081s][info][cds] The current max heap size = 990M, HeapRegion::GrainBytes = 1048576
        [0.081s][info][cds] narrow_klass_base = 0x00007f50f2000000, narrow_klass_shift = 0
        [0.081s][info][cds] narrow_oop_mode = 0, narrow_oop_base = 0x0000000000000000, narrow_oop_shift = 0
        [0.081s][info][cds] heap range = [0x00000000c2200000 - 0x0000000100000000]
        [0.081s][info][cds] Preferred address to map heap data (to avoid relocation) is 0x00000000ffe00000
        [0.081s][info][cds] Heap data mapped at 0x00000000ffe00000, size = 1092944 bytes
        [0.081s][info][cds] CDS heap data relocation delta = 0 bytes
        [0.081s][info][cds] initial optimized module handling: enabled
        [0.081s][info][cds] initial full module graph: enabled
        [0.082s][info][cds] _archived_main_module_name (null)
        [0.082s][info][cds] optimized module handling: enabled
        [0.082s][info][cds] full module graph: enabled
        [0.082s][info][cds] use_full_module_graph = true; java.base = 0x00007f50f2508f00
        [0.082s][info][cds] Unmapping region #2 at base 0x00007f516c11d000 (Bitmap)
        Could not load Hello java.lang.ClassNotFoundException: Hello[1.302s][info][cds,dynamic] Preparing for dynamic dump at exit in thread main
        [1.302s][info][cds ] Regenerate MethodHandle Holder classes...
        [1.624s][info][cds ] Regenerate MethodHandle Holder classes...done
        [1.631s][info][cds ] Verify Before CDS dynamic dump
        [1.723s][warning][cds ] Skipping jdk/internal/event/ThreadSleepEvent: Not in loaded state
        [1.723s][warning][cds ] Skipping jdk/internal/event/ThreadSleepEvent: JFR event class
        [1.723s][warning][cds ] Skipping jdk/internal/event/Event: Not in loaded state
        [1.723s][warning][cds ] Skipping jdk/internal/event/Event: JFR event class
        [1.723s][info ][cds ] Gathering all archivable objects ...
        [1.723s][info ][cds ] Gathering classes and symbols ...
        [1.728s][info ][cds ] _estimated_hashtable_bytes = 4680 + 1112 = 5792
        [1.728s][info ][cds ] _estimated_metaspaceobj_bytes = 260848
        [1.728s][info ][cds ] total estimate bytes = 274832
        [1.728s][info ][cds ] Reserved output buffer space at 0x00007f515003e000 [278528 bytes]
        [1.728s][info ][cds,dynamic] Copying 31 klasses and 287 symbols
        [1.728s][info ][cds ] Allocating RW objects ...
        [1.729s][info ][cds ] done (847 objects)
        [1.729s][info ][cds ] Allocating RO objects ...
        [1.729s][info ][cds ] done (1607 objects)
        [1.729s][info ][cds ] Relocating embedded pointers in core regions ...
        [1.730s][info ][cds ] MetaspaceObjs estimate = 260848 used = 260832; diff = 16 bytes
        [1.730s][info ][cds,dynamic] Archiving hidden sun.nio.fs.UnixFileAttributeViews$Basic$$Lambda/0x00007f50f3042680
        [1.730s][info ][cds ] Hashtables estimate = 5792 used = 3808; diff = 1984 bytes
        [1.731s][info ][cds ] Make classes shareable
        [1.731s][info ][cds ] Number of classes 31
        [1.731s][info ][cds ] instance classes = 29
        [1.731s][info ][cds ] boot = 25
        [1.731s][info ][cds ] app = 4
        [1.731s][info ][cds ] platform = 0
        [1.731s][info ][cds ] unregistered = 0
        [1.731s][info ][cds ] (hidden) = 1
        [1.731s][info ][cds ] (unlinked) = 0
        [1.731s][info ][cds ] obj array classes = 2
        [1.731s][info ][cds ] type array classes = 0
        [1.731s][info ][cds ] symbols = 287
        [1.731s][info ][cds ] Adjust lambda proxy class dictionary
        [1.731s][info ][cds ] Dumping shared data to file:
        [1.731s][info ][cds ] /opt/mach5/mesos/work_dir/slaves/afbc6042-3a24-4198-9369-18c663a3f74c-S21881/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/cd54aced-0e33-4a0f-a255-f1fd56fccb9c/runs/9d82a49e-b64d-4c3a-b4db-9bf2bae87dff/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_tier2_runtime/scratch/0/top-13h31m01s785.jsa
        [1.731s][info ][cds ] Shared file region (rw) 0: 123984 bytes, addr 0x0000000800d40000 file offset 0x00001000 crc 0x0c13ec62
        [1.731s][info ][cds ] Shared file region (ro) 1: 140656 bytes, addr 0x0000000800d5f000 file offset 0x00020000 crc 0x9a9da41d
        [1.732s][info ][cds ] Shared file region (bm) 2: 4184 bytes, addr 0x0000000000000000 file offset 0x00043000 crc 0x93c47e57
        [1.732s][info ][cds,dynamic] Written dynamic archive 0x0000000800d40000 - 0x0000000800d81570 [792 bytes header, 267632 bytes total]
        [1.732s][info ][cds,dynamic] 31 klasses; 287 symbols
        [1.732s][info ][cds ] Verify After CDS dynamic dump
        ];
         LingeredApp stderr: []
         LingeredApp exitValue = 0
        Command line: ['/opt/mach5/mesos/work_dir/jib-master/install/jdk-22+27-2180/linux-x64-debug.jdk/jdk-22/fastdebug/bin/java' '-XX:MaxRAMPercentage=4.16667' '-Dtest.boot.jdk=/opt/mach5/mesos/work_dir/jib-master/install/jdk/21/35/bundles/linux-x64/jdk-21_linux-x64_bin.tar.gz/jdk-21' '-Djava.io.tmpdir=/opt/mach5/mesos/work_dir/slaves/afbc6042-3a24-4198-9369-18c663a3f74c-S21881/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/cd54aced-0e33-4a0f-a255-f1fd56fccb9c/runs/9d82a49e-b64d-4c3a-b4db-9bf2bae87dff/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_tier2_runtime/tmp' '-Xshare:on' '-XX:SharedArchiveFile=/opt/mach5/mesos/work_dir/slaves/afbc6042-3a24-4198-9369-18c663a3f74c-S21881/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/cd54aced-0e33-4a0f-a255-f1fd56fccb9c/runs/9d82a49e-b64d-4c3a-b4db-9bf2bae87dff/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_tier2_runtime/scratch/0/top-13h31m01s785.jsa' '-Xlog:cds,class+load' '-cp' '/opt/mach5/mesos/work_dir/slaves/afbc6042-3a24-4198-9369-18c663a3f74c-S21881/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/cd54aced-0e33-4a0f-a255-f1fd56fccb9c/runs/9d82a49e-b64d-4c3a-b4db-9bf2bae87dff/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_tier2_runtime/scratch/0/loadclass.jar' 'JCmdTestLingeredApp' '2dd21e8a-5468-43cf-ba8b-61a5742ae2e8.lck']
        LingeredApp startup took 1002ms
        Check for hs_err_pid/core/mdmp files:
        None.
        [2023-12-04T13:31:04.938661826Z] Gathering output for process 3473148
        [ELAPSED: 1442 ms]
        [logging stdout to /opt/mach5/mesos/work_dir/slaves/afbc6042-3a24-4198-9369-18c663a3f74c-S21881/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/cd54aced-0e33-4a0f-a255-f1fd56fccb9c/runs/9d82a49e-b64d-4c3a-b4db-9bf2bae87dff/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_tier2_runtime/scratch/0/runtime.cds.appcds.dynamicArchive.DynamicSharedSymbols.java-0000-jcmd-symboltable.stdout]
        [logging stderr to /opt/mach5/mesos/work_dir/slaves/afbc6042-3a24-4198-9369-18c663a3f74c-S21881/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/cd54aced-0e33-4a0f-a255-f1fd56fccb9c/runs/9d82a49e-b64d-4c3a-b4db-9bf2bae87dff/testoutput/test-support/jtreg_open_test_hotspot_jtreg_hotspot_tier2_runtime/scratch/0/runtime.cds.appcds.dynamicArchive.DynamicSharedSymbols.java-0000-jcmd-symboltable.stderr]
        [STDERR]

        [2023-12-04T13:31:06.372605581Z] Waiting for completion for process 3473148
        [2023-12-04T13:31:06.372743232Z] Waiting for completion finished for process 3473148
        [2023-12-04T13:31:06.380069117Z] Waiting for completion for process 3473148
        [2023-12-04T13:31:06.380345440Z] Waiting for completion finished for process 3473148
        ----------System.err:(2080/84919)*----------
         stdout: [3473098:
        VERSION: 1.1
        25 2: [Ljava/util/jar/Manifest;
        21 65535: ThreadSleepEvent.java
        13 2: LambdaForm$MH
        26 65535: Ljdk/internal/event/Event;

        <snip>

        10 65535: randomUUID
        33 65535: jdk/test/lib/process/StreamPumper
        53 65535: (Ljdk/test/lib/apps/LingeredApp;[Ljava/lang/String;)V
        13 65535: setForceCrash
        128 65535: (Ljava/lang/String;Ljdk/internal/logger/LazyLoggers$LazyLoggerFactories;Ljava/lang/Module;Ljava/util/function/BooleanSupplier;)V
        ];
         stderr: []
         exitValue = 0

        java.lang.RuntimeException: '17 2: jdk/test/lib/apps
        ' missing from stdout/stderr
        at jdk.test.lib.process.OutputAnalyzer.shouldContain(OutputAnalyzer.java:242)
        at DynamicSharedSymbols.doTest(DynamicSharedSymbols.java:93)
        at DynamicSharedSymbols.testDefaultBase(DynamicSharedSymbols.java:58)
        at DynamicArchiveTestBase.runTest(DynamicArchiveTestBase.java:76)
        at DynamicSharedSymbols.main(DynamicSharedSymbols.java:53)
        at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
        at java.base/java.lang.reflect.Method.invoke(Method.java:580)
        at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138)
        at java.base/java.lang.Thread.run(Thread.java:1570)

        JavaTest Message: Test threw exception: java.lang.RuntimeException: '17 2: jdk/test/lib/apps
        ' missing from stdout/stderr
        JavaTest Message: shutting down test

        STATUS:Failed.`main' threw exception: java.lang.RuntimeException: '17 2: jdk/test/lib/apps ' missing from stdout/stderr
        ----------rerun:(36/11223)*----------

        There are five sightings of this failure mode in jdk-22+27-2180-tier2.
        It appears to be failing on all platforms.

              coleenp Coleen Phillimore
              dcubed Daniel Daugherty
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

                Created:
                Updated:
                Resolved: