node.js - nginx/sails.js : incomplete file upload

Question

我们正在使用 sails.js 开发一个应用程序。在此应用程序中，我们有一个上传 Controller :
https://github.com/makinacorpus/mnhn_bai/blob/master/api/controllers/Object3DController.js

该 Controller 在底层使用了船长，如文档中所述。

现在的问题是，当我们上传大文件时，它们存储不完整，上传的大小永远不会相同，对于 15 mb 的文件，大小从 7mb 到 14mb 不等。

架构如下:
haproxy -> nginx -> node.js/sails。

如果我们用简单的 apache + proxypass 配置替换 nginx 反向代理，上传就可以完美地工作。

如果我们用一个简单的 python 上传 Controller (例如在 Flask 中)替换 Node.js 应用程序，上传也会显示正确的长度和数据。

当然，nginx 已经正确配置了缓冲区大小、client_body_timeout 和 client_max_body_size，正如我所说，Flask 刚刚正确接收了上传。

使用nginx应用程序上传导致200响应，因此看起来文件已上传，但实际上在磁盘上，文件不完整。

在nginx调试日志中我们可以看到:

2014/12/03 01:57:23 [debug] 39583#0: *1 http proxy header:
"POST /admin/edit_object/6 HTTP/1.1^M
Host: xxxxxx.makina-corpus.net^M
X-Real-IP: xxxx^M
X-Forwarded-For: xxxxx^M
X-NginX-Proxy: true^M
X-Forwarded-Proto: http^M
Connection: upgrade^M
Content-Length: 15361775^M
Origin: http://bai.makina-corpus.net^M
User-Agent: Mozilla/5.0 (Unknown; Linux x86_64) AppleWebKit/534.34 (KHTML, like Gecko) CasperJS/1.1.0-beta3+PhantomJS/1.9.8 Safari/534.34^M
Content-Type: multipart/form-data; boundary=----WebKitFormBoundaryRt4v4f7RkrlzUEX2^M
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8^M
Referer: http://xxxxxxxxxx.makina-corpus.net/admin/edit_object/6^M
Cookie: sails.sid=s%3Akv_Gxxxxxxxx2F5iaDWA^M
Accept-Encoding: gzip^M
Accept-Language: en,*^M
Authorization: Basic xxxx=^M
^M
"
2014/12/03 01:57:23 [debug] 39583#0: *1 http cleanup add: 00000000011CC520
2014/12/03 01:57:23 [debug] 39583#0: *1 init keepalive peer
2014/12/03 01:57:23 [debug] 39583#0: *1 get keepalive peer
2014/12/03 01:57:23 [debug] 39583#0: *1 get rr peer, try: 1
2014/12/03 01:57:23 [debug] 39583#0: *1 get keepalive peer: using connection 0000000001156018
2014/12/03 01:57:23 [debug] 39583#0: *1 http upstream connect: -4
2014/12/03 01:57:23 [debug] 39583#0: *1 http upstream send request
2014/12/03 01:57:23 [debug] 39583#0: *1 chain writer buf fl:0 s:806
2014/12/03 01:57:23 [debug] 39583#0: *1 chain writer buf fl:1 s:15361775
2014/12/03 01:57:23 [debug] 39583#0: *1 chain writer in: 00000000011CC5C0
2014/12/03 01:57:23 [debug] 39583#0: *1 tcp_nopush
2014/12/03 01:57:23 [debug] 39583#0: *1 writev: 806
2014/12/03 01:57:23 [debug] 39583#0: *1 sendfile: @0 15361775
2014/12/03 01:57:23 [debug] 39583#0: *1 sendfile: 2776864, @0 2776864:15361775
2014/12/03 01:57:23 [debug] 39583#0: *1 chain writer out: 00000000011CC5D0
2014/12/03 01:57:23 [debug] 39583#0: *1 event timer add: 35: 60000:1417568303245
2014/12/03 01:57:23 [debug] 39583#0: *1 http run request: "/admin/edit_object/6?"
2014/12/03 01:57:23 [debug] 39583#0: *1 http request empty handler
2014/12/03 01:57:23 [debug] 39583#0: *1 http upstream request: "/admin/edit_object/6?"
2014/12/03 01:57:23 [debug] 39583#0: *1 http upstream send request handler
2014/12/03 01:57:23 [debug] 39583#0: *1 http upstream send request
2014/12/03 01:57:23 [debug] 39583#0: *1 chain writer in: 00000000011CC5D0
2014/12/03 01:57:23 [debug] 39583#0: *1 sendfile: @2776864 12584911
2014/12/03 01:57:23 [debug] 39583#0: *1 sendfile: 2488810, @2776864 2488810:12584911
2014/12/03 01:57:23 [debug] 39583#0: *1 chain writer out: 00000000011CC5D0
2014/12/03 01:57:23 [debug] 39583#0: *1 event timer del: 35: 1417568303245
2014/12/03 01:57:23 [debug] 39583#0: *1 event timer add: 35: 60000:1417568303254
2014/12/03 01:57:23 [debug] 39583#0: *1 http upstream request: "/admin/edit_object/6?"
2014/12/03 01:57:23 [debug] 39583#0: *1 http upstream process header
2014/12/03 01:57:23 [debug] 39583#0: *1 malloc: 00000000011CD000:262144
2014/12/03 01:57:23 [debug] 39583#0: *1 recv: fd:35 369 of 262144
2014/12/03 01:57:23 [debug] 39583#0: *1 http proxy status 200 "200 OK"
2014/12/03 01:57:23 [debug] 39583#0: *1 http proxy header: "X-Powered-By: Sails <sailsjs.org>"
2014/12/03 01:57:23 [debug] 39583#0: *1 http proxy header: "Access-Control-Allow-Origin: "
2014/12/03 01:57:23 [debug] 39583#0: *1 http proxy header: "Access-Control-Allow-Credentials: "
2014/12/03 01:57:23 [debug] 39583#0: *1 http proxy header: "Access-Control-Allow-Methods: "
2014/12/03 01:57:23 [debug] 39583#0: *1 http proxy header: "Access-Control-Allow-Headers: "
2014/12/03 01:57:23 [debug] 39583#0: *1 http proxy header: "Content-Type: application/json; charset=utf-8"
2014/12/03 01:57:23 [debug] 39583#0: *1 http proxy header: "Content-Length: 33"
2014/12/03 01:57:23 [debug] 39583#0: *1 http proxy header: "Vary: Accept-Encoding"
2014/12/03 01:57:23 [debug] 39583#0: *1 http proxy header: "Date: Wed, 03 Dec 2014 00:57:23 GMT"
2014/12/03 01:57:23 [debug] 39583#0: *1 http proxy header: "Connection: keep-alive"
2014/12/03 01:57:23 [debug] 39583#0: *1 http proxy header done
2014/12/03 01:57:23 [debug] 39583#0: *1 uploadprogress error-tracker error: 0
2014/12/03 01:57:23 [debug] 39583#0: *1 xslt filter header
2014/12/03 01:57:23 [debug] 39583#0: *1 HTTP/1.1 200 OK^M
Server: nginx^M
Date: Wed, 03 Dec 2014 00:57:23 GMT^M

问题似乎是船长似乎从未遇到上游级别的“完成”事件，无限循环？ sails 标准输出

Parser: Done reading textparam through field `gallery`
Parser: Done reading textparam through field `category`
Parser: Done reading textparam through field `copyright`
Parser: Done reading textparam through field `published`
Parser: Done reading textparam through field `filename_3D`
Parser: Done reading textparam through field `filename_flat`
Parser: Done reading textparam through field `preview`
Parser: Done reading textparam through field `preview_animated`
Something is trying to read from Upstream `media_files`...
Passing control to app...
User allowed : admin ( 1 )
RenamerPump:
• dirname => undefined
• field => media_files
• fd => 04cb80ba-dce6-4a1d-9b54-ac8b08ca3e06
100
100
100
100
100
100
100
100
100
100
100

有趣的是，上传后磁盘上的文件在末尾包含来自另一个不相关请求的 header :

07bb890: 3130 3130 3130 3130 3130 3130 3130 3130  1010101010101010
07bb8a0: 3130 3130 3130 3130 3130 3130 3130 3130  1010101010101010
07bb8b0: 3130 3130 3130 3130 3130 3130 3130 3130  1010101010101010
07bb8c0: 3130 3130 3130 3130 3130 3130 4745 5420  101010101010GET
07bb8d0: 2f20 4854 5450 2f31 2e31 0d0a 486f 7374  / HTTP/1.1..Host
07bb8e0: xxxx xxxx xxxx xxxx xxxx xxxx 2d63 6f72  : xxx.makina-cor
07bb8f0: 7075 732e 6e65 740d 0a58 2d52 6561 6c2d  pus.net..X-Real-
07bb900: 4950  
07bb910: 3134 0d0a 582d 466f 7277 6172 6465 642d  14..X-Forwarded-
07bb920: 466f                                     For: xxxxxxxxxxx
07bb930: 2e31                              
07bb940: 2e31 340d 0a58 2d4e 6769 6e58 2d50 726f  .14..X-NginX-Pro
07bb950: 7879 3a20 7472 7565 0d0a 582d 466f 7277  xy: true..X-Forw
07bb960: 6172 6465 642d 5072 6f74 6f3a 2068 7474  arded-Proto: htt
07bb970: 700d 0a43 6f6e 6e65 6374 696f 6e3a 2075  p..Connection: u
07bb980: 7067 7261 6465 0d0a 5573 6572 2d41 6765  pgrade..User-Age
07bb990: 6e74 3a20 4d6f 7a69 6c6c 612f 352e 3020  nt: Mozilla/5.0
07bb9a0: 2855 6e6b 6e6f 776e 3b20 4c69 6e75 7820  (Unknown; Linux
07bb9b0: 7838 365f 3634 2920 4170 706c 6557 6562  x86_64) AppleWeb
07bb9c0: 4b69 742f 3533 342e 3334 2028 4b48 544d  Kit/534.34 (KHTM
07bb9d0: 4c2c 206c 696b 6520 4765 636b 6f29 2043  L, like Gecko) C
07bb9e0: 6173 7065 724a 532f 312e 312e 302d 6265  asperJS/1.1.0-be
07bb9f0: 7461 332b 5068 616e 746f 6d4a 532f 312e  ta3+PhantomJS/1.
07bba00: 392e 3820 5361 6661 7269 2f35 3334 2e33  9.8 Safari/534.3
07bba10: 340d 0a41 6363 6570 743a 2074 6578 742f  4..Accept: text/
07bba20: 6874 6d6c 2c61 7070 6c69 6361 7469 6f6e  html,application
07bba30: 2f78 6874 6d6c 2b78 6d6c 2c61 7070 6c69  /xhtml+xml,appli
07bba40: 6361 7469 6f6e 2f78 6d6c 3b71 3d30 2e39  cation/xml;q=0.9
07bba50: 2c2a 2f2a 3b71 3d30 2e38 0d0a 4163 6365  ,*/*;q=0.8..Acce
07bba60: 7074 2d45 6e63 6f64 696e 673a 2067 7a69  pt-Encoding: gzi
07bba70: 700d 0a41 6363 6570 742d 4c61 6e67 7561  p..Accept-Langua
07bba80: 6765 3a20 656e 2c2a 0d0a 4175 7468 6f72  ge: en,*..Author
07bba90: 697a 6174 696f 6e3a 2042 6173 6963 2063  ization: Basic c
07bbaa0: 6d39 xxxx xxxx xxxx xxxx 3d0d 0a         xxxx=..
(END)

而在其他请求中，我们没有其他请求 header ，而只是一个不完整的文件。这里，缺失的位来自原始文件的末尾，开头始终是正确的。

请注意，与 apache 的主要区别在于 nginx 向 sails 应用程序快速发送大量数据。相反，apache 正在流式传输请求。这是因为 nginx 确实请求缓冲。

如果有人知道从哪里继续在船长中挖掘上传问题!

如果我用这个例子替换 save 方法，我会看到来自 nginx 的位被正确写入，我在 POSTed 数据中有完整且正确的文件，所以错误显然是在船长请求消耗中的某个地方

var body = "";
req.on('data', function (chunk) {
  body += chunk;
});
req.on('end', function () {
  console.log('POSTed: ' + body.length);
  console.log('POSTed: ' + body.slice(-400));
  res.writeHead(200);
  res.end('<html/>');
});

Answer 1

从 nginx 调试日志来看，问题似乎是由于后端提前返回响应造成的 - 请注意，在最后一次 sendfile() 调用中，nginx 只能发送它尝试发送的 12584911 字节中的 2488810 字节:

...
2014/12/03 01:57:23 [debug] 39583#0: *1 chain writer in: 00000000011CC5D0
2014/12/03 01:57:23 [debug] 39583#0: *1 sendfile: @2776864 12584911
2014/12/03 01:57:23 [debug] 39583#0: *1 sendfile: 2488810, @2776864 2488810:12584911
2014/12/03 01:57:23 [debug] 39583#0: *1 chain writer out: 00000000011CC5D0
2014/12/03 01:57:23 [debug] 39583#0: *1 event timer del: 35: 1417568303245
2014/12/03 01:57:23 [debug] 39583#0: *1 event timer add: 35: 60000:1417568303254
2014/12/03 01:57:23 [debug] 39583#0: *1 http upstream request: "/admin/edit_object/6?"
2014/12/03 01:57:23 [debug] 39583#0: *1 http upstream process header
2014/12/03 01:57:23 [debug] 39583#0: *1 malloc: 00000000011CD000:262144
2014/12/03 01:57:23 [debug] 39583#0: *1 recv: fd:35 369 of 262144
2014/12/03 01:57:23 [debug] 39583#0: *1 http proxy status 200 "200 OK"
2014/12/03 01:57:23 [debug] 39583#0: *1 http proxy header: "X-Powered-By: Sails <sailsjs.org>"
...

后端返回了 200 OK 答案。此时，nginx 认为没有理由发送请求正文的其余部分并停止发送 - 这就是导致上传文件不完整的原因。此外，您还配置了 keepalive 上游连接，并且您正在点击 this bug - 这就是为什么您会看到不相关请求的 header 。

教导后端代码仅在完全读取请求后发送响应(如您的测试代码中所示)应该可以解决问题。