rack-ilneprof

[euglena1215]

• そういえばuser_id_to_nameをThread.currentではなくインスタンス変数で管理していたので書き換える

[isucon@ip-172-31-21-245 ruby]$ sudo cat /var/log/lineprof.log | grep ms | sort | uniq | head -n 20
 103.5ms     2 |  256        search session, params
 104.5ms     1 |  71          user_id_to_name[id]
 104.7ms     3 |  124        @name = get_user_name session[:userId]
  50.1ms     2 |  260        search session, params
  50.1ms   969 |  135          get_friend_tweets(params[:until], friend_user_ids.map(&:to_i)).each do |row|
  50.6ms     2 |  236        @name = get_user_name session[:userId]
  51.0ms     1 |  71          user_id_to_name[id]
  51.2ms     3 |  264        @name = get_user_name session[:userId]
  51.3ms     4 |  179        user = db.xquery(%| SELECT * FROM users WHERE name = ? |, name).first
  51.8ms     1 |  175      post '/login' do
  51.8ms     2 |  260        search session, params
  51.9ms     1 |  217      post '/unfollow' do
  52.7ms     2 |  56            db.xquery(%|
  52.9ms     4 |  105          friends = db.xquery(%| SELECT * FROM friends WHERE me = ? |, user).first
  53.0ms     1 |  71          user_id_to_name[id]
  53.1ms     1 |  131        friends = get_friends(@name)
  53.2ms     3 |  124        @name = get_user_name session[:userId]
  54.9ms     2 |  87          users = db.xquery(%|
  55.2ms     2 |  256        search session, params
  55.6ms     2 |  260        search session, params

[euglena1215]

get_friend_tweetsをどうにかしないとダメみたい、一旦SELECT を消してお茶を濁してみる →ほとんどのデータ使ってるので消すのは意味なさそう

[isucon@ip-172-31-21-245 ~]$ sudo cat /var/log/lineprof.log | grep ms | sort | uniq | head -n 20
 100.5ms   998 |  135          get_friend_tweets(params[:until], friend_user_ids.map(&:to_i)).each do |row|
 108.3ms     2 |  256        search session, params
 147.5ms     1 |  71          user_id_to_name[id]
 147.7ms     3 |  124        @name = get_user_name session[:userId]
 183.2ms     2 |  167        ok = system("mysql -u root -D isuwitter < #{Dir.pwd}/../sql/seed_isutomo.sql")
 275.2ms     2 |  168        ok = system("mysql -u root -D isutomo < #{Dir.pwd}/../sql/seed_isutomo.sql")
  50.1ms     3 |  264        @name = get_user_name session[:userId]
  51.1ms  1033 |  135          get_friend_tweets(params[:until], friend_user_ids.map(&:to_i)).each do |row|
  51.6ms     1 |  71          user_id_to_name[id]
  51.8ms     3 |  124        @name = get_user_name session[:userId]
  51.9ms     1 |  71          user_id_to_name[id]
  52.0ms     1 |  93          users.each do |user|
  52.7ms     1 |  71          user_id_to_name[id]
  52.8ms     3 |  124        @name = get_user_name session[:userId]
  52.9ms     1 |  93          users.each do |user|
  52.9ms     3 |  124        @name = get_user_name session[:userId]
  53.2ms     1 |  93          users.each do |user|
  53.3ms     2 |  260        search session, params
  53.6ms     1 |  93          users.each do |user|
  53.6ms     2 |  260        search session, params

get_friend_tweetsのblockの中で一番遅いのはhtmlifyなので事前htmlifyするよう変更してみる

[isucon@ip-172-31-21-245 ~]$ sudo tail -n 1000 /var/log/lineprof.log | grep "row"
  33.5ms   717 |  135          get_friend_tweets(params[:until], friend_user_ids.map(&:to_i)).each do |row|
   4.1ms    50 |  136            row['html'] = htmlify row['text']
   0.2ms    50 |  137            row['time'] = row['created_at'].strftime '%F %T'
   1.2ms    50 |  138            row['name'] = user_id_to_name[row['user_id']]
               |  139            @tweets.push row
   0.5ms     2 |  287          rows = db.xquery(%|
   3.5ms    51 |  293        rows.each do |row|
   2.0ms    50 |  294          row['html'] = htmlify row['text']
   0.2ms    50 |  295          row['time'] = row['created_at'].strftime '%F %T'
               |  296          row['name'] = @user
               |  297          @tweets.push row
  59.2ms   612 |  135          get_friend_tweets(params[:until], friend_user_ids.map(&:to_i)).each do |row|
   2.5ms    50 |  136            row['html'] = htmlify row['text']
   0.3ms    50 |  137            row['time'] = row['created_at'].strftime '%F %T'
   1.2ms    50 |  138            row['name'] = user_id_to_name[row['user_id']]
               |  139            @tweets.push row
  22.3ms   780 |  135          get_friend_tweets(params[:until], friend_user_ids.map(&:to_i)).each do |row|
   2.1ms    50 |  136            row['html'] = htmlify row['text']
   0.2ms    50 |  137            row['time'] = row['created_at'].strftime '%F %T'
   1.2ms    50 |  138            row['name'] = user_id_to_name[row['user_id']]
               |  139            @tweets.push row
  18.9ms    52 |  241        get_all_tweets(params[:until],@query).each do |row|
   2.0ms    50 |  242          row['html'] = htmlify row['text']
   0.3ms    50 |  243          row['time'] = row['created_at'].strftime '%F %T'
   1.2ms    50 |  244          row['name'] = user_id_to_name[row['user_id']]
               |  245          @tweets.push row
  10.7ms    52 |  241        get_all_tweets(params[:until],@query).each do |row|
   2.1ms    50 |  242          row['html'] = htmlify row['text']
   0.3ms    50 |  243          row['time'] = row['created_at'].strftime '%F %T'
   1.2ms    50 |  244          row['name'] = user_id_to_name[row['user_id']]
               |  245          @tweets.push row
   0.6ms     2 |  287          rows = db.xquery(%|
   7.2ms    51 |  293        rows.each do |row|
   5.1ms    50 |  294          row['html'] = htmlify row['text']
   0.3ms    50 |  295          row['time'] = row['created_at'].strftime '%F %T'
               |  296          row['name'] = @user
               |  297          @tweets.push row
   7.4ms    52 |  241        get_all_tweets(params[:until],@query).each do |row|
   2.1ms    50 |  242          row['html'] = htmlify row['text']
   0.3ms    50 |  243          row['time'] = row['created_at'].strftime '%F %T'
   1.2ms    50 |  244          row['name'] = user_id_to_name[row['user_id']]
               |  245          @tweets.push row
  35.7ms   993 |  135          get_friend_tweets(params[:until], friend_user_ids.map(&:to_i)).each do |row|
   2.3ms    50 |  136            row['html'] = htmlify row['text']
   0.3ms    50 |  137            row['time'] = row['created_at'].strftime '%F %T'
   1.2ms    50 |  138            row['name'] = user_id_to_name[row['user_id']]
               |  139            @tweets.push row
  21.5ms    52 |  241        get_all_tweets(params[:until],@query).each do |row|
   2.3ms    50 |  242          row['html'] = htmlify row['text']
   0.3ms    50 |  243          row['time'] = row['created_at'].strftime '%F %T'
   1.2ms    50 |  244          row['name'] = user_id_to_name[row['user_id']]
               |  245          @tweets.push row
   5.7ms    52 |  241        get_all_tweets(params[:until],@query).each do |row|
   1.9ms    50 |  242          row['html'] = htmlify row['text']
   0.2ms    50 |  243          row['time'] = row['created_at'].strftime '%F %T'
   1.1ms    50 |  244          row['name'] = user_id_to_name[row['user_id']]
               |  245          @tweets.push row

[euglena1215]

[isucon@ip-172-31-21-245 ~]$ sudo cat /var/log/lineprof.log | grep ms | sort | uniq | head -n 20
 100.0ms     3 |  270        @name = get_user_name session[:userId]
 101.4ms     1 |  77          user_id_to_name[id]
 101.5ms     2 |  262        search session, params
 101.7ms     3 |  270        @name = get_user_name session[:userId]
 102.5ms     1 |  99          users.each do |user|
 104.6ms     1 |  77          user_id_to_name[id]
 104.9ms     3 |  130        @name = get_user_name session[:userId]
 105.4ms     1 |  77          user_id_to_name[id]
 105.6ms     1 |  77          user_id_to_name[id]
 105.6ms     3 |  130        @name = get_user_name session[:userId]
 105.8ms     3 |  130        @name = get_user_name session[:userId]
 110.1ms     1 |  206      post '/follow' do
 116.8ms     1 |  206      post '/follow' do
 119.3ms     1 |  206      post '/follow' do
 140.2ms     1 |  77          user_id_to_name[id]
 140.5ms     2 |  243        @name = get_user_name session[:userId]
 171.3ms     2 |  262        search session, params
 206.2ms     4 |  186        user = db.xquery(%| SELECT * FROM users WHERE name = ? |, name).first
 206.6ms     1 |  182      post '/login' do
  50.0ms   588 |  141          get_friend_tweets(params[:until], friend_user_ids.map(&:to_i)).each do |row|