Performance of incremental GC


#1

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

Your Results: (note for timings- percentile is first, duration is second in millisecs)
---
categories_admin:
  50: 86
  75: 91
  90: 99
  99: 161
home_admin:
  50: 76
  75: 78
  90: 84
  99: 102
topic_admin:
  50: 40
  75: 41
  90: 44
  99: 65
categories:
  50: 72
  75: 75
  90: 83
  99: 151
home:
  50: 49
  75: 52
  90: 57
  99: 85
topic:
  50: 18
  75: 18
  90: 19
  99: 31
timings:
  load_rails: 2768
ruby-version: 2.1.5-p273
rss_kb: 239832
pss_kb: 235203
physicalprocessorcount: 1
architecture: amd64
virtual: physical
operatingsystem: Ubuntu
processor0: Intel(R) Core(TM) i7-4700HQ CPU @ 2.40GHz
memorysize: 15.59 GB
kernelversion: 3.13.0

guoxiang-GS60-2PC-Ghost pid:14019 ruby /home/guoxiang/ rbenv/versions/2 1 5/bin/thin start  p 6  79

GC STATS:
count: 554
heap_used: 2487
heap_length: 2692
heap_increment: 863
heap_live_slot: 462831
heap_free_slot: 550848
heap_final_slot: 0
heap_swept_slot: 376426
heap_eden_page_length: 1624
heap_tomb_page_length: 863
total_allocated_object: 211751502
total_freed_object: 211288671
malloc_increase: 4232
malloc_limit: 16777216
minor_gc_count: 504
major_gc_count: 50
remembered_shady_object: 11943
remembered_shady_object_limit: 23886
old_object: 437374
old_object_limit: 874748
oldmalloc_increase: 4680
oldmalloc_limit: 16777216

Objects:
TOTAL: 1013679
FREE: 550736
T_STRING: 220011
T_ARRAY: 67104
T_DATA: 61509
T_NODE: 38261
T_OBJECT: 27645
T_HASH: 26832
T_CLASS: 11509
T_REGEXP: 3492
T_ICLASS: 3336
T_MODULE: 1650
T_RATIONAL: 891
T_STRUCT: 655
T_MATCH: 21
T_FLOAT: 11
T_BIGNUM: 9
T_FILE: 6
T_COMPLEX: 1

Process Info:
Name:	ruby
State:	R (running)
Tgid:	14019
Ngid:	0
Pid:	14019
PPid:	13462
TracerPid:	0
Uid:	1000	1000	1000	1000
Gid:	1000	1000	1000	1000
FDSize:	64
Groups:	4 24 27 30 46 108 124 1000 
VmPeak:	  713032 kB
VmSize:	  711500 kB
VmLck:	       0 kB
VmPin:	       0 kB
VmHWM:	  240384 kB
VmRSS:	  239572 kB
VmData:	  498504 kB
VmStk:	     140 kB
VmExe:	    2844 kB
VmLib:	   25548 kB
VmPTE:	     904 kB
VmSwap:	       0 kB
Threads:	6
SigQ:	0/127276
SigPnd:	0000000000000000
ShdPnd:	0000000000000000
SigBlk:	0000000000000000
SigIgn:	0000000000001000
SigCgt:	0000000182006e47
CapInh:	0000000000000000
CapPrm:	0000000000000000
CapEff:	0000000000000000
CapBnd:	0000001fffffffff
Seccomp:	0
Cpus_allowed:	ff
Cpus_allowed_list:	0-7
Mems_allowed:	00000000,00000001
Mems_allowed_list:	0
voluntary_ctxt_switches:	222596
nonvoluntary_ctxt_switches:	60539


Classes:
Class report omitted use ?full=1 to include it

ruby 2.2.0p6 (2015-01-03 revision 49125) [x86_64-linux]

Your Results: (note for timings- percentile is first, duration is second in millisecs)
---
categories_admin:
  50: 87
  75: 92
  90: 100
  99: 125
home_admin:
  50: 76
  75: 79
  90: 85
  99: 104
topic_admin:
  50: 41
  75: 42
  90: 45
  99: 53
categories:
  50: 72
  75: 76
  90: 85
  99: 105
home:
  50: 50
  75: 52
  90: 59
  99: 73
topic:
  50: 18
  75: 18
  90: 19
  99: 28
timings:
  load_rails: 2667
ruby-version: 2.2.0-p6
rss_kb: 220104
pss_kb: 215500
physicalprocessorcount: 1
architecture: amd64
virtual: physical
operatingsystem: Ubuntu
processor0: Intel(R) Core(TM) i7-4700HQ CPU @ 2.40GHz
memorysize: 15.59 GB
kernelversion: 3.13.0

guoxiang-GS60-2PC-Ghost pid:4879 ruby /home/guoxiang/ rbenv/versions/ruby 2 2  /bin/thin start  p 6  79

GC STATS:
count: 581
heap_allocated_pages: 2418
heap_sorted_length: 2455
heap_allocatable_pages: 213
heap_available_slots: 985565
heap_live_slots: 446919
heap_free_slots: 538646
heap_final_slots: 0
heap_marked_slots: 446872
heap_swept_slots: 538692
heap_eden_pages: 2205
heap_tomb_pages: 213
total_allocated_pages: 2418
total_freed_pages: 0
total_allocated_objects: 210196038
total_freed_objects: 209749119
malloc_increase_bytes: 6992
malloc_increase_bytes_limit: 16777216
minor_gc_count: 530
major_gc_count: 51
remembered_wb_unprotected_objects: 11566
remembered_wb_unprotected_objects_limit: 23132
old_objects: 420854
old_objects_limit: 841708
oldmalloc_increase_bytes: 7440
oldmalloc_increase_bytes_limit: 18172660

Objects:
TOTAL: 985565
FREE: 538514
T_STRING: 211524
T_ARRAY: 63249
T_DATA: 61539
T_NODE: 38337
T_HASH: 25499
T_OBJECT: 22158
T_CLASS: 11532
T_REGEXP: 3504
T_ICLASS: 3336
T_SYMBOL: 3200
T_MODULE: 1651
T_RATIONAL: 891
T_STRUCT: 592
T_MATCH: 13
T_FLOAT: 11
T_BIGNUM: 9
T_FILE: 5
T_COMPLEX: 1

Process Info:
Name:	ruby
State:	R (running)
Tgid:	4879
Ngid:	0
Pid:	4879
PPid:	4306
TracerPid:	0
Uid:	1000	1000	1000	1000
Gid:	1000	1000	1000	1000
FDSize:	64
Groups:	4 24 27 30 46 108 124 1000 
VmPeak:	  694604 kB
VmSize:	  691720 kB
VmLck:	       0 kB
VmPin:	       0 kB
VmHWM:	  220032 kB
VmRSS:	  217472 kB
VmData:	  476576 kB
VmStk:	     140 kB
VmExe:	    2896 kB
VmLib:	   25584 kB
VmPTE:	     856 kB
VmSwap:	       0 kB
Threads:	6
SigQ:	0/127276
SigPnd:	0000000000000000
ShdPnd:	0000000000000000
SigBlk:	0000000000000000
SigIgn:	0000000000001000
SigCgt:	0000000182006e4f
CapInh:	0000000000000000
CapPrm:	0000000000000000
CapEff:	0000000000000000
CapBnd:	0000001fffffffff
Seccomp:	0
Cpus_allowed:	ff
Cpus_allowed_list:	0-7
Mems_allowed:	00000000,00000001
Mems_allowed_list:	0
voluntary_ctxt_switches:	223039
nonvoluntary_ctxt_switches:	60075


Classes:
Class report omitted use ?full=1 to include it

ruby 2.2.0p6 (2015-01-03 revision 49125) [x86_64-linux] (USE_RGENGC = 0)

Your Results: (note for timings- percentile is first, duration is second in millisecs)
---
categories_admin:
  50: 225
  75: 242
  90: 423
  99: 942
home_admin:
  50: 165
  75: 168
  90: 173
  99: 199
topic_admin:
  50: 42
  75: 85
  90: 88
  99: 94
categories:
  50: 163
  75: 169
  90: 211
  99: 272
home:
  50: 95
  75: 140
  90: 146
  99: 200
topic:
  50: 17
  75: 62
  90: 64
  99: 69
timings:
  load_rails: 119842
ruby-version: 2.2.0-p6
rss_kb: 152636
pss_kb: 148004
physicalprocessorcount: 1
architecture: amd64
virtual: physical
operatingsystem: Ubuntu
processor0: Intel(R) Core(TM) i7-4700HQ CPU @ 2.40GHz
memorysize: 15.59 GB
kernelversion: 3.13.0

guoxiang-GS60-2PC-Ghost pid:16316 ruby /home/guoxiang/ rbenv/versions/ruby 2 2   without rgengc/bin/thin start  p 6  79

GC STATS:
count: 27376
heap_allocated_pages: 1200
heap_sorted_length: 1200
heap_allocatable_pages: 19
heap_available_slots: 489119
heap_live_slots: 445433
heap_free_slots: 43686
heap_final_slots: 0
heap_marked_slots: 9404313083
heap_swept_slots: 43728
heap_eden_pages: 1181
heap_tomb_pages: 19
total_allocated_pages: 1200
total_freed_pages: 0
total_allocated_objects: 210243633
total_freed_objects: 209798200
malloc_increase_bytes: 5600
malloc_increase_bytes_limit: 16777216

Objects:
TOTAL: 489119
T_STRING: 210589
T_ARRAY: 63099
T_DATA: 61522
FREE: 43594
T_NODE: 38334
T_HASH: 25384
T_OBJECT: 21873
T_CLASS: 11530
T_REGEXP: 3504
T_ICLASS: 3336
T_SYMBOL: 3192
T_MODULE: 1651
T_RATIONAL: 891
T_STRUCT: 580
T_MATCH: 14
T_FLOAT: 11
T_BIGNUM: 9
T_FILE: 5
T_COMPLEX: 1

Process Info:
Name:	ruby
State:	S (sleeping)
Tgid:	16316
Ngid:	0
Pid:	16316
PPid:	15458
TracerPid:	0
Uid:	1000	1000	1000	1000
Gid:	1000	1000	1000	1000
FDSize:	64
Groups:	4 24 27 30 46 108 124 1000 
VmPeak:	  626872 kB
VmSize:	  626652 kB
VmLck:	       0 kB
VmPin:	       0 kB
VmHWM:	  152476 kB
VmRSS:	  152456 kB
VmData:	  411512 kB
VmStk:	     140 kB
VmExe:	    2896 kB
VmLib:	   25588 kB
VmPTE:	     724 kB
VmSwap:	       0 kB
Threads:	6
SigQ:	0/127276
SigPnd:	0000000000000000
ShdPnd:	0000000000000000
SigBlk:	0000000000000000
SigIgn:	0000000000001000
SigCgt:	0000000182006e4f
CapInh:	0000000000000000
CapPrm:	0000000000000000
CapEff:	0000000000000000
CapBnd:	0000001fffffffff
Seccomp:	0
Cpus_allowed:	ff
Cpus_allowed_list:	0-7
Mems_allowed:	00000000,00000001
Mems_allowed_list:	0
voluntary_ctxt_switches:	228016
nonvoluntary_ctxt_switches:	173263


Classes:
Class report omitted use ?full=1 to include it

ruby 2.2.0p6 (2015-01-03 revision 49125) [x86_64-linux] (USE_RINCGC = 0)

Your Results: (note for timings- percentile is first, duration is second in millisecs)
---
categories_admin:
  50: 87
  75: 91
  90: 96
  99: 153
home_admin:
  50: 76
  75: 78
  90: 84
  99: 94
topic_admin:
  50: 40
  75: 42
  90: 45
  99: 53
categories:
  50: 72
  75: 76
  90: 83
  99: 143
home:
  50: 50
  75: 52
  90: 56
  99: 66
topic:
  50: 18
  75: 18
  90: 19
  99: 28
timings:
  load_rails: 2594
ruby-version: 2.2.0-p6
rss_kb: 218848
pss_kb: 214186
physicalprocessorcount: 1
architecture: amd64
virtual: physical
operatingsystem: Ubuntu
processor0: Intel(R) Core(TM) i7-4700HQ CPU @ 2.40GHz
memorysize: 15.59 GB
kernelversion: 3.13.0

guoxiang-GS60-2PC-Ghost pid:23052 ruby /home/guoxiang/ rbenv/versions/ruby 2 2   without rincgc/bin/thin start  p 6  79

GC STATS:
count: 561
heap_allocated_pages: 2417
heap_sorted_length: 2457
heap_allocatable_pages: 184
heap_available_slots: 985184
heap_live_slots: 446556
heap_free_slots: 538628
heap_final_slots: 0
heap_marked_slots: 446509
heap_swept_slots: 538674
heap_eden_pages: 2233
heap_tomb_pages: 184
total_allocated_pages: 2417
total_freed_pages: 0
total_allocated_objects: 210177794
total_freed_objects: 209731238
malloc_increase_bytes: 6992
malloc_increase_bytes_limit: 21664727
minor_gc_count: 514
major_gc_count: 47
remembered_wb_unprotected_objects: 11558
remembered_wb_unprotected_objects_limit: 23116
old_objects: 420587
old_objects_limit: 841174
oldmalloc_increase_bytes: 7440
oldmalloc_increase_bytes_limit: 24558447

Objects:
TOTAL: 985184
FREE: 538496
T_STRING: 211395
T_ARRAY: 62384
T_DATA: 61547
T_NODE: 38356
T_HASH: 26210
T_OBJECT: 22055
T_CLASS: 11532
T_REGEXP: 3506
T_ICLASS: 3336
T_SYMBOL: 3200
T_MODULE: 1651
T_RATIONAL: 891
T_STRUCT: 586
T_MATCH: 13
T_FLOAT: 11
T_BIGNUM: 9
T_FILE: 5
T_COMPLEX: 1

Process Info:
Name:	ruby
State:	R (running)
Tgid:	23052
Ngid:	0
Pid:	23052
PPid:	22506
TracerPid:	0
Uid:	1000	1000	1000	1000
Gid:	1000	1000	1000	1000
FDSize:	64
Groups:	4 24 27 30 46 108 124 1000 
VmPeak:	  694212 kB
VmSize:	  692588 kB
VmLck:	       0 kB
VmPin:	       0 kB
VmHWM:	  219796 kB
VmRSS:	  218284 kB
VmData:	  477452 kB
VmStk:	     140 kB
VmExe:	    2892 kB
VmLib:	   25584 kB
VmPTE:	     848 kB
VmSwap:	       0 kB
Threads:	6
SigQ:	0/127276
SigPnd:	0000000000000000
ShdPnd:	0000000000000000
SigBlk:	0000000000000000
SigIgn:	0000000000001000
SigCgt:	0000000182006e4f
CapInh:	0000000000000000
CapPrm:	0000000000000000
CapEff:	0000000000000000
CapBnd:	0000001fffffffff
Seccomp:	0
Cpus_allowed:	ff
Cpus_allowed_list:	0-7
Mems_allowed:	00000000,00000001
Mems_allowed_list:	0
voluntary_ctxt_switches:	222997
nonvoluntary_ctxt_switches:	59624


Classes:
Class report omitted use ?full=1 to include it

bm_vm3.rb Benchmarks

Ruby 2.1.5

raw data:

[["vm3_gc",
  [[1.781873639,
    1.783857101,
    1.785210547,
    1.765383432,
    1.782443273,
    1.772300559,
    1.781810876,
    1.775731151,
    1.790814346,
    1.779261756]]]]

Elapsed time: 17.801257535 (sec)
-----------------------------------------------------------
benchmark results:
minimum results in each 10 measurements.
Execution time (sec)
name	ruby 2.1.5p273 (2014-11-13 revision 48405) [x86_64-linux]
Posting results to Web UI....
vm3_gc	1.765

Ruby 2.2

raw data:

[["vm3_gc",
  [[2.3463893930002087,
    2.3218893540001773,
    2.3346126609999374,
    2.325292480999906,
    2.3357411790002516,
    2.331829299000219,
    2.3262738720000016,
    2.3313931529996808,
    2.3262657880000006,
    2.3227735149998807]]]]

Elapsed time: 23.304931506 (sec)
-----------------------------------------------------------
benchmark results:
minimum results in each 10 measurements.
Execution time (sec)
name	ruby 2.2.0p6 (2015-01-03 revision 49125) [x86_64-linux]
Posting results to Web UI....
vm3_gc	2.322

USE_RGENGC = 0

raw data:

[["vm3_gc",
  [[1.5703227599997263,
    1.5682877579997694,
    1.6116582240001662,
    1.5651109710001947,
    1.552847889000077,
    1.550723786999697,
    1.5628306730000077,
    1.5581518529997993,
    1.561870511000052,
    1.5770128940002905]]]]

Elapsed time: 15.682895972 (sec)
-----------------------------------------------------------
benchmark results:
minimum results in each 10 measurements.
Execution time (sec)
name	ruby 2.2.0p6 (2015-01-03 revision 49125) [x86_64-linux]
Posting results to Web UI....
vm3_gc	1.551

USE_RINCGC = 0

raw data:

[["vm3_gc",
  [[2.095197224000003,
    2.0840697899998304,
    2.1194490730003963,
    2.091287412999918,
    2.0882632130001184,
    2.0964824409998073,
    2.08875445700005,
    2.0652376550001463,
    2.072298475000025,
    2.108764761999737]]]]

Elapsed time: 20.911727736 (sec)
-----------------------------------------------------------
benchmark results:
minimum results in each 10 measurements.
Execution time (sec)
name	ruby 2.2.0p6 (2015-01-03 revision 49125) [x86_64-linux]
Posting results to Web UI....
vm3_gc	2.065

#2

@sam I did the runs with RGENGC and RINCGC disabled. Ruby compiled with RGENGC disabled was not usable for me, the benchmark took extremely long to run. The notable difference is with the 99th percentile where both RGENGC and RINCGC yielded better results.

RubyBench - Long Running Ruby Benchmark. Although the percentage shown is -9% slower for Ruby 2.2.0, the actual data is only 3 milliseconds higher for Ruby 2.2.0. Is it really a significant difference?