ruby-core@ruby-lang.org archive (unofficial mirror)
 help / color / mirror / Atom feed
From: lourens@bearmetal.eu
To: ruby-core@ruby-lang.org
Subject: [ruby-core:93678] [Ruby master Misc#15802] Reduce the minimum string buffer size from 127 to 63 bytes
Date: Thu, 11 Jul 2019 09:24:45 +0000 (UTC)	[thread overview]
Message-ID: <redmine.journal-79289.20190711092445.976c6ed1425866ae@ruby-lang.org> (raw)
In-Reply-To: redmine.issue-15802.20190427164014@ruby-lang.org

Issue #15802 has been updated by methodmissing (Lourens Naudé).


Apologies for the late reply - I will do some more testing and qualify with a percentage instead.

----------------------------------------
Misc #15802: Reduce the minimum string buffer size from 127 to 63 bytes
https://bugs.ruby-lang.org/issues/15802#change-79289

* Author: methodmissing (Lourens Naudé)
* Status: Open
* Priority: Normal
* Assignee: 
----------------------------------------
References Github PR https://github.com/ruby/ruby/pull/2151 - another small change, but posting here for further discussion.

While having a look through `String` specific allocation paths with [dhat](http://valgrind.org/docs/manual/dh-manual.html#dh-manual.overview) on redmine I noticed many string buffer use cases actually need way less than the current `128` byte minimum size (127 current minimum size + sentinel).

These auxiliary buffers are malloc heap specific as the `String` type is not supported by the transient heap due to complexity.

#### How to interpret the DHAT output

From the example output below, we can draw the following conclusions for the specific allocation site leading up to `rb_str_buf_new`:

* Total allocated size of `434944` bytes with a very low read and write access ratio under 25%
* The buffer is thus 75% larger than it should be for this particular site (more examples further down below)
* Short lived as expected from a buffer use case, but did occupy non-insignificant heap space still for a fair amount of time
* The `0`s at the tail end of the output represent memory never accessed (rows are byte offsets)
* As an aside, this particular string's first few characters are `hot` (accessed more frequently than the tail end)

```
==26579== -------------------- 95 of 300 --------------------
==26579== max-live:    330,368 in 2,581 blocks
==26579== tot-alloc:   434,944 in 3,398 blocks (avg size 128.00)
==26579== deaths:      3,347, at avg age 368,102,626 (2.64% of prog lifetime)
==26579== acc-ratios:  0.22 rd, 0.25 wr  (97,275 b-read, 110,341 b-written)
==26579==    at 0x4C2DECF: malloc (in /usr/lib/valgrind/vgpreload_exp-dhat-amd64-linux.so)
==26579==    by 0x1521D3: objspace_xmalloc0 (gc.c:9407)
==26579==    by 0x284A9B: rb_str_buf_new (string.c:1331)
==26579==    by 0x31B9F7: rb_ary_join (array.c:2331)
==26579==    by 0x2E5B4E: vm_call_cfunc_with_frame (vm_insnhelper.c:2207)
==26579==    by 0x2E5B4E: vm_call_cfunc (vm_insnhelper.c:2225)
==26579==    by 0x2F7C7C: vm_sendish (vm_insnhelper.c:3623)
==26579==    by 0x2F7C7C: vm_exec_core (insns.def:789)
==26579==    by 0x2EE34D: rb_vm_exec (vm.c:1892)
==26579==    by 0x2EEEED: invoke_iseq_block_from_c (vm.c:1104)
==26579==    by 0x2EEEED: invoke_block_from_c_bh (vm.c:1122)
==26579==    by 0x2EEEED: vm_yield (vm.c:1167)
==26579==    by 0x2EEEED: rb_yield_0 (vm_eval.c:980)
==26579==    by 0x2EEEED: rb_yield_1 (vm_eval.c:986)
==26579==    by 0x2EEEED: rb_yield (vm_eval.c:996)
==26579==    by 0x31153B: rb_ary_each (array.c:2087)
==26579==    by 0x2E5B4E: vm_call_cfunc_with_frame (vm_insnhelper.c:2207)
==26579==    by 0x2E5B4E: vm_call_cfunc (vm_insnhelper.c:2225)
==26579==    by 0x2F7D2B: vm_sendish (vm_insnhelper.c:3623)
==26579==    by 0x2F7D2B: vm_exec_core (insns.def:771)
==26579==    by 0x2EE34D: rb_vm_exec (vm.c:1892)
==26579== 
==26579== Aggregated access counts by offset:
==26579== 
==26579== [   0]  11407 8731 9660 11112 11171 11724 13165 13609 10826 10998 11436 11420 11405 10295 9710 9316 
==26579== [  16]  5664 4959 3874 3607 2965 2395 1908 1509 1285 967 597 261 149 141 140 124 
==26579== [  32]  73 57 56 55 55 55 54 52 51 51 51 51 51 51 51 51 
==26579== [  48]  34 34 34 34 34 34 17 0 0 0 0 0 0 0 0 0 
==26579== [  64]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==26579== [  80]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==26579== [  96]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==26579== [ 112]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
```

#### Why lower is better

The easiest reproducible case from the benchmark suite is the `require` benchmark (the allocation site below is from Rails though - DHAT is very slow and doesn't make sense in context of a benchmark):

```
==28383== -------------------- 572 of 600 --------------------
==28383== max-live:    36,992 in 289 blocks
==28383== tot-alloc:   91,520 in 715 blocks (avg size 128.00)
==28383== deaths:      553, at avg age 908,212,488 (8.68% of prog lifetime)
==28383== acc-ratios:  6.15 rd, 0.41 wr  (563,074 b-read, 37,525 b-written)
==28383==    at 0x4C2DECF: malloc (in /usr/lib/valgrind/vgpreload_exp-dhat-amd64-linux.so)
==28383==    by 0x1521D3: objspace_xmalloc0 (gc.c:9407)
==28383==    by 0x284A9B: rb_str_buf_new (string.c:1331)
==28383==    by 0x290D56: str_gsub (string.c:5163)
==28383==    by 0x2E5B4E: vm_call_cfunc_with_frame (vm_insnhelper.c:2207)
==28383==    by 0x2E5B4E: vm_call_cfunc (vm_insnhelper.c:2225)
==28383==    by 0x2F7C7C: vm_sendish (vm_insnhelper.c:3623)
==28383==    by 0x2F7C7C: vm_exec_core (insns.def:789)
==28383==    by 0x2EE34D: rb_vm_exec (vm.c:1892)
==28383==    by 0x18B336: rb_load_internal0 (load.c:612)
==28383==    by 0x18E1B0: rb_require_internal (load.c:1028)
==28383==    by 0x18E3B2: rb_require_safe (load.c:1074)
==28383==    by 0x18E3B2: rb_f_require (load.c:821)
==28383==    by 0x2E5B4E: vm_call_cfunc_with_frame (vm_insnhelper.c:2207)
==28383==    by 0x2E5B4E: vm_call_cfunc (vm_insnhelper.c:2225)
==28383==    by 0x2F1F42: vm_call_method (vm_insnhelper.c:2712)
==28383== 
==28383== Aggregated access counts by offset:
==28383== 
==28383== [   0]  17936 15574 14945 15051 14538 15487 15599 15077 14658 14483 14826 14849 15232 15238 15522 15310 
==28383== [  16]  15055 15020 15143 15156 15271 14807 14656 14271 14051 13761 13365 13156 12756 12530 12302 12002 
==28383== [  32]  7652 7427 7106 6807 6594 6315 6044 5932 5750 5606 5520 5439 5347 5237 5174 5095 
==28383== [  48]  2252 2211 2158 2128 2117 2088 2075 2045 2034 2018 2006 1992 1974 1973 1964 1964 
==28383== [  64]  183 183 183 183 183 183 183 183 183 183 183 183 183 183 183 183 
==28383== [  80]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==28383== [  96]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==28383== [ 112]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
```

```
lourens@CarbonX1:~/src/ruby/ruby$ /usr/local/bin/ruby --disable=gems -rrubygems -I./benchmark/lib ./benchmark/benchmark-driver/exe/benchmark-driver             --executables="compare-ruby::~/src/ruby/trunk/ruby --disable=gems -I.ext/common --disable-gem"             --executables="built-ruby::./miniruby -I./lib -I. -I.ext/common  -r./prelude --disable-gem" -v --repeat-count=24 -r ips $(ls ./benchmark/*require.{yml,rb} 2>/dev/null)
compare-ruby: ruby 2.7.0dev (2019-04-25 trunk 9bfc185a0d) [x86_64-linux]
built-ruby: ruby 2.7.0dev (2019-04-25 lower-str-buf-.. 9bfc185a0d) [x86_64-linux]
Calculating -------------------------------------
                     compare-ruby  built-ruby 
             require        1.870       2.408 i/s -       1.000 times in 0.534865s 0.415268s

Comparison:
                          require
          built-ruby:         2.4 i/s 
        compare-ruby:         1.9 i/s - 1.29x  slower

lourens@CarbonX1:~/src/ruby/ruby$ /usr/local/bin/ruby --disable=gems -rrubygems -I./benchmark/lib ./benchmark/benchmark-driver/exe/benchmark-driver             --executables="compare-ruby::~/src/ruby/trunk/ruby --disable=gems -I.ext/common --disable-gem"             --executables="built-ruby::./miniruby -I./lib -I. -I.ext/common  -r./prelude --disable-gem" -v --repeat-count=24 -r memory $(ls ./benchmark/*require.{yml,rb} 2>/dev/null)
compare-ruby: ruby 2.7.0dev (2019-04-25 trunk 9bfc185a0d) [x86_64-linux]
built-ruby: ruby 2.7.0dev (2019-04-25 lower-str-buf-.. 9bfc185a0d) [x86_64-linux]
Calculating -------------------------------------
                     compare-ruby  built-ruby 
             require      28.128M     26.932M bytes -       1.000 times

Comparison:
                          require
          built-ruby:  26932000.0 bytes 
        compare-ruby:  28128000.0 bytes - 1.04x  larger
```

Also the `hash_aref_dsym_long` benchmark has significant memory reduction:

```
lourens@CarbonX1:~/src/ruby/ruby$ /usr/local/bin/ruby --disable=gems -rrubygems -I./benchmark/lib ./benchmark/benchmark-driver/exe/benchmark-driver             --executables="compare-ruby::~/src/ruby/trunk/ruby --disable=gems -I.ext/common --disable-gem"             --executables="built-ruby::./miniruby -I./lib -I. -I.ext/common  -r./prelude --disable-gem" -v --repeat-count=6 -r memory $(ls ./benchmark/hash_aref_dsym_long.{yml,rb} 2>/dev/null)
compare-ruby: ruby 2.7.0dev (2019-04-26 trunk 5689c46457) [x86_64-linux]
built-ruby: ruby 2.7.0dev (2019-04-26 lower-str-buf-.. 9abd605533) [x86_64-linux]
last_commit=Reduce the minimum string buffer size from 127 to 63 bytes
Calculating -------------------------------------
                     compare-ruby  built-ruby 
 hash_aref_dsym_long     117.580M    104.984M bytes -       1.000 times

Comparison:
              hash_aref_dsym_long
          built-ruby: 104984000.0 bytes 
        compare-ruby: 117580000.0 bytes - 1.12x  larger
```

#### Other allocation sites of note

```
==26579== -------------------- 98 of 300 --------------------
==26579== max-live:    323,456 in 2,527 blocks
==26579== tot-alloc:   402,816 in 3,147 blocks (avg size 128.00)
==26579== deaths:      3,147, at avg age 377,614,197 (2.71% of prog lifetime)
==26579== acc-ratios:  0.21 rd, 0.16 wr  (87,620 b-read, 64,622 b-written)
==26579==    at 0x4C2DECF: malloc (in /usr/lib/valgrind/vgpreload_exp-dhat-amd64-linux.so)
==26579==    by 0x1521D3: objspace_xmalloc0 (gc.c:9407)
==26579==    by 0x284A9B: rb_str_buf_new (string.c:1331)
==26579==    by 0x294584: rb_str_inspect (string.c:5911)
==26579==    by 0x2F33F8: vm_call0_cfunc_with_frame (vm_eval.c:86)
==26579==    by 0x2F33F8: vm_call0_cfunc (vm_eval.c:100)
==26579==    by 0x2F33F8: vm_call0_body.constprop.410 (vm_eval.c:132)
==26579==    by 0x2FE4CE: rb_vm_call0 (vm_eval.c:60)
==26579==    by 0x2FE4CE: rb_call0 (vm_eval.c:309)
==26579==    by 0x2FE4CE: rb_call (vm_eval.c:603)
==26579==    by 0x2FE4CE: rb_funcall_with_block (vm_eval.c:857)
==26579==    by 0x2EEFBE: vm_yield_with_symbol (vm_insnhelper.c:2869)
==26579==    by 0x2EEFBE: invoke_block_from_c_bh (vm.c:1131)
==26579==    by 0x2EEFBE: vm_yield (vm.c:1167)
==26579==    by 0x2EEFBE: rb_yield_0 (vm_eval.c:980)
==26579==    by 0x2EEFBE: rb_yield_1 (vm_eval.c:986)
==26579==    by 0x2EEFBE: rb_yield (vm_eval.c:996)
==26579==    by 0x317627: rb_ary_collect_bang (array.c:3052)
==26579==    by 0x2E5B4E: vm_call_cfunc_with_frame (vm_insnhelper.c:2207)
==26579==    by 0x2E5B4E: vm_call_cfunc (vm_insnhelper.c:2225)
==26579==    by 0x2F7D2B: vm_sendish (vm_insnhelper.c:3623)
==26579==    by 0x2F7D2B: vm_exec_core (insns.def:771)
==26579==    by 0x2EE34D: rb_vm_exec (vm.c:1892)
==26579==    by 0x2EEEED: invoke_iseq_block_from_c (vm.c:1104)
==26579==    by 0x2EEEED: invoke_block_from_c_bh (vm.c:1122)
==26579==    by 0x2EEEED: vm_yield (vm.c:1167)
==26579==    by 0x2EEEED: rb_yield_0 (vm_eval.c:980)
==26579==    by 0x2EEEED: rb_yield_1 (vm_eval.c:986)
==26579==    by 0x2EEEED: rb_yield (vm_eval.c:996)
==26579== 
==26579== Aggregated access counts by offset:
==26579== 
==26579== [   0]  13063 14338 12631 14007 13323 12720 11984 11344 9232 7280 6288 5776 4256 3856 3584 2976 
==26579== [  16]  1968 1216 1296 720 160 48 48 48 64 16 0 0 0 0 0 0 
==26579== [  32]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==26579== [  48]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==26579== [  64]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==26579== [  80]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==26579== [  96]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==26579== [ 112]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
```

```
==26579== -------------------- 186 of 300 --------------------
==26579== max-live:    155,136 in 1,212 blocks
==26579== tot-alloc:   155,136 in 1,212 blocks (avg size 128.00)
==26579== deaths:      651, at avg age 245,150,551 (1.75% of prog lifetime)
==26579== acc-ratios:  1.63 rd, 0.33 wr  (253,660 b-read, 51,700 b-written)
==26579==    at 0x4C2DECF: malloc (in /usr/lib/valgrind/vgpreload_exp-dhat-amd64-linux.so)
==26579==    by 0x1521D3: objspace_xmalloc0 (gc.c:9407)
==26579==    by 0x284A9B: rb_str_buf_new (string.c:1331)
==26579==    by 0x13AA2E: rb_file_join (file.c:4732)
==26579==    by 0x2E5B4E: vm_call_cfunc_with_frame (vm_insnhelper.c:2207)
==26579==    by 0x2E5B4E: vm_call_cfunc (vm_insnhelper.c:2225)
==26579==    by 0x2F7C7C: vm_sendish (vm_insnhelper.c:3623)
==26579==    by 0x2F7C7C: vm_exec_core (insns.def:789)
==26579==    by 0x2EE34D: rb_vm_exec (vm.c:1892)
==26579==    by 0x2EEEED: invoke_iseq_block_from_c (vm.c:1104)
==26579==    by 0x2EEEED: invoke_block_from_c_bh (vm.c:1122)
==26579==    by 0x2EEEED: vm_yield (vm.c:1167)
==26579==    by 0x2EEEED: rb_yield_0 (vm_eval.c:980)
==26579==    by 0x2EEEED: rb_yield_1 (vm_eval.c:986)
==26579==    by 0x2EEEED: rb_yield (vm_eval.c:996)
==26579==    by 0x374412: dir_yield (dir.c:803)
==26579==    by 0x374412: dir_each_entry (dir.c:860)
==26579==    by 0x374412: dir_each (dir.c:830)
==26579==    by 0x1355D2: rb_ensure (eval.c:1076)
==26579==    by 0x373447: dir_foreach (dir.c:2955)
==26579==    by 0x2E5B4E: vm_call_cfunc_with_frame (vm_insnhelper.c:2207)
==26579==    by 0x2E5B4E: vm_call_cfunc (vm_insnhelper.c:2225)
==26579== 
==26579== Aggregated access counts by offset:
==26579== 
==26579== [   0]  17075 17890 16143 17188 15855 18234 17616 19067 13136 11474 10379 11350 10094 9420 8556 7614 
==26579== [  16]  5325 5125 5030 4865 3582 2982 3010 3018 2997 3011 3056 3104 2695 2748 2696 2680 
==26579== [  32]  1741 1726 1664 1612 1285 1191 1138 1067 1043 1008 984 983 971 985 972 970 
==26579== [  48]  565 562 568 559 560 557 557 557 557 557 557 557 557 557 557 557 
==26579== [  64]  4 4 4 4 4 4 4 4 4 4 4 4 4 4 4 4 
==26579== [  80]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==26579== [  96]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==26579== [ 112]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
```

```
==28716== -------------------- 64 of 300 --------------------
==28716== max-live:    273,280 in 2,135 blocks
==28716== tot-alloc:   446,464 in 3,488 blocks (avg size 128.00)
==28716== deaths:      2,277, at avg age 365,758,007 (3.44% of prog lifetime)
==28716== acc-ratios:  0.21 rd, 0.15 wr  (96,380 b-read, 71,208 b-written)
==28716==    at 0x4C2DECF: malloc (in /usr/lib/valgrind/vgpreload_exp-dhat-amd64-linux.so)
==28716==    by 0x1521D3: objspace_xmalloc0 (gc.c:9407)
==28716==    by 0x284A9B: rb_str_buf_new (string.c:1331)
==28716==    by 0x294584: rb_str_inspect (string.c:5911)
==28716== 
==28716== Aggregated access counts by offset:
==28716== 
==28716== [   0]  14382 15824 13909 15391 14767 14067 13241 12472 10180 7932 6842 6270 4714 4213 3909 3280 
==28716== [  16]  2173 1349 1386 810 216 63 54 55 68 20 1 0 0 0 0 0 
==28716== [  32]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==28716== [  48]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==28716== [  64]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==28716== [  80]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==28716== [  96]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==28716== [ 112]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
```

```
==28716== -------------------- 276 of 300 --------------------
==28716== max-live:    19,712 in 154 blocks
==28716== tot-alloc:   146,432 in 1,144 blocks (avg size 128.00)
==28716== deaths:      1,115, at avg age 150,688,929 (1.41% of prog lifetime)
==28716== acc-ratios:  0.06 rd, 0.08 wr  (9,024 b-read, 12,049 b-written)
==28716==    at 0x4C2DECF: malloc (in /usr/lib/valgrind/vgpreload_exp-dhat-amd64-linux.so)
==28716==    by 0x1521D3: objspace_xmalloc0 (gc.c:9407)
==28716==    by 0x284A9B: rb_str_buf_new (string.c:1331)
==28716==    by 0x23B70C: rb_reg_regsub (re.c:3820)
==28716== 
==28716== Aggregated access counts by offset:
==28716== 
==28716== [   0]  3569 4271 3304 1590 670 640 673 692 537 526 525 518 502 482 465 443 
==28716== [  16]  223 203 182 153 127 113 101 85 71 63 57 52 49 48 44 38 
==28716== [  32]  14 9 7 6 5 4 4 4 3 1 0 0 0 0 0 0 
==28716== [  48]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==28716== [  64]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==28716== [  80]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==28716== [  96]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==28716== [ 112]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
```

```
==29686== -------------------- 391 of 600 --------------------
==29686== max-live:    8,192 in 64 blocks
==29686== tot-alloc:   9,472 in 74 blocks (avg size 128.00)
==29686== deaths:      74, at avg age 207,459,973 (1.96% of prog lifetime)
==29686== acc-ratios:  0.21 rd, 0.17 wr  (1,998 b-read, 1,628 b-written)
==29686==    at 0x4C2DECF: malloc (in /usr/lib/valgrind/vgpreload_exp-dhat-amd64-linux.so)
==29686==    by 0x1521D3: objspace_xmalloc0 (gc.c:9407)
==29686==    by 0x284A9B: rb_str_buf_new (string.c:1331)
==29686==    by 0x30BB8A: inspect_ary (array.c:2379)
==29686== 
==29686== Aggregated access counts by offset:
==29686== 
==29686== [   0]  296 296 296 370 370 370 370 370 296 222 296 74 0 0 0 0 
==29686== [  16]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==29686== [  32]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==29686== [  48]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==29686== [  64]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==29686== [  80]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==29686== [  96]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
==29686== [ 112]  0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
```

#### Rails specific - redmine boot

Booting redmine only, no real work done otherwise - about `101720` bytes different in current malloc sizes. I understand `GC.malloc_allocated_size` to reflect the current delta between `xmalloc` and `xfree`, but may be wrong. And that value is not representative of total malloc heap churn, judging by the much higher total allocated values coming back from [valgrind](https://github.com/ruby/ruby/pull/2151#issuecomment-487300456).

```
lourens@CarbonX1:~/src/redmine$ bundle exec rails c -e production
/home/lourens/src/redmine/vendor/bundle/ruby/2.7.0/gems/activerecord-5.2.1.1/lib/active_record/associations/builder/collection_association.rb:26: warning: Capturing the given block using Proc.new is deprecated; use `&block` instead
Loading production environment (Rails 5.2.1.1)
irb(main):001:0> RUBY_DESCRIPTION
=> "ruby 2.7.0dev (2019-04-26 trunk 5689c46457) [x86_64-linux]"
irb(main):002:0> GC.start
=> nil
irb(main):003:0> GC.malloc_allocated_size
=> 74907128
```

```
lourens@CarbonX1:~/src/redmine$ bundle exec rails c -e production
/home/lourens/src/redmine/vendor/bundle/ruby/2.7.0/gems/activerecord-5.2.1.1/lib/active_record/associations/builder/collection_association.rb:26: warning: Capturing the given block using Proc.new is deprecated; use `&block` instead
Loading production environment (Rails 5.2.1.1)
irb(main):001:0> RUBY_DESCRIPTION
=> "ruby 2.7.0dev (2019-04-26 lower-str-buf-.. 9abd605533) [x86_64-linux]"
irb(main):002:0> GC.start
=> nil
irb(main):003:0> GC.malloc_allocated_size
=> 74805408
```

#### Rails specific - some requests / workload

Same sequence of redmine requests - 6 for this branch and trunk respectively using this as a simple initializer for reporting on exit, a `228600` bytes difference.

```ruby
if GC.respond_to?(:malloc_allocated_size)
  at_exit do
    p "#{RUBY_DESCRIPTION} GC.malloc_allocated_size: #{GC.malloc_allocated_size}"
  end
end
```

```
[2019-04-25 23:42:43] INFO  WEBrick 1.4.2
[2019-04-25 23:42:43] INFO  ruby 2.7.0 (2019-04-26) [x86_64-linux]
[2019-04-25 23:42:43] INFO  WEBrick::HTTPServer#start: pid=31335 port=3000
127.0.0.1 - - [25/Apr/2019:23:42:48 WEST] "GET / HTTP/1.1" 200 4373
http://localhost:3000/news -> /
127.0.0.1 - - [25/Apr/2019:23:42:49 WEST] "GET /projects HTTP/1.1" 200 5470
http://localhost:3000/ -> /projects
127.0.0.1 - - [25/Apr/2019:23:42:51 WEST] "GET /activity HTTP/1.1" 200 7373
http://localhost:3000/projects -> /activity
127.0.0.1 - - [25/Apr/2019:23:42:51 WEST] "GET /issues HTTP/1.1" 200 19195
http://localhost:3000/activity -> /issues
127.0.0.1 - - [25/Apr/2019:23:42:52 WEST] "GET /time_entries HTTP/1.1" 200 12508
http://localhost:3000/issues -> /time_entries
127.0.0.1 - - [25/Apr/2019:23:42:53 WEST] "GET /issues/gantt HTTP/1.1" 200 22597
http://localhost:3000/time_entries -> /issues/gantt
127.0.0.1 - - [25/Apr/2019:23:42:54 WEST] "GET /issues/calendar HTTP/1.1" 200 16712
http://localhost:3000/issues/gantt -> /issues/calendar
127.0.0.1 - - [25/Apr/2019:23:42:54 WEST] "GET /news HTTP/1.1" 200 5472
http://localhost:3000/issues/calendar -> /news
^C[2019-04-25 23:42:58] INFO  going to shutdown ...
[2019-04-25 23:42:59] INFO  WEBrick::HTTPServer#start done.
Exiting
"ruby 2.7.0dev (2019-04-26 trunk 5689c46457) [x86_64-linux] GC.malloc_allocated_size: 84901440"
```

```
[2019-04-25 23:41:51] INFO  WEBrick 1.4.2
[2019-04-25 23:41:51] INFO  ruby 2.7.0 (2019-04-26) [x86_64-linux]
[2019-04-25 23:41:51] INFO  WEBrick::HTTPServer#start: pid=31029 port=3000
127.0.0.1 - - [25/Apr/2019:23:41:59 WEST] "GET / HTTP/1.1" 200 4373
http://localhost:3000/activity -> /
127.0.0.1 - - [25/Apr/2019:23:42:02 WEST] "GET /projects HTTP/1.1" 200 5470
http://localhost:3000/ -> /projects
127.0.0.1 - - [25/Apr/2019:23:42:04 WEST] "GET /activity HTTP/1.1" 200 7373
http://localhost:3000/projects -> /activity
127.0.0.1 - - [25/Apr/2019:23:42:05 WEST] "GET /issues HTTP/1.1" 200 19195
http://localhost:3000/activity -> /issues
127.0.0.1 - - [25/Apr/2019:23:42:06 WEST] "GET /time_entries HTTP/1.1" 200 12508
http://localhost:3000/issues -> /time_entries
127.0.0.1 - - [25/Apr/2019:23:42:07 WEST] "GET /issues/gantt HTTP/1.1" 200 22597
http://localhost:3000/time_entries -> /issues/gantt
127.0.0.1 - - [25/Apr/2019:23:42:07 WEST] "GET /javascripts/raphael.js?1543965852 HTTP/1.1" 200 90648
http://localhost:3000/issues/gantt -> /javascripts/raphael.js?1543965852
127.0.0.1 - - [25/Apr/2019:23:42:08 WEST] "GET /issues/calendar HTTP/1.1" 200 16712
http://localhost:3000/issues/gantt -> /issues/calendar
127.0.0.1 - - [25/Apr/2019:23:42:09 WEST] "GET /news HTTP/1.1" 200 5472
http://localhost:3000/issues/calendar -> /news
^C[2019-04-25 23:42:14] INFO  going to shutdown ...
[2019-04-25 23:42:15] INFO  WEBrick::HTTPServer#start done.
Exiting
"ruby 2.7.0dev (2019-04-26 lower-str-buf-.. 9abd605533) [x86_64-linux] GC.malloc_allocated_size: 84672840"
```



-- 
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>

  parent reply	other threads:[~2019-07-11  9:24 UTC|newest]

Thread overview: 4+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
     [not found] <redmine.issue-15802.20190427164014@ruby-lang.org>
2019-04-27 16:40 ` [ruby-core:92442] [Ruby trunk Misc#15802] Reduce the minimum string buffer size from 127 to 63 bytes lourens
2019-05-22  6:02 ` [ruby-core:92763] " ko1
2019-07-11  9:24 ` lourens [this message]
2019-07-30  4:04 ` [ruby-core:94018] [Ruby master " ko1

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-list from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

  List information: https://www.ruby-lang.org/en/community/mailing-lists/

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=redmine.journal-79289.20190711092445.976c6ed1425866ae@ruby-lang.org \
    --to=ruby-core@ruby-lang.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).