Skip to content

LongPollingTransportOnReceiveGetsCalled() is flaky #34563

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
dougbu opened this issue Jul 20, 2021 · 3 comments · Fixed by #37894
Closed

LongPollingTransportOnReceiveGetsCalled() is flaky #34563

dougbu opened this issue Jul 20, 2021 · 3 comments · Fixed by #37894
Labels
area-signalr Includes: SignalR clients and servers test-failure test-fixed
Milestone

Comments

@dougbu
Copy link
Contributor

dougbu commented Jul 20, 2021

Failing Test(s)

  • com.microsoft.signalr.LongPollingTransportTest.LongPollingTransportOnReceiveGetsCalled()

Error Message

expected: <true> but was: <false>

Stacktrace

org.opentest4j.AssertionFailedError: expected: <true> but was: <false>
	at org.junit.jupiter.api.AssertionUtils.fail(AssertionUtils.java:38)
	at org.junit.jupiter.api.AssertTrue.assertTrue(AssertTrue.java:40)
	at org.junit.jupiter.api.AssertTrue.assertTrue(AssertTrue.java:35)
	at org.junit.jupiter.api.Assertions.assertTrue(Assertions.java:137)
	at com.microsoft.signalr.LongPollingTransportTest.LongPollingTransportOnReceiveGetsCalled(LongPollingTransportTest.java:159)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:515)
	at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:115)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$6(TestMethodTestDescriptor.java:171)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:72)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:167)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:114)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:59)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:105)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:72)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:95)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:71)
	at java.util.ArrayList.forEach(ArrayList.java:1257)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:110)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:72)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:95)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:71)
	at java.util.ArrayList.forEach(ArrayList.java:1257)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:110)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:72)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:95)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:71)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:32)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:51)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:170)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:154)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:90)
	at org.junit.platform.console.tasks.ConsoleTestExecutor.executeTests(ConsoleTestExecutor.java:65)
	at org.junit.platform.console.tasks.ConsoleTestExecutor.lambda$execute$0(Co

Logs

There is a lot of information in https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-aspnetcore-refs-heads-main-a61547be830e450ca0/signalr.client.java.Tests--/console.9d51f993.log?sv=2019-07-07 but it's not clear what's relevant. Copying a little bit here.

09:27:51.476 [pool-175-thread-1] INFO com.microsoft.signalr.HubConnection - HubConnection started.
09:27:51.477 [pool-175-thread-1] DEBUG com.microsoft.signalr.LongPollingTransport - OnReceived callback has been invoked.
09:27:51.477 [main] DEBUG com.microsoft.signalr.HubConnection - Stopping HubConnection.
09:27:51.477 [main] INFO com.microsoft.signalr.LongPollingTransport - LongPolling transport stopped.
09:27:51.477 [main] ERROR com.microsoft.signalr.HubConnection - HubConnection disconnected with an error Request has no handler: DELETE http://example.com?id=bVOiRPG8-6YiJ6d7ZcTOVQ.
09:27:51.478 [main] INFO com.microsoft.signalr.HubConnection - HubConnection stopped.
09:27:51.478 [main] DEBUG com.microsoft.signalr.HubConnection - The HubConnection is transitioning from the CONNECTED state to the DISCONNECTED state.
09:27:51.478 [RxCachedThreadScheduler-3] DEBUG com.microsoft.signalr.LongPollingTransport - Message received.
09:27:51.478 [RxCachedThreadScheduler-3] DEBUG com.microsoft.signalr.LongPollingTransport - Long Polling transport polling complete.
09:27:51.479 [main] DEBUG com.microsoft.signalr.HubConnection - The HubConnection is attempting to transition from the DISCONNECTED state to the CONNECTING state.
09:27:51.479 [main] DEBUG com.microsoft.signalr.HubConnection - Starting HubConnection.
09:27:51.480 [main] DEBUG com.microsoft.signalr.HubConnection - The HubConnection is attempting to transition from the CONNECTING state to the CONNECTED state.
09:27:51.480 [main] INFO com.microsoft.signalr.HubConnection - HubConnection started.
09:27:51.480 [Timer-130] DEBUG com.microsoft.signalr.HubConnection - Sending PING message.
09:27:51.480 [main] DEBUG com.microsoft.signalr.HubConnection - Stopping HubConnection.
09:27:51.481 [main] INFO com.microsoft.signalr.HubConnection - HubConnection stopped.
09:27:51.481 [main] DEBUG com.microsoft.signalr.HubConnection - The HubConnection is transitioning from the CONNECTED state to the DISCONNECTED state.
09:27:51.481 [main] DEBUG com.microsoft.signalr.HubConnection - The HubConnection is attempting to transition from the DISCONNECTED state to the CONNECTING state.
09:27:51.481 [main] DEBUG com.microsoft.signalr.HubConnection - Starting HubConnection.
09:27:51.482 [main] DEBUG com.microsoft.signalr.HubConnection - The HubConnection is attempting to transition from the CONNECTING state to the CONNECTED state.
09:27:51.482 [main] INFO com.microsoft.signalr.HubConnection - HubConnection started.
09:27:51.482 [main] DEBUG com.microsoft.signalr.HubConnection - Sending INVOCATION message '1'.
09:27:51.482 [Timer-131] DEBUG com.microsoft.signalr.HubConnection - Sending PING message.
09:27:51.483 [main] DEBUG com.microsoft.signalr.HubConnection - Received message of type COMPLETION.
09:27:51.486 [main] DEBUG com.microsoft.signalr.HubConnection - The HubConnection is attempting to transition from the DISCONNECTED state to the CONNECTING state.
09:27:51.487 [main] DEBUG com.microsoft.signalr.HubConnection - The HubConnection is attempting to transition from the CONNECTING state to the DISCONNECTED state.

Failures (1):
  JUnit Jupiter:LongPollingTransportTest:LongPollingTransportOnReceiveGetsCalled()
    MethodSource [className = 'com.microsoft.signalr.LongPollingTransportTest', methodName = 'LongPollingTransportOnReceiveGetsCalled', methodParameterTypes = '']
    => org.opentest4j.AssertionFailedError: expected: <true> but was: <false>

Test run finished after 7824 ms
[        17 containers found      ]
[         0 containers skipped    ]
[        17 containers started    ]
[         0 containers aborted    ]
[        17 containers successful ]
[         0 containers failed     ]
[       258 tests found           ]
[         0 tests skipped         ]
[       258 tests started         ]
[         0 tests aborted         ]
[       257 tests successful      ]
[         1 tests failed          ]


> Task :test:junitPlatformTest FAILED

FAILURE: Build failed with an exception.

* What went wrong:
Execution failed for task ':test:junitPlatformTest'.
> Process 'command '/Library/Java/JavaVirtualMachines/adoptopenjdk-8.jdk/Contents/Home/bin/java'' finished with non-zero exit value 1

Build

@dougbu dougbu added test-failure area-signalr Includes: SignalR clients and servers labels Jul 20, 2021
dougbu added a commit that referenced this issue Jul 20, 2021
- un-quarantine `ContentLength_Received_MultipleDataFramesOverSize_Reset`, #33373 fix seems to have worked
- quarantine `LoggingConnectionMiddlewareCanBeAddedBeforeAndAfterHttps()`, #34561
- skip `LongPollingTransportOnReceiveGetsCalled()` because we can't quarantine Java tests, #34563
dougbu added a commit that referenced this issue Jul 21, 2021
- un-quarantine `ContentLength_Received_MultipleDataFramesOverSize_Reset`, #33373 fix seems to have worked
- quarantine `LoggingConnectionMiddlewareCanBeAddedBeforeAndAfterHttps()`, #34561
- skip `LongPollingTransportOnReceiveGetsCalled()` because we can't quarantine Java tests, #34563
@BrennanConroy BrennanConroy added this to the Next sprint planning milestone Jul 21, 2021
@ghost
Copy link

ghost commented Jul 21, 2021

Thanks for contacting us.

We're moving this issue to the Next sprint planning milestone for future evaluation / consideration. We would like to keep this around to collect more feedback, which can help us with prioritizing this work. We will re-evaluate this issue, during our next planning meeting(s).
If we later determine, that the issue has no community involvement, or it's very rare and low-impact issue, we will close it - so that the team can focus on more important and high impact issues.
To learn more about what to expect next and how this issue will be handled you can read more about our triage process here.

@BrennanConroy
Copy link
Member

Timeout was changed from 1 second to 30 seconds in #35687, marking as test-fixed.

@TanayParikh
Copy link
Contributor

Eligible for un-quarantining Oct 23 if the test remains passing.

@ghost ghost locked as resolved and limited conversation to collaborators Nov 27, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
area-signalr Includes: SignalR clients and servers test-failure test-fixed
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants