request-log-analyzerでRailsのログを解析する
wvanbergen/request-log-analyzer
がなかなか使えそうなので、ご紹介。
how to install
gem i request-log-analyzer
how to use
ログ食わせるだけ。
$ request-log-analyzer log/development.log
遅い処理を特定するのにはいい感じ。
・Request duration - by mean
・View rendering time - by mean
・Database time - by mean
Request-log-analyzer, by Willem van Bergen and Bart ten Brinke - version 1.12.1 Website: http://railsdoctors.com development.log: 100% [==============================================================================] Time: 00:00:00 Request summary ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ Parsed lines: 1189 Skipped lines: 12 Parsed requests: 821 Skipped requests: 0 Warnings: no_current_request: 12 First request: 2011-09-25 13:14:01 Last request: 2012-02-20 21:46:09 Total time analyzed: 149 days Request distribution per hour ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 0:00 ┃ 0 hits/day ┃ 1:00 ┃ 1 hits/day ┃ ░░░░░░ 2:00 ┃ 2 hits/day ┃ ░░░░░░░░░░░░░░░░░░░░░░░░░░ 3:00 ┃ 1 hits/day ┃ ░░░░░░░░ 4:00 ┃ 1 hits/day ┃ ░ 5:00 ┃ 1 hits/day ┃ ░ 6:00 ┃ 0 hits/day ┃ 7:00 ┃ 0 hits/day ┃ 8:00 ┃ 0 hits/day ┃ 9:00 ┃ 0 hits/day ┃ 10:00 ┃ 0 hits/day ┃ 11:00 ┃ 0 hits/day ┃ 12:00 ┃ 0 hits/day ┃ 13:00 ┃ 1 hits/day ┃ ░ 14:00 ┃ 0 hits/day ┃ 15:00 ┃ 0 hits/day ┃ 16:00 ┃ 0 hits/day ┃ 17:00 ┃ 0 hits/day ┃ 18:00 ┃ 1 hits/day ┃ ░░░░░░░░░░░░░░░ 19:00 ┃ 3 hits/day ┃ ░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░ 20:00 ┃ 0 hits/day ┃ 21:00 ┃ 1 hits/day ┃ ░░░░░░ 22:00 ┃ 0 hits/day ┃ 23:00 ┃ 0 hits/day ┃ Most requested ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ #. ┃ 697 hits ┃ 84.9% ┃ ░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░ ProjectsController#list.JS ┃ 49 hits ┃ 6.0% ┃ ░░░░ ProjectsController#index.HTML ┃ 31 hits ┃ 3.8% ┃ ░░░ ProjectsController#list.HTML ┃ 30 hits ┃ 3.7% ┃ ░░ CategoriesController#show.HTML ┃ 8 hits ┃ 1.0% ┃ ░ ProjectsController#index.JS ┃ 3 hits ┃ 0.4% ┃ CategoriesController#index.HTML ┃ 1 hits ┃ 0.1% ┃ ProjectsController#most_popular.HTML ┃ 1 hits ┃ 0.1% ┃ ProjectsController#show.HTML ┃ 1 hits ┃ 0.1% ┃ HTTP methods ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ GET ┃ 821 hits ┃ 100.0% ┃ ░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░ HTTP statuses returned ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 200 ┃ 112 hits ┃ 90.3% ┃ ░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░ 500 ┃ 12 hits ┃ 9.7% ┃ ░░░░░░░░░░ ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ Request duration - by sum ┃ Hits ┃ Sum ┃ Mean ┃ StdDev ┃ Min ┃ Max ┃ 95 %tile ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ ProjectsController#index.HTML ┃ 31 ┃ 26.88s ┃ 0.87s ┃ 0.48s ┃ 0.30s ┃ 2.05s ┃ 0.30s-2.05s ProjectsController#list.JS ┃ 49 ┃ 14.31s ┃ 0.29s ┃ 0.18s ┃ 0.20s ┃ 1.49s ┃ 0.20s-1.51s ProjectsController#list.HTML ┃ 30 ┃ 9.75s ┃ 0.33s ┃ 0.24s ┃ 0.25s ┃ 1.57s ┃ 0.25s-1.58s CategoriesController#show.HTML ┃ 8 ┃ 6.19s ┃ 0.77s ┃ 0.23s ┃ 0.22s ┃ 0.91s ┃ 0.22s-0.92s ProjectsController#index.JS ┃ 3 ┃ 4.46s ┃ 1.49s ┃ 0.50s ┃ 0.91s ┃ 1.80s ┃ 0.90s-1.83s ProjectsController#most_popular.HTML ┃ 1 ┃ 1.13s ┃ 1.13s ┃ 0.00s ┃ 1.13s ┃ 1.13s ┃ 1.11s-1.15s ProjectsController#show.HTML ┃ 1 ┃ 0.71s ┃ 0.71s ┃ 0.00s ┃ 0.71s ┃ 0.71s ┃ 0.71s-0.73s CategoriesController#index.HTML ┃ 1 ┃ 0.34s ┃ 0.34s ┃ 0.00s ┃ 0.34s ┃ 0.34s ┃ 0.34s-0.35s ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ Request duration - by mean ┃ Hits ┃ Sum ┃ Mean ┃ StdDev ┃ Min ┃ Max ┃ 95 %tile ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ ProjectsController#index.JS ┃ 3 ┃ 4.46s ┃ 1.49s ┃ 0.50s ┃ 0.91s ┃ 1.80s ┃ 0.90s-1.83s ProjectsController#most_popular.HTML ┃ 1 ┃ 1.13s ┃ 1.13s ┃ 0.00s ┃ 1.13s ┃ 1.13s ┃ 1.11s-1.15s ProjectsController#index.HTML ┃ 31 ┃ 26.88s ┃ 0.87s ┃ 0.48s ┃ 0.30s ┃ 2.05s ┃ 0.30s-2.05s CategoriesController#show.HTML ┃ 8 ┃ 6.19s ┃ 0.77s ┃ 0.23s ┃ 0.22s ┃ 0.91s ┃ 0.22s-0.92s ProjectsController#show.HTML ┃ 1 ┃ 0.71s ┃ 0.71s ┃ 0.00s ┃ 0.71s ┃ 0.71s ┃ 0.71s-0.73s CategoriesController#index.HTML ┃ 1 ┃ 0.34s ┃ 0.34s ┃ 0.00s ┃ 0.34s ┃ 0.34s ┃ 0.34s-0.35s ProjectsController#list.HTML ┃ 30 ┃ 9.75s ┃ 0.33s ┃ 0.24s ┃ 0.25s ┃ 1.57s ┃ 0.25s-1.58s ProjectsController#list.JS ┃ 49 ┃ 14.31s ┃ 0.29s ┃ 0.18s ┃ 0.20s ┃ 1.49s ┃ 0.20s-1.51s ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ View rendering time - by sum ┃ Hits ┃ Sum ┃ Mean ┃ StdDev ┃ Min ┃ Max ┃ 95 %tile ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ ProjectsController#index.HTML ┃ 26 ┃ 12.66s ┃ 0.49s ┃ 0.43s ┃ 0.16s ┃ 1.74s ┃ 0.16s-1.75s ProjectsController#list.JS ┃ 49 ┃ 9.94s ┃ 0.20s ┃ 0.12s ┃ 0.13s ┃ 1.02s ┃ 0.13s-1.03s ProjectsController#list.HTML ┃ 30 ┃ 6.75s ┃ 0.22s ┃ 0.17s ┃ 0.16s ┃ 1.10s ┃ 0.16s-1.11s ProjectsController#index.JS ┃ 3 ┃ 2.46s ┃ 0.82s ┃ 0.48s ┃ 0.27s ┃ 1.11s ┃ 0.26s-1.11s ProjectsController#most_popular.HTML ┃ 1 ┃ 0.97s ┃ 0.97s ┃ 0.00s ┃ 0.97s ┃ 0.97s ┃ 0.96s-0.99s CategoriesController#index.HTML ┃ 1 ┃ 0.25s ┃ 0.25s ┃ 0.00s ┃ 0.25s ┃ 0.25s ┃ 0.25s-0.26s ProjectsController#show.HTML ┃ 1 ┃ 0.04s ┃ 0.04s ┃ 0.00s ┃ 0.04s ┃ 0.04s ┃ 0.04s-0.04s CategoriesController#show.HTML ┃ 1 ┃ 0.02s ┃ 0.02s ┃ 0.00s ┃ 0.02s ┃ 0.02s ┃ 0.02s-0.02s ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ View rendering time - by mean ┃ Hits ┃ Sum ┃ Mean ┃ StdDev ┃ Min ┃ Max ┃ 95 %tile ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ ProjectsController#most_popular.HTML ┃ 1 ┃ 0.97s ┃ 0.97s ┃ 0.00s ┃ 0.97s ┃ 0.97s ┃ 0.96s-0.99s ProjectsController#index.JS ┃ 3 ┃ 2.46s ┃ 0.82s ┃ 0.48s ┃ 0.27s ┃ 1.11s ┃ 0.26s-1.11s ProjectsController#index.HTML ┃ 26 ┃ 12.66s ┃ 0.49s ┃ 0.43s ┃ 0.16s ┃ 1.74s ┃ 0.16s-1.75s CategoriesController#index.HTML ┃ 1 ┃ 0.25s ┃ 0.25s ┃ 0.00s ┃ 0.25s ┃ 0.25s ┃ 0.25s-0.26s ProjectsController#list.HTML ┃ 30 ┃ 6.75s ┃ 0.22s ┃ 0.17s ┃ 0.16s ┃ 1.10s ┃ 0.16s-1.11s ProjectsController#list.JS ┃ 49 ┃ 9.94s ┃ 0.20s ┃ 0.12s ┃ 0.13s ┃ 1.02s ┃ 0.13s-1.03s ProjectsController#show.HTML ┃ 1 ┃ 0.04s ┃ 0.04s ┃ 0.00s ┃ 0.04s ┃ 0.04s ┃ 0.04s-0.04s CategoriesController#show.HTML ┃ 1 ┃ 0.02s ┃ 0.02s ┃ 0.00s ┃ 0.02s ┃ 0.02s ┃ 0.02s-0.02s ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ Database time - by sum ┃ Hits ┃ Sum ┃ Mean ┃ StdDev ┃ Min ┃ Max ┃ 95 %tile ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ ProjectsController#index.HTML ┃ 26 ┃ 7.64s ┃ 0.29s ┃ 0.08s ┃ 0.24s ┃ 0.66s ┃ 0.24s-0.66s ProjectsController#list.JS ┃ 49 ┃ 2.48s ┃ 0.05s ┃ 0.06s ┃ 0.04s ┃ 0.43s ┃ 0.04s-0.44s ProjectsController#list.HTML ┃ 30 ┃ 1.70s ┃ 0.06s ┃ 0.07s ┃ 0.04s ┃ 0.44s ┃ 0.04s-0.44s ProjectsController#index.JS ┃ 3 ┃ 1.59s ┃ 0.53s ┃ 0.13s ┃ 0.38s ┃ 0.61s ┃ 0.38s-0.61s CategoriesController#show.HTML ┃ 1 ┃ 0.66s ┃ 0.66s ┃ 0.00s ┃ 0.66s ┃ 0.66s ┃ 0.65s-0.67s ProjectsController#show.HTML ┃ 1 ┃ 0.53s ┃ 0.53s ┃ 0.00s ┃ 0.53s ┃ 0.53s ┃ 0.52s-0.54s ProjectsController#most_popular.HTML ┃ 1 ┃ 0.10s ┃ 0.10s ┃ 0.00s ┃ 0.10s ┃ 0.10s ┃ 0.10s-0.11s CategoriesController#index.HTML ┃ 1 ┃ 0.08s ┃ 0.08s ┃ 0.00s ┃ 0.08s ┃ 0.08s ┃ 0.08s-0.08s ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ Database time - by mean ┃ Hits ┃ Sum ┃ Mean ┃ StdDev ┃ Min ┃ Max ┃ 95 %tile ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ CategoriesController#show.HTML ┃ 1 ┃ 0.66s ┃ 0.66s ┃ 0.00s ┃ 0.66s ┃ 0.66s ┃ 0.65s-0.67s ProjectsController#index.JS ┃ 3 ┃ 1.59s ┃ 0.53s ┃ 0.13s ┃ 0.38s ┃ 0.61s ┃ 0.38s-0.61s ProjectsController#show.HTML ┃ 1 ┃ 0.53s ┃ 0.53s ┃ 0.00s ┃ 0.53s ┃ 0.53s ┃ 0.52s-0.54s ProjectsController#index.HTML ┃ 26 ┃ 7.64s ┃ 0.29s ┃ 0.08s ┃ 0.24s ┃ 0.66s ┃ 0.24s-0.66s ProjectsController#most_popular.HTML ┃ 1 ┃ 0.10s ┃ 0.10s ┃ 0.00s ┃ 0.10s ┃ 0.10s ┃ 0.10s-0.11s CategoriesController#index.HTML ┃ 1 ┃ 0.08s ┃ 0.08s ┃ 0.00s ┃ 0.08s ┃ 0.08s ┃ 0.08s-0.08s ProjectsController#list.HTML ┃ 30 ┃ 1.70s ┃ 0.06s ┃ 0.07s ┃ 0.04s ┃ 0.44s ┃ 0.04s-0.44s ProjectsController#list.JS ┃ 49 ┃ 2.48s ┃ 0.05s ┃ 0.06s ┃ 0.04s ┃ 0.43s ┃ 0.04s-0.44s Process blockers (> 1 sec duration) ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ ProjectsController#index.HTML ┃ 6 hits ┃ 54.5% ┃ ░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░ ProjectsController#index.JS ┃ 2 hits ┃ 18.2% ┃ ░░░░░░░░░░░░░ ProjectsController#most_popular.HTML ┃ 1 hits ┃ 9.1% ┃ ░░░░░░ ProjectsController#list.HTML ┃ 1 hits ┃ 9.1% ┃ ░░░░░░ ProjectsController#list.JS ┃ 1 hits ┃ 9.1% ┃ ░░░░░░ Parse warnings ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ Parsable lines were encountered without a header line before it. It could be that logging is not setup correctly for your application. Visit this website for logging configuration tips: http://github.com/wvanbergen/request-log-analyzer/wikis/configure-logging Need an expert to analyze your application? Mail to contact@railsdoctors.com or visit us at http://railsdoctors.com. ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ Thanks for using request-log-analyzer!
コンソールだと色が変わってみやすい。