Chapters1 Przypadki testów wydajności
Testy wydajności Railsów to specjalny rodzaj testów integracji, przeznaczonych do benchmarkingu i profilowania kodu testowego. Wyniki badań pomagają zdiagnozować, skąd wynikają problemy z pamięcią lub prędkością aplikacji i pozwalają uzyskać głębszy obraz tych problemów.
W świeżo wygenerowanej aplikacji Rails, test/performance/browsing_test.rb zawiera przykładowy test sprawności:
require 'test_helper'
require 'performance_test_help'
# Profilowanie wyników dla każdej z metod badań jest zapisywane w tmp/performance.
class BrowsingTest < ActionController::PerformanceTest
def test_homepage
get '/'
end
end
Powyższy przykład to prosty przypadek testu skuteczności dla profilowania żądania GET do strony głównej aplikacji.
1.1 Tworzenie testów wydajnościowych
Railsy udostępniają generator o nazwie performance_test dla tworzenia nowych testów wydajności:
script/generate performance_test homepage
To tworzy homepage_test.rb w katalogu test/performance:
require 'test_helper'
require 'performance_test_help'
class HomepageTest < ActionController::PerformanceTest
# Zastąp swoim prawdziwym testem.
def test_homepage
get '/'
end
end
1.2 Przykłady
Załóżmy, że aplikacja posiada następujący kontroler i model:
# routes.rb
map.root :controller => 'home'
map.resources :posts
# home_controller.rb
class HomeController < ApplicationController
def dashboard
@users = User.last_ten(:include => :avatars)
@posts = Post.all_today
end
end
# posts_controller.rb
class PostsController < ApplicationController
def create
@post = Post.create(params[:post])
redirect_to(@post)
end
end
# post.rb
class Post < ActiveRecord::Base
before_save :recalculate_costly_stats
def slow_method
# tu odpalamy miliardy bilionów zapytań, zanudzając wszystkich wkoło
end
private
def recalculate_costly_stats
# ciężkie obliczenia CPU
end
end
1.2.1 Przykładowy Kontroler
Ponieważ wyniki badań są specjalnym rodzajem testów integracji, można w nich użyć metod get i post.
Oto test wydajności dla HomeController#dashboard i PostsController#create:
require 'test_helper'
require 'performance_test_help'
class PostPerformanceTest < ActionController::PerformanceTest
def setup
# Applikacja wymaga zalogowanego użytkownika
login_as(:lifo)
end
def test_homepage
get '/dashboard'
end
def test_creating_new_post
post '/posts', :post => { :body => 'lifo is fooling you' }
end
end
Więcej szczegółów na temat metod get i post możesz znaleźć w przewodniku Testowanie Aplikacji Rails
1.2.2 Przykładowy Model
Choć testy wydajności są testami integracyjnymi, przez co są bliżej naturalnego cyklu żądanie/odpowiedź, można dodatkowo przetestować sprawność czystego kodu modelu.
Test wydajności dla modelu Post:
require 'test_helper'
require 'performance_test_help'
class PostModelTest < ActionController::PerformanceTest
def test_creation
Post.create :body => 'still fooling you', :cost => '100'
end
def test_slow_method
# używając fixture'a posts(:awesome)
posts(:awesome).slow_method
end
end
1.3 Tryby
Testy wydajności mogą być prowadzone w dwóch trybach: benchmarkingu i profilowania.
1.3.1 Benchmarking (Analiza Porównawcza)
Benchmarking pomaga dowiedzieć się, jak szybko przebiega każdy test wydajności. Każdy przypadek badania przeprowadzany jest 4 razy w trybie analizy porównawczej.
Aby uruchomić test wydajności w trybie benchmarkingu:
$ rake test:benchmark
1.3.2 Profilowanie
Profilowanie pozwala zobaczyć szczegóły testu wydajności i zapewnieni szersze spojrzenie na części zbyt wolne i potrzebujące większej pamięci. Każdy przypadek badania przeprowadzany jest 1 raz w trybie profilowania.
Aby uruchomić test wydajności w trybie profilowania:
$ rake test:profile
1.4 Metryki
Benchmarking i profilowanie uruchamiają testy wydajności w różnych trybach opisanych poniżej.
1.4.1 Czas zegarowy
Czas zegarowy mierzy upływ czasu rzeczywistego podczas badania. Dotyczy to również wszelkich procesów jednocześnie uruchomionych na tym samym systemie.
Tryb: Benchmarking
1.4.2 Czas procesu
Czas procesu mierzy czas wykorzystany przez proces. Jest niezależny od innych procesów uruchomionych równocześnie na tym samym systemie. Dlatego też czas procesu może być stały dla danego badania skuteczności, niezależnie od obciążenia maszyny.
Tryb: Profilowanie
1.4.3 Pamięć
Pamięć mierzy ilość zużywanej pamięci dla danego przypadku testu wydajności.
Tryb: Benchmarking, profilowanie wymaga poprawionego GC Ruby
1.4.4 Obiekty
Obiekty zliczają liczbę alokowanych obiektów dla danego przypadku testu wydajności.
Tryb: Benchmarking, profilowanie wymaga poprawionego GC Ruby
1.4.5 GC Runs
GC Runs zliczają ilość wywołań GC dla danego przypadku testu wydajności.
Tryb: Benchmarking wymaga poprawionego GC Ruby
1.4.6 GC Time
GC Time mierzy upływ czasu spędzonego w GC dla danego przypadku testu wydajności.
Tryb: Benchmarking wymaga poprawionego GC Ruby
1.5 Analizowanie Wyjścia
Testy wydajności generują różne wyjścia w katalogu tmp/performance w zależności od trybu i metryki.
1.5.1 Benchmarking
W trybie benchmarkingu testy wydajności generują dwa rodzaje wyjść:
1.5.1.1 Wiersz poleceń
Jest to podstawowa forma wyjścia w trybie analizy porównawczej. Przykład:
BrowsingTest#test_homepage (31 ms warmup)
wall_time: 6 ms
memory: 437.27 KB
objects: 5514
gc_runs: 0
gc_time: 19 ms
1.5.1.2 Pliki CSV
Wyniki testów wydajności mogą był również dołączone do plików .csv wewnątrz tmp/performance. Dla przykładu, uruchomienie domyślnego BrowsingTest#test_homepage wygeneruje pięć następujących plików:
- BrowsingTest#test_homepage_gc_runs.csv
- BrowsingTest#test_homepage_gc_time.csv
- BrowsingTest#test_homepage_memory.csv
- BrowsingTest#test_homepage_objects.csv
- BrowsingTest#test_homepage_wall_time.csv
Wyniki są dopisywane do tych plików każdorazowo gdy test porównawczy zostanie uruchomiony w trybie benchmarkingu, można zatem zbierać dane przez pewien okres czasu. Może być to bardzo pomocne przy analizowaniu efektów zmian w kodu.
Przykładowe wyjście z BrowsingTest#test_homepage_wall_time.csv:
measurement,created_at,app,rails,ruby,platform
0.00738224999999992,2009-01-08T03:40:29Z,,2.3.0.master.0744148,ruby-1.8.6.110,i686-darwin9.0.0
0.00755874999999984,2009-01-08T03:46:18Z,,2.3.0.master.0744148,ruby-1.8.6.110,i686-darwin9.0.0
0.00762099999999993,2009-01-08T03:49:25Z,,2.3.0.master.0744148,ruby-1.8.6.110,i686-darwin9.0.0
0.00603075000000008,2009-01-08T04:03:29Z,,2.3.0.master.0744148,ruby-1.8.6.111,i686-darwin9.1.0
0.00619899999999995,2009-01-08T04:03:53Z,,2.3.0.master.0744148,ruby-1.8.6.111,i686-darwin9.1.0
0.00755449999999991,2009-01-08T04:04:55Z,,2.3.0.master.0744148,ruby-1.8.6.110,i686-darwin9.0.0
0.00595999999999997,2009-01-08T04:05:06Z,,2.3.0.master.0744148,ruby-1.8.6.111,i686-darwin9.1.0
0.00740450000000004,2009-01-09T03:54:47Z,,2.3.0.master.859e150,ruby-1.8.6.110,i686-darwin9.0.0
0.00603150000000008,2009-01-09T03:54:57Z,,2.3.0.master.859e150,ruby-1.8.6.111,i686-darwin9.1.0
0.00771250000000012,2009-01-09T15:46:03Z,,2.3.0.master.859e150,ruby-1.8.6.110,i686-darwin9.0.0
1.5.2 Profilowanie
W trybie profilowania, można wybrać jeden z czterech rodzajów wyjść.
1.5.2.1 Wiersz poleceń
Jest to bardzo podstawowy rodzaj wyjścia w trybie profilu:
BrowsingTest#test_homepage (58 ms warmup)
process_time: 63 ms
memory: 832.13 KB
objects: 7882
1.5.2.2 Proste (Flat)
Wyjście proste (Flat) pokazuje całkowity czas spędzony w każdej metodzie. Sprawdź dokumentację ruby prof dla dokładniejszych wyjaśnień.
1.5.2.3 Wykres (Graph)
Wyjście w postaci wykresu pokazuje, jak długo zajmuje uruchomienie każdej metody, jakie metody wywołują i jakie metody są wywoływane. Sprawdź dokumentację ruby prof dla dokładniejszych wyjaśnień.
1.5.2.4 Wyjście w postaci drzewka (Tree)
Wyjście w postaci drzewka to profilowanie informacji w formacie drzewa wywołań (calltree) wykorzystanym przez kcachegrind i podobne narzędzia.
1.6 Tuning uruchamiania testów
Domyślnie, w trybie analizy porównawczej każdy test porównawczy jest uruchamiany 4 razy i 1 raz w trybie profilowania. Jednakże, uruchamianie testów może być łatwo skonfigurowane.
konfiguracja testu wydajności nie jest jeszcze aktywna w Railsach. Jednak wkrótce się to zmieni.
1.7 Test wydajności Środowiska
Testy wydajności są uruchamiane w środowisku test. Jednak przeprowadzania testów wydajności ustawi następujące parametry konfiguracyjne:
ActionController::Base.perform_caching = true
ActiveSupport::Dependencies.mechanism = :require
Rails.logger.level = ActiveSupport::BufferedLogger::INFO
Podczas gdy ActionController::Base.perform_caching jest ustawione na true, testy wydajności będą się zachowywać podobnie jak robią to w środowisku production (produkcji).
1.8 Instalacja poprawionego GC Ruby (GC-Patched Ruby)
Aby w pełni korzystać z Railsowych testów wydajności, trzeba zbudować specjalne binaria Ruby z wykorzystaniem niektórych specjalnych uprawnień z dodatku – „GC patch":http://rubyforge.org/tracker/download.php/1814/7062/17676/3291/ruby186gc.patch do pomiaru ilości uruchomień garbage collectora/czasu i pamięci/alokacji obiektów.
Proces ten jest bardzo prosty. Jeśli nigdy wcześniej kompilowałeś binariów Ruby, podążaj za następującymi krokami, aby zbudować binaria rubiego w katalogu domowym:
1.8.1 Instalacja
Skompiluj Ruby i zastosuj następujący “GC Patch”: http://rubyforge.org/tracker/download.php/1814/7062/17676/3291/ruby186gc.patch.
1.8.2 Pobranie i wypakowanie
[lifo@null ~]$ mkdir rubygc
[lifo@null ~]$ wget <download the latest stable ruby from ftp://ftp.ruby-lang.org/pub/ruby>
[lifo@null ~]$ tar -xzvf <ruby-version.tar.gz>
[lifo@null ~]$ cd <ruby-version>
1.8.3 Zastosowanie Patcha
[lifo@null ruby-version]$ curl http://rubyforge.org/tracker/download.php/1814/7062/17676/3291/ruby186gc.patch | patch -p0
1.8.4 Konfiguracja i instalacja
Poniższy kod zainstaluje rubiego w twoim katalogu domowym w folderze /rubygc. Upewnij się, że
[lifo@null ruby-version]$ ./configure --prefix=/<homedir>/rubygc
[lifo@null ruby-version]$ make && make install
1.8.5 Przygotowanie Aliasów
Najwygodniej będzie dodać następujące wiersze w ~/.profile:
alias gcruby='~/rubygc/bin/ruby'
alias gcrake='~/rubygc/bin/rake'
alias gcgem='~/rubygc/bin/gem'
alias gcirb='~/rubygc/bin/irb'
alias gcrails='~/rubygc/bin/rails'
1.8.6 Instalacja Rubygems i Gemów Zależnych
Pobierz Rubygems i zainstaluj je ze źródła. Plik README dla Rubygem powinien zawierać niezbędne instrukcje instalacyjne.
Dodatkowo, należy zainstalować następujące gemy:
- rake
- rails
- ruby-prof
- rack
- mysql
Jeśli nie powiedzie się instalacja mysql, można spróbować zainstalować go ręcznie:
[lifo@null mysql]$ gcruby extconf.rb --with-mysql-config
[lifo@null mysql]$ make && make install
Możesz zabierać się do pracy. Nie zapomnij użyć aliasów gcruby i gcrake przy uruchamianiu testów wydajności.
2 Narzędzia wiersza poleceń
Pisanie przypadków testów wydajności może wydawać się przesadą, jeśli potrzebujesz jednorazowego testu. Railsy zapewniają dwa narzędzia linii komend, które umożliwiają szybkie i nieco niechlujne testy wydajności:
2.1 benchmarker
benchmarker jest spakowany w standardowej bibliotece Ruby Benchmark
Zastosowanie:
$ script/performance/benchmarker [times] 'Person.expensive_way' 'Person.another_expensive_way' ...
Przykłady:
$ script/performance/benchmarker 10 'Item.all' 'CouchItem.all'
Jeśli argument [times] został pominięty, dostarczone metody będą uruchomione tylko raz:
$ script/performance/benchmarker 'Item.first' 'Item.last'
2.2 profiler
profiler jest spakowany w gemie http://ruby-prof.rubyforge.org/[ruby-prof]
Zastosowanie:
$ script/performance/profiler 'Person.expensive_method(10)' [times] [flat|graph|graph_html]
Przykłady:
$ script/performance/profiler 'Item.all'
To sprofiluje Item.all w trybie działania RubyProf::WALL_TIME. Domyślnie, wypisuje na płaskie wyjście (flat uotput) do powłoki (shella).
$ script/performance/profiler 'Item.all' 10 graph
To sprofiluje 10.times { Item.all } z trybem działania RubyProf::WALL_TIME i wypisze wyjście w postaci wykresu (graph output) do powłoki (shella).
Jeśli chcesz zachować dane wyjściowe w pliku:
$ script/performance/profiler 'Item.all' 10 graph 2> graph.txt
3 Metody Helpera
Railsy zapewniają rozmaite metody helpera wewnątrz modułów Active Record, Action Controllera i Action View dla pomiaru czasu wykorzystanego przez dany fragment kodu. Metoda nazywa się benchmark() we wszystkich trzech komponentach.
3.1 Model
Project.benchmark("Creating project") do
project = Project.create("name" => "stuff")
project.create_manager("name" => "David")
project.milestones << Milestone.find(:all)
end
Taki kod benchmark załączony w bloku Project.benchmark("Creating project") do...end i wypisuje wynik do pliku dziennika:
Creating project (185.3ms)
Dla dodatkowych opcji benchmark() należy odnieść się do API docs
3.2 Kontroler (Controller)
Można użyć tej metody helpera analogicznie wewnątrz controllers
def process_projects
self.class.benchmark("Processing projects") do
Project.process(params[:project_ids])
Project.update_cached_projects
end
end
UWAGA: benchmark jest metoda klasową wewnątrz kontrolerów
3.3 Widok
Oraz w views:
<% benchmark("Showing projects partial") do %>
<%= render @projects %>
<% end %>
4 Żądanie zapisywania do logu (rejestracji)
Railsowe pliki log zawierają bardzo użyteczne informacje na temat czasu potrzebnego do obsłużenia każdego żądania. Oto typowy wpis do logu (pliku dziennika):
Processing ItemsController#index (for 127.0.0.1 at 2009-01-08 03:06:39) [GET]
Rendering template within layouts/items
Rendering items/index
Completed in 5ms (View: 2, DB: 0) | 200 OK [http://0.0.0.0/items]
W tej części interesujący jest tylko ostatni wiersz:
Completed in 5ms (View: 2, DB: 0) | 200 OK [http://0.0.0.0/items]
Dane te są dość proste do zrozumienia. Rails używa milisekund (ms) jako parametru do pomiaru czasu. Całe żądanie zajmuje 5 ms wewnątrz Rails, z czego 2 ms spędza na renderowaniu widoków i ani jedna milisekunda nie została poświęcona na komunikację z bazą danych. Można bezpieczne założyć, że pozostałe 3 ms zostały spędzone wewnątrz kontrolera.
Michał Koziarski wyjaśnia znaczenie milisekund jako parametru na interesting blog post
5 Przydatne linki
5.1 Railsowe Wtyczki i Gemy
5.2 Podstawowe narzędzia
5.3 Poradniki i dokumentacja
- ruby-prof API Documentation
- Request Profiling Railscast – nieco przestarzałe, ale również przydatne dla zrozumienia wykresów.
6 Produkty Komercyjne
Railsy mają szczęście posiadaać trzy startupy poświęcone konkretnym narzędziom działania Railsów:
7 Changelog
- 9 stycznia 2009: Kompletne przepisanie przez Pratik
- 6 września 2008: Wstępna wersja Matthew Bergmana