socket closes before a push stream is able to finish

[jonathanong]

i've been debugging why some of my push streams have been getting truncated. realized that it's because i haev much larger push streams (say 200kb) whereas my request is being sent immediately with a 204 status code. my events look like this:

acknowledged
body: resume
body: open
body: data
body: pause
socket: closed
body: destroyed (because the socket is closed)
body: readable
body: close
stream: _chunkDone
stream: drain
body: data
body: pause
stream: _chunkDone
stream: drain

where body.pipe(pushStream). how do i avoid the socket from being closed until all the current push streams are pushed? i don't get this issue when pushing smaller files.

another possibility is that an error is occuring somewhere as the push stream actually emits RST_STREAM: 3.

[indutny]

Well, any push stream could be RSTed by browser, they are optional after all. Are you experiencing this stuff with browser?

[jonathanong]

naw this is all node-spdy. i monkey patched all the .destroy()s to see what's going on, and they only occur after the socket closes. haven't checked the browser yet

[indutny]

What do you mean by socket? Underlying TCP connection?

[jonathanong]

yeah. res.socket. i don't tknow what's going on so i hijacked all the .emit()s to see what events are being emitted.

[indutny]

res.socket is a SPDY stream, not a underlying TCP socket. Could you please paste a test case that reproduces the problem?

[jonathanong]

yeah give me a bit

[jonathanong]

created this in the root directory of this lib:

var fs = require('fs');
var zlib = require('zlib');
var util = require('util');
var https = require('https');

var keys = require('./test/fixtures/keys');
var spdy = require('./');

spdy.createServer(keys, function (req, res) {
  res.statusCode = 204;
  res.end();

  console.log('response sent!');
  emit(req.socket, 'server socket')

  var stream = res.push('/fontawesome-webfont.svg', {
    'content-type': 'image/svg+xml',
    'content-encoding': 'gzip'
  })
  stream.once('acknowledge', function () {
    fs.createReadStream('fontawesome-webfont.svg')
    .pipe(zlib.createGzip())
    .pipe(stream)
    .once('finish', function () {
      // res.end();
    })
    // res.end();
  })
  emit(stream, 'push stream')
}).listen(function () {
  var agent = spdy.createAgent({
    host: 'localhost',
    port: this.address().port,
    rejectUnauthorized: false,
  })

  emit(agent, 'agent')
  agent
  .once('push', function (stream) {
    emit(stream, 'pushed stream')
    stream.resume();
  })

  var req = https.request({
    path: '/',
    method: 'POST',
    agent: agent,
  })
  .once('response', function (response) {
    emit(response, 'response')
    response.resume();
  })
  emit(req, 'request')
  req.end()
})

function emit(stream, name) {
  var emit = stream.emit
  stream.emit = function (event) {
    console.log(name + ' emitted: ' + event)
    emit.apply(stream, arguments)
  }
  return stream
}

using this file:

curl -O https://cdn.rawgit.com/FortAwesome/Font-Awesome/v4.1.0/fonts/fontawesome-webfont.svg

basically, the events emittred are:

agent emitted: newListener
request emitted: socket
request emitted: prefinish
request emitted: finish
response sent!
server socket emitted: resume
server socket emitted: readable
server socket emitted: end
server socket emitted: close
request emitted: response
response emitted: resume
response emitted: readable
response emitted: end
request emitted: close

so the push stream on the server is in fact never acknowledged because the socket is closed immediately after the response from the server is sent.

[jonathanong]

the tests never fail because your run() in your stream-test.js never called res.end(), so it keeps the socket open indefinately.

so either the server and/or the the client is prematurely closing the socket, or i'm doing something wrong. the only time it actually works if i do res.end() only after stream.once('finish'), which i wouldn't do in real life because that kind of defeats the purpose of push streams

[jonathanong]

nevermind. i got it. apparently i wrote the test not exactly how i was writing my code. i was listening to socket.on('close') to cleanup stuff, but apparently that's not how the socket works... because it's a different socket.