From: tenderlove@...
Date: 2020-12-10T00:26:37+00:00
Subject: [ruby-core:101349] [Ruby master Bug#17373] Ruby 3.0 is slower at Discourse bench than Ruby 2.7

Issue #17373 has been updated by tenderlovemaking (Aaron Patterson).


@xrxr and I made a patch that implements a *negative* lookup cache.  We also changed `respond_to?` to use the per class method cache.

This PR has the "respond_to" patch:  https://github.com/ruby/ruby/pull/3873

This PR has the negative cache in addition to the "respond_to" patch: https://github.com/ruby/ruby/pull/3872

Neither of these patches seemed to have a large impact on RailsBench.  Maybe they will help Discourse, but I'm not sure.

I do want to talk about the problems with the negative cache patch though.  First, I think some of the invalidation is broken (and that's why the CI is red), but that's not really the biggest issue.

The pCMC is effectively a weak reference cache.  In our strategy, we just insert a NULL in the cache for that method name.  The fact that there is a cache entry, but the entry is NULL allows us to avoid lookups for the negative case.

The problem though: If we cache *negative* values (in this case it caches a `NULL`), how long should those negative values live?  Right now, they get GC'd extremely quickly.  For example, here is a `perf` report *before* adding a negative cache:

![perf 1](https://user-images.githubusercontent.com/3124/101704483-b3432100-3a39-11eb-8d19-9957a65349a5.png)


You can see `rb_id_table_lookup` is pretty high in the report.  Now compare to a perf report *after* adding the negative cache:

![perf 2](https://user-images.githubusercontent.com/3124/101704885-93602d00-3a3a-11eb-9d58-321578cedc4f.png)

Now the number 2 entry is `cc_table_free_i`.  Now we're spending time freeing entries in the pCMC because the negative cache entries aren't real objects.  I guess the question is: how long should these negative entries live?  They can't live forever.

Numbers for RailsBench were approximately the same with this patch presumably because of the extra GC time.

Anyway, I don't have good answers right now, but I wanted to share progress.  Also, I'm sorry these screenshots look so big in the webui, I don't know how to make them smaller ����

----------------------------------------
Bug #17373: Ruby 3.0 is slower at Discourse bench than Ruby 2.7
https://bugs.ruby-lang.org/issues/17373#change-89056

* Author: sam.saffron (Sam Saffron)
* Status: Open
* Priority: Normal
* ruby -v: 3.0
* Backport: 2.5: UNKNOWN, 2.6: UNKNOWN, 2.7: UNKNOWN
----------------------------------------
We have a continuous effort to keep https://rubybench.org/ up to date. Unfortunately we have lapsed a bit on updates so I decided to run Discourse bench by hand.

On my local system I am noticing the timing are much slower on Discourse bench than they were on Ruby 2.7: 

```
98c9120cc00ba691b4abcc13a49a30fa54638535

---
categories:
  50: 34
  75: 35
  90: 36
  99: 40
home:
  50: 47
  75: 50
  90: 56
  99: 92
topic:
  50: 53
  75: 55
  90: 58
  99: 92
categories_admin:
  50: 33
  75: 34
  90: 38
  99: 68
home_admin:
  50: 45
  75: 47
  90: 51
  99: 95
topic_admin:
  50: 51
  75: 52
  90: 54
  99: 59
timings:
  load_rails: 1449
ruby-version: 3.0.0-p-1
rss_kb: 293808
pss_kb: 284244

2.7.2


---
categories:
  50: 29
  75: 30
  90: 33
  99: 43
home:
  50: 42
  75: 43
  90: 47
  99: 73
topic:
  50: 47
  75: 47
  90: 52
  99: 54
categories_admin:
  50: 30
  75: 31
  90: 36
  99: 56
home_admin:
  50: 41
  75: 43
  90: 48
  99: 71
topic_admin:
  50: 47
  75: 48
  90: 52
  99: 55
timings:
  load_rails: 1339
ruby-version: 2.7.2-p137
rss_kb: 296836
pss_kb: 287310


2.6.6


---
categories:
  50: 30
  75: 30
  90: 31
  99: 51
home:
  50: 40
  75: 42
  90: 60
  99: 79
topic:
  50: 47
  75: 48
  90: 53
  99: 71
categories_admin:
  50: 30
  75: 31
  90: 35
  99: 50
home_admin:
  50: 41
  75: 43
  90: 62
  99: 100
topic_admin:
  50: 48
  75: 49
  90: 65
  99: 93
timings:
  load_rails: 1464
ruby-version: 2.6.6-p146
rss_kb: 332268
pss_kb: 322865
```

Concretely this means a typical "homepage" view is taking 47 milliseconds now, when in the past it was taking 42 or even 40 ms.

There may be some issues with the bench, you can see it here: 

https://github.com/discourse/discourse/tree/ruby-3

The script to run the bench is `ruby script/bench.rb`

I re-tested against a cleanly built Ruby 2.7 direct from the Git branch to ensure compilation was not at fault.


This is pretty concerning, Discourse bench usually tracks Rails performance pretty accurately. 

---Files--------------------------------
aaron ��� perf _home_aaron_git_railsbench ��� ssh whiteclaw.local ��� 175��54 2020-12-07 12-41-12.png (842 KB)
aaron ��� perf _home_aaron_git_railsbench ��� ssh whiteclaw.local ��� 175��54 2020-12-07 12-41-58.png (874 KB)
aaron ��� perf _home_aaron_git_railsbench ��� ssh whiteclaw.local ��� 299��65 2020-12-07 13-19-20.png (142 KB)


-- 
https://bugs.ruby-lang.org/

Unsubscribe: <mailto:ruby-core-request@ruby-lang.org?subject=unsubscribe>
<http://lists.ruby-lang.org/cgi-bin/mailman/options/ruby-core>