blob: 1adc73d2e70456a57323224e3582dd05519d01ca [file] [log] [blame]
Kevin Clarkca8a1b32008-06-18 01:17:06 +00001require 'rubygems'
2$:.unshift File.dirname(__FILE__) + '/../lib'
3require 'thrift'
4require 'thrift/server/nonblockingserver'
Kevin Clark2ddd8ed2008-06-18 01:18:35 +00005require 'thrift/transport/unixsocket'
Kevin Clarkca8a1b32008-06-18 01:17:06 +00006require 'stringio'
Kevin Clarkd3cee022008-06-18 01:19:09 +00007
Kevin Clarkca8a1b32008-06-18 01:17:06 +00008HOST = 'localhost'
9PORT = 42587
10
Kevin Clarkca8a1b32008-06-18 01:17:06 +000011###############
12## Server
13###############
14
Kevin Clarkd3cee022008-06-18 01:19:09 +000015class Server
16 attr_accessor :serverclass
17 attr_accessor :interpreter
18 attr_accessor :host
19 attr_accessor :port
Kevin Clarkca8a1b32008-06-18 01:17:06 +000020
Kevin Clarkd3cee022008-06-18 01:19:09 +000021 def initialize(opts)
22 @serverclass = opts.fetch(:class, Thrift::NonblockingServer)
23 @interpreter = opts.fetch(:interpreter, "ruby")
24 @host = opts.fetch(:host, ::HOST)
25 @port = opts.fetch(:port, ::PORT)
Kevin Clarkca8a1b32008-06-18 01:17:06 +000026 end
27
Kevin Clarkd3cee022008-06-18 01:19:09 +000028 def start
Kevin Clark75532ee2008-06-18 01:19:14 +000029 return if @serverclass == Object
Kevin Clark66038a02008-06-18 01:19:18 +000030 args = (File.basename(@interpreter) == "jruby" ? "-J-server" : "")
31 @pipe = IO.popen("#{@interpreter} #{args} #{File.dirname(__FILE__)}/server.rb #{@host} #{@port} #{@serverclass.name}", "r+")
Kevin Clark1a95a1d2008-06-18 01:19:28 +000032 Marshal.load(@pipe) # wait until the server has started
33 sleep 0.2 # give the server time to actually start spawning sockets
Kevin Clarkca8a1b32008-06-18 01:17:06 +000034 end
35
Kevin Clarkd3cee022008-06-18 01:19:09 +000036 def shutdown
37 return unless @pipe
38 Marshal.dump(:shutdown, @pipe)
39 begin
40 @pipe.read(10) # block until the server shuts down
41 rescue EOFError
Kevin Clarkca8a1b32008-06-18 01:17:06 +000042 end
Kevin Clarkd3cee022008-06-18 01:19:09 +000043 @pipe.close
44 @pipe = nil
Kevin Clarkca8a1b32008-06-18 01:17:06 +000045 end
46end
47
Kevin Clarkca8a1b32008-06-18 01:17:06 +000048class BenchmarkManager
Kevin Clarkd3cee022008-06-18 01:19:09 +000049 def initialize(opts, server)
Kevin Clark2ddd8ed2008-06-18 01:18:35 +000050 @socket = opts.fetch(:socket) do
51 @host = opts.fetch(:host, 'localhost')
52 @port = opts.fetch(:port)
53 nil
54 end
Kevin Clarkca8a1b32008-06-18 01:17:06 +000055 @num_processes = opts.fetch(:num_processes, 40)
56 @clients_per_process = opts.fetch(:clients_per_process, 10)
57 @calls_per_client = opts.fetch(:calls_per_client, 50)
Kevin Clarkd3cee022008-06-18 01:19:09 +000058 @interpreter = opts.fetch(:interpreter, "ruby")
59 @server = server
Kevin Clarkca8a1b32008-06-18 01:17:06 +000060 end
61
62 def run
63 @pool = []
64 @benchmark_start = Time.now
65 puts "Spawning benchmark processes..."
66 @num_processes.times do
67 spawn
Kevin Clarke4644f12008-06-18 01:19:41 +000068 sleep 0.01 # space out spawns
Kevin Clarkca8a1b32008-06-18 01:17:06 +000069 end
70 collect_output
71 @benchmark_end = Time.now # we know the procs are done here
72 translate_output
73 analyze_output
74 report_output
75 end
76
77 def spawn
Kevin Clarkd3cee022008-06-18 01:19:09 +000078 pipe = IO.popen("#{@interpreter} #{File.dirname(__FILE__)}/client.rb #{@host} #{@port} #{@clients_per_process} #{@calls_per_client}")
79 @pool << pipe
Kevin Clarkca8a1b32008-06-18 01:17:06 +000080 end
81
Kevin Clark2ddd8ed2008-06-18 01:18:35 +000082 def socket_class
83 if @socket
84 Thrift::UNIXSocket
85 else
86 Thrift::Socket
87 end
88 end
89
Kevin Clarkca8a1b32008-06-18 01:17:06 +000090 def collect_output
91 puts "Collecting output..."
92 # read from @pool until all sockets are closed
93 @buffers = Hash.new { |h,k| h[k] = '' }
94 until @pool.empty?
95 rd, = select(@pool)
96 next if rd.nil?
97 rd.each do |fd|
98 begin
Kevin Clarkfb5c0eb2008-06-18 01:19:04 +000099 @buffers[fd] << fd.readpartial(4096)
Kevin Clarkca8a1b32008-06-18 01:17:06 +0000100 rescue EOFError
101 @pool.delete fd
102 end
103 end
104 end
105 end
106
107 def translate_output
108 puts "Translating output..."
109 @output = []
110 @buffers.each do |fd, buffer|
111 strio = StringIO.new(buffer)
112 logs = []
113 begin
114 loop do
115 logs << Marshal.load(strio)
116 end
117 rescue EOFError
118 @output << logs
119 end
120 end
121 end
122
123 def analyze_output
124 puts "Analyzing output..."
125 call_times = []
126 client_times = []
127 connection_failures = []
Kevin Clarkd2719792008-06-18 01:19:37 +0000128 connection_errors = []
Kevin Clark66038a02008-06-18 01:19:18 +0000129 shortest_call = 0
130 shortest_client = 0
Kevin Clarkca8a1b32008-06-18 01:17:06 +0000131 longest_call = 0
132 longest_client = 0
133 @output.each do |logs|
134 cur_call, cur_client = nil
135 logs.each do |tok, time|
136 case tok
137 when :start
138 cur_client = time
139 when :call_start
140 cur_call = time
141 when :call_end
142 delta = time - cur_call
143 call_times << delta
144 longest_call = delta unless longest_call > delta
Kevin Clark66038a02008-06-18 01:19:18 +0000145 shortest_call = delta if shortest_call == 0 or delta < shortest_call
Kevin Clarkca8a1b32008-06-18 01:17:06 +0000146 cur_call = nil
147 when :end
148 delta = time - cur_client
149 client_times << delta
150 longest_client = delta unless longest_client > delta
Kevin Clark66038a02008-06-18 01:19:18 +0000151 shortest_client = delta if shortest_client == 0 or delta < shortest_client
Kevin Clarkca8a1b32008-06-18 01:17:06 +0000152 cur_client = nil
153 when :connection_failure
154 connection_failures << time
Kevin Clarkd2719792008-06-18 01:19:37 +0000155 when :connection_error
156 connection_errors << time
Kevin Clarkca8a1b32008-06-18 01:17:06 +0000157 end
158 end
159 end
160 @report = {}
161 @report[:total_calls] = call_times.inject(0.0) { |a,t| a += t }
162 @report[:avg_calls] = @report[:total_calls] / call_times.size
163 @report[:total_clients] = client_times.inject(0.0) { |a,t| a += t }
164 @report[:avg_clients] = @report[:total_clients] / client_times.size
165 @report[:connection_failures] = connection_failures.size
Kevin Clarkd2719792008-06-18 01:19:37 +0000166 @report[:connection_errors] = connection_errors.size
Kevin Clark66038a02008-06-18 01:19:18 +0000167 @report[:shortest_call] = shortest_call
168 @report[:shortest_client] = shortest_client
Kevin Clarkca8a1b32008-06-18 01:17:06 +0000169 @report[:longest_call] = longest_call
170 @report[:longest_client] = longest_client
171 @report[:total_benchmark_time] = @benchmark_end - @benchmark_start
172 @report[:fastthread] = $".include?('fastthread.bundle')
173 end
174
175 def report_output
176 fmt = "%.4f seconds"
177 puts
178 tabulate "%d",
Kevin Clark75532ee2008-06-18 01:19:14 +0000179 [["Server class", "%s"], @server.serverclass == Object ? "" : @server.serverclass],
Kevin Clarkd3cee022008-06-18 01:19:09 +0000180 [["Server interpreter", "%s"], @server.interpreter],
181 [["Client interpreter", "%s"], @interpreter],
Kevin Clark2ddd8ed2008-06-18 01:18:35 +0000182 [["Socket class", "%s"], socket_class],
Kevin Clarkca8a1b32008-06-18 01:17:06 +0000183 ["Number of processes", @num_processes],
184 ["Clients per process", @clients_per_process],
185 ["Calls per client", @calls_per_client],
186 [["Using fastthread", "%s"], @report[:fastthread] ? "yes" : "no"]
187 puts
Kevin Clark75532ee2008-06-18 01:19:14 +0000188 failures = (@report[:connection_failures] > 0)
Kevin Clarkca8a1b32008-06-18 01:17:06 +0000189 tabulate fmt,
Kevin Clarkd2719792008-06-18 01:19:37 +0000190 [["Connection failures", "%d", [:red, :bold]], @report[:connection_failures]],
191 [["Connection errors", "%d", [:red, :bold]], @report[:connection_errors]],
Kevin Clarkca8a1b32008-06-18 01:17:06 +0000192 ["Average time per call", @report[:avg_calls]],
193 ["Average time per client (%d calls)" % @calls_per_client, @report[:avg_clients]],
194 ["Total time for all calls", @report[:total_calls]],
195 ["Real time for benchmarking", @report[:total_benchmark_time]],
Kevin Clark66038a02008-06-18 01:19:18 +0000196 ["Shortest call time", @report[:shortest_call]],
197 ["Longest call time", @report[:longest_call]],
198 ["Shortest client time (%d calls)" % @calls_per_client, @report[:shortest_client]],
Kevin Clarkca8a1b32008-06-18 01:17:06 +0000199 ["Longest client time (%d calls)" % @calls_per_client, @report[:longest_client]]
200 end
201
Kevin Clark75532ee2008-06-18 01:19:14 +0000202 ANSI = {
203 :reset => 0,
204 :bold => 1,
205 :black => 30,
206 :red => 31,
207 :green => 32,
208 :yellow => 33,
209 :blue => 34,
210 :magenta => 35,
211 :cyan => 36,
212 :white => 37
213 }
214
Kevin Clarkca8a1b32008-06-18 01:17:06 +0000215 def tabulate(fmt, *labels_and_values)
216 labels = labels_and_values.map { |(l,)| Array === l ? l.first : l }
217 label_width = labels.inject(0) { |w,l| l.size > w ? l.size : w }
218 labels_and_values.each do |(l,v)|
219 f = fmt
Kevin Clark75532ee2008-06-18 01:19:14 +0000220 l, f, c = l if Array === l
221 fmtstr = "%-#{label_width+1}s #{f}"
Kevin Clarkd2719792008-06-18 01:19:37 +0000222 if STDOUT.tty? and c and v.to_i > 0
Kevin Clark75532ee2008-06-18 01:19:14 +0000223 fmtstr = "\e[#{[*c].map { |x| ANSI[x] } * ";"}m" + fmtstr + "\e[#{ANSI[:reset]}m"
224 end
225 puts fmtstr % [l+":", v]
Kevin Clarkca8a1b32008-06-18 01:17:06 +0000226 end
227 end
228end
229
230def resolve_const(const)
231 const and const.split('::').inject(Object) { |k,c| k.const_get(c) }
232end
233
234puts "Starting server..."
Kevin Clarkd3cee022008-06-18 01:19:09 +0000235args = {}
236args[:interpreter] = ENV['THRIFT_SERVER_INTERPRETER'] || ENV['THRIFT_INTERPRETER'] || "ruby"
237args[:class] = resolve_const(ENV['THRIFT_SERVER']) || Thrift::NonblockingServer
238server = Server.new(args)
239server.start
Kevin Clarkca8a1b32008-06-18 01:17:06 +0000240
Kevin Clarkd3cee022008-06-18 01:19:09 +0000241args = { :num_processes => 40, :clients_per_process => 5, :host => HOST, :port => PORT }
242args[:interpreter] = ENV['THRIFT_CLIENT_INTERPRETER'] || ENV['THRIFT_INTERPRETER'] || "ruby"
243BenchmarkManager.new(args, server).run
Kevin Clarkca8a1b32008-06-18 01:17:06 +0000244
Kevin Clarkd3cee022008-06-18 01:19:09 +0000245server.shutdown