見出し画像

ISUCON11(予選)に参加してきました!

株式会社ラフールでSREをしている伊藤です。弊社の技術的な取り組み等を理解してもらうために、不定期ですが技術的な事を書いています。

※SREとは、Site Reliability Engineer(サイト信頼性エンジニア)の略称で、サービスやインフラの信頼性を支えているエンジニア。

私のプロフィールについては第1回目の記事(リンク)に記載していますので、興味のある方はぜひ一読していただけると幸いです。

今回で11回目になるISUCONというイベントに個人的な取り組み(趣味?)として先日参加しましたので、自分の記録として本noteを書かさせていただきます!

※今回の記事は技術的な内容が大半ですのでご了承ください。よくわからないという方は雰囲気だけでも感じ取っていただければと思います。

そもそもISUCONとは・・・

毎年恒例、三度の飯よりチューニングを愛するエンジニア(学生含む)が丸一日8時間かけてひたすらチューニングしまくるイベントです。
予め実行委員会が課題となるWEBアプリケーションを開発し、当日参加者には使える資源としてサーバー3台が提供され、与えられた資源の中でどこまで速くできるのかを競います。

勝負の優劣をつけるスコアは、こちらも実行委員会が用意したベンチマーカーという擬似ユーザーの挙動を模したプログラムにより測定されます。
本noteでは、当日実施したことを時系列で紹介させていただきます!
(この後出てくるソースコードはあくまでもインフラエンジニアである私が書いたものですので、突っ込みどころがあるかもしれませんが、そこはご了承ください・・・)

課題アプリケーションの仕様を確認

いの一番にやるのがWEBアプリケーションの仕様確認です。
競技開始と同時にマニュアル(以下画像は抜粋)が配布されるので、まずはそれを読み込みます。

画像1

回を重ねるごとにネタ的要素が強くなり、マニュアルを読みながら思わずニヤッとしてしまいます。(ちなみに2年前のISUCON9ではメルカリさんが問題作成を担当し、イス専用のメルカリちっくなWEBアプリが課題でした)

ゴリゴリとチューニングしたいと逸る気持ちを抑えて、しっかりとマニュアルを読み込みます。この作業を怠ってしまうと、せっかく長い時間かけてチューニングしても全然スコアが上がらない事態になってしまいます。

ですので、少し時間を取り過ぎかなというくらいにじっくりとマニュアルを読み込み、ベンチマーカーがどのような動きをするのか、どうすればスコアが上がるのかをしっかり理解します。

課題アプリケーションは複数種類のプログラミング言語で開発されています。例えばRuby、PHP、Python、Go等です。私は当社のラフールサーベイがRubyで開発されていることからもRubyを選択しました。

一通りマニュアルを読み、仕様を把握したことでチューニング作業に入ります。

NewRelicの導入

今回はNewRelicというパフォーマンス分析ツールを使って、チューニングを進めることにし、こちらの手順を使って導入しました。

画像2

インデックスを追加

一通りベンチマークを実行した後にNewRelicを確認した結果、/api/trendが全体のうちの80%以上の時間を占めていました。

画像3

ですので、まずはここからチューニングすることにしました。ソースコード中のSQLを確認したところインデックスが効いていないものがあったのでインデックスを追加しました。

ISUCONあるあるですが、インデックスを追加したはずなのになぜかスコアが上がらないことがあります。これはベンチマークの初期化処理でDBの状態をリセットしているが故に発生しており、ベンチマークの初期化処理にインデックス追加処理を追加する必要があります。

画像をDBから静的ファイルへ

/api/isu/:jia_isu_uuid/iconに画像データをDBから抽出している箇所があったので、ファイル化しました。

これは過去のISUCONでも何度も出ているチューニングポイントです。

しかし、今回はログインしたユーザでしか画像が表示されない仕様だったので、単純にNginxから配信させずにあくまでもRubyから画像ファイルを読み込んで返すようにしました。(普通にNginxから配信すると認証無しでアクセスできてしまうため)

あとこちらも先のインデックス追加と同様に、ベンチマークの初期化処理で画像ファイルをクリアし、ベンチマーク開始時に存在する画像だけをファイル化するようにしました。

コンディション登録処理の大改修

ベンチマーカーの挙動を確認しようとアクセスログを確認したところ、ISUからのコンディション通知が大量に来ていました。。。

(これが最初の大きな難関だな・・・)

ほぼ全てのアクセスのレスポンスコードが499になっており、クライアント側が一定時間を超過したために強制切断していると推測。
そして改めて課題アプリケーションのマニュアルを読むと、コンディションが変化しているかどうかがスコアアップのポイントであったので、コンディションをきちんと捌いて更新できるように大改修を決意。

そして、レギュレーション(以下抜粋)の中で昔から気になっていたある一文が頭に浮かびました。

画像4

「ジョブキュー機構の追加による遅延書き込み」

昔のISUCONのレギュレーションに記載されているのは知っていましたが、これまでジョブキューを導入することはありませんでした。

が、しかし、ついにジョブキューを試す日が来たか!!

というわけで、Ruby界隈で有名なジョブキューであるSidekiqを使うことに。ちなみにSidekiqはISUCON当日まで使ったことはありませんでした。これまで使ったことのないツールを勢いで試せるのがISUCONの良さだと思っています。

SidekiqはRedisベースのジョブキュー機構ですので、何はともあれRedisをインストールしました。

$ sudo apt install redis-server

そしてSidekiqのgemをbundle installし、準備完了!
Sidekiqの上で動くワーカー処理の実装をしました。既存のコードから実際の処理をワーカー側に移植しました。(以下は実際のコード抜粋)

require 'sidekiq'

Sidekiq.configure_server do |config|
config.redis = { 'url': 'redis://192.168.0.11:6379', 'db' => 1 }
end

class MyWorker
include Sidekiq::Worker

def perform(data)
  # TODO: 一定割合リクエストを落としてしのぐようにしたが、本来は全量さばけるようにすべき
  drop_probability = 0.5
  if rand <= drop_probability
    logger.info "SKIP"
    return
  end
  logger.info "NOT SKIP"

  params = data["params"]
  json_params = data["json_params"]

  jia_isu_uuid = params["jia_isu_uuid"]
  return if !jia_isu_uuid || jia_isu_uuid.empty?

  return unless json_params.kind_of?(Array)
  return if json_params.empty?

  db_transaction do
    count = db.xquery('SELECT COUNT(*) AS `cnt` FROM `isu` WHERE `jia_isu_uuid` = ?', jia_isu_uuid).first
    return if count.fetch(:cnt).zero?

    json_params.each do |cond|
      timestamp = Time.at(cond.fetch("timestamp"))
      return unless valid_condition_format?(cond.fetch("condition"))

      db.xquery(
        'INSERT INTO `isu_condition` (`jia_isu_uuid`, `timestamp`, `is_sitting`, `condition`, `message`) VALUES (?, ?, ?, ?, ?)',
        jia_isu_uuid,
        timestamp,
        cond.fetch("is_sitting"),
        cond.fetch("condition"),
        cond.fetch("message"),
      )
    end

  end
  logger.info "OK"
end
end

続けて、元々の処理をSidekiqにキューイングするように改修しました。

require './worker.rb'

Sidekiq.configure_client do |config|
config.redis = { 'url': 'redis://192.168.0.11:6379', 'db' => 1 }
end

class MyClient
def enqueue(data)
  MyWorker.perform_async(data)
end
end

module Isucondition
 class App < Sinatra::Base
   # ISUからのコンディションを受け取る
   post '/api/condition/:jia_isu_uuid' do
     begin
       json_params
     rescue JSON::ParserError
       halt_error 202, ''
     end
     data = {"params": params, "json_params": json_params}
     queue.enqueue(data)
     status 202
     ''
   end
 end
end

ただし、初めて触ったものだったので、エンキューにパラメータを渡す部分で少しだけはまって無駄に時間を消費してしまいました。

この辺りは普段から触っておくべきだなと反省。。。

なんとかSidekiqへの連携が完了し、再度ベンチマークを実行したところ大きくスコアが改善しました!
最初の難関はなんとか突破できました!(良かった、ホッ)

Nginxのチューニング

Sidekiqを使って処理を非同期にしたとしても、大量アクセスが来ていることからNginxのチューニングを実施しました。
Nginxのチューニングに関しては予め手元に用意しておいたオレオレ最強パラメーターを投入しました。

user  www-data;
worker_processes  auto;
worker_rlimit_nofile 100000;

events {
  worker_connections 2048;
  multi_accept on;
  use epoll;
}

error_log  /var/log/nginx/error.log warn;
pid        /run/nginx.pid;

http {
  include       /etc/nginx/mime.types;
  default_type  application/octet-stream;

  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"
                      "\tmsec:$msec"
                      "\tupstream_connect_time:$upstream_connect_time"
                      "\tupstream_header_time:$upstream_header_time"
                      "\tupstream_addr:$upstream_addr"
                      "\tupstream_cache_status:$upstream_cache_status"
                      "\tupstream_status:$upstream_status";

  access_log  /var/log/nginx/access.log  ltsv;

  sendfile on;
  tcp_nopush on;
  tcp_nodelay on;
  keepalive_timeout 120;
  types_hash_max_size 2048;
  server_tokens off;

  client_header_timeout 10;
  client_body_timeout 10;
  reset_timedout_connection on;
  send_timeout 10;
  limit_conn_zone $binary_remote_addr zone=addr:10m;
  limit_conn addr 65535;
  open_file_cache max=100000 inactive=120s;
  open_file_cache_valid 120s;
  open_file_cache_min_uses 2;
  open_file_cache_errors on;
  client_max_body_size 100m;
  client_body_buffer_size 100m;
  
  gzip on;
  gzip_vary on;
  gzip_proxied any;
  gzip_comp_level 1;
  gzip_buffers 16 8k;
  gzip_http_version 1.1;
  gzip_types text/plain text/css application/json application/javascript text/xml application/xml application/xml+rss text/javascript;

(以下略)

複数台構成に

ここまではサーバー1台で捌いてきましたが、色々とチューニングが進んできたので、残りの2台のサーバーにも処理を渡そうと考えました。

Nginxやpuma、MariaDBに複数台構成のために必要な設定を行いました。

この処置の後にベンチマークを実行した結果、複数台構成の効果でさらにスコアが引き上がりました。

/api/trendのチューニング

さてここまで来て、改めてNewRelicやアクセスログを確認したところ、/api/trendのレスポンスが大きく悪化していることに気付きました。

これは/api/trendがISUからのコンディションデータを参照しており、受信するコンディションデータが大量に増加したことでレスポンスが悪化していました。

ソースコードを眺めてみた結果、SQLで全件取得した上でプログラムで最初の1件だけ取得している箇所がありました。
これは明らかに無駄で、SQLでそもそも最初の1件だけを取得してしまえばいいのです。この改修をしたところ大きくスコアが改善しました。

ただし、このSQLには心残りがあります。。。
それは完璧なインデックスを貼れなかったことです。

こちらが問題のSQLですが、この内容であればjia_isu_uuidtimestampの複合インデックスを効かせることで、結果が瞬殺で得られるかと期待しましたが、ハズレてしまいました。。。

SELECT * FROM `isu_condition` WHERE `jia_isu_uuid` = ? ORDER BY timestamp DESC LIMIT 1

不要なトランザクションを外す

これは実際の開発現場でやるのはデータの不整合が起きてしまうリスクがあるので要注意ですが、明らかにトランザクションが外せそうなところは外すようにしました。不要なロック待ちを減らしたかったからです。

グラフのデータ算出処理のチューニング

グラフは基本的に1日単位での表示でしたが、ソースコードを確認したところ、全件取得した後にプログラム内で特定の日付のみのデータに整形していたので、SQL文で特定の日付のみ取得するようにしたところスコアが改善しました。

# グラフのデータ点を一日分生成
def generate_isu_graph_response(jia_isu_uuid, graph_date)
   date_str = graph_date.strftime("%Y-%m-%d")
    rows = db.xquery('SELECT * FROM `isu_condition` WHERE `jia_isu_uuid` = ? AND `timestamp` LIKE "' + date_str + '%" ORDER BY `timestamp` ASC', jia_isu_uuid)

ソースコードを読んでいくとまだまだ改善できそうでしたが、競技終了間近でしたのでチューニングとしては以上となります。

不要なログを止める

競技終了間際でチューニングに没頭しすぎると忘れがちですが、NginxやMy SQLのログ、NewRelicを止めました。ISUCONのような大量アクセスが発生するシステムだとちょっとしたI/Oが積み上がって大きな負荷になったりするので侮るなかれです。

再起動テスト


そしてこれも忘れがちですが、ISUCONでは再起動してもサービスがちゃんと稼働することというルールがあり、過去のISUCONでもどれだけハイスコアを出していても再起動テストに失敗して敗退したチームは数知れません。

特にプロセスの自動起動ができておらず、サービスにアクセスできなくなってしまうので、そこは重点的にチェックしました。

終了!

8時間(実際には9時間弱)の戦いが終わりました。。。

途中昼飯のパンは齧ったもののトイレに行くのも忘れてチューニングに没頭していました。

後日結果が発表されましたが、残念ながら本戦への出場には至りませんでした。(スコア的には2万弱で本戦出場ラインには遠く及ばず・・・)
いつの日か本戦に出場できるよう、引き続きチューニングの腕を磨いていきたいと思います!

競技終了後に課題アプリケーションとベンチマーカー一式が一般公開されるので、制限時間意識せずにどこまでチューニングできるかは、また別の記事で試してみたいと思います。

まとめ

今回はISUCONに参加した記録を執筆させていただきました。

私の結果としては残念ながらハイスコアでなかったものの、他の方の何かしらの参考になればと思い、そしてISUCONというイベントの楽しさが伝わればと思い、執筆させていただきました。

私の考えるISUCONに参加するメリットは3点です。

・普段触ることのないジャンルのアプリケーションに触れられる。
・業務では躊躇してしまうようなテクニックを高負荷状態で試せる。
・純粋に楽しい。

これは体験した人にしかわかりませんが、苦労してチューニングした結果、大きくスコアが上がるとアドレナリンが大量放出されます!

ISUCONには最大3名のチームで参加できるので、次回はチームでの参加も考えてみたいです。

インフラ、課題アプリケーション、ベンチマーカー、スコアリングの仕組み、そして賞金あり、と至れり尽くせりのイベントでありながら、なんと参加費無料(!!)。

エンジニア向け競技イベントとして、他にもAtCoderやKaggle等あり、これらも全て無料で参加でき、いい時代になったなぁとつくづく感じます。

ですので、個人的に思っているのは「スキルアップするかどうかは、やるかやらないかが大きく影響している」と。

当然プライベートな時間を全てスキルアップに充ててしまうのは、QOL(Quality of Life)の観点で必ずしもいいわけではありません。

プログラミングとは関係無い趣味を楽しんだり、家族や友人との時間も大切ですので、各人の事情により様々ですが、たまにはこういうイベントに参加してみるのも新しい発見があったりしていいのかなと思います!

拙い文章となってしまいましたが、最後まで読んでいただき誠にありがとうございました。次回記事も読んでいただけると幸いです!

この記事が参加している募集

オープン社内報

この記事が気に入ったらサポートをしてみませんか?