kavo’s diary

備忘録

ISUCON14(2024)参加記録

今年は2名で参戦。初期スコア917、最高スコア4953だった。

scoregraph

https://github.com/shimodatkh/2024-12-08-isu14

準備したこと

  • pproteinで計測する。private ip接続。CFで一発構築
  • isucrudCRUDを見る
  • netdataでメトリクス監視
  • IDEにcursor採用

流れ

  • 相方の体調が思わしくなくリモートに切り替え
  • 10:11 初回計測 初期スコア917
  • 10:47 pproteinで計測準備完了
  • 11:15 スロークエリから不足しているインデックス追加 スコア3200くらい
  • 12-13時頃 internalGetMatchingを改善しようと最短距離マッチングを試す→長時間マッチしないNG
  • 14-17時 chairのマッチング可否をride_statusesから算出するのが複雑なのでchairs.can_matchフラグを作る案を実行→COMPLETE前に次のrideの通知が来てしまいNG
  • 15時くらい internalGetMatchingの間隔を200msにする
  • 17:40 DBを2号機に渡す
  • 17:55 ログ等切ってスコア4953

振り返り

  • cursorは素晴らしい操作体験。途中で無料枠使い切ったので20ドル払った。IDEからスイッチせずにほとんどのlinuxコマンドが1~2プロンプトで完成する。修正提案も優秀。ただメソッド丸ごと書き換えレベルはなかなかうまくいかなかった
  • 計測周りの構築は練習の甲斐があってわりとスムーズにできた
  • internalGetMatchingの修正で右往左往して結局エラー解消できなかった
    • 結局何が良くなかったか。「なんとなくこうしたら良くなりそう」からのベンチ通らない。エラー原因特定の精度は低かったと思う。ベンチのログだけではそんなに深いことはわからない。
      • 処理・仕様読みに時間をかける決断。シナリオも読む。ここは昔から言うは易いのだが、ついお祈りで動け!とガチャ的な作業をしてしまう。
    • あとスコアでの良し悪し判断もブレるのでそれだけでは弱い。細かい計測+継続的な比較がほしいところ
  • プレミ
    • go buildをビルドスクリプトに含めたがエラーに気づかず結構ベンチ流してた

来年への抱負

  • よくわからないけど動けば/スコア上がればいいなとお祈り修正をせず、ログ出し・ドキュメント・コード読みと向き合って「理解」する
  • ISUCONエージェント作成
  • DBのベンチ前後のテーブル、データ量をすぐに出す何か
  • アプリログをデバッグですぐ見れる手段の確立
  • ビルドスクリプト用意

対戦ありがとうございました。

AWS re:Invent 2023参加記録

色々調べていったものの、現地に行ってわかったことも結構あったのでメモ。

電子機器

持っていったもの

  • 社用Macbook Pro
  • アイリスオーヤマ モバイルモニター 13.3インチ DP-BF132S-B
  • 充電系
    • Anker 733 Power Bank (GaNPrime PowerCore 65W) 10000mAh
    • Anker PowerCore Fusion 5000
    • Anker PowerCore Speed 10000
    • Anker Nano II 30W

振り返り

  • o: モバイルモニターは非常に役立った。GameDayやWorkshop系で手順と操作コンソールを同時に表示できると効率が段違い。
  • o: Anker 733は多少重いし高いし10000が若干物足りないがまあよかったと思う。コンセントに直接刺せるのが◯。
  • o: 充電器はホテルに放置しておく分があると、毎日抜き差ししなくてよくて楽。
  • x: PCは私用のWindowsを持っていけばよかった。社用PCを持って行っても、毎日セッションと明日の予定検討で一杯で日本の仕事を考える余裕などない。また、周りの人が感じてないNW不調を感じることが多くあり、プロキシソフトの影響が疑われ、その点でもストレスだった。WindowsよりMacの方が・・・とも思ったが、ローカル環境を使うことはほぼなかった。
  • x: 充電が不安でモバイルバッテリーを多めに持っていったが過剰だった。参加したハンズオン系のセッションでは全部コンセントがあった。
  • x: ワイヤレスマウスLift持っていくの忘れて辛かった。Walgreenで急遽買えて助かったが、無駄な出費で悲しい。

ネットワーク周り

  • グローバルWiFiレンタル4G無制限プランを借りていった。
  • 現地についてから知ったが、ahamoだと特に追加料金なしでローミングできた。10mbps程度。
  • レンタルWiFiはずっと速度が微妙だった。1mbps程度。もう途中から充電すらあまりしていなかった。結構高かったのに・・・。あとやはり充電が面倒、次があったらeSIMにしたい。というかahamoローミングがあるからいらない説もある。
  • eSIMは使ってみたかったが携帯が対応しておらず断念

衣類

  • SWAGパーカーは裏起毛でとても温かい。暖房が効いている場所だと暑いくらい。
  • 上着何持っていくか悩み、ウルトラライトダウンベスト(ワイドキルト)とシームレスダウンパーカを持っていった。が、シームレスダウンパーカは腕が動きづらいしかさばるしであまり着なかった。長袖ヒートテック+Tシャツ+SWAGパーカー+ウルトラライトダウンベストくらいで夜はちょっと寒いけどなんとか、くらいだった。
  • SWAGのTシャツがいつどれくらい貰えるのか不明瞭だったが、2023の感覚だと以下。
    • 資格認定者が貰えるTシャツ:Registrationのホールの後ろ側で受け取りできた。確か3日目くらいに行ったがLサイズはもうなくてXLをもらった気がする。Registrationと同時に貰えば問題なく貰えそう。
    • re:playで貰えるTシャツ:すごい数があって多分行けばほぼ貰えそう。4日目の夜なのでタイミングは遅め。
    • Expoで貰えるTシャツ:3日目に行ったときはほとんどのブースで無くなっていた印象。ほしいなら初日とかに行ったほうがいいのかも?
  • マスクは個人的に持って行ってよかった。ラスベガスは路上喫煙が非常に多く、そこら中で悪臭がしていてしんどかった。またホテルの入り口で何かわからないが変な匂いがしていた。

英語

  • 入国審査でDo you travel alone?と聞かれたがaloneが聞き取れず何回も聞き返してしまった。結局相手が翻訳アプリを使ってくれて理解した。
  • 聞き取りはOtterを利用してみた。かなり聞き取りには良いが、さらにその文章を翻訳させるのがちょっと手間だった。Chromeの翻訳機能だとotterの書き直しと衝突して文章が変に重なって行ってしまう。
  • Keynoteは同時通訳の機器を借りることができ、それで聞いた。

移動関係

  • 行きのサンフランシスコ乗継の時間がちょうど2時間で心配していた。たまたま1つ目の飛行機が55分程早く着いたため間に合ったが、時間通りだったら間に合ってなかった。手配会社・・・。
    • とにかく税関が時間かかるので、税関に素早く着くのが大事。
    • 今回小型スーツケースとリュックを持ち込んで預けもの無しにしたので、それもよかった。
  • 空気で膨らませるヨックションを飛行機で使ったが、使わない場合の太ももの血流が圧迫される違和感が明らかに減り、非常に良かった。
  • 無印のネッククッションを持っていったが、すごくかさばるのでこちらも膨らませるタイプにしたい。
  • 飛行機の揺れが酷いところでは乗り物酔いになった気がする。タクシー・バス移動やモノレールも揺れるので、乗り物酔い薬を持っていけばよかったかも。不味いから飲みたくはないけど。

その他

  • 5k
    • 荷物が預けられるかを心配していたが、ちゃんと預けられる。ウルトラアリーナのアリーナで預けて紙のリストバンドと交換する。
  • ホテル室内用のスリッパを持っていけばよかった。

ISUCON13(2013)参加記録

今年は2名で参戦。おおよそ22000点くらいが最高スコアだった。

https://github.com/shimodatkh/2023-11-25-isu13

決めていたこと

  • pproteinで計測する
  • go-callvisでコールグラフを見る
  • コードはローカルで書いてmainにpush

流れ

  • 初回3000点くらいだった
  • git周りミスっててリポジトリ作り直したり権限いじったり
  • port番号のミスにハマる。pproteinでprofとalpが見えるようになる。
  • sqlはスペックのせいかslpがインストールできず見れなくて、諦めて競技サーバでptqueryを手打ちして凌ぐ
  • go-callvis動かすと計測サーバがスペックのせいか無反応になってしまうので諦め。ほかサーバではPATHがうまくいかなくて諦め。悲しい・・・
  • 12時頃インデックス貼って6000点くらい
  • getLivestreamStatisticsHandlerのSQLをまとめようとするが失敗。ここはgithub PRでやったのでrevertしやすかった
  • このあたりでプロファイラにsha256.Sum256が目立つ状況になっていたので、hashをテーブルに保存するように修正することにした
  • 修正したがbenchmark timeoutでなんだこれ?となる。実はベンチマーカーに障害が起きていた
  • しかし、ベンチマーカー障害解消の周知後もbenchmark timeoutが続き、原因がわからない。ただweb画面にアイコンが出なくなっていてアプリがおかしくなっていることはわかっていた
  • 結局右往左往したあとrevertした。見直しながら1つずつ入れていくと、型変換ミスに気づいた
  • db:"name"忘れ
  • fillLivestreamResponse N+1改善
  • 17:12 13,188点 UserRankingのN+1改善
  • SetMaxOpenConns(50)
  • 17:32 21,120点 計測系外す

振り返り

  • 今年はあまり素振りができず、計測環境が整うまでにかなり手間取った
  • rLoginがブチブチ切れて辛かった。keepalive設定を思いつくまで結構かかった
  • 計測サーバ、本番用にはケチらずもっといいスペックに変えておけばよかった
  • revertするかも・・・と思ってるときはgithub PRでやるとrevertがGUIでできてやりやすかった
  • copilotとても有用
  • 切り戻しの判断が遅かったかも。もっと切り戻し判断をシステマチックにしてみたい
  • アプリログを見るのが遅かった。見やすい状態をつくれていなかった

pproteinを競技サーバとは別のサーバに置いて使う

今年のISUCONはpproteinを使ってみようと思う。

pprotein用サーバ作成

  • pprotein用のec2を立てる. 9000port開け
  • static ip割当
  • pproteinインストール、起動、ブラウザアクセス

pprotein→競技サーバアクセス疎通

最初IP直でsettingに書いたが穴開いてないので駄目なんだった。本番ではセキュリティグループはいじれないので、ポートフォワードでやってみる。

pprotein用サーバから競技サーバへポートフォワード実行

ssh isucon@18.182.156.175 -L 127.0.0.1:3001:localhost:3000 -i /tmp/isu13

pproteinのgroup/targetsに以下を設定

[
  {
    "Type": "pprof",
    "Label": "srv1",
    "URL": "http://localhost:3001/debug/pprof/profile",
    "Duration": 60
  },
  {
    "Type": "httplog",
    "Label": "srv1",
    "URL": "http://localhost:3001/debug/log/httplog",
    "Duration": 60
  },
  {
    "Type": "slowlog",
    "Label": "srv1",
    "URL": "http://localhost:3001/debug/log/slowlog",
    "Duration": 60
  }
]

これでアクセスが通るようになった。

自動起動設定

pprotein

sudo vi /etc/systemd/system/pprotein.service

[Unit]
Description=pprotein service

[Service]
ExecStart=/home/isucon/pprotein
WorkingDirectory=/home/isucon
Restart=always
User=isucon

[Install]
WantedBy=multi-user.target
sudo systemctl daemon-reload
sudo systemctl restart pprotein.service
sudo systemctl status pprotein.service

ポートフォワード

sudo vi /etc/systemd/system/portforward-srv1.service

[Unit]
Description=SSH port forwarding

[Service]
ExecStart=/usr/bin/ssh -i /tmp/isu13 -L 127.0.0.1:3001:localhost:3000 isucon@18.182.156.175 -N
Restart=always
RestartSec=15
User=isucon

[Install]
WantedBy=multi-user.target
sudo systemctl daemon-reload
sudo systemctl restart portforward-srv1.service
sudo systemctl status portforward-srv1.service

ISUCON練習会 過去問(11予選)並走会に参加した

2023/10/21にDiscordのISUCON精進鯖で開催された並走会に参加した。

ISUCON精進鯖(非公式)について - HackMD

ISUCON練習会 過去問並走会 - HackMD

GitHub - shimodatkh/isucon-practice-11q

ssh接続

rlgファイル作る プライベートキーどれだっけ? ユーザ名がubuntuじゃなくてisuconだった

10:19 初回走行 2220点

score: 2220(2248 - 28) : pass

サービス確認

sudo systemctl status

             ├─nginx.service 
             │ ├─ 524 nginx: master process /usr/sbin/nginx -g daemon on; master_process on;
             │ ├─3002 nginx: worker process
             │ └─3003 nginx: worker process
             ├─mariadb.service 
             │ └─587 /usr/sbin/mysqld
...
             ├─isucondition.go.service 
             │ └─769 /home/isucon/webapp/go/isucondition
...
             ├─jiaapi-mock.service 
             │ └─438 /usr/local/bin/jiaapi-mock

ブラウザアクセス確認

JIAのアカウントでログイン を押下するとhttp://localhost:5000/?callback=https://18.~~~に遷移してしまう。ブラウザで見るのは諦めた。

pprotein導入

pprotein導入 - HackMD

2xxと3xxが同じ→キャッシュ効いてそう

静的ファイルならnginxが返せないのかとか検討

pproteinの結果を見る

Avg(RowsExamined):DBから読み込んだ行数 Avg(RowsSent):送った行数

この乖離が大きいのは効率が悪い可能性が高い

nginx設定

URI正規表現パターンを探索する

isucon@ip-192-168-0-11:~$ alp ltsv --format tsv --file /var/log/nginx/access.log -m "^/api/isu/.+[0-9a-f\-]$,^/api/condition/.+[0-9a-f\-]$,^/api/isu/.+[0-9a-f\-]/graph$,^/api/isu/.+[0-9a-f\-]/icon$,^/isu/.+[0-9a-f\-]$,^/isu/.+[0-9a-f\-]/graph$,^/isu/.+[0-9a-f\-]/condition$" --sort sum -r
Count   1xx     2xx     3xx     4xx     5xx     Method  Uri     Min     Max     Sum     Avg     P90     P95     P99     Stddev  Min(Body)       Max(Body)       Sum(Body)       Avg(Body)
140974  0       131782  0       9192    0       POST    ^/api/condition/.+[0-9a-f\-]$   0.008   0.324   1291.483        0.009   0.020   0.100   0.100   0.026   0.000   14.000  112.000 0.001

pprofの設定をアップデート

matching_groups:
    - ^/api/condition/.+[0-9a-f\-]$
    - ^/api/isu/.+[0-9a-f\-]$
    - ^/api/isu/.+[0-9a-f\-]/icon$
    - ^/api/isu/.+[0-9a-f\-]/graph$
    - ^/isu/.+[0-9a-f\-]/condition$
    - ^/isu/.+[0-9a-f\-]/graph$
    - ^/isu/.+[0-9a-f\-]$

13:27 インデックス設定 16,311点

まずは

  • Avg(RowsExamined):DBから読み込んだ行数
  • Avg(RowsSent):送った行数

の乖離が多いものにインデックス設定。

CREATE INDEX idx_jia_isu_uuid_timestamp ON isu_condition (jia_isu_uuid, timestamp DESC);

14:16 trendの不要なデータ取得をlimit 21,788点

次に大きそうなtrendを見る。 コードを読んでいると複数行SQLで取得しているのに1行しか使ってないことに気づいた。

"SELECT * FROMisu_conditionWHEREjia_isu_uuid= ? ORDER BY timestamp DESC limit 1"

17:52 postIsuConditionのinsertを非同期&bluk化 27,774点

postIsuConditionがhttplogのsumで最大であり、sql.withLockのブロックも大きいことから、細かいinsertが大量に入り待ち状態になっていると想定した。

参考:

postIsuConditionをバックグラウンドバルク化 · tohutohu/isucon-practice-11q@168a4dd · GitHub

時間経って再開

cd bench ./bench -all-addresses 192.168.0.11 -target 192.168.0.11:443 -tls -jia-service-url http://192.168.0.10:4999

sudo mysql -uroot -e "show databases;set global slow_query_log_file = '/var/log/mysql/m ysql-slow.log';set global long_query_time = 0;set global slow_query_log = ON;show variables like 'slow%';"

dropProbabilityを消してみる:24,178点

点数はあまり変わりないが、post conditionの2xx回数が11312>32812と増加。これ自体は今後のためになりそうなので戻さず維持。

getIsuConditionsFromDBの効率化:71,780点

getIsuConditionsFromDBは最後にconditionsResponse[:limit]で20個までで切っているのでここは減らせるはず

ただし取り方が複雑なので少し面倒。とりあえずすぐ手前のSQL2つに limit 20をつけてみる。 ただし、これはcalculateConditionLevelの計算がエラーになる、またはconditionLevelがinfo/warning/criticalにならないような変なデータがあると単純なlimit 20の場合最終的な個数が変わってしまう。

点数は3倍くらいに伸びた。今まで見かけなかった↓のエラーログが出るようになった。

00:18:49.141812 ERR: load: mismatch: GET /api/condition/:jia_isu_uuid か GET /api/isu/:jia_isu_uuid/graph で確認 された condition がありません: 200 (GET: /api/condition/c1b42d3d-2b68-42bb-b0f6-48edfaeb338a?condition_level=warning%2Ccritical&end_time=1629583549)

これは指定したcondition_levelのデータだけを取ってくるということなのでwarning%2Ccritical、つまりinfoは無視していたということ

やはりcondition_levelを事前計算するのがよいか。

当日できたのはここまで。

ISUCON練習 private-isu[4] ~16275点 アプリ書き換え時デバッグ、getIndex・getAccountNameのN+1解消

getIndexの改善

引き続き無駄な部分を改善する。

  • コメントは3個まででよい
  • UserのデータはAccountNameだけしか使ってないと思われる

GitHub - jmoiron/sqlx: general purpose extensions to golang's database/sql

sqlxは多分、フィールドの配列構造体を直接SQL結果からバインドできない・・・と思う。

  • Post
    • Comment

ので、Postの取得とCommentの取得は別SQLで実行する。

デバッグ

  • SQLレベル:mysqlコンソールで直打ち
  • Goレベル:

post取得部分

SQL

今のpost取得SQL

ポストのユーザとコメント数をくっつけたもの

Go

{
    "version": "0.2.0",
    "configurations": [
        {
            "name": "Launch Go App",
            "type": "go",
            "request": "launch",
            "mode": "debug",
            "program": "${workspaceFolder}/app.go",
            "env": {
                "ISUCONP_DB_HOST": "localhost",
                "ISUCONP_DB_PORT": "3306",
                "ISUCONP_DB_USER": "root",
                "ISUCONP_DB_PASSWORD": "root",
                "ISUCONP_DB_NAME": "isuconp",
                "ISUCONP_MEMCACHED_ADDRESS": "memcached:11211"
            }
        }
    ]
}

vscodeデバッグ起動。dockerのmysqlに接続。

docker compose build app && docker compose up -d --force-recreate app

{"pass":true,"score":15863,"success":12204,"fail":0,"messages":}

GET /が0.004secまで行った。

getAccountName

次はURI実行時間が1位になったgetAccountNameを見る。AVGが0.030。

処理を読むとgetIndexと同様のmakePostsを使っていたのでN+1を解消。

{"pass":true,"score":16275,"success":12514,"fail":0,"messages":}

これでgetAccountNameのAVGが0.018になった。

インデックスも改善できるかと思ったが、逆にスコア8000くらいに減ってしまったので取り消し。

CREATE INDEX idx_posts_created_at_user_id ON posts (user_id, created_at desc);

ISUCON練習 private-isu[3] ~13148点 Nginxログ解析、pprof、無効ユーザの除外とpost20個制限

Nginxログ解析

ログフォーマットを設定。

apt update && apt install -y vim

vi /etc/nginx/nginx.conf

# nginx -t 
nginx: the configuration file /etc/nginx/nginx.conf syntax is ok
nginx: configuration file /etc/nginx/nginx.conf test is successful

alpの集約を調整。

../../../alp.exe json --file access.log -r --sort=sum -m "/image/\d+.(jpg|png|gif), @[a-zA-Z]+, /posts/\d+" | head -n 30

GET /、getIndexが支配的。

プロファイラ

GitHub - felixge/fgprof: 🚀 fgprof is a sampling Go profiler that allows you to analyze On-CPU as well as Off-CPU (e.g. I/O) time together.

を使う。 コード修正

fgprof導入 · shimodatkh/private-isu@93f42fe · GitHub

docker compose up -d --force-recreate app

go tool pprof --http=:6061 http://localhost:6060/debug/fgprof?seconds=120

を仕掛けてベンチ実行。

getIndexに絞るとこうなった。

コード読み解き

まずはgetIndexを読む。処理を箇条書きで書いてみる。

とりあえず無効ユーザは無駄なこと、Postは20個、コメントは3個まででよいことはわかった。

一旦簡単なところから、無効ユーザの除外とpost20個制限をつけてみる。

getIndex 無効ユーザの除外とpost20個制限 · shimodatkh/private-isu@9c47086 · GitHub

docker compose build app docker compose up -d --force-recreate app

{"pass":true,"score":13148,"success":10431,"fail":0,"messages":[]}

real 1m12.421s

GET /のAVGが0.133から0.030と減っている。