📝

isucon 11予選環境のローカル構築メモ

2022/05/05に公開

matsuu さんが https://github.com/matsuu/cloud-init-isucon という最高のcloud-configを公開されていたので、ローカルでの実行ログを残しておく。

前提

M1 MBP で構築している。OSverは次のとおり。

% sw_vers
ProductName:	macOS
ProductVersion:	12.3.1
BuildVersion:	21E258

事前準備

multipass が必要であるため、brewで入れる。

% brew install --cask multipass
Running `brew update --preinstall`...
==> Auto-updated Homebrew!
Updated 2 taps (homebrew/core and homebrew/cask).
==> New Formulae
age-plugin-yubikey         mbw                        sse2neon
arxiv_latex_cleaner        minimap2                   stanc3
cpi                        mkfontscale                virt-manager
libapplewm                 monika                     xkbcomp
libxfont2                  primecount
==> Updated Formulae
Updated 179 formulae.
==> New Casks
detail
==> Updated Casks
Updated 87 casks.

==> Downloading https://github.com/canonical/multipass/releases/download/v1.9.0/
==> Downloading from https://objects.githubusercontent.com/github-production-rel
######################################################################## 100.0%
==> Installing Cask multipass
==> Running installer for multipass; your password may be necessary.

Package installers may write to any location; options such as `--appdir` are ignored.
Password:
installer: Package name is multipass
installer: Installing at base path /
installer: The install was successful.
🍺  multipass was successfully installed!

環境構築開始

https://github.com/matsuu/cloud-init-isucon を git clone して構築開始する。 README 記載のとおり、タイムアウトした。(6分半程度で)

% git clone git@github.com:matsuu/cloud-init-isucon.git
% cd cloud-init-isucon/isucon11q
% cd isucon11q

// 構築開始。メモリだけ多めに12Gにしている。
% multipass launch --name isucon11q --cpus 2 --disk 16G --mem 12G --cloud-init isucon11q.cfg 20.04

Verifying image:  - (ここで色々と表示が遷移)

launch failed: The following errors occurred:
timed out waiting for initialization to complete

VM自体は立っており、プロビジョニング状況をtailで追える。

// ここからubuntu shellに入る
% multipass shell isucon11q

Welcome to Ubuntu 20.04.4 LTS (GNU/Linux 5.4.0-109-generic aarch64)

 * Documentation:  https://help.ubuntu.com
 * Management:     https://landscape.canonical.com
 * Support:        https://ubuntu.com/advantage

 System information disabled due to load higher than 2.0

7 updates can be applied immediately.
7 of these updates are standard security updates.
To see these additional updates run: apt list --upgradable

*** System restart required ***
To run a command as administrator (user "root"), use "sudo <command>".
See "man sudo_root" for details.

// 構築状況を確認する
$ sudo tail -f /var/log/cloud-init-output.log
TASK [langs.perl : roles/langs.perl/tasks/main: Add PATH for perl] *************
Thursday 05 May 2022  18:38:54 +0900 (0:02:04.844)       0:03:07.906 **********
changed: [127.0.0.1]

TASK [langs.perl : roles/langs.perl/tasks/main: Download cpm] ******************
Thursday 05 May 2022  18:38:54 +0900 (0:00:00.086)       0:03:07.993 **********
changed: [127.0.0.1]

TASK [langs.php : roles/langs.php/tasks/main: Install PHP 8.0.9 from xbuild] ***
Thursday 05 May 2022  18:38:55 +0900 (0:00:00.816)       0:03:08.809 **********

(略)

Thursday 05 May 2022  18:53:21 +0900 (0:00:14.843)       0:17:35.230 **********
===============================================================================
langs.php : roles/langs.php/tasks/main: Install PHP 8.0.9 from xbuild - 253.13s
contestant : roles/contestant/tasks/isucondition-rust: Build Web Application Rust - 223.74s
langs.ruby : roles/langs.ruby/tasks/main: Install Ruby v3.0.2 from xbuild - 140.25s
langs.perl : roles/langs.perl/tasks/main: Install Perl 5.34.0 from xbuild - 124.84s
langs.python : roles/langs.python/tasks/main: Install python v3.9.6 from xbuild -- 73.10s
contestant : roles/contestant/tasks/isucondition-perl: Build Web Application Perl -- 47.01s
common : roles/common/tasks/package: Install Package(Build) ------------ 25.95s
langs.rust : roles/langs.rust/tasks/main: Install Rust ----------------- 25.54s
langs.rust : roles/langs.rust/tasks/main: Update to 1.54.0 ------------- 25.32s
langs.nodejs : roles/langs.nodejs/tasks/main: Install Node.js v14.17.4 from xbuild -- 16.48s
contestant : roles/contestant/tasks/mariadb: Install Package ----------- 15.19s
bench : roles/bench/tasks/bench: Build Web Application Go -------------- 14.84s
langs.go : roles/langs.go/tasks/main: Install Go 1.16.5 from xbuild ---- 12.60s
contestant : roles/contestant/tasks/nginx: Install package -------------- 7.54s
contestant : roles/contestant/tasks/isucondition-ruby: Build Web Application ruby --- 6.43s
contestant : roles/contestant/tasks/isucondition-go: Build Web Application Go --- 5.35s
contestant : roles/contestant/tasks/isucondition-python: Build Web Application Python --- 5.17s
bench : roles//tasks/package: Install Package --------------------------- 5.08s
contestant : roles/contestant/tasks/isucondition-nodejs: Build Web Application Node --- 4.52s
common : roles/common/tasks/package: Purge Package (snapd) -------------- 3.86s
Created symlink /etc/systemd/system/multi-user.target.wants/isucondition.go.service → /etc/systemd/system/isucondition.go.service.
Updating certificates in /etc/ssl/certs...
1 added, 0 removed; done.
Running hooks in /etc/ca-certificates/update.d...
done.
Cloud-init v. 22.1-14-g2e17a0d6-0ubuntu1~20.04.3 running 'modules:final' at Thu, 05 May 2022 09:35:14 +0000. Up 13.25 seconds.
Cloud-init v. 22.1-14-g2e17a0d6-0ubuntu1~20.04.3 finished at Thu, 05 May 2022 09:53:22 +0000. Datasource DataSourceNoCloud [seed=/dev/vda][dsmode=net].  Up 1101.11 seconds

1101.11 seconds のとおりで、おおよそ18-19分かかることがわかる。
ここまでで構築完了。(あっさりできていてスゴイ)

// ベンチ試走
ubuntu@isucon11q:~$ sudo -i -u isucon
isucon@isucon11q:~$ cd bench
isucon@isucon11q:~/bench$ ./bench -all-addresses 127.0.0.11 -target 127.0.0.11:443 -tls -jia-service-url http://127.0.0.1:4999

18:54:48.482464 ISUCON11 benchmarker
18:54:48.482720 ===> PREPARE
18:54:48.482731 start: load initial data
18:54:48.484323 finish: load initial data
18:54:54.020850 ===> LOAD
18:54:54.020859 LOAD INFO
  Language: go
  Campaign: None
18:54:54.020868 SCORE: 00.StartBenchmark       : 0
18:54:54.020873 SCORE: 01.GraphGood            : 0
18:54:54.020874 SCORE: 02.GraphNormal          : 0
18:54:54.020876 SCORE: 03.GraphBad             : 0
18:54:54.020877 SCORE: 04.GraphWorst           : 0
18:54:54.020879 SCORE: 05.TodayGraphGood       : 0
18:54:54.020881 SCORE: 06.TodayGraphNormal     : 0
18:54:54.020882 SCORE: 07.TodayGraphBad        : 0
18:54:54.020883 SCORE: 08.TodayGraphWorst      : 0
18:54:54.020884 SCORE: 09.ReadInfoCondition    : 0
18:54:54.020886 SCORE: 10.ReadWarningCondition : 0
18:54:54.020887 SCORE: 11.ReadCriticalCondition: 0
18:54:54.020888 SCORE: _1.IsuInitialize        : 0
18:54:54.020889 SCORE: _2.NormalUserInitialize : 0
18:54:54.020891 SCORE: _3.ViewerInitialize     : 0
18:54:54.020892 SCORE: _5.ViewerDropout        : 0
18:54:54.020893 SCORE: _6.RepairIsu            : 0
18:54:54.020894 SCORE: _7.PostInfoCondition    : 0
18:54:54.020896 SCORE: _8.PostWarningCondition : 0
18:54:54.020897 SCORE: _9.PostCriticalCondition: 0
18:54:54.020899 score: 0(0 - 0) : Score
18:54:54.020900 deduction: 0 / timeout: 0
18:54:57.022925 score: 1418(1420 - 2) : pass
18:54:57.022938 deduction: 0 / timeout: 21
18:54:59.022846 ユーザーは増えませんでした
18:55:00.023408 score: 2282(2284 - 2) : pass
18:55:00.023422 deduction: 0 / timeout: 21
18:55:03.024277 score: 3134(3136 - 2) : pass
18:55:03.024286 deduction: 0 / timeout: 21
18:55:04.023002 ユーザーは増えませんでした
18:55:06.025087 score: 4006(4008 - 2) : pass
18:55:06.025095 deduction: 0 / timeout: 21
18:55:09.023076 ユーザーは増えませんでした
18:55:09.026049 SCORE: 00.StartBenchmark       : 1
18:55:09.026054 SCORE: 01.GraphGood            : 0
18:55:09.026056 SCORE: 02.GraphNormal          : 0
18:55:09.026057 SCORE: 03.GraphBad             : 0
18:55:09.026059 SCORE: 04.GraphWorst           : 83
18:55:09.026060 SCORE: 05.TodayGraphGood       : 0
18:55:09.026061 SCORE: 06.TodayGraphNormal     : 0
18:55:09.026062 SCORE: 07.TodayGraphBad        : 0
18:55:09.026064 SCORE: 08.TodayGraphWorst      : 96
18:55:09.026065 SCORE: 09.ReadInfoCondition    : 85
18:55:09.026066 SCORE: 10.ReadWarningCondition : 107
18:55:09.026067 SCORE: 11.ReadCriticalCondition: 4
18:55:09.026068 SCORE: _1.IsuInitialize        : 48
18:55:09.026095 SCORE: _2.NormalUserInitialize : 7
18:55:09.026098 SCORE: _3.ViewerInitialize     : 21
18:55:09.026099 SCORE: _4.ViewerLoop           : 9
18:55:09.026100 SCORE: _5.ViewerDropout        : 21
18:55:09.026102 SCORE: _6.RepairIsu            : 63
18:55:09.026104 SCORE: _7.PostInfoCondition    : 1403
18:55:09.026105 SCORE: _8.PostWarningCondition : 1797
18:55:09.026107 SCORE: _9.PostCriticalCondition: 112
18:55:09.026342 score: 4784(4786 - 2) : pass
18:55:09.026351 deduction: 0 / timeout: 21
18:55:12.027177 score: 5946(5948 - 2) : pass
18:55:12.027191 deduction: 0 / timeout: 21
18:55:14.023584 ユーザーは増えませんでした
18:55:15.035131 score: 6770(6772 - 2) : pass
18:55:15.035204 deduction: 0 / timeout: 21
18:55:18.035369 score: 7594(7596 - 2) : pass
18:55:18.035382 deduction: 0 / timeout: 21
18:55:19.023952 ユーザーは増えませんでした
18:55:21.036803 score: 8110(8112 - 2) : pass
18:55:21.036818 deduction: 0 / timeout: 21
18:55:24.024234 ユーザーは増えませんでした
18:55:24.039420 SCORE: 00.StartBenchmark       : 1
18:55:24.039433 SCORE: 01.GraphGood            : 0
18:55:24.039435 SCORE: 02.GraphNormal          : 0
18:55:24.039436 SCORE: 03.GraphBad             : 0
18:55:24.039438 SCORE: 04.GraphWorst           : 204
18:55:24.039440 SCORE: 05.TodayGraphGood       : 0
18:55:24.039441 SCORE: 06.TodayGraphNormal     : 0
18:55:24.039442 SCORE: 07.TodayGraphBad        : 0
18:55:24.039443 SCORE: 08.TodayGraphWorst      : 139
18:55:24.039446 SCORE: 09.ReadInfoCondition    : 151
18:55:24.039448 SCORE: 10.ReadWarningCondition : 251
18:55:24.039449 SCORE: 11.ReadCriticalCondition: 32
18:55:24.039450 SCORE: _1.IsuInitialize        : 48
18:55:24.039451 SCORE: _2.NormalUserInitialize : 7
18:55:24.039453 SCORE: _3.ViewerInitialize     : 21
18:55:24.039454 SCORE: _4.ViewerLoop           : 9
18:55:24.039455 SCORE: _5.ViewerDropout        : 21
18:55:24.039457 SCORE: _6.RepairIsu            : 107
18:55:24.039458 SCORE: _7.PostInfoCondition    : 2239
18:55:24.039459 SCORE: _8.PostWarningCondition : 3937
18:55:24.039461 SCORE: _9.PostCriticalCondition: 934
18:55:24.039828 score: 8750(8752 - 2) : pass
18:55:24.039834 deduction: 0 / timeout: 21
18:55:27.040287 score: 9374(9376 - 2) : pass
18:55:27.040304 deduction: 0 / timeout: 21
18:55:29.024368 ユーザーは増えませんでした
18:55:30.041166 score: 9840(9842 - 2) : pass
18:55:30.041178 deduction: 0 / timeout: 21
18:55:33.041253 score: 10294(10296 - 2) : pass
18:55:33.041264 deduction: 0 / timeout: 21
18:55:34.031491 ユーザーは増えませんでした
18:55:36.041259 score: 10826(10828 - 2) : pass
18:55:36.041455 deduction: 0 / timeout: 21
18:55:39.031613 ユーザーは増えませんでした
18:55:39.041692 SCORE: 00.StartBenchmark       : 1
18:55:39.041760 SCORE: 01.GraphGood            : 0
18:55:39.041777 SCORE: 02.GraphNormal          : 0
18:55:39.041793 SCORE: 03.GraphBad             : 0
18:55:39.041807 SCORE: 04.GraphWorst           : 314
18:55:39.041848 SCORE: 05.TodayGraphGood       : 0
18:55:39.041863 SCORE: 06.TodayGraphNormal     : 0
18:55:39.041879 SCORE: 07.TodayGraphBad        : 0
18:55:39.041910 SCORE: 08.TodayGraphWorst      : 158
18:55:39.041928 SCORE: 09.ReadInfoCondition    : 176
18:55:39.041944 SCORE: 10.ReadWarningCondition : 340
18:55:39.041959 SCORE: 11.ReadCriticalCondition: 103
18:55:39.041990 SCORE: _1.IsuInitialize        : 48
18:55:39.042007 SCORE: _2.NormalUserInitialize : 7
18:55:39.042021 SCORE: _3.ViewerInitialize     : 21
18:55:39.042036 SCORE: _4.ViewerLoop           : 9
18:55:39.042068 SCORE: _5.ViewerDropout        : 21
18:55:39.042086 SCORE: _6.RepairIsu            : 124
18:55:39.042100 SCORE: _7.PostInfoCondition    : 2701
18:55:39.042114 SCORE: _8.PostWarningCondition : 5293
18:55:39.042143 SCORE: _9.PostCriticalCondition: 2889
18:55:39.042410 score: 11422(11424 - 2) : pass
18:55:39.042447 deduction: 0 / timeout: 21
18:55:42.044617 score: 11838(11840 - 2) : pass
18:55:42.044740 deduction: 0 / timeout: 21
18:55:44.031790 ユーザーは増えませんでした
18:55:45.045301 score: 12400(12402 - 2) : pass
18:55:45.045317 deduction: 0 / timeout: 21
18:55:48.045573 score: 12802(12804 - 2) : pass
18:55:48.045583 deduction: 0 / timeout: 21
18:55:49.032010 ユーザーは増えませんでした
18:55:51.045588 score: 13298(13300 - 2) : pass
18:55:51.045601 deduction: 0 / timeout: 21
18:55:54.021371 defer s.loadWaitGroup.Done() keepPostingError
18:55:54.021427 defer s.loadWaitGroup.Done() loadErrorCheck
18:55:54.021480 defer s.loadWaitGroup.Done() AddNormalUser
18:55:54.021518 defer s.loadWaitGroup.Done() AddNormalUser
18:55:54.021541 defer s.loadWaitGroup.Done() AddNormalUser
18:55:54.021560 defer s.loadWaitGroup.Done() AddNormalUser
18:55:54.021579 defer s.loadWaitGroup.Done() AddNormalUser
18:55:54.021600 LOAD WAIT
18:55:54.021638 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021640 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021642 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021643 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021645 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021646 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021648 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021649 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021651 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021652 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021654 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021655 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021657 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021658 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021659 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021661 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021662 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021663 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021665 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021699 defer s.loadWaitGroup.Done() AddIsuconUser
18:55:54.021708 --- userAdder END
18:55:54.021709 defer s.loadWaitGroup.Done() userAdder
18:55:54.021735 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021737 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021739 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021740 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021741 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021742 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021744 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021745 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021756 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021759 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021761 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021762 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021763 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021765 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021766 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021768 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021769 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021770 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021772 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021773 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021774 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021775 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021777 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021779 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021781 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021782 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021784 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021785 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021794 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021796 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021803 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021817 defer s.loadWaitGroup.Done() AddNormalUser
18:55:54.021820 defer s.loadWaitGroup.Done() keepPosting
18:55:54.021824 end s.loadWaitGroup.Wait()
18:55:54.021838 <=== LOAD END
18:55:54.021859 SCORE: 00.StartBenchmark       : 1
18:55:54.021861 SCORE: 01.GraphGood            : 0
18:55:54.021862 SCORE: 02.GraphNormal          : 0
18:55:54.021863 SCORE: 03.GraphBad             : 0
18:55:54.021864 SCORE: 04.GraphWorst           : 449
18:55:54.021866 SCORE: 05.TodayGraphGood       : 0
18:55:54.021867 SCORE: 06.TodayGraphNormal     : 0
18:55:54.021869 SCORE: 07.TodayGraphBad        : 0
18:55:54.021870 SCORE: 08.TodayGraphWorst      : 172
18:55:54.021871 SCORE: 09.ReadInfoCondition    : 198
18:55:54.021873 SCORE: 10.ReadWarningCondition : 405
18:55:54.021874 SCORE: 11.ReadCriticalCondition: 174
18:55:54.021875 SCORE: _1.IsuInitialize        : 48
18:55:54.021876 SCORE: _2.NormalUserInitialize : 7
18:55:54.021877 SCORE: _3.ViewerInitialize     : 21
18:55:54.021878 SCORE: _4.ViewerLoop           : 9
18:55:54.021880 SCORE: _5.ViewerDropout        : 21
18:55:54.021881 SCORE: _6.RepairIsu            : 136
18:55:54.021882 SCORE: _7.PostInfoCondition    : 2978
18:55:54.021884 SCORE: _8.PostWarningCondition : 6404
18:55:54.021885 SCORE: _9.PostCriticalCondition: 5268
18:55:54.021886 SCORE: 00.StartBenchmark       : 1
18:55:54.021887 SCORE: 01.GraphGood            : 0
18:55:54.021888 SCORE: 02.GraphNormal          : 0
18:55:54.021889 SCORE: 03.GraphBad             : 0
18:55:54.021890 SCORE: 04.GraphWorst           : 449
18:55:54.021891 SCORE: 05.TodayGraphGood       : 0
18:55:54.021892 SCORE: 06.TodayGraphNormal     : 0
18:55:54.021892 SCORE: 07.TodayGraphBad        : 0
18:55:54.021893 SCORE: 08.TodayGraphWorst      : 172
18:55:54.021894 SCORE: 09.ReadInfoCondition    : 198
18:55:54.021895 SCORE: 10.ReadWarningCondition : 405
18:55:54.021896 SCORE: 11.ReadCriticalCondition: 174
18:55:54.022118 score: 14072(14074 - 2) : pass
18:55:54.022119 deduction: 0 / timeout: 22
18:55:54.022123 <=== sendResult finish

ベンチ試走完了まで確認できた。

Discussion