XHR Upload gets stuck

[gx0r]

2.0.0. Doing XHR file upload which looks like:

Accept:application/json, text/*
Authorization:Bearer eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9
Content-Type:multipart/form-data; boundary=----WebKitFormBoundary7Eorcxsik6vfiLcS
Origin:https://localhost:8443
User-Agent:Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/44.0.2403.130 Safari/537.36

Query String Parameters

type:audio/x-m4a
lastModified:1439253609432
size:8833949
name:06.m4a

Request Payload
------WebKitFormBoundary7Eorcxsik6vfiLcS
Content-Disposition: form-data; name="file"; filename="06 Fragile and Dear.m4a"
Content-Type: audio/x-m4a

------WebKitFormBoundary7Eorcxsik6vfiLcS--

However, upload get stuck immediately on the first chunk from the browser perspective. Server doesn't crash.

[indutny]

@llambda may I ask you to open chrome://net-internals/, restart server, let it hang again then click "Save to file" and send it to me is some way ( you may use fedor@indutny.com email).

Thanks!

[gx0r]

Yes. BTW, observation, spdy 1.32 gets stuck at 100% upload but it stalls there.

[indutny]

Whoa, this was another stupid thing that I have done :) Please update to 2.0.2 (looks like I did an accidental release)

[gx0r]

Ok, much better. It gets to 100% upload; however, it gets stuck there at 100% and never totally finishes. I am piping the upload to a file. The same thing happens also with SPDY 1.32.

When I use plain HTTPS the problem doesn't happen.

No errors or server crash.

[gx0r]

EDIT: actually, looks like it finally finished but it takes about 4 minutes after the XHR hits 100%. This is for an 8MB m4a file. A small 20kB file uploaded instantly.

Uploading a 2MB file took maybe 30 seconds.

Again with plain HTTPS it all uploads almost instantly.

Also see this a couple times in log, not sure if related, didn't notice when it occurred

Error: Got RST: CANCEL
    at Stream._handleRST (/home/u/app/node_modules/spdy/node_modules/spdy-transport/lib/spdy-transport/stream.js:265:22)
    at Stream._handleFrame (/home/u/app/node_modules/spdy/node_modules/spdy-transport/lib/spdy-transport/stream.js:118:10)
    at Connection._handleFrame (/home/u/app/node_modules/spdy/node_modules/spdy-transport/lib/spdy-transport/connection.js:296:12)
    at Parser.<anonymous> (/home/u/app/node_modules/spdy/node_modules/spdy-transport/lib/spdy-transport/connection.js:149:10)
    at emitOne (events.js:77:13)
    at Parser.emit (events.js:169:7)
    at readableAddChunk (/home/u/app/node_modules/spdy/node_modules/spdy-transport/node_modules/readable-stream/lib/_stream_readable.js:198:16)
    at Parser.Readable.push (/home/u/app/node_modules/spdy/node_modules/spdy-transport/node_modules/readable-stream/lib/_stream_readable.js:162:10)
    at Parser.Transform.push (/home/u/app/node_modules/spdy/node_modules/spdy-transport/node_modules/readable-stream/lib/_stream_transform.js:133:32)
    at next (/home/u/app/node_modules/spdy/node_modules/spdy-transport/lib/spdy-transport/protocol/base/parser.js:52:12)
    at /home/u/app/node_modules/spdy/node_modules/spdy-transport/lib/spdy-transport/protocol/http2/parser.js:71:5
    at Parser.onRSTFrame (/home/u/app/node_modules/spdy/node_modules/spdy-transport/lib/spdy-transport/protocol/http2/parser.js:349:3)
    at Parser.onFrameBody (/home/u/app/node_modules/spdy/node_modules/spdy-transport/lib/spdy-transport/protocol/http2/parser.js:147:10)
    at Parser.execute (/home/u/app/node_modules/spdy/node_modules/spdy-transport/lib/spdy-transport/protocol/http2/parser.js:64:8)
    at Parser._consume (/home/u/app/node_modules/spdy/node_modules/spdy-transport/lib/spdy-transport/protocol/base/parser.js:92:8)
    at /home/u/app/node_modules/spdy/node_modules/spdy-transport/lib/spdy-transport/protocol/base/parser.js:60:12

Edit: i need to investigate more, might be some other relevant information, hold on

[indutny]

@llambda this is pretty odd. Are you testing it with koa again? I just used formidable and something like this:

var spdy = require('./');
var fs = require('fs');
var formidable = require('formidable');

var options = {
  key: "-----BEGIN RSA PRIVATE KEY-----\nMIIEowIBAAKCAQEAy1Mogi0sHpx/rCQ3jJDuNTAVa4IjfnGWGkYKttNnNd2Zyjf6\npa+fJlOjLghSlnB4uDZCSVWLrjLAIGZopqxQ3jNSQDFyGaDGBFkVJ+u7qxzt/2MC\nlJt6aosyruCwSdcIxWnLLB3DCt43/juCWAnK/7sGpOV9CySJy7jRx7XQmPeF+EqL\nfWTP+9r8vqLfpFmz5mNetHwACGknjegQPzh/+tu4+xKIst1uPJFhJ694vNcPtLfr\nsWc2sE+pWApjfg7Ak6jMSG3LgvGZkmj5CXeEUuZ47mWLGo2MqgtQaUJrVP3zFtGM\nafP7HmEASIYPRQ1YHxxZfsSlhckoQDgkwOWXQQIDAQABAoIBAQCN5xTPfY1cM+cb\nEg++x+uoLU3VwXbaKZYT8ixKGtLekjFiI52IA0D0s8ygNOjG2+o0zpGGsvCQfBUA\nx9hj8sFhwrm12YyDfGSW5kFQokJRExi7c7N6WeSe9VVDHceLUUtq1AIbYQ4dyKeV\nhJzcqsEFp9bkQNH7c93D09J9KlRSXLa+dwVGampOfYrc0KHJUrcx9k2ge3gr26fm\nmV1vBi7+k1bADmQZjeJMCzAtpnWLHVeaukVayN9WkBi13jbasAceF/TtgGuozQp4\nnLEj9+5TZD+U8izExJlZTjjBOfHSgvcgPHs8PqUK6IiRvtdneaA6hItBjGkQIH+3\ngzuDjv0dAoGBANNo/zzuD114kF5TnupH0MNlCFaaZC5NC75SzbbVpDWyQ2wjZdrp\n9zVX0IAT7+c7ncjrtExs+fiWxYiarBkBf+DCXDpMQKcImsfSOjUvtLQO4/621plr\nJx9oz8PdtWEzcXlDHCghuNmY6EEJkpOF+eKis6eIEv2FcML2L2+BbNCbAoGBAPY1\nmS9DyC5l8RlNng0MUPeCSCqi7tQ3EfcXITMky2oncqF1/s7XPpOwJn20KkvGQ1do\nZ81KeF5hc+DeBBG9SDxoWvzppf3QEGb8Glwfsd0/s8/k+IV6q0CKhwM+RQR24DP7\nMRrHU+bLebOTHEpDA2iRPf9DUBSuLbbJY0oOTK9TAoGAOoXQUi+cdUWQwWvoi/ZB\nZjWrrz2iCecuHwuRAtH1WR/15hOOeKFX255pi2r5eEtajGojSRzJvfUOzZfzmCCA\nI9np6gF9zD9niXU6w8pm/Yk5uCMpGOM+u0UqbpALS9MP0H+xZbKgFyxq7sYVm1z1\nJbXggbn7d87evjmkO/vaAY0CgYAp/lZUU3FPSJ/ouu5cN1+P966rZwLpO0NbK5zE\nBmCTiIrqsx901A2eTwshoZsdNYHC5NHfl/YT0vdawUNcazZo5zutq4ReWCCUECfG\n0rkZjYXzzY/95EBVT8tbaEGJU2VGOG/Vq23KDaaCVHMcz3VDXpJ+eVKtVFADvzGq\nLeoydQKBgDlApjgsdfiBXOW2ThJHPx5VSMsCO8GkiWJQm+fq79xAZ7IBhY0mdLwO\nTnkZErQfvqPzgM9rr/eYZf4+Ul8xtkDa8jHuR8UZntVcMy28ck+s0OSIbPE1V9RE\nAuc1nfe4g3hQVrdHeyCHcOGZSZgFfOfW1s1qhVY/sjEMnzCPsWV6\n-----END RSA PRIVATE KEY-----",
  cert: "-----BEGIN CERTIFICATE-----\nMIICwjCCAaygAwIBAgIDAQABMAsGCSqGSIb3DQEBCzAXMRUwEwYDVQQDFgx0ZXN0\nLmluZHV0bnkwHhcNMTUwODEyMDMzNzQ1WhcNMjUwODEwMDMzNzQ1WjAXMRUwEwYD\nVQQDFgx0ZXN0LmluZHV0bnkwggEgMAsGCSqGSIb3DQEBAQOCAQ8AMIIBCgKCAQEA\ny1Mogi0sHpx/rCQ3jJDuNTAVa4IjfnGWGkYKttNnNd2Zyjf6pa+fJlOjLghSlnB4\nuDZCSVWLrjLAIGZopqxQ3jNSQDFyGaDGBFkVJ+u7qxzt/2MClJt6aosyruCwSdcI\nxWnLLB3DCt43/juCWAnK/7sGpOV9CySJy7jRx7XQmPeF+EqLfWTP+9r8vqLfpFmz\n5mNetHwACGknjegQPzh/+tu4+xKIst1uPJFhJ694vNcPtLfrsWc2sE+pWApjfg7A\nk6jMSG3LgvGZkmj5CXeEUuZ47mWLGo2MqgtQaUJrVP3zFtGMafP7HmEASIYPRQ1Y\nHxxZfsSlhckoQDgkwOWXQQIDAQABox0wGzAZBgNVHREEEjAQgg4qLnRlc3QuaW5k\ndXRueTALBgkqhkiG9w0BAQsDggEBAGYNi5CCq+/YmzH2Z7fgQ30oRdwvbn3MlM1F\nTrX33V+7Uu8bccABIrTXfOpWRMqREeygx4GvbffMvR1CnFGG5mxIEqaSSM9mBEBZ\nymlxiej6yCHAvPb3aG73Aa/bs55beOpXmRsMU3Ix9QhJzWOY6JDN0OBdSEuBBimE\n4jEnQOYczARbLKZJe7MenNo6dD7OKiwJGCFZBWFeCZBflqDm+HA5rUpG7EOi3Rr+\nGIABvRn+y0u4eVeEJBN4rWzNiMv44CD55PrbbNq9OQVIS3NmFScl4tQFDb0fgAdb\nR0ZtujqDjMY3uZZxtiu6CmBTUKhwF3tTn5sMV4Y6ZR9RgT/UEuQ=\n-----END CERTIFICATE-----",
  ALPNProtocols: [ 'spdy/3.1' ],
  NPNProtocols: [ 'spdy/3.1' ]
};

spdy.createServer(options, function(req, res) {
  if (req.url === '/upload') {
    var form = new formidable.IncomingForm();

    form.parse(req, function(err, fields, files) {
      res.writeHead(200, {'content-type': 'text/plain'});
      res.write('received upload:\n\n');
      console.log(files);
      res.end();
    });
    return;
  }

  res.writeHead(200, {
    'Content-Type': 'text/html'
  });
  res.end('<form method=POST enctype="multipart/form-data" action="upload"><input name=file type=file /><button/></form>');
}).listen(1443);

And it managed to get the whole file in a reasonable amount of time.

[gx0r]

Yep, I was doing something stupid :)

inputStream
                .pipe(new SlowStream({ maxWriteInterval:  20}))
                .pipe(outputStream);

Had that in to simulate slow uploads, forgot to disable it. All seems good now! Thanks for the help.

[indutny]

Haha! No worries, thanks for helping me figure it out!