lib/stella/engine/loadbase.rb in stella-0.8.0.001 vs lib/stella/engine/loadbase.rb in stella-0.8.1.001
- old
+ new
@@ -24,11 +24,11 @@
if Stella.sysinfo.os == :unix
File.unlink latest if File.exists? latest
FileUtils.ln_sf File.basename(@logdir), latest
end
-
+
@reqlog = Stella::Logger.new log_path(plan, 'requests')
@failog = Stella::Logger.new log_path(plan, 'requests-exceptions')
@sumlog = Stella::Logger.new log_path(plan, 'summary')
@optlog = Stella::Logger.new log_path(plan, 'options')
@authlog = Stella::Logger.new log_path(plan, 'requests-auth')
@@ -46,18 +46,27 @@
@sumlog.add_template :dsummary, '%20s: %8d'
@sumlog.add_template :fsummary, '%20s: %8.2f'
@optlog.add_template :head, '%10s: %s'
@failog.add_template :request, '%s %s'
- @dumper = prepare_dumper(plan, opts)
-
if Stella.stdout.lev > 2
Load.timers += [:query, :connect, :socket_gets_first_byte, :get_body]
Load.counts = [:request_header_size, :request_content_size]
Load.counts += [:response_headers_size, :response_content_size]
end
+ events = [Load.timers, Load.counts, :failed].flatten
+ @testrun = Stella::Testrun.new plan, events, opts
+ @testrun.mode = 'l'
+
+ if Stella::Engine.service
+ Stella::Engine.service.testplan_sync plan
+ Stella::Engine.service.testrun_create @testrun
+ end
+
+ @dumper = prepare_dumper(plan, opts)
+
counts = calculate_usecase_clients plan, opts
@optlog.head 'RUNID', runid(plan)
@optlog.head 'OPTIONS', opts.inspect
@@ -77,61 +86,40 @@
begin
@optlog.head "START", Time.now.to_s
Stella.stdout.status "Running"
execute_test_plan packages, opts[:repetitions], opts[:duration], opts[:arrival]
- Stella.stdout.info $/, "Done"
rescue Interrupt
Stella.stdout.info $/, "Stopping test"
Stella.abort!
@threads.each { |t| t.join } unless @threads.nil? || @threads.empty? # wait
rescue => ex
STDERR.puts "Unhandled exception: #{ex.message}"
STDERR.puts ex.backtrace if Stella.debug? || Stella.stdout.lev >= 3
end
+ Stella.stdout.status "Processing"
+
@optlog.head "END", Time.now.to_s
@optlog.flush
@dumper.stop
- Stella.stdout.status "Processing"
-
- Benelux.update_global_timeline
-
bt = Benelux.timeline
tt = Benelux.thread_timeline
+
+ # TODO: don't get test time from benelux.
test_time = tt.stats.group(:execute_test_plan).mean
generate_report @sumlog, plan, test_time
- report_time = tt.stats.group(:generate_report).mean
+ #report_time = tt.stats.group(:generate_report).mean
- # Here is the calcualtion for the number of
- # Benelux assets created for each request:
- #
- # [5*2*REQ+6, 5*1*REQ+3, 13*REQ]
- #
-
- failed = bt.stats.group(:failed).merge
- total = bt.stats.group(:do_request).merge
-
- @sumlog.info $/, "Summary: "
- @sumlog.dsummary 'successful req', total.n
- @sumlog.dsummary "failed req", failed.n
- @sumlog.dsummary "max clients", @max_clients
- @sumlog.dsummary "repetitions", @real_reps
- @sumlog.fsummary "test time", test_time
- @sumlog.fsummary "reporting time", report_time
- @sumlog.flush
-
Stella.stdout.info File.read(@sumlog.path)
- # DNE:
- #p [@real_reps, total.n]
Stella.stdout.info $/, "Log dir: #{@logdir}"
- failed.n == 0
+ @testrun.summary[:summary][:failed].n == 0
end
protected
class ThreadPackage
attr_accessor :index
@@ -141,98 +129,50 @@
@index, @client, @usecase = i, c, u
end
end
def prepare_dumper(plan, opts)
- Stella::Hand.new(15.seconds, 2.seconds) do
+ hand = Stella::Hand.new(LoadQueue::ROTATE_TIMELINE, 2.seconds) do
Benelux.update_global_timeline
+ # @threads contains only stella clients
+ concurrency = @threads.select { |t| !t.status.nil? }.size
+ batch, timeline = Benelux.timeline_updates, Benelux.timeline_chunk
+ @testrun.add_sample batch, concurrency, timeline
+
#reqlog.info [Time.now, Benelux.timeline.size].inspect
@reqlog.info Benelux.timeline.messages.filter(:kind => :request)
@failog.info Benelux.timeline.messages.filter(:kind => :exception)
@failog.info Benelux.timeline.messages.filter(:kind => :timeout)
@authlog.info Benelux.timeline.messages.filter(:kind => :authentication)
@reqlog.clear and @failog.clear and @authlog.clear
+
Benelux.timeline.clear if opts[:"no-stats"]
+
end
-
- end
-
- def calculate_usecase_clients(plan, opts)
- counts = { :total => 0 }
- plan.usecases.each_with_index do |usecase,i|
- count = case opts[:clients]
- when 0..9
- if (opts[:clients] % plan.usecases.size > 0)
- msg = "Client count does not evenly match usecase count"
- raise Stella::WackyRatio, msg
- else
- (opts[:clients] / plan.usecases.size)
- end
- else
- (opts[:clients] * usecase.ratio).to_i
- end
- counts[usecase.digest_cache] = count
- counts[:total] += count
+ hand.finally do
+ #total = @testrun.stats[:summary][:do_request].n
+ #failed = @testrun.stats[:summary][:failed].n
+ #@sumlog.info $/, "Summary: "
+ #@sumlog.dsummary 'successful req', total-failed
+ #@sumlog.dsummary "failed req", failed
+ #@sumlog.dsummary "max clients", @max_clients
+ #@sumlog.dsummary "repetitions", @real_reps
+ ##@sumlog.fsummary "test time", test_time
+ ##@sumlog.fsummary "reporting time", report_time
+ #@sumlog.flush
end
- counts
+ hand
end
-
- def build_thread_package(plan, opts, counts)
- packages, pointer = Array.new(counts[:total]), 0
- plan.usecases.each do |usecase|
- count = counts[usecase.digest_cache]
- Stella.ld "THREAD PACKAGE: #{usecase.desc} (#{pointer} + #{count})"
- # Fill the thread_package with the contents of the block
- packages.fill(pointer, count) do |index|
- client = Stella::Client.new opts[:hosts].first, index+1, opts
- client.add_observer(self)
- client.enable_nowait_mode if opts[:nowait]
- Stella.stdout.info4 "Created client #{client.digest.short}"
- ThreadPackage.new(index+1, client, usecase)
- end
- pointer += count
- end
- packages.compact # TODO: Why one nil element sometimes?
- end
-
- def execute_test_plan(*args)
- raise "Override execute_test_plan method in #{self}"
- end
-
- def running_threads
- @threads.select { |t| t.status } # non-false status are still running
- end
-
- def generate_runtime_report(plan)
- gt = Benelux.timeline
- gstats = gt.stats.group(:do_request).merge
-
- plan.usecases.uniq.each_with_index do |uc,i|
- uc.requests.each do |req|
- filter = [uc.digest_cache, req.digest_cache]
- Load.timers.each do |sname|
- stats = gt.stats.group(sname)[filter].merge
- #Stella.stdout.info stats.inspect
- puts [sname, stats.min, stats.mean, stats.max, stats.sd, stats.n].join('; ')
- end
-
- end
- end
-
- end
-
def generate_report(sumlog,plan,test_time)
global_timeline = Benelux.timeline
global_stats = global_timeline.stats.group(:do_request).merge
if global_stats.n == 0
Stella.ld "No stats"
return
end
-
-
@sumlog.info " %-72s ".att(:reverse) % ["#{plan.desc} (#{plan.digest_cache.shorter})"]
plan.usecases.uniq.each_with_index do |uc,i|
# TODO: Create Ranges object, like Stats object
# global_timeline.ranges(:do_request)[:usecase => '1111']
@@ -240,22 +180,23 @@
requests = 0 #global_timeline.ranges(:do_request).size
desc = uc.desc || "Usecase ##{i+1} "
desc << " (#{uc.digest_cache.shorter}) "
str = ' ' << " %-66s %s %d%% ".bright.att(:reverse)
- @sumlog.info str % [desc, '', uc.ratio_pretty]
-
+ @sumlog.info str % [desc, '', uc.ratio_pretty]
uc.requests.each do |req|
filter = [uc.digest_cache, req.digest_cache]
desc = req.desc
@sumlog.info " %-72s ".bright % ["#{req.desc} (#{req.digest_cache.shorter})"]
@sumlog.info " %s" % [req.to_s]
+
Load.timers.each do |sname|
stats = global_timeline.stats.group(sname)[filter].merge
# Stella.stdout.info stats.inspect
str = ' %-30s %.3f <= ' << '%.3fs' << ' >= %.3f; %.3f(SD) %d(N)'
- @sumlog.info str % [sname, stats.min, stats.mean, stats.max, stats.sd, stats.n]
+ msg = str % [sname, stats.min, stats.mean, stats.max, stats.sd, stats.n]
+ @sumlog.info msg
@sumlog.flush
end
@sumlog.info $/
end
@@ -318,10 +259,79 @@
@sumlog.flush
end
end
+ def calculate_usecase_clients(plan, opts)
+ counts = { :total => 0 }
+ plan.usecases.each_with_index do |usecase,i|
+ count = case opts[:clients]
+ when 0..9
+ if (opts[:clients] % plan.usecases.size > 0)
+ msg = "Client count does not evenly match usecase count"
+ raise Stella::WackyRatio, msg
+ else
+ (opts[:clients] / plan.usecases.size)
+ end
+ else
+ (opts[:clients] * usecase.ratio).to_i
+ end
+ counts[usecase.digest_cache] = count
+ counts[:total] += count
+ end
+ counts
+ end
+
+
+ def build_thread_package(plan, opts, counts)
+ packages, pointer = Array.new(counts[:total]), 0
+ plan.usecases.each do |usecase|
+ count = counts[usecase.digest_cache]
+ Stella.ld "THREAD PACKAGE: #{usecase.desc} (#{pointer} + #{count})"
+ # Fill the thread_package with the contents of the block
+ packages.fill(pointer, count) do |index|
+ client = Stella::Client.new opts[:hosts].first, index+1, opts
+ client.add_observer(self)
+ client.enable_nowait_mode if opts[:nowait]
+ Stella.stdout.info4 "Created client #{client.digest.short}"
+ ThreadPackage.new(index+1, client, usecase)
+ end
+ pointer += count
+ end
+ packages.compact # TODO: Why one nil element sometimes?
+ # Randomize so when ramping up load
+ # we get a mix of usecases.
+ packages.sort_by {rand}
+ end
+
+ def execute_test_plan(*args)
+ raise "Override execute_test_plan method in #{self}"
+ end
+
+ def running_threads
+ @threads.select { |t| t.status } # non-false status are still running
+ end
+
+ def generate_runtime_report(plan)
+ gt = Benelux.timeline
+ gstats = gt.stats.group(:do_request).merge
+
+ plan.usecases.uniq.each_with_index do |uc,i|
+ uc.requests.each do |req|
+ filter = [uc.digest_cache, req.digest_cache]
+
+ Load.timers.each do |sname|
+ stats = gt.stats.group(sname)[filter].merge
+ #Stella.stdout.info stats.inspect
+ puts [sname, stats.min, stats.mean, stats.max, stats.sd, stats.n].join('; ')
+ end
+
+ end
+ end
+
+ end
+
def update_prepare_request(client_id, usecase, req, counter)
end
def update_receive_response(client_id, usecase, uri, req, params, headers, counter, container)
@@ -365,11 +375,11 @@
else
Stella.le ' Client-%s %-45s %s' % [client_id.shorter, desc, ex.message]
Stella.ld ex.backtrace
end
end
-
+
def update_usecase_quit client_id, msg, req, container
args = [Time.now.to_f, Stella.sysinfo.hostname, client_id.short]
Benelux.thread_timeline.add_count :quit, 1
args.push [req, container.status, 'QUIT', msg, container.unique_id[0,10]]
Benelux.thread_timeline.add_message args.join('; '), :kind => :exception
@@ -391,10 +401,10 @@
Benelux.thread_timeline.add_message args.join('; '), :kind => :exception
if Stella.stdout.lev >= 3
Stella.le ' Client-%s %-45s %s' % [client_id.shorter, desc, ex.message]
end
end
-
+
def update_request_repeat client_id, counter, total, req, container
Stella.stdout.info3 " Client-%s REPEAT %d of %d" % [client_id.shorter, counter, total]
end
def update_follow_redirect client_id, ret, req, container