Bug #10631: Rails 4.2 much slower on 2.2.0-rc1 vs. 2.1.5

• Status: Closed
• Assignee: -
• Target version: -
• ruby -v: ruby 2.2.0rc1 (2014-12-18 trunk 48887) [x86_64-darwin14]
• Backport: 2.0.0: UNKNOWN, 2.1: UNKNOWN

[felixbuenemann (Felix Bünemann)]

I'm seeing huge slowdowns when running Rails 4.2.0 on Ruby 2.2.0-rc1 (or -preview1) compared to Ruby 2.1.5.

On a production app I'm seeing ajax requests taking 4 seconds instead of 400 milliseconds.

I was also able to reproduce this using a very simple rails app:
https://github.com/felixbuenemann/rails-ruby22-regression

It has only 3 pages that link to each other and wiselinks gem for PJAX support.
The reason I included wiselinks is because it shows even larger differences in request time.
On the demo app a wiselinks requests takes under 20ms for 2.1.5 vs. 480ms on 2.2.0-rc1.

Similar differences can be seen on normal requests as measured by wrk:

chruby 2.1.5

ruby -v
ruby 2.1.5p273 (2014-11-13 revision 48405) [x86_64-darwin14.0]

wrk -c1 -t1 -d30 --latency http://localhost:3000/pages/a
Running 30s test @ http://localhost:3000/pages/a
  1 threads and 1 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    56.87ms    6.35ms  88.48ms   82.20%
    Req/Sec    17.15      3.00    20.00     71.20%
  Latency Distribution
     50%   54.86ms
     75%   60.03ms
     90%   65.94ms
     99%   78.46ms
  529 requests in 30.01s, 1.33MB read
Requests/sec:     17.63
Transfer/sec:     45.50KB

chruby 2.2.0-rc1

ruby -v
ruby 2.2.0rc1 (2014-12-18 trunk 48887) [x86_64-darwin14]

wrk -c1 -t1 -d30 --latency http://localhost:3000/pages/a
Running 30s test @ http://localhost:3000/pages/a
  1 threads and 1 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   255.41ms   13.24ms 301.49ms   75.51%
    Req/Sec     3.51      0.74     5.00     85.71%
  Latency Distribution
     50%  251.72ms
     75%  262.70ms
     90%  274.60ms
     99%  301.49ms
  117 requests in 30.04s, 301.98KB read
Requests/sec:      3.89
Transfer/sec:     10.05KB

As can be seen average request time jumped from 57ms to 255ms.
I also noticed that the difference gets larger the more code/gems the app loads.

All tests where done in development mode.
Using production mode both ruby versions are similarly fast, so this might have to do with rails dynamic code reloading in development mode.

Both rubies were installed without special options using ruby-install and no tweaking of GC/HEAP was done.

[tenderlovemaking (Aaron Patterson)]

The README says you tried this on OS X. Can you try it on Linux? This may be related to Bug #10015, and testing on Linux would eliminate that possibility.

[felixbuenemann (Felix Bünemann)]

Yes, I tried it on Yosemite 10.10.2. I now re-ran the tests on an Ubuntu Trusty VM with 2.1.5 and 2.2.0-rc1 installed through ruby-install and results look promising:

chruby 2.1.5

ruby -v
ruby 2.1.5p273 (2014-11-13 revision 48405) [x86_64-linux]

wrk -c1 -t1 -d30 --latency http://192.168.161.137:3000/pages/a
Running 30s test @ http://192.168.161.137:3000/pages/a
  1 threads and 1 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    57.20ms    7.27ms  80.10ms   78.01%
    Req/Sec    16.94      3.38    26.00     64.40%
  Latency Distribution
     50%   56.93ms
     75%   59.67ms
     90%   65.88ms
     99%   78.76ms
  522 requests in 30.01s, 1.32MB read
Requests/sec:     17.39
Transfer/sec:     44.89KB

chruby 2.2.0-rc1

ruby -v
ruby 2.2.0rc1 (2014-12-18 trunk 48887) [x86_64-linux]

wrk -c1 -t1 -d30 --latency http://192.168.161.137:3000/pages/a
Running 30s test @ http://192.168.161.137:3000/pages/a
  1 threads and 1 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    47.84ms    6.46ms  73.89ms   75.60%
    Req/Sec    20.61      4.55    26.00     60.00%
  Latency Distribution
     50%   47.42ms
     75%   49.82ms
     90%   55.03ms
     99%   70.13ms
  631 requests in 30.02s, 1.59MB read
Requests/sec:     21.02
Transfer/sec:     54.26KB

Manual testing also showed ruby 2.2 to be faster than 2.1.

So this might indeed be related to the Dir[] performance regression reported in #10015.

Thanks for the hints and merry christmas Aaron!

[felixbuenemann (Felix Bünemann)]

I tried the following patch against ruby-trunk r48405 to make sure this is the Dir[] performance regression:

--- a/dir.c
+++ b/dir.c
@@ -1241,7 +1241,7 @@ glob_make_pattern(const char *p, const char *e, int flags, rb_encoding *enc)
        else {
            const char *m = find_dirsep(p, e, flags, enc);
            const enum glob_pattern_type magic = has_magic(p, m, flags, enc);
-           const enum glob_pattern_type non_magic = (HAVE_HFS || FNM_SYSCASE) ? PLAIN : ALPHA;
+           const enum glob_pattern_type non_magic = ALPHA;
            char *buf;

            if (!(FNM_SYSCASE || magic > non_magic) && !recursive && *m) {

After that performance problems on OS X are gone.

Please mark this as a duplicate of #10015 and close it.

[duerst (Martin Dürst)]

• Status changed from Open to Closed

Duplicate of #10015