Skip to content
This repository has been archived by the owner on Oct 15, 2020. It is now read-only.

Slow TCP #6

Open
morkai opened this issue Jan 13, 2016 · 9 comments
Open

Slow TCP #6

morkai opened this issue Jan 13, 2016 · 9 comments
Assignees

Comments

@morkai
Copy link
Contributor

morkai commented Jan 13, 2016

So I've decided to see how node-chakracore v6.0.0-pre1 will compare to node-v8 v5.4.0 in generating reports in one of my apps (~500k documents fetched from MongoDB). On average node-chakracore took 2x more time to finish than node-v8.

Then I tried to import data from 27 ~8 MB text files. Parsing (CPU only) in ChakraCore was faster than in v8 (chakra=6.8s vs v8=5.6s), but then came time for some I/O (MongoDB) and there v8 won again (chakra=143s vs v8=50s).

Simple TCP client-server scripts show that the net module is 2x slower in ChakraCore (92k data events per second in v8 - 42k in ChakraCore).

node and MongoDB are on the same machine (Windows 10 Home 64-bit). Tried to run it on a different machine (laptop) with Windows 7 Enterprise 64-bit, but node.exe ends immediately without any errors (node -v still shows v6.0.0-pre1).

@jianchun
Copy link

Thank you for checking this out and doing the tests! We will investigate the scenario you described. Indeed we have areas that need more work to improve performance.

I tried your "Simple TCP client-server scripts" on win7 x64 and didn't see the crash. So the crash was in mongoDB test? Please let us know if you found an easier repro.

@morkai
Copy link
Contributor Author

morkai commented Jan 13, 2016

There wasn't any crash. If a file is passed as the first argument, then it isn't executed. If no file is passed - the REPL is not started.

For example, given file hello.js:

console.log('Hello World!');

on Win10 machine I get:

C:\Workspace>"C:\Program Files\nodejs (chakracore)\nodevars.bat"
Your environment has been set up for using Node.js 6.0.0-pre1 (x64) and npm.

C:\Workspace>node -v
v6.0.0-pre1

C:\Workspace>node hello.js
Hello World!

C:\Workspace>

on Win7 machine:

C:\Workspace>"C:\Program Files\nodejs (chakracore)\nodevars.bat"
Your environment has been set up for using Node.js  and npm.

C:\Workspace>node -v
v6.0.0-pre1

C:\Workspace>node hello.js

C:\Workspace>

@jianchun
Copy link

What version of Win7 do you have? I'm on Windows 7 Enterprise Service Pack 1 and the hello.js example works.

C:\tmp>ver

Microsoft Windows [Version 6.1.7601]

C:\tmp>"c:\Program Files\nodejs (chakracore)\nodevars.bat"
Your environment has been set up for using Node.js 6.0.0-pre1 (x64) and npm.

C:\tmp>node -v
v6.0.0-pre1

C:\tmp>node hello.js
Hello World!

@morkai
Copy link
Contributor Author

morkai commented Jan 14, 2016

My Computer Properties shows Windows 7 Enterprise Service Pack 1 64-bit.
ver shows Microsoft Windows [Version 6.1.7601].

It currently has:

  • nodejs v0.10.33 32-bit (works, installed long time ago),
  • nodejs v5.4.1 64-bit (works, installed today),
  • nodejs (chakracore) v6.0.0-pre1 64-bit (doesn't work, installed today) and
  • nodejs (chakracore) v6.0.0-pre1 32-bit (doesn't work, installed today).

It is a company laptop and has McAfee running (can't disable it).

@kunalspathak
Copy link
Member

@morkai , Regading crash on Windows 7, similar issue was recently reported at chakra-core/ChakraCore#212 and was fixed with chakra-core/ChakraCore#202. Just to make sure that this is same issue, could you please confirm if your machine has IE11 installed?

@morkai
Copy link
Contributor Author

morkai commented Jan 29, 2016

No IE11 on the Windows 7 machine - only IE9.

@kunalspathak
Copy link
Member

Thanks for confirming @morkai . The latest release should unblock you from using Node.js with chakracore on Windows 7 machine.

We are investigating the performance issue you reported and will update you on it.

@kunalspathak
Copy link
Member

@morkai , after investigating this for sometime, it seems that the slowness in node+chakracore is happening because of JIT optimization that we don't do for arguments. See chakra-core/ChakraCore#313 for details.
I noticed some other areas in chakrashim that needs tweaking to improve performance.

  • Whenever we create new instance of ObjectTemplates, we call JsGetOwnPropertyNames. JsGetOwnPropertyNames goes all the way down to engine and returns array of own property names of an object. Most of the time there are no properties on the template (specially for perf test you shared), so ideally we can skip it. We can easily detect here if any properties were ever set on the template and skip calls to JsGetOwnPropertyNames if there were no properties on the template. In my experiment I saw some performance gain by tweaking this.
  • Another chakracore issue that I noticed was here. UInt8Array object is created and the prototype of that object is set immediately after creation. In engine, there is inline caching optimization around object's properties and we invalidate the caches of that object and its prototype chain if we see the prototype of an object has changed (SetPrototype is internally detected as ChangePrototype). For new type that is just created, we should not bother invalidating the inline cache. We spend sometime doing this in the perf test that you shared.
  • Other minor thing is we call JsGetPropertyIdFromName repeatedly for same property names. We could save calls to engine if we can cache the propertyId to propertyName mapping.

On my dev machine, I was seeing approx. 68000 req/sec with node+v8. Before my changes mentioned above, node+chakracore was at 27000 req/sec. After my changes it boosted up to 44000 req/sec. I will continue my investigation in other gaps, but i think this is good starter point to catch up on TCP modules.

@kfarnung
Copy link
Contributor

@kunalspathak Can we test the delta between node-v8 and node-chakracore?

jackhorton pushed a commit that referenced this issue Nov 2, 2017
Currently when running the test without an internet connection there are
two JavaScript test failures and one cctest. The cctest only fails on
Mac as far as I know. (I've only tested using Mac and Linux thus far).

This commit moves the two JavaScript tests to test/internet.

The details for test_inspector_socket_server.cc:

[ RUN      ] InspectorSocketServerTest.FailsToBindToNodejsHost
make[1]: *** [cctest] Segmentation fault: 11
make: *** [test] Error 2

lldb output:

[ RUN      ] InspectorSocketServerTest.FailsToBindToNodejsHost
Process 63058 stopped
* thread #1: tid = 0x7b175, 0x00007fff96d04384
* libsystem_info.dylib`_gai_simple + 87, queue =
* 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=1,
* address=0x0)
    frame #0: 0x00007fff96d04384 libsystem_info.dylib`_gai_simple + 87
libsystem_info.dylib`_gai_simple:
->  0x7fff96d04384 <+87>: movw   (%rdx), %ax
    0x7fff96d04387 <+90>: movw   %ax, -0x2a(%rbp)
    0x7fff96d0438b <+94>: movq   %r13, -0x38(%rbp)
    0x7fff96d0438f <+98>: movq   0x18(%rbp), %rcx

(lldb) bt
* thread #1: tid = 0x7b175, 0x00007fff96d04384
* libsystem_info.dylib`_gai_simple + 87, queue =
* 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=1,
* address=0x0)
  * frame #0: 0x00007fff96d04384 libsystem_info.dylib`_gai_simple + 87
    frame #1: 0x00007fff96cfe98b libsystem_info.dylib`search_addrinfo +
179
    frame #2: 0x00007fff96cfafef libsystem_info.dylib`si_addrinfo + 2255
    frame #3: 0x00007fff96cfa67b libsystem_info.dylib`getaddrinfo + 179
    frame #4: 0x00000001017d8888
cctest`uv__getaddrinfo_work(w=0x00007fff5fbfe210) + 72 at
getaddrinfo.c:102
    frame #5: 0x00000001017d880e
cctest`uv_getaddrinfo(loop=0x000000010287cb80, req=0x00007fff5fbfe1c8,
cb=0x0000000000000000, hostname="nodejs.org", service="0",
hints=0x00007fff5fbfe268) + 734 at getaddrinfo.c:192
    frame #6: 0x000000010171f781
cctest`node::inspector::InspectorSocketServer::Start(this=0x00007fff5fbfe658)
+ 801 at inspector_socket_server.cc:398
    frame #7: 0x00000001016ed590
cctest`InspectorSocketServerTest_FailsToBindToNodejsHost_Test::TestBody(this=0x0000000105001fd0)
+ 288 at test_inspector_socket_server.cc:593

I'm not sure about the exact cause for this but when using a standalone
c program to simulate this it seems like when the ai_flags
`AI_NUMERICSERV` is set, which is done in inspector_socket_server.cc
line 394, the servname (the port in the FailsToBindToNodejsHost test) is
expected to be a numeric port string to avoid looking it up in
/etc/services. When the port is 0 as is it was before this commit the
segment fault occurs but not if it is non-zero.

PR-URL: nodejs/node#16255
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: James M Snell <jasnell@gmail.com>
kfarnung pushed a commit to kfarnung/node-chakracore that referenced this issue Nov 29, 2017
Currently when running the test without an internet connection there are
two JavaScript test failures and one cctest. The cctest only fails on
Mac as far as I know. (I've only tested using Mac and Linux thus far).

This commit moves the two JavaScript tests to test/internet.

The details for test_inspector_socket_server.cc:

[ RUN      ] InspectorSocketServerTest.FailsToBindToNodejsHost
make[1]: *** [cctest] Segmentation fault: 11
make: *** [test] Error 2

lldb output:

[ RUN      ] InspectorSocketServerTest.FailsToBindToNodejsHost
Process 63058 stopped
* thread #1: tid = 0x7b175, 0x00007fff96d04384
* libsystem_info.dylib`_gai_simple + 87, queue =
* 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=1,
* address=0x0)
    frame #0: 0x00007fff96d04384 libsystem_info.dylib`_gai_simple + 87
libsystem_info.dylib`_gai_simple:
->  0x7fff96d04384 <+87>: movw   (%rdx), %ax
    0x7fff96d04387 <+90>: movw   %ax, -0x2a(%rbp)
    0x7fff96d0438b <+94>: movq   %r13, -0x38(%rbp)
    0x7fff96d0438f <+98>: movq   0x18(%rbp), %rcx

(lldb) bt
* thread #1: tid = 0x7b175, 0x00007fff96d04384
* libsystem_info.dylib`_gai_simple + 87, queue =
* 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=1,
* address=0x0)
  * frame #0: 0x00007fff96d04384 libsystem_info.dylib`_gai_simple + 87
    frame #1: 0x00007fff96cfe98b libsystem_info.dylib`search_addrinfo +
179
    frame #2: 0x00007fff96cfafef libsystem_info.dylib`si_addrinfo + 2255
    frame #3: 0x00007fff96cfa67b libsystem_info.dylib`getaddrinfo + 179
    frame #4: 0x00000001017d8888
cctest`uv__getaddrinfo_work(w=0x00007fff5fbfe210) + 72 at
getaddrinfo.c:102
    frame #5: 0x00000001017d880e
cctest`uv_getaddrinfo(loop=0x000000010287cb80, req=0x00007fff5fbfe1c8,
cb=0x0000000000000000, hostname="nodejs.org", service="0",
hints=0x00007fff5fbfe268) + 734 at getaddrinfo.c:192
    frame nodejs#6: 0x000000010171f781
cctest`node::inspector::InspectorSocketServer::Start(this=0x00007fff5fbfe658)
+ 801 at inspector_socket_server.cc:398
    frame nodejs#7: 0x00000001016ed590
cctest`InspectorSocketServerTest_FailsToBindToNodejsHost_Test::TestBody(this=0x0000000105001fd0)
+ 288 at test_inspector_socket_server.cc:593

I'm not sure about the exact cause for this but when using a standalone
c program to simulate this it seems like when the ai_flags
`AI_NUMERICSERV` is set, which is done in inspector_socket_server.cc
line 394, the servname (the port in the FailsToBindToNodejsHost test) is
expected to be a numeric port string to avoid looking it up in
/etc/services. When the port is 0 as is it was before this commit the
segment fault occurs but not if it is non-zero.

PR-URL: nodejs/node#16255
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: James M Snell <jasnell@gmail.com>
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests

5 participants