ISUCON練習日記2021-03-07 ISUCON10予選
ISUCON10予選問題で練習した。色々忘れないようにメモ。
IP取得
wget -q -O - http://checkip.amazonaws.com/
ファイルサイズ
sudo ls -lh /var/log/mysql/mysql-slow.log |awk '{print $5}'
nazotteのN+1をなんとかしようとする
方針は複数ある
- POINT 型
- アプリ側で内外判定する
geo系sqlを簡易テスト
結局syntax errorを越えられずできなかった。
$ sudo mysql isuumo -e "SELECT ST_Contains(ST_PolygonFromText('POLYGON((1 1,1 2,2 2,2 1,3 3))'), ST_GeomFromText('POINT(1 1
)'))"
ERROR 3037 (22023) at line 1: Invalid GIS data provided to function st_geometryfromtext.
MySQL Bugs: #76595: "Invalid GIS data provided" reported with valid geometries 記法ミスなのかバグなのかバージョン差異なのか不明
アプリログ出す
【systemd】StandardOutput=fileはログをファイルに出力できるけど追記されない | 純規の暇人趣味ブログ
journalctl -u isuumo.go.service でチラ見はできる、でも長いので実用性低い sudo vi /etc/systemd/system/isuumo.go.service [Service] StandardOutput=append:/tmp/test.log sudo systemctl daemon-reload sre $ sudo journalctl --version systemd 237 +PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid
240未満だったので意味なかった。
sudo vi /etc/systemd/system/isuumo.go.service
$ sudo systemctl daemon-reload && sre && sst
● isuumo.go.service - isuumo.go
Loaded: loaded (/etc/systemd/system/isuumo.go.service; enabled; vendor preset: enabled)
Active: activating (auto-restart) (Result: exit-code) since Sat 2021-03-06 15:16:46 UTC; 29ms ago
Process: 11467 ExecStart=/bin/sh -c exec /home/isucon/isuumo/webapp/go/isuumo >> /var/log/isuapp.log (code=exited, status=2)
Main PID: 11467 (code=exited, status=2)
Mar 06 15:16:46 ix systemd[1]: isuumo.go.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Mar 06 15:16:46 ix systemd[1]: isuumo.go.service: Failed with result 'exit-code'.
sudo touch /var/log/isuapp.log
sudo chmod 666 /var/log/isuapp.log
sudo ls -l /var/log/isuapp.log
-rw-rw-rw- 1 root root 0 Mar 6 15:17 /var/log/isuapp.log
$ sudo systemctl daemon-reload && sre && sst
● isuumo.go.service - isuumo.go
Loaded: loaded (/etc/systemd/system/isuumo.go.service; enabled; vendor preset: enabled)
Active: active (running) since Sat 2021-03-06 15:17:25 UTC; 54ms ago
Main PID: 11724 (isuumo)
Tasks: 4 (limit: 2333)
CGroup: /system.slice/isuumo.go.service
└─11724 /home/isucon/isuumo/webapp/go/isuumo
Mar 06 15:17:25 ix systemd[1]: Started isuumo.go.
ログファイルが存在しないときもINVALIDARGUMENTになる。ちょっとわかりにくい。
tail -f /var/log/isuapp.log
nazotte N+1 part0 ソースコード構造変化
読み解き(L1049くらいのestatesInPolygon := []Estate{}から１５行くらい)
内容を整理するとこんな感じ
- IN: coordinates
- 長方形に絞ったestate群を得る
- for: estate（長方形に絞ったestate群）
- select: lat/lonとidを条件に内外判定し、内なら1件得る
- 結果があるならappend
- 数を制限する
- OUT: Estates
このSQLをforの外に出すことを考える
SQL文の代入箇所を変数名で埋めるとこうなる
SELECT * FROM estate WHERE id = estate.ID AND ST_Contains( ST_PolygonFromText( coordinates.coordinatesToText() ), ST_GeomFromText( 'POINT(estate.Latitude estate.Longitude)' ) )
条件部に代入値ではなくテーブルが持つ列を渡してしまえば一気に結果を得られる。
SELECT * FROM estate AND ST_Contains( ST_PolygonFromText( 'POLYGON((10.0 10.0,100.0 10.0,100.0 100.0,10.0 100.0))' ), ST_GeomFromText( 'POINT(latitude longitude)' ) )
このSQLが正しいか、どう試すのがもっとも早いか？
文法レベルはオンラインのシンタックスチェッカーが早いかも。
$ sudo mysql isuumo -e " > SELECT * FROM estate > WHERE > ST_Contains( > ST_PolygonFromText( > 'POLYGON((10.0 10.0,100.0 10.0,100.0 100.0,10.0 100.0))' > ), > ST_GeomFromText( > 'POINT(latitude longitude)' > ) > ) limit 1 > " ERROR 3037 (22023) at line 2: Invalid GIS data provided to function st_geometryfromtext.
st_geometryfromtext噛んでるから列名が読めるわけないか。 CONCAT('POINT(', latitude, ' ', longitude, ')'))とかにする必要がある。まあでもpoint型作るか・・・
POINT型を作る（次項）
nazotte N+1 part1 point型列の追加
vi 0_Schema.sql point POINT AS (POINT(latitude, longitude)) STORED NOT NULL, ./init.sh $ sudo mysql isuumo -e "describe estate" +-----------------+---------------+------+-----+---------+-------------------+ | Field | Type | Null | Key | Default | Extra | +-----------------+---------------+------+-----+---------+-------------------+ | id | int(11) | NO | PRI | NULL | | | name | varchar(64) | NO | | NULL | | | description | varchar(4096) | NO | | NULL | | | thumbnail | varchar(128) | NO | | NULL | | | address | varchar(128) | NO | | NULL | | | latitude | double | NO | | NULL | | | longitude | double | NO | | NULL | | | rent | int(11) | NO | MUL | NULL | | | door_height | int(11) | NO | | NULL | | | door_width | int(11) | NO | | NULL | | | features | varchar(64) | NO | | NULL | | | popularity | int(11) | NO | | NULL | | | popularity_desc | int(11) | NO | MUL | NULL | VIRTUAL GENERATED | +-----------------+---------------+------+-----+---------+-------------------+ エラーは出てないけど型にも追加されてない。 反映先DBが別サーバだったからだった。 $ sudo mysql isuumo -e "describe estate" | point | point | NO | | NULL | VIRTUAL GENERATED | $ sudo mysql isuumo -e "SELECT latitude, longitude,point, ST_X(point), ST_Y(POINT) from estate limit 1" +-------------------+-------------------+---------------------------+-------------------+-------------------+ | latitude | longitude | point | ST_X(point) | ST_Y(POINT) | +-------------------+-------------------+---------------------------+-------------------+-------------------+ | 37.71778813321466 | 140.2540394463388 | F{B@i=U!a@ | 37.71778813321466 | 140.2540394463388 | +-------------------+-------------------+---------------------------+-------------------+-------------------+ STOREDの意味は以下。 SPATIAL INDEX の有効化のため。 > Generated Columnには、「VIRTUAL」 or 「STORED」が指定できます。 > 「VIRTUAL」は実データを持たず、読み込むタイミングで計算します。 > 「STORED」は計算結果を記憶領域に保存し、通常の列情報のように読み取ります。 > 既定値は「VIRTUAL」です。 [https://www.dcom-web.co.jp/lab/database/mysql/generated_column:title]
nazotte N+1 part2 SQL変形
1.SQL変形 query2 := fmt.Sprintf(`/*[N1] */SELECT * FROM estate WHERE ST_Contains(ST_PolygonFromText(%s), point)`, coordinates.coordinatesToText()) 2.受け皿用意 estates2 := []Estate{} 3.SQL実行(getで複数取れる) err = db.Get(&estates2, query2) 4.ログ出してみる c.Echo().Logger.Debugf(" N1 length:%d", len(estates2)) $ go build && sre && curl localhost/api/stats key,count,sum,avg この時点でビルドは成功、アプリ起動成功はしてる。ただなぞってをやってみるとエラー出ている $ tail -f /var/log/isuapp.log | ./colorizer.sed {"time":"2021-03-07T01:45:22.06709935Z","level":"ERROR","prefix":"echo","file":"main.go","line":"1005","message":"Database execution error : missing destination name point in *[]main.Estate"} {"time":"2021-03-07T01:45:22.070117889Z","id":"","remote_ip":"127.0.0.1","host":"localhost:1323","method":"GET","uri":"/api/recommended_estate/10831","user_agent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/88.0.4324.190 Safari/537.36","status":500,"error":"","latency":7294970,"latency_human":"7.29497ms","bytes_in":0,"bytes_out":0} missing destination name point つまりpointの詰め先がない、Estateに追加し忘れていた {"time":"2021-03-13T04:16:28.149906619Z","level":"ERROR","prefix":"echo","file":"main.go","line":"736","message":"Database Execution error : sql: Scan error on column index 12, name \"point\": converting driver.Value type []uint8 (\"\\x00\\x00\\x00\\x00\\x01\\x01\\x00\\x00\\x00\\x8a\\x1a\\xc49\\xe1/B@\\xc4\\xee\\xf6\\x15s_a@\") to a int64: invalid syntax"} intだと怒られた // err = db.Get(&estates2, query2) err = db.Select(&estates2, query2) 複数なのでselectにする必要がある {"pass":false,"score":0,"messages":[{"text":"POST /api/estate/nazotte: レスポンスが不正です","count":4}],"reason":"スコアが0点を下回りました","language":"go"}
ようやくN+1を解消できた スコアはむしろちょっと下がってしまったが、 main.searchEstateNazotteがavgが半分くらいになってcountが1.5倍くらいになった。
{"pass":true,"score":878,"messages":[{"text":"POST /api/estate/nazotte: リクエストに失敗しました (タイムアウトしました)","count":21}],"reason":"OK","language":"go"}
key count sum avg
main.searchEstateNazotte 64 151911 2373.61
main.searchEstateNazotte: part2 64 143798 2246.84
main.searchChairs 1755 130583 127.03
main.searchChairs: part2 1755 101552 98.79
main.searchEstates 2757 80959 78.75
main.searchEstates: part2 2757 57661 56.09
main.searchChairs: part3 1755 31096 30.25
main.getEstateDetail 4619 30148 29.33
main.getChairDetail 3813 29353 28.55
main.searchEstates: part3 2757 21818 21.22
main.searchRecommendedEstateWithChair 475 11247 23.68
main.getLowPricedChair 703 8763 12.47
main.searchEstateNazotte: part1 64 8065 126.02
main.getLowPricedEstate 703 7742 11.01
{"pass":true,"score":862,"messages":[],"reason":"OK","language":"go"}
key count sum avg
main.searchChairs 1618 145225 141.27
main.searchChairs: part2 1618 112470 109.41
main.searchEstateNazotte 92 90917 988.23
main.searchEstates 2706 81321 79.11
main.searchEstateNazotte: part2 92 79046 859.19
main.searchEstates: part2 2706 60499 58.85
main.getChairDetail 3515 37648 36.62
main.getEstateDetail 4358 33131 32.23
main.searchChairs: part3 1618 32321 31.44
main.searchEstates: part3 2706 23101 22.47
main.searchEstateNazotte: part1 92 11795 128.21
main.searchRecommendedEstateWithChair 437 11189 25.60
main.getLowPricedChair 706 9845 13.95
main.getLowPricedEstate 706 9203 13.04
ログを見やすくする
tail
https://github.com/shimodatkh/colorizer/blob/master/colorizer.sed
cd wget https://raw.githubusercontent.com/shimodatkh/colorizer/master/colorizer.sed chmod 777 colorizer.sed tail -f /var/log/isuapp.log | ~/colorizer.sed
less
sudo apt-get install source-highlight export LESS='-R' export LESSOPEN='| /usr/share/source-highlight/src-hilite-lesspipe.sh %s' less /var/log/isuapp.log
