Re: Understanding "weird" CPU behavior

[Alen Vrečko]

Did you profile "per process" or "per OS"? Flame graphs are awesome.
Compare the flame graph of Express non-clustered with Express
clustered. I'd be surprised if nothing pops-up.

2016-09-19 14:29 GMT+02:00 אדם חונן :
> Yes, of course.
>
> What I've been doing with the profiler (which BTW, is a sampling
> profiler...) is this: run in both modes - single process and cluster for the
> same duration of time, then compare the absolute execution time.
>
> The thing is, the profiler will show you where the CPU is spent, but what I
> want to understand is why, when using the express version, suddenly the
> effect of splitting the traffic to two seems to use that much more CPU in
> relation to when running in a single process.
> You see, when using the cluster module you have 3 processes: 1 master and 2
> workers. The master routes requests in a round robin manner to the 2
> workers.
> Without Express, you see the master taking close to 0 CPU and the work being
> roughly routed to the two workers.
> The result is a slightly higher CPU usage with each worker doing pretty much
> what previously a single process did (only half the requests).
>
> When using express, the master process acts the same way - express is not
> used on that process. Not even loaded to memory.
> So OK, with Express there's a certain extra XX% of work that's being done
> because it also handles HTTP routes, does more elaborate request parsing and
> what not.
> For the sake of example, let's say it does +47% work as it happened when I
> measured it on my machines.
> I still expect that when moving to the clustered setup, although this extra
> 47% will apply to each process, the grand total of CPU will be roughly the
> same (or actually slightly larger) than when running in a single process -
> just like it was when not using Express.
> After all, the Express code is agnostic to running in a single process, or
> via the cluster module.
>
> So since the actual result is that the difference goes up to 111%, I was
> thinking that there's something else going on here as well and that the
> processes are somehow interfering with one another somehow  - directly or
> indirectly.
> I'm not sure a profiler is the right tool to check that and hence my
> question - what is.
>
> On Mon, Sep 19, 2016 at 2:02 PM, Richard Warburton
>  wrote:
>>
>> Hi,
>>
>> Execution profilers are designed to tell you what part of your code is
>> using up CPU time. I don't regularly touch Javascript myself, but the V8
>> Javascript runtime contains a builtin sampling profiler which can be run
>> from node so that seems like a good place to start.
>>
>> On Mon, Sep 19, 2016 at 10:10 AM, Adam  wrote:
>>>
>>> Hi,
>>>
>>> I've encountered a CPU issue which is somewhat of a puzzler for me.
>>>
>>> Here's a description of what I'm doing: While investigating why an
>>> application written for Node.js was consuming what seemed to us as
>>> unreasonable amounts of CPU I ended up discovering that most of the CPU
>>> usage is actually attributed to framework we're using - Express.
>>> I've validated this by comparing two "Hello World" style applications,
>>> both in single process mode and when using clustering.
>>> I've implemented this super simple application using vanilla Node and
>>> then again using express:
>>>
>>> Express version:
>>> var express = require('express');
>>> var app = express();
>>>
>>> let userCount = 0;
>>> app.get('/', function (req, res) {
>>>   userCount++;
>>>   const hello = {msg: "Hello world", userCount: userCount};
>>>   res.send(JSON.stringify(hello));
>>> });
>>>
>>> app.listen(3000, function () {
>>>   console.log('Example app listening on port 3000!');
>>> });
>>>
>>>
>>> Plain Node version
>>> var http = require('http');
>>>
>>> let userCount = 0;
>>> var server = http.createServer(function (request, response) {
>>> userCount++;
>>> response.writeHead(200, {"Content-Type": "application/json"});
>>> const hello = {msg: "Hello world", userCount: userCount};
>>> response.end(JSON.stringify(hello));
>>> });
>>>
>>> server.listen(3000);
>>> console.log("Server running at http://127.0.0.1:3000/;);
>>>
>>>
>>> I've then used wrk2 from a load generator machine (c4.large - 2 CPUs) to
>>> send a constant load (2k reqs/sec) to the machine (another c4.large) running
>>> each of these 4 setups.
>>> I was expecting to see higher CPU with express (after all it does more)
>>> and I was expecting the clustered versions to use somewhat more CPU than the
>>> single process versions.
>>> What I actually saw was that indeed the express version uses more CPU
>>> than the plain Node version, but while the extra total CPU used when putting
>>> the plain Node version in a cluster was a bit higher, the same test for the
>>> Express version yielding MUCH more CPU.
>>>
>>> Here are the grand totals in all cases this includes both CPUs:
>>>
>>> single process - plain Node version - total 

Re: Understanding "weird" CPU behavior

[Suresh Khemka]

Hi,
I have not used it myself but few of my team members working on node
usually rely on Perf and flamegraphs for debugging similar issues.

http://www.brendangregg.com/flamegraphs.html

On Mon, Sep 19, 2016 at 4:32 PM, Richard Warburton <
richard.warbur...@gmail.com> wrote:

> Hi,
>
> Execution profilers are designed to tell you what part of your code is
> using up CPU time. I don't regularly touch Javascript myself, but the V8
> Javascript runtime contains a builtin sampling profiler which can be run
> from node so that seems like a good place to start.
>
> On Mon, Sep 19, 2016 at 10:10 AM, Adam  wrote:
>
>> Hi,
>>
>> I've encountered a CPU issue which is somewhat of a puzzler for me.
>>
>> Here's a description of what I'm doing: While investigating why an
>> application written for Node.js was consuming what seemed to us as
>> unreasonable amounts of CPU I ended up discovering that most of the CPU
>> usage is actually attributed to framework we're using - Express.
>> I've validated this by comparing two "Hello World" style applications,
>> both in single process mode and when using clustering.
>> I've implemented this super simple application using vanilla Node and
>> then again using express:
>>
>> Express version:
>> var express = require('express');
>> var app = express();
>>
>> let userCount = 0;
>> app.get('/', function (req, res) {
>>   userCount++;
>>   const hello = {msg: "Hello world", userCount: userCount};
>>   res.send(JSON.stringify(hello));
>> });
>>
>> app.listen(3000, function () {
>>   console.log('Example app listening on port 3000!');
>> });
>>
>>
>> Plain Node version
>> var http = require('http');
>>
>> let userCount = 0;
>> var server = http.createServer(function (request, response) {
>> userCount++;
>> response.writeHead(200, {"Content-Type": "application/json"});
>> const hello = {msg: "Hello world", userCount: userCount};
>> response.end(JSON.stringify(hello));
>> });
>>
>> server.listen(3000);
>> console.log("Server running at http://127.0.0.1:3000/;);
>>
>>
>> I've then used wrk2 from a load generator machine (c4.large - 2 CPUs) to
>> send a constant load (2k reqs/sec) to the machine (another c4.large)
>> running each of these 4 setups.
>> I was expecting to see higher CPU with express (after all it does more)
>> and I was expecting the clustered versions to use somewhat more CPU than
>> the single process versions.
>> What I actually saw was that indeed the express version uses more CPU
>> than the plain Node version, but while the extra total CPU used when
>> putting the plain Node version in a cluster was a bit higher, the same test
>> for the Express version yielding MUCH more CPU.
>>
>> Here are the grand totals in all cases this includes both CPUs:
>>
>>
>>- single process - plain Node version - total 12.95%
>>- 2 processes using Node's cluster module - plain Node version -
>>total 14.52%
>>- single process - Express version - total 19.05%
>>- 2 processes using Node's cluster module - Express version - total
>>30.66%
>>
>>
>> So, the results for the plain Node version are consistent with what I was
>> expecting, but the results for the Express version are not.
>> As an initial step, I'd like to understand why does putting the same code
>> inside a cluster perform so much worse when using express.
>> So I'm wondering regarding two things:
>>
>>1. Are my assumption even correct? Perhaps with increased processing
>>it IS actually expected to see such deterioration when moving from single
>>to clustered?
>>2. If my assumption is correct, which tools (if any...) can I use to
>>diagnose this so I'll know what to look for when I dive into the code. My
>>initial intuition was increased context switches, but looking at vmstat
>>output I could not find proof for that.
>>
>>
>> --
>> You received this message because you are subscribed to the Google Groups
>> "mechanical-sympathy" group.
>> To unsubscribe from this group and stop receiving emails from it, send an
>> email to mechanical-sympathy+unsubscr...@googlegroups.com.
>> For more options, visit https://groups.google.com/d/optout.
>>
>
>
>
> --
> regards,
>
>   Richard Warburton
>
>   http://insightfullogic.com
>   @RichardWarburto 
>
> --
> You received this message because you are subscribed to the Google Groups
> "mechanical-sympathy" group.
> To unsubscribe from this group and stop receiving emails from it, send an
> email to mechanical-sympathy+unsubscr...@googlegroups.com.
> For more options, visit https://groups.google.com/d/optout.
>



-- 
Regards
Suresh Kumar Khemka
+91 9741600488(M)
``Hard work never killed anybody...but why take chances?'' - Anonymous

-- 
You received this message because you are subscribed to the Google Groups 
"mechanical-sympathy" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to