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

finagle-http: Implement streaming disconnection tests #487

Closed

Conversation

olix0r
Copy link
Contributor

@olix0r olix0r commented Mar 28, 2016

Problem

finagle-http's streaming test coverage misses some important cases

Solution

Introduce new tests to http.StreamingTest to validate that

  1. A client behaves well when a connection is lost before a server responds.
  2. A server closes the transport after responding, as described in Finagle streaming client not closing sockets #475.

@olix0r
Copy link
Contributor Author

olix0r commented Mar 28, 2016

cc @mosesn

@olix0r olix0r force-pushed the ver/test-streaming-disconnects branch from 1b8d78d to cf4c8c5 Compare March 28, 2016 23:23
@mosesn
Copy link
Contributor

mosesn commented Mar 29, 2016

Does this need the two patches I added here: https://github.com/mosesn/finagle/commits/mnakamura/test-streaming-disconnects ?

@olix0r
Copy link
Contributor Author

olix0r commented Mar 29, 2016

@mosesn indeed it does...

@olix0r olix0r force-pushed the ver/test-streaming-disconnects branch 2 times, most recently from ddd5f64 to 090396e Compare May 26, 2016 21:48
@mosesn mosesn added Ship It and removed Ship It labels May 26, 2016
olix0r and others added 3 commits May 27, 2016 18:45
Problem

finagle-http's streaming test coverage misses some important cases

Solution

Introduce new tests to http.StreamingTest to validate that

1. A client behaves well when a connection is lost before a server responds.
2. A server closes the transport after responding, as described in twitter#475.
@olix0r olix0r force-pushed the ver/test-streaming-disconnects branch from 090396e to d0938ab Compare May 27, 2016 18:56
@olix0r
Copy link
Contributor Author

olix0r commented May 27, 2016

This branch looks right to me, but it fails (which either means there's still a bug or the tests are bad...)

[info] StreamingTest:
[info] - client: request stream fails on write *** FAILED ***
[info]   com.twitter.finagle.ChannelWriteException: com.twitter.finagle.ChannelClosedException: null at remote address: /0.0.0.0:62345. Remote Info: Not Available from service: client. Remote Info: Upstream Address: Not Available, Upstream Client Id: Not Available, Downstream Address: /0.0.0.0:62345, Downstream Client Id: client, Trace Id: bbee79fcb6d28fea.bbee79fcb6d28fea<:bbee79fcb6d28fea
[info]   at com.twitter.finagle.NoStacktrace(Unknown Source)
[info]   ...
[info]   Cause: com.twitter.finagle.ChannelClosedException: null at remote address: /0.0.0.0:62345. Remote Info: Not Available
[info]   at com.twitter.finagle.NoStacktrace(Unknown Source)
[info]   ...
[info]   Cause: java.nio.channels.ClosedChannelException:
[info]   at org.jboss.netty.channel.socket.nio.AbstractNioWorker.cleanUpWriteBuffer(AbstractNioWorker.java:433)
[info]   at org.jboss.netty.channel.socket.nio.AbstractNioWorker.writeFromUserCode(AbstractNioWorker.java:128)
[info]   at org.jboss.netty.channel.socket.nio.NioClientSocketPipelineSink.eventSunk(NioClientSocketPipelineSink.java:84)
[info]   at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendDownstream(DefaultChannelPipeline.java:779)
[info]   at org.jboss.netty.channel.SimpleChannelHandler.writeRequested(SimpleChannelHandler.java:292)
[info]   at org.jboss.netty.channel.SimpleChannelHandler.handleDownstream(SimpleChannelHandler.java:254)
[info]   at org.jboss.netty.channel.DefaultChannelPipeline.sendDownstream(DefaultChannelPipeline.java:591)
[info]   at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendDownstream(DefaultChannelPipeline.java:784)
[info]   at org.jboss.netty.channel.SimpleChannelHandler.writeRequested(SimpleChannelHandler.java:292)
[info]   at org.jboss.netty.channel.SimpleChannelHandler.handleDownstream(SimpleChannelHandler.java:254)
[info]   ...
[info] - client: response stream fails on read *** FAILED ***
[info]   com.twitter.finagle.ChannelWriteException: com.twitter.finagle.ChannelClosedException: null at remote address: /0.0.0.0:62347. Remote Info: Not Available from service: client. Remote Info: Upstream Address: Not Available, Upstream Client Id: Not Available, Downstream Address: /0.0.0.0:62347, Downstream Client Id: client, Trace Id: bbee79fcb6d28fea.bbee79fcb6d28fea<:bbee79fcb6d28fea
[info]   at com.twitter.finagle.NoStacktrace(Unknown Source)
[info]   ...
[info]   Cause: com.twitter.finagle.ChannelClosedException: null at remote address: /0.0.0.0:62347. Remote Info: Not Available
[info]   at com.twitter.finagle.NoStacktrace(Unknown Source)
[info]   ...
[info]   Cause: java.nio.channels.ClosedChannelException:
[info]   at org.jboss.netty.channel.socket.nio.AbstractNioWorker.cleanUpWriteBuffer(AbstractNioWorker.java:433)
[info]   at org.jboss.netty.channel.socket.nio.AbstractNioWorker.writeFromUserCode(AbstractNioWorker.java:128)
[info]   at org.jboss.netty.channel.socket.nio.NioClientSocketPipelineSink.eventSunk(NioClientSocketPipelineSink.java:84)
[info]   at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendDownstream(DefaultChannelPipeline.java:779)
[info]   at org.jboss.netty.channel.SimpleChannelHandler.writeRequested(SimpleChannelHandler.java:292)
[info]   at org.jboss.netty.channel.SimpleChannelHandler.handleDownstream(SimpleChannelHandler.java:254)
[info]   at org.jboss.netty.channel.DefaultChannelPipeline.sendDownstream(DefaultChannelPipeline.java:591)
[info]   at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendDownstream(DefaultChannelPipeline.java:784)
[info]   at org.jboss.netty.channel.SimpleChannelHandler.writeRequested(SimpleChannelHandler.java:292)
[info]   at org.jboss.netty.channel.SimpleChannelHandler.handleDownstream(SimpleChannelHandler.java:254)
[info]   ...
[info] - client: server disconnect on pending response should fail request
[info] - client: client closes transport after server disconnects
[info] - client: fail request writer *** FAILED ***
[info]   $anon.this.res2.isDefined was true (StreamingTest.scala:146)
[info] - client: discard respond reader *** FAILED ***
[info]   com.twitter.finagle.ChannelWriteException: com.twitter.finagle.ChannelClosedException: null at remote address: /0.0.0.0:62553. Remote Info: Not Available from service: client. Remote Info: Upstream Address: Not Available, Upstream Client Id: Not Available, Downstream Address: /0.0.0.0:62553, Downstream Client Id: client, Trace Id: bbee79fcb6d28fea.bbee79fcb6d28fea<:bbee79fcb6d28fea
[info]   at com.twitter.finagle.NoStacktrace(Unknown Source)
[info]   ...
[info]   Cause: com.twitter.finagle.ChannelClosedException: null at remote address: /0.0.0.0:62553. Remote Info: Not Available
[info]   at com.twitter.finagle.NoStacktrace(Unknown Source)
[info]   ...
[info]   Cause: java.nio.channels.ClosedChannelException:
[info]   at org.jboss.netty.channel.socket.nio.AbstractNioWorker.cleanUpWriteBuffer(AbstractNioWorker.java:433)
[info]   at org.jboss.netty.channel.socket.nio.AbstractNioWorker.writeFromUserCode(AbstractNioWorker.java:128)
[info]   at org.jboss.netty.channel.socket.nio.NioClientSocketPipelineSink.eventSunk(NioClientSocketPipelineSink.java:84)
[info]   at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendDownstream(DefaultChannelPipeline.java:779)
[info]   at org.jboss.netty.channel.SimpleChannelHandler.writeRequested(SimpleChannelHandler.java:292)
[info]   at org.jboss.netty.channel.SimpleChannelHandler.handleDownstream(SimpleChannelHandler.java:254)
[info]   at org.jboss.netty.channel.DefaultChannelPipeline.sendDownstream(DefaultChannelPipeline.java:591)
[info]   at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendDownstream(DefaultChannelPipeline.java:784)
[info]   at org.jboss.netty.channel.SimpleChannelHandler.writeRequested(SimpleChannelHandler.java:292)
[info]   at org.jboss.netty.channel.SimpleChannelHandler.handleDownstream(SimpleChannelHandler.java:254)
[info]   ...
[info] - server: request stream fails read
[info] - server: response stream fails write
[info] - server: fail response writer
[info] - server: fail request reader
[info] - end-to-end: client may process multiple streaming requests simultaneously
[info] ScalaTest
[info] Run completed in 3 seconds, 443 milliseconds.
[info] Total number of tests run: 11
[info] Suites: completed 1, aborted 0
[info] Tests: succeeded 7, failed 4, canceled 0, ignored 0, pending 0
[info] *** 4 TESTS FAILED ***

These failures originate in assertSecondRequestOk.

@olix0r
Copy link
Contributor Author

olix0r commented May 27, 2016

61f193a appears to break these tests.

Specifically, the following:

  def connect(addr: SocketAddress, mod: Modifier, name: String = "client") = {
    val fac = ClientBuilder()
      .codec(new Custom(mod, identity))
      .hosts(Seq(addr.asInstanceOf[InetSocketAddress]))
      .hostConnectionLimit(1)
      .name(name)
      .buildFactory()
    await(fac()
  }

This obtains a single connection such that when the transport fails, subsequent requests fail.

Tests pass when this is changed to:

  def connect(addr: SocketAddress, mod: Modifier, name: String = "client") =
    ClientBuilder()
      .codec(new Custom(mod, identity))
      .hosts(Seq(addr.asInstanceOf[InetSocketAddress]))
      .hostConnectionLimit(1)
      .name(name)
      .build()

@mosesn
Copy link
Contributor

mosesn commented May 28, 2016

@olix0r that patch seems to be nonsense. I don't understand it, or why either of us thought it was a good idea (you seem to have merged it in here: https://github.com/BuoyantIO/finagle/pull/3/files. Trying to find the original on my hard drive in case github did something funny here.

@mosesn
Copy link
Contributor

mosesn commented May 28, 2016

Nope, github is correct, that commit is just a bunch of nonsense. I'll try to figure out what I was thinking about again.

@mosesn
Copy link
Contributor

mosesn commented May 28, 2016

OK I just have no idea what that commit was supposed to do, but I think the test might not be right now that I'm thinking about it. If the client succeeds in writing all of its bytes to the wire, it won't realize that the remote has closed the connection until it next tries to write over the connection, so that test is inherently racy.

@olix0r
Copy link
Contributor Author

olix0r commented May 28, 2016

Yep, the client: server disconnect on pending response should fail request test times out because the response is never triggered. I could change this to attempt a write after its closed, but maybe that test isn't particularly useful.

@mosesn
Copy link
Contributor

mosesn commented May 28, 2016

The good news is that I figured out what that patch was supposed to do! The FactoryToService'd client is lazy, so it hasn't tried to establish a connection on creation. My concern was that when we made a request, we could still be establishing a connection when we cut the connection.

@mosesn
Copy link
Contributor

mosesn commented May 28, 2016

@olix0r it seems like adding a promise that you satisfy when the request has been received, and awaiting that promise also fixes the test.

@mosesn
Copy link
Contributor

mosesn commented May 28, 2016

OK, now that I think about it more, I'm confused. Why does this fix it? Why would the server never receiving the request mean that we should time out?

@olix0r
Copy link
Contributor Author

olix0r commented May 28, 2016

@mosesn is it because the read() fails on the response?

I've changed it as follows and the test now passes:

  test("client: server disconnect on pending response should fail request") {
    val failure = new Promise[Unit]
    val service = Service.mk[Request, Response] { req =>
      failure.setDone()
      Future.never
    }
    val server = startServer(service, closingTransport(failure))
    val client = connect(server.boundAddress, identity)

    val resF = client(get("/"))
    intercept[ChannelClosedException] { await(resF) }

    await(client.close())
    await(server.close())
  }

@olix0r
Copy link
Contributor Author

olix0r commented May 28, 2016

@mosesn but now i'm confused -- how is this at all functionally different than:

  test("client: server disconnect on pending response should fail request") {
    val failure = new Promise[Unit]
    val service = Service.mk[Request, Response] { req =>
      Future.never
    }
    val server = startServer(service, closingTransport(failure))
    val client = connect(server.boundAddress, identity)

    val resF = client(get("/"))
    failure.setDone()
    intercept[ChannelClosedException] { await(resF) }

    await(client.close())
    await(server.close())
  }

I assume that failure is being satisfied before the server processes the request -- why does this timeout but the other mode, where the server fully receives the request, fails?

@mosesn
Copy link
Contributor

mosesn commented May 28, 2016

OK, so thinking about it more (and adding a bunch of printlns), I think that the problem is that the client says it has successfully established a connection when the kernel finishes the handshake, and the server might not have called accept and assigned a transport yet. So there's a race between failure being set to done and calling the modifier we pass to the startServer.

The smallest diff I've found that can fix the test is removing the if (failure.isDefined) which seems pretty compelling.

A failure could be satisfied before the transport was provisioned, causing the
transport not to be closed.

Provide reusable transport-closing helper.
@mosesn mosesn added the Ship It label May 29, 2016
@mosesn
Copy link
Contributor

mosesn commented May 29, 2016

Thaaaaaaanks @olix0r

@mosesn
Copy link
Contributor

mosesn commented Jun 2, 2016

Made it to develop here: 4488767 thanks!

@mosesn mosesn closed this Jun 2, 2016
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Development

Successfully merging this pull request may close these issues.

None yet

2 participants