SwiftyRequest: KituraKit tests fail with SwiftyRequest 2.0.6

The KituraKit CI tests have started failing on Linux with SwiftyRequest 2.0.6 or newer: https://travis-ci.org/IBM-Swift/KituraKit/builds/554336585

They passed with SwiftyRequest 2.0.5: https://travis-ci.org/IBM-Swift/KituraKit/builds/526027333

It looks likely that it relates to this change: https://github.com/IBM-Swift/SwiftyRequest/commit/d9915f2a5570feab63e187174516974f4a082e20

  • my guess would be the use of URLSession.shared, though I haven’t investigated beyond looking at this diff.

The symptom seems to be this:

  • the first test that performs a POST request (MainTests.testClientPost) passes.
  • the next test also performs a POST request (MainTests.testClientPostWithIdentifier) and this fails due to a timeout.

(Note: the next test fails with a connect error, however this seems to be an unrelated symptom of the Kitura test server not being stopped+started again in time for the test execution when a previous test times out.)

However, if I reorder / comment out tests, then different tests fail with the same pattern: for example, if I comment out the testClientPost test, then testClientPostWithIdentifier passes, and the test following it fails with a timeout.

I did a little digging with some debugging

This revealed that the first POST test sends a complete HTTP message:

^[[0;39m[DEBUG] [IncomingHTTPSocketProcessor.swift:245 parse(_:from:completeBuffer:)] HTTP parser parsed 316 out of 316 bytes for socket 12^[[0;39m
^[[0;39m[DEBUG] [IncomingHTTPSocketProcessor.swift:246 parse(_:from:completeBuffer:)] Buffered bytes:
POST /users HTTP/1.1^M
Host: localhost:8080^M
Accept-Encoding: deflate, gzip^M
Accept: application/json^M
Content-Type: application/json^M
Connection: keep-alive^M
User-Agent: KituraKitPackageTests.xctest (unknown version) curl/7.35.0^M
Accept-Language: en^M
Content-Length: 43^M
^M
{"name":"John Doe","date":540899256,"id":5}^[[0;39m
^[[0;39m[VERBOSE] [HTTPServerRequest.swift:333 parsingCompleted()] HTTP request from=127.0.0.1; proto=http;^[[0;39m
^[[0;39m[VERBOSE] [CodableRouter.swift:362 postSafely(_:handler:)] Received POST type-safe request^[[0;39m

But the next test sends an incomplete message (Content-Length is specified, but no message body is written):

^[[0;39m[DEBUG] [IncomingHTTPSocketProcessor.swift:245 parse(_:from:completeBuffer:)] HTTP parser parsed 275 out of 275 bytes for socket 20^[[0;39m
^[[0;39m[DEBUG] [IncomingHTTPSocketProcessor.swift:246 parse(_:from:completeBuffer:)] Buffered bytes:
POST /usersid HTTP/1.1^M
Host: localhost:8080^M
Accept-Encoding: deflate, gzip^M
Accept: application/json^M
Content-Type: application/json^M
Connection: keep-alive^M
User-Agent: KituraKitPackageTests.xctest (unknown version) curl/7.35.0^M
Accept-Language: en^M
Content-Length: 43^M
^M
^[[0;39m
/home/djones6/swift51_repo_update/KituraKit/Tests/KituraKitTests/MainTests.swift:192: error: MainTests.testClientPostWithIdentifier : Asynchronous wait failed - Exceeded timeout of 3.0 seconds, with unfulfilled expectations: A response is received from the server -> user

This causes Kitura to wait indefinitely for the remainder of the message to be delivered, but it never is, and the test then times out while expecting a response.

About this issue

  • Original URL
  • State: closed
  • Created 5 years ago
  • Comments: 30 (4 by maintainers)

Most upvoted comments

I can conclude that this is an issue caused by abrupt connection closures on the server side and libcurl’s multi interface(with connection reuse enabled) unable to handle these abrupt closures. The solution on the server-side is a graceful shutdown of active connections (which apparently isn’t implemented in Kitura-net). The client-side solution must probably be a fix to libcurl (but proving the problem using a C test program may need more effort).

Thanks for that input @djones6

I don’t think that libcurl is involved on the Kitura-net server side. The only time that Kitura-net uses it is in ClientRequest (and that’s not in play here). For server requests, we receive bytes directly via BlueSocket and parse them using CHTTPParser.

If there’s a difference in behaviour using Kitura-net vs Kitura-NIO as the server side, then my suspicions would be either something timing related, or some difference in socket options with BlueSocket vs. swift-nio.

I don’t understand how changing the server side affects how the client side is behaving, given that both server implementations are producing the same response. I wonder if it’s somehow related to timing?