Object lifetime analysis
with Ruby 2.1
Koichi Sasada<ko1@heroku.inc>

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

1

Who am I ?
• Koichi Sasada a.k.a. ko1• From Japan• 笹田 (family name) 耕一 (givenname) in Kanji character

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

2

Who am I ?
• CRuby/MRI committer• Virtual machine (YARV) from Ruby 1.9• YARV development since 2004/1/1• Recently, improving GC performance• Matz team at Heroku, Inc.
• Full-time CRuby developer• Working in Japan• Director of Ruby Association
Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

3

Advertisement• Foundation to encourage Ruby dev. and communities• Chairman is Matz, Located at Matsue-city, Shimane, Japan• Activities• Ruby programmer certification program• http://www.ruby.or.jp/en/certification/examination/ in English• Maintenance of Ruby (Cruby) interpreter• Now, it is for Ruby 1.9.3• Ruby 2.0.0 in the future?

• Events, especially RubyWorld Conference• Ruby Prize• Grant project. We have selected 3 proposals in 2013
• Win32Utils Support, Conductor, Smalruby - smalruby-editor• We will make this grant 2014!!

• Donation for Ruby developments and communities
Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

4

Advertisement• Heroku, Inc. http://www.heroku.com
You should know about Heroku!!

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

5

Advertisement

This presentation is supported by

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

6

Advertisement• Heroku, Inc. http://www.heroku.com• Heroku supports OSSs / Ruby development• Many talents for Ruby, and also other languages• Heroku employs 3 Ruby interpreter coredevelopers• Matz• Nobu• Ko1 (me)• We name our group “Matz team”
Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

7

Matz team in Heroku
in JapanNobu @ Tochigi
Patch monster

Matz @ Shimane
Title collector

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

ko1 @ Tokyo8
EDD developer

Mission of Matz team
• Improve quality of next version of CRuby• Matz decides a spec finally• Nobu fixed huge number of bugs
• Ko1 improves the performance

Current target is Ruby 2.2!!
Now, Ruby 2.1 is old version for us.
Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

9

Ruby 2.1
Current stable
http://www.flickr.com/photos/loginesta/5266114104

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

10

Ruby 2.1
• Ruby 2.1.0 was released at 2013/12/25• New features• Performance improvements• Ruby 2.1.1 was released at 2014/02/24• Includes many bug fixes found after 2.1.0 release• Introduce a new GC tuning parameter to change
generational GC behavior (introduce it later)

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

11

Ruby 2.1 the biggest change
Version policy• Change the versioning policy• Drop “patch level” in the version• Teeny represents patch level• Release new teeny versions about every 3 month• Teeny upgrades keep compatibility• Minor upgrades can break backward compatibility• We make an effort to keep compatibility(recently. Remember Ruby 1.9 )

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

12

Ruby 2.1 New syntax• New syntaxes• Required keyword
parameter• Rational number literal• Complex number literal• `def’ returns symbol ofmethod namehttp://www.flickr.com/photos/rooreynolds/4133549889

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

13

Ruby 2.1 Runtime new features• String#scrub• Process.clock_gettime• Binding#local_variable_get/set• Bignum now uses GMP (if available)• Extending ObjectSpace

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

14

Performance improvements• Optimize “string literal”.freeze• Sophisticated inline method cache• Introducing Generational GC: RGenGC

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

15

Accumulated execution time (sec)

RGenGC
Performance evaluation (RDoc)
14
12
10
8
6

About x15 speedup!

4
20
Total mark time (ms)w/o RGenGC

Total sweep time (sec)
RGenGC* Disabled lazy sweep to measure correctly.

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

16

RGenGC
Performance evaluation (RDoc)
Total execution time (sec)

140
120

16.04393815
4.946003494

100
80
60
40

103.7627479

102.3799865

w/o RGenGC

RGenGC20

0other than GC

GC* 12% improvements compare with w/ and w/o RGenGC
Object lifetime analysis with Ruby 2.1,
* Disabledlazy sweep
to measurecorrectly.
RubyConf.tw
2014, K.Sasada
from Heroku,
Inc.

17

Ruby 2.2
Next version
http://www.flickr.com/photos/adafruit/8483990604

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

18

Schedule of Ruby 2.2• Not published officially• Schedule draft is available by Naruse-san• https://bugs.ruby-lang.org/projects/rubytrunk/wiki/ReleaseEngineering22

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

19

Ruby 2.2 schedule
2013/12Ruby 2.1.0

Rubyconf.PH
3/28, 29

2014/12/25

We arehere!

Ruby 2.2.0

RDRC
6/26, 27
Rubyconf.tw
4/25, 26

RubyKaigi
9/18, 19, 20

RubyConf
11/17, 18, 19

Events are important for
EDD (Event Driven Development) Developers
Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

20

Ruby 2.2 (rough) schedule
2013/12Ruby 2.1.0

We arehere!

2014/12/25
Ruby 2.2.0

Sep/2014
Preview 1
Big feature freeze

Bug fix only

Nov/2014
Preview2
Feature freeze

Critical Bug fix only

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

Dec/2014
Releasecandidate21

2.2 big features (planned)• New syntax: not available now• New method: not available now• Internal• GC• Symbol GC (merged recently)• 2age promotion strategy for RGenGC• Incremental GC to reduce major GC pause time

• VM
• More sophisticated method cache
Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

22

Symbol GC• Symbols remain forever → Security issue• “n.times{|i| i.to_s.to_sym}”
creates “n” symbols and they are never collected• Symbol GC: Collect dynamically created symbols

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

23

Object lifetime
Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

24

Ruby’s object/memory
management• “Object.new” allocate a new object• “foo” (string literal) also allocate a new object• Everything are objects in Ruby!

• We don’t need to “de-allocate” objects manually

Why we don’t need to clean up objects?

Memory management tuning in Ruby,
RubyConfPH 2014 by K.Sasada<ko1@heroku.com>

25

Garbage collection
The automatic memory management

http://www.flickr.com/photos/circasassy/6817999189/

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

26

Garbage collection
The automatic memory management

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

27

Garbage collection
The automatic memory management

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

28

Object lifetime• Human’s lifetime

BirthLifetime

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

Death

29

Object lifetime# Object creation
obj = Object.new# Collected by GC# when nobody refers it

Birth

Death

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

30

Object lifetime
Age at the dying
GC GC GC
→ Lifetime
Birth

Death
GC surviving count→ Age
Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

31

Why lifetime is important?
• Old objects slow down major (full) GC• RGenGC have reduced GC overhead comes fromold objects• However, major (full) GC needs a time

• Long life (old) objects can be unexpected
memory leak

Reducing old objects makes
Ruby program faster 
Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

32

Questions• How to measure object lifetime?
• How to find old objects?

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

33

Allocation tracer gem
Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

34

Allocation tracer• Trace object allocations• Two features
1. Show statistics data by line
2. Show lifetime statistics table• Using newobj/freeobj internal hooks
introduced from Ruby 2.1.0.
• So that this gem only supports Ruby 2.1
and later
Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

35

Allocation Tracer(1) Show statistics data by line
• Show statistics data by each lines• Collect following data
• Allocation count• Old object count• Total object lifetime (average lifetime by dividing
allocation count)• Min/Max lifetime• Total amount of memory usage (average memory usage
by dividing allocation count)Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

36

Allocation Tracer(1) Show statistics data by line
Demo

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

37

Allocation Tracer(2) Object lifetime statistics• Show object lifetime statistics table for each type
Age
0
1
2
T_OBJECT
7534
435532
T_CLASS
090
T_STRING
116307 17706739
T_REGEXP
041192
T_ARRAY
32874 4490228
T_HASH
872
89158
T_STRUCT
1
8507
T_FILE
19330
T_DATA
8510
578913
T_MATCH
7829992
T_RATION
02
AL
T_NODE
9333
649080
T_ICLASS
090
T_MODUL
00E
T_FLOAT
0
0

3

4

5

6

7

8

9

10

6695
1
24244
1
5878
113
247
5
146
52

12916
0
97981
0
9262
323
197
2
69
0

2841
0
9461
0
4863
90
62
1
96
0

2298
0
5470
0
2567
85
55
1
53
0

2570
0
4825
0
2485
93
59
0
77
0

4222
0
7243
0
5697
138
9
0
54
0

3256
4
6533
0
3752
161
42
0
65
0

2659
5
5581
3
3033
101
67
0
90
0

4839
1
15826
0
5672
183
127
0
62
0

0

0

0

0

0

0

0

0

0

19438
1

4948
0

2665
0

7
0

17
0

5
0

9
0

26
1

135
1

0

0

0

0

0

0

0

0

0

0

0

0

0

0

0

0

0

0

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

38

Allocation Tracer(2) Object lifetime statistics• Show object lifetime table for each type20000000
18000000
14000000
12000000
10000000
8000000

6000000
4000000
2000000
0

1
5
9
13
17
21
25
29
33
37
41
45
49
53
57
61
65
69
73
77
81
85
89
93
97
101
105
109
113
117
121
125
129
133
137
141
145
149
153
157
161
165
169
173
177
181
185
189

Object count16000000

Object lifetime
T_OBJECT

T_CLASS

T_STRING

T_REGEXP

T_ARRAY

T_HASH

T_STRUCT

T_DATA

T_MATCH

T_RATIONAL

T_NODE

T_ICLASS

T_MODULE

T_FLOAT

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

T_FILE

39

Allocation Tracer(2) Object lifetime statistics• Show object lifetime table for each typeAge/percentage

1.2

0.8
0.6
0.4
0.2
0

1
5
9
13
17
21
25
29
33
37
41
45
49
53
57
61
65
69
73
77
81
85
89
93
97
101
105
109
113
117
121
125
129
133
137
141
145
149
153
157
161
165
169
173
177
181
185
189

Percentage of objects

1

Object lifetime
T_OBJECT

T_CLASS

T_STRING

T_REGEXP

T_ARRAY

T_HASH

T_STRUCT

T_DATA

T_MATCH

T_RATIONAL

T_NODE

T_ICLASS

T_MODULE

T_FLOAT

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

T_FILE40

Allocation Tracer(2) Object lifetime statistics
T_RATIONAL
T_REGEXP
T_HASH
T_MODULE
T_STRUCTT_ICLASS
T_FLOATT_CLASS
T_FILE
T_NODET_DATA
1%
0%
0%
0%
2%
T_MATCH 3%
3%
T_OBJECT
4%

T_ARRAY
18%

T_STRING
69%

Most of allocated objects are String
Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

41

Allocation Tracer demo(2) Object lifetime statistics
T_STRING

Most of String die at first GC

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

42

Allocation Tracer example• Using “by line” statistics on RDoc program

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

43

Allocation Tracer example
path

line

count

total_memsize/home/ko1/src/ruby/trunk/lib/rdoc/markup/pa
rser.rb

327

128,097 498,086,366/home/ko1/src/ruby/trunk/lib/rdoc/parser/c.rb

644

3,132 111,437,037/home/ko1/src/ruby/trunk/lib/time.rb

325

1,146,900 85,714,539/home/ko1/src/ruby/trunk/lib/rdoc/token_stre
am.rb

59

1,267,168 81,137,600/home/ko1/src/ruby/trunk/lib/rdoc/store.rb

892

23,038 65,504,272

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

44

lib/rdoc/markup/parser.rb:327@input.byteslice(0, byte_offset).length• @input is String• @input.byteslice(0, byte_offset) makes new String• Return only length of sliced string→ Created string object is completely temporary

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

45

lib/rdoc/markup/parser.rb:327
Introduce String#byteslice_length@input.byteslice_length(0, byte_offset)• No temporary String object

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

46

After introducing new method…
path
line counttotal_memsize/home/ko1/src/ruby/trunk/lib/rdoc
644
4,369
93,019,334/parser/c.rb/home/ko1/src/ruby/trunk/lib/rdoc
59
1,386,966
88,834,304/token_stream.rb/home/ko1/src/ruby/trunk/lib/time.
325
1,137,612
84,959,225
rb/home/ko1/src/ruby/trunk/lib/rdoc
162
944,833
60,724,300/ruby_lex.rb

And total consuming memory reduced fromabout 140MB to 120MB
Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

47

Another GC tip
GC Tracer
Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

48

gc_tracer gem• Helper gem to analyze GC behavior for tuning

http://www.flickr.com/photos/nasa_goddard/5188180370
Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

49

How to use tuning parameters?
1. Profile your application
2. Try GC parameters (environment variables)

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

50

Profile memory management
GC.stat (MRI specific)• “GC.stat” returns statistics information about GC• Counts• :count=>2,• :minor_gc_count=>2,• :major_gc_count=>0,# GC count# minor GC count# major GC count• Current slot information• :heap_live_slot=>6836, #=> # of live objects• :heap_free_slot=>519, #=> # of freed objects• :heap_final_slot=>0, #=> # of waiting finalizer objects• total_slots = heap_live_slot + heap_free_slot + heap_final_slot• Statistics• :total_allocated_object=>7674,• :total_freed_object=>838,# total allocated objects# total freed objects• Current living objects = total_allocated_object - total_freed_object
Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

51

Profile memory management
GC.latest_gc_info (MRI specific)• “GC.latest_gc_info” returns details of latest GC• :gc_by=>:newobj# why GC invoked?

• newobj: no slots available• malloc: malloc_increase > malloc_limit• :major_by=>nil• :have_finalizer=>false• :immediate_sweep=>false# why major GC invoked?
# have finalizer?
# immediate sweep?

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

52

Profile memory management“gc_tracer” gem (MRI 2.1.0 later!!)• GC::Tracer.start_logging(filename)• Save all GC.stat/GC.latest_gc_info results at every GC events
into specified file
• GC events:• Start• End marking• End sweeping
GC startMark

GC end sweeping
Sweep

Sweep

GC end marking

GC startMark

GC end sweeping
Sweep

Sweep

GC end marking

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

53

Profile memory management“gc_tracer” gem• Run your application with gc_tracer• Plot with Excel!

http://www.flickr.com/photos/microsoftsweden/5394685465
Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

54

120
100
80
60
40
20
0

1
7
13
19
25
31
37
43
49
55
61
67
73
79
85
91
97
103
109
115
121
127
133
139
145
151
157
163
169
175
181
187
193
199
205
211
217
223
229
235
241
247
253
259
265
271
277

Profile memory management“gc_tracer” gemminor_gc_countmajor_gc_countObject lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

55

Profile memory management“gc_tracer” gem
40,000,000

35,000,000

30,000,000

25,000,000

20,000,000

15,000,000

10,000,000

5,000,000

1
7
13
19
25
31
37
43
49
55
61
67
73
79
85
91
97
103
109
115
121
127
133
139
145
151
157
163
169
175
181
187
193
199
205
211
217
223
229
235
241
247
253
259
265
271
277

0

total_allocated_object

total_freed_object

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

56

Profile memory management“gc_tracer” gem
1,000,000
900,000
800,000
700,000
600,000
500,000
400,000
300,000
200,000
100,000

1
7
13
19
25
31
37
43
49
55
61
67
73
79
85
91
97
103
109
115
121
127
133
139
145
151
157
163
169
175
181
187
193
199
205
211
217
223
229
235
241
247
253
259
265
271
277

0

total_slots

heap_swept_slot

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

57

Profile memory management“gc_tracer” gemruby 2.2 dev/RUBY_GC_HEAP_OLDOBJECT_FACTOR=2.0 (default)
1600000
1400000
1200000
1000000
800000600000400000200000

1
7
13
19
25
31
37
43
49
55
61
67
73
79
85
91
97
103
109
115
121
127
133
139
145
151
157
163
169
175
181
187
193
199
205
211
217
223
229
235
241
247
253
259
265

0

total_slots

old_object

old_object_limit

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

58

Profile memory management“gc_tracer” gem
Ruby 2.2dev w/ RUBY_GC_HEAP_OLDOBJECT_FACTOR=1.3
1000000
900000800000700000600000500000400000300000200000100000

1
7
13
19
25
31
37
43
49
55
61
67
73
79
85
91
97
103
109
115
121
127
133
139
145
151
157
163
169
175
181
187
193
199
205
211
217
223
229
235
241
247
253
259
265
271
277

0

total_slots

old_object

old_object_limit

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

59

For more information

Please refer my slide at
RubyConf PH 2014

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

60

Summary of this talk
• Ruby 2.1 was released and 2.2 will be released this year
• Object lifetime analysis is important for program tuning• Allocation Tracer gem helps how applications allocate
objects• Another GC Tips
• GC Tracer gem helps GC behavior analysis for GC tuning

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

61

Thank you for your attention
Q&A?
Koichi Sasada<ko1@heroku.com>

Object lifetime analysis with Ruby 2.1,
RubyConf.tw 2014, K.Sasada from Heroku, Inc.

62