From 4fdb4149af4d3ae87fe705561cce224e7f36258c Mon Sep 17 00:00:00 2001 From: Yosi Attias Date: Fri, 3 Mar 2017 15:10:52 +0200 Subject: [PATCH] Initial benchmarks Single: DefaultSerializer 26898.121201442846/ips; 76 objects ArraySerializer 4341.036271334371/ips; 346 objects ArraySerializer: each_serializer: DefaultSerializer 17288.40932750992/ips; 122 objects FlatAuthorSerializer 26483.24239241187/ips; 85 objects ArraySerializer: each_serializer: FlatAuthorSerializer 19398.298446172044/ips; 114 objects AuthorWithDefaultRelationshipsSerializer 86.69406914259615/ips; 18634 objects ArraySerializer: each_serializer: AuthorWithDefaultRelationshipsSerializer 80.46248323664165/ips; 20091 objects --- Gemfile | 4 + bin/bench | 171 +++++++++++++++++++++++++ test/benchmark/app.rb | 60 +++++++++ test/benchmark/benchmarking_support.rb | 67 ++++++++++ test/benchmark/bm_active_record.rb | 41 ++++++ test/benchmark/setup.rb | 75 +++++++++++ 6 files changed, 418 insertions(+) create mode 100755 bin/bench create mode 100644 test/benchmark/app.rb create mode 100644 test/benchmark/benchmarking_support.rb create mode 100644 test/benchmark/bm_active_record.rb create mode 100644 test/benchmark/setup.rb diff --git a/Gemfile b/Gemfile index d5d669a1..ef4e6445 100644 --- a/Gemfile +++ b/Gemfile @@ -45,6 +45,10 @@ tzinfo_platforms = @windows_platforms tzinfo_platforms += [:jruby] if version >= '4.1' gem 'tzinfo-data', platforms: tzinfo_platforms +group :bench do + gem 'benchmark-ips', '>= 2.7.2' +end + group :test do gem 'sqlite3', platform: (@windows_platforms + [:ruby]) gem 'activerecord-jdbcsqlite3-adapter', platform: :jruby diff --git a/bin/bench b/bin/bench new file mode 100755 index 00000000..8e8d5a49 --- /dev/null +++ b/bin/bench @@ -0,0 +1,171 @@ +#!/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', 'benchmark') } + 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 ', 'Benchmark name pattern') do |value| + options[:pattern] = value.split(',') + end + + opts.on('-e', '--env ', '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['rails_version'] = runs_output.first['rails_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__ diff --git a/test/benchmark/app.rb b/test/benchmark/app.rb new file mode 100644 index 00000000..e8b89b3b --- /dev/null +++ b/test/benchmark/app.rb @@ -0,0 +1,60 @@ +# 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 BenchmarkLogger < 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 BenchmarkApp < 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 occurred + 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! + diff --git a/test/benchmark/benchmarking_support.rb b/test/benchmark/benchmarking_support.rb new file mode 100644 index 00000000..dd27f6c5 --- /dev/null +++ b/test/benchmark/benchmarking_support.rb @@ -0,0 +1,67 @@ +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(BenchmarkApp).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, + rails_version: ::Rails.version.to_s, + iterations_per_second: entry.ips, + iterations_per_second_standard_deviation: entry.error_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 diff --git a/test/benchmark/bm_active_record.rb b/test/benchmark/bm_active_record.rb new file mode 100644 index 00000000..64355e42 --- /dev/null +++ b/test/benchmark/bm_active_record.rb @@ -0,0 +1,41 @@ +require_relative './benchmarking_support' +require_relative './app' +require_relative './setup' + +time = 10 +disable_gc = true + + + +authors_query = Author.preload(:posts).preload(:profile) +author = authors_query.first +authors = authors_query.to_a + + +Benchmark.ams('Single: DefaultSerializer', time: time, disable_gc: disable_gc) do + ActiveModel::DefaultSerializer.new(author).to_json +end + +Benchmark.ams('ArraySerializer', time: time, disable_gc: disable_gc) do + ActiveModel::ArraySerializer.new(authors).to_json +end + +Benchmark.ams('ArraySerializer: each_serializer: DefaultSerializer', time: time, disable_gc: disable_gc) do + ActiveModel::ArraySerializer.new(authors, each_serializer:ActiveModel::DefaultSerializer).to_json +end + +Benchmark.ams('FlatAuthorSerializer', time: time, disable_gc: disable_gc) do + FlatAuthorSerializer.new(author).to_json +end + +Benchmark.ams('ArraySerializer: each_serializer: FlatAuthorSerializer', time: time, disable_gc: disable_gc) do + ActiveModel::ArraySerializer.new(authors, each_serializer: FlatAuthorSerializer).to_json +end + +Benchmark.ams('AuthorWithDefaultRelationshipsSerializer', time: time, disable_gc: disable_gc) do + AuthorWithDefaultRelationshipsSerializer.new(author).to_json +end + +Benchmark.ams('ArraySerializer: each_serializer: AuthorWithDefaultRelationshipsSerializer', time: time, disable_gc: disable_gc) do + ActiveModel::ArraySerializer.new(authors, each_serializer: AuthorWithDefaultRelationshipsSerializer).to_json +end diff --git a/test/benchmark/setup.rb b/test/benchmark/setup.rb new file mode 100644 index 00000000..341d134e --- /dev/null +++ b/test/benchmark/setup.rb @@ -0,0 +1,75 @@ +########################################### +# Setup active record models +########################################## +require 'active_record' +require 'sqlite3' + + +# Change the following to reflect your database settings +ActiveRecord::Base.establish_connection( + adapter: 'sqlite3', + database: ':memory:' +) + +# Don't show migration output when constructing fake db +ActiveRecord::Migration.verbose = false + +ActiveRecord::Schema.define do + create_table :authors, force: true do |t| + t.string :name + end + + create_table :posts, force: true do |t| + t.text :body + t.string :title + t.references :author + end + + create_table :profiles, force: true do |t| + t.text :project_url + t.text :bio + t.date :birthday + t.references :author + end +end + +class Author < ActiveRecord::Base + has_one :profile + has_many :posts +end + +class Post < ActiveRecord::Base + belongs_to :author +end + +class Profile < ActiveRecord::Base + belongs_to :author +end + +# Build out the data to serialize +author = Author.create(name: 'Preston Sego') +Profile.create(project_url: 'https://github.com/NullVoxPopuli', author: author) +50.times do + Post.create( + body: 'something about how password restrictions are evil, and less secure, and with the math to prove it.', + title: 'Your bank is does not know how to do security', + author: author + ) +end + +ActiveModel::Serializer.root = false +ActiveModel::ArraySerializer.root = false + +class FlatAuthorSerializer < ActiveModel::Serializer + attributes :id, :name +end + +class AuthorWithDefaultRelationshipsSerializer < ActiveModel::Serializer + attributes :id, :name + + has_one :profile + has_many :posts +end + +# For debugging SQL output +#ActiveRecord::Base.logger = Logger.new(STDERR)