Setup benchmarking structure

- Setup dummy app files in `test/dummy`
- Setup dummy test server `bin/serve_dummy
  - Note:  Serializer caching can be completely disabled by passing in
  `CACHE_ON=off bin/serve_dummy start` since Serializer#_cache is only
  set at boot.
- run with
  - ./bin/bench
  - `bin/bench` etc adapted from ruby-bench-suite
  - target files are `test/dummy/bm_*.rb`. Just add another to run it.
  - benchmark cache/no cache
  - remove rake dependency that loads unnecessary files
- remove git gem dependency
  - Running over revisions to be added in subsequent PR
This commit is contained in:
Benjamin Fleischer 2016-01-05 00:48:29 -06:00
parent 952ab0438f
commit 4cc454d49b
13 changed files with 700 additions and 86 deletions

View File

@ -1,6 +1,7 @@
inherit_from: .rubocop_todo.yml
AllCops:
TargetRubyVersion: 2.2
Exclude:
- config/initializers/forbidden_yaml.rb
- !ruby/regexp /(vendor|bundle|bin|db|tmp)\/.*/

View File

@ -36,6 +36,11 @@ end
# Windows does not include zoneinfo files, so bundle the tzinfo-data gem
gem 'tzinfo-data', platforms: (@windows_platforms + [:jruby])
group :bench do
# https://github.com/rails-api/active_model_serializers/commit/cb4459580a6f4f37f629bf3185a5224c8624ca76
gem 'benchmark-ips', require: false, group: :development
end
group :test do
gem 'sqlite3', platform: (@windows_platforms + [:ruby])
gem 'activerecord-jdbcsqlite3-adapter', platform: :jruby
@ -45,5 +50,4 @@ end
group :development, :test do
gem 'rubocop', '~> 0.36', require: false
gem 'git'
end

View File

@ -74,38 +74,3 @@ end
desc 'CI test task'
task :ci => [:default]
require 'git'
require 'benchmark'
Rake::TestTask.new :benchmark_tests do |t|
t.libs << "test"
t.test_files = FileList['test/**/*_benchmark.rb']
t.ruby_opts = ['-r./test/test_helper.rb']
t.verbose = true
end
task :benchmark do
@git = Git.init('.')
ref = @git.current_branch
actual = run_benchmark_spec ref
master = run_benchmark_spec 'master'
@git.checkout(ref)
puts "\n\nResults ============================\n"
puts "------------------------------------~> (Branch) MASTER"
puts master
puts "------------------------------------\n\n"
puts "------------------------------------~> (Actual Branch) #{ref}"
puts actual
puts "------------------------------------"
end
def run_benchmark_spec(ref)
@git.checkout(ref)
response = Benchmark.realtime { Rake::Task['benchmark_tests'].invoke }
Rake::Task['benchmark_tests'].reenable
response
end

View File

@ -17,6 +17,7 @@ Gem::Specification.new do |spec|
spec.files = `git ls-files -z`.split("\x0")
spec.test_files = spec.files.grep(%r{^(test|spec|features)/})
spec.require_paths = ['lib']
spec.executables = []
spec.required_ruby_version = '>= 2.0.0'

170
bin/bench Executable file
View File

@ -0,0 +1,170 @@
#!/usr/bin/env ruby
# ActiveModelSerializers Benchmark driver
# Adapted from
# https://github.com/ruby-bench/ruby-bench-suite/blob/8ad567f7e43a044ae48c36833218423bb1e2bd9d/rails/benchmarks/driver.rb
require 'bundler'
Bundler.setup
require 'json'
require 'pathname'
require 'optparse'
require 'digest'
require 'pathname'
require 'shellwords'
require 'logger'
require 'English'
class BenchmarkDriver
ROOT = Pathname File.expand_path(File.join('..', '..'), __FILE__)
BASE = ENV.fetch('BASE') { ROOT.join('test', 'dummy') }
ESCAPED_BASE = Shellwords.shellescape(BASE)
def self.benchmark(options)
new(options).run
end
def self.parse_argv_and_run(argv = ARGV, options = {})
options = {
repeat_count: 1,
pattern: [],
env: 'CACHE_ON=on'
}.merge!(options)
OptionParser.new do |opts|
opts.banner = 'Usage: bin/bench [options]'
opts.on('-r', '--repeat-count [NUM]', 'Run benchmarks [NUM] times taking the best result') do |value|
options[:repeat_count] = value.to_i
end
opts.on('-p', '--pattern <PATTERN1,PATTERN2,PATTERN3>', 'Benchmark name pattern') do |value|
options[:pattern] = value.split(',')
end
opts.on('-e', '--env <var1=val1,var2=val2,var3=vale>', 'ENV variables to pass in') do |value|
options[:env] = value.split(',')
end
end.parse!(argv)
benchmark(options)
end
attr_reader :commit_hash, :base
# Based on logfmt:
# https://www.brandur.org/logfmt
# For more complete implementation see:
# see https://github.com/arachnid-cb/logfmtr/blob/master/lib/logfmtr/base.rb
# For usage see:
# https://blog.codeship.com/logfmt-a-log-format-thats-easy-to-read-and-write/
# https://engineering.heroku.com/blogs/2014-09-05-hutils-explore-your-structured-data-logs/
# For Ruby parser see:
# https://github.com/cyberdelia/logfmt-ruby
def self.summary_logger(device = 'output.txt')
require 'time'
logger = Logger.new(device)
logger.level = Logger::INFO
logger.formatter = proc { |severity, datetime, progname, msg|
msg = "'#{msg}'"
"level=#{severity} time=#{datetime.utc.iso8601(6)} pid=#{Process.pid} progname=#{progname} msg=#{msg}#{$INPUT_RECORD_SEPARATOR}"
}
logger
end
def self.stdout_logger
logger = Logger.new(STDOUT)
logger.level = Logger::INFO
logger.formatter = proc { |_, _, _, msg| "#{msg}#{$INPUT_RECORD_SEPARATOR}" }
logger
end
def initialize(options)
@writer = ENV['SUMMARIZE'] ? self.class.summary_logger : self.class.stdout_logger
@repeat_count = options[:repeat_count]
@pattern = options[:pattern]
@commit_hash = options.fetch(:commit_hash) { `git rev-parse --short HEAD`.chomp }
@base = options.fetch(:base) { ESCAPED_BASE }
@env = Array(options[:env]).join(' ')
@rubyopt = options[:rubyopt] # TODO: rename
end
def run
files.each do |path|
next if !@pattern.empty? && /#{@pattern.join('|')}/ !~ File.basename(path)
run_single(Shellwords.shellescape(path))
end
end
private
def files
Dir[File.join(base, 'bm_*')]
end
def run_single(path)
script = "RAILS_ENV=production #{@env} ruby #{@rubyopt} #{path}"
environment = `ruby -v`.chomp.strip[/\d+\.\d+\.\d+\w+/]
runs_output = measure(script)
if runs_output.empty?
results = { error: :no_results }
return
end
results = {}
results['commit_hash'] = commit_hash
results['version'] = runs_output.first['version']
results['benchmark_run[environment]'] = environment
results['runs'] = []
runs_output.each do |output|
results['runs'] << {
'benchmark_type[category]' => output['label'],
'benchmark_run[result][iterations_per_second]' => output['iterations_per_second'].round(3),
'benchmark_run[result][total_allocated_objects_per_iteration]' => output['total_allocated_objects_per_iteration']
}
end
ensure
results && report(results)
end
def report(results)
@writer.info { 'Benchmark results:' }
@writer.info { JSON.pretty_generate(results) }
end
def summarize(result)
puts "#{result['label']} #{result['iterations_per_second']}/ips; #{result['total_allocated_objects_per_iteration']} objects"
end
# FIXME: ` provides the full output but it'll return failed output as well.
def measure(script)
results = Hash.new { |h, k| h[k] = [] }
@repeat_count.times do
output = sh(script)
output.each_line do |line|
next if line.nil?
begin
result = JSON.parse(line)
rescue JSON::ParserError
result = { error: line } # rubocop:disable Lint/UselessAssignment
else
summarize(result)
results[result['label']] << result
end
end
end
results.map do |_, bm_runs|
bm_runs.sort_by do |run|
run['iterations_per_second']
end.last
end
end
def sh(cmd)
`#{cmd}`
end
end
BenchmarkDriver.parse_argv_and_run if $PROGRAM_NAME == __FILE__

39
bin/serve_dummy Executable file
View File

@ -0,0 +1,39 @@
#!/usr/bin/env bash
set -e
case "$1" in
start)
config="${CONFIG_RU:-test/dummy/config.ru}"
bundle exec ruby -Ilib -S rackup "$config" --daemonize --pid tmp/dummy_app.pid --warn --server webrick
until [ -f 'tmp/dummy_app.pid' ]; do
sleep 0.1 # give it time to start.. I don't know a better way
done
cat tmp/dummy_app.pid
true
;;
stop)
if [ -f 'tmp/dummy_app.pid' ]; then
kill -TERM $(cat tmp/dummy_app.pid)
else
echo 'No pidfile'
false
fi
;;
status)
if [ -f 'tmp/dummy_app.pid' ]; then
kill -0 $(cat tmp/dummy_app.pid)
[ "$?" -eq 0 ]
else
echo 'No pidfile'
false
fi
;;
*)
echo "Usage: $0 [start|stop|status]"
;;
esac

View File

@ -1,50 +0,0 @@
require 'test_helper'
module ActionController
module Serialization
class SerializerTest < ActionController::TestCase
class PostController < ActionController::Base
def render_with_cache_enable
comment = Comment.new({ id: 1, body: 'ZOMG A COMMENT' })
author = Author.new(id: 1, name: 'Joao Moura.')
post = Post.new({ id: 1, title: 'New Post', blog:nil, body: 'Body', comments: [comment], author: author })
render json: post
end
end
tests PostController
def test_render_with_cache_enable
ActionController::Base.cache_store.clear
get :render_with_cache_enable
expected = {
id: 1,
title: 'New Post',
body: 'Body',
comments: [
{
id: 1,
body: 'ZOMG A COMMENT' }
],
blog: {
id: 999,
name: 'Custom blog'
},
author: {
id: 1,
name: 'Joao Moura.'
}
}
assert_equal 'application/json', @response.content_type
assert_equal expected.to_json, @response.body
get :render_with_cache_enable
assert_equal expected.to_json, @response.body
end
end
end
end

65
test/dummy/app.rb Normal file
View File

@ -0,0 +1,65 @@
# https://github.com/rails-api/active_model_serializers/pull/872
# approx ref 792fb8a9053f8db3c562dae4f40907a582dd1720 to test against
require 'bundler/setup'
require 'rails'
require 'active_model'
require 'active_support'
require 'active_support/json'
require 'action_controller'
require 'action_controller/test_case'
require 'action_controller/railtie'
abort "Rails application already defined: #{Rails.application.class}" if Rails.application
class NullLogger < Logger
def initialize(*_args)
end
def add(*_args, &_block)
end
end
class DummyLogger < ActiveSupport::Logger
def initialize
@file = StringIO.new
super(@file)
end
def messages
@file.rewind
@file.read
end
end
# ref: https://gist.github.com/bf4/8744473
class DummyApp < Rails::Application
# Set up production configuration
config.eager_load = true
config.cache_classes = true
# CONFIG: CACHE_ON={on,off}
config.action_controller.perform_caching = ENV['CACHE_ON'] != 'off'
config.action_controller.cache_store = ActiveSupport::Cache.lookup_store(:memory_store)
config.active_support.test_order = :random
config.secret_token = 'S' * 30
config.secret_key_base = 'abc123'
config.consider_all_requests_local = false
# otherwise deadlock occured
config.middleware.delete 'Rack::Lock'
# to disable log files
config.logger = NullLogger.new
config.active_support.deprecation = :log
config.log_level = :info
end
require 'active_model_serializers'
# Initialize app before any serializers are defined, for running across revisions.
# ref: https://github.com/rails-api/active_model_serializers/pull/1478
Rails.application.initialize!
# HACK: Serializer::cache depends on the ActionController-dependent configs being set.
ActiveSupport.on_load(:action_controller) do
require_relative 'fixtures'
end
require_relative 'controllers'

View File

@ -0,0 +1,66 @@
require 'benchmark/ips'
require 'json'
# Add benchmarking runner from ruby-bench-suite
# https://github.com/ruby-bench/ruby-bench-suite/blob/master/rails/benchmarks/support/benchmark_rails.rb
module Benchmark
module ActiveModelSerializers
module TestMethods
def request(method, path)
response = Rack::MockRequest.new(DummyApp).send(method, path)
if response.status.in?([404, 500])
fail "omg, #{method}, #{path}, '#{response.status}', '#{response.body}'"
end
response
end
end
# extend Benchmark with an `ams` method
def ams(label = nil, time:, disable_gc: true, warmup: 3, &block)
fail ArgumentError.new, 'block should be passed' unless block_given?
if disable_gc
GC.disable
else
GC.enable
end
report = Benchmark.ips(time, warmup, true) do |x|
x.report(label) { yield }
end
entry = report.entries.first
output = {
label: label,
version: ::ActiveModel::Serializer::VERSION.to_s,
iterations_per_second: entry.ips,
iterations_per_second_standard_deviation: entry.stddev_percentage,
total_allocated_objects_per_iteration: count_total_allocated_objects(&block)
}.to_json
puts output
output
end
def count_total_allocated_objects
if block_given?
key =
if RUBY_VERSION < '2.2'
:total_allocated_object
else
:total_allocated_objects
end
before = GC.stat[key]
yield
after = GC.stat[key]
after - before
else
-1
end
end
end
extend Benchmark::ActiveModelSerializers
end

116
test/dummy/bm_caching.rb Normal file
View File

@ -0,0 +1,116 @@
require_relative './benchmarking_support'
require_relative './app'
# https://github.com/ruby-bench/ruby-bench-suite/blob/8ad567f7e43a044ae48c36833218423bb1e2bd9d/rails/benchmarks/actionpack_router.rb
class ApiAssertion
include Benchmark::ActiveModelSerializers::TestMethods
BadRevisionError = Class.new(StandardError)
def valid?
caching = get_caching
caching[:body].delete('meta')
non_caching = get_non_caching
non_caching[:body].delete('meta')
assert_responses(caching, non_caching)
rescue BadRevisionError => e
msg = { error: e.message }
STDERR.puts msg
STDOUT.puts msg
exit 1
end
def get_status(on_off = 'on'.freeze)
get("/status/#{on_off}")
end
def clear
get('/clear')
end
def get_caching(on_off = 'on'.freeze)
get("/caching/#{on_off}")
end
def get_non_caching(on_off = 'on'.freeze)
get("/non_caching/#{on_off}")
end
private
def assert_responses(caching, non_caching)
assert_equal(caching[:code], 200, "Caching response failed: #{caching}")
assert_equal(caching[:body], expected, "Caching response format failed: \n+ #{caching[:body]}\n- #{expected}")
assert_equal(caching[:content_type], 'application/json; charset=utf-8', "Caching response content type failed: \n+ #{caching[:content_type]}\n- application/json")
assert_equal(non_caching[:code], 200, "Non caching response failed: #{non_caching}")
assert_equal(non_caching[:body], expected, "Non Caching response format failed: \n+ #{non_caching[:body]}\n- #{expected}")
assert_equal(non_caching[:content_type], 'application/json; charset=utf-8', "Non caching response content type failed: \n+ #{non_caching[:content_type]}\n- application/json")
end
def get(url)
response = request(:get, url)
{ code: response.status, body: JSON.load(response.body), content_type: response.content_type }
end
def expected
@expected ||=
{
'post' => {
'id' => 1337,
'title' => 'New Post',
'body' => 'Body',
'comments' => [
{
'id' => 1,
'body' => 'ZOMG A COMMENT'
}
],
'blog' => {
'id' => 999,
'name' => 'Custom blog'
},
'author' => {
'id' => 42,
'name' => 'Joao Moura.'
}
}
}
end
def assert_equal(expected, actual, message)
return true if expected == actual
if ENV['FAIL_ASSERTION'] =~ /\Atrue|on|0\z/i # rubocop:disable Style/GuardClause
fail BadRevisionError, message
else
STDERR.puts message unless ENV['SUMMARIZE']
end
end
def debug(msg = '')
if block_given? && ENV['DEBUG'] =~ /\Atrue|on|0\z/i
STDERR.puts yield
else
STDERR.puts msg
end
end
end
assertion = ApiAssertion.new
assertion.valid?
# STDERR.puts assertion.get_status
time = 10
{
'caching on: caching serializers: gc off' => { disable_gc: true, send: [:get_caching, 'on'] },
# 'caching on: caching serializers: gc on' => { disable_gc: false, send: [:get_caching, 'on'] },
'caching off: caching serializers: gc off' => { disable_gc: true, send: [:get_caching, 'off'] },
# 'caching off: caching serializers: gc on' => { disable_gc: false, send: [:get_caching, 'off'] },
'caching on: non-caching serializers: gc off' => { disable_gc: true, send: [:get_non_caching, 'on'] },
# 'caching on: non-caching serializers: gc on' => { disable_gc: false, send: [:get_non_caching, 'on'] },
'caching off: non-caching serializers: gc off' => { disable_gc: true, send: [:get_non_caching, 'off'] }
# 'caching off: non-caching serializers: gc on' => { disable_gc: false, send: [:get_non_caching, 'off'] }
}.each do |label, options|
assertion.clear
Benchmark.ams(label, time: time, disable_gc: options[:disable_gc]) do
assertion.send(*options[:send])
end
# STDERR.puts assertion.get_status(options[:send][-1])
end

3
test/dummy/config.ru Normal file
View File

@ -0,0 +1,3 @@
require File.expand_path(['..', 'app'].join(File::SEPARATOR), __FILE__)
run Rails.application

77
test/dummy/controllers.rb Normal file
View File

@ -0,0 +1,77 @@
class PostController < ActionController::Base
POST =
begin
if ENV['BENCH_STRESS']
comments = (0..50).map do |i|
Comment.new(id: i, body: 'ZOMG A COMMENT')
end
else
comments = [Comment.new(id: 1, body: 'ZOMG A COMMENT')]
end
author = Author.new(id: 42, name: 'Joao Moura.')
Post.new(id: 1337, title: 'New Post', blog: nil, body: 'Body', comments: comments, author: author)
end
def render_with_caching_serializer
toggle_cache_status
render json: POST, serializer: CachingPostSerializer, adapter: :json, meta: { caching: perform_caching }
end
def render_with_non_caching_serializer
toggle_cache_status
render json: POST, adapter: :json, meta: { caching: perform_caching }
end
def render_cache_status
toggle_cache_status
# Uncomment to debug
# STDERR.puts cache_store.class
# STDERR.puts cache_dependencies
# ActiveSupport::Cache::Store.logger.debug [ActiveModelSerializers.config.cache_store, ActiveModelSerializers.config.perform_caching, CachingPostSerializer._cache, perform_caching, params].inspect
render json: { caching: perform_caching, meta: { cache_log: cache_messages, cache_status: cache_status } }.to_json
end
def clear
ActionController::Base.cache_store.clear
# Test caching is on
# Uncomment to turn on logger; possible performance issue
# logger = DummyLogger.new
# ActiveSupport::Cache::Store.logger = logger # seems to be the best way
#
# the below is used in some rails tests but isn't available/working in all versions, so far as I can tell
# https://github.com/rails/rails/pull/15943
# ActiveSupport::Notifications.subscribe(/^cache_(.*)\.active_support$/) do |*args|
# logger.debug ActiveSupport::Notifications::Event.new(*args)
# end
render json: 'ok'.to_json
end
private
def cache_status
{
controller: perform_caching,
app: Rails.configuration.action_controller.perform_caching,
serializers: Rails.configuration.serializers.each_with_object({}) { |serializer, data| data[serializer.name] = serializer._cache.present? }
}
end
def cache_messages
ActiveSupport::Cache::Store.logger.is_a?(DummyLogger) && ActiveSupport::Cache::Store.logger.messages.split("\n")
end
def toggle_cache_status
case params[:on]
when 'on'.freeze then self.perform_caching = true
when 'off'.freeze then self.perform_caching = false
else nil # no-op
end
end
end
Rails.application.routes.draw do
get '/status(/:on)' => 'post#render_cache_status'
get '/clear' => 'post#clear'
get '/caching(/:on)' => 'post#render_with_caching_serializer'
get '/non_caching(/:on)' => 'post#render_with_non_caching_serializer'
end

157
test/dummy/fixtures.rb Normal file
View File

@ -0,0 +1,157 @@
Rails.configuration.serializers = []
class AuthorSerializer < ActiveModel::Serializer
attributes :id, :name
has_many :posts, embed: :ids
has_one :bio
end
Rails.configuration.serializers << AuthorSerializer
class BlogSerializer < ActiveModel::Serializer
attributes :id, :name
end
Rails.configuration.serializers << BlogSerializer
class CommentSerializer < ActiveModel::Serializer
attributes :id, :body
belongs_to :post
belongs_to :author
end
Rails.configuration.serializers << CommentSerializer
class PostSerializer < ActiveModel::Serializer
attributes :id, :title, :body
has_many :comments, serializer: CommentSerializer
belongs_to :blog, serializer: BlogSerializer
belongs_to :author, serializer: AuthorSerializer
def blog
Blog.new(id: 999, name: 'Custom blog')
end
end
Rails.configuration.serializers << PostSerializer
class CachingAuthorSerializer < AuthorSerializer
cache key: 'writer', only: [:name], skip_digest: true
end
Rails.configuration.serializers << CachingAuthorSerializer
class CachingCommentSerializer < CommentSerializer
cache expires_in: 1.day, skip_digest: true
end
Rails.configuration.serializers << CachingCommentSerializer
class CachingPostSerializer < PostSerializer
cache key: 'post', expires_in: 0.1, skip_digest: true
belongs_to :blog, serializer: BlogSerializer
belongs_to :author, serializer: CachingAuthorSerializer
has_many :comments, serializer: CachingCommentSerializer
end
Rails.configuration.serializers << CachingPostSerializer
if ENV['ENABLE_ACTIVE_RECORD'] == 'true'
require 'active_record'
ActiveRecord::Base.establish_connection(adapter: 'sqlite3', database: ':memory:')
ActiveRecord::Schema.define do
self.verbose = false
create_table :blogs, force: true do |t|
t.string :name
t.timestamps null: false
end
create_table :authors, force: true do |t|
t.string :name
t.timestamps null: false
end
create_table :posts, force: true do |t|
t.string :title
t.text :body
t.references :author
t.references :blog
t.timestamps null: false
end
create_table :comments, force: true do |t|
t.text :body
t.references :author
t.references :post
t.timestamps null: false
end
end
class Comment < ActiveRecord::Base
belongs_to :author
belongs_to :post
end
class Author < ActiveRecord::Base
has_many :posts
has_many :comments
end
class Post < ActiveRecord::Base
has_many :comments
belongs_to :author
belongs_to :blog
end
class Blog < ActiveRecord::Base
has_many :posts
end
else
# ActiveModelSerializers::Model is a convenient
# serializable class to inherit from when making
# serializable non-activerecord objects.
class DummyModel
include ActiveModel::Model
include ActiveModel::Serializers::JSON
attr_reader :attributes
def initialize(attributes = {})
@attributes = attributes
super
end
# Defaults to the downcased model name.
def id
attributes.fetch(:id) { self.class.name.downcase }
end
# Defaults to the downcased model name and updated_at
def cache_key
attributes.fetch(:cache_key) { "#{self.class.name.downcase}/#{id}" }
end
# Defaults to the time the serializer file was modified.
def updated_at
@updated_at ||= attributes.fetch(:updated_at) { File.mtime(__FILE__) }
end
def read_attribute_for_serialization(key)
if key == :id || key == 'id'
attributes.fetch(key) { id }
else
attributes[key]
end
end
end
class Comment < DummyModel
attr_accessor :id, :body
end
class Author < DummyModel
attr_accessor :id, :name, :posts
end
class Post < DummyModel
attr_accessor :id, :title, :body, :comments, :blog, :author
end
class Blog < DummyModel
attr_accessor :id, :name
end
end