isucon14 の1位の人のやったことを全てみて学ぶ

1位の人の全てのコミットを追うまとめ - https://github.com/takonomura/isucon14

具体的な作業

10:08 各サーバの情報などをスクリプトで自動取得し保存

10:08 nginx / mysql / systemd 系のものも取得
10:13 プロセス名を修正
10:13 netdata install
10:13 nginx.conf と site-enabled をひとまとめにして nginx.confへ

10:17 nginx 秘伝のタレ

nginx.conf

  worker_rlimit_nofile 100000

  events {
      worker_connections 4096;
  }

  http {
      open_file_cache max=100 inactive=65s;
      gzip_static on;

      log_format json escape=json '{'
          '"time":"$time_local",'
          '"host":"$remote_addr",'
          '"forwardedfor":"$http_x_forwarded_for",'
          '"req":"$request",'
          '"status":"$status",'
          '"method":"$request_method",'
          '"uri":"$request_uri",'
          '"body_bytes":$body_bytes_sent,'
          '"referer":"$http_referer",'
          '"ua":"$http_user_agent",'
          '"request_time":$request_time,'
          '"cache":"$upstream_http_x_cache",'
          '"runtime":"$upstream_http_x_runtime",'
          '"response_time":"$upstream_response_time",'
          '"vhost":"$host"}';
      access_log /var/log/nginx/access.log json;
  }

  server {
    listen 443 ssl default_server http2; # http2 追加
    ...
  }

  server {
    listen 443 ssl http2; # http2 追加
    ...

10:25 alp の設定ファイルを導入

設定ファイル

  # https://github.com/tkuchiki/alp/blob/main/example/config.yml
  file: /var/log/nginx/access.log
  sort: sum
  reverse: true
  query_string: true
  query_string_ignore_values: true
  output: count,2xx,4xx,5xx,method,uri,min,p50,p99,max,sum
  matching_groups:
  - '^/api/chair/rides/[0-9A-Z]+/status$'
  - '^/api/app/rides/[0-9A-Z]+/evaluation$'
  percentiles: [50, 99]
  ltsv: {}
  json: {}
  regexp: {}
  pcap: {}

10:36 sql-perfomance の設定

shell

  #!/bin/bash
  set -exuo pipefail

  . env.sh

  mysql -u"$ISUCON_DB_USER" \
          -p"$ISUCON_DB_PASSWORD" \
          --host "$ISUCON_DB_HOST" \
          --port "$ISUCON_DB_PORT" \
          "$ISUCON_DB_NAME" << EOF
  select
    SCHEMA_NAME,
    -- DIGEST,
    DIGEST_TEXT,
    COUNT_STAR,
    round(SUM_TIMER_WAIT / pow(1000,4), 3) as SUM_TIMER_WAIT_SEC,
    round(MIN_TIMER_WAIT / pow(1000,4), 3) as MIN_TIMER_WAIT_SEC,
    round(AVG_TIMER_WAIT / pow(1000,4), 3) as AVG_TIMER_WAIT_SEC,
    round(MAX_TIMER_WAIT / pow(1000,4), 3) as MAX_TIMER_WAIT_SEC,
    round(SUM_LOCK_TIME / pow(1000,4), 3) as SUM_LOCK_TIME_SEC,
    round(QUANTILE_95 / pow(1000,4), 3) as P95,
    round(QUANTILE_99 / pow(1000,4), 3) as P99,
    round(QUANTILE_999 / pow(1000,4), 3) as P999,
    SUM_ERRORS,
    SUM_WARNINGS,
    SUM_ROWS_AFFECTED,
    SUM_ROWS_SENT,
    SUM_ROWS_EXAMINED,
    SUM_CREATED_TMP_DISK_TABLES,
    SUM_CREATED_TMP_TABLES,
    SUM_SELECT_FULL_JOIN,
    SUM_SELECT_FULL_RANGE_JOIN,
    SUM_SELECT_RANGE,
    SUM_SELECT_RANGE_CHECK,
    SUM_SELECT_SCAN,
    SUM_SORT_MERGE_PASSES,
    SUM_SORT_RANGE,
    SUM_SORT_ROWS,
    SUM_SORT_SCAN,
    SUM_NO_INDEX_USED,
    SUM_NO_GOOD_INDEX_USED,
    -- round(SUM_CPU_TIME / pow(1000,4), 3) as SUM_CPU_TIME_SEC,
    round(MAX_CONTROLLED_MEMORY / pow(1024,2), 3) as MAX_CONTROLLED_MEMORY_MB,
    round(MAX_TOTAL_MEMORY / pow(1024,2), 3) as MAX_TOTAL_MEMORY_MB,
    -- COUNT_SECONDARY,
    -- FIRST_SEEN,
    -- LAST_SEEN,
    QUERY_SAMPLE_TEXT,
    -- QUERY_SAMPLE_SEEN,
    round(QUERY_SAMPLE_TIMER_WAIT / pow(1000,4), 3) as QUERY_SAMPLE_TIMER_WAIT_SEC
  from
    performance_schema.events_statements_summary_by_digest
  where
    SCHEMA_NAME != 'performance_schema'
    AND SCHEMA_NAME IS NOT NULL
  order by
    SUM_TIMER_WAIT desc
  limit
    20\G
  EOF

10:38 log rotate sh の設定

script

  #!/bin/bash
  set -e

  cd "$HOME"
  mkdir -p logs
  TIMESTAMP=$(date +%H%M%S)

  for f in /var/log/nginx/{access,error}.log /var/log/mysql/mysql-slow.log; do
    if sudo test -f "$f"; then
      output="logs/$(basename "$f")"
      output="${output/%.log/.$TIMESTAMP.log}"
      echo mv "$f" "$output"
      sudo mv "$f" "$output"
      sudo chown $USER:$USER "$output"
      gzip "$output"
    fi
  done

  if sudo systemctl is-active "mysql.service" >/dev/null; then
    sudo mysql -uroot -e "TRUNCATE TABLE performance_schema.events_statements_summary_by_digest;"
  fi

10:53 chair に index をはる
- CREATE INDEX idx_chairs_created_at ON chairs (created_at);
- CREATE INDEX idx_chairs_owner_id_created_at ON chairs (owner_id, created_at DESC);
11:04 performance_schema を initialize 時に削除するようにする
11:08 isu2 の情報を保存
11:12 db を分割
11:30 systemd の修正
11:36 rides に index
- CREATE INDEX idx_rides_chair_id_created_at ON rides (chair_id, created_at);
11:57 notification の polling を 500ms にする
12:10 appGetNearbyChairs の N+1 を修正
- この時、アプリロジックで持っている isActive / distance <50 をすべて解消するクエリをを書き一気に解決している。
- 一つ前の実装から13分しか経ってない。コードを読み、コードを書く速度が異常
- しかもこの時 ride の N+1 には手を入れていない
- retrieve はそのまま timeをDBから引っ張ってるだけだった。。

12:28 chairs テーブルにマッチ可能か、location に関する情報を追加する

スキーマ

  CREATE TABLE chairs
  (
    id           VARCHAR(26)  NOT NULL COMMENT '椅子ID',
    owner_id     VARCHAR(26)  NOT NULL COMMENT 'オーナーID',
    name         VARCHAR(30)  NOT NULL COMMENT '椅子の名前',
    model        TEXT         NOT NULL COMMENT '椅子のモデル',
    is_active    TINYINT(1)   NOT NULL COMMENT '配椅子受付中かどうか',
  +  is_matchable TINYINT(1)   NOT NULL COMMENT 'マッチ可能かどうか',
    access_token VARCHAR(255) NOT NULL COMMENT 'アクセストークン',
  +  latitude     INTEGER      NULL COMMENT '経度',
  +  longitude    INTEGER      NULL COMMENT '緯度',
  +  total_distance INTEGER NOT NULL,
  +  location_updated_at DATETIME(6) NULL,
    created_at   DATETIME(6)  NOT NULL DEFAULT CURRENT_TIMESTAMP(6) COMMENT '登録日時',
    updated_at   DATETIME(6)  NOT NULL DEFAULT CURRENT_TIMESTAMP(6) ON UPDATE CURRENT_TIMESTAMP(6) COMMENT '更新日時',
    PRIMARY KEY (id)
  )
    COMMENT = '椅子情報テーブル';
  CREATE INDEX idx_chairs_created_at ON chairs (created_at);

  CREATE INDEX idx_chairs_owner_id_created_at ON chairs (owner_id, created_at DESC);
  +CREATE INDEX idx_chairs_is_matchable ON chairs (is_matchable);

12:53 初期データを改造し、はじめから chair table に locatioin 情報を持っているようにする

ddl


  ALTER TABLE chairs
  ADD COLUMN latitude INTEGER COMMENT '経度' AFTER is_active,
  ADD COLUMN longitude INTEGER COMMENT '緯度' AFTER latitude,
  ADD COLUMN location_updated_at DATETIME(6) COMMENT '位置情報の更新日時' AFTER longitude;
  -- UPDATE chairs c
  -- JOIN (
  --     SELECT 
  --         cl.chair_id,
  --         cl.latitude,
  --         cl.longitude,
  --         cl.created_at AS location_updated_at
  --     FROM chair_locations cl
  --     INNER JOIN (
  --         SELECT chair_id, MAX(created_at) AS max_created_at
  --         FROM chair_locations
  --         GROUP BY chair_id
  --     ) latest
  --     ON cl.chair_id = latest.chair_id AND cl.created_at = latest.max_created_at
  -- ) latest_location
  -- ON c.id = latest_location.chair_id
  -- SET 
  --     c.latitude = latest_location.latitude,
  --     c.longitude = latest_location.longitude,
  --     c.location_updated_at = latest_location.location_updated_at;

13:00 この時点で ChairLocation を消している
- これにより chair location への insert は消えた
- insert が多いので消そう→そのためには既存のレコードに持たせれば良くね？の発想が早い

13:29 chair の is_matchable の実装

isActive(これは owner が椅子を用意できたという意味だと思う)
isFree (これは勝手に作った、ステートが COMPLETE になったことを示す）
この二つが && で true なら手配可能とする STORED カラムを作って利用
以後はこのカラムのみをみて対応している

ddl

  ADD COLUMN is_free TINYINT(1) NOT NULL DEFAULT 0 COMMENT 'マッチ中かどうか' AFTER is_active;
  -- UPDATE chairs c
  -- LEFT JOIN (
  --     SELECT
  --         r.chair_id,
  --         MAX(CASE WHEN rs.status = 'COMPLETED' THEN 1 ELSE 0 END) AS has_completed_ride
  --     FROM rides r
  --     LEFT JOIN ride_statuses rs ON r.id = rs.ride_id
  --     GROUP BY r.chair_id
  -- ) ride_data ON c.id = ride_data.chair_id
  -- SET c.is_free = CASE
  --     WHEN ride_data.chair_id IS NULL OR ride_data.has_completed_ride = 1 THEN 1
  --     ELSE 0
  -- END;
  ALTER TABLE chairs
  ADD COLUMN is_matchable TINYINT(1) AS (is_active AND is_free) STORED NOT NULL COMMENT 'マッチ可能かどうか';

13:59 マッチングアルゴリズムの修正
- とりあえず直近1台ではなく2台とってみる
14:10 binlog の停止 / 5354
14:28 prepared statement の停止

14:30 mysql innodb 設定

  innodb_buffer_pool_size = 1GB
  innodb_flush_log_at_trx_commit = 2
  innodb_flush_method = O_DIRECT

14:30 ride と chair の bulk matching / 6679
- 元々の処理は chair と1つとって、それに対してマッチさせる感じだった
- match 可能な chair と chair が null な ride を取得
- ride に対して一番最適な chair を取得しその結果を格納する
14:46 rides に index をはる
- CREATE INDEX idx_ride_statuses_ride_id_created_at ON rides (ride_id, created_at DESC);
14:47 chi logger 削除

14:53 db connection の設定

connection

  func initDB(db *sql.DB) {
      waitDB(db)
      go pollDB(db)

      db.SetConnMaxLifetime(10 * time.Second)
      db.SetMaxIdleConns(512)
      db.SetMaxOpenConns(512)
  }

  func waitDB(db *sql.DB) {
      for {
          err := db.Ping()
          if err == nil {
              return
          }

          log.Printf("Failed to ping DB: %s", err)
          log.Println("Retrying...")
          time.Sleep(time.Second)
      }
  }

  func pollDB(db *sql.DB) {
      for {
          err := db.Ping()
          if err != nil {
              log.Printf("Failed to ping DB: %s", err)
          }

          time.Sleep(time.Second)
      }
  }

14:54 db の max connection を 65535 へ / 15152
14:53 chair に index / 25228
- CREATE INDEX idx_chairs_access_token ON chairs (access_token);
15:01 evaluation を利用した処理の効率化 / 25800
- 評価をすると COMPLETE に移動することを利用し、評価があるかどうか？のチェックで rideStatus のチェックをしなくていいようにしている
- 賢すぎる
15:06 rides に index / 24639
- CREATE INDEX idx_rides_chair_id_updated_at ON rides (chair_id, updated_at DESC);
15:12 notification の polling を 500ms にする / 26572
15:16 coupon に index
- CREATE INDEX idx_coupons_used_by ON coupons (used_by);
- CREATE INDEX idx_coupons_user_id_used_by_created_at ON coupons (user_id, used_by, created_at);
- CREATE INDEX idx_coupons_user_id_code ON coupons (user_id, code);
15:34 isu3 の情報を保存
15:46 まだクライアントに送信されていない通知について、通知を送ってないものに関しては retryAfeterMs を調整する / 32809
16:17 SSE の導入 / 32809
- http.Flusher
  - http.Flusher は Go の標準ライブラリの net/http パッケージに含まれるインターフェースで、HTTP レスポンスのストリーミングをサポートするためのものです。これを使うことで、サーバーがクライアントに部分的なデータを送信した後も、接続を保持し続けることができます。
  - このようにしており、対策が完璧
```
  func chairGetNotificationSSE(w http.ResponseWriter, r *http.Request) {
      flusher, ok := w.(http.Flusher)
      if !ok {
          chairGetNotification(w, r)
          return
      }
```
  - しかも既存の実装も使いつつ、最小限の修正になっている
16:38 X-Accel-Buffering を追加 / 32926
- バッファリングを無効化すると、サーバーから送信されたデータが即座にクライアントに転送されます。これによりNginx では貯めずにすぐに転送します
16:52 signal ? / 33896
16:56 appGetNotification のリトライ頻度を 500ms へ / 51957
17:22 app notification の SSE / 56521
17:36 ssm / snapd など不要なものを止める
17:43 isuride-go.service に StartLimitInterval=0 を設定し再起動何度でもできるように
17:44 sqlx.Connect から sqlx.Open へ
- sqlx.Connect
  - アプリケーション起動時にデータベース接続が確実に確立されている必要がある場合
  - 起動時に接続エラーを検知して明確に対処したい場合。
- sqlx.Open
  - 接続が必ずしも即時必要ではなく、遅延的な接続が許容される場合。
  - データベースの使用頻度が低いアプリケーションや、接続を管理する特殊なロジックが必要な場合。
以後ベンチマークなんども

学び

自動で初期状態を取得している
nginx で最初に入れるのは数個だけ
alp の設定ファイルなんてあるのか
schema の状態を取得する設定のシェル用意してる
ログローテートしないのですぐ消えてたので良くない
appGetNearbyChairs の N+1 を探すのも、修正もクソ早い。しかも正確。 ⭐️
初期データをいじればもっと早いは確かに〜〜〜
mysql や nginx の設定を一気に入れることをしていない
bulk match は思いついたらできそうだが、書くスピードが追いついてない
結果がコミットごとに見れるのとてもいいな https://github.com/takonomura/isucon14/commit/88eae785a891255020747eb00c4e7079afe904b3
STORED なるほど・・・ is_active と is_free があるのか
評価をすると COMPLETE に移動することを利用し、評価があるかどうか？のチェックで rideStatus のチェックをしなくていいようにしている。ドキュメントからの推察力高杉　⭐️
まだクライアントに送信されていない通知の retryAfterMs の調整について、コードを理解するスピードが早すぎる
SSE についての理解度。net/http Flusher というかスピード早すぎ
X-Accel-Buffering はじめてしった
ssm / snapd などとめてなかった
StartLimitInterval=0 で何度も再起動できるようにした

フラミナル

考え方や調べたことを書き殴ります。IT技術系記事多め

isucon14 の1位の人のやったことを全てみて学ぶ

具体的な作業

学び