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

More than 5 years have passed since last update.

posted at

updated at

お前らにISUCONの負け方を教えてやる

ISUCONに出場しました。
残念ながら予選落ちでした。

今、もう一度やってみれば、予選は突破できる気がします。(どのチームも思っているとは思いますが)
なぜ予選落ちしたのか振り返りを行った結果とやってはいけないことがいくつかわかったので、
共有します。

皆さんは勝った方法やこうしておけばよかったって書いている人が多かったので、
逆に僕は確実に負けるためにやるべきことを共有します。
※タイトルは完全に煽りです。

事前準備をしない

チャットの作成をしない

  • チームメンバーでのコミュニケーションできる環境は必須です。コミュニケーションを取りづらくするために チャットを作成しないようにしましょう。

GCPの使用準備をしない

  • 今回のISUCONはGCPを使用しての出題だったのですが、GCEのインスタンスにログインできる状態を 作ってしまうと、時間のロスができないので、ログインできるまでの準備はやめときましょう。

gcp - Google Cloud Platformをローカルから利用するための準備 - Qiita
GoogleCloudPlatform - GCEのインスタンスをCloud SDK(gcloud)で追加する - Qiita

過去問を解かない

  • 過去問をやるとISUCONでのハマりどころやチューニングポイントがかなりわかってしまいます。

オンライン予選の概要を読まない

  • 今回はOSがUbuntuをいうことが記述されていたりしたので、前提条件を読むことで事前準備できたり、練習できたり してしまうので、勝つ可能性が上がってしまいます。読まないようにしましょう。

【締め切りました】ISUCON5 オンライン予選の参加登録を開始&参加チームとメンバーリスト : ISUCON公式Blog

レギュレーションは読まない

  • レギュレーションを読んでしまうとレギュレーションぎりぎりの実装を思いついたりしてしまって、 その結果、スコアが伸びる可能性があるので、読まないでおきましょう。

方針を決めない

  • 方針を決めるとチームとしてどういうふうにチューニングを行っていくかが定まってしまい、 非常に効率的な動きをしてしまう可能性が高いです。

e8a35572-9f95-9497-f424-5c2e9b2d07a3.jpeg

計測しない

  • ボトルネックとなる部分を見つけ、改善してしまうとスコアが上がってしまうので、 ボトルネックとなる部分を見つけないように計測はしないようにしましょう。

mysqlのスローログの出力は行わない

  • 以下のような設定を行うと遅いクエリが出力されてしまいます。 そういった部分はボトルネックとなっている可能性が非常に高いので、 出力するのはやめときましょう。
set global long_query_time = 0.5;
set global slow_query_log = 1;
set global slow_query_log_file = "/tmp/slow.log";
set @@global.log_queries_not_using_indexes = 1;
  • pt-query-digestを使用するとスローログのSlowクエリの統計情報、プロファイル情報が見えてしまいます。
pt-query-digest /tmp/slow.log > /tmp/digest.txt
# 230ms user time, 40ms system time, 32.43M rss, 99.63M vsz
# Current date: Sat Sep 26 12:27:04 2015
# Hostname: isucon5
# Files: /tmp/slow.log
# Overall: 21 total, 1 unique, 0.31 QPS, 0.37x concurrency _______________
# Time range: 2015-09-26 12:25:36 to 12:26:44
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time            25s   717ms      2s      1s      2s   356ms      1s
# Lock time            1ms    48us   137us    68us   103us    21us    57us
# Rows sent            210      10      10      10      10       0      10
# Rows examine      14.58k     710     712  710.76  685.39    0.00  685.39
# Query size         4.63k     225     226  225.86  223.14       0  223.14
# Profile
# Rank Query ID           Response time  Calls R/Call V/M   Item
# ==== ================== ============== ===== ====== ===== ==============
#    1 0xCE3E456E0D0EFD1C 25.1693 100.0%    21 1.1985  0.11 SELECT comments entries
# Query 1: 0.31 QPS, 0.37x concurrency, ID 0xCE3E456E0D0EFD1C at byte 0 __
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.11
# Time range: 2015-09-26 12:25:36 to 12:26:44
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count        100      21
# Exec time    100     25s   717ms      2s      1s      2s   356ms      1s
# Lock time    100     1ms    48us   137us    68us   103us    21us    57us
# Rows sent    100     210      10      10      10      10       0      10
# Rows examine 100  14.58k     710     712  710.76  685.39    0.00  685.39
# Query size   100   4.63k     225     226  225.86  223.14       0  223.14
# String:
# Databases    isucon5q
# Hosts        localhost
# Users        root
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms  #######################################
#    1s  ################################################################
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isucon5q` LIKE 'comments'\G
#    SHOW CREATE TABLE `isucon5q`.`comments`\G
#    SHOW TABLE STATUS FROM `isucon5q` LIKE 'entries'\G
#    SHOW CREATE TABLE `isucon5q`.`entries`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT c.id AS id, c.entry_id AS entry_id, c.user_id AS user_id, c.comment AS comment, c.created_at AS created_at
FROM comments c
JOIN entries e ON c.entry_id = e.id
WHERE e.user_id = '1025'
ORDER BY c.created_at DESC
LIMIT 10\G
  • 今回だと以下のようにINDEXを貼るとボトルネックが解消されてしまいます。
CREATE INDEX comments_001 ON comments(entry_id, user_id, created_at);
CREATE INDEX relations_001 ON relations(one, another, created_at);

設定後に設定を確認しない

  • いつもの場所にあるからってその場所にあるとは限りません、設定が反映されているかの 確認は行うと設定ファイルの場所が違うことに気づいてしまうので、確認作業はやめましょう。

※ mysqlの設定が反映されているかは以下のように行う

SHOW VARIABLES

nginxのアクセスログの解析は行わない。

  • アクセスログからkataribeを使用して解析を行ってしまうと /がボトルネックだってことがわかってしまいますので、アクセスログはそっとしておきましょう。
Top 20 Sort By Count
Count    Total      Mean    Stddev     Min   P50.0   P90.0   P95.0   P99.0     Max  2xx  3xx  4xx  5xx  Request
   58  137.967  2.378741  2.383782   0.000   1.364   5.102   8.451  11.961  11.961   46   12    0    0  GET / HTTP/1.1
   26   24.642  0.947769  1.514433   0.001   0.019   2.657   3.476   6.370   6.370    0   26    0    0  POST /login HTTP/1.1
   26   11.090  0.426538  0.818077   0.000   0.013   1.849   2.413   3.221   3.221   26    0    0    0  GET /login HTTP/1.1
   15   24.968  1.664533  1.372024   0.200   1.167   2.980   5.204   5.204   5.204   15    0    0    0  GET /friends HTTP/1.1
   12    1.312  0.109333  0.220687   0.000   0.007   0.555   0.644   0.644   0.644    0   12    0    0  GET /logout HTTP/1.1
    9   10.742  1.193556  1.496899   0.188   0.739   5.357   5.357   5.357   5.357    9    0    0    0  GET /footprints HTTP/1.1
    9   12.865  1.429444  1.655567   0.004   0.724   4.465   4.465   4.465   4.465    0    9    0    0  POST /diary/entry HTTP/1.1
    5    6.428  1.285600  1.108686   0.012   0.701   2.976   2.976   2.976   2.976    5    0    0    0  GET /profile/verna3128 HTTP/1.1
    4    1.919  0.479750  0.482137   0.015   0.757   1.130   1.130   1.130   1.130    3    1    0    0  GET /diary/entries/verna3128 HTTP/1.1
    3    2.855  0.951667  0.176621   0.747   0.930   1.178   1.178   1.178   1.178    3    0    0    0  GET /diary/entries/nelson_oconner3115 HTTP/1.1
    3    2.051  0.683667  0.334091   0.245   0.751   1.055   1.055   1.055   1.055    3    0    0    0  GET /diary/entries/aubree2573 HTTP/1.1
    3    2.391  0.797000  1.099584   0.009   0.030   2.352   2.352   2.352   2.352    3    0    0    0  GET /diary/entry/491143 HTTP/1.1
    3    0.013  0.004333  0.000943   0.003   0.005   0.005   0.005   0.005   0.005    2    0    1    0  GET /diary/entry/500002 HTTP/1.1
    3    1.354  0.451333  0.501273   0.081   0.113   1.160   1.160   1.160   1.160    3    0    0    0  GET /diary/entries/kadin4205 HTTP/1.1
    3    1.518  0.506000  0.613385   0.007   0.141   1.370   1.370   1.370   1.370    3    0    0    0  GET /diary/entries/margaretta963 HTTP/1.1
    3    4.974  1.658000  1.166931   0.009   2.426   2.539   2.539   2.539   2.539    3    0    0    0  GET /profile/nelson_oconner3115 HTTP/1.1
    3    3.059  1.019667  1.026465   0.002   0.632   2.425   2.425   2.425   2.425    3    0    0    0  GET /diary/entry/498580 HTTP/1.1
    3    0.443  0.147667  0.198246   0.004   0.011   0.428   0.428   0.428   0.428    3    0    0    0  GET /diary/entry/495813 HTTP/1.1
    3    0.182  0.060667  0.059129   0.013   0.025   0.144   0.144   0.144   0.144    3    0    0    0  GET /diary/entries/nat4887 HTTP/1.1
    3   11.190  3.730000  3.734361   0.006   2.349   8.835   8.835   8.835   8.835    3    0    0    0  GET /profile/gudrun262 HTTP/1.1

matsuu/kataribe

アプリケーションのプロファイリングは行わない

  • stackprofなどを使うと以下のようにコードのどの部分がボトルネックか判明してしまいます。
stackprof.log
$ ./prof.sh 
==================================
  Mode: cpu(1000)
  Samples: 2052 (0.10% miss rate)
  GC: 212 (10.33%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
       786  (38.3%)         786  (38.3%)     block in Mysql2::Client#query
      1788  (87.1%)         349  (17.0%)     block in <class:WebApp>
       339  (16.5%)         339  (16.5%)     Mysql2::Client.pseudo_bind
      1272  (62.0%)          91   (4.4%)     Isucon5::WebApp#is_friend?
        56   (2.7%)          56   (2.7%)     Rack::Request#session
       830  (40.4%)          44   (2.1%)     Mysql2::Client#query
      1196  (58.3%)          40   (1.9%)     Mysql2::Client#xquery
        34   (1.7%)          16   (0.8%)     Erubis::XmlHelper#escape_xml
        14   (0.7%)          14   (0.7%)     Isucon5::WebApp#db
        86   (4.2%)          14   (0.7%)     Isucon5::WebApp#get_user

tmm1/stackprof

最後に

  • 皆さん、この記事の内容のことを行うだけで確実にISUCONに負けることができます。 今後、ISUCONで負けたい方がいたら、参考にしていただけると幸いです。
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
110
Help us understand the problem. What are the problem?