Bug ID: JDK-8240622 jfr/api/consumer/streaming/TestJVMExit.java timed out failing to attach

JDK-8240622 : jfr/api/consumer/streaming/TestJVMExit.java timed out failing to attach

Type: Bug
Component: hotspot
Sub-Component: jfr
Affected Version: 15,22

Priority: P4
Status: Open
Resolution: Unresolved
OS: os_x
CPU: x86_64

Submitted: 2020-03-05
Updated: 2024-06-19

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.

Other
tbdUnresolved

Related Reports

Relates :	JDK-8235211 - serviceability/attach/RemovingUnixDomainSocketTest.java fails with AttachNotSupportedException: Unable to open socket file
Relates :	JDK-8241033 - Create test library utility for getting JFR streaming repository
Relates :	JDK-8285249 - jdk/jfr/api/consumer/streaming/TestJVMExit.java fails to attach
Relates :	JDK-8240710 - JFR TestCrossProcessStreaming.java failed to attach

Description

The following test failed in the JDK15 CI:

jdk/jfr/api/consumer/streaming/TestJVMExit.java

Here's a snippet from the log file:

#section:main
----------messages:(7/397)----------
command: main jdk.jfr.api.consumer.streaming.TestJVMExit
reason: User specified action: run main/othervm jdk.jfr.api.consumer.streaming.TestJVMExit 
Mode: othervm [/othervm specified]
Additional options from @modules: --add-modules jdk.jfr,jdk.attach,java.base --add-exports java.base/jdk.internal.misc=ALL-UNNAMED
Timeout information:
--- Timeout information end.
elapsed time (seconds): 512.385
----------configuration:(4/112)----------
Boot Layer
  add modules: jdk.jfr jdk.attach java.base 
  add exports: java.base/jdk.internal.misc ALL-UNNAMED

----------System.out:(3487/78651)----------
Command line: [/scratch/mesos/jib-master/install/jdk-15+14-494/macosx-x64-debug.jdk/jdk-15/fastdebug/bin/java -cp /scratch/mesos/slaves/90726e33-be99-4e27-9d68-25dad266ef13-S881/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/5f5ea42e-0295-44dc-8481-34c6265e6dc7/runs/2824b517-64b1-4ae9-b22f-5b2fa22420ce/testoutput/test-support/jtreg_open_test_jdk_jdk_svc/classes/0/jdk/jfr/api/consumer/streaming/TestJVMExit.d:/scratch/mesos/jib-master/install/jdk-15+14-494/src.full/open/test/jdk/jdk/jfr/api/consumer/streaming:/scratch/mesos/slaves/90726e33-be99-4e27-9d68-25dad266ef13-S881/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/5f5ea42e-0295-44dc-8481-34c6265e6dc7/runs/2824b517-64b1-4ae9-b22f-5b2fa22420ce/testoutput/test-support/jtreg_open_test_jdk_jdk_svc/classes/0/test/lib:/scratch/mesos/jib-master/install/jdk-15+14-494/src.full/open/test/lib:/scratch/mesos/slaves/90726e33-be99-4e27-9d68-25dad266ef13-S881/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/5f5ea42e-0295-44dc-8481-34c6265e6dc7/runs/2824b517-64b1-4ae9-b22f-5b2fa22420ce/testoutput/test-support/jtreg_open_test_jdk_jdk_svc/classes/0/test/jdk:/scratch/mesos/jib-master/install/jdk-15+14-494/src.full/open/test/jdk:/scratch/mesos/jib-master/install/jtreg/5.0/b01/bundles/jtreg_bin-5.0.zip/jtreg/lib/javatest.jar:/scratch/mesos/jib-master/install/jtreg/5.0/b01/bundles/jtreg_bin-5.0.zip/jtreg/lib/jtreg.jar --add-exports java.base/jdk.internal.misc=ALL-UNNAMED -XX:StartFlightRecording:settings=none jdk.jfr.api.consumer.streaming.TestProcess /scratch/mesos/slaves/90726e33-be99-4e27-9d68-25dad266ef13-S881/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/5f5ea42e-0295-44dc-8481-34c6265e6dc7/runs/2824b517-64b1-4ae9-b22f-5b2fa22420ce/testoutput/test-support/jtreg_open_test_jdk_jdk_svc/scratch/2/action-1583429052398 ]
[exit-application]:/scratch/mesos/jib-master/install/jdk-15+14-494/macosx-x64-debug.jdk/jdk-15/fastdebug/bin/java -cp /scratch/mesos/slaves/90726e33-be99-4e27-9d68-25dad266ef13-S881/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/5f5ea42e-0295-44dc-8481-34c6265e6dc7/runs/2824b517-64b1-4ae9-b22f-5b2fa22420ce/testoutput/test-support/jtreg_open_test_jdk_jdk_svc/classes/0/jdk/jfr/api/consumer/streaming/TestJVMExit.d:/scratch/mesos/jib-master/install/jdk-15+14-494/src.full/open/test/jdk/jdk/jfr/api/consumer/streaming:/scratch/mesos/slaves/90726e33-be99-4e27-9d68-25dad266ef13-S881/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/5f5ea42e-0295-44dc-8481-34c6265e6dc7/runs/2824b517-64b1-4ae9-b22f-5b2fa22420ce/testoutput/test-support/jtreg_open_test_jdk_jdk_svc/classes/0/test/lib:/scratch/mesos/jib-master/install/jdk-15+14-494/src.full/open/test/lib:/scratch/mesos/slaves/90726e33-be99-4e27-9d68-25dad266ef13-S881/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/5f5ea42e-0295-44dc-8481-34c6265e6dc7/runs/2824b517-64b1-4ae9-b22f-5b2fa22420ce/testoutput/test-support/jtreg_open_test_jdk_jdk_svc/classes/0/test/jdk:/scratch/mesos/jib-master/install/jdk-15+14-494/src.full/open/test/jdk:/scratch/mesos/jib-master/install/jtreg/5.0/b01/bundles/jtreg_bin-5.0.zip/jtreg/lib/javatest.jar:/scratch/mesos/jib-master/install/jtreg/5.0/b01/bundles/jtreg_bin-5.0.zip/jtreg/lib/jtreg.jar --add-exports java.base/jdk.internal.misc=ALL-UNNAMED -XX:StartFlightRecording:settings=none jdk.jfr.api.consumer.streaming.TestProcess /scratch/mesos/slaves/90726e33-be99-4e27-9d68-25dad266ef13-S881/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/5f5ea42e-0295-44dc-8481-34c6265e6dc7/runs/2824b517-64b1-4ae9-b22f-5b2fa22420ce/testoutput/test-support/jtreg_open_test_jdk_jdk_svc/scratch/2/action-1583429052398
Attach failed: No such process
Retrying...
Attach failed: No such process
Retrying...
Attach failed: No such process

<many pages of Attach failed messages>

This test machine is running 10.13.4 so I don't think this is
related to the recent OSX security policy changes.

Comments

Seems to be some intermittent macOS issue.
19-06-2024
I'm off two minds about whether to re-open this old issue or essentially clone it, as we have the same failure mode again, this time on macos aarch64. I'vechosen to re-open to save myself some time.
13-07-2023
Going to reclose as CNR.
08-04-2020
I looked at the test artefacts, but I couldn't see a report showing processes running on the machine at the timeout. I've seen such reports in the past, but not on this one. Why? I like to know if the TestProcess is running? Did something fail at start up, or did it exit prematurely? We could perhaps increase logging, For example, put in a 1 s delay before retrying (so the log is not flooded) and then the hundredth time launch a shell "ps" with OutputAnalyzer to see what other processes are running.
13-03-2020
Given that this is not a bug in the "VM attach" mechanism, and this test does not explicitly test that mechanism, we could throw a jtreg.Skipped exception after certain number of attempts to make this test more stable. That is, in such (rather rare) situation the test would be marked as "Skipped" in the test results rather then "Failed". [~egahlin] Erik, do you have an opinion on such approach? Alternatively, I could reassign this to SVC team to investigate why attach fails. However, this could also be an Infra issue related to permissions or process termination.
13-03-2020
This problem is hard to reproduce. Ran 150+ times on various hosts, including several runs nodes where the problem was originally seen, but could not prepuce it. I believe this is not a test bug. The test starts a child process which generates events and then waits for special "signal" from the parent process in a loop. The main (parent) process, after starting a test child process, attempts to attach to it, also in a loop, to get the JFR repository property via VM attach mechanism (VirtualMachine.getSystemProperties). W/o this step succeeding the test can not proceed, it basically fails, regardless of whether the child process died for some reason, but in attach mechanism or some system settings/permissions that prevent the attach.
13-03-2020
Actually JDK-8235211 now has failures on 10.13.6 and 10.14.6. I know initially they were all on 10.13.4.
11-03-2020
JDK-8235211 is another bug with occasional attach failures that is only happening on 10.13.4 and not 10.13.6.
11-03-2020
ILW = MLM = P4
10-03-2020
Another case: Attach failed: Unable to open socket file /var/folders/xx/t8wy4yqn0hs8cbszbm013vq80000mv/T/.java_pid16626: target process 16626 doesn't respond within 10500ms or HotSpot VM not loaded Retrying... Attach failed: Unable to open socket file /var/folders/xx/t8wy4yqn0hs8cbszbm013vq80000mv/T/.java_pid16626: target process 16626 doesn't respond within 10500ms or HotSpot VM not loaded Retrying... Attach failed: Unable to open socket file /var/folders/xx/t8wy4yqn0hs8cbszbm013vq80000mv/T/.java_pid16626: target process 16626 doesn't respond within 10500ms or HotSpot VM not loaded Retrying... Attach failed: Unable to open socket file /var/folders/xx/t8wy4yqn0hs8cbszbm013vq80000mv/T/.java_pid16626: target process 16626 doesn't respond within 10500ms or HotSpot VM not loaded Retrying... Attach failed: Unable to open socket file /var/folders/xx/t8wy4yqn0hs8cbszbm013vq80000mv/T/.java_pid16626: target process 16626 doesn't respond within 10500ms or HotSpot VM not loaded Retrying... Attach failed: Unable to open socket file /var/folders/xx/t8wy4yqn0hs8cbszbm013vq80000mv/T/.java_pid16626: target process 16626 doesn't respond within 10500ms or HotSpot VM not loaded Retrying... Attach failed: Unable to open socket file /var/folders/xx/t8wy4yqn0hs8cbszbm013vq80000mv/T/.java_pid16626: target process 16626 doesn't respond within 10500ms or HotSpot VM not loaded Retrying... Attach failed: No such process Retrying... Attach failed: No such process The retry logic is an infinite loop that relies on test harness timeout to kill things: public Path getRepository() { while (true) { try { VirtualMachine vm = VirtualMachine.attach(String.valueOf(process.pid())); Properties p = vm.getSystemProperties(); vm.detach(); String repo = (String) p.get("jdk.jfr.repository"); if (repo != null) { return Paths.get(repo); } } catch (Exception e) { System.out.println("Attach failed: " + e.getMessage()); System.out.println("Retrying..."); } takeNap(); } } Probably worth checking for "no such process" and giving up.
10-03-2020