diff --git a/.gitignore b/.gitignore index 59c74047..263ef72b 100644 --- a/.gitignore +++ b/.gitignore @@ -1,4 +1,13 @@ -/.bundle -/tmp -/log -/public +log/ +tmp/ +.generators +.idea/ +data*.txt +result.json +ruby_prof_reports/ +.ruby-version +.rubocop.yml +/docker-valgrind-massif/ +/stackprof_reports/ +1M.json +.byebug_history diff --git a/Gemfile b/Gemfile index e20b1260..12dc5c95 100644 --- a/Gemfile +++ b/Gemfile @@ -7,20 +7,24 @@ gem 'rails', '~> 5.2.3' gem 'pg', '>= 0.18', '< 2.0' gem 'puma', '~> 3.11' gem 'bootsnap', '>= 1.1.0', require: false - +gem 'pghero' +gem 'oj' +gem 'activerecord-import' group :development, :test do # Call 'byebug' anywhere in the code to stop execution and get a debugger console gem 'byebug', platforms: [:mri, :mingw, :x64_mingw] end group :development do + gem 'rack-mini-profiler' # Access an interactive console on exception pages or by calling 'console' anywhere in the code. gem 'web-console', '>= 3.3.0' gem 'listen', '>= 3.0.5', '< 3.2' end group :test do + gem 'minitest' end # Windows does not include zoneinfo files, so bundle the tzinfo-data gem -gem 'tzinfo-data', platforms: [:mingw, :mswin, :x64_mingw, :jruby] +# gem 'tzinfo-data', platforms: [:mingw, :mswin, :x64_mingw, :jruby] diff --git a/Gemfile.lock b/Gemfile.lock index fccf6f5f..47d997e4 100644 --- a/Gemfile.lock +++ b/Gemfile.lock @@ -33,6 +33,8 @@ GEM activemodel (= 5.2.3) activesupport (= 5.2.3) arel (>= 9.0) + activerecord-import (1.0.4) + activerecord (>= 3.2) activestorage (5.2.3) actionpack (= 5.2.3) activerecord (= 5.2.3) @@ -76,9 +78,14 @@ GEM nio4r (2.3.1) nokogiri (1.10.2) mini_portile2 (~> 2.4.0) + oj (3.10.2) pg (1.1.4) + pghero (2.4.1) + activerecord (>= 5) puma (3.12.1) rack (2.0.6) + rack-mini-profiler (1.1.6) + rack (>= 1.2.0) rack-test (1.1.0) rack (>= 1.0, < 3) rails (5.2.3) @@ -134,17 +141,21 @@ PLATFORMS ruby DEPENDENCIES + activerecord-import bootsnap (>= 1.1.0) byebug listen (>= 3.0.5, < 3.2) + minitest + oj pg (>= 0.18, < 2.0) + pghero puma (~> 3.11) + rack-mini-profiler rails (~> 5.2.3) - tzinfo-data web-console (>= 3.3.0) RUBY VERSION ruby 2.6.3p62 BUNDLED WITH - 2.0.2 + 2.1.4 diff --git a/app/controllers/trips_controller.rb b/app/controllers/trips_controller.rb index acb38be2..b2b1fa06 100644 --- a/app/controllers/trips_controller.rb +++ b/app/controllers/trips_controller.rb @@ -2,6 +2,6 @@ class TripsController < ApplicationController def index @from = City.find_by_name!(params[:from]) @to = City.find_by_name!(params[:to]) - @trips = Trip.where(from: @from, to: @to).order(:start_time) + @trips = Trip.eager_load(bus: [:services]).where(from: @from, to: @to).order(:start_time).load end end diff --git a/app/models/bus.rb b/app/models/bus.rb index 1dcc54cb..1918e7d5 100644 --- a/app/models/bus.rb +++ b/app/models/bus.rb @@ -17,4 +17,15 @@ class Bus < ApplicationRecord validates :number, presence: true, uniqueness: true validates :model, inclusion: { in: MODELS } + + def self.find_cached_or_create(bus_data) + @all_buses ||= Bus.all.map{ |bus| [bus.number, bus]}.to_h + unless @all_buses[bus_data['number']] + @all_buses[bus_data['number']] ||= Bus.create!( + model: bus_data['model'], + services: Service.find_dumped(bus_data['services']), + number: bus_data['number']) + end + @all_buses[bus_data['number']] + end end diff --git a/app/models/city.rb b/app/models/city.rb index 19ec7f36..d17ab288 100644 --- a/app/models/city.rb +++ b/app/models/city.rb @@ -5,4 +5,10 @@ class City < ApplicationRecord def name_has_no_spaces errors.add(:name, "has spaces") if name.include?(' ') end + + def self.find_cached_or_create(name) + #name = name.gsub(' ','') + @all_cities ||= City.all.map{|city| [city.name, city]}.to_h + @all_cities[name] ||= City.create!(name:name) + end end diff --git a/app/models/service.rb b/app/models/service.rb index 9cbb2a32..d88c8d64 100644 --- a/app/models/service.rb +++ b/app/models/service.rb @@ -16,4 +16,18 @@ class Service < ApplicationRecord validates :name, presence: true validates :name, inclusion: { in: SERVICES } + + def self.find_dumped(names) + @all_dumped ||= dump_all_to_db + @all_dumped.slice(*names).values + end + + private + + def self.dump_all_to_db + SERVICES.sort.reverse.each do |name| + Service.find_or_create_by!(name: name) + end + Service.all.map{ |s| [s.name, s]}.to_h + end end diff --git a/app/models/trip.rb b/app/models/trip.rb index 9d63dfff..d7bed72a 100644 --- a/app/models/trip.rb +++ b/app/models/trip.rb @@ -29,4 +29,19 @@ def to_h }, } end + + def to_h_old + { + 'from' => from.name, + 'to' => to.name, + 'start_time' => start_time, + 'duration_minutes' => duration_minutes, + 'price_cents' => price_cents, + 'bus' => { + 'number' => bus.number, + 'model' => bus.model, + 'services' => bus.services.map(&:name), + }, + } + end end diff --git a/app/services/trips_load.rb b/app/services/trips_load.rb new file mode 100644 index 00000000..79a93250 --- /dev/null +++ b/app/services/trips_load.rb @@ -0,0 +1,36 @@ +class TripsLoad + + def self.perform(file_name) + json = Oj.load(File.read(file_name)) + ActiveRecord::Base.transaction do + City.delete_all + Bus.delete_all + Service.delete_all + Trip.delete_all + ActiveRecord::Base.connection.execute('delete from buses_services;') + trips_array = [] + + json.each_with_index do |trip, index| + + from = City.find_cached_or_create(trip['from']) + to = City.find_cached_or_create(trip['to']) + bus = Bus.find_cached_or_create(trip['bus']) + + trip_hash = { + from_id: from.id, + to_id: to.id, + bus_id: bus.id, + start_time: trip['start_time'], + duration_minutes: trip['duration_minutes'], + price_cents: trip['price_cents'] + } + trips_array << trip_hash + if index%1000 == 999 + Trip.import(trips_array, validate: true, validate_uniqueness: true) + trips_array =[] + end + end + Trip.import(trips_array, validate: true, validate_uniqueness: true) + end + end +end \ No newline at end of file diff --git a/app/views/trips/_services.html.erb b/app/views/trips/_services.html.erb index 2de639fc..0be503e1 100644 --- a/app/views/trips/_services.html.erb +++ b/app/views/trips/_services.html.erb @@ -1,6 +1,6 @@
  • Сервисы в автобусе:
    • diff --git a/app/views/trips/index.html.erb b/app/views/trips/index.html.erb index a60bce41..019edb52 100644 --- a/app/views/trips/index.html.erb +++ b/app/views/trips/index.html.erb @@ -2,15 +2,24 @@ <%= "Автобусы #{@from.name} – #{@to.name}" %>

    - <%= "В расписании #{@trips.count} рейсов" %> + <%= "В расписании #{@trips.size} рейсов" %>

    <% @trips.each do |trip| %> - <%= render "delimiter" %> + ==================================================== <% end %> diff --git a/case-study.db.md b/case-study.db.md new file mode 100644 index 00000000..a577a71f --- /dev/null +++ b/case-study.db.md @@ -0,0 +1,102 @@ +# Case-study оптимизации загрузки данных + +## Актуальная проблема + +Необходимо импортировать файл с данными fixtures/large.json с 100_000 трипов менее чем за 1 минуту. + +У нас уже была rake задача, которая умела делать нужную обработку. + +Но она недостаточно производительна +Так: + small.json с 1K трипов обрабатывается за 9 секунд + medium.json с 10K трипов обрабатывается за 80 секунд + +По грубым оценкам large.json с 100K трипов будет обрабатываться не менее 800 секунд. + +## Формирование метрики +Для анализа влияния изменений на скорость работы возьмем время обработки файла small.json - 9 секунд + +## Гарантия корректности работы оптимизированной программы +Для проверки корректности работы обновленной программы был написан тест, который заполнял БД данными из файла example.json, потом выгружал БД в json и сравнивал с исходным. + +## Feedback-Loop + +1. Проверка корректности работы, замер метрики, сбор отчета +2. Изучение отчетов профайлеров + +Например + rails test test/system/load_test.rb && rake reload_json"[fixtures/small.json]" && rake pghero:capture_query_stats + +## Вникаем в детали системы, чтобы найти главные точки роста + +Для того, чтобы найти "точки роста" для оптимизации я воспользовался +- pg_hero + +Вот какие проблемы удалось найти и решить + +### Находка №1 +- pg_hero показал что запросы + ```SELECT "services".* FROM "services" INNER JOIN "buses_services" ON "services"."id" = "buses_services"."service_id" WHERE "buses_services"."bus_id" = $1``` + занимают 25% времени. explain показал последовательное чтение. +- добавить индекс ```:buses_services, [:bus_id, :service_id] ``` +- значимого изменения метрики нет +- в отчете pg_hero запрос переместился с верхней строчки вниз + +### Находка №2 +- pg_hero показал что запросы ```SELECT ? AS one FROM "buses" WHERE "buses"."number" = $1 AND "buses"."id" != $2 LIMIT $3``` занимают 23% времени +- добавить индекс ```:buses, :number``` +- метрика изменилась незначительно на 0.3 секунды +- в отчете pg_hero запрос переместился с верхней строчки вниз + +### Находка №3 +- pg_hero показал что запросы ```SELECT "services".* FROM "services" WHERE "services"."name" = $1 LIMIT $2``` занимают 18% времени +- принято решение заполнить все возможные сервисы предварительно и собрать в хеш и не запрашивать бд +- метрика снизилась примерно на 1,5 секунды до 7,2 секунд +- запрос исчез из отчета + +### Находка №4 +- pg_hero показал что запросы ```SELECT "cities".* FROM "cities" WHERE "cities"."name" = $1 LIMIT $2``` занимают 12% времени +- принято решение кешировать города в хеш +- метрика снизилась до 6 секунд +- запросы стал занимать менее 0.1% времени + +### Находка №5 +- pg_hero показал что запросы + ```SELECT "services".* FROM "services" INNER JOIN "buses_services" ON "services"."id" = "buses_services"."service_id" WHERE "buses_services"."bus_id" = $1``` + занимают 47% времени. +- принято решение переписать поиск и заполнение автобуса +- метрика уменьшилась до 4,8 секунды +- запрос исчез из отчета + +### Протеситирована метрика время обработки medium.json - 21 секунда. Переходим на эту метрику + +### Находка №6 +- pg_hero показал что запросы + ```SELECT "buses".* FROM "buses" WHERE "buses"."number" = $1 LIMIT $2``` занимают 33% времени +- принято решение кешировать автобусы аналогично городам +- метрика снизилась до 14 секунд +- запрос исчез из отчета + +### Находка №7 +- pg_hero показал что запросы вставки в таблицу trip занимают 40% времени +- вставлять записи пачками +- ничего не изменилось, потому что activerecord запрограммирован вставлять по одной + +### Находка №8 +- Существует гем activerecord-import, который позволяет вставлять записи пачками +- применить гем +- метрика уменьшилась до 7 секунд +- запросы вставки в таблицу trips самые емкие по времени, но с этим ничего не поделать + +## Результаты +В результате проделанной оптимизации удалось обработать файл с данными за заданое время. Сейчас оно составляет 22 секунды. + +###Какими ещё результами можете поделиться +1. Также можно применить activerecord-import на остальные модели. +1. В rails 6 в классе ActiveRecord есть метод insert_all. +1. При необходимости быстрой работы с бд надо организовывать ее на низком уровне. + +## Защита от регрессии производительности + +Для защиты от потери достигнутого прогресса при дальнейших изменениях программы был написан тест с проверкой загрузки файла medium.json менее чем за 8 секунд. + diff --git a/case-study.view.md b/case-study.view.md new file mode 100644 index 00000000..2e070c58 --- /dev/null +++ b/case-study.view.md @@ -0,0 +1,72 @@ +# Case-study оптимизации отображения +## Актуальная проблема + +При большом объеме данных страница расписания показывается слишком медленно. + +http://localhost:3000/%D0%B0%D0%B2%D1%82%D0%BE%D0%B1%D1%83%D1%81%D1%8B/%D0%A1%D0%B0%D0%BC%D0%B0%D1%80%D0%B0/%D0%9C%D0%BE%D1%81%D0%BA%D0%B2%D0%B0 + +Для уточнения задачи были загружены данные файла fixtures/large.json +Сейчас на странице 1004 рейсов +Сейчас время отклика составляет 11_006 миллисекунд. + +Бюджет не задан четко, но время загрузки должно быть "адекватно" + +Идеальным временем зарузки страницы считаетсчя 50-100 миллисекунд. + +## Формирование метрики + +Метрикой будет время ответа сервера, записаное в его логах. Сейчас это 11 секунд. + +## Гарантия корректности работы оптимизированной программы + +Так как работа по оптимизации не должна воздействовать на содержимое страницы был написан тест сверяющий страницу до внесенных измений с новой. + +## Вникаем в детали системы, чтобы найти главные точки роста + +Для того, чтобы найти "точки роста" для оптимизации я воспользовался +- gem 'rack-mini-profiler' + +Вот какие проблемы удалось найти и решить + +### Находка №0 +- Страница загружается 11 секунд только первый раз, потом она загружается 4,5 секунд + +### Находка №1 +- rack-mini-profiler показал, что запросы для каждого trip делается дополнительный запрос по buses +- добавил eager_load для bus +- метрика именьшилась до 3,3 секунды +- Лишние запросы исчезли + +### Находка №2 +- rack-mini-profiler показал что запросы для каждого trip делается дополнительный запрос по services +- добавил eager_load для services +- метрика именьшилась до 2,4 секунды +- Лишние запросы исчезли. Осталось 4 sql запроса, из время выполнения 113 миллискунд + +### Находка №3 +- rack-mini-profiler показал что основное время занимает больше число вызово рендеринга trips/_services, который каждый раз рендерит trips/_service +- надо ускорить/упростить вызов +- метрика именьшилась до 1,1 секунды +- Лишние вызовы исчезли. + +### Находка №4 +- в процессе просмотр кода обнаружено, что для указания количества рейсов используется метод count, который делает дополнительный запрос +- загружать полностью выборку и использовать size +- метрика не изменилась +- Лишний запрос исчез. + +### Находка №5 +- rack-mini-profiler показал что основное время занимает рендеринг индекса +- просмотреть, что можно оптимизировать там. +- решено собрать всё в один файл. Новый файл занимает 25 и остается читабельным +- метрика уменьшилась первоначально до 0,6 секунды при повторных вызовах до 0,2 секунды. + +## Результаты +В результате проделанной оптимизации удалось получить страницу c 1000 рейсами менее чем за 0,6 секунды, что считааю достаточным показателем. + +## Защита от регрессии производительности +Для защиты от потери достигнутого прогресса при дальнейших изменениях программы был написан тест с проверкой загрузки индексной страницы на 100 поездках (файле medium.json) менее чем за 0.3 секунд. Ограничение пришлось огрубить,так как загрузка большего объема сильно замедлит тестирование. + +## Чем еще поделиться +1. Все ускорилось и без индекса по trips, хотя он очень просился. Эксперимент показал, что время контретно этого запроса уменьшается с 20 до 9 ms. Что для единичного запроса незначительно. + diff --git a/config/routes.rb b/config/routes.rb index a2da6a7b..92916b51 100644 --- a/config/routes.rb +++ b/config/routes.rb @@ -2,4 +2,6 @@ # For details on the DSL available within this file, see http://guides.rubyonrails.org/routing.html get "/" => "statistics#index" get "автобусы/:from/:to" => "trips#index" + + mount PgHero::Engine, at: "pghero" end diff --git a/db/migrate/20200306143220_create_pghero_query_stats.rb b/db/migrate/20200306143220_create_pghero_query_stats.rb new file mode 100644 index 00000000..fbf41263 --- /dev/null +++ b/db/migrate/20200306143220_create_pghero_query_stats.rb @@ -0,0 +1,15 @@ +class CreatePgheroQueryStats < ActiveRecord::Migration[5.2] + def change + create_table :pghero_query_stats do |t| + t.text :database + t.text :user + t.text :query + t.integer :query_hash, limit: 8 + t.float :total_time + t.integer :calls, limit: 8 + t.timestamp :captured_at + end + + add_index :pghero_query_stats, [:database, :captured_at] + end +end diff --git a/db/migrate/20200307171251_add_index_to_bus_services.rb b/db/migrate/20200307171251_add_index_to_bus_services.rb new file mode 100644 index 00000000..61d6d5fa --- /dev/null +++ b/db/migrate/20200307171251_add_index_to_bus_services.rb @@ -0,0 +1,5 @@ +class AddIndexToBusServices < ActiveRecord::Migration[5.2] + def change + add_index :buses_services, [:service_id, :bus_id] + end +end diff --git a/db/migrate/20200307174443_add_index_number_to_buses.rb b/db/migrate/20200307174443_add_index_number_to_buses.rb new file mode 100644 index 00000000..04b54561 --- /dev/null +++ b/db/migrate/20200307174443_add_index_number_to_buses.rb @@ -0,0 +1,5 @@ +class AddIndexNumberToBuses < ActiveRecord::Migration[5.2] + def change + add_index :buses, :number + end +end diff --git a/db/migrate/20200311194043_add_from_to_index_to_trips.rb b/db/migrate/20200311194043_add_from_to_index_to_trips.rb new file mode 100644 index 00000000..6bf571ef --- /dev/null +++ b/db/migrate/20200311194043_add_from_to_index_to_trips.rb @@ -0,0 +1,7 @@ +class AddFromToIndexToTrips < ActiveRecord::Migration[5.2] + disable_ddl_transaction! + + def change + add_index :trips, [:from_id, :to_id], algorithm: :concurrently + end +end diff --git a/db/schema.rb b/db/schema.rb index f6921e45..df42c848 100644 --- a/db/schema.rb +++ b/db/schema.rb @@ -10,25 +10,39 @@ # # It's strongly recommended that you check this file into your version control system. -ActiveRecord::Schema.define(version: 2019_03_30_193044) do +ActiveRecord::Schema.define(version: 2020_03_11_194043) do # These are extensions that must be enabled in order to support this database + enable_extension "pg_stat_statements" enable_extension "plpgsql" create_table "buses", force: :cascade do |t| t.string "number" t.string "model" + t.index ["number"], name: "index_buses_on_number" end create_table "buses_services", force: :cascade do |t| t.integer "bus_id" t.integer "service_id" + t.index ["service_id", "bus_id"], name: "index_buses_services_on_service_id_and_bus_id" end create_table "cities", force: :cascade do |t| t.string "name" end + create_table "pghero_query_stats", force: :cascade do |t| + t.text "database" + t.text "user" + t.text "query" + t.bigint "query_hash" + t.float "total_time" + t.bigint "calls" + t.datetime "captured_at" + t.index ["database", "captured_at"], name: "index_pghero_query_stats_on_database_and_captured_at" + end + create_table "services", force: :cascade do |t| t.string "name" end @@ -40,6 +54,7 @@ t.integer "duration_minutes" t.integer "price_cents" t.integer "bus_id" + t.index ["from_id", "to_id"], name: "index_trips_on_from_id_and_to_id" end end diff --git a/lib/tasks/pghero.rake b/lib/tasks/pghero.rake new file mode 100644 index 00000000..a8c133f6 --- /dev/null +++ b/lib/tasks/pghero.rake @@ -0,0 +1,5 @@ +desc 'Очистка запросов в pg_hero' +task :empty_pghero_query_stats => :environment do + # puts ActiveRecord::Base.connection.execute('delete from pg_statements').inspect + puts ActiveRecord::Base.connection.execute('delete from pghero_query_stats').inspect +end \ No newline at end of file diff --git a/lib/tasks/utils.rake b/lib/tasks/utils.rake index 540fe871..4932de94 100644 --- a/lib/tasks/utils.rake +++ b/lib/tasks/utils.rake @@ -1,34 +1,9 @@ # Наивная загрузка данных из json-файла в БД # rake reload_json[fixtures/small.json] -task :reload_json, [:file_name] => :environment do |_task, args| - json = JSON.parse(File.read(args.file_name)) - - ActiveRecord::Base.transaction do - City.delete_all - Bus.delete_all - Service.delete_all - Trip.delete_all - ActiveRecord::Base.connection.execute('delete from buses_services;') - json.each do |trip| - from = City.find_or_create_by(name: trip['from']) - to = City.find_or_create_by(name: trip['to']) - services = [] - trip['bus']['services'].each do |service| - s = Service.find_or_create_by(name: service) - services << s - end - bus = Bus.find_or_create_by(number: trip['bus']['number']) - bus.update(model: trip['bus']['model'], services: services) - - Trip.create!( - from: from, - to: to, - bus: bus, - start_time: trip['start_time'], - duration_minutes: trip['duration_minutes'], - price_cents: trip['price_cents'], - ) - end - end +desc 'Загрузка данных из файла' +task :reload_json, [:file_name] => :environment do |_task, args| + time1 = Time.now + TripsLoad.perform(args.file_name) + puts "Imported in #{Time.now - time1}" end diff --git a/test/integration/trips_index_test.rb b/test/integration/trips_index_test.rb new file mode 100644 index 00000000..dac6a6ac --- /dev/null +++ b/test/integration/trips_index_test.rb @@ -0,0 +1,9 @@ +require 'test_helper' + +class TripsIndexTest < ActionDispatch::IntegrationTest + test "Index for 100 trips in 0.3 second" do + TripsLoad.perform('fixtures/medium.json') + total = Benchmark.measure{ get URI.escape('/автобусы/Самара/Москва') }.total + assert(total < 0.3) + end +end diff --git a/test/system/load_test.rb b/test/system/load_test.rb new file mode 100644 index 00000000..6e2fbed4 --- /dev/null +++ b/test/system/load_test.rb @@ -0,0 +1,16 @@ +require 'test_helper' +require 'json' + +class TestLoad < ActiveSupport::TestCase + def test_correct_load + source_json = JSON.load(File.read('fixtures/example.json')) + system 'bin/rake reload_json[fixtures/example.json]' + result_json = Trip.all.order(:id).map(&:to_h_old) + assert_equal source_json, result_json + end + + def test_perfomance_load + total = Benchmark.measure{ system 'bin/rake reload_json[fixtures/medium.json]'}.total + assert(total < 8) + end +end \ No newline at end of file