require('fs').stat mangling argument

[cbaron]

Version: v6.1.0, v6.5.0
Platform: Darwin ${mymacbook}.local 15.3.0 Darwin Kernel Version 15.3.0: Thu Dec 10 18:40:58 PST 2015; root:xnu-3248.30.4~1/RELEASE_X86_64 x86_64

Subsystem: fs

The repo is here : https://github.com/cbaron/Enterprise

It is a web application. The static file server I wrote is having an issue with the latest node. The app.js, router.js, and lib/MyObject.js files are of concern. Sometimes, everything works fine, other times, it seems that the closure in my code is not being respected as I will try to illustrate below. I would be happy to work through this issue if you do not have enough information.

    static( request, response, path ) {
            var fileName = path.pop()
                filePath = `${__dirname}/${path.join('/')}/${fileName}`,
                ext = this.Path.extname( filePath )

            return this.P( this.FS.stat, [ filePath ] )
            .then( ( [ stat ] ) => new Promise( ( resolve, reject ) => {

                var stream = this.FS.createReadStream( filePath )

                response.on( 'error', e => { stream.end(); reject(e) } )
                stream.on( 'error', reject )
                stream.on( 'end', () => {
                    console.log( fileName, filePath, stat.size, stream.bytesRead )
                    response.end();
                    resolve()
                } )

                response.writeHead(
                    200,
                    {
                        'Connection': 'keep-alive',
                        'Content-Encoding': ext === ".gz" ? 'gzip' : 'identity',
                        'Content-Length': stat.size,
                        'Content-Type':
                            /\.css/.test(fileName)
                                ? 'text/css'
                                : ext === '.svg'
                                    ? 'image/svg+xml'
                                    : 'text/plain'
                    }
                )
                stream.pipe( response, { end: false } )
            } ) )
        }

this.P refers to the function ->

( fun, args=[ ], thisArg=undefined ) =>
        new Promise( ( resolve, reject ) => Reflect.apply( fun, thisArg, args.concat( ( e, ...callback ) => e ? reject(e) : resolve(callback) ) ) )

this.FS refers to require('fs')

The request argument is an http request, the response is the response object, and path is information that pertains to a file on the local system. You can simply pointfilePath point to a local file on your system.

The issue is occurring when my web page requests 3 static files at the same time.

When it works correctly, I get the following STDOUT

main.css.gz /Users/cbaron/freelancR/Enterprise/static/css/main.css.gz 1514 1514
debug.js.gz /Users/cbaron/freelancR/Enterprise/static/js/debug.js.gz 53243 53243
vendor.js.gz /Users/cbaron/freelancR/Enterprise/static/js/debug.js.gz 140517 140517

When it doesn't =>

main.css.gz /Users/cbaron/freelancR/Enterprise/static/js/debug.js.gz 1514 53243
vendor.js.gz /Users/cbaron/freelancR/Enterprise/static/js/debug.js.gz 140517 53243
debug.js.gz /Users/cbaron/freelancR/Enterprise/static/js/debug.js.gz 53243 53243

Note that the filePath variable in the static function is not being closed properly. It seems something is happening to that literal in require('fs').stat.

Let me know how I can help!

[bnoordhuis]

Can you provide a minimal, standalone test case? 'Standalone' in this context means core modules only, no third-party modules like express or request.

If that is not an option, can you close this issue and open one over at https://github.com/nodejs/help/issues? Thanks.

[cbaron]

Certainly, I will try to get to that today. Thanks.

[cbaron]

test.zip

Check this out. Run tester.js

Let me know how I can help. Thanks.

[thefourtheye]

@cbaron When I executed this with Node.js v6.5.0, on Darwin Kernel 15.6.0, I got

➜  test node tester.js
{ Error: Parse Error
    at Error (native)
    at Socket.socketOnData (_http_client.js:361:20)
    at emitOne (events.js:96:13)
    at Socket.emit (events.js:188:7)
    at readableAddChunk (_stream_readable.js:176:18)
    at Socket.Readable.push (_stream_readable.js:134:10)
    at TCP.onread (net.js:543:20) bytesParsed: 1664, code: 'HPE_INVALID_CONSTANT' }
debug.js.gz <user home>/test/static/js/debug.js.gz 53243 53243
vendor.js.gz <user home>/test/static/js/debug.js.gz 140517 140517

Is this expected?

[cbaron]

Yes, I think that is expected. What is happening on my machine, is that sometimes, the file requested is not returned, but in fact another file's data is returned in the response because the filePath variable gets changed. Then, because of the mismatched Content-Length with what is actually sent - HPE_INVALID_CONSTANT gets called.

Note the last two lines on STDOUT

debug.js.gz <user home>/test/static/js/debug.js.gz 53243 53243
vendor.js.gz <user home>/test/static/js/debug.js.gz 140517 140517

The filePath variable gets changed in your request to thevendor.js.gz file -- do you see that? Although, oddly enough, it seems that the bytesRead is correct for the vendor request, but not the .css request.

I ran it just now, and see the following:

debug.js.gz /Users/cbaron/freelancR/node/test/static/js/vendor.js.gz 53243 1514

Note that the debug.js.gz is requested, its size is 53243, but only 1514 bytes are read ( The number of bytes in the .css.gz file. On my machine, sometimes, but not every time, the http response sends back the wrong file. For example, /static/js/debug.js.gz is requested, but /static/js/vendor.js.gz is sent back.

Do you see that?

I appreciate the involvement. I hope we can come to some conclusion here. I hope I am not wasting your time.

[cbaron]

@thefourtheye, @bnoordhuis -- what say you?

Do you want more proof that something is potentially wrong ?

[cbaron]

At least an update?!?

I'm trying to write an application on the bleeding edge..

[bnoordhuis]

I don't have time to look at this right now. If you think this is a node.js bug, you will either have to investigate yourself or get another contributor to look at it.

[cbaron]

@thefourtheye, or @mscdex, will you help me track down this bug? I don't understand how its not apparent that it is a bonafide nodejs bug.

[cbaron]

ping @thefourtheye, or @mscdex, can you at least confirm this is a bug ?

[mscdex]

@cbaron The problem is that you're missing a comma after the fileName = path.pop() line. Because it's missing, the following variables are treated as globals, so they end up persisting between requests. So the actual stat objects are correct because of the synchronous nature of the JS execution, but when the fs.stat callback is executed, the global filePath is now that of the most recent request (the one for debug.js in this case), so you end up reading the same file 3 times, making 2 of the responses have the wrong stat information.

[cbaron]

@mscdex, much appreciated. Perhaps you think little of my skills, but please let me know if I can be of help to you in the future. I owe you one.