reading log files

I once worked in a company where the default environment.rb deactivated the log file, and I guess it was just because the were bored by long lines of output they didn’t want to read. The sweet advantages of having a DB admin who checks your db queries before they go live.

general facts and hints

First of all: The less lines per request the better. If you see lines that basically repeat, maybe only some id being different, then you have a problem and should think about eager loading, counter caches and other optimizations. Partial caching for sidebar elements might also be a possibility.

A few example log lines

In the example posted at railsforum.com there are four database queries, one on topics, three on posts (of which one is most likely a find_by_sql or count_by_sql ?). We only have to look at the Load lines, the Cache lines are totally ok unless they come in dozens or hunderts. It takes ActiveRecord some time to generate a final sql query, so try to cache common objects e.g. in an instance variable (See railscast #1) and reduce the Cache lines.

These following two lines are almost the same, time to check all related find and remove the differences so ActiveRecord can cache one of them.
1
2
Post Load (0.000185)   SELECT * FROM `posts` WHERE (topic_id = 3338) ORDER BY posts.id DESC LIMIT 1
Post Load (0.000132)   SELECT * FROM `posts` WHERE (`posts`.topic_id = 3338) ORDER BY posts.id DESC LIMIT
Do you know about counter caches? They are awesome four of three kids say. If you are in the index view and print out each topic with the number of posts then a counter cache will save you a lot of queries like this one:
1
2

SQL (0.000180)   SELECT count(*) AS count_all FROM `posts` WHERE (`posts`.topic_id = 3338)

more examples??? Please send them in.

Further logfile analysis

There are a few tools but I use only two: The RailsLogVisualizer to see which actions are called often in production mode. And I look at what the longest taking requests are. grep and sort nr are your friend, the logfile is your enemy ;) But at the end, the trick is just understanding the log, sorry about, no way around.

Thanks to a poster on railsforum.com for the idea to this blogpost.

Leave a Reply