title: CPU Higher than expected in Node running in docker
body: <p>I have a vagrant machine running at 33% CPU on my Mac (10.9.5) when nothing is supposed to be happening. The VM machine is run by Kinematic. Looking inside one of the containers I see 2 node (v0.12.2) processes running at 3-4% CPU each.</p>
  
  <pre><code>root@49ab3ab54901:/usr/src# top -bc
  top - 03:11:59 up  8:31,  0 users,  load average: 0.13, 0.18, 0.22
  Tasks:   7 total,   1 running,   6 sleeping,   0 stopped,   0 zombie
  %Cpu(s):  0.2 us,  0.7 sy,  0.0 ni, 99.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
  KiB Mem:   2051824 total,  1942836 used,   108988 free,    74572 buffers
  KiB Swap:  1466848 total,    18924 used,  1447924 free.   326644 cached Mem
  
    PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
      1 root      20   0    4332    672    656 S   0.0  0.0   0:00.10 /bin/sh -c node -e "require('./seed/seeder.js').seed().then(function (resp) {   console.log('successfully seeded!');   pro+
     15 root      20   0  737320  81008  13452 S   0.0  3.9   0:32.57 node /usr/local/bin/nodemon app/api.js
     33 root      20   0    4332    740    652 S   0.0  0.0   0:00.00 sh -c node app/api.js
     34 root      20   0  865080  68952  14244 S   0.0  3.4   0:01.70 node app/api.js
     83 root      20   0   20272   3288   2776 S   0.0  0.2   0:00.11 bash
  18563 root      20   0   20248   3152   2840 S   0.0  0.2   0:00.11 bash
  18575 root      20   0   21808   2308   2040 R   0.0  0.1   0:00.00 top -bc
  </code></pre>
  
  <p>I went on and runned a <code>node --prof</code> and processed the log with <code>node-tick-processor</code>. It looks like that 99.3% of CPU is used in the syscall :
  (for full output see <a href="http://pastebin.com/6qgFuFWK" rel="nofollow">http://pastebin.com/6qgFuFWK</a> )</p>
  
  <pre><code>root@d6d78487e1ec:/usr/src# node-tick-processor isolate-0x26c0180-v8.log
  ...
  Statistical profiling result from isolate-0x26c0180-v8.log, (130664 ticks, 0 unaccounted, 0 excluded).
  
  ...
   [C++]:
     ticks  total  nonlib   name
    129736   99.3%   99.3%  syscall
      160    0.1%    0.1%  node::ContextifyScript::New(v8::FunctionCallbackInfo&lt;v8::Value&gt; const&amp;)
      124    0.1%    0.1%  __write
       73    0.1%    0.1%  __xstat
       18    0.0%    0.0%  v8::internal::Heap::AllocateFixedArray(int, v8::internal::PretenureFlag)
       18    0.0%    0.0%  node::Stat(v8::FunctionCallbackInfo&lt;v8::Value&gt; const&amp;)
       17    0.0%    0.0%  __lxstat
       16    0.0%    0.0%  node::Read(v8::FunctionCallbackInfo&lt;v8::Value&gt; const&amp;)
  ...
        1    0.0%    0.0%  __fxstat
        1    0.0%    0.0%  _IO_default_xsputn
  
   [GC]:
     ticks  total  nonlib   name
       22    0.0%
  
   [Bottom up (heavy) profile]:
    Note: percentage shows a share of a particular caller in the total
    amount of its parent calls.
    Callers occupying less than 2.0% are not shown.
  
     ticks parent  name
    129736   99.3%  syscall
  
  
   [Top down (heavy) profile]:
    Note: callees occupying less than 0.1% are not shown.
  
    inclusive      self           name
    ticks   total  ticks   total
    129736   99.3%  129736   99.3%  syscall
  
      865    0.7%      0    0.0%  Function: ~&lt;anonymous&gt; node.js:27:10
      864    0.7%      0    0.0%    LazyCompile: ~startup node.js:30:19
      851    0.7%      0    0.0%      LazyCompile: ~Module.runMain module.js:499:26
      799    0.6%      0    0.0%        LazyCompile: Module._load module.js:273:24
      795    0.6%      0    0.0%          LazyCompile: ~Module.load module.js:345:33
      794    0.6%      0    0.0%            LazyCompile: ~Module._extensions..js module.js:476:37
      792    0.6%      0    0.0%              LazyCompile: ~Module._compile module.js:378:37
      791    0.6%      0    0.0%                Function: ~&lt;anonymous&gt; /usr/src/app/api.js:1:11
      791    0.6%      0    0.0%                  LazyCompile: ~require module.js:383:19
      791    0.6%      0    0.0%                    LazyCompile: ~Module.require module.js:362:36
      791    0.6%      0    0.0%                      LazyCompile: Module._load module.js:273:24
      788    0.6%      0    0.0%                        LazyCompile: ~Module.load module.js:345:33
      786    0.6%      0    0.0%                          LazyCompile: ~Module._extensions..js module.js:476:37
      783    0.6%      0    0.0%                            LazyCompile: ~Module._compile module.js:378:37
      644    0.5%      0    0.0%                              Function: ~&lt;anonymous&gt; /usr/src/app/api.authentication.js:1:11
      627    0.5%      0    0.0%                                                                                                                             
  </code></pre>
  
  <p>...</p>
  
  <p>A <code>strace</code> resulted in nothing abnormal:</p>
  
  <pre><code>% time     seconds  usecs/call     calls    errors syscall
  ------ ----------- ----------- --------- --------- ----------------
   54.51    0.001681          76        22           clone
   17.28    0.000533           4       132           epoll_ctl
   16.80    0.000518          24        22           wait4
    6.39    0.000197           2       110        66 stat
    5.03    0.000155           1       176           close
    0.00    0.000000           0       176           read
    0.00    0.000000           0        88           write
    0.00    0.000000           0        44           rt_sigaction
    0.00    0.000000           0        88           rt_sigprocmask
    0.00    0.000000           0        22           rt_sigreturn
    0.00    0.000000           0        66           ioctl
    0.00    0.000000           0        66           socketpair
    0.00    0.000000           0        88           epoll_wait
    0.00    0.000000           0        22           pipe2
  ------ ----------- ----------- --------- --------- ----------------
  100.00    0.003084                  1122        66 total
  </code></pre>
  
  <p>And the other node process:</p>
  
  <pre><code> % time     seconds  usecs/call     calls    errors syscall
   ------ ----------- ----------- --------- --------- ----------------
     0.00    0.000000           0        14           epoll_wait
   ------ ----------- ----------- --------- --------- ----------------
   100.00    0.000000                    14           total
  </code></pre>
  
  <p>Am I missing something?
  I wonder if it is VirtualBox's or Docker's layers consuming 4%. </p>
  
  <p>When you have a few containers with 2 processes running at 4%, it adds up quickly.</p>