Bug ID: JDK-8273188 java/lang/instrument/BootClassPath/BootClassPathTest.sh fails with "FATAL ERROR in native method: processing of -javaagent failed, processJavaStart failed"

JDK-8273188 : java/lang/instrument/BootClassPath/BootClassPathTest.sh fails with "FATAL ERROR in native method: processing of -javaagent failed, processJavaStart failed"

Type: Bug
Component: core-svc
Sub-Component: java.lang.instrument
Affected Version: 18

Priority: P2
Status: Closed
Resolution: Fixed
OS: generic
CPU: generic

Submitted: 2021-08-31
Updated: 2022-01-21
Resolved: 2021-09-09

Versions (Unresolved/Resolved/Fixed)

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 18
18 b15Fixed

Related Reports

Relates :

JDK-8260265 - UTF-8 by Default

Sub Tasks

JDK-8273198 :	ProblemList java/lang/instrument/BootClassPath/BootClassPathTest.sh due to JDK-8273188 - Resolved
JDK-8273248 :	ProblemList java/lang/instrument/BootClassPath/BootClassPathTest.sh on all configs - Resolved

Description

The following test failed in the JDK18 CI:

java/lang/instrument/BootClassPath/BootClassPathTest.sh

Here's a snippet from the log file:

#section:shell
----------messages:(3/142)----------
command: shell BootClassPathTest.sh
reason: User specified action: run shell/timeout=240 BootClassPathTest.sh 
elapsed time (seconds): 17.544
----------System.out:(14/1531)*----------
COMPILEJAVA=/System/Volumes/Data/mesos/work_dir/jib-master/install/jdk-18+13-659/macosx-x64-debug.jdk/jdk-18/fastdebug
Creating manifest file...
Env vars:
  LANG=null
  LC_ALL=C
  LC_CTYPE=null
Created /System/Volumes/Data/mesos/work_dir/slaves/369e65c9-433d-40ff-b6a0-b4e65701097a-S2204/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/99495dd2-ba91-4795-b19f-2b2b5f25b724/runs/2c6114b7-3144-4cb8-a362-50f904d10eba/testoutput/test-support/jtreg_open_test_jdk_jdk_svc/classes/1/java/lang/instrument/BootClassPath/BootClassPathTest.d/boot\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffdLietuvi\ufffd\ufffd\ufffd\ufffde\ufffd\ufffdtinaT\ufffd\ufffdrk\ufffd\ufffdeespa\ufffd\ufffdol\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd
Building test classes...
Creating agent jar file...
added manifest
adding: Agent.class(in = 1393) (out= 731)(deflated 47%)
Running test...
FATAL ERROR in native method: processing of -javaagent failed, processJavaStart failed
Cleanup...
----------System.err:(17/1830)----------
Exception in thread "main" java.lang.reflect.InvocationTargetException
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at java.instrument/sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:491)
	at java.instrument/sun.instrument.InstrumentationImpl.loadClassAndCallPremain(InstrumentationImpl.java:503)
Caused by: java.lang.ClassNotFoundException: AgentSupport
	at java.base/jdk.internal.loader.BuiltinClassLoader.loadClass(BuiltinClassLoader.java:641)
	at java.base/jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(ClassLoaders.java:188)
	at java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:520)
	at java.base/java.lang.Class.forName0(Native Method)
	at java.base/java.lang.Class.forName(Class.java:375)
	at Agent.premain(Agent.java:36)
	... 6 more
*** java.lang.instrument ASSERTION FAILED ***: "result" with message agent load/premain call failed at /System/Volumes/Data/mesos/work_dir/slaves/35546316-ed70-4084-8244-d672e7734fd1-S109179/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/b7325ed7-6067-4497-823f-288ea8ef4db3/runs/90d9009d-09f5-4984-8177-3ff66fc4b45b/workspace/open/src/java.instrument/share/native/libinstrument/JPLISAgent.c line: 422
/System/Volumes/Data/mesos/work_dir/jib-master/install/jdk-18+13-659/src.full/open/test/jdk/java/lang/instrument/BootClassPath/BootClassPathTest.sh: line 86: 97423 Abort trap: 6           (core dumped) "${JAVA}" ${TESTVMOPTS} -javaagent:"${TESTCLASSES}"/Agent.jar -classpath "${TESTCLASSES}" DummyMain
----------rerun:(30/3806)*----------

Comments

Changeset: 54dee132 Author: Naoto Sato <naoto@openjdk.org> Date: 2021-09-09 19:41:56 +0000 URL: https://git.openjdk.java.net/jdk/commit/54dee132d1a149165e7478b29b740d086c18c424
09-09-2021
The gist of the issue is that the test case now always creates the boot class path with non-ASCII chars, because the default encoding is fixed to UTF-8 with the fix to JDK-8260265. On macOS, javaagent tries to load the class with US-ASCII by nl_langinfo(). The file system encoding is always UTF-8 on mac, so no need to determine the encoding with nl_langinfo. On Linux, the "defaultEncoding" in Setup.java used to be US-ASCII in "C" locale (which matches the result from nl_langinfo()), so no `unicode` suffix was appended to the `boot` path. But now the "defaultEncoding" is always UTF-8, the setup code appends the unicode path, which fails to read in the native code using US-ASCII. The setup code should use the encoding from "sun.jnu.encoding" instead. Actually, the code there was copied from UnicodeTest.java which was modified with JDK-8260265, so the same fix needs to be applied.
08-09-2021
java.instrument/unix/native/libinstrument/EncodingSupport_md.c uses `iconv` to convert UTF-8 to Platform encoding which is US-ASCII in this case.
07-09-2021
This test failure is only observed in linux-x64 and macOS-x64 in Tier5. The test is passing on windows-x64 for some reason.
31-08-2021
I ran the test 3 additional times in release, fast debug and slow debug and did not get any failures.
31-08-2021
Built a new repo with the HEAD just before the fix for: JDK-8260265 UTF-8 by Default $ git log HEAD^! commit 32048536e9ea9245437eb37308e905435cce6305 (HEAD) Author: Ioi Lam <iklam@openjdk.org> Date: Mon Aug 30 21:06:26 2021 +0000 8272343: Remove MetaspaceClosure::FLAG_MASK Reviewed-by: ccheung, minqi $ do_java_test "sun/tools/jcmd/JcmdOutputEncodingTest.java sun/tools/jstack/BasicJStackTest.java java/lang/instrument/BootClassPath/BootClassPathTest.sh" INFO: GNUMAKE=make INFO: GNUMAKE version is: GNU Make 3.81 INFO: JTREG options: INFO: JOBS=1 INFO: TEST_MODE=agentvm INFO: EXTRA_PROBLEM_LISTS=ProblemList-extra.txt INFO: VM_OPTIONS= INFO: test_val=sun/tools/jcmd/JcmdOutputEncodingTest.java sun/tools/jstack/BasicJStackTest.java java/lang/instrument/BootClassPath/BootClassPathTest.sh Test Config: macosx-x86_64-normal-server-release INFO: TIMEOUT_FACTOR=4 Done testing Test Run macosx-x86_64-normal-server-release time: 0.67 minutes. TEST TOTAL PASS FAIL ERROR jtreg:open/test/jdk/sun/tools/jcmd/JcmdOutputEncodingTest.java 1 1 0 0 jtreg:open/test/jdk/sun/tools/jstack/BasicJStackTest.java 1 1 0 0 jtreg:open/test/jdk/java/lang/instrument/BootClassPath/BootClassPathTest.sh 1 1 0 0 Test Config: macosx-x86_64-normal-server-fastdebug INFO: TIMEOUT_FACTOR=6 Done testing Test Run macosx-x86_64-normal-server-fastdebug time: 1.13 minutes. TEST TOTAL PASS FAIL ERROR jtreg:open/test/jdk/sun/tools/jcmd/JcmdOutputEncodingTest.java 1 1 0 0 jtreg:open/test/jdk/sun/tools/jstack/BasicJStackTest.java 1 1 0 0 jtreg:open/test/jdk/java/lang/instrument/BootClassPath/BootClassPathTest.sh 1 1 0 0 Test Config: macosx-x86_64-normal-server-slowdebug INFO: TIMEOUT_FACTOR=12 Done testing Test Run macosx-x86_64-normal-server-slowdebug time: 3.27 minutes. TEST TOTAL PASS FAIL ERROR jtreg:open/test/jdk/sun/tools/jcmd/JcmdOutputEncodingTest.java 1 1 0 0 jtreg:open/test/jdk/sun/tools/jstack/BasicJStackTest.java 1 1 0 0 jtreg:open/test/jdk/java/lang/instrument/BootClassPath/BootClassPathTest.sh 1 1 0 0 Total test time: 5.08 minutes. While not proof, this is a strong indicator that this test failure: java/lang/instrument/BootClassPath/BootClassPathTest.sh is a regression caused by JDK-8260265.
31-08-2021
Fails every time on linux-x64-debug and macosx-x64-debug. The failure goes away when I revert JDK-8260265.
31-08-2021
The linux failure has additional text in stderr that doesn't appear on the macosx failures, but may be indicative of the root cause: error: illegal argument for -d: java.nio.file.InvalidPathException: Malformed input or input contains unmappable characters: /opt/mach5/mesos/work_dir/slaves/ff806ead-2cac-495d-9cbc-62116f99bf14-S13788/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/226be985-2b3f-4a6e-b87e-453114a41db0/runs/fdc6335f-e332-43c0-b620-eea8d0025582/testoutput/test-support/jtreg_open_test_jdk_jdk_svc/classes/2/java/lang/instrument/BootClassPath/BootClassPathTest.d/boot?????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????????Lietuvi????????????e??????tinaT??????rk??????eespa??????ol??????????????????????????? Exception in thread "main" java.nio.file.InvalidPathException: Malformed input or input contains unmappable characters: /opt/mach5/mesos/work_dir/slaves/ff806ead-2cac-495d-9cbc-62116f99bf14-S13788/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/226be985-2b3f-4a6e-b87e-453114a41db0/runs/fdc6335f-e332-43c0-b620-eea8d0025582/testoutput/test-support/jtreg_open_test_jdk_jdk_svc/classes/2/java/lang/instrument/BootClassPath/BootClassPathTest.d/boot???????????????????????????????????????????????????????????????????????????????????????????????????Lietuvi????e??tinaT??rk??eespa??ol????????? at java.base/sun.nio.fs.UnixPath.encode(UnixPath.java:121) at java.base/sun.nio.fs.UnixPath.<init>(UnixPath.java:68) at java.base/sun.nio.fs.UnixFileSystem.getPath(UnixFileSystem.java:279) at java.base/java.nio.file.Path.of(Path.java:147) at java.base/java.nio.file.Paths.get(Paths.java:69) at jdk.compiler/com.sun.tools.javac.main.Arguments.checkDirectory(Arguments.java:864) at jdk.compiler/com.sun.tools.javac.main.Arguments.validate(Arguments.java:470) at jdk.compiler/com.sun.tools.javac.main.Main.compile(Main.java:276) at jdk.compiler/com.sun.tools.javac.main.Main.compile(Main.java:176) at jdk.compiler/com.sun.tools.javac.Main.compile(Main.java:64) at jdk.compiler/com.sun.tools.javac.Main.main(Main.java:50) Exception in thread "main" java.lang.reflect.InvocationTargetException at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:568) at java.instrument/sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:491) at java.instrument/sun.instrument.InstrumentationImpl.loadClassAndCallPremain(InstrumentationImpl.java:503) Caused by: java.lang.ClassNotFoundException: AgentSupport at java.base/jdk.internal.loader.BuiltinClassLoader.loadClass(BuiltinClassLoader.java:641) at java.base/jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(ClassLoaders.java:188) at java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:520) at java.base/java.lang.Class.forName0(Native Method) at java.base/java.lang.Class.forName(Class.java:375) at Agent.premain(Agent.java:36) ... 6 more
31-08-2021
Reproduced the test failure on my MBP13 with release, fastdebug and slow debug bits. Attached the logs: $ unzip -l 8273188-repro-logs.zip Archive: 8273188-repro-logs.zip Length Date Time Name --------- ---------- ----- ---- 8840 08-31-2021 11:49 test_failures.2021-08-31-114444/BootClassPathTest.jtr.fastdebug 8723 08-31-2021 11:46 test_failures.2021-08-31-114444/BootClassPathTest.jtr.release 8841 08-31-2021 11:54 test_failures.2021-08-31-114444/BootClassPathTest.jtr.slowdebug --------- ------- 26404 3 files
31-08-2021
jdk-18+13-659 contains only three change sets: 2021-08-31 00:24 minqi: 9732fb - OpenJDK 8273153 Consolidate file_exists into os:file_exists 2021-08-30 21:13 naoto: 7fc854 - OpenJDK 8260265 UTF-8 by Default 2021-08-30 21:16 vromero: 060942 - OpenJDK 8272347 ObjectMethods::bootstrap should specify NPE if any argument except lookup is null Of these three, this fix looks the most related: JDK-8260265 UTF-8 by Default [~naoto] - Can you investigate to see if JDK-8260265 has caused these test failures?
31-08-2021