diff --git a/benchmark/README.md b/benchmark/README.md index a92013f..810c966 100644 --- a/benchmark/README.md +++ b/benchmark/README.md @@ -37,3 +37,47 @@ Random writing of 100MB Tart 2.0 GB/s 493.31 kIOPS Random writing of 1000MB local 1.7 GB/s 414.89 kIOPS Random writing of 1000MB Tart 1.1 GB/s 287.4 kIOPS ``` + +Host: + +* Hardware: MacBook Pro (Apple M1 Pro, 8 performance and 2 efficiency cores, 32 GB RAM, `MacBookPro18,3`) +* OS: macOS Sequoia 15.1.1 + +Guest: + +* Hardware: [Virtualization.Framework](https://developer.apple.com/documentation/virtualization) +* OS: macOS Sonoma 14.6 + +``` +Name Executor B/W (read) B/W (write) I/O (read) I/O (write) Latency (read) Latency (write) Latency (sync) +Single 4KiB random write process local 0 B/s 19 MB/s 0 IOPS 4.81 kIOPS 0s ± 0s 203.418µs ± 155.865µs 0s ± 0s +Single 4KiB random write process Tart 0 B/s 18 MB/s 0 IOPS 4.54 kIOPS 0s ± 0s 213.655µs ± 188.822µs 0s ± 0s +Single 4KiB random write process Tart (--root-disk-opts="sync=none") 0 B/s 19 MB/s 0 IOPS 4.68 kIOPS 0s ± 0s 208.413µs ± 183.45µs 0s ± 0s +Single 4KiB random write process Tart (--root-disk-opts="caching=cached") 0 B/s 24 MB/s 0 IOPS 6.11 kIOPS 0s ± 0s 158.07µs ± 2.294654ms 0s ± 0s +Single 4KiB random write process Tart (--root-disk-opts="sync=none,caching=cached") 0 B/s 22 MB/s 0 IOPS 5.49 kIOPS 0s ± 0s 173.414µs ± 310.213µs 0s ± 0s +16 parallel 64KiB random write processes local 0 B/s 18 GB/s 0 IOPS 273.76 kIOPS 0s ± 0s 323.423µs ± 604.999µs 0s ± 0s +16 parallel 64KiB random write processes Tart 0 B/s 16 GB/s 0 IOPS 273.48 kIOPS 0s ± 0s 335.086µs ± 7.591748ms 0s ± 0s +16 parallel 64KiB random write processes Tart (--root-disk-opts="sync=none") 0 B/s 18 GB/s 0 IOPS 281.49 kIOPS 0s ± 0s 326.655µs ± 7.485473ms 0s ± 0s +16 parallel 64KiB random write processes Tart (--root-disk-opts="caching=cached") 0 B/s 17 GB/s 0 IOPS 266.79 kIOPS 0s ± 0s 340µs ± 7.868384ms 0s ± 0s +16 parallel 64KiB random write processes Tart (--root-disk-opts="sync=none,caching=cached") 0 B/s 16 GB/s 0 IOPS 251.02 kIOPS 0s ± 0s 355.077µs ± 8.354218ms 0s ± 0s +Single 1MiB random write process local 0 B/s 1.3 GB/s 0 IOPS 1.31 kIOPS 0s ± 0s 751.716µs ± 370.731µs 0s ± 0s +Single 1MiB random write process Tart 0 B/s 1.1 GB/s 0 IOPS 1.1 kIOPS 0s ± 0s 885.833µs ± 3.572539ms 0s ± 0s +Single 1MiB random write process Tart (--root-disk-opts="sync=none") 0 B/s 1.1 GB/s 0 IOPS 1.08 kIOPS 0s ± 0s 898.427µs ± 3.464261ms 0s ± 0s +Single 1MiB random write process Tart (--root-disk-opts="caching=cached") 0 B/s 1000 MB/s 0 IOPS 976.47 IOPS 0s ± 0s 972.491µs ± 6.87654ms 0s ± 0s +Single 1MiB random write process Tart (--root-disk-opts="sync=none,caching=cached") 0 B/s 1.1 GB/s 0 IOPS 1.03 kIOPS 0s ± 0s 925.545µs ± 4.261693ms 0s ± 0s +Random reads/writes (4k) local 62 MB/s 62 MB/s 15.37 kIOPS 15.37 kIOPS 2.059453ms ± 1.431822ms 2.098761ms ± 1.445082ms 0s ± 0s +Random reads/writes (4k) Tart 38 MB/s 38 MB/s 9.6 kIOPS 9.61 kIOPS 3.30369ms ± 1.500464ms 3.350589ms ± 1.512986ms 0s ± 0s +Random reads/writes (4k) Tart (--root-disk-opts="sync=none") 39 MB/s 39 MB/s 9.82 kIOPS 9.83 kIOPS 3.228106ms ± 1.367512ms 3.27626ms ± 1.385964ms 0s ± 0s +Random reads/writes (4k) Tart (--root-disk-opts="caching=cached") 35 MB/s 35 MB/s 8.74 kIOPS 8.76 kIOPS 3.640772ms ± 15.472355ms 3.661779ms ± 15.264288ms 0s ± 0s +Random reads/writes (4k) Tart (--root-disk-opts="sync=none,caching=cached") 24 MB/s 24 MB/s 5.98 kIOPS 5.99 kIOPS 5.31188ms ± 4.55205ms 5.375047ms ± 5.113847ms 0s ± 0s +Random reads/writes (64k) local 435 MB/s 436 MB/s 6.79 kIOPS 6.8 kIOPS 4.955892ms ± 2.066685ms 4.440414ms ± 1.860036ms 0s ± 0s +Random reads/writes (64k) Tart 352 MB/s 353 MB/s 5.5 kIOPS 5.51 kIOPS 5.946067ms ± 2.041124ms 5.658948ms ± 1.928372ms 0s ± 0s +Random reads/writes (64k) Tart (--root-disk-opts="sync=none") 331 MB/s 332 MB/s 5.16 kIOPS 5.17 kIOPS 6.330765ms ± 1.726782ms 6.033862ms ± 1.671028ms 0s ± 0s +Random reads/writes (64k) Tart (--root-disk-opts="caching=cached") 428 MB/s 428 MB/s 6.68 kIOPS 6.69 kIOPS 4.661666ms ± 18.342779ms 4.904961ms ± 18.396772ms 0s ± 0s +Random reads/writes (64k) Tart (--root-disk-opts="sync=none,caching=cached") 297 MB/s 298 MB/s 4.64 kIOPS 4.65 kIOPS 6.591009ms ± 2.827053ms 7.166883ms ± 3.001036ms 0s ± 0s +sync test local 0 B/s 48 MB/s 0 IOPS 21.15 kIOPS 0s ± 0s 23.471µs ± 81.868µs 23.374µs ± 6.255µs +sync test Tart 0 B/s 24 MB/s 0 IOPS 10.72 kIOPS 0s ± 0s 24.983µs ± 61.761µs 67.575µs ± 76.196µs +sync test Tart (--root-disk-opts="sync=none") 0 B/s 21 MB/s 0 IOPS 9.5 kIOPS 0s ± 0s 26.973µs ± 63.935µs 77.388µs ± 47.103µs +sync test Tart (--root-disk-opts="caching=cached") 0 B/s 30 MB/s 0 IOPS 13.19 kIOPS 0s ± 0s 11.923µs ± 25.225µs 62.894µs ± 208.933µs +sync test Tart (--root-disk-opts="sync=none,caching=cached") 0 B/s 38 MB/s 0 IOPS 17.02 kIOPS 0s ± 0s 10.124µs ± 21.868µs 47.803µs ± 33.706µs +``` diff --git a/benchmark/internal/command/fio/benchmark.go b/benchmark/internal/command/fio/benchmark.go index 6561ce0..fb2b8b3 100644 --- a/benchmark/internal/command/fio/benchmark.go +++ b/benchmark/internal/command/fio/benchmark.go @@ -7,23 +7,63 @@ type Benchmark struct { var benchmarks = []Benchmark{ { - Name: "Random writing of 1MB", - Command: "fio --rw randwrite --runtime 30 --time_based --unlink 1 --output-format json " + - "--size 1MB --name unnamed --numjobs 1 --iodepth 1 --end_fsync 1", + // Ars Technica's "Single 4KiB random write process" test[1] + // with JSON output and created file cleanup + // + // [1]: https://arstechnica.com/gadgets/2020/02/how-fast-are-your-disks-find-out-the-open-source-way-with-fio/ + Name: "Single 4KiB random write process", + Command: "fio --name=benchmark --ioengine=posixaio --rw=randwrite --bs=4k --size=4g --numjobs=1 --iodepth=1 --runtime=60 --time_based --end_fsync=1" + + " --output-format json --unlink 1", }, { - Name: "Random writing of 10MB", - Command: "fio --rw randwrite --runtime 30 --time_based --unlink 1 --output-format json " + - "--size 10MB --name unnamed --numjobs 1 --iodepth 1 --end_fsync 1", + // Ars Technica's "16 parallel 64KiB random write processes" test[1] + // with JSON outpu, created file cleanup and group reporting (for + // easier analysis) + // + // [1]: https://arstechnica.com/gadgets/2020/02/how-fast-are-your-disks-find-out-the-open-source-way-with-fio/ + Name: "16 parallel 64KiB random write processes", + Command: "fio --name=benchmark --ioengine=posixaio --rw=randwrite --bs=64k --size=256m --numjobs=16 --iodepth=16 --runtime=60 --time_based --end_fsync=1" + + " --output-format json --unlink 1 --group_reporting", }, { - Name: "Random writing of 100MB", - Command: "fio --rw randwrite --runtime 30 --time_based --unlink 1 --output-format json " + - "--size 100MB --name unnamed --numjobs 1 --iodepth 1 --end_fsync 1", + // Ars Technica's "16 parallel 64KiB random write processes" test[1] + // with JSON output, created file cleanup and reduced file I/O size + // from 16 to 10 GB to avoid "No space left on device". + // + // [1]: https://arstechnica.com/gadgets/2020/02/how-fast-are-your-disks-find-out-the-open-source-way-with-fio/ + Name: "Single 1MiB random write process", + Command: "fio --name=benchmark --ioengine=posixaio --rw=randwrite --bs=1m --size=10g --numjobs=1 --iodepth=1 --runtime=60 --time_based --end_fsync=1" + + " --output-format json --unlink 1", }, { - Name: "Random writing of 1000MB", - Command: "fio --rw randwrite --runtime 30 --time_based --unlink 1 --output-format json " + - "--size 1000MB --name unnamed --numjobs 1 --iodepth 1 --end_fsync 1", + // Oracle's "Test random read/writes" (in IOPS Performance Tests[1]) category + // with JSON output, created file cleanup, without ETA newline, without custom + // file path, with file I/O size reduced from 500GB to 2GB to prevent + // "No space left on device" and with posixaio instead of libaio. + // + // [1]: https://docs.oracle.com/en-us/iaas/Content/Block/References/samplefiocommandslinux.htm#FIO_Commands + Name: "Random reads/writes (4k)", + Command: "fio --name=benchmark --size=2GB --direct=1 --rw=randrw --bs=4k --ioengine=posixaio --iodepth=256 --runtime=120 --numjobs=4 --time_based --group_reporting" + + " --output-format json --unlink 1", + }, + { + // Oracle's "Test random read/writes" (in Throughput Performance Tests[1]) category + // with JSON output, created file cleanup, without ETA newline, without custom + // file path, with file I/O size reduced from 500GB to 2GB to prevent + // "No space left on device" and with posixaio instead of libaio. + // + // [1]: https://docs.oracle.com/en-us/iaas/Content/Block/References/samplefiocommandslinux.htm#Throughput_Performance_Tests + Name: "Random reads/writes (64k)", + Command: "fio --name=benchmark --size=2GB --direct=1 --rw=randrw --bs=64k --ioengine=posixaio --iodepth=64 --runtime=120 --numjobs=4 --time_based --group_reporting" + + " --output-format json --unlink 1", + }, + { + // RedHat's "How can I test to see if my environment is fast enough for etcd"[1] + // with custom name + // + // [1]: https://access.redhat.com/solutions/5726511 + Name: "sync test", + Command: "mkdir -p test-data && fio --name=benchmark --rw=write --ioengine=sync --fdatasync=1 --directory=test-data --size=22m --bs=2300" + + " --output-format json --unlink 1", }, } diff --git a/benchmark/internal/command/fio/fio.go b/benchmark/internal/command/fio/fio.go index aae969f..2c43c4f 100644 --- a/benchmark/internal/command/fio/fio.go +++ b/benchmark/internal/command/fio/fio.go @@ -1,21 +1,23 @@ package fio import ( - "context" "encoding/json" - "errors" "fmt" - "github.com/cirruslabs/tart/benchmark/internal/executor" + executorpkg "github.com/cirruslabs/tart/benchmark/internal/executor" "github.com/cirruslabs/tart/benchmark/internal/executor/local" "github.com/cirruslabs/tart/benchmark/internal/executor/tart" "github.com/dustin/go-humanize" "github.com/gosuri/uitable" "github.com/spf13/cobra" "go.uber.org/zap" + "go.uber.org/zap/zapio" + "os" + "os/exec" ) var debug bool var image string +var prepare string func NewCommand() *cobra.Command { cmd := &cobra.Command{ @@ -26,6 +28,7 @@ func NewCommand() *cobra.Command { cmd.Flags().BoolVar(&debug, "debug", false, "enable debug logging") cmd.Flags().StringVar(&image, "image", "ghcr.io/cirruslabs/macos-sonoma-base:latest", "image to use for testing") + cmd.Flags().StringVar(&prepare, "prepare", "", "command to run before running each benchmark") return cmd } @@ -43,28 +46,95 @@ func run(cmd *cobra.Command, args []string) error { _ = logger.Sync() }() - executors, err := initializeExecutors(cmd.Context(), logger) - if err != nil { - return err + var executorInitializers = []struct { + Name string + Fn func() (executorpkg.Executor, error) + }{ + { + Name: "local", + Fn: func() (executorpkg.Executor, error) { + return local.New(logger) + }, + }, + { + Name: "Tart", + Fn: func() (executorpkg.Executor, error) { + return tart.New(cmd.Context(), image, nil, logger) + }, + }, + { + Name: "Tart (--root-disk-opts=\"sync=none\")", + Fn: func() (executorpkg.Executor, error) { + return tart.New(cmd.Context(), image, []string{ + "--root-disk-opts", + "sync=none", + }, logger) + }, + }, + { + Name: "Tart (--root-disk-opts=\"caching=cached\")", + Fn: func() (executorpkg.Executor, error) { + return tart.New(cmd.Context(), image, []string{ + "--root-disk-opts", + "caching=cached", + }, logger) + }, + }, + { + Name: "Tart (--root-disk-opts=\"sync=none,caching=cached\")", + Fn: func() (executorpkg.Executor, error) { + return tart.New(cmd.Context(), image, []string{ + "--root-disk-opts", + "sync=none,caching=cached", + }, logger) + }, + }, } - defer func() { - errs := []error{err} - - for _, executor := range executors { - if err := executor.Close(); err != nil { - errs = append(errs, fmt.Errorf("failed to close executor %s: %w", executor.Name(), err)) - } - } - - err = errors.Join(errs...) - }() table := uitable.New() - table.AddRow("Name", "Executor", "Bandwidth", "I/O operations") + table.AddRow("Name", "Executor", "B/W (read)", "B/W (write)", "I/O (read)", "I/O (write)", + "Latency (read)", "Latency (write)", "Latency (sync)") for _, benchmark := range benchmarks { - for _, executor := range executors { - logger.Sugar().Infof("running benchmark %q on %s executor", benchmark.Name, executor.Name()) + for _, executorInitializer := range executorInitializers { + if prepare != "" { + shell := "/bin/sh" + + if shellFromEnv, ok := os.LookupEnv("SHELL"); ok { + shell = shellFromEnv + } + + logger.Sugar().Infof("running prepare command %q using shell %q", + prepare, shell) + + cmd := exec.CommandContext(cmd.Context(), shell, "-c", prepare) + + loggerWriter := &zapio.Writer{Log: logger, Level: zap.DebugLevel} + + cmd.Stdout = loggerWriter + cmd.Stderr = loggerWriter + + if err := cmd.Run(); err != nil { + return fmt.Errorf("failed to run prepare command %q: %v", prepare, err) + } + } + + logger.Sugar().Infof("initializing executor %s", executorInitializer.Name) + + executor, err := executorInitializer.Fn() + if err != nil { + return err + } + + logger.Sugar().Infof("installing Flexible I/O tester (fio) on executor %s", + executorInitializer.Name) + + if _, err := executor.Run(cmd.Context(), "brew install fio"); err != nil { + return err + } + + logger.Sugar().Infof("running benchmark %q on %s executor", benchmark.Name, + executorInitializer.Name) stdout, err := executor.Run(cmd.Context(), benchmark.Command) if err != nil { @@ -84,12 +154,28 @@ func run(cmd *cobra.Command, args []string) error { job := fioResult.Jobs[0] + readBandwidth := humanize.Bytes(uint64(job.Read.BW)*humanize.KByte) + "/s" + readIOPS := humanize.SIWithDigits(job.Read.IOPS, 2, "IOPS") + + logger.Sugar().Infof("read bandwidth: %s, read IOPS: %s, read latency: %s", + readBandwidth, readIOPS, job.Read.LatencyNS.String()) + writeBandwidth := humanize.Bytes(uint64(job.Write.BW)*humanize.KByte) + "/s" writeIOPS := humanize.SIWithDigits(job.Write.IOPS, 2, "IOPS") - logger.Sugar().Infof("write bandwidth: %s, write IOPS: %s\n", writeBandwidth, writeIOPS) + logger.Sugar().Infof("write bandwidth: %s, write IOPS: %s, write latency: %s", + writeBandwidth, writeIOPS, job.Write.LatencyNS.String()) - table.AddRow(benchmark.Name, executor.Name(), writeBandwidth, writeIOPS) + logger.Sugar().Infof("sync latency: %s", job.Sync.LatencyNS.String()) + + table.AddRow(benchmark.Name, executorInitializer.Name, readBandwidth, writeBandwidth, + readIOPS, writeIOPS, job.Read.LatencyNS.String(), job.Write.LatencyNS.String(), + job.Sync.LatencyNS.String()) + + if err := executor.Close(); err != nil { + return fmt.Errorf("failed to close executor %s: %w", + executorInitializer.Name, err) + } } } @@ -97,37 +183,3 @@ func run(cmd *cobra.Command, args []string) error { return nil } - -func initializeExecutors(ctx context.Context, logger *zap.Logger) ([]executor.Executor, error) { - var result []executor.Executor - - logger.Info("initializing local executor") - - local, err := local.New(logger) - if err != nil { - return nil, err - } - result = append(result, local) - - logger.Info("local executor initialized") - - logger.Info("initializing Tart executor") - - tart, err := tart.New(ctx, image, logger) - if err != nil { - return nil, err - } - result = append(result, tart) - - logger.Info("Tart executor initialized") - - for _, executor := range result { - logger.Sugar().Infof("installing Flexible I/O tester (fio) on %s executor", executor.Name()) - - if _, err := executor.Run(ctx, "brew install fio"); err != nil { - return nil, err - } - } - - return result, nil -} diff --git a/benchmark/internal/command/fio/json.go b/benchmark/internal/command/fio/json.go index 4305c60..1fac277 100644 --- a/benchmark/internal/command/fio/json.go +++ b/benchmark/internal/command/fio/json.go @@ -1,15 +1,35 @@ package fio +import ( + "fmt" + "time" +) + type Result struct { Jobs []Job `json:"jobs"` } type Job struct { Name string `json:"jobname"` - Write Write `json:"write"` + Read Stats `json:"read"` + Write Stats `json:"write"` + Sync Stats `json:"sync"` } -type Write struct { - BW float64 `json:"bw"` - IOPS float64 `json:"iops"` +type Stats struct { + BW float64 `json:"bw"` + IOPS float64 `json:"iops"` + LatencyNS Latency `json:"lat_ns"` +} + +type Latency struct { + Mean float64 `json:"mean"` + Stddev float64 `json:"stddev"` +} + +func (latency Latency) String() string { + meanDuration := time.Duration(latency.Mean) * time.Nanosecond + stddevDuration := time.Duration(latency.Stddev) * time.Nanosecond + + return fmt.Sprintf("%v ± %v", meanDuration, stddevDuration) } diff --git a/benchmark/internal/executor/executor.go b/benchmark/internal/executor/executor.go index 516f6a0..a7c9cbb 100644 --- a/benchmark/internal/executor/executor.go +++ b/benchmark/internal/executor/executor.go @@ -5,7 +5,6 @@ import ( ) type Executor interface { - Name() string Run(ctx context.Context, command string) ([]byte, error) Close() error } diff --git a/benchmark/internal/executor/tart/tart.go b/benchmark/internal/executor/tart/tart.go index de35d55..bcf3733 100644 --- a/benchmark/internal/executor/tart/tart.go +++ b/benchmark/internal/executor/tart/tart.go @@ -8,7 +8,9 @@ import ( "github.com/avast/retry-go/v4" "github.com/google/uuid" "go.uber.org/zap" + "go.uber.org/zap/zapio" "golang.org/x/crypto/ssh" + "io" "net" "strings" "time" @@ -21,7 +23,7 @@ type Tart struct { logger *zap.Logger } -func New(ctx context.Context, image string, logger *zap.Logger) (*Tart, error) { +func New(ctx context.Context, image string, runArgsExtra []string, logger *zap.Logger) (*Tart, error) { tart := &Tart{ vmName: fmt.Sprintf("tart-benchmark-%s", uuid.NewString()), logger: logger, @@ -39,7 +41,11 @@ func New(ctx context.Context, image string, logger *zap.Logger) (*Tart, error) { tart.vmRunCancel = vmRunCancel go func() { - _ = Cmd(vmRunCtx, tart.logger, "run", "--no-graphics", tart.vmName) + runArgs := []string{"run", "--no-graphics", tart.vmName} + + runArgs = append(runArgs, runArgsExtra...) + + _ = Cmd(vmRunCtx, tart.logger, runArgs...) }() ip, err := CmdWithOutput(ctx, tart.logger, "ip", "--wait", "60", tart.vmName) @@ -103,10 +109,12 @@ func (tart *Tart) Run(ctx context.Context, command string) ([]byte, error) { }() defer monitorCancel() + loggerWriter := &zapio.Writer{Log: tart.logger, Level: zap.DebugLevel} stdoutBuf := &bytes.Buffer{} sshSession.Stdin = bytes.NewBufferString(command) - sshSession.Stdout = stdoutBuf + sshSession.Stdout = io.MultiWriter(stdoutBuf, loggerWriter) + sshSession.Stderr = loggerWriter if err := sshSession.Shell(); err != nil { return nil, err diff --git a/benchmark/internal/executor/tart/tart_test.go b/benchmark/internal/executor/tart/tart_test.go index d11c4ab..1126b0c 100644 --- a/benchmark/internal/executor/tart/tart_test.go +++ b/benchmark/internal/executor/tart/tart_test.go @@ -11,7 +11,7 @@ import ( func TestTart(t *testing.T) { ctx := context.Background() - tart, err := tart.New(ctx, "ghcr.io/cirruslabs/macos-sonoma-base:latest", zap.NewNop()) + tart, err := tart.New(ctx, "ghcr.io/cirruslabs/macos-sonoma-base:latest", nil, zap.NewNop()) require.NoError(t, err) output, err := tart.Run(ctx, "echo \"this is a test\"")