ISCUON13 過去問を手探りでやってみる

• 「ボトルネックの特定は外側から順番に」に従って、外形監視からする。
• プロファイラーは何がいいかわからんので色々使ってみる

Memos

ログイン後 linux user を isucon に切り替える

ssh
sudo su isucon
cd 

benchmark tool は結構オプションが色々いける

./bench_linux_amd64 run --target https://pipe.u.isucon.dev --nameserver 35.72.35.148 --enable-ssl

を参考に VSCode でログイン後ユーザーを変えてリモート接続する https://qiita.com/craymaru/items/f126597ed91940226805

# Enable Kerb Forwarding
Host isucon13
	HostName xxxx
	IdentityFile xxx.pem
	User ubuntu
    RemoteCommand sudo su ubuntu

sudo service isupipe-go restart 
sudo service isupipe-go status

ポートフォワード

ssh -i "xxx.pem" ubuntu@35.72.35.148 -fNL 1080:localhost:1080

unit file 確認

sudo cat /etc/systemd/system/isupipe-go.service

直接バイナリ実行してる

ExecStart=/home/isucon/webapp/go/isupipe

profiler 導入

pprof

質問と応答

Go でプロファイラー（例: `pprof`）を差し込む場合、通常は `main` 関数にプロファイリングの設定や開始・停止を記述しますが、それがプロファイリングされるコードの範囲を制限するものではありません。

実際には、`main` 関数にプロファイリングの開始を記述することで、プログラム全体でのプロファイリングが可能です。

基本トップレベルに書くぽい

"net/http/pprof"
"runtime"

    runtime.SetBlockProfileRate(1)
    runtime.SetMutexProfileFraction(1)
    go func() {
        log.Fatal(http.ListenAndServe("localhost:6060", nil))
    }()

go build -o isupipe
ls --full-time
sudo service isupipe-go restart
sudo service isupipe-go status

ps aux | grep "isupipe"
isucon      5265  3.1  0.3 1825708 12992 ?       Ssl  00:53   0:25 /home/isucon/webapp/go/isupipe

lsof -c isupipe
isupipe 5265 isucon    7u     IPv6              43103      0t0    TCP *:8080 (LISTEN)
isupipe 5265 isucon   25u     IPv4              54197      0t0    TCP 127.0.0.1:61316->127.0.0.1:3306 (ESTABLISHED)

プロファイリングツール起動（こいつは WEB UI も提供してくれる）

go tool pprof -seconds 60 -http=localhost:1080 http://localhost:6060/debug/pprof/profile

一度保存したファイルは以下の感じで開ける

go tool pprof -http=localhost:1080 /home/isucon/pprof/pprof.isupipe.samples.cpu.001.pb.gz

うまくとれてないっぽい

profiling してる間に裏で benchmarker 実行

go tool pprof -seconds 60 -http=localhost:1080 http://localhost:6060/debug/pprof/profile

多そうなやつ

• getLivestreamStatisticsHandler
• searchLivestreamsHandler

getLivestreamStatisticsHandler

stats_handler.go を見ていく

sqlx.GetContext が多い。多分SQL

if err := tx.GetContext(ctx, &livestream, "SELECT * FROM livestreams WHERE id = ?", livestreamID); err != nil {

みていく

how columns from livestreams;
+---------------+--------------+------+-----+---------+----------------+
| Field         | Type         | Null | Key | Default | Extra          |
+---------------+--------------+------+-----+---------+----------------+
| id            | bigint       | NO   | PRI | NULL    | auto_increment |
| user_id       | bigint       | NO   |     | NULL    |                |
| title         | varchar(255) | NO   |     | NULL    |                |
| description   | text         | NO   |     | NULL    |                |
| playlist_url  | varchar(255) | NO   |     | NULL    |                |
| thumbnail_url | varchar(255) | NO   |     | NULL    |                |
| start_at      | bigint       | NO   |     | NULL    |                |
| end_at        | bigint       | NO   |     | NULL    |                |
+---------------+--------------+------+-----+---------+----------------+

show index from livestreams;

まずは SELECT 系しかしてないので tx で transaction 貼ってるところを止める

次に、なんか大量に Get してるところを一回の SQL でよんできて構造体に mapping する

	// // Rank 以外の Stats を算出
	var stats LivestreamStatistics
	if err := dbConn.GetContext(ctx, &stats, `
	SELECT
	    COUNT(DISTINCT r.id) AS total_reactions,
	    COUNT(DISTINCT h.user_id) AS viewers_count,
	    COALESCE(MAX(l2.tip), 0) AS max_tip,
	    COUNT(DISTINCT lr.id) AS total_reports
	FROM livestreams l
	LEFT JOIN reactions r ON l.id = r.livestream_id
	LEFT JOIN livecomments l2 ON l.id = l2.livestream_id
	LEFT JOIN livestream_viewers_history h ON h.livestream_id = l.id
	LEFT JOIN livecomment_reports lr ON lr.livestream_id = l.id
	WHERE l.id = ?`, livestreamID); err != nil {
		return echo.NewHTTPError(http.StatusInternalServerError, "failed to get livestream stats: "+err.Error())
	}

Conn pooling もしてみる

	dbConn = conn
	dbConn.SetMaxOpenConns(10)
	dbConn.SetMaxIdleConns(5)

これ参考に DB に index 貼ってく

	SELECT
	    COUNT(DISTINCT r.id) AS total_reactions,
	    COUNT(DISTINCT h.user_id) AS viewers_count,
	    COALESCE(MAX(l2.tip), 0) AS max_tip,
	    COUNT(DISTINCT lr.id) AS total_reports
	FROM livestreams l
	LEFT JOIN reactions r ON l.id = r.livestream_id
	LEFT JOIN livecomments l2 ON l.id = l2.livestream_id
	LEFT JOIN livestream_viewers_history h ON h.livestream_id = l.id
	LEFT JOIN livecomment_reports lr ON lr.livestream_id = l.id

• r.livestream_id

alter table reactions add index livestream_id_idx (livestream_id);

show columns from livestream_viewers_history;
+---------------+--------+------+-----+---------+----------------+
| Field         | Type   | Null | Key | Default | Extra          |
+---------------+--------+------+-----+---------+----------------+
| id            | bigint | NO   | PRI | NULL    | auto_increment |
| user_id       | bigint | NO   |     | NULL    |                |
| livestream_id | bigint | NO   |     | NULL    |                |
| created_at    | bigint | NO   |     | NULL    |                |
+---------------+--------+------+-----+---------+----------------+
show index from livestream_viewers_history;

• livestream_id

alter table livestream_viewers_history add index livestream_id_idx (livestream_id);
alter table livecomment_reports add index livestream_id_idx (livestream_id);

alter table livecomments add index livestream_id_idx (livestream_id);

Statのクエリ N+1 解決がうまくいかんな

curl https://pipe.u.isucon.dev/api/livestream/7496/statistics \
--resolve pipe.u.isucon.dev:443:35.72.35.148

これでいけた。DB側でソートしてから返すことでフロントでのソートを短縮。mysqlはクエリキャッシュとかもあるはずだからまあ良さげちゃうか？

	query := `
SELECT
    l.id,
    COALESCE(SUM(r.reaction_count), 0) AS total_reactions,
    COALESCE(SUM(lc.tip), 0) AS total_tips,
    COALESCE(SUM(r.reaction_count), 0) + COALESCE(SUM(lc.tip), 0) AS score
FROM
    livestreams l
LEFT JOIN
    (SELECT livestream_id, COUNT(*) AS reaction_count
     FROM reactions
     GROUP BY livestream_id) r ON l.id = r.livestream_id
LEFT JOIN
    livecomments lc ON l.id = lc.livestream_id
GROUP BY
    l.id
ORDER BY
    score ASC,
	l.id ASC;
	`

今は 23.04% なんか減った感じはする

なんか遅いな〜と思ったら、一回のプロファイルではでかく出てる Stat はそこまで呼び出し多くないから、他を調査しないといけないくさい

pprofile は単一リクエストのプロファイルは取れるが、全体となると別が良さそうか

Icon対応

user_handler の以下の部分はだいぶ厳しいと思われる

iconHash := sha256.Sum256(image)

とりあえず no Image の時は固定値を返すとして、DBに値も保存しておきたいので、Icon作成時に保存するのが良さそうか。

Obserbability

https://trap.jp/post/2046/ ベンチマーカー側が cookie 保存するのでトラッキングID仕込んでユーザー遷移を追う感じっぽい

これは自作するのは大変そうだけど、正味 observability の出来が一番影響しそうなので他の人のを参考にしてみる

mazrean/isucrud: ISUCON用DBに対するCRUD操作周りのコールフロー可視化ツール https://github.com/mazrean/isucrud

isucrud .

こういうのができた すごいツールだ

NodeGarph ツール考える　

ユーザーリクエストのトレース、分散トレーシングは必須　 トレースのためには trace ID が必要

1.AWS Distro for OpenTelemetryを試してみた https://zenn.dev/kobayashi_m42/articles/try-aws-distro-for-opentelemetry

1.Trace Context https://www.w3.org/TR/trace-context/

The traceparent header represents the incoming request in a tracing system in a common format, understood by all vendors. Here’s an example of a traceparent header.

The `traceparent` HTTP header field identifies the incoming request in a tracing system. It has four fields:

- `version`
- `trace-id`
- `parent-id`
- `trace-flags`

これ自作はキッツイから library が欲しい

trace golang node graph 今だと世の中的には Graphana で可視化一択っぽいか..?

参考実装

https://gammalab.net/blog/43uqjmpr8qx/

    "go.opentelemetry.io/otel"
    "go.opentelemetry.io/otel/exporters/stdout/stdouttrace"
    "go.opentelemetry.io/otel/sdk/resource"
    sdktrace "go.opentelemetry.io/otel/sdk/trace"
    semconv "go.opentelemetry.io/otel/semconv/v1.7.0"
    "go.opentelemetry.io/otel/attribute"

install https://opentelemetry.io/docs/languages/go/getting-started/

go get "go.opentelemetry.io/otel" \
  "go.opentelemetry.io/otel/exporters/stdout/stdoutmetric" \
  "go.opentelemetry.io/otel/exporters/stdout/stdouttrace" \
  "go.opentelemetry.io/otel/exporters/stdout/stdoutlog" \
  "go.opentelemetry.io/otel/sdk/log" \
  "go.opentelemetry.io/otel/log/global" \
  "go.opentelemetry.io/otel/propagation" \
  "go.opentelemetry.io/otel/sdk/metric" \
  "go.opentelemetry.io/otel/sdk/resource" \
  "go.opentelemetry.io/otel/sdk/trace" \
  "go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp"\
  "go.opentelemetry.io/contrib/bridges/otelslog"

これがいいらしい　 https://pkg.go.dev/go.opentelemetry.io/contrib/instrumentation/github.com/labstack/echo/otelecho

go get go.opentelemetry.io/contrib/instrumentation/github.com/labstack/echo/otelecho

参考実装はできたけど、これ exporter でローカル graphana とか別の graphana に飛ばさないとダメな気がする

func main() {

	runtime.SetBlockProfileRate(1)
	runtime.SetMutexProfileFraction(1)
	go func() {
		log.Fatal(http.ListenAndServe("localhost:6060", nil))
	}()

	e := echo.New()
	e.Debug = true
	e.Logger.SetLevel(echolog.DEBUG)
	e.Use(middleware.Logger())
	cookieStore := sessions.NewCookieStore(secret)
	cookieStore.Options.Domain = "*.u.isucon.dev"
	e.Use(session.Middleware(cookieStore))
	// e.Use(middleware.Recover())

	// OTEL // OTEL// OTEL// OTEL
	// tracerの初期化
	cleanup, err := setupTraceProvider("example-service", "1.0.0")

	if err != nil {
		panic(err)
	}
	defer cleanup()
	// /metrics と /health は計測しないようにする
	skipper := otelecho.WithSkipper(
		func(c echo.Context) bool {
			return c.Path() == "/metrics" || c.Path() == "/health"
		},
	)
	e.Use(otelecho.Middleware("api", skipper))

	e.Use(middleware.LoggerWithConfig(middleware.LoggerConfig{
		Skipper: func(c echo.Context) bool {
			return c.Path() == "/metrics" || c.Path() == "/health"
		},
		Format: `{"time":"${time_rfc3339_nano}",${custom},"remote_ip":"${remote_ip}",` +
			`"host":"${host}","method":"${method}","uri":"${uri}","status":${status},` +
			`"error":"${error}","latency":${latency},"latency_human":"${latency_human}",` +
			`"bytes_in":${bytes_in},"bytes_out":${bytes_out}}` + "\n",
		CustomTagFunc: func(c echo.Context, buf *bytes.Buffer) (int, error) {
			span := trace.SpanFromContext(c.Request().Context())
			buf.WriteString(fmt.Sprintf("\"%s\":\"%s\"", "traceID", span.SpanContext().TraceID().String()))
			buf.WriteString(fmt.Sprintf(",\"%s\":\"%s\"", "spanID", span.SpanContext().SpanID().String()))
			return 0, nil
		},
	}))
	// OTEL// OTEL// OTEL// OTEL

	// 初期化
	e.POST("/api/initialize", initializeHandler)

	// top
	e.GET("/api/tag", getTagHandler)
	e.GET("/api/user/:username/theme", getStreamerThemeHandler)

	// livestream
	// reserve livestream
	e.POST("/api/livestream/reservation", reserveLivestreamHandler)
	// list livestream
	e.GET("/api/livestream/search", searchLivestreamsHandler)
	e.GET("/api/livestream", getMyLivestreamsHandler)
	e.GET("/api/user/:username/livestream", getUserLivestreamsHandler)
	// get livestream
	e.GET("/api/livestream/:livestream_id", getLivestreamHandler)
	// get polling livecomment timeline
	e.GET("/api/livestream/:livestream_id/livecomment", getLivecommentsHandler)
	// ライブコメント投稿
	e.POST("/api/livestream/:livestream_id/livecomment", postLivecommentHandler)
	e.POST("/api/livestream/:livestream_id/reaction", postReactionHandler)
	e.GET("/api/livestream/:livestream_id/reaction", getReactionsHandler)

	// (配信者向け)ライブコメントの報告一覧取得API
	e.GET("/api/livestream/:livestream_id/report", getLivecommentReportsHandler)
	e.GET("/api/livestream/:livestream_id/ngwords", getNgwords)
	// ライブコメント報告
	e.POST("/api/livestream/:livestream_id/livecomment/:livecomment_id/report", reportLivecommentHandler)
	// 配信者によるモデレーション (NGワード登録)
	e.POST("/api/livestream/:livestream_id/moderate", moderateHandler)

	// livestream_viewersにINSERTするため必要
	// ユーザ視聴開始 (viewer)
	e.POST("/api/livestream/:livestream_id/enter", enterLivestreamHandler)
	// ユーザ視聴終了 (viewer)
	e.DELETE("/api/livestream/:livestream_id/exit", exitLivestreamHandler)

	// user
	e.POST("/api/register", registerHandler)
	e.POST("/api/login", loginHandler)
	e.GET("/api/user/me", getMeHandler)
	// フロントエンドで、配信予約のコラボレーターを指定する際に必要
	e.GET("/api/user/:username", getUserHandler)
	e.GET("/api/user/:username/statistics", getUserStatisticsHandler)
	e.GET("/api/user/:username/icon", getIconHandler)
	e.POST("/api/icon", postIconHandler)

	// stats
	// ライブ配信統計情報
	e.GET("/api/livestream/:livestream_id/statistics", getLivestreamStatisticsHandler)

	// 課金情報
	e.GET("/api/payment", GetPaymentResult)

	e.HTTPErrorHandler = errorResponseHandler

	// DB接続
	conn, err := connectDB(e.Logger)
	if err != nil {
		e.Logger.Errorf("failed to connect db: %v", err)
		os.Exit(1)
	}
	defer conn.Close()
	dbConn = conn
	dbConn.SetMaxOpenConns(10)
	dbConn.SetMaxIdleConns(5)

	subdomainAddr, ok := os.LookupEnv(powerDNSSubdomainAddressEnvKey)
	if !ok {
		e.Logger.Errorf("environ %s must be provided", powerDNSSubdomainAddressEnvKey)
		os.Exit(1)
	}
	powerDNSSubdomainAddress = subdomainAddr

	// HTTPサーバ起動
	listenAddr := net.JoinHostPort("", strconv.Itoa(listenPort))
	if err := e.Start(listenAddr); err != nil {
		e.Logger.Errorf("failed to start HTTP server: %v", err)
		os.Exit(1)
	}
}

type ErrorResponse struct {
	Error string `json:"error"`
}

func errorResponseHandler(err error, c echo.Context) {
	c.Logger().Errorf("error at %s: %+v", c.Path(), err)
	if he, ok := err.(*echo.HTTPError); ok {
		if e := c.JSON(he.Code, &ErrorResponse{Error: err.Error()}); e != nil {
			c.Logger().Errorf("%+v", e)
		}
		return
	}

	if e := c.JSON(http.StatusInternalServerError, &ErrorResponse{Error: err.Error()}); e != nil {
		c.Logger().Errorf("%+v", e)
	}
}

func setupTraceProvider(serviceName string, serviceVersion string) (func(), error) {

	// otelのライブラリではexporterという枠組みで計測した情報をどこに送信するかを設定できる
	// 今回はとりあえず標準出力に出してみる
	exporter, err := stdouttrace.New(
		stdouttrace.WithPrettyPrint(),
		stdouttrace.WithWriter(os.Stderr),
	)
	if err != nil {
		return nil, err
	}

	// ここでresourceを設定することで、全てのspanに共通のメタデータを設定できる
	resource := resource.NewWithAttributes(
		semconv.SchemaURL,
		semconv.ServiceNameKey.String(serviceName),
		semconv.ServiceVersionKey.String(serviceVersion),
	)

	// 実際に計測するためのtracerProviderを作成する
	tracerProvider := sdktrace.NewTracerProvider(
		sdktrace.WithBatcher(exporter),
		sdktrace.WithSampler(sdktrace.AlwaysSample()),
		sdktrace.WithResource(resource),
	)
	otel.SetTracerProvider(tracerProvider)

	// tracerProviderを終了するための関数を返す
	cleanup := func() {
		ctx, cancel := context.WithCancel(context.Background())
		defer cancel()
		tracerProvider.Shutdown(ctx)
	}

	return cleanup, nil
}

graphana install

https://grafana.com/docs/grafana/latest/setup-grafana/installation/debian/

sudo apt-get install -y apt-transport-https software-properties-common wget

run

sudo /bin/systemctl start grafana-server

VSCode で portforwading するとすぐ見れる

sudo cat /etc/grafana/grafana.ini

initial user は admin, admin で入れる

ログインできた

otel から graphana に飛ばす

あ〜これはやめてログをファイルに出して、その読み取りは自作した方がいいかも… Grafana の依存関係多いし

file exporter 設定必要そう

alpha だけどこれ使うか https://pkg.go.dev/github.com/open-telemetry/opentelemetry-collector-contrib/exporter/fileexporter

github.com/open-telemetry/opentelemetry-collector-contrib/exporter/fileexporter

go get github.com/open-telemetry/opentelemetry-collector-contrib/exporter/fileexporter

curl https://pipe.u.isucon.dev/ --resolve pipe.u.isucon.dev:443:35.72.35.148

作った https://github.com/mikanbox/isuexporter

こいつを読み込む

	// tracerの初期化
	cleanup, err := isuexporter.TraceFileProvider("output.json", "isucon13", "0.0.0")
	if err != nil {
		panic(err)
	}
	defer cleanup()