Real Time Salami - Speaker Deck

Slide 1

Slide 1 text

Ingredients ❤ Pork ❤ Salt, nitrate, nitrite ❤ Dextose, Sugar ❤ White Pepper, Black Pepper ❤ Garlic, Fennel ❤ Chianti

Slide 2

Slide 2 text

Aaron Patterson @tenderlove

Slide 3

Slide 3 text

Aaron Patterson @tenderlove NO TIME

Slide 4

Slide 4 text

AT&T, AT&T logo and all AT&T related marks are trademarks of AT&T Intellectual Property and/or AT&T affiliated companies.

Slide 5

Slide 5 text

AT&T, AT&T logo and all AT&T related marks are trademarks of AT&T Intellectual Property and/or AT&T affiliated companies. NO TIME

Slide 6

Slide 6 text

WWFMD

Slide 7

Slide 7 text

WWFMD NO TIME

Slide 8

Slide 8 text

No content

Slide 9

Slide 9 text

ALWAYS IME

Slide 10

Slide 10 text

Gorbachev Puff-Puff Thunderhorse

Slide 11

Slide 11 text

No content

Slide 12

Slide 12 text

No content

Slide 13

Slide 13 text

No content

Slide 14

Slide 14 text

No content

Slide 15

Slide 15 text

No content

Slide 16

Slide 16 text

No content

Slide 17

Slide 17 text

@gorbypuff

Slide 18

Slide 18 text

No content

Slide 19

Slide 19 text

No content

Slide 20

Slide 20 text

FOOD STUFF WORK STUFF HACKER STUFF

Slide 21

Slide 21 text

FOOD STUFF

Slide 22

Slide 22 text

Meat Curing Fermented Sausages

Slide 23

Slide 23 text

Botulism

Slide 24

Slide 24 text

Great Robot Uprising of 1863

Slide 25

Slide 25 text

PSA: Use Metric no, seriously

Slide 26

Slide 26 text

Hardware

Slide 27

Slide 27 text

Wine Fridge

Slide 28

Slide 28 text

Temp Controller 20ºF - 80ºF

Slide 29

Slide 29 text

Ionizing Humidiﬁer

Slide 30

Slide 30 text

Humidity Controller

Slide 31

Slide 31 text

Fans

Slide 32

Slide 32 text

Grinding

Slide 33

Slide 33 text

Stufﬁng

Slide 34

Slide 34 text

Ingredients

Slide 35

Slide 35 text

Meat (80%) Pork Shoulder

Slide 36

Slide 36 text

Fat (20%) Pork back fat

Slide 37

Slide 37 text

Sugar (0.5%) Dextrose (glucose) and Sucrose

Slide 38

Slide 38 text

Salt (3%) NaCL + Nitrate + Nitrite

Slide 39

Slide 39 text

Pink Salt (Cure #2)

Slide 40

Slide 40 text

Nitrates release Nitrites

Slide 41

Slide 41 text

Nitrites prevent Botulism

Slide 42

Slide 42 text

Nitrites change the meat color.

Slide 43

Slide 43 text

0hrs 24hrs

Slide 44

Slide 44 text

Bacteria (0.012%) Bactoferm T-SPX (Pediococcus pentosaceus & Staphylococcus xylosus) 30 DAYS

Slide 45

Slide 45 text

Bactoferm F-RM-52 (Lactobacillus sakei & Staphylococcus carnosus) 7 DAYS

Slide 46

Slide 46 text

Spices

Slide 47

Slide 47 text

Curing Environment

Slide 48

Slide 48 text

Windspeed

Slide 49

Slide 49 text

Temperature 50 55 60 65 70 Day 1 Day 2 Day 3 Day 4 Day 5 Day 6 Day 7 Temperature (F)

Slide 50

Slide 50 text

Wine Fridge 55ºF - 65ºF

Slide 51

Slide 51 text

Hack Your Fridge

Slide 52

Slide 52 text

Humidity 0 22.5 45 67.5 90 Day 1 Day 2 Day 3 Day 4 Day 5 Day 6 Day 7 Relative Humidity

Slide 53

Slide 53 text

Humidity Controller

Slide 54

Slide 54 text

Humidity Controller

Slide 55

Slide 55 text

Humidity Feed

Slide 56

Slide 56 text

Addiction

Slide 57

Slide 57 text

Safety

Slide 58

Slide 58 text

Salt

Slide 59

Slide 59 text

Nitrite Prevents Botulism

Slide 60

Slide 60 text

22 mg / kg lethal dose

Slide 61

Slide 61 text

Pink Salt for safety

Slide 62

Slide 62 text

Acid

Slide 63

Slide 63 text

4 4.75 5.5 6.25 7 Day 1 Day 2 Day 3 Day 4 Day 5 Day 6 Day 7 pH pH (0.3% sugar)

Slide 64

Slide 64 text

pH Meter

Slide 65

Slide 65 text

Water ~45% weight loss (30% minimum)

Slide 66

Slide 66 text

Salt Nitrite Acid Water Activity Short Medium Long

Slide 67

Slide 67 text

Molds

Slide 68

Slide 68 text

WORK STUFF

Slide 69

Slide 69 text

Streaming Fermented Sausages

Slide 70

Slide 70 text

Template Rendering Today

Slide 71

Slide 71 text

Templates Results are Buffered

Slide 72

Slide 72 text

Clients are blocked while Rails works

Slide 73

Slide 73 text

The entire page must ﬁt in memory

Slide 74

Slide 74 text

We can do I/O and CPU in parallel.

Slide 75

Slide 75 text

So why buffer?

Slide 76

Slide 76 text

ActionController::Live

Slide 77

Slide 77 text

Example class BrowserController < ApplicationController include ActionController::Live def index 100.times do response.stream.write "hello!\n" end response.stream.close end end

Slide 78

Slide 78 text

Example class BrowserController < ApplicationController include ActionController::Live def index 100.times do response.stream.write "hello!\n" end response.stream.close end end Mix in Stream

Slide 79

Slide 79 text

response.stream acts like an I/O object

Slide 80

Slide 80 text

Everything Is a File

Slide 81

Slide 81 text

How does it work?

Slide 82

Slide 82 text

Our API def index response.status = 200 response.headers[‘X-Whatever’] = ‘<3’ response.stream.write ‘hello’ response.stream.write ‘ world’ response.stream.close end

Slide 83

Slide 83 text

Rack API def call(env) return [200, {‘X-Whatever’ => ‘<3’}, [‘hello world’]] end

Slide 84

Slide 84 text

Wrapped Response class Response attr_accessor :status attr_reader :headers, :stream def initialize @status = 200 @headers = {} @stream = StringIO.new end end def call(env) res = Response.new controller.response = res controller.index [res.status, res.headers, res.stream] end

Slide 85

Slide 85 text

Threaded action def call(env) res = Response.new controller.response = res Thread.new { controller.index } [res.status, res.headers, res.stream] end

Slide 86

Slide 86 text

Block until write def call(env) res = Response.new controller.response = res Thread.new { controller.index } res.stream.await [res.status, res.headers, res.stream] end

Slide 87

Slide 87 text

Block until write def call(env) res = Response.new controller.response = res Thread.new { controller.index } res.stream.await [res.status, res.headers, res.stream] end Block

Slide 88

Slide 88 text

Blocking Buffer class Buffer def initialize @latch = Latch.new @buffer = Queue.new end def await # wait for write @latch.await end def write(str) @latch.release @buffer << str end end

Slide 89

Slide 89 text

Blocking Buffer class Buffer def initialize @latch = Latch.new @buffer = Queue.new end def await # wait for write @latch.await end def write(str) @latch.release @buffer << str end end `call` blocks here

Slide 90

Slide 90 text

Slide 91

Slide 91 text

What can we do?

Slide 92

Slide 92 text

Rails Internals

Slide 93

Slide 93 text

Streaming ERB

Slide 94

Slide 94 text

View Source # encoding: utf-8 require 'erb' doc = ERB.new '<%= hello %> world' puts doc.src

Slide 95

Slide 95 text

Source #coding:UTF-8 _erbout = ''; _erbout.concat(( hello ).to_s); _erbout.concat " world"; _erbout.force_encoding(__ENCODING__)

Slide 96

Slide 96 text

Control Output class MyERB < ERB def set_eoutvar(compiler, eoutvar = '_erbout') compiler.put_cmd = "#{eoutvar}.write" compiler.insert_cmd = "#{eoutvar}.write" compiler.pre_cmd = [] compiler.post_cmd = [] end end doc = MyERB.new '<%= hello %> world', nil, nil, '$stdout' puts doc.src

Slide 97

Slide 97 text

Source #coding:UTF-8 $stdout.write(( hello ).to_s); $stdout.write " world"

Slide 98

Slide 98 text

$ ruby test.rb hello world $

Slide 99

Slide 99 text

Choose streaming or buffering.

Slide 100

Slide 100 text

Web Apps

Slide 101

Slide 101 text

Inﬁnite Streams

Slide 102

Slide 102 text

Server Sent Events

Slide 103

Slide 103 text

SSE Response HTTP/1.1 200 OK X-Frame-Options: SAMEORIGIN X-XSS-Protection: 1; mode=block X-Content-Type-Options: nosniff Content-Type: text/event-stream Transfer-Encoding: chunked event: ping data: {"ping":"2012-10-06T21:44:41-07:00"} event: reload data: {"changed":["/Users/aaron/git/lolwut/app/views/ users/"]}

Slide 104

Slide 104 text

Slide 105

Slide 105 text

Slide 106

Slide 106 text

Slide 107

Slide 107 text

Client Side jQuery(document).ready(function() { setTimeout(function() { var source = new EventSource('/control'); // if we get a reload command, reload the page source.addEventListener('reload', function(e) { window.location.reload(); }); }, 1); });

Slide 108

Slide 108 text

Slide 109

Slide 109 text

Slide 110

Slide 110 text

Slide 111

Slide 111 text

Real-Time Browser Communication

Slide 112

Slide 112 text

No content

Slide 113

Slide 113 text

Puma Browser FS-Events FS Events

Slide 114

Slide 114 text

Puma Browser FS-Events FS Events

Slide 115

Slide 115 text

Puma Browser Console DRB DB Events

Slide 116

Slide 116 text

Puma Browser Console DRB DB Events Socket

Slide 117

Slide 117 text

Real-Time Salami

Slide 118

Slide 118 text

No content

Slide 119

Slide 119 text

Data Broadcasting

Slide 120

Slide 120 text

Thread Thread Thread Observer Browser Salami Browser Observer

Slide 121

Slide 121 text

Thread Thread Thread Observer Browser Salami Browser Observer create index index

Slide 122

Slide 122 text

Message Bus class Bus include Observable def publish data changed notify_observers data end def add_observer &block o = Class.new { define_method(:update) { |data| block.call data } }.new super(o) end end

Slide 123

Slide 123 text

Subscriber BUS = Bus.new def index queue = Queue.new BUS.add_observer { |data| queue << data } # .. end

Slide 124

Slide 124 text

Emit SSE def index queue = Queue.new observer = BUS.add_observer { |data| queue << data } begin while data = queue.pop begin io.write data, :event => 'measurement' rescue IOError queue.push nil io.close end end ensure BUS.delete_observer observer end end

Slide 125

Slide 125 text

Publisher def create sig, data = params['_json'] BUS.publish({ :now => Time.now, :data => JSON.load(data.unpack('m').first) }) render :nothing => true end

Slide 126

Slide 126 text

Feedback

Slide 127

Slide 127 text

GChart + SSE var source = new EventSource('/measurements.json'); var chart = document.getElementById('chart'); source.addEventListener('measurement', function(e) { var payload = JSON.parse(e.data); var data = payload.data; if(chart && table) { var count = table.getNumberOfRows(); table.addRow(['', data[0], data[1]]); if(count > 60) { table.removeRow(0); } gchart.draw(table, options(data.interface)); } }, false);

Slide 128

Slide 128 text

No content

Slide 129

Slide 129 text

HACKER STUFF

Slide 130

Slide 130 text

Ruby VM

Slide 131

Slide 131 text

Stack Based

Slide 132

Slide 132 text

No content

Slide 133

Slide 133 text

Ghostscript GS>2 GS<1>3 GS<2>add GS<1>stack 5 GS<1>pop GS> [] [2] [2, 3] [5] [5] [] Instructions Stack

Slide 134

Slide 134 text

In Ruby

Slide 135

Slide 135 text

Compile is = RubyVM::InstructionSequence.new '2 + 3'

Slide 136

Slide 136 text

Disassemble is = RubyVM::InstructionSequence.new '2 + 3' puts is.disasm

Slide 137

Slide 137 text

Instructions 0000 trace 1 0002 putobject 2 0004 putobject 3 0006 opt_plus 0008 leave

Slide 138

Slide 138 text

Instructions 0000 trace 1 0002 putobject 2 0004 putobject 3 0006 opt_plus 0008 leave Instruction names Parameters

Slide 139

Slide 139 text

What does it mean?

Slide 140

Slide 140 text

insns.def

Slide 141

Slide 141 text

trace - trace (set_trace_func) putobject - push object on the stack opt_plus - optimized X + Y leave - return from this scope

Slide 142

Slide 142 text

Slight Detour

Slide 143

Slide 143 text

Ruby -> GS /trace { pop } def /putobject { } def /opt_plus { add } def /leave { } def

Slide 144

Slide 144 text

Ruby on GS GS>1 trace GS>1 putobject GS<1>2 putobject GS<2>opt_plus GS<1>leave GS<1>stack 3 GS<1>

Slide 145

Slide 145 text

Translation is = RubyVM::InstructionSequence.new '2 + 3' puts is.to_a.last.map { |l,i| [Hash === i ? nil : i, l].compact.join ' ' }.join "\n" 1 trace 2 putobject 3 putobject opt_plus leave Translated Instructions

Slide 146

Slide 146 text

2013: PrintRuby

Slide 147

Slide 147 text

MASSIVELY Distributed

Slide 148

Slide 148 text

MASSIVELY Distributed

Slide 149

Slide 149 text

Take that Node.js!

Slide 150

Slide 150 text

Slight Detour Massive Detour

Slide 151

Slide 151 text

Actual Slight Detour

Slide 152

Slide 152 text

Get Instructions RubyVM::InstructionSequence#to_a

Slide 153

Slide 153 text

to_a irb> is = RubyVM::InstructionSequence.new '3 + 2' => irb> is.to_a => ["YARVInstructionSequence/SimpleDataFormat", 2, 0, 1, {:arg_size=>0, :local_size=>1, :stack_max=>2}, "", "", nil, 1, :top, [], 0, [], [[:trace, 1], [:putobject, 3], [:putobject, 2], [:opt_plus, {:mid=>: +, :flag=>256, :orig_argc=>1, :blockptr=>nil}], [:leave]]]

Slide 154

Slide 154 text

Eval Instructions RubyVM::InstructionSequence#eval

Slide 155

Slide 155 text

eval irb> is = RubyVM::InstructionSequence.new '3 + 2' => irb> is.eval => 5

Slide 156

Slide 156 text

Load Instructions? Can’t do it.

Slide 157

Slide 157 text

Or can we?

Slide 158

Slide 158 text

No content

Slide 159

Slide 159 text

No content

Slide 160

Slide 160 text

No content

Slide 161

Slide 161 text

handle = DL::Handle::DEFAULT address = handle['rb_iseq_load'] func = Fiddle::Function.new(address, [DL::TYPE_VOIDP] * 3, DL::TYPE_VOIDP) RubyVM::InstructionSequence.class_eval do # This monkey patch allows us to load arbitrary byte code with # Ruby's VM define_singleton_method(:load) { |data, parent = nil, opt = nil| func.call(DL.dlwrap(data), parent, opt).to_value } end

Slide 162

Slide 162 text

Slide 163

Slide 163 text

is = RubyVM::InstructionSequence.new '3 + 5' is2 = RubyVM::InstructionSequence.load is.to_a p is2.eval # => 8 Load Instructions

Slide 164

Slide 164 text

Manipulate Insns is = RubyVM::InstructionSequence.new '3 + 5' myis = is.to_a myis.last.map! { |ins, val| if ins == :putobject [ins, 10] else [ins, val].compact end } is2 = RubyVM::InstructionSequence.load myis p is2.eval # => 20

Slide 165

Slide 165 text

When your code is a little too readable.

Slide 166

Slide 166 text

When “meta” isn’t meta enough.

Slide 167

Slide 167 text

Take your app from lolscale to roﬂscale

Slide 168

Slide 168 text

Works on every Ruby: Guaranteed

Slide 169

Slide 169 text

Works on every Ruby: Guaranteed Seal of Approval

Slide 170

Slide 170 text

He’s lying.

Slide 171

Slide 171 text

Yes, you are.

Slide 172

Slide 172 text

Listen, we’ve been talking, and we think you have a problem

Slide 173

Slide 173 text

Anyway,

Slide 174

Slide 174 text

Cool hacks, but what else?

Slide 175

Slide 175 text

Micro- Optimizations

Slide 176

Slide 176 text

Step 1: Benchmark

Slide 177

Slide 177 text

def active_record user = User.find_by_login('tater') user.starred_items.count end require 'perftools' PerfTools::CpuProfiler.start("/tmp/ar") 10000.times { active_record } PerfTools::CpuProfiler.stop

Slide 178

Slide 178 text

ActiveRecord ConnectionAdapters Mysql2Adapter#execute 0 (0.0%) of 107 (21.0%) Enumerable#to_a 0 (0.0%) of 32 (6.3%) ActiveRecord ConnectionAdapters AbstractAdapter#log 9 (1.8%) of 107 (21.0%) ActiveSupport Notifications Instrumenter#instrument 0 (0.0%) of 98 (19.3%) 98 ActiveRecord ConnectionAdapters AbstractMysqlAdapter#execute 0 (0.0%) of 107 (21.0%) 107 107 Arel Visitors ToSql#accept 0 (0.0%) of 104 (20.4%) Arel Visitors MySQL#visit_Arel_Nodes_SelectStatement 1 (0.2%) of 104 (20.4%) Arel Visitors ToSql#visit_Arel_Nodes_SelectStatement 1 (0.2%) of 103 (20.2%) 103 Arel Visitors Visitor#accept 0 (0.0%) of 104 (20.4%) 104 Arel Visitors Visitor#visit 1 (0.2%) of 104 (20.4%) 104 104 Arel Visitors ToSql#visit_Arel_Nodes_JoinSource 1 (0.2%) of 40 (7.9%) 40 Arel Visitors ToSql#visit_Arel_Nodes_InnerJoin 9 (1.8%) of 22 (4.3%) 22 Arel Visitors ToSql#visit_Arel_Nodes_Equality 8 (1.6%) of 18 (3.5%) 18 Arel Visitors ToSql#visit_Arel_Nodes_On 0 (0.0%) of 13 (2.6%) 13 Arel Visitors ToSql#visit_Arel_Nodes_And 0 (0.0%) of 11 (2.2%) 11 Arel Visitors ToSql#visit_Arel_Attributes_Attribute 10 (2.0%) 10 Array#map 3 (0.6%) of 92 (18.1%) 91 Array#join 51 (10.0%) 11 Mysql2 Client#query 82 (16.1%) of 83 (16.3%) 83 ActiveSupport Notifications Fanout#start 0 (0.0%) of 15 (2.9%) 15 41 Arel Visitors MySQL#visit_Arel_Nodes_SelectCore 0 (0.0%) of 91 (17.9%) 91 Arel Visitors ToSql#visit_Arel_Nodes_SelectCore 16 (3.1%) of 91 (17.9%) 91 41 14 18 22 17 Mysql2 Result#each 32 (6.3%) 32 Struct#hash 4 (0.8%) of 21 (4.1%) 13 Arel Table#hash 2 (0.4%) of 17 (3.3%) 17 10 15 ActiveSupport Notifications Fanout#listeners_for 9 (1.8%) 9 13 6 5 ARel mysql2

Slide 179

Slide 179 text

Quick PSA: AR::Relation != ARel

Slide 180

Slide 180 text

user.starred.foo.bar.count starred

Slide 181

Slide 181 text

user.starred.foo.bar.count starred foo bar count SQL AST DB

Slide 182

Slide 182 text

Build a tree to build a tree

Slide 183

Slide 183 text

Yo Dawg Moment

Slide 184

Slide 184 text

Slide 185

Slide 185 text

Step 2: Look at the code

Slide 186

Slide 186 text

Select Core def visit_Arel_Nodes_SelectCore o [ "SELECT", ("FROM #{visit(o.source)} " if o.source), ].compact.join ' ' end

Slide 187

Slide 187 text

Select Core def visit_Arel_Nodes_SelectCore o [ "SELECT", ("FROM #{visit(o.source)} " if o.source), ].compact.join ' ' end

Slide 188

Slide 188 text

Step 3: Read the insns

Slide 189

Slide 189 text

“SELECT” irb> puts RubyVM::InstructionSequence.new('"SELECT"').disasm == disasm: @>========== 0000 trace 1 0002 putstring "SELECT" 0004 leave => nil

Slide 190

Slide 190 text

putstring VALUE rb_str_resurrect(VALUE str) { return str_replace(str_alloc(rb_cString), str); }

Slide 191

Slide 191 text

Easy Proof irb> 10.times { puts "foo".object_id } 70166440589860 70166440589800 70166440589740 70166440589660 70166440589580 70166440589520 70166440589420 70166440589360 70166440589260 70166440589200 => 10

Slide 192

Slide 192 text

"FROM #{visit(o.source)} " irb> puts RubyVM::InstructionSequence.new('"FROM #{visit(o.source)} "').disasm == disasm: @>========== 0000 trace 1 0002 putobject "FROM " 0004 putself 0005 putself 0006 send :o, 0, nil, 24, 0012 send :source, 0, nil, 0, 0018 send :visit, 1, nil, 8, 0024 tostring 0025 putstring " " 0027 concatstrings 3 0029 leave => nil

Slide 193

Slide 193 text

Slide 194

Slide 194 text

putobject /** @c put @e put some object. i.e. Fixnum, true, false, nil, and so on. @j ΦϒδΣΫτ val ΛελοΫʹϓογϡ͢Δɻ i.e. Fixnum, true, false, nil, and so on. */ DEFINE_INSN putobject (VALUE val) () (VALUE val) { /* */ }

Slide 195

Slide 195 text

Slide 196

Slide 196 text

“foo #{x} bar #{y} baz”

Slide 197

Slide 197 text

“foo #{x} bar #{y} baz” putobject

Slide 198

Slide 198 text

“foo #{x} bar #{y} baz” putstring

Slide 199

Slide 199 text

“foo #{x} bar #{y} baz” putstring

Slide 200

Slide 200 text

“foo #{x} bar #{y} baz” concat

Slide 201

Slide 201 text

“foo #{x} bar #{y} baz” Fixed in 2.0

Slide 202

Slide 202 text

“foo #{x} bar #{y} baz” putobject Fixed in 2.0

Slide 203

Slide 203 text

“foo #{x} bar #{y} baz” putobject Fixed in 2.0

Slide 204

Slide 204 text

“foo #{x} bar #{y} baz” putobject Fixed in 2.0

Slide 205

Slide 205 text

“foo #{x} bar #{y} baz” concat Fixed in 2.0

Slide 206

Slide 206 text

Step 4: Update the code

Slide 207

Slide 207 text

Use Constants irb> SELECT = "SELECT" => "SELECT" irb> 5.times { p SELECT.object_id } 70230907127200 70230907127200 70230907127200 70230907127200 70230907127200 => 5

Slide 208

Slide 208 text

Use String#<< FROM = "FROM " def visit_Arel_Nodes_SelectCore o select = "SELECT" if o.source select << FROM select << visit(o.source) end select end

Slide 209

Slide 209 text

String Allocations FROM = "FROM " def visit_Arel_Nodes_SelectCore o select = "SELECT" if o.source select << FROM select << visit(o.source) end select end

Slide 210

Slide 210 text

String Allocations FROM = "FROM " def visit_Arel_Nodes_SelectCore o select = "SELECT" if o.source select << FROM select << visit(o.source) end select end

Slide 211

Slide 211 text

18% reduction in GC invocations. 56 -> 46 invocations

Slide 212

Slide 212 text

18% reduction in GC time. 963ms => 786ms

Slide 213

Slide 213 text

Please, please,

Slide 214

Slide 214 text

please, please,

Slide 215

Slide 215 text

please, please,

Slide 216

Slide 216 text

optimize for readability ﬁrst,

Slide 217

Slide 217 text

then ﬁnd your bottlenecks.

Slide 218

Slide 218 text

DTrace Ruby 2.0

Slide 219

Slide 219 text

Probe Format provider:module:function:name /predicate/ { D Code }

Slide 220

Slide 220 text

Ruby Probes ruby:::function-entry; ruby:::function-return; ruby:::require-entry; ruby:::require-return; ruby:::load-entry; ruby:::load-return; ruby:::raise; ruby:::object-create; ruby:::array-create; ruby:::hash-create; ruby:::string-create; ruby:::parse-begin; ruby:::parse-end; ruby:::insn; ruby:::insn-operand; ruby:::gc-mark-begin; ruby:::gc-mark-end; ruby:::gc-sweep-begin; ruby:::gc-sweep-end;

Slide 221

Slide 221 text

Function Probes ruby:::function-entry; ruby:::function-return; ruby:::require-entry; ruby:::require-return; ruby:::load-entry; ruby:::load-return; ruby:::raise;

Slide 222

Slide 222 text

Object Creation ruby:::object-create; ruby:::array-create; ruby:::hash-create; ruby:::string-create;

Slide 223

Slide 223 text

GC Actions ruby:::gc-mark-begin; ruby:::gc-mark-end; ruby:::gc-sweep-begin; ruby:::gc-sweep-end;

Slide 224

Slide 224 text

Ruby Internals ruby:::parse-begin; ruby:::parse-end; ruby:::insn; ruby:::insn-operand;

Slide 225

Slide 225 text

Inspecting Rails Boot Time

Slide 226

Slide 226 text

No incredible revelations

Slide 227

Slide 227 text

No incredible revelations SPOILER

Slide 228

Slide 228 text

Count Insns ruby$target:::insn { @[copyinstr(arg0)] = count(); }

Slide 229

Slide 229 text

Test Script ruby -Ilib:. -rconfig/environment -e 0

Slide 230

Slide 230 text

Output putself 76307 putobject 79394 leave 141904 opt_send_simple 204104 getlocal 249011 trace 421121 $

Slide 231

Slide 231 text

Modify Compile RubyVM::InstructionSequence.compile_option = { trace_instruction: false }

Slide 232

Slide 232 text

Works on every Ruby: Guaranteed

Slide 233

Slide 233 text

Works on every Ruby: Guaranteed Seal of Approval

Slide 234

Slide 234 text

He’s lying again.

Slide 235

Slide 235 text

Output branchunless 56244 setlocal 56857 branchif 60836 dup 65032 send 66905 putself 76301 putobject 79396 leave 141896 opt_send_simple 204095 getlocal 249000 $

Slide 236

Slide 236 text

Is it faster? 100 samples of loading conﬁg/environment.rb

Slide 237

Slide 237 text

> mean(times$trace) [1] 1.570746 > mean(times$notrace) [1] 1.545819 Runtime (in s)

Slide 238

Slide 238 text

> sd(times$notrace) [1] 0.05686799 > sd(times$trace) [1] 0.05532489 Standard Dev (in s)

Slide 239

Slide 239 text

Answer: no.

Slide 240

Slide 240 text

Favorite Instruction?

Slide 241

Slide 241 text

Use a timer tick-5000hz { @[insn] = count(); } ruby$target:::insn { insn = copyinstr(arg0); }

Slide 242

Slide 242 text

Samples branchif 518 putself 542 getinstancevariable 550 putobject 667 leave 1355 getconstant 1521 invokesuper 1655 getlocal 2009 opt_send_simple 3008 send 5958 $

Slide 243

Slide 243 text

trace trace 57 getclassvariable 64 opt_regexpmatch1 65 toregexp 66 setinlinecache 82 jump 83 newarray 99 tostring 112 concatstrings 115 opt_regexpmatch2 120 expandarray 133 defined 179 setinstancevariable 189 putspecialobject 209 opt_eq 233 checkmatch 234 putstring 234 opt_aref 285 putnil 315 defineclass 336 getinlinecache 402 pop 433 dup 464 setlocal 471 branchunless 491 branchif 518 putself 542 getinstancevariable 550 putobject 667 leave 1355 getconstant 1521 invokesuper 1655 getlocal 2009 opt_send_simple 3008 send 5958

Slide 244

Slide 244 text

GC Time.

Slide 245

Slide 245 text

Measure GC time ruby$target:::gc-mark-begin { self->mark = timestamp; } ruby$target:::gc-sweep-begin { self->sweep = timestamp; } ruby$target:::gc-mark-end { @mark_time = sum(timestamp - self->mark); } ruby$target:::gc-sweep-end { @sweep_time = sum(timestamp - self->sweep); }

Slide 246

Slide 246 text

Track Total Time BEGIN { start = timestamp; } END { total = timestamp - start; printf("mark time (ns): "); printa("%@d\n", @mark_time); printf("sweep time (ns): "); printa("%@d\n", @sweep_time); printf("total time (ns): %d", total); }

Slide 247

Slide 247 text

GC Time mark time (ns) 276526868 sweep time (ns) 74943136 program time (ns) 1464656199

Slide 248

Slide 248 text

GC Time 76% 5% 19% Mark Sweep Rest mark time (ns) 276526868 sweep time (ns) 74943136 program time (ns) 1464656199

Slide 249

Slide 249 text

Compile Time.

Slide 250

Slide 250 text

Parse and Compile ruby$target:::parse-begin { parse = timestamp; } ruby$target:::parse-end { @compile = sum(timestamp - parse); }

Slide 251

Slide 251 text

Compile time compile time (ns) 255934383 program time (ns) 1237971025 79% 21% Compile Rest

Slide 252

Slide 252 text

Searching.

Slide 253

Slide 253 text

D Probes ruby$target:::find-require-entry { req_search = timestamp; } ruby$target:::find-require-return { t = timestamp; printf("%d,%d,%s\n", t, t - req_search, copyinstr(arg0)); }

Slide 254

Slide 254 text

Statistics Total Files 1649 Total Search Time 460096404 Total Time 1499901879 Mean Time 278846 Min Time 13840 Max Time 1392542 Std Dev 192585 Time in Nanoseconds 30%

Slide 255

Slide 255 text

No content

Slide 256

Slide 256 text

Linear Fit Call: lm(formula = trunk_require$y ~ trunk_require$x) Coefficients: (Intercept) trunk_require$x 134747.2 174.6

Slide 257

Slide 257 text

Bug #7158

Slide 258

Slide 258 text

Statistics Total Files 1649 Total Search Time 182910579 Total Time 1141907918 Mean Time 110854 Min Time 1905 Max Time 926160 Std Dev 134429 Time in Nanoseconds 16%

Slide 259

Slide 259 text

Comparison 0 375 750 1125 1500 Program Time (ms) Search Time (ms) trunk Bug #7158

Slide 260

Slide 260 text

No content

Slide 261

Slide 261 text

Sorted Compare

Slide 262

Slide 262 text

$ time ruby-trunk -Ilib:. -rconfig/environment -e 0 real 0m1.479s user 0m1.280s sys 0m0.191s $ time ruby-req -Ilib:. -rconfig/environment -e 0 real 0m1.145s user 0m0.972s sys 0m0.169s

Slide 263

Slide 263 text

Combined!

Slide 264

Slide 264 text

rest 25% find file 30% compile 21% sweep 5% mark 19% mark sweep compile find file rest Combined Graph

Slide 265

Slide 265 text

rest 39% find file 16% compile 21% sweep 5% mark 19% mark sweep compile find file rest After #7158

Slide 266

Slide 266 text

#7158 = ὑὑὑὑ

Slide 267

Slide 267 text

No content

Slide 268

Slide 268 text

Stay cool!!!

Slide 269

Slide 269 text

Never change!!!

Slide 270

Slide 270 text

Work!

Slide 271

Slide 271 text

Eat!

Slide 272

Slide 272 text

Hack!

Slide 273

Slide 273 text

Try Ruby 2.0!

Slide 274

Slide 274 text

No content

Slide 275

Slide 275 text

THANK YOU

Slide 276

Slide 276 text

Proﬁle Info https://gist.github.com/3989310 https://gist.github.com/3997732 https://bugs.ruby-lang.org/issues/7158