第 17 章

[Day 17] Profiling with memory

After #15 and #16, we can get flame graph below:

The runtime.gcDrain takes 25.14(13.9%) CPU time, it means that our service creating and destroying short life objects frequently.

Memory Profiling

We can get allocation and heap flame graph from localhost:6060/debug/pprof/allocs and localhost:6060/debug/pprof/heap after benchmarking.

Note: Use redis-benchmark -p 16379 -t SET -P 16 -n 10000000 -r 1000000 in this chapter.

Here’s the allocation flame graph:

Here’s the heap flame graphc:

The difference between “allocs” and “heap” in Go pprof:

allocs: Memory allocation history, including active and destroyed objects.
heap: Memory in current state, only active or haven’t collected by GC.

Because runtime.gcDrain takes a lot of time, we need to focus on “allocs” flame graph.

Use `bufio.(*Reader).ReadSlice()`

The resp.(*Reader).readLine() implementation:

func (r *Reader) readLine() ([]byte, error) {
	var buf bytes.Buffer

	for {
		data, err := r.rd.ReadBytes('\r')
		if err != nil {
			return nil, err
		}

		buf.Write(data)
		b, err := r.rd.ReadByte()
		if err != nil {
			return nil, err
		}
		if b == '\n' {
			return buf.Bytes()[:buf.Len()-1], nil
		}
		buf.WriteByte(b)
	}
}

It needs to glow var buf bytes.Buffer many times when reading. Refactor with r.rd.ReadSlice('\n') and reuse the buffer in bufio.(*Reader).

func (r *Reader) readLine() ([]byte, error) {
	var fragments []byte

	for {
		data, err := r.rd.ReadSlice('\n')
		if errors.Is(err, bufio.ErrBufferFull) {
			fragments = append(fragments, data...)
			continue
		}
		if err != nil {
			return nil, err
		}

		if len(data) == 1 && data[0] == '\n' && len(fragments) > 0 && fragments[len(fragments)-1] == '\r' {
			return fragments[:len(fragments)-1], nil
		}

		if len(data) >= 2 && data[len(data)-2] == '\r' {
			data = data[:len(data)-2]
			if len(fragments) == 0 {
				return data, nil
			}

			return append(fragments, data...), nil
		}

		fragments = append(fragments, data...)
	}
}

Result

Use go tool pprof -http=:8000 -base ./scripts/out_archive/1-original.allocs ./scripts/out_archive/2-readslice.allocs, we can compare the memory decreasing between changes.

Type casting with interface

Interface is an useful feature, it makes us write clean and readable code.

However, Go allocates memory on heap for interfaces because of casting.

In resp.ReadCommand():

rd.Read() returns resp.Value{} interface
arr, ok := v.(Array) cast it into resp.Array{} struct
cmd, ok := arr.data[0].(BulkString) casts arr.data[0] from resp.Value{} to resp.(BulkString)
args casts remaining elements from arr.data from resp.Value{} to resp.(BulkString)

func ReadCommand(rd *Reader) (*Command, error) {
	v, err := rd.Read()
	if err != nil {
		return nil, fmt.Errorf("%w: %w", ErrProtocol, err)
	}

	arr, ok := v.(Array)
	if !ok {
		return nil, fmt.Errorf("%w: expected array, got %T(%+v)", ErrProtocol, v, v)
	}
	if arr.null || len(arr.data) == 0 {
		return nil, fmt.Errorf("%w: empty array", ErrProtocol)
	}

	cmd, ok := arr.data[0].(BulkString)
	if !ok {
		return nil, fmt.Errorf("%w: command expected bulk string, got %T(%+v)", ErrProtocol, arr.data[0], arr.data[0])
	}

	args := make([]BulkString, 0, len(arr.data)-1)
	for i := range arr.data[1:] {
		arg, ok := arr.data[i+1].(BulkString)
		if !ok {
			return nil, fmt.Errorf("%w: argument [%d] expected bulk string, got %T(%+v)", ErrProtocol, i, arr.data[i+1], arr.data[i+1])
		}
		args = append(args, arg)
	}

	return &Command{
		raw:  v,
		aof:  arr.Clone(),
		cmd:  cmd,
		args: args,
	}, nil
}

I made a fast path of command parsing for resp.(*Reader).ReadCommand(), it expects an resp.(Array) with resp.(BulkString) directly.

func (r *Reader) ReadCommand() ([]BulkString, error) {
	t, err := r.rd.ReadByte()
	if err != nil {
		return nil, err
	}
	if t != MAGIC_ARRAY {
		return nil, fmt.Errorf("expected array, got %c", t)
	}

	sz, err := r.readInt()
	if err != nil {
		return nil, err
	}
	if sz < 0 {
		return nil, nil
	}

	values := make([]BulkString, sz)
	for i := range values {
		t, err := r.rd.ReadByte()
		if err != nil {
			return nil, err
		}
		if t != MAGIC_BULK_STRING {
			return nil, fmt.Errorf("element [%d] expected bulk string, got %c", i, t)
		}

		values[i], err = r.readBulkString()
		if err != nil {
			return nil, err
		}
	}

	return values, nil
}

func (r *Reader) Buffered() int {
	return r.rd.Buffered()
}

resp.ReadCommand() uses resp.(*Reader).ReadCommand() directly.

func ReadCommand(rd *Reader) (*Command, error) {
	values, err := rd.ReadCommand()
	if err != nil {
		return nil, fmt.Errorf("%w: %w", ErrProtocol, err)
	}
	if len(values) == 0 {
		return nil, fmt.Errorf("%w: empty array", ErrProtocol)
	}

	return &Command{
		raw:  values,
		aof:  slices.Clone(values),
		cmd:  values[0],
		args: values[1:],
	}, nil
}

Result

AOF Copy-on-Write

resp.(*Commands).aof is a copy of resp.(*Commands).raw, because command could be updated when writing to AOF (SET ... EX ... is updated to SET ... PXAT ...), even if AOF feature disabled.

As you know, resp.(*Commands).UpdateAOF() and resp.(*Commands).MarshalAOF() are only invoked when AOF feature enabled, we can initialize resp.(*Commands).aof in these recievers instead of initializing in resp.ReadCommand()

func (cmd *Command) UpdateAOF(i int, v BulkString) {
	if cmd.aof == nil {
		cmd.aof = slices.Clone(cmd.raw)
	}

	if i < len(cmd.aof) {
		cmd.aof[i] = v
	} else {
		cmd.aof = append(cmd.aof, v)
	}
}

func (cmd *Command) MarshalAOF() []byte {
	if cmd.aof == nil {
		return marshalCommand(cmd.raw)
	}
	return marshalCommand(cmd.aof)
}

Result

Refactor `resp.(*Commands)` fields

There’s definition of resp.(*Commands):

type Command struct {
	raw  []BulkString
	aof  []BulkString
	cmd  BulkString
	args []BulkString
}

After resp.ReadCommand() refactor, cmd and args fields are unnecessary, we can remove it safely.

type Command struct {
	raw  []BulkString
	aof  []BulkString
-	cmd  BulkString
-	args []BulkString
}

func (cmd *Command) Command() string {
	return strings.ToUpper(string(cmd.raw[0].data))
}

func (cmd *Command) Args() []BulkString {
	return cmd.raw[1:]
}

Result

Shared Buffer

Most of resp.(BulkString) are short, but we need to buf := make([]byte, sz) every time before reading.

func (r *Reader) readBulkString() (BulkString, error) {
	sz, err := r.readInt()
	if err != nil {
		return BulkString{}, err
	}
	if sz < 0 { // Ref: https://redis.io/docs/latest/develop/reference/protocol-spec/#null-bulk-strings
		return BulkString{null: true}, nil
	}

	buf := make([]byte, sz)
	if _, err := io.ReadFull(r.rd, buf); err != nil {
		return BulkString{}, err
	}

	// Drop tailing "\r\n" from reader.
	if cr, err := r.rd.ReadByte(); err != nil || cr != '\r' {
		return BulkString{}, errors.New("unexpected sentinel")
	}
	if nl, err := r.rd.ReadByte(); err != nil || nl != '\n' {
		return BulkString{}, errors.New("unexpected sentinel")
	}

	return BulkString{data: buf}, nil
}

We can define a shared []byte in resp.(*Reader) and reuse it.

type Reader struct {
	rd       *bufio.Reader
+	bytesbuf [1 << 12]byte
}

func (r *Reader) readBulkString() (BulkString, error) {
	sz, err := r.readInt()
	if err != nil {
		return BulkString{}, err
	}
	if sz < 0 { // Ref: https://redis.io/docs/latest/develop/reference/protocol-spec/#null-bulk-strings
		return BulkString{null: true}, nil
	}

	var buf []byte
	if sz <= len(r.bytesbuf) {
		buf = r.bytesbuf[:sz:sz]
	} else {
		buf = make([]byte, sz)
	}
	if _, err := io.ReadFull(r.rd, buf); err != nil {
		return BulkString{}, err
	}

	// Drop tailing "\r\n" from reader.
	if cr, err := r.rd.ReadByte(); err != nil || cr != '\r' {
		return BulkString{}, errors.New("unexpected sentinel")
	}
	if nl, err := r.rd.ReadByte(); err != nil || nl != '\n' {
		return BulkString{}, errors.New("unexpected sentinel")
	}

	return BulkString{data: string(buf)}, nil
}

We defined a bytesbuf with 4096 byte, and reuse it between requests in same connection.

Because the resp.(BulkString).data referenced to bytesbuf, it covered by other requests and get unexpected data.

We can update resp.(BulkString).data data type from []byte to string, and make a string copy when creating resp.(BulkString).

About `valuebuf`

We can make a valuebuf in resp.(*Reader) as a shared buffer likes bytesbuf for resp.(*Reader).ReadCommand()

type Reader struct {
	rd       *bufio.Reader
+	valuebuf [8]BulkString
	bytesbuf [1 << 12]byte
}

func (r *Reader) ReadCommand() ([]BulkString, error) {
	t, err := r.rd.ReadByte()
	if err != nil {
		return nil, err
	}
	if t != MAGIC_ARRAY {
		return nil, fmt.Errorf("expected array, got %c", t)
	}

	sz, err := r.readInt()
	if err != nil {
		return nil, err
	}
	if sz < 0 {
		return nil, nil
	}

	var values []BulkString
	if sz <= len(r.valuebuf) {
		clear(r.valuebuf[:])
		values = r.valuebuf[:sz:sz]
	} else {
		values = make([]BulkString, sz)
	}
	for i := range values {
		t, err := r.rd.ReadByte()
		if err != nil {
			return nil, err
		}
		if t != MAGIC_BULK_STRING {
			return nil, fmt.Errorf("element [%d] expected bulk string, got %c", i, t)
		}

		values[i], err = r.readBulkString()
		if err != nil {
			return nil, err
		}
	}

	return values, nil
}

There’s core changes about using valuebuf: use r.valuebuf if sz <= 8, or make([]BulkString, sz)

	var values []BulkString
	if sz <= len(r.valuebuf) {
		clear(r.valuebuf[:])
		values = r.valuebuf[:sz:sz]
	} else {
		values = make([]BulkString, sz)
	}

It’s important to clear(r.valuebuf[:] before assigning, the r.valuebuf could remains previous data and costs a lot if there’s a long string.

Note: resp.(*Reader).ReadCommand() could return valuebuf and it is assigned to resp.(*Command).raw and take its ownership. It’s ok in this case because commands are synchronization in command pipeline in this case, but it risks when sharing.

Result

Something else

OK response

It responses “+OK\r\n” when set successfully, it makes a new resp.SimpleString{} every time.

	return resp.SimpleString("OK"), nil

Use a defined variable resp.OKValue makes it better.

var OKValue = ok{}

type ok struct{}

func (ok) Marshal() []byte {
	return []byte("+OK\r\n")
}

Debug Logging

The debugging logging creates a slog.Any("error", err) and takes CPU time and allocs object. Remove it (or disable it).

Conclusion

I tried to benchmark Redis, Olivine #14 and after profiling by parameters below:

$ redis-benchmark -t SET -P 16 -n 10000000 -r 1000000

Environment:

Macbook Pro 2023 14”
CPU: Apple M2 Pro
RAM: 32GB
SSD: 512GB

Result:

Redis 8.8: 1090512.50 req/s
Olivine #14: 70773.91 req/s
Olivine profiled: 1397038.25 req/s

The throughput is up to 20x, even more than official redis server.

Memory Profiling

Use bufio.(*Reader).ReadSlice()

Result

Type casting with interface

Result

AOF Copy-on-Write

Result

Refactor resp.(*Commands) fields

Result

Shared Buffer

About valuebuf

Result

Something else

OK response

Debug Logging

Conclusion

Use `bufio.(*Reader).ReadSlice()`

Refactor `resp.(*Commands)` fields

About `valuebuf`