Node: Assertion `(parser->current_buffer_len_) == (0)' failed

[nitroxis]

• Version: v8.1.4
• Platform: Linux 4.9.0-2-amd64 #1 SMP Debian 4.9.18-1 (2017-03-30) x86_64 GNU/Linux
• Subsystem: node_http_parser.cc

Hi,

I get the following crash from time to time (randomly, it seems):

/usr/local/bin/node[26969]: ../src/node_http_parser.cc:420:static void node::{anonymous}::Parser::Execute(const v8::FunctionCallbackInfo<v8::Value>&): Assertion `(parser->current_buffer_len_) == (0)' failed.
Main process exited, code=killed, status=6/ABRT
 1: node::Abort() [/usr/local/bin/node]
 2: node::Assert(char const* const (*) [4]) [/usr/local/bin/node]
 3: 0x14135d1 [/usr/local/bin/node]
 4: 0xcc6de636c65

I'm not entirely sure where this comes from as there is no JS stack trace, but I believe it happens when processing the response of a HTTP request. This bug has been around for a long time, but it's very inconsistent. It might have already been reported here, at least it seems to be related.

[BridgeAR]

Does the same error occur with 8.4?

[nitroxis]

I will try to update node, but it might take weeks until it happens again, unless I find a way to reproduce it.

[bnoordhuis]

I'll close this out for now, let us know if you can reproduce with the latest v8.x.

[nitroxis]

Coincidentally, it just happened again. Same stack trace, different line:

/usr/local/bin/node[23084]: ../src/node_http_parser.cc:423:static void node::{anonymous}::Parser::Execute(const v8::FunctionCallbackInfo<v8::Value>&): Assertion `(parser->current_buffer_len_) == (0)' failed.
 1: node::Abort() [/usr/local/bin/node]
 2: node::Assert(char const* const (*) [4]) [/usr/local/bin/node]
 3: 0x142b461 [/usr/local/bin/node]
 4: 0x11eabb74aac7
Main process exited, code=killed, status=6/ABRT

I still don't know where exactly in the JS code this happened.

[psamim]

It also happened to me, node version 8.4.0 on Archlinux. The 8:54:18 AM api.1 part in the log is from node-foreman.

8:54:18 AM api.1       |  /usr/bin/node[5205]: ../src/node_http_parser.cc:423:static void node::{anonymous}::Parser::Execute(const v8::FunctionCallbackInfo<v8::Value>&): Assertion `(parser->current_buffer_len_) == (0)' failed.
8:54:18 AM api.1       |   1:
8:54:18 AM api.1       |  node::Abort() [/usr/bin/node]
8:54:18 AM api.1       |   2:
8:54:18 AM api.1       |  node::Assert(char const* const (*) [4]) [/usr/bin/node]
8:54:18 AM api.1       |   3: 0x5616b4c073dd [/usr/bin/node]
8:54:18 AM api.1       |   4: v8::internal::FunctionCallbackArguments::Call(void (*)(v8::FunctionCallbackInfo<v8::Value> const&)) [/usr/bin/node]
8:54:18 AM api.1       |   5: 0x5616b442414c [/usr/bin/node]
8:54:18 AM api.1       |   6: 0x5616b4424754 [/usr/bin/node]
8:54:18 AM api.1       |   7: 0x5350f1840dd

[addaleax]

@psamim Any chance you could get us a core dump of that crash?

[psamim]

I do not know how.

On Sun, Sep 17, 2017 at 5:20 PM Anna Henningsen [e-mail]
wrote:

@psamim https://github.com/psamim Any chance you could get us a core
dump of that crash?

—
You are receiving this because you were mentioned.

Reply to this email directly, view it on GitHub
https://github.com/nodejs/node/issues/15102#issuecomment-330041571, or mute
the thread
https://github.com/notifications/unsubscribe-auth/AByDh44MUSI-Ma64CJV0WGCVtBCCLETMks5sjRWggaJpZM4PICpG
.

[signupsi]

linux node v8.4.0

/usr/local/bin/node[30809]: ../src/node_http_parser.cc:423:static void node::{a nonymous}::Parser::Execute(const v8::FunctionCallbackInfo&): Asserti on `(parser->current_buffer_len_) == (0)' failed.
1: node::Abort() [node]
2: node::Assert(char const* const () [4]) [node]
3: 0x13c5bcd [node]
4: v8::internal::FunctionCallbackArguments::Call(void ()(v8::FunctionCallback Info const&)) [node]
5: 0xc3ac4a [node]
6: v8::internal::Builtin_HandleApiCall(int, v8::internal::Object*, v8::intern al::Isolate) [node]
7: 0x39c5acd040dd
Aborted

solution:
1) install following module

npm install http-parser-js

2) and add the line below in your code

process.binding('http_parser').HTTPParser = require('http-parser-js').HTTPParser;

and it solves the problem

[cjihrig]

I do not know how.

@psamim start Node with the --abort-on-uncaught-exception flag. Before starting node, also run ulimit -c unlimited.

[psamim]

@cjihrig I did and the same thing happened:

3:56:58 PM api.1       |  /usr/bin/node[22446]: ../src/node_http_parser.cc:423:static void node::{anonymous}::Parser::Execute(const v8::FunctionCallbackInfo<v8::Value>&): Assertion `(parser->current_buffer_len_) == (0)' failed.
3:56:58 PM api.1       |   1:
3:56:58 PM api.1       |  node::Abort()
3:56:58 PM api.1       |   [/usr/bin/node]
3:56:58 PM api.1       |   2:
3:56:58 PM api.1       |  node::Assert(char const* const (*) [4])
3:56:58 PM api.1       |   [/usr/bin/node]
3:56:58 PM api.1       |   3:
3:56:58 PM api.1       |  0x5616f1cbd3dd [/usr/bin/node]
3:56:58 PM api.1       |   4: v8::internal::FunctionCallbackArguments::Call(void (*)(v8::FunctionCallbackInfo<v8::Value> const&)) [/usr/bin/node]
3:56:58 PM api.1       |   5: 0x5616f14da14c [/usr/bin/node]
3:56:58 PM api.1       |   6:
3:56:58 PM api.1       |  0x5616f14da754 [/usr/bin/node]
3:56:58 PM api.1       |   7: 0x3f5c6b9840dd

[addaleax]

@psamim Do you find a file name core or similar where you were running your node program?

[psamim]

There are 125 files named core but none are in the root directory where I
run the program.

On Tue, Sep 19, 2017 at 5:06 PM Anna Henningsen [e-mail]
wrote:

@psamim https://github.com/psamim Do you find a file name core or
similar where you were running your node program?

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/nodejs/node/issues/15102#issuecomment-330524795, or mute
the thread
https://github.com/notifications/unsubscribe-auth/AByDhzjLCd0_LaKLisnl7Jse3h9y7oOZks5sj7VNgaJpZM4PICpG
.

[addaleax]

@psamim does any of the creation times of those files match the time of the crash as per the logs? that would be a good indicator that it’s what we’re looking for :)

[psamim]

The problem seems resolved for me, in version 8.5.0.

[bnoordhuis]

The problem seems resolved for me, in version 8.5.0.

Happy to hear that. I'll close out the issue.

[himanshu-singh1995]

I got the following error in node v10.16.0 while uploading a 1GB file on S3 using putObject method provided by the aws-sdk. By the uploading a file size of 1GB to S3 using putObject of aws-sdk, I was able to reproduce this error every time.

Note: Upload string(not Buffer) to S3.

node[10695]: ../src/node_http_parser.cc:442:static void node::{anonymous}::Parser::Finish(const v8::FunctionCallbackInfo<v8::Value>&): Assertion `parser->current_buffer_.IsEmpty()' failed.
 1: 0x8f9d10 node::Abort() [node]
 2: 0x8f9de5  [node]
 3: 0x9638b2  [node]
 4: 0xb8dfef  [node]
 5: 0xb8eb59 v8::internal::Builtin_HandleApiCall(int, v8::internal::Object**, v8::internal::Isolate*) [node]
 6: 0x154a4c55be1d 
Aborted (core dumped)

Code to reproduce this error

const fs = require('fs');
const AWS = require('aws-sdk');
AWS.config.update(/* creds */);

let data = null
fs.readFile('filename','utf8', (err, _data) => data = _data)  // this file should be >= 1GB
const params = {
      ACL: 'public-read',
      Body: data,
      Bucket: '<bucket>',
      Key: '<key>',
      ContentType: 'text/plain',
    };
const s3 = new AWS.S3({ apiVersion: '2006-03-01' });
s3.putObject(params).promise().then(console.log, console.log);

[jsohan]

@himanshu-singh1995 I think I am facing the same issue. Did you find a fix or work around for this. Also was it any file 1GB and bigger?

[addaleax]

@himanshu-singh1995 @jsohan Can you tell whether you are affected by this on Node v12.x or v14.x as well?

[jsohan]

@addaleax This effects me on Node v12. Not sure what the root cause it but this error is being thrown from s3.putObject() function when dealing with large strings

[addaleax]

@jsohan Is there a chance you could share a core dump (+ your exact Node.js version, assuming you’re using the binaries from https://nodejs.org/, or if not, the Node.js executable you are using)? It would be good to know what the JS stack trace is here, but unfortunately the crash output here does not provide that…

[jsohan]

@addaleax Not to sure what a core Dump is but I'm running node v12.14.0 locally . Error was first thrown in production but I'm not sure the exact node version ran there. When I reproduce the bug locally I run the following code:

function getData(){
    return new Promise(resolve => {
      fs.readFile('temp.txt','utf8', (err, _data) => {
        return resolve(_data);
      })  // this file should be >= 1GB

    })
  }

  async function tempFunction(){
    console.log("tempFunction called ***************************************");
    let data = await getData(); //gets data
    var params = {
      Bucket: s3Config.bucket,
      Key: "temp3",
      Body: data
    };
    console.log("passing: temp | FileSize: " + Buffer.byteLength(data, 'utf8') + " bytes");
    await aws3.putObject(params).promise() //uploads data
      .then(async (data) => {
        console.log("done uploading");
      })
      .catch(err => {
        console.log("error was thrown in tempFunction")
        console.log(err);
      })
  }

And I get the following console output:

Skipping unexpected line on STDOUT for shard shardId-000000000000: tempFunction called *************************************** 
Skipping unexpected line on STDOUT for shard shardId-000000000000: passing: temp | FileSize: 1058393952 bytes 
Received error line from subprocess [C:\Program Files\nodejs\node.exe[21196]: c:\ws\src\node_http_parser_impl.h:488: Assertion `parser->current_buffer_.IsEmpty()' failed.] for shard shardId-000000000000 
C:\Program Files\nodejs\node.exe[21196]: c:\ws\src\node_http_parser_impl.h:488: Assertion `parser->current_buffer_.IsEmpty()' failed.
Received error line from subprocess [ 1: 00007FF6BC67124F napi_wrap+124431] for shard shardId-000000000000 
 1: 00007FF6BC67124F napi_wrap+124431
 2: 00007FF6BC612A06 v8::base::CPU::has_sse+34502
 3: 00007FF6BC612D23 v8::base::CPU::has_sse+35299
Received error line from subprocess [ 2: 00007FF6BC612A06 v8::base::CPU::has_sse+34502] for shard shardId-000000000000 
Received error line from subprocess [ 3: 00007FF6BC612D23 v8::base::CPU::has_sse+35299] for shard shardId-000000000000 
Received error line from subprocess [ 4: 00007FF6BC60079E v8::internal::Scope::locals+181358] for shard shardId-000000000000 
 4: 00007FF6BC60079E v8::internal::Scope::locals+181358
Received error line from subprocess [ 5: 00007FF6BCDCC4E0 v8::internal::Builtins::builtin_handle+325536] for shard shardId-000000000000 
 5: 00007FF6BCDCC4E0 v8::internal::Builtins::builtin_handle+325536
 6: 00007FF6BCDCBA27 v8::internal::Builtins::builtin_handle+322791
Received error line from subprocess [ 6: 00007FF6BCDCBA27 v8::internal::Builtins::builtin_handle+322791] for shard shardId-000000000000 
Received error line from subprocess [ 7: 00007FF6BCDCBD68 v8::internal::Builtins::builtin_handle+323624] for shard shardId-000000000000 

Sorry if the formatting is little weird. This is being thrown from the record processor function of aws-kcl library, getting data from a Kinesis stream
The error is a little different locally but in production it's more like it is in @himanshu-singh1995 post

[addaleax]

@jsohan Sorry, didn’t know you’re running Windows… in that case, yeah, core dumps or C++ stack traces won’t be available/useful.

Can you try adding this to your code (before you make the request), and run Node.js with --http-parser=legacy?

const { HTTPParser } = process.binding('http_parser');
const origFinish = HTTPParser.prototype.finish;
HTTPParser.prototype.finish = function(...args) {
  console.trace('finish called', args);
  return origFinish.call(this, ...args);
};

that should give us the JS stack trace, which is the most useful thing we can get here.

[jsohan]

@addaleax here's what I got

Skipping unexpected line on STDOUT for shard shardId-000000000000: tempFunction called *************************************** 
Skipping unexpected line on STDOUT for shard shardId-000000000000: passing: temp | FileSize: 1058393952 bytes 
Received error line from subprocess [Trace: finish called []] for shard shardId-000000000000 
Trace: finish called []
    at HTTPParser.finish (c:\Users\jsohan\Documents\gitRepo\abacus-nodejs\archiver.js:16:11)
    at Socket.socketErrorListener (_http_client.js:414:12)
Received error line from subprocess [    at HTTPParser.finish (c:\Users\jsohan\Documents\gitRepo\abacus-nodejs\archiver.js:16:11)] for shard shardId-000000000000 
Received error line from subprocess [    at Socket.socketErrorListener (_http_client.js:414:12)] for shard shardId-000000000000 
Received error line from subprocess [    at Socket.emit (events.js:210:5)] for shard shardId-000000000000 
Received error line from subprocess [    at Socket.EventEmitter.emit (domain.js:475:20)] for shard shardId-000000000000 
Received error line from subprocess [    at errorOrDestroy (internal/streams/destroy.js:108:12)] for shard shardId-000000000000 
    at Socket.emit (events.js:210:5)
    at Socket.EventEmitter.emit (domain.js:475:20)
    at errorOrDestroy (internal/streams/destroy.js:108:12)
    at onwriteError (_stream_writable.js:446:5)
Received error line from subprocess [    at onwriteError (_stream_writable.js:446:5)] for shard shardId-000000000000 
Received error line from subprocess [    at onwrite (_stream_writable.js:473:5)] for shard shardId-000000000000 
    at onwrite (_stream_writable.js:473:5)
    at internal/streams/destroy.js:50:7
Received error line from subprocess [    at internal/streams/destroy.js:50:7] for shard shardId-000000000000 
Received error line from subprocess [    at Socket._destroy (net.js:664:5)] for shard shardId-000000000000 
    at Socket._destroy (net.js:664:5)
    at Socket.destroy (internal/streams/destroy.js:38:8)
Received error line from subprocess [    at Socket.destroy (internal/streams/destroy.js:38:8)] for shard shardId-000000000000 
Received error line from subprocess [C:\Program Files\nodejs\node.exe[17300]: c:\ws\src\node_http_parser_impl.h:488: Assertion `parser->current_buffer_.IsEmpty()' failed.] for shard shardId-000000000000 
C:\Program Files\nodejs\node.exe[17300]: c:\ws\src\node_http_parser_impl.h:488: Assertion `parser->current_buffer_.IsEmpty()' failed.
Received error line from subprocess [ 1: 00007FF6BC67124F napi_wrap+124431] for shard shardId-000000000000 
 1: 00007FF6BC67124F napi_wrap+124431
 2: 00007FF6BC612A06 v8::base::CPU::has_sse+34502
Received error line from subprocess [ 2: 00007FF6BC612A06 v8::base::CPU::has_sse+34502] for shard shardId-000000000000 
Received error line from subprocess [ 3: 00007FF6BC612D23 v8::base::CPU::has_sse+35299] for shard shardId-000000000000 
 3: 00007FF6BC612D23 v8::base::CPU::has_sse+35299
 4: 00007FF6BC5FC9BE v8::internal::Scope::locals+165518
Received error line from subprocess [ 4: 00007FF6BC5FC9BE v8::internal::Scope::locals+165518] for shard shardId-000000000000 
Received error line from subprocess [ 5: 00007FF6BCDCC4E0 v8::internal::Builtins::builtin_handle+325536] for shard shardId-000000000000 
 5: 00007FF6BCDCC4E0 v8::internal::Builtins::builtin_handle+325536
 6: 00007FF6BCDCBA27 v8::internal::Builtins::builtin_handle+322791
Received error line from subprocess [ 6: 00007FF6BCDCBA27 v8::internal::Builtins::builtin_handle+322791] for shard shardId-000000000000 
Received error line from subprocess [ 7: 00007FF6BCDCBD68 v8::internal::Builtins::builtin_handle+323624] for shard shardId-000000000000 
 7: 00007FF6BCDCBD68 v8::internal::Builtins::builtin_handle+323624
Received error line from subprocess [ 8: 00007FF6BCDCBB6E v8::internal::Builtins::builtin_handle+323118] for shard shardId-000000000000 
Received error line from subprocess [ 9: 00007FF6BD24414D v8::internal::SetupIsolateDelegate::SetupHeap+568205] for shard shardId-000000000000 
 8: 00007FF6BCDCBB6E v8::internal::Builtins::builtin_handle+323118
 9: 00007FF6BD24414D v8::internal::SetupIsolateDelegate::SetupHeap+568205
10: 00007FF6BD1C3BDC v8::internal::SetupIsolateDelegate::SetupHeap+42524

[addaleax]

@jsohan Thanks, that seems quite helpful already – can you expand the stack trace a bit more, e.g. by adding --stack-trace-limit=100? That should be even more helpful here. (Thanks for being patient with figuring this out!)

[jsohan]

@addaleax Would be awesome to find out what's going wrong here

[addaleax]

@jsohan Awesome, thank you! I managed to put together a fully self-contained reproduction based on this :)

The good news is that this already appears to be fixed (at least to some degree) on Node v14.x, so it might just be a matter of backporting the right fix + adding a test.

[jsohan]

Awesome. Any idea on how I would go about this? @addaleax

[addaleax]

For a workaround, you might be able to wrap the self.writeBody(stream, httpRequest); line in aws-sdk/lib/http/node.js:102 as setImmediate(() => self.writeBody(stream, httpRequest));, I think that would fix this for you. (Unfortunately, there probably isn’t any way to fix this in your code without monkey-patching either the AWS library or Node’s HTTP internals…)

[addaleax]

Looks like the fix was f663b31cc2aec, which was semver-major, so I’ll open a separate fix instead of backporting that