Closed pinkumohikan closed 5 years ago
edwardo3657はユーザのID
初期状態のベンチ
{
"valid" : true,
"requests" : 1222,
"elapsed" : 76230,
"done" : "[{Isucon5InitExecutor},{BootstrapChecker},{Isucon5Load,Isucon5Load,Isucon5Load,Isucon5Load,Isucon5Checker}]",
"responses" : {
"success" : 944,
"redirect" : 277,
"failure" : 1,
"error" : 0,
"exception" : 0
},
"violations" : [ ]
}
memo: ベンチの回し方
cd /home/isucon/isucon5-qualify/bench
cat ~/webapp/script/testsets/testsets.json | jq '.[0]' | gradle run -Pargs="net.isucon.isucon5q.bench.scenario.Isucon5Qualification 127.0.0.1"
netdata入れる
# make sure you run `bash` for your shell
bash
# install Netdata directly from GitHub source
bash <(curl -Ss https://my-netdata.io/kickstart.sh)
systemctl start netdata
systemctl stop netdata
ミドルウェア等の初期バージョン
# mysql --version
mysql Ver 14.14 Distrib 5.7.25, for Linux (x86_64) using EditLine wrapper
# nginx -v
nginx version: nginx/1.14.0 (Ubuntu)
# go version
go version go1.10.4 linux/amd64
netdata 用のポート番号を開けておく必要がある
TCP: 19999
・sessionのbackendはcookie (dbやmemcacheとかは使ってない) ・mysqlへ依存 ・staticファイルの配信をアプリからやってるっぽい ・アプリは8080でlistenしてる
各種設定のバックアップ :done:
sudo cat /var/log/nginx/access.log | ./kataribe
{
"valid" : true,
"requests" : 1389,
"elapsed" : 65073,
"done" : "[{Isucon5InitExecutor},{BootstrapChecker},{Isucon5Load,Isucon5Load,Isucon5Load,Isucon5Load,Isucon5Checker}]",
"responses" : {
"success" : 1067,
"redirect" : 321,
"failure" : 1,
"error" : 0,
"exception" : 0
},
"violations" : [ ]
}
isucon@iZ6wef3qmnwxt2ngt1il94Z:~$ sudo cat /var/log/nginx/access.log | ./kataribe
Top 20 Sort By Count
Count Total Mean Stddev Min P50.0 P90.0 P95.0 P99.0 Max 2xx 3xx 4xx 5xx TotalBytes MinBytes MeanBytes MaxBytes Request
254 226.652 0.892331 0.345878 0.000 0.936 1.133 1.192 1.319 3.731 234 20 0 0 4115312 29 16202 17750 GET / HTTP/1.1
90 0.045 0.000500 0.000563 0.000 0.000 0.001 0.001 0.002 0.002 90 0 0 0 92340 1026 1026 1026 GET /login HTTP/1.1
90 0.164 0.001822 0.001918 0.000 0.001 0.003 0.005 0.016 0.016 0 90 0 0 0 0 0 0 POST /login HTTP/1.1
89 27.604 0.310157 0.049717 0.160 0.296 0.388 0.405 0.438 0.438 89 0 0 0 1421957 13272 15977 18323 GET /friends HTTP/1.1
67 0.033 0.000493 0.000529 0.000 0.000 0.001 0.001 0.002 0.002 0 67 0 0 1943 29 29 29 GET /logout HTTP/1.1
66 16.022 0.242758 0.051864 0.119 0.231 0.295 0.360 0.405 0.405 66 0 0 0 541450 8126 8203 8277 GET /footprints HTTP/1.1
64 0.349 0.005453 0.008107 0.002 0.003 0.009 0.014 0.060 0.060 0 64 0 0 0 0 0 0 POST /diary/entry HTTP/1.1
22 0.354 0.016091 0.005559 0.009 0.015 0.025 0.025 0.031 0.031 22 0 0 0 1374306 50281 62468 71768 GET /diary/entries/joesph_langworth88 HTTP/1.1
18 0.721 0.040056 0.094733 0.008 0.019 0.028 0.430 0.430 0.430 18 0 0 0 1137028 53408 63168 72412 GET /diary/entries/brayan1665 HTTP/1.1
16 0.103 0.006438 0.004153 0.003 0.006 0.012 0.020 0.020 0.020 16 0 0 0 67763 2888 4235 5963 GET /profile/joesph_langworth88 HTTP/1.1
15 0.279 0.018600 0.007392 0.010 0.018 0.032 0.037 0.037 0.037 15 0 0 0 993981 57521 66265 72165 GET /diary/entries/melvin257 HTTP/1.1
15 0.112 0.007467 0.004440 0.003 0.006 0.015 0.016 0.016 0.016 15 0 0 0 61890 2900 4126 5966 GET /profile/melvin257 HTTP/1.1
15 0.093 0.006200 0.001904 0.003 0.006 0.008 0.011 0.011 0.011 15 0 0 0 57910 2841 3860 5900 GET /profile/vincent3181 HTTP/1.1
15 0.254 0.016933 0.006933 0.010 0.016 0.021 0.040 0.040 0.040 15 0 0 0 978669 56849 65244 72050 GET /diary/entries/maybell3768 HTTP/1.1
15 0.281 0.018733 0.005825 0.011 0.018 0.030 0.032 0.032 0.032 15 0 0 0 972896 56567 64859 72060 GET /diary/entries/vada4885 HTTP/1.1
15 0.259 0.017267 0.006005 0.009 0.016 0.029 0.030 0.030 0.030 15 0 0 0 973534 56244 64902 71757 GET /diary/entries/vincent3181 HTTP/1.1
14 0.070 0.005000 0.002268 0.003 0.004 0.009 0.009 0.009 0.009 14 0 0 0 64530 2859 4609 5922 GET /profile/brayan1665 HTTP/1.1
14 0.185 0.013214 0.002110 0.010 0.014 0.016 0.016 0.016 0.016 14 0 0 0 921516 59510 65822 72728 GET /diary/entries/ashleigh_blick1542 HTTP/1.1
13 0.082 0.006308 0.002162 0.003 0.006 0.009 0.011 0.011 0.011 13 0 0 0 49613 2873 3816 5939 GET /profile/ashleigh_blick1542 HTTP/1.1
12 0.220 0.018333 0.008863 0.012 0.015 0.021 0.046 0.046 0.046 12 0 0 0 807313 60153 67276 72560 GET /diary/entries/vaughn_heathcote3206 HTTP/1.1
Top 20 Sort By Total
Count Total Mean Stddev Min P50.0 P90.0 P95.0 P99.0 Max 2xx 3xx 4xx 5xx TotalBytes MinBytes MeanBytes MaxBytes Request
254 226.652 0.892331 0.345878 0.000 0.936 1.133 1.192 1.319 3.731 234 20 0 0 4115312 29 16202 17750 GET / HTTP/1.1
89 27.604 0.310157 0.049717 0.160 0.296 0.388 0.405 0.438 0.438 89 0 0 0 1421957 13272 15977 18323 GET /friends HTTP/1.1
66 16.022 0.242758 0.051864 0.119 0.231 0.295 0.360 0.405 0.405 66 0 0 0 541450 8126 8203 8277 GET /footprints HTTP/1.1
18 0.721 0.040056 0.094733 0.008 0.019 0.028 0.430 0.430 0.430 18 0 0 0 1137028 53408 63168 72412 GET /diary/entries/brayan1665 HTTP/1.1
3 0.474 0.158000 0.196659 0.012 0.026 0.436 0.436 0.436 0.436 3 0 0 0 213528 69489 71176 72443 GET /diary/entries/ola_spinka3898 HTTP/1.1
22 0.354 0.016091 0.005559 0.009 0.015 0.025 0.025 0.031 0.031 22 0 0 0 1374306 50281 62468 71768 GET /diary/entries/joesph_langworth88 HTTP/1.1
64 0.349 0.005453 0.008107 0.002 0.003 0.009 0.014 0.060 0.060 0 64 0 0 0 0 0 0 POST /diary/entry HTTP/1.1
15 0.281 0.018733 0.005825 0.011 0.018 0.030 0.032 0.032 0.032 15 0 0 0 972896 56567 64859 72060 GET /diary/entries/vada4885 HTTP/1.1
15 0.279 0.018600 0.007392 0.010 0.018 0.032 0.037 0.037 0.037 15 0 0 0 993981 57521 66265 72165 GET /diary/entries/melvin257 HTTP/1.1
15 0.259 0.017267 0.006005 0.009 0.016 0.029 0.030 0.030 0.030 15 0 0 0 973534 56244 64902 71757 GET /diary/entries/vincent3181 HTTP/1.1
15 0.254 0.016933 0.006933 0.010 0.016 0.021 0.040 0.040 0.040 15 0 0 0 978669 56849 65244 72050 GET /diary/entries/maybell3768 HTTP/1.1
12 0.220 0.018333 0.008863 0.012 0.015 0.021 0.046 0.046 0.046 12 0 0 0 807313 60153 67276 72560 GET /diary/entries/vaughn_heathcote3206 HTTP/1.1
10 0.205 0.020500 0.006004 0.014 0.022 0.032 0.032 0.032 0.032 10 0 0 0 678002 62423 67800 71575 GET /diary/entries/annamae350 HTTP/1.1
6 0.188 0.031333 0.029797 0.009 0.024 0.096 0.096 0.096 0.096 6 0 0 0 423160 66289 70526 72916 GET /diary/entries/armando772 HTTP/1.1
14 0.185 0.013214 0.002110 0.010 0.014 0.016 0.016 0.016 0.016 14 0 0 0 921516 59510 65822 72728 GET /diary/entries/ashleigh_blick1542 HTTP/1.1
11 0.173 0.015727 0.005512 0.009 0.015 0.021 0.029 0.029 0.029 11 0 0 0 735047 63232 66822 71441 GET /diary/entries/glen4851 HTTP/1.1
90 0.164 0.001822 0.001918 0.000 0.001 0.003 0.005 0.016 0.016 0 90 0 0 0 0 0 0 POST /login HTTP/1.1
6 0.121 0.020167 0.003436 0.016 0.022 0.025 0.025 0.025 0.025 6 0 0 0 417329 66154 69554 72256 GET /diary/entries/aurore_senger1051 HTTP/1.1
6 0.120 0.020000 0.005831 0.013 0.019 0.029 0.029 0.029 0.029 6 0 0 0 415672 66067 69278 71962 GET /diary/entries/bud_cruickshank2266 HTTP/1.1
15 0.112 0.007467 0.004440 0.003 0.006 0.015 0.016 0.016 0.016 15 0 0 0 61890 2900 4126 5966 GET /profile/melvin257 HTTP/1.1
Top 20 Sort By Mean
Count Total Mean Stddev Min P50.0 P90.0 P95.0 P99.0 Max 2xx 3xx 4xx 5xx TotalBytes MinBytes MeanBytes MaxBytes Request
254 226.652 0.892331 0.345878 0.000 0.936 1.133 1.192 1.319 3.731 234 20 0 0 4115312 29 16202 17750 GET / HTTP/1.1
89 27.604 0.310157 0.049717 0.160 0.296 0.388 0.405 0.438 0.438 89 0 0 0 1421957 13272 15977 18323 GET /friends HTTP/1.1
66 16.022 0.242758 0.051864 0.119 0.231 0.295 0.360 0.405 0.405 66 0 0 0 541450 8126 8203 8277 GET /footprints HTTP/1.1
3 0.474 0.158000 0.196659 0.012 0.026 0.436 0.436 0.436 0.436 3 0 0 0 213528 69489 71176 72443 GET /diary/entries/ola_spinka3898 HTTP/1.1
18 0.721 0.040056 0.094733 0.008 0.019 0.028 0.430 0.430 0.430 18 0 0 0 1137028 53408 63168 72412 GET /diary/entries/brayan1665 HTTP/1.1
1 0.032 0.032000 0.000000 0.032 0.032 0.032 0.032 0.032 0.032 0 1 0 0 0 0 0 0 POST /diary/comment/494842 HTTP/1.1
6 0.188 0.031333 0.029797 0.009 0.024 0.096 0.096 0.096 0.096 6 0 0 0 423160 66289 70526 72916 GET /diary/entries/armando772 HTTP/1.1
10 0.205 0.020500 0.006004 0.014 0.022 0.032 0.032 0.032 0.032 10 0 0 0 678002 62423 67800 71575 GET /diary/entries/annamae350 HTTP/1.1
6 0.121 0.020167 0.003436 0.016 0.022 0.025 0.025 0.025 0.025 6 0 0 0 417329 66154 69554 72256 GET /diary/entries/aurore_senger1051 HTTP/1.1
6 0.120 0.020000 0.005831 0.013 0.019 0.029 0.029 0.029 0.029 6 0 0 0 415672 66067 69278 71962 GET /diary/entries/bud_cruickshank2266 HTTP/1.1
3 0.058 0.019333 0.010403 0.011 0.013 0.034 0.034 0.034 0.034 3 0 0 0 210002 68209 70000 71248 GET /diary/entries/aaliyah_reichel2696 HTTP/1.1
15 0.281 0.018733 0.005825 0.011 0.018 0.030 0.032 0.032 0.032 15 0 0 0 972896 56567 64859 72060 GET /diary/entries/vada4885 HTTP/1.1
3 0.056 0.018667 0.018661 0.004 0.007 0.045 0.045 0.045 0.045 3 0 0 0 15455 4933 5151 5261 GET /diary/entry/484389 HTTP/1.1
15 0.279 0.018600 0.007392 0.010 0.018 0.032 0.037 0.037 0.037 15 0 0 0 993981 57521 66265 72165 GET /diary/entries/melvin257 HTTP/1.1
12 0.220 0.018333 0.008863 0.012 0.015 0.021 0.046 0.046 0.046 12 0 0 0 807313 60153 67276 72560 GET /diary/entries/vaughn_heathcote3206 HTTP/1.1
6 0.108 0.018000 0.005508 0.011 0.020 0.026 0.026 0.026 0.026 6 0 0 0 419144 66381 69857 72630 GET /diary/entries/hilario2774 HTTP/1.1
6 0.106 0.017667 0.004110 0.013 0.017 0.023 0.023 0.023 0.023 6 0 0 0 421038 66746 70173 73202 GET /diary/entries/maida_hane3532 HTTP/1.1
15 0.259 0.017267 0.006005 0.009 0.016 0.029 0.030 0.030 0.030 15 0 0 0 973534 56244 64902 71757 GET /diary/entries/vincent3181 HTTP/1.1
6 0.103 0.017167 0.004298 0.012 0.017 0.023 0.023 0.023 0.023 6 0 0 0 416919 66351 69486 72130 GET /diary/entries/halle_bernier4949 HTTP/1.1
15 0.254 0.016933 0.006933 0.010 0.016 0.021 0.040 0.040 0.040 15 0 0 0 978669 56849 65244 72050 GET /diary/entries/maybell3768 HTTP/1.1
Top 20 Sort By Standard Deviation
Count Total Mean Stddev Min P50.0 P90.0 P95.0 P99.0 Max 2xx 3xx 4xx 5xx TotalBytes MinBytes MeanBytes MaxBytes Request
254 226.652 0.892331 0.345878 0.000 0.936 1.133 1.192 1.319 3.731 234 20 0 0 4115312 29 16202 17750 GET / HTTP/1.1
3 0.474 0.158000 0.196659 0.012 0.026 0.436 0.436 0.436 0.436 3 0 0 0 213528 69489 71176 72443 GET /diary/entries/ola_spinka3898 HTTP/1.1
18 0.721 0.040056 0.094733 0.008 0.019 0.028 0.430 0.430 0.430 18 0 0 0 1137028 53408 63168 72412 GET /diary/entries/brayan1665 HTTP/1.1
66 16.022 0.242758 0.051864 0.119 0.231 0.295 0.360 0.405 0.405 66 0 0 0 541450 8126 8203 8277 GET /footprints HTTP/1.1
89 27.604 0.310157 0.049717 0.160 0.296 0.388 0.405 0.438 0.438 89 0 0 0 1421957 13272 15977 18323 GET /friends HTTP/1.1
6 0.188 0.031333 0.029797 0.009 0.024 0.096 0.096 0.096 0.096 6 0 0 0 423160 66289 70526 72916 GET /diary/entries/armando772 HTTP/1.1
3 0.056 0.018667 0.018661 0.004 0.007 0.045 0.045 0.045 0.045 3 0 0 0 15455 4933 5151 5261 GET /diary/entry/484389 HTTP/1.1
3 0.048 0.016000 0.015578 0.004 0.006 0.038 0.038 0.038 0.038 3 0 0 0 4053 1127 1351 1463 GET /diary/entry/500126 HTTP/1.1
3 0.037 0.012333 0.011813 0.003 0.005 0.029 0.029 0.029 0.029 3 0 0 0 14507 4617 4835 4945 GET /diary/entry/494842 HTTP/1.1
3 0.058 0.019333 0.010403 0.011 0.013 0.034 0.034 0.034 0.034 3 0 0 0 210002 68209 70000 71248 GET /diary/entries/aaliyah_reichel2696 HTTP/1.1
12 0.220 0.018333 0.008863 0.012 0.015 0.021 0.046 0.046 0.046 12 0 0 0 807313 60153 67276 72560 GET /diary/entries/vaughn_heathcote3206 HTTP/1.1
64 0.349 0.005453 0.008107 0.002 0.003 0.009 0.014 0.060 0.060 0 64 0 0 0 0 0 0 POST /diary/entry HTTP/1.1
3 0.028 0.009333 0.007587 0.003 0.005 0.020 0.020 0.020 0.020 0 3 0 0 0 0 0 0 POST /friends/eriberto2028 HTTP/1.1
3 0.029 0.009667 0.007409 0.003 0.006 0.020 0.020 0.020 0.020 3 0 0 0 3871 1063 1290 1404 GET /diary/entry/500143 HTTP/1.1
15 0.279 0.018600 0.007392 0.010 0.018 0.032 0.037 0.037 0.037 15 0 0 0 993981 57521 66265 72165 GET /diary/entries/melvin257 HTTP/1.1
12 0.088 0.007333 0.007040 0.002 0.006 0.008 0.030 0.030 0.030 12 0 0 0 22134 1059 1844 2403 GET /diary/entry/500137 HTTP/1.1
15 0.254 0.016933 0.006933 0.010 0.016 0.021 0.040 0.040 0.040 15 0 0 0 978669 56849 65244 72050 GET /diary/entries/maybell3768 HTTP/1.1
6 0.039 0.006500 0.006131 0.002 0.005 0.020 0.020 0.020 0.020 6 0 0 0 26975 3983 4495 4670 GET /diary/entry/497511 HTTP/1.1
3 0.025 0.008333 0.006128 0.004 0.004 0.017 0.017 0.017 0.017 3 0 0 0 12626 3986 4208 4320 GET /diary/entry/498759 HTTP/1.1
15 0.259 0.017267 0.006005 0.009 0.016 0.029 0.030 0.030 0.030 15 0 0 0 973534 56244 64902 71757 GET /diary/entries/vincent3181 HTTP/1.1
Top 20 Sort By Maximum(100 Percentile)
Count Total Mean Stddev Min P50.0 P90.0 P95.0 P99.0 Max 2xx 3xx 4xx 5xx TotalBytes MinBytes MeanBytes MaxBytes Request
254 226.652 0.892331 0.345878 0.000 0.936 1.133 1.192 1.319 3.731 234 20 0 0 4115312 29 16202 17750 GET / HTTP/1.1
89 27.604 0.310157 0.049717 0.160 0.296 0.388 0.405 0.438 0.438 89 0 0 0 1421957 13272 15977 18323 GET /friends HTTP/1.1
3 0.474 0.158000 0.196659 0.012 0.026 0.436 0.436 0.436 0.436 3 0 0 0 213528 69489 71176 72443 GET /diary/entries/ola_spinka3898 HTTP/1.1
18 0.721 0.040056 0.094733 0.008 0.019 0.028 0.430 0.430 0.430 18 0 0 0 1137028 53408 63168 72412 GET /diary/entries/brayan1665 HTTP/1.1
66 16.022 0.242758 0.051864 0.119 0.231 0.295 0.360 0.405 0.405 66 0 0 0 541450 8126 8203 8277 GET /footprints HTTP/1.1
6 0.188 0.031333 0.029797 0.009 0.024 0.096 0.096 0.096 0.096 6 0 0 0 423160 66289 70526 72916 GET /diary/entries/armando772 HTTP/1.1
64 0.349 0.005453 0.008107 0.002 0.003 0.009 0.014 0.060 0.060 0 64 0 0 0 0 0 0 POST /diary/entry HTTP/1.1
12 0.220 0.018333 0.008863 0.012 0.015 0.021 0.046 0.046 0.046 12 0 0 0 807313 60153 67276 72560 GET /diary/entries/vaughn_heathcote3206 HTTP/1.1
3 0.056 0.018667 0.018661 0.004 0.007 0.045 0.045 0.045 0.045 3 0 0 0 15455 4933 5151 5261 GET /diary/entry/484389 HTTP/1.1
15 0.254 0.016933 0.006933 0.010 0.016 0.021 0.040 0.040 0.040 15 0 0 0 978669 56849 65244 72050 GET /diary/entries/maybell3768 HTTP/1.1
3 0.048 0.016000 0.015578 0.004 0.006 0.038 0.038 0.038 0.038 3 0 0 0 4053 1127 1351 1463 GET /diary/entry/500126 HTTP/1.1
15 0.279 0.018600 0.007392 0.010 0.018 0.032 0.037 0.037 0.037 15 0 0 0 993981 57521 66265 72165 GET /diary/entries/melvin257 HTTP/1.1
3 0.058 0.019333 0.010403 0.011 0.013 0.034 0.034 0.034 0.034 3 0 0 0 210002 68209 70000 71248 GET /diary/entries/aaliyah_reichel2696 HTTP/1.1
1 0.032 0.032000 0.000000 0.032 0.032 0.032 0.032 0.032 0.032 0 1 0 0 0 0 0 0 POST /diary/comment/494842 HTTP/1.1
10 0.205 0.020500 0.006004 0.014 0.022 0.032 0.032 0.032 0.032 10 0 0 0 678002 62423 67800 71575 GET /diary/entries/annamae350 HTTP/1.1
15 0.281 0.018733 0.005825 0.011 0.018 0.030 0.032 0.032 0.032 15 0 0 0 972896 56567 64859 72060 GET /diary/entries/vada4885 HTTP/1.1
22 0.354 0.016091 0.005559 0.009 0.015 0.025 0.025 0.031 0.031 22 0 0 0 1374306 50281 62468 71768 GET /diary/entries/joesph_langworth88 HTTP/1.1
15 0.259 0.017267 0.006005 0.009 0.016 0.029 0.030 0.030 0.030 15 0 0 0 973534 56244 64902 71757 GET /diary/entries/vincent3181 HTTP/1.1
12 0.088 0.007333 0.007040 0.002 0.006 0.008 0.030 0.030 0.030 12 0 0 0 22134 1059 1844 2403 GET /diary/entry/500137 HTTP/1.1
6 0.100 0.016667 0.005821 0.012 0.014 0.029 0.029 0.029 0.029 6 0 0 0 415246 65845 69207 71812 GET /diary/entries/ashlee4481 HTTP/1.1
TOP 37 Slow Requests
1 3.731 GET / HTTP/1.1
2 1.498 GET / HTTP/1.1
3 1.319 GET / HTTP/1.1
4 1.304 GET / HTTP/1.1
5 1.290 GET / HTTP/1.1
6 1.274 GET / HTTP/1.1
7 1.267 GET / HTTP/1.1
8 1.240 GET / HTTP/1.1
9 1.226 GET / HTTP/1.1
10 1.213 GET / HTTP/1.1
11 1.213 GET / HTTP/1.1
12 1.195 GET / HTTP/1.1
13 1.192 GET / HTTP/1.1
14 1.187 GET / HTTP/1.1
15 1.179 GET / HTTP/1.1
16 1.174 GET / HTTP/1.1
17 1.173 GET / HTTP/1.1
18 1.171 GET / HTTP/1.1
19 1.162 GET / HTTP/1.1
20 1.157 GET / HTTP/1.1
21 1.150 GET / HTTP/1.1
22 1.146 GET / HTTP/1.1
23 1.136 GET / HTTP/1.1
24 1.135 GET / HTTP/1.1
25 1.133 GET / HTTP/1.1
26 1.133 GET / HTTP/1.1
27 1.129 GET / HTTP/1.1
28 1.126 GET / HTTP/1.1
29 1.124 GET / HTTP/1.1
30 1.124 GET / HTTP/1.1
31 1.123 GET / HTTP/1.1
32 1.122 GET / HTTP/1.1
33 1.117 GET / HTTP/1.1
34 1.115 GET / HTTP/1.1
35 1.111 GET / HTTP/1.1
36 1.107 GET / HTTP/1.1
37 1.107 GET / HTTP/1.1
てす
てすてす
varnish インストール :done:
# varnishd -V
varnishd (varnish-5.2.1 revision 67e562482)
Copyright (c) 2006 Verdens Gang AS
Copyright (c) 2006-2015 Varnish Software AS
MySQL Slow query log
{
"valid" : true,
"requests" : 1380,
"elapsed" : 65696,
"done" : "[{Isucon5InitExecutor},{BootstrapChecker},{Isucon5Load,Isucon5Load,Isucon5Load,Isucon5Load,Isucon5Checker}]",
"responses" : {
"success" : 1068,
"redirect" : 311,
"failure" : 1,
"error" : 0,
"exception" : 0
},
"violations" : [ ]
}
isucon@iZ6wef3qmnwxt2ngt1il94Z:~$ sudo mysqldumpslow /var/log/mysql/mysql-slow.log
Reading mysql slow query log from /var/log/mysql/mysql-slow.log
Count: 1 Time=1.43s (1s) Lock=0.00s (0s) Rows=10.0 (10), isucon[isucon]@localhost
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 = N
ORDER BY c.created_at DESC
LIMIT N
Count: 2 Time=0.43s (0s) Lock=0.00s (0s) Rows=20.0 (40), isucon[isucon]@localhost
SELECT * FROM entries WHERE user_id = N ORDER BY created_at DESC LIMIT N
Count: 1 Time=0.34s (0s) Lock=0.00s (0s) Rows=2.0 (2), root[root]@localhost
show variables like 'S'
Count: 321 Time=0.28s (90s) Lock=0.00s (0s) Rows=204.3 (65576), isucon[isucon]@localhost
SELECT * FROM relations WHERE one = N OR another = N ORDER BY created_at DESC
Count: 66 Time=0.23s (15s) Lock=0.00s (0s) Rows=50.0 (3300), isucon[isucon]@localhost
SELECT user_id, owner_id, DATE(created_at) AS date, MAX(created_at) as updated
FROM footprints
WHERE user_id = N
GROUP BY user_id, owner_id, DATE(created_at)
ORDER BY updated DESC
LIMIT N
Count: 235 Time=0.23s (52s) Lock=0.00s (0s) Rows=10.0 (2350), isucon[isucon]@localhost
SELECT user_id, owner_id, DATE(created_at) AS date, MAX(created_at) AS updated
FROM footprints
WHERE user_id = N
GROUP BY user_id, owner_id, DATE(created_at)
ORDER BY updated DESC
LIMIT N
explains:
mysql> explain SELECT * FROM relations WHERE one = 4697 OR another = 4698 ORDER BY created_at DESC;
+----+-------------+-----------+------------+------+---------------+------+---------+------+--------+----------+-----------------------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+-----------+------------+------+---------------+------+---------+------+--------+----------+-----------------------------+
| 1 | SIMPLE | relations | NULL | ALL | friendship | NULL | NULL | NULL | 422509 | 10.02 | Using where; Using filesort |
+----+-------------+-----------+------------+------+---------------+------+---------+------+--------+----------+-----------------------------+
1 row in set, 1 warning (0.00 sec)
mysql> explain SELECT user_id, owner_id, DATE(created_at) AS date, MAX(created_at) AS updated FROM footprints WHERE user_id = 4697 GROUP BY user_id, owner_id, DATE(created_at) ORDER BY updated DESC LIMIT 1;
+----+-------------+------------+------------+------+---------------+------+---------+------+--------+----------+----------------------------------------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+------------+------------+------+---------------+------+---------+------+--------+----------+----------------------------------------------+
| 1 | SIMPLE | footprints | NULL | ALL | NULL | NULL | NULL | NULL | 451883 | 10.00 | Using where; Using temporary; Using filesort |
+----+-------------+------------+------------+------+---------------+------+---------+------+--------+----------+----------------------------------------------+
1 row in set, 1 warning (0.00 sec)
https://github.com/matsuu/kataribe#varnishncsa
varnishncsa -a -w $logfile -D -P $pidfile -F '%h %l %u %t "%r" %s %b "%{Referer}i" "%{User-agent}i" %D'
(pprof) list main.
Total: 250ms
ROUTINE ======================== main.GetIndex in /home/isucon/webapp/go/app.go
0 100ms (flat, cum) 40.00% of Total
. . 344: for rows.Next() {
. . 345: var id, userID, private int
. . 346: var body string
. . 347: var createdAt time.Time
. . 348: checkErr(rows.Scan(&id, &userID, &private, &body, &createdAt))
. 40ms 349: if !isFriend(w, r, userID) {
. . 350: continue
. . 351: }
. . 352: entriesOfFriends = append(entriesOfFriends, Entry{id, userID, private == 1, strings.SplitN(body, "\n", 2)[0], strings.SplitN(body, "\n", 2)[1], createdAt})
. . 353: if len(entriesOfFriends) >= 10 {
. . 354: break
. . 355: }
. . 356: }
. 10ms 357: rows.Close()
. . 358:
. . 359: rows, err = db.Query(`SELECT * FROM comments ORDER BY created_at DESC LIMIT 1000`)
. . 360: if err != sql.ErrNoRows {
. . 361: checkErr(err)
. . 362: }
. . 363: commentsOfFriends := make([]Comment, 0, 10)
. . 364: for rows.Next() {
. . 365: c := Comment{}
. . 366: checkErr(rows.Scan(&c.ID, &c.EntryID, &c.UserID, &c.Comment, &c.CreatedAt))
. 40ms 367: if !isFriend(w, r, c.UserID) {
. . 368: continue
. . 369: }
. 10ms 370: row := db.QueryRow(`SELECT * FROM entries WHERE id = ?`, c.EntryID)
. . 371: var id, userID, private int
. . 372: var body string
. . 373: var createdAt time.Time
. . 374: checkErr(row.Scan(&id, &userID, &private, &body, &createdAt))
. . 375: entry := Entry{id, userID, private == 1, strings.SplitN(body, "\n", 2)[0], strings.SplitN(body, "\n", 2)[1], createdAt}
ROUTINE ======================== main.isFriend in /home/isucon/webapp/go/app.go
0 80ms (flat, cum) 32.00% of Total
. . 154:}
. . 155:
. . 156:func isFriend(w http.ResponseWriter, r *http.Request, anotherID int) bool {
. . 157: session := getSession(w, r)
. . 158: id := session.Values["user_id"]
. 60ms 159: row := db.QueryRow(`SELECT COUNT(1) AS cnt FROM relations WHERE (one = ? AND another = ?) OR (one = ? AND another = ?)`, id, anotherID, anotherID, id)
. . 160: cnt := new(int)
. 20ms 161: err := row.Scan(cnt)
. . 162: checkErr(err)
. . 163: return *cnt > 0
. . 164:}
. . 165:
. . 166:func isFriendAccount(w http.ResponseWriter, r *http.Request, name string) bool {
ROUTINE ======================== main.myHandler.func1 in /home/isucon/webapp/go/app.go
0 100ms (flat, cum) 40.00% of Total
. . 216: msg = rcv.(error).Error()
. . 217: http.Error(w, msg, http.StatusInternalServerError)
. . 218: }
. . 219: }
. . 220: }()
. 100ms 221: fn(w, r)
. . 222: }
. . 223:}
. . 224:
. . 225:func getSession(w http.ResponseWriter, r *http.Request) *sessions.Session {
. . 226: session, _ := store.Get(r, "isucon5q-go.session")
10秒間のプロファイル取るやつ
go tool pprof http://localhost:6060/debug/pprof/profile?seconds=10
あまり変わらず
{
"valid" : true,
"requests" : 1768,
"elapsed" : 64686,
"done" : "[{Isucon5InitExecutor},{BootstrapChecker},{Isucon5Load,Isucon5Load,Isucon5Load,Isucon5Load,Isucon5Checker}]",
"responses" : {
"success" : 1367,
"redirect" : 400,
"failure" : 1,
"error" : 0,
"exception" : 0
},
"violations" : [ ]
}
N+1を倒した #22 #23
before:
"success" : 1367,
"redirect" : 400,
after:
"success" : 1971,
"redirect" : 557,
🎉
done
{
"valid" : true,
"requests" : 4114,
"elapsed" : 63394,
"done" : "[{Isucon5InitExecutor},{BootstrapChecker},{Isucon5Load,Isucon5Load,Isucon5Load,Isucon5Load,Isucon5Checker}]",
"responses" : {
"success" : 3224,
"redirect" : 889,
"failure" : 1,
"error" : 0,
"exception" : 0
},
"violations" : [ ]
}
BUILD SUCCESSFUL
sudo systemctl stop netdata sudo systemctl disable netdata
おわり
{
"valid" : true,
"requests" : 4347,
"elapsed" : 64429,
"done" : "[{Isucon5InitExecutor},{BootstrapChecker},{Isucon5Load,Isucon5Load,Isucon5Load,Isucon5Load,Isucon5Checker}]",
"responses" : {
"success" : 3402,
"redirect" : 944,
"failure" : 1,
"error" : 0,
"exception" : 0
},
"violations" : [ ]
}
追実験
# mysql --version
mysql Ver 8.0.17 for Linux on x86_64 (MySQL Community Server - GPL)
{
"valid" : true,
"requests" : 3909,
"elapsed" : 63620,
"done" : "[{Isucon5InitExecutor},{BootstrapChecker},{Isucon5Load,Isucon5Load,Isucon5Load,Isucon5Load,Isucon5Checker}]",
"responses" : {
"success" : 3059,
"redirect" : 849,
"failure" : 1,
"error" : 0,
"exception" : 0
},
"violations" : [ ]
}
下がった
{
"valid" : true,
"requests" : 4018,
"elapsed" : 63621,
"done" : "[{Isucon5InitExecutor},{BootstrapChecker},{Isucon5Load,Isucon5Load,Isucon5Load,Isucon5Load,Isucon5Checker}]",
"responses" : {
"success" : 3149,
"redirect" : 868,
"failure" : 1,
"error" : 0,
"exception" : 0
},
"violations" : [ ]
}
全体像