private-isuをdockerでやってみた時のメモ
ISUCON本の付録Aをやってみたログ
訳があって未経験のphpで解きましたが、GitHub Copilotのおかげで何とかなった。
実行環境
- MacBook Pro 2021
- Apple M1 Pro
- 16GB
- MacOS Ventura
環境構築直後のベンチマーク
遅すぎてタイムアウトで測定不可だった
{"pass":true,"score":0,"success":163,"fail":40,"messages":["リクエストがタイムアウトしました (GET /)","リクエストがタイムアウトしました (GET /image/3114.jpg)","リクエストがタイムアウトしました (GET /image/4460.jpg)","リクエストがタイムアウトしました (GET /image/9995.jpg)","リクエストがタイムアウトしました (POST /login)","リクエストがタイムアウトしました (POST /register)"]}
benchmark中に取得したdocker statsコマンドの実行結果。mysqlのCPUが100%を超えていて、appは1%しか使われていないのでmysqlにボトルネックがあることが分かる。
CONTAINER ID NAME CPU % MEM USAGE / LIMIT MEM % NET I/O BLOCK I/O PIDS
533142f4102b cool_goldberg 0.00% 11.53MiB / 7.667GiB 0.15% 0B / 0B 0B / 0B 8
8a1fd0811825 webapp-nginx-1 0.00% 4.633MiB / 7.667GiB 0.06% 45.1MB / 45.1MB 0B / 4.1kB 5
7d50ab8c5bb4 webapp-app-1 1.08% 46.93MiB / 1GiB 4.58% 108MB / 45.2MB 1.91MB / 0B 7
67344c58c590 webapp-mysql-1 102.86% 412.2MiB / 1GiB 40.25% 3.78MB / 104MB 5.26MB / 19.7MB 44
74bc728fd19e webapp-memcached-1 0.03% 5.219MiB / 7.667GiB 0.07% 398kB / 314kB 0B / 0B 10
comments.post_id, created_atにインデックスを張る(SCORE: 9703)
本に従ってインデックスを張る。
ALTER TABLE comments ADD INDEX post_id_idx(post_id, created_at DESC);
{"pass":true,"score":9703,"success":8702,"fail":0,"messages":[]}
ボトルネックがappに移った
CONTAINER ID NAME CPU % MEM USAGE / LIMIT MEM % NET I/O BLOCK I/O PIDS
126239fc0346 brave_hamilton 26.04% 19.98MiB / 7.667GiB 0.25% 0B / 0B 0B / 0B 9
8a1fd0811825 webapp-nginx-1 8.46% 6.184MiB / 7.667GiB 0.08% 2.14GB / 2.15GB 0B / 909kB 5
7d50ab8c5bb4 webapp-app-1 104.28% 27.37MiB / 1GiB 2.67% 3.25GB / 2.14GB 1.91MB / 1.31MB 7
67344c58c590 webapp-mysql-1 40.46% 549.1MiB / 1GiB 53.63% 88MB / 3.12GB 188MB / 259MB 44
74bc728fd19e webapp-memcached-1 2.67% 5.516MiB / 7.667GiB 0.07% 11.6MB / 9.49MB 0B / 0B 10
workerプロセスを4にする
rubyのunicornと違って、特に何もしなくてもphp-fpm: pool www
のプロセスが複数立ち上がるのでphpでは作業不要だった
root@7d50ab8c5bb4:/var/www/html# ps -fe
UID PID PPID C STIME TTY TIME CMD
root 1 0 0 13:10 ? 00:00:00 /sbin/docker-init -- docker-php-entrypoint php-fpm
root 6 1 0 13:10 ? 00:00:01 php-fpm: master process (/usr/local/etc/php-fpm.conf)
www-data 751 6 1 13:44 ? 00:00:24 php-fpm: pool www
www-data 4088 6 0 13:47 ? 00:00:12 php-fpm: pool www
www-data 4145 6 0 13:47 ? 00:00:12 php-fpm: pool www
root 7730 0 0 14:18 pts/0 00:00:00 bash
www-data 8163 6 21 14:20 ? 00:00:00 php-fpm: pool www
www-data 8212 6 22 14:20 ? 00:00:00 php-fpm: pool www
root 8382 7730 0 14:21 pts/0 00:00:00 ps -fe
www-data 8383 4088 0 14:21 ? 00:00:00 php-fpm: pool www
nginxのaccess.logをJSONで出力するように設定変更してalpで確認できるようにする
diff --git a/webapp/etc/nginx/conf.d/php.conf b/webapp/etc/nginx/conf.d/php.conf
index 6cf6834..93d1923 100644
--- a/webapp/etc/nginx/conf.d/php.conf
+++ b/webapp/etc/nginx/conf.d/php.conf
@@ -1,3 +1,15 @@
+log_format json escape=json '{"time":"$time_iso8601",'
+ '"host":"$remote_addr",'
+ '"port":$remote_port,'
+ '"method":"$request_method",'
+ '"uri":"$request_uri",'
+ '"status":"$status",'
+ '"body_bytes":$body_bytes_sent,'
+ '"referer":"$http_referer",'
+ '"ua":"$http_user_agent",'
+ '"request_time":"$request_time",'
+ '"response_time":"$upstream_response_time"}';
+
server {
listen 80;
@@ -17,4 +29,5 @@ server {
fastcgi_index index.php;
fastcgi_pass app:9000;
}
+ access_log /var/log/nginx/access.log json;
}
設定を変えて再起動
docker compose stop nginx
docker compose rm nginx
docker compose up nginx -d
slowクエリログを出力してpt-query-digestで見れるようにしておく(SCORE:7986)
ローカルから見れるようにフォルダのマウントもやっておく
diff --git a/webapp/docker-compose.yml b/webapp/docker-compose.yml
index f4bf719..ef95f1f 100644
--- a/webapp/docker-compose.yml
+++ b/webapp/docker-compose.yml
@@ -42,6 +42,7 @@ services:
- mysql:/var/lib/mysql
- ./etc/my.cnf:/etc/my.cnf
- ./sql:/docker-entrypoint-initdb.d
+ - ./logs/mysql:/var/log/mysql
ports:
- "3306:3306"
deploy:
diff --git a/webapp/etc/my.cnf b/webapp/etc/my.cnf
index 1780a5d..bdaeebb 100644
--- a/webapp/etc/my.cnf
+++ b/webapp/etc/my.cnf
@@ -1,2 +1,7 @@
[mysqld]
default_authentication_plugin=mysql_native_password
+
+slow_query_log=1
+slow_query_log_file=/var/log/mysql/mysqlslow.log
+long_query_time=0
コンテナを再作成
docker compose stop mysql
docker compose rm mysql
docker compose up mysql -d
ベンチーマークは16%も悪化した
- {"pass":true,"score":9703,"success":8702,"fail":0,"messages":[]}
+ {"pass":true,"score":7986,"success":7323,"fail":0,"messages":[]}
実装を切り替えてのベンチ比較
まだアプリに手を入れていないこのタイミングで言語を切り替えてベンチを取得してみる
Goに実装を変更
sed -i "" -e 's/build: php/build: golang/' docker-compose.yml
mv etc/nginx/conf.d/default.conf.org etc/nginx/conf.d/default.conf
mv etc/nginx/conf.d/php.conf etc/nginx/conf.d/php.conf.org
docker compose down app nginx
docker compose build app
docker compose up app nginx -d
ものすごく遅くなった。いろんな要素があるので単純に言語ごとの速度比較は難しい。
{"pass":true,"score":4527,"success":4332,"fail":0,"messages":[]}
Rubyに実装を変更
sed -i "" -e 's/build: golang/build: ruby/' docker-compose.yml
docker compose down app nginx
docker compose build app
docker compose up app nginx -d
更に悪い結果になった。これはアプリの並行度が1なので遅いのは分かっていた。
{"pass":true,"score":2683,"success":2324,"fail":0,"messages":[]}
実装をphpに戻して先に進む。
'mysql_native_password' is deprecatedのログを消す
ログに大量のアラートが表示されて煩いので消したい
webapp-mysql-1 | 2023-09-02T01:32:26.022087Z 20384 [Warning] [MY-013360] [Server] Plugin mysql_native_password reported: ''mysql_native_password' is deprecated and will be removed in a future release. Please use caching_sha2_password instead'
my.confにlog_error_suppression_list=MY-013360
を追記する
a1@MacBookPro2021 webapp % git diff
diff --git a/webapp/etc/my.cnf b/webapp/etc/my.cnf
index bdaeebb..2efb8ba 100644
--- a/webapp/etc/my.cnf
+++ b/webapp/etc/my.cnf
@@ -5,3 +5,4 @@ slow_query_log=1
slow_query_log_file=/var/log/mysql/mysqlslow.log
long_query_time=0
+log_error_suppression_list=MY-013360
設定を反映させる
docker compose down mysql && docker compose up mysql app nginx -d
ベンチも100ぐらい向上した
静的ファイルをnginxで配信する
diff --git a/webapp/etc/nginx/conf.d/php.conf b/webapp/etc/nginx/conf.d/php.conf
index 93d1923..b118c1e 100644
--- a/webapp/etc/nginx/conf.d/php.conf
+++ b/webapp/etc/nginx/conf.d/php.conf
@@ -16,6 +16,11 @@ server {
client_max_body_size 10m;
root /public;
+ location ~ ^/(favicon\.ico|css/|js/|img/) {
+ root /public;
+ expires 1d;
+ }
+
location / {
try_files $uri /index.php$is_args$args;
}
設定を反映する
docker compose down nginx && docker compose up nginx -d
スコアはそんなに変わらないけどjs, css, favicon.icoへの2回目以降のアクセスが302になっている
% cat logs/nginx/access.log|alp json -m "/image/.+,/posts/[0-9]+,/@.+"
+-------+-----+------+-----+-----+-----+--------+--------------------+-------+-------+---------+-------+-------+-------+-------+--------+-----------+-------------+----------------+------------+
| COUNT | 1XX | 2XX | 3XX | 4XX | 5XX | METHOD | URI | MIN | MAX | SUM | AVG | P90 | P95 | P99 | STDDEV | MIN(BODY) | MAX(BODY) | SUM(BODY) | AVG(BODY) |
+-------+-----+------+-----+-----+-----+--------+--------------------+-------+-------+---------+-------+-------+-------+-------+--------+-----------+-------------+----------------+------------+
| 23 | 0 | 0 | 23 | 0 | 0 | GET | /logout | 0.009 | 0.257 | 2.259 | 0.098 | 0.163 | 0.163 | 0.257 | 0.049 | 5.000 | 5.000 | 115.000 | 5.000 |
| 37 | 0 | 37 | 0 | 0 | 0 | GET | /posts | 0.446 | 0.789 | 24.316 | 0.657 | 0.768 | 0.774 | 0.789 | 0.066 | 34529.000 | 35329.000 | 1293392.000 | 34956.541 |
| 46 | 0 | 46 | 0 | 0 | 0 | GET | /login | 0.010 | 0.182 | 3.665 | 0.080 | 0.126 | 0.165 | 0.182 | 0.039 | 1240.000 | 1240.000 | 57040.000 | 1240.000 |
| 48 | 0 | 0 | 0 | 48 | 0 | GET | /admin/banned | 0.013 | 0.293 | 4.059 | 0.085 | 0.111 | 0.133 | 0.293 | 0.043 | 13.000 | 13.000 | 624.000 | 13.000 |
| 48 | 0 | 0 | 48 | 0 | 0 | POST | /register | 0.024 | 0.421 | 6.466 | 0.135 | 0.186 | 0.192 | 0.421 | 0.056 | 5.000 | 5.000 | 240.000 | 5.000 |
| 50 | 0 | 0 | 50 | 0 | 0 | POST | /comment | 0.018 | 0.210 | 4.824 | 0.096 | 0.148 | 0.165 | 0.210 | 0.035 | 5.000 | 5.000 | 250.000 | 5.000 |
| 76 | 0 | 0 | 38 | 38 | 0 | POST | / | 0.012 | 0.252 | 8.662 | 0.114 | 0.187 | 0.223 | 0.252 | 0.050 | 5.000 | 13.000 | 684.000 | 9.000 |
| 84 | 0 | 84 | 0 | 0 | 0 | GET | /@.+ | 0.091 | 0.655 | 31.578 | 0.376 | 0.508 | 0.573 | 0.655 | 0.104 | 6262.000 | 31484.000 | 1509264.000 | 17967.429 |
| 243 | 0 | 0 | 243 | 0 | 0 | POST | /login | 0.011 | 0.545 | 30.946 | 0.127 | 0.175 | 0.192 | 0.487 | 0.061 | 5.000 | 5.000 | 1215.000 | 5.000 |
| 333 | 0 | 333 | 0 | 0 | 0 | GET | / | 0.098 | 0.984 | 151.083 | 0.454 | 0.638 | 0.700 | 0.768 | 0.127 | 3918.000 | 35770.000 | 7394158.000 | 22204.679 |
| 404 | 0 | 404 | 0 | 0 | 0 | GET | /posts/[0-9]+ | 0.026 | 0.446 | 57.884 | 0.143 | 0.186 | 0.221 | 0.323 | 0.048 | 1665.000 | 6522.000 | 1495798.000 | 3702.470 |
| 461 | 0 | 1 | 460 | 0 | 0 | GET | /js/main.js | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 1824.000 | 1824.000 | 3.957 |
| 461 | 0 | 1 | 460 | 0 | 0 | GET | /css/style.css | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 1549.000 | 1549.000 | 3.360 |
| 461 | 0 | 1 | 460 | 0 | 0 | GET | /js/timeago.min.js | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 1915.000 | 1915.000 | 4.154 |
| 461 | 0 | 1 | 460 | 0 | 0 | GET | /favicon.ico | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 | 43.000 | 43.000 | 0.093 |
| 3630 | 0 | 3630 | 0 | 0 | 0 | GET | /image/.+ | 0.009 | 0.521 | 341.730 | 0.094 | 0.131 | 0.154 | 0.243 | 0.040 | 35046.000 | 1199259.000 | 1134379256.000 | 312501.172 |
+-------+-----+------+-----+-----+-----+--------+--------------------+-------+-------+---------+-------+-------+-------+-------+--------+-----------+-------------+----------------+------------+
アップロード画像を静的ファイル化する(SCORE: 12297)
デフォルトの実装では、画像をDBに保存し、表示する時もDBから取り出して遅い。
画像を登録時と初回表示時にpublicフォルダに保存し、次に要求された時はpublicフォルダの内容をnginxが返すようにする
diff --git a/webapp/php/index.php b/webapp/php/index.php
index 6ea6f81..b0e2b95 100644
--- a/webapp/php/index.php
+++ b/webapp/php/index.php
@@ -355,13 +355,17 @@ $app->post('/', function (Request $request, Response $response) {
if ($_FILES['file']) {
$mime = '';
+ $ext = '';
// 投稿のContent-Typeからファイルのタイプを決定する
if (strpos($_FILES['file']['type'], 'jpeg') !== false) {
$mime = 'image/jpeg';
+ $ext = 'jpg';
} elseif (strpos($_FILES['file']['type'], 'png') !== false) {
$mime = 'image/png';
+ $ext = 'png';
} elseif (strpos($_FILES['file']['type'], 'gif') !== false) {
$mime = 'image/gif';
+ $ext = 'gif';
} else {
$this->get('flash')->addMessage('notice', '投稿できる画像形式はjpgとpngとgifだけです');
return redirect($response, '/', 302);
@@ -378,10 +382,18 @@ $app->post('/', function (Request $request, Response $response) {
$this->get('flash')->addMessage('notice', '投稿できる画像形式はjpgとpngとgifだけです');
return redirect($response, '/', 302);
@@ -378,10 +382,18 @@ $app->post('/', function (Request $request, Response $response) {
$ps->execute([
$me['id'],
$mime,
- file_get_contents($_FILES['file']['tmp_name']),
+ //file_get_contents($_FILES['file']['tmp_name']),
+ "",
$params['body'],
]);
+
$pid = $db->lastInsertId();
+
+ $imgdata = file_get_contents($_FILES['file']['tmp_name']);
+ $filename = "/home/public/image/{$pid}.{$ext}";
+ file_put_contents($filename, $imgdata);
+
return redirect($response, "/posts/{$pid}", 302);
} else {
$this->get('flash')->addMessage('notice', '画像が必須です');
@@ -400,6 +412,11 @@ $app->get('/image/{id}.{ext}', function (Request $request, Response $response, $
($args['ext'] == 'png' && $post['mime'] == 'image/png') ||
($args['ext'] == 'gif' && $post['mime'] == 'image/gif')) {
$response->getBody()->write($post['imgdata']);
+
+ // 取得されたタイミングでファイルに書き出す
+ $filename = "/home/public/image/{$args['id']}.{$args['ext']}";
+ file_put_contents($filename, $post['imgdata']);
+
return $response->withHeader('Content-Type', $post['mime']);
}
$response->getBody()->write('404');
直前のベンチマークから4885スコアが上がった
{"pass":true,"score":12297,"success":11697,"fail":0,"messages":[]}
画像の取得SUM時間が大幅に改善された
% cat logs/nginx/access.log|alp json -m "/image/.+,/posts/[0-9]+,/@.+"
+-------+-----+------+-----+-----+-----+--------+--------------------+-------+-------+---------+-------+-------+-------+-------+--------+-----------+-------------+----------------+------------+
| COUNT | 1XX | 2XX | 3XX | 4XX | 5XX | METHOD | URI | MIN | MAX | SUM | AVG | P90 | P95 | P99 | STDDEV | MIN(BODY) | MAX(BODY) | SUM(BODY) | AVG(BODY) |
+-------+-----+------+-----+-----+-----+--------+--------------------+-------+-------+---------+-------+-------+-------+-------+--------+-----------+-------------+----------------+------------+
- | 3630 | 0 | 3630 | 0 | 0 | 0 | GET | /image/.+ | 0.009 | 0.521 | 341.730 | 0.094 | 0.131 | 0.154 | 0.243 | 0.040 | 35046.000 | 1199259.000 | 1134379256.000 | 312501.172 |
+ | 8418 | 0 | 8418 | 0 | 0 | 0 | GET | /image/.+ | 0.016 | 0.796 | 45.166 | 0.005 | 0.000 | 0.000 | 0.229 | 0.039 | 39440.000 | 1086666.000 | 2921578002.000 | 347063.198 |
+-------+-----+------+-----+-----+-----+--------+--------------------+-------+-------+---------+-------+-------+-------+-------+--------+-----------+-------------+----------------+------------+
ファイルがあれば返す、なければphpに流す設定を忘れてたので追加で行った
本の通りhttp://app:9000のようにproxyするとダメなので、画像がない場合はindex.phpを返すようにした
diff --git a/webapp/etc/nginx/conf.d/php.conf b/webapp/etc/nginx/conf.d/php.conf
index b118c1e..0f4c3e8 100644
--- a/webapp/etc/nginx/conf.d/php.conf
+++ b/webapp/etc/nginx/conf.d/php.conf
@@ -21,6 +21,12 @@ server {
expires 1d;
}
+ location /image/ {
+ root /public;
+ expires 1d;
+ try_files $uri $uri/ /index.php?$query_string;
+ }
+
location / {
try_files $uri /index.php$is_args$args;
}
一度取得した画像は302を返すようになった。
% cat logs/nginx/access.log|alp json -m "/image/.+,/posts/[0-9]+,/@.+"
+-------+-----+------+-----+-----+-----+--------+--------------------+-------+-------+---------+-------+-------+-------+-------+--------+-----------+-------------+----------------+------------+
| COUNT | 1XX | 2XX | 3XX | 4XX | 5XX | METHOD | URI | MIN | MAX | SUM | AVG | P90 | P95 | P99 | STDDEV | MIN(BODY) | MAX(BODY) | SUM(BODY) | AVG(BODY) |
+-------+-----+------+-----+-----+-----+--------+--------------------+-------+-------+---------+-------+-------+-------+-------+--------+-----------+-------------+----------------+------------+
| 25561 | 0 | 9795 | 15000 | 0 | 766 | GET | /image/.+ | 0.000 | 0.796 | 151.447 | 0.006 | 0.000 | 0.001 | 0.216 | 0.038 | 0.000 | 1089626.000 | 3136524621.000 | 122707.430 |
+-------+-----+------+-----+-----+-----+--------+--------------------+-------+-------+---------+-------+-------+-------+-------+--------+-----------+-------------+----------------+------------+
postsとusersをJOINして必要な行数だけ取得する(SCORE:13987)
diff --git a/webapp/php/index.php b/webapp/php/index.php
index 6e2a558..294b3e9 100644
--- a/webapp/php/index.php
+++ b/webapp/php/index.php
@@ -146,13 +146,16 @@ $container->set('helper', function ($c) {
unset($comment);
$post['comments'] = array_reverse($comments);
- $post['user'] = $this->fetch_first('SELECT * FROM `users` WHERE `id` = ?', $post['user_id']);
- if ($post['user']['del_flg'] == 0) {
- $posts[] = $post;
- }
- if (count($posts) >= POSTS_PER_PAGE) {
- break;
- }
+ //$post['user'] = $this->fetch_first('SELECT * FROM `users` WHERE `id` = ?', $post['user_id']);
+ $post['user'] = ['account_name' => $post['account_name']];
+
+ // if ($post['user']['del_flg'] == 0) {
+ // $posts[] = $post;
+ // }
+ // if (count($posts) >= POSTS_PER_PAGE) {
+ // break;
+ // }
+ $posts[] = $post;
}
return $posts;
}
@@ -297,7 +300,9 @@ $app->get('/', function (Request $request, Response $response) {
$me = $this->get('helper')->get_session_user();
$db = $this->get('db');
- $ps = $db->prepare('SELECT `id`, `user_id`, `body`, `mime`, `created_at` FROM `posts` ORDER BY `created_at` DESC');
+ //$ps = $db->prepare('SELECT `id`, `user_id`, `body`, `mime`, `created_at` FROM `posts` ORDER BY `created_at` DESC');
+ $ps = $db->prepare('SELECT `posts`.`id`, `posts`.`user_id`, `posts`.`body`, `posts`.`mime`, `posts`.`created_at`, `users`.`account_name` FROM `posts` INNER JOIN `users` ON `posts`.`user_id` = `users`.`id` WHERE `users`.`del_flg` = 0 ORDER BY `posts`.`created_at` DESC LIMIT ' . POSTS_PER_PAGE);
+
$ps->execute();
$results = $ps->fetchAll(PDO::FETCH_ASSOC);
$posts = $this->get('helper')->make_posts($results);
ORDER BY 狙いのINDEXも張る
ALTER TABLE posts ADD INDEX posts_order_idx(created_at DESC);
スコアも落ちたし、なんかエラーメッセージが出るようになった。
{"pass":true,"score":10579,"success":10170,"fail":12,"messages":["ページのHTMLがパースできませんでした (GET /posts)"]}
なんか変なワーニングが出ているのと関連するのか?
webapp-app-1 | [02-Sep-2023 14:23:30] WARNING: [pool www] server reached pm.max_children setting (5), consider raising it
言われた通り設定を変えて
diff --git a/webapp/php/Dockerfile b/webapp/php/Dockerfile
index 53e4d22..91966c9 100644
--- a/webapp/php/Dockerfile
+++ b/webapp/php/Dockerfile
@@ -1,5 +1,8 @@
FROM php:8.2-fpm-bullseye
+# pm.max_childrenを変更する
+RUN sed -i 's/pm.max_children = .*/pm.max_children = 20/' /usr/local/etc/php-fpm.d/www.conf
+
RUN apt update && apt install -y \
unzip libmemcached-dev zlib1g-dev
スコアはだいぶ良くなったけど、別のワーニングが出るようになった。
{"pass":true,"score":13426,"success":12769,"fail":12,"messages":["ページのHTMLがパースできませんでした (GET /posts)"]}
webapp-app-1 | [02-Sep-2023 14:53:00] WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning 32 children, there are 0 idle, and 7 total children
適切値がよく分からないけど増やしてみる
diff --git a/webapp/php/Dockerfile b/webapp/php/Dockerfile
index 53e4d22..5a95d7d 100644
--- a/webapp/php/Dockerfile
+++ b/webapp/php/Dockerfile
@@ -1,5 +1,11 @@
FROM php:8.2-fpm-bullseye
+# pm.max_childrenを変更する
+RUN sed -i 's/pm.max_children = .*/pm.max_children = 20/' /usr/local/etc/php-fpm.d/www.conf
+RUN sed -i 's/pm.start_servers = .*/pm.start_servers = 20/' /usr/local/etc/php-fpm.d/www.conf
+RUN sed -i 's/pm.min_spare_servers = .*/pm.min_spare_servers = 20/' /usr/local/etc/php-fpm.d/www.conf
+RUN sed -i 's/pm.max_spare_servers = .*/pm.max_spare_servers = 40/' /usr/local/etc/php-fpm.d/www.conf
+
RUN apt update && apt install -y \
unzip libmemcached-dev zlib1g-dev
修正後、ほとんどメッセージが出なくなった(1回だけ出たけど)ので一旦これで完了
{"pass":true,"score":13987,"success":13301,"fail":12,"messages":["ページのHTMLがパースできませんでした (GET /posts)"]}
commentsテーブルへインデックスを追加する(SCORE: 14283)
大量に発行されているこれを改善する
# Query 4: 1.40 QPS, 0.02x concurrency, ID 0xCDEB1AFF2AE2BE51B2ED5CF03D4E749F at byte 657303705
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-09-02T15:19:54 to 2023-09-02T15:20:56
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 87
# Exec time 9 1s 9ms 28ms 13ms 20ms 4ms 10ms
# Lock time 0 84us 0 3us 0 1us 0 1us
# Rows sent 0 87 1 1 1 1 0 1
# Rows examine 81 8.30M 97.66k 97.69k 97.67k 97.04k 0.00 97.04k
# Query size 0 5.43k 63 64 63.94 62.76 0 62.76
# String:
# Hosts webapp-app-1.webapp_default
# Users root
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms #####
# 10ms ################################################################
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'comments'\G
# SHOW CREATE TABLE `comments`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT COUNT(*) AS count FROM `comments` WHERE `user_id` = '314'\G
ALTER TABLE `comments` ADD INDEX `idx_user_id`(`user_id`);
スコアは微増
{"pass":true,"score":14283,"success":13585,"fail":12,"messages":["ページのHTMLがパースできませんでした (GET /posts)"]}
外部コマンド呼び出しをやめる(SCORE: 14399)
diff --git a/webapp/php/index.php b/webapp/php/index.php
index 294b3e9..a755d96 100644
--- a/webapp/php/index.php
+++ b/webapp/php/index.php
@@ -196,9 +196,10 @@ function validate_user($account_name, $password) {
}
function digest($src) {
- // opensslのバージョンによっては (stdin)= というのがつくので取る
- $src = escapeshellarg($src);
- return trim(`printf "%s" {$src} | openssl dgst -sha512 | sed 's/^.*= //'`);
+// // opensslのバージョンによっては (stdin)= というのがつくので取る
+// $src = escapeshellarg($src);
+// return trim(`printf "%s" {$src} | openssl dgst -sha512 | sed 's/^.*= //'`);
+ return hash('sha512', $src);
}
微増
{"pass":true,"score":14399,"success":13673,"fail":12,"messages":["ページのHTMLがパースできませんでした (GET /posts)"]}
postsからのN+1クエリ結果をキャッシュする(SCORE:38813)
$memcached = new Memcached();
$memcached->addServer('localhost', 11211);
直接Memcachedを操作したらエラーになった。
Fatal error: Uncaught RuntimeException: Flash messages middleware failed. Session not found. in /var/www/html/vendor/slim/flash/src/Messages.php:66 Stack trace:
use Memcachedと書いたのがダメだったっぽい。session_start()ができてなかった。
Warning: The use statement with non-compound name 'Memcached' has no effect in /var/www/html/index.php on line 7
Warning: ini_set(): Session ini settings cannot be changed after headers have already been sent in /var/www/html/index.php on line 35
Warning: ini_set(): Session ini settings cannot be changed after headers have already been sent in /var/www/html/index.php on line 36
Warning: session_start(): Session cannot be started after headers have already been sent in /var/www/html/index.php on line 38
コメント数とコメントキャッシュするようにした。ついでcommentsとusersのJOIN対応の漏れも対応
--- a/webapp/php/index.php
+++ b/webapp/php/index.php
@@ -129,24 +129,61 @@ $container->set('helper', function ($c) {
$options += ['all_comments' => false];
$all_comments = $options['all_comments'];
+ $memcached = new Memcached();
+ $memd_addr_array = explode(':', ini_get('session.save_path'));
+ $memcached->addServer($memd_addr_array[0], $memd_addr_array[1]);
+
$posts = [];
foreach ($results as $post) {
- $post['comment_count'] = $this->fetch_first('SELECT COUNT(*) AS `count` FROM `comments` WHERE `post_id` = ?', $post['id'])['count'];
- $query = 'SELECT * FROM `comments` WHERE `post_id` = ? ORDER BY `created_at` DESC';
- if (!$all_comments) {
- $query .= ' LIMIT 3';
- }
- $ps = $this->db()->prepare($query);
- $ps->execute([$post['id']]);
- $comments = $ps->fetchAll(PDO::FETCH_ASSOC);
- foreach ($comments as &$comment) {
- $comment['user'] = $this->fetch_first('SELECT * FROM `users` WHERE `id` = ?', $comment['user_id']);
+ // $post['comment_count'] = $this->fetch_first('SELECT COUNT(*) AS `count` FROM `comments` WHERE `post_id` = ?', $post['id'])['count'];
+ // 投稿ごとのコメント数をmemcachedから取得
+ $comment_count = $memcached->get("comments.{$post['id']}.count");
+ if ($comment_count === false) {
+ // Memcachedにキャッシュがない場合はDBから取得
+ $comment_count = $this->fetch_first('SELECT COUNT(*) AS `count` FROM `comments` WHERE `post_id` = ?', $post['id'])['count'];
+ // Memcachedにキャッシュを保存
+ $memcached->set("comments.{$post['id']}.count", $comment_count, 10);
+ }
+ $post['comment_count'] = $comment_count;
+
+ // 投稿ごとのコメントをmemcachedから取得
+ $comment_value = $memcached->get("comments.{$post['id']}.{$all_comments}");
+ if ($comment_value === false) {
+ // Memcachedにキャッシュがない場合はDBから取得
+ $query = 'SELECT * FROM `comments` WHERE `post_id` = ? ORDER BY `created_at` DESC';
+ if (!$all_comments) {
+ $query .= ' LIMIT 3';
+ }
+ $ps = $this->db()->prepare($query);
+ $ps->execute([$post['id']]);
+ $comments = $ps->fetchAll(PDO::FETCH_ASSOC);
+ foreach ($comments as &$comment) {
+ $comment['user'] = $this->fetch_first('SELECT * FROM `users` WHERE `id` = ?', $comment['user_id']);
+ }
+ unset($comment);
+ $post['comments'] = array_reverse($comments);
+ // Memcachedにキャッシュを保存
+ $memcached->set("comments.{$post['id']}.{$all_comments}", $post['comments'], 10);
+ } else {
+ $post['comments'] = $comment_value;
}
- unset($comment);
- $post['comments'] = array_reverse($comments);
+ // $query = 'SELECT * FROM `comments` WHERE `post_id` = ? ORDER BY `created_at` DESC';
+ // if (!$all_comments) {
+ // $query .= ' LIMIT 3';
+ // }
+
+ // $ps = $this->db()->prepare($query);
+ // $ps->execute([$post['id']]);
+ // $comments = $ps->fetchAll(PDO::FETCH_ASSOC);
+ // foreach ($comments as &$comment) {
+ // $comment['user'] = $this->fetch_first('SELECT * FROM `users` WHERE `id` = ?', $comment['user_id']);
+ // }
+ // unset($comment);
+ // $post['comments'] = array_reverse($comments);
//$post['user'] = $this->fetch_first('SELECT * FROM `users` WHERE `id` = ?', $post['user_id']);
+ //print_r($post);
$post['user'] = ['account_name' => $post['account_name']];
// if ($post['user']['del_flg'] == 0) {
@@ -319,7 +356,8 @@ $app->get('/posts', function (Request $request, Response $response) {
$params = $request->getQueryParams();
$max_created_at = $params['max_created_at'] ?? null;
$db = $this->get('db');
- $ps = $db->prepare('SELECT `id`, `user_id`, `body`, `mime`, `created_at` FROM `posts` WHERE `created_at` <= ? ORDER BY `created_at` DESC');
+ //$ps = $db->prepare('SELECT `id`, `user_id`, `body`, `mime`, `created_at` FROM `posts` WHERE `created_at` <= ? ORDER BY `created_at` DESC');
+ $ps = $db->prepare('SELECT `posts`.`id`, `posts`.`user_id`, `posts`.`body`, `posts`.`mime`, `posts`.`created_at`, `users`.`account_name` FROM `posts` INNER JOIN `users` ON `posts`.`user_id` = `users`.`id` WHERE `posts`.`created_at` <= ? ORDER BY `posts`.`created_at` DESC');
$ps->execute([$max_created_at === null ? null : $max_created_at]);
$results = $ps->fetchAll(PDO::FETCH_ASSOC);
$posts = $this->get('helper')->make_posts($results);
@@ -329,7 +367,8 @@ $app->get('/posts', function (Request $request, Response $response) {
$app->get('/posts/{id}', function (Request $request, Response $response, $args) {
$db = $this->get('db');
- $ps = $db->prepare('SELECT * FROM `posts` WHERE `id` = ?');
+ //$ps = $db->prepare('SELECT * FROM `posts` WHERE `id` = ?');
+ $ps = $db->prepare('SELECT `posts`.`id`, `posts`.`user_id`, `posts`.`body`, `posts`.`mime`, `posts`.`created_at`, `users`.`account_name` FROM `posts` INNER JOIN `users` ON `posts`.`user_id` = `users`.`id` WHERE `posts`.`id` = ?');
$ps->execute([$args['id']]);
$results = $ps->fetchAll(PDO::FETCH_ASSOC);
$posts = $this->get('helper')->make_posts($results, ['all_comments' => true]);
@@ -516,7 +555,8 @@ $app->get('/@{account_name}', function (Request $request, Response $response, $a
return $response->withStatus(404);
}
- $ps = $db->prepare('SELECT `id`, `user_id`, `body`, `created_at`, `mime` FROM `posts` WHERE `user_id` = ? ORDER BY `created_at` DESC');
+ //$ps = $db->prepare('SELECT `id`, `user_id`, `body`, `created_at`, `mime` FROM `posts` WHERE `user_id` = ? ORDER BY `created_at` DESC');
+ $ps = $db->prepare('SELECT `posts`.`id`, `posts`.`user_id`, `posts`.`body`, `posts`.`created_at`, `posts`.`mime`, `users`.`account_name` FROM `posts` INNER JOIN `users` ON `posts`.`user_id` = `users`.`id` WHERE `users`.`del_flg` = 0 AND `posts`.`user_id` = ? ORDER BY `posts`.`created_at` DESC');
$ps->execute([$user['id']]);
$results = $ps->fetchAll(PDO::FETCH_ASSOC);
$posts = $this->get('helper')->make_posts($results);
大幅に改善した
{"pass":true,"score":38813,"success":36582,"fail":12,"messages":["リクエストがタイムアウトしました (GET /posts)"]}
適切なインデックスが使えないクエリを解決する(SCORE: 30275)
ALTER TABLE `posts` ADD INDEX `posts_user_idx`(`user_id`,`created_at` DESC);
確かにスコアが下がった
{"pass":true,"score":31611,"success":29858,"fail":12,"messages":["リクエストがタイムアウトしました (GET /posts)"]}
diff --git a/webapp/php/index.php b/webapp/php/index.php
index 1e68de9..3f21597 100644
--- a/webapp/php/index.php
+++ b/webapp/php/index.php
@@ -556,7 +556,7 @@ $app->get('/@{account_name}', function (Request $request, Response $response, $a
}
//$ps = $db->prepare('SELECT `id`, `user_id`, `body`, `created_at`, `mime` FROM `posts` WHERE `user_id` = ? ORDER BY `created_at` DESC');
- $ps = $db->prepare('SELECT `posts`.`id`, `posts`.`user_id`, `posts`.`body`, `posts`.`created_at`, `posts`.`mime`, `users`.`account_name` FROM `posts` INNER JOIN `users` ON `posts`.`user_id` = `users`.`id` WHERE `users`.`del_flg` = 0 AND `posts`.`user_id` = ? ORDER BY `posts`.`created_at` DESC');
+ $ps = $db->prepare('SELECT `posts`.`id`, `posts`.`user_id`, `posts`.`body`, `posts`.`created_at`, `posts`.`mime`, `users`.`account_name` FROM `posts` FORCE INDEX('posts_user_idx') INNER JOIN `users` ON `posts`.`user_id` = `users`.`id` WHERE `users`.`del_flg` = 0 AND `posts`.`user_id` = ? ORDER BY `posts`.`created_at` DESC');
$ps->execute([$user['id']]);
$results = $ps->fetchAll(PDO::FETCH_ASSOC);
$posts = $this->get('helper')->make_posts($results);
逆にスコアが落ちた
{"pass":true,"score":30275,"success":28570,"fail":12,"messages":["リクエストがタイムアウトしました (GET /posts)"]}
memcachedへのN+1を解消する(SCORE: 31119)
diff --git a/webapp/php/index.php b/webapp/php/index.php
index 3f21597..84127f4 100644
--- a/webapp/php/index.php
+++ b/webapp/php/index.php
@@ -133,12 +133,22 @@ $container->set('helper', function ($c) {
$memd_addr_array = explode(':', ini_get('session.save_path'));
$memcached->addServer($memd_addr_array[0], $memd_addr_array[1]);
+ // "comments.{$post['id']}.count"を配列に格納
+ $count_keys = [];
+ $comment_keys = [];
+ foreach ($results as $post) {
+ $count_keys[] = "comments.{$post['id']}.count";
+ $comment_keys[] = "comments.{$post['id']}.{$all_comments}";
+ }
+ $cached_counts = $memcached->getMulti($count_keys);
+ $cached_comments = $memcached->getMulti($comment_keys);
+
$posts = [];
foreach ($results as $post) {
// $post['comment_count'] = $this->fetch_first('SELECT COUNT(*) AS `count` FROM `comments` WHERE `post_id` = ?', $post['id'])['count'];
// 投稿ごとのコメント数をmemcachedから取得
- $comment_count = $memcached->get("comments.{$post['id']}.count");
+ $comment_count = $cached_counts["comments.{$post['id']}.count"];
if ($comment_count === false) {
// Memcachedにキャッシュがない場合はDBから取得
$comment_count = $this->fetch_first('SELECT COUNT(*) AS `count` FROM `comments` WHERE `post_id` = ?', $post['id'])['count'];
@@ -148,7 +158,7 @@ $container->set('helper', function ($c) {
$post['comment_count'] = $comment_count;
// 投稿ごとのコメントをmemcachedから取得
- $comment_value = $memcached->get("comments.{$post['id']}.{$all_comments}");
+ $comment_value = $cached_comments["comments.{$post['id']}.{$all_comments}"];
if ($comment_value === false) {
// Memcachedにキャッシュがない場合はDBから取得
$query = 'SELECT * FROM `comments` WHERE `post_id` = ? ORDER BY `created_at` DESC';
{"pass":true,"score":31119,"success":29398,"fail":12,"messages":["リクエストがタイムアウトしました (GET /posts)"]}
commentとusersをJOINする(SCORE: 32944)
diff --git a/webapp/php/index.php b/webapp/php/index.php
index 9481496..8f44868 100644
--- a/webapp/php/index.php
+++ b/webapp/php/index.php
@@ -160,10 +160,11 @@ $container->set('helper', function ($c) {
$post['comment_count'] = $comment_count;
// 投稿ごとのコメントをmemcachedから取得
- $comment_value = $cached_comments["comments.{$post['id']}.{$all_comments}"];
- if ($comment_value === false) {
+ if (isset($cached_comments["comments.{$post['id']}.{$all_comments}"])) {
+ $post['comments'] = $cached_comments["comments.{$post['id']}.{$all_comments}"];
+ } else {
// Memcachedにキャッシュがない場合はDBから取得
- $query = 'SELECT * FROM `comments` WHERE `post_id` = ? ORDER BY `created_at` DESC';
+ $query = 'SELECT `comments`.`comment`, `users`.`account_name` FROM `comments` INNER JOIN `users` ON `comments`.`user_id` = `users`.`id` WHERE `post_id` = ? ORDER BY `comments`.`created_at` DESC';
if (!$all_comments) {
$query .= ' LIMIT 3';
}
@@ -171,14 +172,13 @@ $container->set('helper', function ($c) {
$ps->execute([$post['id']]);
$comments = $ps->fetchAll(PDO::FETCH_ASSOC);
foreach ($comments as &$comment) {
- $comment['user'] = $this->fetch_first('SELECT * FROM `users` WHERE `id` = ?', $comment['user_id']);
+ //$comment['user'] = $this->fetch_first('SELECT * FROM `users` WHERE `id` = ?', $comment['user_id']);
+ $comment['user'] = ['account_name' => $comment['account_name']];
}
unset($comment);
$post['comments'] = array_reverse($comments);
// Memcachedにキャッシュを保存
$memcached->set("comments.{$post['id']}.{$all_comments}", $post['comments'], 10);
- } else {
- $post['comments'] = $comment_value;
}
// $query = 'SELECT * FROM `comments` WHERE `post_id` = ? ORDER BY `created_at` DESC';
// if (!$all_comments) {
最終的なpg-query-digestの結果
# 9.8s user time, 110ms system time, 35.30M rss, 389.77G vsz
# Current date: Sun Sep 3 18:50:53 2023
# Hostname: MacBookPro2021
# Files: logs/mysql/mysqlslow.log
# Overall: 236.17k total, 24 unique, 1.02k QPS, 0.66x concurrency ________
# Time range: 2023-09-03T09:44:34 to 2023-09-03T09:48:25
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 154s 1us 429ms 650us 424us 7ms 93us
# Lock time 384ms 0 36ms 1us 1us 86us 1us
# Rows sent 597.92k 0 9.76k 2.59 2.90 68.11 0.99
# Rows examine 17.22M 0 20.61k 76.47 14.52 838.18 5.75
# Query size 29.28M 27 307 130.01 192.76 65.16 65.89
# Profile
# Rank Query ID Response time Calls R/Call V/
# ==== =================================== ============== ====== ====== ==
# 1 0x01FC258EA063B3C25700886A16FC2476 112.5191 73.3% 1460 0.0771 0.03 SELECT posts users
# 2 0x13A5F43F08D701A98595EFFEEEB00AFF 19.2202 12.5% 112458 0.0002 0.00 SELECT comments users
# 3 0x422390B42D4DD86C7539A5F45EB76A80 15.4889 10.1% 112394 0.0001 0.00 SELECT comments
# MISC 0xMISC 6.2893 4.1% 9859 0.0006 0.0 <21 ITEMS>
# Query 1: 23.55 QPS, 1.81x concurrency, ID 0x01FC258EA063B3C25700886A16FC2476 at byte 76373
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.03
# Time range: 2023-09-03T09:44:34 to 2023-09-03T09:45:36
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 1460
# Exec time 73 113s 14ms 321ms 77ms 180ms 49ms 65ms
# Lock time 1 5ms 0 1ms 3us 1us 35us 1us
# Rows sent 4 28.52k 20 20 20 20 0 20
# Rows examine 88 15.22M 10.56k 10.79k 10.67k 10.29k 0 10.29k
# Query size 1 365.00k 256 256 256 256 0 256
# String:
# Hosts webapp-app-1.webapp_default
# Users root
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms ################################################################
# 100ms #########################
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'posts'\G
# SHOW CREATE TABLE `posts`\G
# SHOW TABLE STATUS LIKE 'users'\G
# SHOW CREATE TABLE `users`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT `posts`.`id`, `posts`.`user_id`, `posts`.`body`, `posts`.`mime`, `posts`.`created_at`, `users`.`account_name` FROM `posts` INNER JOIN `users` ON `posts`.`user_id` = `users`.`id` WHERE `users`.`del_flg` = 0 ORDER BY `posts`.`created_at` DESC LIMIT 20\G
# Query 2: 486.83 QPS, 0.08x concurrency, ID 0x13A5F43F08D701A98595EFFEEEB00AFF at byte 8838247
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-09-03T09:44:34 to 2023-09-03T09:48:25
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 47 112458
# Exec time 12 19s 55us 48ms 170us 403us 397us 98us
# Lock time 53 204ms 0 36ms 1us 1us 109us 1us
# Rows sent 54 327.76k 0 3 2.98 2.90 0.19 2.90
# Rows examine 3 655.51k 0 6 5.97 5.75 0.38 5.75
# Query size 71 21.01M 193 197 195.89 192.76 0 192.76
# String:
# Hosts webapp-app-1.webapp_default
# Users root
# Query_time distribution
# 1us
# 10us ########################################################
# 100us ################################################################
# 1ms #
# 10ms #
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'comments'\G
# SHOW CREATE TABLE `comments`\G
# SHOW TABLE STATUS LIKE 'users'\G
# SHOW CREATE TABLE `users`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT `comments`.`comment`, `users`.`account_name` FROM `comments` INNER JOIN `users` ON `comments`.`user_id` = `users`.`id` WHERE `post_id` = '9302' ORDER BY `comments`.`created_at` DESC LIMIT 3\G
# Query 3: 486.55 QPS, 0.07x concurrency, ID 0x422390B42D4DD86C7539A5F45EB76A80 at byte 8259487
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-09-03T09:44:34 to 2023-09-03T09:48:25
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 47 112394
# Exec time 10 15s 38us 44ms 137us 332us 351us 76us
# Lock time 41 161ms 0 21ms 1us 1us 61us 1us
# Rows sent 18 109.76k 1 1 1 1 0 1
# Rows examine 6 1.07M 0 23 9.97 14.52 3.13 9.83
# Query size 24 7.17M 64 68 66.89 65.89 0.32 65.89
# String:
# Hosts webapp-app-1.webapp_default
# Users root
# Query_time distribution
# 1us
# 10us ################################################################
# 100us #####################################
# 1ms #
# 10ms #
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'comments'\G
# SHOW CREATE TABLE `comments`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT COUNT(*) AS `count` FROM `comments` WHERE `post_id` = '9336'\G