1
Help us understand the problem. What are the problem?

More than 1 year has passed since last update.

ISUCON9予選感想戦

はじめに

本記事では、ISUCON9の予選問題をローカル環境で実行しながら振り返りを行います。言語はrubyで行います。

環境構築

環境構築には以下のリポジトリのVagrantfileを使用します。
https://github.com/matsuu/vagrant-isucon

本番との違いはREADME.mdにも記載のある通り、スペックと台数です。

初期実装のスコア

実装をrubyに切り替えてベンチマークを実行します。

  • 実装の切り替え
$ sudo systemctl stop    isucari.golang.service
$ sudo systemctl disable isucari.golang.service
$ sudo systemctl start   isucari.ruby.service
$ sudo systemctl enable  isucari.ruby.service
  • ベンチマークの実行

ベンチマークは本番と同様にNginxを通して実行したいので、target_urlを指定して実行します。

$ ./bin/benchmarker -target-url https://127.0.0.1

実行結果は以下の通りです。

{"pass":true,"score":2010,"campaign":0,"language":"ruby","messages":[]}

アクセスログを解析する

alp v0.4.0を使用してアクセスログの解析をします。
https://github.com/tkuchiki/alp

v1.0.0もありますが、事前準備の段階でv1.0.0が上手く動かなかったため、v0.4.0を使用しました。

$ sudo wget https://github.com/tkuchiki/alp/releases/download/v0.4.0/alp_linux_amd64.zip
$ sudo unzip alp_linux_amd64.zip
$ sudo mv alp /usr/bin/

Nginxのログをalpで解析できる形式にします。
nginx.confを修正したらNginxを再起動する必要があります。

nginx.conf
log_format ltsv "time:$time_local"
            "\thost:$remote_addr"
            "\tforwardedfor:$http_x_forwarded_for"
            "\treq:$request"
            "\tstatus:$status"
            "\tmethod:$request_method"
            "\turi:$request_uri"
            "\tsize:$body_bytes_sent"
            "\treferer:$http_referer"
            "\tua:$http_user_agent"
            "\treqtime:$request_time"
            "\tcache:$upstream_http_x_cache"
            "\truntime:$upstream_http_x_runtime"
            "\tapptime:$upstream_response_time"
            "\tvhost:$host";
access_log /var/log/nginx/access.log ltsv;

この状態で改めてベンチマークを実行し、アクセスログを解析します。
集計の正規表現はalpの結果を見ながら適当に足して行きました。

$ sudo cat /var/log/nginx/access.log | alp --aggregates="/users/\d+.json","/items/\d+.json","/new_items/\d+.json","/upload/.+.jpg","/transactions/\d+.png"

結果は以下のように表示されます。
大きな時間を取っているGET /users/transactions.jsonGET /new_items/\d+.jsonから対応していく方針になります。

+-------+--------+-------------------------------------+-----+------+-----+-----+-----+-------+-------+---------+-------+-------+-------+-------+--------+------------+------------+--------------+------------+
| COUNT | METHOD |                 URI                 | 1XX | 2XX  | 3XX | 4XX | 5XX |  MIN  |  MAX  |   SUM   |  AVG  |  P1   |  P50  |  P99  | STDDEV | MIN(BODY)  | MAX(BODY)  |  SUM(BODY)   | AVG(BODY)  |
+-------+--------+-------------------------------------+-----+------+-----+-----+-----+-------+-------+---------+-------+-------+-------+-------+--------+------------+------------+--------------+------------+
|     1 | GET    | /static/js/runtime~main.a8a9905a.js |   0 |    1 |   0 |   0 |   0 | 0.008 | 0.008 |   0.008 | 0.008 | 0.008 | 0.008 | 0.008 |  0.000 |   1502.000 |   1502.000 |     1502.000 |   1502.000 |
|    34 | GET    | /transactions/\d+.png               |   0 |   22 |   0 |  12 |   0 | 0.004 | 0.012 |   0.124 | 0.004 | 0.000 | 0.004 | 0.000 |  0.004 |     32.000 |    626.000 |    13945.000 |    410.147 |
|     1 | GET    | /reports.json                       |   0 |    1 |   0 |   0 |   0 | 0.012 | 0.012 |   0.012 | 0.012 | 0.012 | 0.012 | 0.012 |  0.000 |  94019.000 |  94019.000 |    94019.000 |  94019.000 |
|     1 | GET    | /static/js/2.ff6e1067.chunk.js      |   0 |    1 |   0 |   0 |   0 | 0.032 | 0.032 |   0.032 | 0.032 | 0.032 | 0.032 | 0.032 |  0.000 | 508459.000 | 508459.000 |   508459.000 | 508459.000 |
|     9 | POST   | /items/edit                         |   0 |    3 |   0 |   6 |   0 | 0.004 | 0.052 |   0.092 | 0.010 | 0.004 | 0.008 | 0.012 |  0.015 |     57.000 |     92.000 |      615.000 |     68.333 |
|     1 | GET    | /static/css/main.19393e92.chunk.css |   0 |    1 |   0 |   0 |   0 | 0.052 | 0.052 |   0.052 | 0.052 | 0.052 | 0.052 | 0.052 |  0.000 |    994.000 |    994.000 |      994.000 |    994.000 |
|    57 | GET    | /upload/.+.jpg                      |   0 |   57 |   0 |   0 |   0 | 0.004 | 0.128 |   1.644 | 0.029 | 0.008 | 0.024 | 0.004 |  0.025 |  51229.000 | 130127.000 |  4362729.000 |  76539.105 |
|    13 | POST   | /bump                               |   0 |   13 |   0 |   0 |   0 | 0.004 | 0.352 |   0.756 | 0.058 | 0.076 | 0.068 | 0.008 |  0.092 |     90.000 |     91.000 |     1171.000 |     90.077 |
|     1 | GET    | /static/js/main.babc3d4d.chunk.js   |   0 |    1 |   0 |   0 |   0 | 0.452 | 0.452 |   0.452 | 0.452 | 0.452 | 0.452 | 0.452 |  0.000 |  90365.000 |  90365.000 |    90365.000 |  90365.000 |
|    53 | GET    | /settings                           |   0 |   53 |   0 |   0 |   0 | 0.012 | 0.488 |   6.173 | 0.116 | 0.048 | 0.092 | 0.000 |  0.125 |   3086.000 |   3100.000 |   163919.000 |   3092.811 |
|  2207 | GET    | /items/\d+.json                     |   0 | 2206 |   0 |   1 |   0 | 0.005 | 0.517 |  16.024 | 0.007 | 0.008 | 0.004 | 0.012 |  0.019 |      0.000 |   4041.000 |  4840278.000 |   2193.148 |
|    61 | POST   | /login                              |   0 |   53 |   0 |   8 |   0 | 0.060 | 0.781 |  18.730 | 0.307 | 0.124 | 0.389 | 0.060 |  0.183 |     72.000 |    266.000 |    14293.000 |    234.311 |
|    52 | POST   | /sell                               |   0 |   34 |   0 |  18 |   0 | 0.004 | 0.820 |   5.281 | 0.102 | 0.080 | 0.000 | 0.008 |  0.204 |     12.000 |    105.000 |     1836.000 |     35.308 |
|    40 | POST   | /ship_done                          |   0 |   22 |   0 |  18 |   0 | 0.816 | 0.824 |  19.747 | 0.494 | 0.020 | 0.000 | 0.000 |  0.392 |     28.000 |     82.000 |     1602.000 |     40.050 |
|    21 | POST   | /complete                           |   0 |   20 |   0 |   1 |   0 | 0.004 | 0.876 |  14.621 | 0.696 | 0.008 | 0.828 | 0.832 |  0.287 |      0.000 |     33.000 |      660.000 |     31.429 |
|    38 | POST   | /ship                               |   0 |   26 |   0 |  12 |   0 | 0.808 | 0.937 |  19.301 | 0.508 | 0.020 | 0.820 | 0.828 |  0.398 |     28.000 |     60.000 |     1944.000 |     51.158 |
|   267 | GET    | /users/\d+.json                     |   0 |  267 |   0 |   0 |   0 | 0.008 | 1.325 |  53.977 | 0.202 | 0.168 | 0.072 | 0.120 |  0.199 |     97.000 |  23995.000 |  3711121.000 |  13899.330 |
|    51 | POST   | /buy                                |   0 |   27 |   0 |  24 |   0 | 0.000 | 2.029 |  48.036 | 0.942 | 0.004 | 1.613 | 1.640 |  0.809 |     28.000 |     48.000 |     1809.000 |     35.471 |
|   130 | GET    | /new_items.json                     |   0 |  130 |   0 |   0 |   0 | 0.048 | 2.045 |  51.348 | 0.395 | 0.508 | 0.097 | 0.188 |  0.320 |  23011.000 |  23940.000 |  3043699.000 |  23413.069 |
|   700 | GET    | /new_items/\d+.json                 |   0 |  698 |   0 |   2 |   0 | 0.028 | 2.061 | 167.766 | 0.240 | 0.088 | 0.088 | 0.148 |  0.217 |      0.000 |  24044.000 | 16387888.000 |  23411.269 |
|     1 | POST   | /initialize                         |   0 |    1 |   0 |   0 |   0 | 7.156 | 7.156 |   7.156 | 7.156 | 7.156 | 7.156 | 7.156 |  0.000 |     32.000 |     32.000 |       32.000 |     32.000 |
|   160 | GET    | /users/transactions.json            |   0 |  151 |   0 |   9 |   0 | 0.028 | 7.467 | 450.698 | 2.817 | 0.384 | 2.613 | 3.492 |  1.551 |      0.000 |  30441.000 |  3087209.000 |  19295.056 |
+-------+--------+-------------------------------------+-----+------+-----+-----+-----+-------+-------+---------+-------+-------+-------+-------+--------+------------+------------+--------------+------------+

categoriesのオンメモリ化

GET /users/transactions.jsonGET /new_items/\d+.jsonの実装を確認すると、get_user_simple_by_id()get_category_by_id()が非常に気軽に呼ばれていることに気がつきます。
このうち、get_category_by_id()についてはcategoriesテーブルの更新が無いため、メモリに乗せることができます。

def get_category_by_id(category_id)
  category = categories.find{|item| item[:id] == category_id}

  return if category.nil?

  parent_category_name = if category[:parent_id] != 0
    parent_category = get_category_by_id(category[:parent_id])

    return if parent_category.nil?

    parent_category['category_name']
  end

  {
    'id' => category[:id],
    'parent_id' => category[:parent_id],
    'category_name' => category[:category_name],
    'parent_category_name' => parent_category_name
  }
end

def categories
  [
    {:id => 1, :parent_id => 0, :category_name => "ソファー"},
    {:id => 2, :parent_id => 1, :category_name => "一人掛けソファー"},
    {:id => 3, :parent_id => 1, :category_name => "二人掛けソファー"},
    {:id => 4, :parent_id => 1, :category_name => "コーナーソファー"},
    {:id => 5, :parent_id => 1, :category_name => "二段ソファー"},
    {:id => 6, :parent_id => 1, :category_name => "ソファーベッド"},
    {:id => 10, :parent_id => 0, :category_name => "家庭用チェア"},
    {:id => 11, :parent_id => 10, :category_name => "スツール"},
    {:id => 12, :parent_id => 10, :category_name => "クッションスツール"},
    {:id => 13, :parent_id => 10, :category_name => "ダイニングチェア"},
    {:id => 14, :parent_id => 10, :category_name => "リビングチェア"},
    {:id => 15, :parent_id => 10, :category_name => "カウンターチェア"},
    {:id => 20, :parent_id => 0, :category_name => "キッズチェア"},
    {:id => 21, :parent_id => 20, :category_name => "学習チェア"},
    {:id => 22, :parent_id => 20, :category_name => "ベビーソファ"},
    {:id => 23, :parent_id => 20, :category_name => "キッズハイチェア"},
    {:id => 24, :parent_id => 20, :category_name => "テーブルチェア"},
    {:id => 30, :parent_id => 0, :category_name => "オフィスチェア"},
    {:id => 31, :parent_id => 30, :category_name => "デスクチェア"},
    {:id => 32, :parent_id => 30, :category_name => "ビジネスチェア"},
    {:id => 33, :parent_id => 30, :category_name => "回転チェア"},
    {:id => 34, :parent_id => 30, :category_name => "リクライニングチェア"},
    {:id => 35, :parent_id => 30, :category_name => "投擲用椅子"},
    {:id => 40, :parent_id => 0, :category_name => "折りたたみ椅子"},
    {:id => 41, :parent_id => 40, :category_name => "パイプ椅子"},
    {:id => 42, :parent_id => 40, :category_name => "木製折りたたみ椅子"},
    {:id => 43, :parent_id => 40, :category_name => "キッチンチェア"},
    {:id => 44, :parent_id => 40, :category_name => "アウトドアチェア"},
    {:id => 45, :parent_id => 40, :category_name => "作業椅子"},
    {:id => 50, :parent_id => 0, :category_name => "ベンチ"},
    {:id => 51, :parent_id => 50, :category_name => "一人掛けベンチ"},
    {:id => 52, :parent_id => 50, :category_name => "二人掛けベンチ"},
    {:id => 53, :parent_id => 50, :category_name => "アウトドア用ベンチ"},
    {:id => 54, :parent_id => 50, :category_name => "収納付きベンチ"},
    {:id => 55, :parent_id => 50, :category_name => "背もたれ付きベンチ"},
    {:id => 56, :parent_id => 50, :category_name => "ベンチマーク"},
    {:id => 60, :parent_id => 0, :category_name => "座椅子"},
    {:id => 61, :parent_id => 60, :category_name => "和風座椅子"},
    {:id => 62, :parent_id => 60, :category_name => "高座椅子"},
    {:id => 63, :parent_id => 60, :category_name => "ゲーミング座椅子"},
    {:id => 64, :parent_id => 60, :category_name => "ロッキングチェア"},
    {:id => 65, :parent_id => 60, :category_name => "座布団"},
    {:id => 66, :parent_id => 60, :category_name => "空気椅子"}
  ]
end

get_user_simple_by_idを削除

get_user_simple_by_id()get_category_by_id()と同様に非常に多く呼ばれています。
こちらはオンメモリ化は難しいので、JOINして取得するようにします。
以下に、一例としてgetNewItemsのクエリを掲載します。

SELECT
  t1.*
  ,t2.`account_name`
  ,t2.`num_sell_items`
FROM
  `items` AS t1
  INNER JOIN `users` AS t2 ON
    t1.`seller_id` = t2.`id`
WHERE
  t1.`status` IN (?, ?)
ORDER BY
  t1.`created_at` DESC, t1.`id` DESC
LIMIT
  #{ITEMS_PER_PAGE + 1}

getTransactionsのAPI呼び出し

ここからは当日できなかった修正です。
api_client.shipment_statusはtransaction_evidenceのstatusがdoneの時には呼び出す必要が無いそうです。
修正後のスコアは以下の通りです。

{"pass":true,"score":3740,"campaign":0,"language":"ruby","messages":[]}

この時点でのalpの結果は以下のようになります。

+-------+--------+-------------------------------------+-----+------+-----+-----+-----+-------+-------+---------+-------+-------+-------+-------+--------+------------+------------+--------------+------------+
| COUNT | METHOD |                 URI                 | 1XX | 2XX  | 3XX | 4XX | 5XX |  MIN  |  MAX  |   SUM   |  AVG  |  P1   |  P50  |  P99  | STDDEV | MIN(BODY)  | MAX(BODY)  |  SUM(BODY)   | AVG(BODY)  |
+-------+--------+-------------------------------------+-----+------+-----+-----+-----+-------+-------+---------+-------+-------+-------+-------+--------+------------+------------+--------------+------------+
|     1 | GET    | /static/js/2.ff6e1067.chunk.js      |   0 |    1 |   0 |   0 |   0 | 0.016 | 0.016 |   0.016 | 0.016 | 0.016 | 0.016 | 0.016 |  0.000 | 508459.000 | 508459.000 |   508459.000 | 508459.000 |
|     1 | GET    | /static/js/runtime~main.a8a9905a.js |   0 |    1 |   0 |   0 |   0 | 0.024 | 0.024 |   0.024 | 0.024 | 0.024 | 0.024 | 0.024 |  0.000 |   1502.000 |   1502.000 |     1502.000 |   1502.000 |
|     1 | GET    | /reports.json                       |   0 |    1 |   0 |   0 |   0 | 0.032 | 0.032 |   0.032 | 0.032 | 0.032 | 0.032 | 0.032 |  0.000 | 143390.000 | 143390.000 |   143390.000 | 143390.000 |
|    50 | GET    | /transactions/\d+.png               |   0 |   40 |   0 |  10 |   0 | 0.008 | 0.080 |   0.544 | 0.011 | 0.008 | 0.012 | 0.012 |  0.015 |     32.000 |    623.000 |    24890.000 |    497.800 |
|    11 | POST   | /items/edit                         |   0 |    6 |   0 |   5 |   0 | 0.004 | 0.116 |   0.304 | 0.028 | 0.028 | 0.000 | 0.048 |  0.033 |     57.000 |     92.000 |      835.000 |     75.909 |
|    56 | GET    | /upload/.+.jpg                      |   0 |   56 |   0 |   0 |   0 | 0.004 | 0.180 |   2.994 | 0.053 | 0.084 | 0.068 | 0.008 |  0.043 |  51574.000 | 146187.000 |  4706042.000 |  84036.464 |
|     1 | GET    | /static/css/main.19393e92.chunk.css |   0 |    1 |   0 |   0 |   0 | 0.192 | 0.192 |   0.192 | 0.192 | 0.192 | 0.192 | 0.192 |  0.000 |    994.000 |    994.000 |      994.000 |    994.000 |
|     1 | GET    | /static/js/main.babc3d4d.chunk.js   |   0 |    1 |   0 |   0 |   0 | 0.520 | 0.520 |   0.520 | 0.520 | 0.520 | 0.520 | 0.520 |  0.000 |  90365.000 |  90365.000 |    90365.000 |  90365.000 |
|    13 | POST   | /bump                               |   0 |   13 |   0 |   0 |   0 | 0.004 | 0.529 |   1.821 | 0.140 | 0.156 | 0.028 | 0.080 |  0.164 |     89.000 |     91.000 |     1168.000 |     89.846 |
|    52 | GET    | /settings                           |   0 |   52 |   0 |   0 |   0 | 0.008 | 0.568 |   7.472 | 0.144 | 0.044 | 0.320 | 0.040 |  0.153 |   3086.000 |   3103.000 |   160855.000 |   3093.365 |
|    60 | POST   | /login                              |   0 |   52 |   0 |   8 |   0 | 0.100 | 0.740 |  22.886 | 0.381 | 0.576 | 0.452 | 0.184 |  0.190 |     72.000 |    269.000 |    14063.000 |    234.383 |
|    55 | POST   | /ship_done                          |   0 |   39 |   0 |  16 |   0 | 0.004 | 0.896 |  33.709 | 0.613 | 0.016 | 0.004 | 0.853 |  0.360 |      0.000 |     82.000 |     2017.000 |     36.673 |
|    65 | POST   | /sell                               |   0 |   50 |   0 |  15 |   0 | 0.004 | 0.936 |   8.002 | 0.123 | 0.068 | 0.016 | 0.080 |  0.208 |     12.000 |    105.000 |     1790.000 |     27.538 |
|   390 | GET    | /users/\d+.json                     |   0 |  386 |   0 |   4 |   0 | 0.007 | 0.944 |  94.877 | 0.243 | 0.144 | 0.280 | 0.225 |  0.153 |      0.000 |  23864.000 |  5174034.000 |  13266.754 |
|    50 | POST   | /ship                               |   0 |   40 |   0 |  10 |   0 | 0.004 | 0.948 |  31.514 | 0.630 | 0.016 | 0.829 | 0.849 |  0.361 |     28.000 |     60.000 |     2720.000 |     54.400 |
|    38 | POST   | /complete                           |   0 |   37 |   0 |   1 |   0 | 0.008 | 1.117 |  30.578 | 0.805 | 0.192 | 0.844 | 0.888 |  0.228 |      0.000 |     33.000 |     1221.000 |     32.132 |
|   128 | GET    | /new_items.json                     |   0 |  128 |   0 |   0 |   0 | 0.212 | 1.509 |  69.956 | 0.547 | 0.212 | 0.372 | 0.369 |  0.185 |  22988.000 |  23744.000 |  2994285.000 |  23392.852 |
|   788 | GET    | /new_items/\d+.json                 |   0 |  785 |   0 |   3 |   0 | 0.044 | 1.857 | 214.928 | 0.273 | 0.044 | 0.112 | 0.296 |  0.148 |      0.000 |  24021.000 | 18454159.000 |  23418.984 |
|  2932 | GET    | /items/\d+.json                     |   0 | 2932 |   0 |   0 |   0 | 0.008 | 1.857 |  37.309 | 0.013 | 0.080 | 0.004 | 0.012 |  0.040 |   1851.000 |   4052.000 |  6539101.000 |   2230.253 |
|    61 | POST   | /buy                                |   0 |   41 |   0 |  20 |   0 | 0.076 | 1.865 |  70.834 | 1.161 | 0.040 | 1.725 | 1.657 |  0.754 |     28.000 |     48.000 |     2118.000 |     34.721 |
|   414 | GET    | /users/transactions.json            |   0 |  409 |   0 |   5 |   0 | 0.024 | 2.341 | 256.159 | 0.619 | 0.216 | 1.160 | 0.340 |  0.411 |      0.000 |  27197.000 |  8797561.000 |  21250.147 |
|     1 | POST   | /initialize                         |   0 |    1 |   0 |   0 |   0 | 8.213 | 8.213 |   8.213 | 8.213 | 8.213 | 8.213 | 8.213 |  0.000 |     32.000 |     32.000 |       32.000 |     32.000 |
+-------+--------+-------------------------------------+-----+------+-----+-----+-----+-------+-------+---------+-------+-------+-------+-------+--------+------------+------------+--------------+------------+

INDEXを張る

itemsテーブルのseller_idbuyer_idcreated_atにINDEXを張ってみます。

還元率を変更してみる

当日はルールへの理解が足りず着手しなかったのですが、postInitializeのレスポンスにあるcampaignの数値を変更することで負荷が上がるようです。
試しに0 → 1に変更してベンチマークを実行した結果が以下のものです。

{
  "pass": true,
  "score": 7240,
  "campaign": 1,
  "language": "ruby",
  "messages": [
    "GET /new_items.json: リクエストに失敗しました(タイムアウトしました)",
    "GET /users/transactions.json リクエストに失敗しました (user_id: 3197)(タイムアウトしました)",
    "POST /login: リクエストに失敗しました(タイムアウトしました)",
    "POST /ship: リクエストに失敗しました (item_id: 50041)(タイムアウトしました)"
  ]
}

タイムアウトが増えますが、スコアは上がっています。

まとめ

1台構成ですが、予選通過ラインに肉薄するスコアが出るようになってきました。
本番の8時間でこれらを実施するのは大変ですが、来年は予選通過できるよう精進したいと思います。

Why not register and get more from Qiita?
  1. We will deliver articles that match you
    By following users and tags, you can catch up information on technical fields that you are interested in as a whole
  2. you can read useful information later efficiently
    By "stocking" the articles you like, you can search right away
Sign upLogin
1
Help us understand the problem. What are the problem?