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

connection: ignore window updates after end stream #40

Open
wants to merge 1 commit into
base: master
Choose a base branch
from

Conversation

dougwilson
Copy link

👋 Hi & thanks for the awesome module! I recently ran into an issue with a client that seemed to sometimes have a race condition where spdy-transport would receive a WINDOW_UPDATE frame on a stream that the server (run using spdy-transport) had ended. This seems to have been network queuing quirks or something.

After banging my head for a while, I realized that the spdy-transport as a server should probably just be ignoring those frames, at least from my read through of the specs (and NGINX seems to be doing just that).

Here is what I found in the HTTP/2 spec (https://tools.ietf.org/html/rfc7540#section-6.9):

WINDOW_UPDATE can be sent by a peer that has sent a frame bearing the
END_STREAM flag. This means that a receiver could receive a
WINDOW_UPDATE frame on a "half-closed (remote)" or "closed" stream.
A receiver MUST NOT treat this as an error (see Section 5.1).

I don't know a lot about SPDY, and so not sure if the change should be applied to the SPDY versions. I tried to look a little bit and saw the following in https://www.chromium.org/spdy/spdy-protocol/spdy-protocol-draft3#TOC-2.6.8-WINDOW_UPDATE :

A sender should ignore all the WINDOW_UPDATE frames associated with the stream after it send the last frame for the stream.

I'm not 100% sure I'm interpreting this correctly, and even if I am, not sure if the approach I took in this PR is the best solution for your architecture :) but maybe it is or you have some pointers.

Copy link
Member

@daviddias daviddias left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hi @dougwilson, thank you for this PR and all the pointers, made it super easy to understand the situation. You PR sounds right, the test just doesn't seem to cover the change, could you check, please?

delta: 1
}, function (err) {
assert(!err)
setTimeout(done, 10)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks like this is just making the test pass super quickly. You need to make sure that the assert on line 307 happens.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hi @diasdavid I wasn't very familiar with the architecture. The entire point of the PR is that the frame event won't fire any longer with a frame type of RST and id of 1. How should I test the absence of that emission?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No worries at all! I'm also refreshing my memory on all of this :)

Made a couple of suggestions above, that plus increasing the timeout to 100ms will be enough.

stream.resume()

stream.once('close', function () {
client.on('frame', function (frame) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Line 306 should be server.on('frame', ..., since it will be sent by the client and ignored by the server.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Making this change the tests no longer pass.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Meaning that the frame keeps being emitted? Could you c&p the error log?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

  8) Transport/Push spdy (v2) should not error on extra PRIORITY frame:

      Uncaught AssertionError: 'DATA' != 'DATA'
      + expected - actual


      at Connection.<anonymous> (C:\Users\dougw\GitHub\nodejs-spdy-transport\test\both\transport\push-test.js:339:16)
      at Connection._handleFrame (C:\Users\dougw\GitHub\nodejs-spdy-transport\lib\spdy-transport\connection.js:273:8)
      at Parser.<anonymous> (C:\Users\dougw\GitHub\nodejs-spdy-transport\lib\spdy-transport\connection.js:155:10)
      at readableAddChunk (C:\Users\dougw\GitHub\nodejs-spdy-transport\node_modules\readable-stream\lib\_stream_readable.js:217:18)
      at Parser.Readable.push (C:\Users\dougw\GitHub\nodejs-spdy-transport\node_modules\readable-stream\lib\_stream_readable.js:176:10)
      at Parser.Transform.push (C:\Users\dougw\GitHub\nodejs-spdy-transport\node_modules\readable-stream\lib\_stream_transform.js:123:32)
      at next (C:\Users\dougw\GitHub\nodejs-spdy-transport\lib\spdy-transport\protocol\base\parser.js:53:12)
      at C:\Users\dougw\GitHub\nodejs-spdy-transport\lib\spdy-transport\protocol\spdy\parser.js:57:5
      at Parser.onFrameBody (C:\Users\dougw\GitHub\nodejs-spdy-transport\lib\spdy-transport\protocol\spdy\parser.js:132:12)
      at Parser.execute (C:\Users\dougw\GitHub\nodejs-spdy-transport\lib\spdy-transport\protocol\spdy\parser.js:49:8)
      at Parser._consume (C:\Users\dougw\GitHub\nodejs-spdy-transport\lib\spdy-transport\protocol\base\parser.js:95:8)
      at C:\Users\dougw\GitHub\nodejs-spdy-transport\lib\spdy-transport\protocol\base\parser.js:62:12
      at _combinedTickCallback (internal/process/next_tick.js:73:7)
      at process._tickCallback (internal/process/next_tick.js:104:9)

  9) SPDY Transport autoSpdy31 should automatically switch on server:
     Error: timeout of 2000ms exceeded. Ensure the done() callback is being called in this test.
      at Timeout.<anonymous> (C:\Users\dougw\GitHub\nodejs-spdy-transport\node_modules\mocha\lib\runnable.js:226:19)

stream.once('close', function () {
client.on('frame', function (frame) {
assert(!(frame.type === 'RST' && frame.id === 1))
})
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If you could move this assert (306~308) to outside of the stream.once('close', you could send multiple windowUpdateFrame and see it being processed before and confirming that it doesn't get emitted after the close happens.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Making this change makes the tests no longer pass.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

  4) Transport/Connection spdy (v3.1) should ignore WINDOW_UPDATE frame after END_STREAM:

      Uncaught AssertionError: false == true
      + expected - actual

      -false
      +true

      at Connection.<anonymous> (C:\Users\dougw\GitHub\nodejs-spdy-transport\test\both\transport\connection-test.js:305:13)
      at Connection._handleFrame (C:\Users\dougw\GitHub\nodejs-spdy-transport\lib\spdy-transport\connection.js:273:8)
      at Parser.<anonymous> (C:\Users\dougw\GitHub\nodejs-spdy-transport\lib\spdy-transport\connection.js:155:10)
      at readableAddChunk (C:\Users\dougw\GitHub\nodejs-spdy-transport\node_modules\readable-stream\lib\_stream_readable.js:217:18)
      at Parser.Readable.push (C:\Users\dougw\GitHub\nodejs-spdy-transport\node_modules\readable-stream\lib\_stream_readable.js:176:10)
      at Parser.Transform.push (C:\Users\dougw\GitHub\nodejs-spdy-transport\node_modules\readable-stream\lib\_stream_transform.js:123:32)
      at next (C:\Users\dougw\GitHub\nodejs-spdy-transport\lib\spdy-transport\protocol\base\parser.js:53:12)
      at C:\Users\dougw\GitHub\nodejs-spdy-transport\lib\spdy-transport\protocol\spdy\parser.js:57:5
      at Parser.onRSTFrame (C:\Users\dougw\GitHub\nodejs-spdy-transport\lib\spdy-transport\protocol\spdy\parser.js:387:3)
      at Parser.onFrameBody (C:\Users\dougw\GitHub\nodejs-spdy-transport\lib\spdy-transport\protocol\spdy\parser.js:143:10)
      at Parser.execute (C:\Users\dougw\GitHub\nodejs-spdy-transport\lib\spdy-transport\protocol\spdy\parser.js:49:8)
      at Parser._consume (C:\Users\dougw\GitHub\nodejs-spdy-transport\lib\spdy-transport\protocol\base\parser.js:95:8)
      at C:\Users\dougw\GitHub\nodejs-spdy-transport\lib\spdy-transport\protocol\base\parser.js:62:12
      at _combinedTickCallback (internal/process/next_tick.js:73:7)
      at process._tickCallback (internal/process/next_tick.js:104:9)

delta: 1
}, function (err) {
assert(!err)
setTimeout(done, 10)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No worries at all! I'm also refreshing my memory on all of this :)

Made a couple of suggestions above, that plus increasing the timeout to 100ms will be enough.

@dougwilson
Copy link
Author

The PR was from so many months ago, I don't really remember the particulars. I tried my best to put together some test that passes with the fix but fails without the fix. In the end, since I never heard back, we forked this module and have an internal copy with lots of fixes, and since MIT doesn't require sharing the patches back, I would have to get legal to sign off on sharing the patches. I'm no longer on the same team, so really don't know how that would work.

From my limited remembrance of the changes, AFAIK the listener is on the client because it is the client within the code that is emitting the RST frame that the fix blocks, so I don't understand why the listener should be on the server (but that seems to cause failures making that change from random other tests, presumably because the server object is shared between all the tests).

The second suggested change seems to fail because a RST can occur prior to the stream close (though I haven't tracked down where it comes from, exactly, so not sure if it is expected 100% of the time or not), so probably additional change would need to be made in order to assert they are allow before stream close but not after.

You have permissions on GitHub to edit my branch, so please feel free to make any tweaks you see fit 💯

@dougwilson
Copy link
Author

P.S. I pushed an update for the timeout change from 10 to 100.

@daviddias
Copy link
Member

daviddias commented May 23, 2017

Oh wow, apologies for failing to respond quickly enough, sad that you had to go the fork route, I would definitely appreciate the bug fixes and the help maintaining the module overall.

I've pulled down your branch and saw what you reported, the fact that the tests are operating over the same server makes the other tests fail, need to rework that to make them independent. My availability is not looking any better currently, hopefully, might schedule will get a bit lighter close to July, then I want to give some love to all the repos in the spdy-http2 org.

@dougwilson
Copy link
Author

Yea, the lag is no problem, stuff happens; I'm no different regarding that :) I honestly just don't remember a lot of the details on the PR off-hand these days.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

Successfully merging this pull request may close these issues.

2 participants