DBを2回呼び出すのと処理をまとめて1回で済ませた時のパフォーマンス比較

初めに

APIでDBを操作する際、各機能が対象とするモデルを1つに限定したいと考えた。なぜなら、各モデル（例：本、出版社）に対するCRUD操作が独立していて、ユースケースに応じてこれらを組み合わせることで、設計をシンプルにできると感じたから。

仮想テーブルを作成してバックエンドでJOIN操作を行う方がパフォーマンスが良いと思うが、実際にどれくらいのパフォーマンス差が現れるのか、小さいアプリケーションなら無視できる程度なのか。この疑問を解決するために、検証を行った。

じゃあなにすんのサ

PostgreSQLのDBを建て、ダミーデータ（本と出版社）を100件、10,000件、1,000,000件登録。本のテーブルには出版社の主キーを保持するフィールドを設定した。
データの取得は以下の2つのパターンで行う。

パターン1：
無作為に本のレコードをDBから取得し、その後出版社の主キーを使用して出版社のレコードを取得する。

パターン2：
無作為に本のレコードをDBから取得し、その際に出版社のテーブルとJOINして、一度のクエリで必要な情報を全て取得する。

本と出版社の両方の情報を取得できるまでのタイムを計測する。

実装

Docker

# docker-compose.yml
version: '3'

services:
  db:
    image: postgres:13
    container_name: postgres
    ports:
      - 5432:5432
    tty: true
    volumes:
      - db-store:/var/lib/postgresql/data
    environment:
      - POSTGRES_PASSWORD=password
      - POSTGRES_USER=mydbuser
      - POSTGRES_DB=mydbname
volumes:
  db-store:

まずは検証用のpostgresqlをDockerで建てる。検証用なので、パスワードとかは全部適当。余談だが、tty: trueも設定しないとportsの設定が反映されないのはいかがなものか。

DDL

# ddl.sql
CREATE TABLE publishers (
    id SERIAL PRIMARY KEY,
    name VARCHAR(255) NOT NULL
);

CREATE TABLE books (
    id SERIAL PRIMARY KEY,
    title VARCHAR(255) NOT NULL,
    author VARCHAR(255) NOT NULL,
    publisher_id INTEGER REFERENCES publishers(id)
);

データテーブルも事前に登録しておく。

ダミーデータ挿入

// dummy.go
package main

import (
	"database/sql"
	"fmt"
	"log"
	"strings"

	_ "github.com/lib/pq"
)

type Book struct {
	ID          int    `json:"id"`
	Title       string `json:"title"`
	Author      string `json:"author"`
	PublisherID int    `json:"publisher_id"`
}

type Publisher struct {
	ID   int    `json:"id"`
	Name string `json:"name"`
}

type BookPublisherRepository struct {
	db *sql.DB
}

func (r *BookPublisherRepository) InsertBook(book Book) error {
	_, err := r.db.Exec("INSERT INTO books (title, author, publisher_id) VALUES ($1, $2, $3)", book.Title, book.Author, book.PublisherID)
	return err
}

func (r *BookPublisherRepository) InsertPublisher(publisher Publisher) error {
	_, err := r.db.Exec("INSERT INTO publishers (name) VALUES ($1)", publisher.Name)
	return err
}

func (r *BookPublisherRepository) InsertBooksBatch(books []Book) error {
	valueStrings := make([]string, 0, len(books))
	valueArgs := make([]interface{}, 0, len(books)*3)
	for i, book := range books {
		valueStrings = append(valueStrings, fmt.Sprintf("($%d, $%d, $%d)", i*3+1, i*3+2, i*3+3))
		valueArgs = append(valueArgs, book.Title)
		valueArgs = append(valueArgs, book.Author)
		valueArgs = append(valueArgs, book.PublisherID)
	}

	stmt := fmt.Sprintf("INSERT INTO books (title, author, publisher_id) VALUES %s", strings.Join(valueStrings, ","))
	_, err := r.db.Exec(stmt, valueArgs...)
	return err
}

func (r *BookPublisherRepository) InsertPublishersBatch(publishers []Publisher) error {
	valueStrings := make([]string, 0, len(publishers))
	valueArgs := make([]interface{}, 0, len(publishers))

	for i, publisher := range publishers {
		valueStrings = append(valueStrings, fmt.Sprintf("($%d)", i+1))
		valueArgs = append(valueArgs, publisher.Name)
	}

	stmt := fmt.Sprintf("INSERT INTO publishers (name) VALUES %s", strings.Join(valueStrings, ","))
	_, err := r.db.Exec(stmt, valueArgs...)
	return err
}

func main() {
	connStr := "host=localhost port=5432 user=mydbuser dbname=mydbname sslmode=disable password=password"

	db, err := sql.Open("postgres", connStr)
	if err != nil {
		log.Fatalf("Failed to open a DB connection: %v", err)
	}
	defer db.Close()

	repo := &BookPublisherRepository{db: db}

	totalRecords := 100

	publishers := make([]Publisher, 0, 1000)
	for i := 1; i <= totalRecords; i++ {
		publishers = append(publishers, Publisher{
			Name: fmt.Sprintf("Dummy Publisher %d", i),
		})
		if len(publishers) == totalRecords/10 {
			err = repo.InsertPublishersBatch(publishers)
			if err != nil {
				log.Fatalf("Failed to insert publishers: %v", err)
			}
			publishers = publishers[:0]
		}
	}

	books := make([]Book, 0, 1000)
	for i := 1; i <= totalRecords; i++ {
		books = append(books, Book{
			Title:       fmt.Sprintf("Dummy Book %d", i),
			Author:      fmt.Sprintf("Dummy Author %d", i),
			PublisherID: i,
		})
		if len(books) == totalRecords/10 {
			err = repo.InsertBooksBatch(books)
			if err != nil {
				log.Fatalf("Failed to insert books: %v", err)
			}
			books = books[:0]
		}
	}
}

ダミーデータを入れるためのスクリプトを作成。100万回クエリを投げるのは非効率な為、バッチ処理で分割してダミーデータを挿入する。

検証コード

// main.go
package main

import (
	"database/sql"
	"log"
	"math/rand"
	"sort"
	"time"

	_ "github.com/lib/pq"
)

type Book struct {
	ID          int    `json:"id"`
	Title       string `json:"title"`
	Author      string `json:"author"`
	PublisherID int    `json:"publisher_id"`
}

type Publisher struct {
	ID   int    `json:"id"`
	Name string `json:"name"`
}

type BookPublisherRepository struct {
	db *sql.DB
}

func (r *BookPublisherRepository) GetBookByID(id int) (*Book, error) {
	row := r.db.QueryRow("SELECT id, title, author, publisher_id FROM books WHERE id = $1", id)
	var book Book
	if err := row.Scan(&book.ID, &book.Title, &book.Author, &book.PublisherID); err != nil {
		if err == sql.ErrNoRows {
			return nil, nil
		}
		return nil, err
	}
	return &book, nil
}

func (r *BookPublisherRepository) GetPublisherByID(id int) (*Publisher, error) {
	row := r.db.QueryRow("SELECT id, name FROM publishers WHERE id = $1", id)
	var publisher Publisher
	if err := row.Scan(&publisher.ID, &publisher.Name); err != nil {
		if err == sql.ErrNoRows {
			return nil, nil
		}
		return nil, err
	}
	return &publisher, nil
}

func (r *BookPublisherRepository) GetBookWithPublisherByID(id int) (*Book, *Publisher, error) {
	row := r.db.QueryRow(`SELECT b.id, b.title, b.author, b.publisher_id, p.id, p.name
	FROM books AS b
	JOIN publishers AS p ON b.publisher_id = p.id
	WHERE b.id = $1`, id)

	var book Book
	var publisher Publisher

	if err := row.Scan(&book.ID, &book.Title, &book.Author, &book.PublisherID, &publisher.ID, &publisher.Name); err != nil {
		if err == sql.ErrNoRows {
			return nil, nil, nil
		}
		return nil, nil, err
	}
	return &book, &publisher, nil
}

func calcAverageTime(durations []time.Duration) time.Duration {
	var total time.Duration
	for _, d := range durations {
		total += d
	}
	return total / time.Duration(len(durations))
}

func runTests(repo *BookPublisherRepository) {
	log.Println("Running tests...")
	attempts := 1000
	totalRecords := 100
	rand.Seed(time.Now().UnixNano())

	log.Println("Attemps:", attempts, "Total records:", totalRecords)

	// Pattern 1
	var durations1 []time.Duration

	for i := 1; i <= attempts; i++ {
		randomID := rand.Intn(totalRecords) + 1
		start := time.Now()
		book, err := repo.GetBookByID(randomID)
		if err != nil {
			log.Printf("Error fetching book with ID %d: %v", randomID, err)
			continue
		}
		_, err = repo.GetPublisherByID(book.PublisherID)
		if err != nil {
			log.Printf("Error fetching publisher with ID %d: %v", book.PublisherID, err)
			continue
		}
		elapsed := time.Since(start)
		durations1 = append(durations1, elapsed)
	}
	sort.Slice(durations1, func(i, j int) bool { return durations1[i] < durations1[j] })
	averageTime1 := calcAverageTime(durations1)
	maxTime1 := durations1[len(durations1)-1]
	minTime1 := durations1[0]
	p95Time1 := durations1[int(float64(len(durations1))*0.95)]

	// Pattern 2
	var durations2 []time.Duration

	for i := 1; i <= attempts; i++ {
		randomID := rand.Intn(totalRecords) + 1
		start := time.Now()
		_, _, err := repo.GetBookWithPublisherByID(randomID)
		if err != nil {
			log.Printf("Error fetching book and publisher with ID %d: %v", randomID, err)
			continue
		}
		elapsed := time.Since(start)
		durations2 = append(durations2, elapsed)
	}
	sort.Slice(durations2, func(i, j int) bool { return durations2[i] < durations2[j] })
	averageTime2 := calcAverageTime(durations2)
	maxTime2 := durations2[len(durations2)-1]
	minTime2 := durations2[0]
	p95Time2 := durations2[int(float64(len(durations2))*0.95)]

	log.Printf("Average time for Pattern 1: %s, Max: %s, Min: %s, P95: %s", averageTime1, maxTime1, minTime1, p95Time1)
	log.Printf("Average time for Pattern 2: %s, Max: %s, Min: %s, P95: %s", averageTime2, maxTime2, minTime2, p95Time2)

	log.Println("Tests completed")
}

func main() {
	connStr := "host=localhost port=5432 user=mydbuser dbname=mydbname sslmode=disable password=password"
	db, err := sql.Open("postgres", connStr)
	if err != nil {
		log.Fatalf("Failed to open a DB connection: %v", err)
	}
	defer db.Close()
	repo := &BookPublisherRepository{db: db}

	runTests(repo)
}

func runTests(repo *PostgresRepository) {
	log.Println("Running tests...")
	attempts := 1000 // Number of searching
	totalRecords := 100 // records in DB

タイム計測はランダムなidに対して1000回データを取得するまでの時間を計測する。

タイム計測

Test Conditions

• Attempts: 1000
• Random Seed: Based on current Unix timestamp

Pattern 1

totalRecords	Average Time	Max Time	Min Time	P95
100	1.263973ms	8.784ms	599.4µs	1.5191ms
10,000	1.300192ms	9.18ms	504.2µs	1.6168ms
1,000,000	1.298335ms	8.8945ms	1.0077ms	1.5715ms

Pattern 2

totalRecords	Average Time	Max Time	Min Time	P95
100	734.247µs	1.4158ms	0s	1.0388ms
10,000	712.16µs	1.5125ms	0s	1.0491ms
1,000,000	767.264µs	1.6421ms	502.2µs	1.0439ms

P95 (95thパーセンタイル): データセット内の値がこの値以下であるデータが全体の95%を占めるという統計的な指標。「ユーザーの95%はこの時間以内にレスポンスが返ってくる」と解釈できる。

まとめ

Pattern 1はN+1問題に近いケースと言える。1回の主要なクエリ（本を取得）とN回のサブクエリ（各本に対応する出版社を取得）の実行が必要になる。データベースとのやり取りが必然的に多くなる為、Pattern 2と比較して明確にパフォーマンスが下がっている。平均タイムも比較するとPattern 1は平均タイムは1.3ms程度であり、Pattern 2は平均タイムは0.7ms~0.8msと約1.7倍の差がある。

ちなみに、Pattern 2でMin Timeで0sが出ているのは、golangのDBクライアントのキャッシュによって即座に結果を返せたケースである可能性が考えられる。[要出典]

意外だったのはPattern 1のタイムがデータ数に比例して増えなかった事である。DBの最適化が凄く優秀なのか、はたまた自分のPCが高性能すぎるのか。P95のタイムで比較すると、ほとんど差が見られなかった。考えても理由が分からなかったので、ここについては知見がある方が居たら是非教えて頂きたい。

終わりに

最近クリーンアーキテクチャの話をよく聞くので、身近なケースでクリーンな設計を導入できないかと考えていた。今回のケースで言うと、本と出版社は別々のモデルであり、処理を混ぜるのはイケてないと感じた。N+1問題があるにせよ、実測値としてさほど大きな差は生まれないのならシンプルな設計を取り入れるのも悪くは無いかと浅慮した結果、普通に大きめの差が出た。

個人開発の自分用アプリなら許容できるが、さらにデータが増えたり、ユーザー数が増えたら悲惨なパフォーマンスになること請け合いである。分離・独立・責務。クリーンアーキテクチャでは最小限の責務を持たせることを奨励しているが、理解が浅いとパフォーマンスに悪影響を及ぼすという良い勉強になった。