KituraKit tests fail with SwiftyRequest 2.0.6 #69
Comments
|
This issue doesn't reproduce with Swift 5.0.1 on trusty, but it does with 5.0.1 on xenial. |
|
Correction: I do see failures on trusty too. |
|
I ran the tests with |
|
|
A significant difference while running with a |
|
So, I can confirm that if we don't use |
|
Studied the two subsequent So, in short, there are two POST requests.
This is the tcpdump output in the failing case is: tcpdump: verbose output suppressed, use -v or -vv for full protocol decode Header of the first request arrives from remote port 39558 Body of the first request arrives from remote port 39558 Response for the first request is sent to remote port 39558 Header for the second request arrives on the same port 39558 Body of the second request arrives from port 39558 A duplicate body pertaining to the second request arrives from port 39558 Header of the second request arrives from a new remote port 39562 No body for the second request arrives from the new port 39562 |
|
Surprisingly, things are quite straightforward with Kitura-NIO: Header for the first request arrives from remote port 39596 Body pertaining to the first request arrives from remote port 39596 Response is sent to remote port 39596 Header of the second request arrives from the same port 39596 Body of the second request arrives from the same port 39596 Response for the second response sent to remote port 39596 |
|
I wonder how the server (Net vs. NIO) changes the nature of the incoming request messages. I checked and confirmed that both Net and NIO use |
|
Ran the test with the latest |
So, this issue isn't related to Kitura/Kitura#1465 |
|
I am now able to repro the issue using this sample program: |
|
The program hangs in the second |
|
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? |
|
Yes, can't rule out a timing issue. |
Oh, but the |
|
I tried to track new HTTP connections using the tcpdump command: Clearly, the two tests make two connections, which is expected. Kitura-NIO Kitura-NIO makes only one connection. This is wrong. When we have one server per test, there's no question of running the two tests on a single connection. I then tried to track the Then, tracking both new connections and connection closures, the activity on (notice the Clearly, we aren't closing active connections in Kitura-NIO on |
|
I created Kitura/Kitura-NIO#216 to track the Kitura-NIO issue. |
|
I put a hack in Still, I wasn't able to reproduce the problem with Kitura-NIO. |
|
Assuming that Kitura-NIO closes active connections on For Kitura-net there's a passing and a failing case: Failing case |
|
Why a Kitura-net based server sent an An Only using I suspect this issue is due to some complex interplay of URLSession - a libcurl enabled client using the |
|
I don't think that 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. |
|
Thanks for that input @djones6 |
|
With this change to abruptly shutdown all active connections during an The first test established a connection with the first server instance and completed its transfer. The server was stopped, all connections are reset. The second test comes up and libcurl's multi handle reuses the first connection for it. Midway, the server's RST packet reaches the second test client but it has already finished a part of its transfer. From there, libcurl tries to recover from here, but fails. Perhaps, if we implemented quiescing in both Kitura-NIO and Kitura-net, the failure may go away. But even in that case, we'd be connecting to the server of test 1, for test 2 and completing the test. This may or may not be acceptable. It seems like it is the asynchronous nature of a |
|
More about connection reuse here: https://ec.haxx.se/libcurl-connectionreuse.html |
|
I put a hack in libcurl to forbid handle reuse here by |
|
There is a related CURLOPT_FORBID_REUSE which could be configured in a |
|
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). |
|
Closing as Kitura/Kitura-net#306 is remaining work needed to resolve this |
|
For reference, Kitura/KituraKit#50 (specifically Kitura/KituraKit@c1f4d1d) refactors the KituraKit tests into a separate, long-lived TestServer process, which will effectively hide this issue. @pushkarnk it would be worth posting your recreate code to Kitura/Kitura-net#306 so that we can recreate the failure while working on the equivalent fix there. |
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: d9915f2
URLSession.shared, though I haven't investigated beyond looking at this diff.The symptom seems to be this:
POSTrequest (MainTests.testClientPost) passes.POSTrequest (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
testClientPosttest, thentestClientPostWithIdentifierpasses, and the test following it fails with a timeout.I did a little digging with some debugging
PrintLoggerfrom the Kitura tests2.3.0+debugging+clientbranch of Kitura-netThis revealed that the first POST test sends a complete HTTP message:
But the next test sends an incomplete message (Content-Length is specified, but no message body is written):
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.
The text was updated successfully, but these errors were encountered: