jtreg icon indicating copy to clipboard operation
jtreg copied to clipboard

7904101: intermittent failure in StreamsTest.agentvm.ok

Open vpa1977 opened this issue 1 month ago • 4 comments

FileDescriptor test intermittently fails because the agent's process output capture lacks synchronisation.

This PR fixes the issue:

  • Agent VM prints the "process output separator" to stderr and stdout before and after action
  • The main vm uses the marker to stop reading the stream for the current test result section (or a general agent log)
  • The main vm restarts reading the log after updating the test section (or clearing it) until the next marker or the process is shut down.

Alternative: -Disable the test and make no assumptions about contents of the agent vm process output.

Testing: tier1 and tier2 tests on mainline jdk (Ubuntu Linux) in agentvm mode.

make test TEST=":tier1 :tier2" JTREG="TEST_MODE=agentvm"

....

==============================
Test summary
==============================
   TEST                                              TOTAL  PASS  FAIL ERROR  SKIP   
   jtreg:test/hotspot/jtreg:tier1                     3124  2837     0     0   287   
   jtreg:test/jdk:tier1                               2519  2480     0     0    39   
   jtreg:test/langtools:tier1                         4670  4660     0     0    10   
   jtreg:test/jaxp:tier1                                 0     0     0     0     0   
   jtreg:test/lib-test:tier1                            38    38     0     0     0   
   jtreg:test/hotspot/jtreg:tier2                      960   913     0     0    47   
>> jtreg:test/jdk:tier2                               4455  4220     1     0   234 <<
   jtreg:test/langtools:tier2                           14    12     0     0     2   
   jtreg:test/jaxp:tier2                               517   516     0     0     1   
   jtreg:test/docs:tier2                                 4     0     0     0     4   
==============================
TEST FAILURE

Unrelated failure: test/jdk/java/nio/channels/DatagramChannel/SendReceiveMaxSize.java


---------System.out:(98/7409)----------
Seed from RandomFactory = 7590698091695474155L
[15:02:42.244] config SendReceiveMaxSize.setUp(): success [0ms]
[15:02:42.272] test SendReceiveMaxSize.testGetOption(SendReceiveMaxSize$$Lambda/0x00000000450736f8@8d234b9, 65507, /10.201.67.1): success [7ms]
[15:02:42.273] test SendReceiveMaxSize.testGetOption(SendReceiveMaxSize$$Lambda/0x0000000045073920@449629ff, 65507, /10.201.67.1): success [0ms]
[15:02:42.273] test SendReceiveMaxSize.testGetOption(SendReceiveMaxSize$$Lambda/0x0000000045078000@2b071f3f, 65527, java.net.Inet6Address@22212892): success [0ms]
[15:02:42.273] test SendReceiveMaxSize.testGetOption(SendReceiveMaxSize$$Lambda/0x0000000045078228@298b6c94, 65527, java.net.Inet6Address@22212892): success [0ms]
testSendReceiveMaxSize: sender: /10.201.67.1:50670 -> receiver: /10.201.67.1:49236
sendBuf:    java.nio.HeapByteBuffer[pos=0 lim=65507 cap=65507]
receiveBuf: java.nio.HeapByteBuffer[pos=0 lim=65507 cap=65507]
sendBuf:    java.nio.HeapByteBuffer[pos=0 lim=65506 cap=65506]
receiveBuf: java.nio.HeapByteBuffer[pos=0 lim=65506 cap=65506]
[15:02:42.286] test SendReceiveMaxSize.testSendReceiveMaxSize(SendReceiveMaxSize$$Lambda/0x00000000450736f8@8d234b9, 65507, /10.201.67.1): success [11ms]
testSendReceiveMaxSize: sender: /10.201.67.1:48168 -> receiver: /10.201.67.1:52274
sendBuf:    java.nio.HeapByteBuffer[pos=0 lim=65507 cap=65507]
receiveBuf: java.nio.HeapByteBuffer[pos=0 lim=65507 cap=65507]
sendBuf:    java.nio.HeapByteBuffer[pos=0 lim=65506 cap=65506]
receiveBuf: java.nio.HeapByteBuffer[pos=0 lim=65506 cap=65506]
[15:02:42.288] test SendReceiveMaxSize.testSendReceiveMaxSize(SendReceiveMaxSize$$Lambda/0x0000000045073920@449629ff, 65507, /10.201.67.1): success [2ms]
testSendReceiveMaxSize: sender: /[fe80:0:0:0:fc54:ff:fe24:9197%17]:46562 -> receiver: /[fe80:0:0:0:fc54:ff:fe24:9197%17]:58635
[15:02:42.289] test SendReceiveMaxSize.testSendReceiveMaxSize(SendReceiveMaxSize$$Lambda/0x0000000045078000@2b071f3f, 65527, java.net.Inet6Address@8959069): failure [1ms]
java.net.SocketException: Message too long
	at java.base/sun.nio.ch.DatagramChannelImpl.send0(Native Method)
	at java.base/sun.nio.ch.DatagramChannelImpl.sendFromNativeBuffer(DatagramChannelImpl.java:914)
	at java.base/sun.nio.ch.DatagramChannelImpl.send(DatagramChannelImpl.java:886)
	at java.base/sun.nio.ch.DatagramChannelImpl.send(DatagramChannelImpl.java:798)
	at SendReceiveMaxSize.testSendReceiveMaxSize(SendReceiveMaxSize.java:155)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
	at java.base/java.lang.reflect.Method.invoke(Method.java:565)
	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:132)
	at org.testng.internal.TestInvoker.invokeMethod(TestInvoker.java:599)
	at org.testng.internal.TestInvoker.invokeTestMethod(TestInvoker.java:174)
	at org.testng.internal.MethodRunner.runInSequence(MethodRunner.java:46)
	at org.testng.internal.TestInvoker$MethodInvocationAgent.invoke(TestInvoker.java:822)
	at org.testng.internal.TestInvoker.invokeTestMethods(TestInvoker.java:147)
	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:146)
	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:128)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1604)
	at org.testng.TestRunner.privateRun(TestRunner.java:764)
	at org.testng.TestRunner.run(TestRunner.java:585)
	at org.testng.SuiteRunner.runTest(SuiteRunner.java:384)
	at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:378)
	at org.testng.SuiteRunner.privateRun(SuiteRunner.java:337)
	at org.testng.SuiteRunner.run(SuiteRunner.java:286)
	at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:53)
	at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:96)
	at org.testng.TestNG.runSuitesSequentially(TestNG.java:1218)
	at org.testng.TestNG.runSuitesLocally(TestNG.java:1140)
	at org.testng.TestNG.runSuites(TestNG.java:1069)
	at org.testng.TestNG.run(TestNG.java:1037)
	at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:109)
	at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:65)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
	at java.base/java.lang.reflect.Method.invoke(Method.java:565)
	at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138)
	at java.base/java.lang.Thread.run(Thread.java:1474)
testSendReceiveMaxSize: sender: /[fe80:0:0:0:fc54:ff:fe24:9197%17]:39368 -> receiver: /[fe80:0:0:0:fc54:ff:fe24:9197%17]:38228
[15:02:42.291] test SendReceiveMaxSize.testSendReceiveMaxSize(SendReceiveMaxSize$$Lambda/0x0000000045078228@298b6c94, 65527, java.net.Inet6Address@8959069): failure [0ms]
java.net.SocketException: Message too long
	at java.base/sun.nio.ch.DatagramChannelImpl.send0(Native Method)
	at java.base/sun.nio.ch.DatagramChannelImpl.sendFromNativeBuffer(DatagramChannelImpl.java:914)
	at java.base/sun.nio.ch.DatagramChannelImpl.send(DatagramChannelImpl.java:886)
	at java.base/sun.nio.ch.DatagramChannelImpl.send(DatagramChannelImpl.java:798)
	at SendReceiveMaxSize.testSendReceiveMaxSize(SendReceiveMaxSize.java:155)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
	at java.base/java.lang.reflect.Method.invoke(Method.java:565)
	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:132)
	at org.testng.internal.TestInvoker.invokeMethod(TestInvoker.java:599)
	at org.testng.internal.TestInvoker.invokeTestMethod(TestInvoker.java:174)
	at org.testng.internal.MethodRunner.runInSequence(MethodRunner.java:46)
	at org.testng.internal.TestInvoker$MethodInvocationAgent.invoke(TestInvoker.java:822)
	at org.testng.internal.TestInvoker.invokeTestMethods(TestInvoker.java:147)
	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:146)
	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:128)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1604)
	at org.testng.TestRunner.privateRun(TestRunner.java:764)
	at org.testng.TestRunner.run(TestRunner.java:585)
	at org.testng.SuiteRunner.runTest(SuiteRunner.java:384)
	at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:378)
	at org.testng.SuiteRunner.privateRun(SuiteRunner.java:337)
	at org.testng.SuiteRunner.run(SuiteRunner.java:286)
	at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:53)
	at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:96)
	at org.testng.TestNG.runSuitesSequentially(TestNG.java:1218)
	at org.testng.TestNG.runSuitesLocally(TestNG.java:1140)
	at org.testng.TestNG.runSuites(TestNG.java:1069)
	at org.testng.TestNG.run(TestNG.java:1037)
	at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:109)
	at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:65)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
	at java.base/java.lang.reflect.Method.invoke(Method.java:565)
	at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138)
	at java.base/java.lang.Thread.run(Thread.java:1474)

===============================================
java/nio/channels/DatagramChannel/SendReceiveMaxSize.java
Total tests run: 8, Passes: 6, Failures: 2, Skips: 0
===============================================

Progress

  • [ ] Change must be properly reviewed (1 review required, with at least 1 Reviewer)
  • [x] Change must not contain extraneous whitespace
  • [x] Commit message must refer to an issue

Issue

Reviewing

Using git

Checkout this PR locally:
$ git fetch https://git.openjdk.org/jtreg.git pull/295/head:pull/295
$ git checkout pull/295

Update a local copy of the PR:
$ git checkout pull/295
$ git pull https://git.openjdk.org/jtreg.git pull/295/head

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 295

View PR using the GUI difftool:
$ git pr show -t 295

Using diff file

Download this PR as a diff file:
https://git.openjdk.org/jtreg/pull/295.diff

Using Webrev

Link to Webrev Comment

vpa1977 avatar Oct 21 '25 02:10 vpa1977

:wave: Welcome back vpetko! A progress list of the required criteria for merging this PR into master will be added to the body of your pull request. There are additional pull request commands available for use with this pull request.

bridgekeeper[bot] avatar Oct 21 '25 02:10 bridgekeeper[bot]

❗ This change is not yet ready to be integrated. See the Progress checklist in the description for automated requirements.

openjdk[bot] avatar Oct 21 '25 02:10 openjdk[bot]

Webrevs

mlbridge[bot] avatar Oct 22 '25 02:10 mlbridge[bot]

Still getting intermittent failure in StreamsTest. moving to draft.

vpa1977 avatar Oct 24 '25 01:10 vpa1977

@vpa1977 This pull request has been inactive for more than 4 weeks and will be automatically closed if another 4 weeks passes without any activity. To avoid this, simply issue a /touch or /keepalive command to the pull request. Feel free to ask for assistance if you need help with progressing this pull request towards integration!

bridgekeeper[bot] avatar Nov 25 '25 06:11 bridgekeeper[bot]

/touch

vpa1977 avatar Nov 25 '25 19:11 vpa1977

@vpa1977 The pull request is being re-evaluated and the inactivity timeout has been reset.

openjdk[bot] avatar Nov 25 '25 19:11 openjdk[bot]

Alternative: -Disable the test and make no assumptions about contents of the agent vm process output.

Before looking deeper into the implementation, do I read this correctly, the a test makes "assumptions about contents of the agent vm process output"?

sormuras avatar Dec 02 '25 12:12 sormuras