Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Assertion `(parser->current_buffer_len_) == (0)' failed #15102

Closed
nitroxis opened this issue Aug 30, 2017 · 29 comments
Closed

Assertion `(parser->current_buffer_len_) == (0)' failed #15102

nitroxis opened this issue Aug 30, 2017 · 29 comments
Labels
c++ Issues and PRs that require attention from people who are familiar with C++. http Issues or PRs related to the http subsystem.

Comments

@nitroxis
Copy link

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
Copy link
Member

Does the same error occur with 8.4?

@nitroxis
Copy link
Author

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

@mscdex mscdex added c++ Issues and PRs that require attention from people who are familiar with C++. http Issues or PRs related to the http subsystem. labels Aug 30, 2017
@bnoordhuis
Copy link
Member

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

@nitroxis
Copy link
Author

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
Copy link

psamim commented Sep 17, 2017

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

@BridgeAR BridgeAR reopened this Sep 17, 2017
@addaleax
Copy link
Member

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

@psamim
Copy link

psamim commented Sep 17, 2017 via email

@SINHASantos
Copy link

SINHASantos commented Sep 18, 2017

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::FunctionCallbackInfov8::Value&): 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 Infov8::Value 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

  1. and add the line below in your code

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

and it solves the problem

@cjihrig
Copy link
Contributor

cjihrig commented Sep 18, 2017

I do not know how.

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

@psamim
Copy link

psamim commented Sep 19, 2017

@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
Copy link
Member

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

@psamim
Copy link

psamim commented Sep 19, 2017 via email

@addaleax
Copy link
Member

addaleax commented Sep 19, 2017

@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
Copy link

psamim commented Sep 26, 2017

The problem seems resolved for me, in version 8.5.0.

@bnoordhuis
Copy link
Member

The problem seems resolved for me, in version 8.5.0.

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

@himanshu-singh1995
Copy link

himanshu-singh1995 commented Jul 8, 2019

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
Copy link

jsohan commented Jul 6, 2020

@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
Copy link
Member

addaleax commented Jul 7, 2020

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

@jsohan
Copy link

jsohan commented Jul 7, 2020

@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
Copy link
Member

addaleax commented Jul 7, 2020

@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
Copy link

jsohan commented Jul 7, 2020

@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 

image

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
Copy link
Member

addaleax commented Jul 7, 2020

@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
Copy link

jsohan commented Jul 7, 2020

@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

image

@addaleax
Copy link
Member

addaleax commented Jul 7, 2020

@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
Copy link

jsohan commented Jul 7, 2020

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

image

@addaleax
Copy link
Member

addaleax commented Jul 7, 2020

@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.

@addaleax addaleax reopened this Jul 7, 2020
@jsohan
Copy link

jsohan commented Jul 7, 2020

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

@addaleax
Copy link
Member

addaleax commented Jul 7, 2020

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
Copy link
Member

addaleax commented Jul 7, 2020

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

addaleax added a commit to addaleax/node that referenced this issue Jul 7, 2020
Since the tests only crash on v12.x, this commit adds separate
regression tests.

Refs: nodejs#15102
addaleax added a commit to addaleax/node that referenced this issue Jul 7, 2020
Fix a crash that occurs when `parser.finish()` is called during
`parser.execute()`. In this particular case, this happened because
a 100 continue response is a place in which `.end()` can be called
which can in turn lead to a write error, which is emitted
synchronously, thus inside the outer `parser.execute()` call.

Resolve that by delaying the `parser.finish()` call until after
the `parser.execute()` call is done.

This only affects v12.x, because on later versions, errors are not
emitted synchronously.

Fixes: nodejs#15102
addaleax added a commit to addaleax/node that referenced this issue Jul 7, 2020
Since the tests only crash on v12.x, this commit adds separate
regression tests.

Refs: nodejs#15102
addaleax added a commit that referenced this issue Jul 14, 2020
Since the tests only crash on v12.x, this commit adds separate
regression tests.

Refs: #15102

PR-URL: #34250
Refs: #34016
Reviewed-By: Luigi Pinca <[email protected]>
MylesBorins pushed a commit that referenced this issue Jul 14, 2020
Since the tests only crash on v12.x, this commit adds separate
regression tests.

Refs: #15102

PR-URL: #34250
Refs: #34016
Reviewed-By: Luigi Pinca <[email protected]>
MylesBorins pushed a commit that referenced this issue Jul 16, 2020
Since the tests only crash on v12.x, this commit adds separate
regression tests.

Refs: #15102

PR-URL: #34250
Refs: #34016
Reviewed-By: Luigi Pinca <[email protected]>
cjihrig pushed a commit that referenced this issue Jul 23, 2020
Since the tests only crash on v12.x, this commit adds separate
regression tests.

Refs: #15102

PR-URL: #34250
Refs: #34016
Reviewed-By: Luigi Pinca <[email protected]>
addaleax added a commit that referenced this issue Sep 22, 2020
Since the tests only crash on v12.x, this commit adds separate
regression tests.

PR-URL: #34251
Refs: #15102
Refs: #34016
Reviewed-By: Fedor Indutny <[email protected]>
Reviewed-By: Gerhard Stöbich <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
c++ Issues and PRs that require attention from people who are familiar with C++. http Issues or PRs related to the http subsystem.
Projects
None yet
Development

No branches or pull requests

10 participants