search

cloudhead / node-static

rfc 2616 compliant HTTP static-file server module, with built-in caching.
MIT License
2.17k stars 245 forks source link

"Cannot set headers..." error happening only on one specific kind of request #207

Closed getify closed 1 year ago

getify commented 6 years ago

I'm using Node 10.1.0, and node-static v0.7.2. The error stack in my logs:

Error [ERR_HTTP_HEADERS_SENT]: Cannot set headers after they are sent to the client
    at ServerResponse.setHeader (_http_outgoing.js:471:11)
    at ServerResponse.writeHead (_http_server.js:231:21)
    at Server.finish (/tmp/site/node_modules/node-static/lib/node-static.js:125:17)
    at finish (/tmp/site/node_modules/node-static/lib/node-static.js:170:14)
    at /tmp/site/node_modules/node-static/lib/node-static.js:337:13
    at streamFile (/tmp/site/node_modules/node-static/lib/node-static.js:382:13)
    at ReadStream.<anonymous> (/tmp/site/node_modules/node-static/lib/node-static.js:375:17)
    at ReadStream.emit (events.js:182:13)
    at fs.close (fs.js:2161:14)
    at FSReqWrap.oncomplete (fs.js:152:20)

I'm experiencing this persistent error every single time a specific kind of request comes in -- but only for that, all other requests are fine -- which appears to be a request from a Slackbot. Here are the request headers from the specific request:

{"x-forwarded-host":"my.domain.tld","x-forwarded-proto":"https","x-forwarded-port":"443","x-forwarded-for":"::ffff:52.71.192.87","if-modified-since":"Mon, 17 Oct 2016 23:58:19 GMT","accept-encoding":"gzip,deflate","accept":"*/*","user-agent":"Slackbot 1.0 (+https://api.slack.com/robots)","host":"my.domain.tld","connection":"close"}

Here's my code:

"use strict";

var path = require("path");
var http = require("http");
var httpServer = http.createServer(handleRequest);
var nodeStatic = require("node-static");
var staticServer = new nodeStatic.Server(path.join(__dirname,"static"),{
        serverInfo: "my-server",
        cache: 86400,
        gzip: true,
});

const HSTS = `max-age=${1E9}; includeSubdomains`;

httpServer.listen(8003);

// *********************

function handleRequest(req,res) {
        // unconditional, permanent HTTPS redirect
        if (req.headers["x-forwarded-proto"] !== "https") {
                res.writeHead(301,{
                        "Strict-Transport-Security": HSTS,
                        "Cache-Control": "public, max-age=31536000",
                        Expires: new Date(Date.now() + 31536000000).toUTCString(),
                        Location: `https://${req.headers["host"]}${req.url}`
                });
                res.end();
        }
        else if (["GET","HEAD"].includes(req.method)) {
                req.addListener("end",function requestEnd(){
                        req.removeListener("end",requestEnd);
                        res.setHeader("Strict-Transport-Security",HSTS);
                        staticServer.serve(req,res);
                }).resume();
        }
        else {
                res.writeHead(404,{ "Strict-Transport-Security": HSTS });
                res.end();
        }
}

As you can see, my server is running on localhost:8003 -- I have a public server on 80/443 that proxies the requests after doing SSL certificate handling, etc.

In my debugging, I have narrowed down that the error happens inside of the staticServer.serve(..) call itself, not in this code shown.

And the res.setHeader(..) call that I make before serve(..) seems to cause the error, though I don't understand why. If I comment that line of code out, the error stops.

But my understanding is that me calling setHeader(..) only queues up a header to be sent. It's not supposed to flush headers or anything, only prepare a header for later sending. I don't have any other calls in that code path to res.writeHead(..) or anything, so I can't figure out how the error is getting triggered.

I am aware that I could set this response header in the new nodeStatic.Server(..) constructor call. But I don't want to do it there, because I actually need to be able to set specific headers on a per-request basis under certain conditions, and that approach sets headers for all static-file responses.

Can you help me figure out why, in only this one specific Slackbot request case, my call to setHeader(..) is triggering logic in node-static that causes this error? I'm really perplexed.

1ns3cur3 commented 6 years ago

I tried this via Postman (don't know how accurate my approach is) but on node v10.0.0, I am consistently getting 404. Doesn't matter which source path I take (forcefully) in Server.prototype.finish.

Let me try with node 10.1.0

Even with 10.1.0, I am not getting that error thrown. Even with node-static v0.7.1 and v0.7.2 I am not getting error thrown.

What am I missing?

  1. Copied your code and ran
  2. Made a GET request from Postman by copying request headers you mentioned.

No error

getify commented 6 years ago

I know, I've tried the same kind of thing and I'm not able to reproduce with those headers either. Super frustrating. I figure it must be:

Is there some way to turn on some kind of verbose logging of everything that happens when a connect/request comes in? I have no idea how to track this down other than what I've already tried.

getify commented 6 years ago

I am consistently getting 404

As implied by the code I pasted, I assume you are using a ./static/ directory with some index.html file in it, for your testing, right? Otherwise, you'd expect to get a 404 I think.

Also, it may help to forcibly set req.url to "/index.html" in the request handler, to ensure all inbound requests serve that one index.html file, instead of 404s.

1ns3cur3 commented 6 years ago

I think I read something about chunked in request header and node closing connection forcing write on response.

A valid 404 from all possible code path means that code is not throwing error.

Regrading verbose logging, I sprinkled console.log in node-static. Other than that, verbose logging should be supported by modules, which node-static doesn't; at least not in installed version. May be dev version has more logging. MAY BE.

Viel Glück!

getify commented 6 years ago

A valid 404 from all possible code path means that code is not throwing error.

That's true, but it's also possible those kinds of requests/responses are going through different code paths inside node-static than regular found resources, since ostensibly it needs to add headers like content-type, etc... if it's processing on a different path, it could just be accidentally avoiding (but not actually un-susceptible to) the error in question.

getify commented 6 years ago

BTW, another reason I can't just only set headers in the headers config of the constructor: certain headers have timestamps in them, and those would be calculated at the time the node server starts up, and never be re-calculated. But they actually should be relative to (recalculated at) each request. Otherwise, the longer the server stays alive without a restart, the more inaccurate that header's timestamp would be. :(

My only viable option here is to be able to call setHeader(..) upon each request. That's why I need this problem fixed.

getify commented 6 years ago

UPDATE:

This post seems to have identified the culprit, or at least pointed at where the probable problem lies.

The problem seems to be that a HEAD request comes into my code as shown above, and the HSTS header is set, and then serve(..) is called, and that seems to trigger incorrect behavior where a response body is sent when it shouldn't.

I'm not fully versed on this, but here are a few assumptions/observations that I'd think of initially:

+@1ns3cur3

getify commented 6 years ago

Further analysis from that thread:

The root of the problem I think is that the node-static tries to send headers twice, and node-request (i.e. request module of Node.js) checks that headers were already sent only in setHeader method. That is, the error is thrown only when setHeader method was called. If setHeader method was not called, the error is not thrown even if writeHead method is called again.

From my reading, that sounds like both a bug in node-static and also in Node itself. Thoughts?

1ns3cur3 commented 6 years ago

@getify Nope, calling writeHead twice is erroneous; Node says that. Earlier I didn't debug HEAD, let me check that once quickly.

1ns3cur3 commented 6 years ago

After adding a static/index.html, for a GET call I am getting this error:


issue/node_modules/node-static/lib/node-static.js:290
                      mime.lookup(files[0]) ||
                           ^

TypeError: mime.lookup is not a function
    at Server.respond (issue/node_modules/node-static/lib/node-static.js:290:28)
    at issue/node_modules/node-static/lib/node-static.js:144:22
    at FSReqWrap.oncomplete (fs.js:166:5)

Here's the input data:

    pathname: null,
    status: 200,
    _headers: {},
    files: issue/static/index.html,
    stat: <...mostly useless stats...>,
    Object.keys(mime): _types,_extensions
getify commented 6 years ago

@1ns3cur3 that's strange, i'm definitely not seeing that.

1ns3cur3 commented 6 years ago

So far, HEAD shouldn't send headers which GET wouldn't; which I guess you aren't.

Other than that, yes, you can call writeHead as many times as you want, if you don't call setHeaders().