Skip to content
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

Ktor WinHttp client echo tests fail with JobCancellationException: Parent job is Cancelling #466

Open
joffrey-bion opened this issue Mar 8, 2024 · 2 comments
Labels
blocked Issues blocked by some external dependency internal Issues that should not appear in the changelog

Comments

@joffrey-bion
Copy link
Owner

joffrey-bion commented Mar 8, 2024

This problem only occurs with the WinHttp client of the Ktor web socket implementation (thus only on Windows).

This exception surfaces when trying to assert the close frame during the echo binary and echo text tests (after the call to session.close()):

  • we collect the flow a second time in expectCloseFrame
  • we go through onCompletion a second time, which rightfully doesn't try to emit() because it sees a non-null error parameter, so it lets the error through
  • the error is caught by the catch operator, which reports a JobCancellationException: Parent job is Cancelling caused by an exception that seems to be thrown during the session.close() call:
IllegalStateException: Unable to close WebSocket: The operation completed successfully. Error 0 (0x80070000)

This seems to be thrown here in the Ktor client:
https://github.com/ktorio/ktor/blob/0a8cb15f6ff600decd6198d3f71bd39f9f482f0d/ktor-client/ktor-client-winhttp/windows/src/io/ktor/client/engine/winhttp/internal/WinHttpWebSocket.kt#L225

And getWinHttpException is defined as such:
https://github.com/ktorio/ktor/blob/0a8cb15f6ff600decd6198d3f71bd39f9f482f0d/ktor-client/ktor-client-winhttp/windows/src/io/ktor/client/engine/winhttp/internal/WinHttpExceptions.kt#L23-L29

Which may explain the part The operation completed successfully, because we try to get the "last error" while there may have been none.


Extra traces during a test run (which helped figuring out the above summary):

KTOR onEach Binary emittedCloseFrame=false
KTOR onCompletion emittedCloseFrame=false error=kotlinx.coroutines.flow.internal.AbortFlowException: Flow was aborted, no more elements needed (cause=null)
KTOR close() closing... (isActive=true)
KTOR close() done (isActive=true)
KTOR onCompletion emittedCloseFrame=false error=kotlinx.coroutines.JobCancellationException: Parent job is Cancelling; job=JobImpl{Cancelled}@9d011b0 (cause=kotlin.IllegalStateException: Unable to close WebSocket: The operation completed successfully. Error 0 (0x80070000))
KTOR catch th=kotlinx.coroutines.JobCancellationException: Parent job is Cancelling; job=JobImpl{Cancelled}@9d011b0

kotlin.AssertionError: Expected Close frame (after echo binary), but the flow failed with org.hildan.krossbow.websocket.WebSocketException: error in Ktor's websocket: kotlinx.coroutines.JobCancellationException: Parent job is Cancelling; job=JobImpl{Cancelled}@9d011b0
kotlin.AssertionError: Expected Close frame (after echo binary), but the flow failed with org.hildan.krossbow.websocket.WebSocketException: error in Ktor's websocket: kotlinx.coroutines.JobCancellationException: Parent job is Cancelling; job=JobImpl{Cancelled}@9d011b0
	at kotlin.Error#<init>(Unknown Source)
	at kotlin.AssertionError#<init>(Unknown Source)
	at kotlin.test.DefaultAsserter#fail(Unknown Source)
	at kotlin.test.Asserter#fail(Unknown Source)
	at kotlin.test#fail(Unknown Source)
	at org.hildan.krossbow.websocket.test.expectCloseFrame$lambda$3$lambda$2#internal(Unknown Source)
        ...
@joffrey-bion
Copy link
Owner Author

Possible things to investigate:

  • why does GetLastError return 0 after WinHttpWebSocketShutdown returning a non-zero code?
  • why do we send the frames asynchronously via globally launched coroutines during the WinHttp web socket instantiation (init block)? This prevents us from getting an exception when calling close()

@joffrey-bion joffrey-bion added the internal Issues that should not appear in the changelog label Mar 9, 2024
@joffrey-bion
Copy link
Owner Author

I opened an issue to the Ktor team:
https://youtrack.jetbrains.com/issue/KTOR-6845

@joffrey-bion joffrey-bion added the blocked Issues blocked by some external dependency label Sep 22, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
blocked Issues blocked by some external dependency internal Issues that should not appear in the changelog
Projects
None yet
Development

No branches or pull requests

1 participant