Pavan ManishFeed

The protobuf encoder was a third of my service CPU

10 min read

A Go gRPC service spent 36% of its time writing map entries into protobuf buffers. Generated marshal methods cut that to 5% and 72,002 allocations to 1, and the bytes on the wire did not change.

A candidate-generation service I run answers gRPC requests with up to 2,000 candidates. Each candidate is an id and a map of six metadata strings, and the response is about 540 KB.

Cloud Profiler said 36.09% of that service’s CPU was inside grpc.encode. Not candidate search, not data fetches, not ranking. A third of the machine was writing bytes.

7.5×faster to encode
3.5×faster to decode
72,002 → 1allocations per response
0 bytesdifferent on the wire

I replaced the default codec with generated marshal methods from vtprotobuf. Encoding went from 2.296 ms to 0.306 ms on the same response, allocations from 72,002 to 1. The wire is untouched.

The rest is the why, and what it is worth.

Where the CPU went

The service runs with Cloud Profiler’s agent: ten sampled seconds a minute, plus an allocation profile. One day gave 604 CPU profiles and I merged 302, so the shares below are that day’s traffic mix rather than one busy minute.

the profile, merged
Two pprof tables. The first lists the service's CPU by cumulative share: grpc.encode at 36.09%, with runtime.mallocgc at 22.97% and the protobuf appendMap function at 20.16% beneath it. The second counts allocations by object, and shows reflect.unsafe_New at 63.06% and reflect.copyVal at 56.77%.
Cloud Profiler on the service, one day, merged and read with go tool pprof -top -cum. The share of CPU under grpc.encode is what started this. The lower panel counts objects rather than bytes, and in that count the encoder and the garbage collector behind it are most of the service.

I read them with go tool pprof -top -cum and took cumulative shares, which answer “how much of the service ran somewhere under this frame”. Shares overlap on purpose: grpc.encode is 36.09% and runtime.mallocgc is 22.97% because most of that allocation happens inside the encoder.

frame share of CPU
grpc.encode, the whole encode path 36.09%
runtime.mallocgc, allocating the buffers 22.97%
proto.MarshalOptions.MarshalAppend 21.72%
internal/impl.appendMap, writing map entries 20.16%
internal/impl.sizeMap, sizing them first 12.28%
runtime.gcBgMarkWorker and runtime.bgsweep 14.19%
internal/impl.appendMapItem, sizing each entry again as it writes it 10.43%
the encode path, stacked
a band sits inside its caller; width is the frame's share of all samplesgoogle.golang.org/grpc.(*Server).processUnaryRPC · 71.31% of all samplesgoogle.golang.org/grpc.encode · 36.09% of all samplesgoogle.golang.org/protobuf/proto.MarshalOptions.Size · 13.12% of all samplesgoogle.golang.org/protobuf/proto.MarshalOptions.MarshalAppend · 21.72% of all samplesgoogle.golang.org/protobuf/internal/impl.appendMap · 20.16% of all samplesgoogle.golang.org/protobuf/internal/impl.appendMapItem · 10.43% of all samples9.73% of all samples1.56% of all samples1.25% of all samples35.22% of all samples28.69% of all samplesprocessUnaryRPC 71.31%grpc.encode 36.09%proto.Sizewalk 1MarshalAppend 21.72%walks 2 and 3appendMap 20.16%appendMapItemother work in the requesteverything else in the profile302 of the day's 604 hourly profiles mergedgrey is time the drawing does not split

grpc.encode50.6% of its caller

The whole encode path: gRPC asks for a size, then for the bytes.

Each band sits inside the frame that called it, so a child's width reads against its parent's: grpc.encode is 36.09% of the merged profile inside a request path at 71.31%. Inside the encoder, proto.Size sizes the message in one walk at 13.12%, and MarshalAppend sizes it again and writes it at 21.72%, down through appendMap at 20.16% to appendMapItem at 10.43%. Grey bands are time the drawing does not split further. Select a frame and the line under the chart names it. The widths are the cumulative shares of go tool pprof -top -cum, over 302 of the day's 604 hourly profiles.

The allocation profile pins the rest. Of every object that service allocated that day, 56.67% came from inside the encoder, and 63.06% from reflect.unsafe_New, the allocator reflect’s map iterator boxes keys and values through. 90.03% of its callers are reflect.copyVal, the iterator itself.

what writing one response costs
one 2,000-candidate response, drawn to scalethe response, on the wire540,934 Bto write it, protobuf-go1,175,041 B72,002 allocations, 2.17 times the response, every byte of it garbageto write it, generated code283 B1 allocation, gRPC's wrapper around the pooled bufferone response
One response, and what each codec spends to write it. The default path allocates 1,175,041 bytes to produce a 540,934-byte response, 2.17 times the bytes that leave, and every one of them is garbage the collector walks later. The generated path allocates 283 bytes, a single object, for the whole response. All three bars share a scale, and the third is drawn at its true width: a hairline.

The cost is per map entry

Each candidate carries a map<string, string> of six keys: a relevance score, a cursor, a catalog id, a product id, a source tag, a rank. 2,000 candidates hold 12,000 entries, and the entry count sets the cost, not the byte count.

In the wire format an entry is a small nested message: a tag, a length, then the key and value, each with their own. One relevance_score entry:

bytes meaning
12 field 2, the map
1c the entry is 28 bytes long
0a 0f and 15 bytes key: "relevance_score"
12 09 and 9 bytes value: "0.6509505"

The awkward byte is 1c. The entry’s length precedes the bytes it describes, so a left-to-right writer has to know it before writing the key. Same one level up, where a candidate’s length precedes its id and map.

So an encoder sizes everything in one pass and remembers the sizes, or writes the buffer from the end and derives each length from what it has already written. Protobuf-go takes the first road. Generated code takes the second.

one entry, 30 bytes, written two ways

One metadata entry written two ways. The reflective codec measures every entry twice before writing anything, then writes front to back and allocates six objects per entry. The generated codec measures the message once, then writes from the end of the buffer toward the start, so every length is known from the bytes already written. Both end on the same 30 bytes.

protobuf-go · reflectivewalk 1 · sizes every entry for the buffer pool0 of 6 allocations
vtprotobuf · generatedwalk 1 · a range loop over the real fields, no reflect0 per entry
The same entry written by both codecs, one write at a time. The reflective encoder cannot write an entry's length before it has measured the entry, so it walks the whole response twice before writing a single byte, and every walk boxes each key and value. The generated encoder writes from the end: by the time it writes a length, the bytes that length describes are already in the buffer. Press Step to move one write at a time.

Three walks and 72,002 allocations

Protobuf-go has no code written for this message type. The .pb.go file carries the struct and a descriptor, and at startup the descriptor becomes a table of field offsets with a size or write function per field.

One reflective engine serves every message type in the process, which is what keeps generated files small and dynamic messages, extensions and unknown fields working. That engine walks the candidate list three times for one response.

the walks over one response
protobuf-goone reflective engine, generated files stay smallwalk 1 · proto.Size, for the pooled buffer+24,000walk 2 · size again inside MarshalAppend+24,000walk 3 · write, front to back+24,00072,002 allocations1.18 MB of garbagevtprotobufgenerated code, one method per messagewalk 1 · SizeVT, a range loop, no reflect+0walk 2 · write backwards from the end+01 allocation283 Bmap entries walked per response: 12,000 · each walk boxes every key and valuesame bytes out, 7.5x faster to encode
The same 2,000-candidate response under both encoders. A dot is one walk over the candidate list, and the count beside each walk is what that walk allocates. The default codec sizes the message three times, once for gRPC's buffer pool and twice inside its own marshal, and every walk boxes each of the 12,000 map entries twice. The generated codec sizes it once with a plain loop and writes it backwards from the end of the buffer, so the length of each entry is known as it is written and nothing has to be sized twice. Both write the same bytes.

Walk 1 is gRPC’s, not the library’s. codecV2.Marshal calls proto.Size for the pooled buffer. The engine visits every candidate, calls sizeMap per map, and caches each candidate’s size in a hidden struct field.

Walk 2 exists because that size is not passed down. MarshalAppend sizes the message again before writing it, and a map entry has nowhere to cache its length, so entries are sized here too.

Walk 3 writes and sizes again. appendMapItem computes the entry’s length, writes it, writes the key and the value, then checks what it wrote matches. It also validates UTF-8.

Every walk iterates the map through reflect.Value.MapRange(), and every iter.Key() and iter.Value() boxes a string header onto the heap. Two allocations per entry, per walk: 12,000 entries, three walks, 72,002 allocations and 1,175,041 bytes of garbage for one response. Sizing is cheap. The reflective map iteration is not.

Write it backwards

vtprotobuf is a protoc plugin that writes one Go method per message beside the .pb.go file. The methods are loops over the real fields: no reflection, no per-entry boxing, no second size pass.

for k := range m.MetaData {              // generated, and a plain range over the real map
	v := m.MetaData[k]
	baseI := i
	i -= len(v)
	copy(dAtA[i:], v)                  // value bytes
	i = protohelpers.EncodeVarint(dAtA, i, uint64(len(v)))
	i--
	dAtA[i] = 0x12                     // value tag
	i -= len(k)
	copy(dAtA[i:], k)                  // key bytes
	i = protohelpers.EncodeVarint(dAtA, i, uint64(len(k)))
	i--
	dAtA[i] = 0xa                      // key tag
	i = protohelpers.EncodeVarint(dAtA, i, uint64(baseI-i)) // the entry's length: what was just written
	i--
	dAtA[i] = 0x12                     // the map's tag
}

The generated code writes from the end toward the start. By the time it writes an entry’s length, every byte that length describes is already in the buffer, so the length is baseI - i, a subtraction instead of another traversal. Fields go last to first, so the bytes land in the order a left-to-right encoder produces.

The buffer comes out of gRPC’s pool at exactly the size SizeVT reported, and the pool reuses it between responses. One allocation per response is left: gRPC’s wrapper around the pooled buffer, 283 bytes against 1.18 MB.

The codec decides per message, not per service. Messages with generated methods take the fast path. Everything else falls through to the codec that was replaced, so other proto files in the process and the service’s own calls to its dependencies keep the encoding they had.

How much faster

Both codecs through gRPC’s encoding.CodecV2 interface, four response sizes, five runs each, on an Apple M4 Pro with Go 1.24.4. The explorer draws every run; the line is the median.

the sweep, all five runs
  • protobuf-go
  • vtprotobuf
median encode, ms, log scale0.010.11101005002,0005,000candidates, log scale 100 · protobuf-go · 0.118 ms 500 · protobuf-go · 0.579 ms 2,000 · protobuf-go · 2.296 ms 5,000 · protobuf-go · 5.742 ms 100 · vtprotobuf · 0.016 ms 500 · vtprotobuf · 0.079 ms 2,000 · vtprotobuf · 0.306 ms 5,000 · vtprotobuf · 0.751 ms median decode, ms, log scale0.010.11101005002,0005,000candidates, log scale 100 · protobuf-go · 0.089 ms 500 · protobuf-go · 0.438 ms 2,000 · protobuf-go · 1.765 ms 5,000 · protobuf-go · 4.428 ms 100 · vtprotobuf · 0.025 ms 500 · vtprotobuf · 0.121 ms 2,000 · vtprotobuf · 0.498 ms 5,000 · vtprotobuf · 1.256 ms allocations per encode, log scale1101001k10k100k1M1005002,0005,000candidates, log scale 100 · protobuf-go · 3,601 allocations 500 · protobuf-go · 18,001 allocations 2,000 · protobuf-go · 72,002 allocations 5,000 · protobuf-go · 180,003 allocations 100 · vtprotobuf · 1 allocations 500 · vtprotobuf · 1 allocations 2,000 · vtprotobuf · 1 allocations 5,000 · vtprotobuf · 1 allocations

2,000 candidates7.5× faster

protobuf-go · 2.296 ms median · 5 runs 2.290–2.299 msvtprotobuf · 0.306 ms median · 5 runs 0.303–0.315 ms

every run · protobuf-go 2.296 2.291 2.290 2.299 2.296 · vtprotobuf 0.315 0.306 0.303 0.307 0.304

Both codecs through gRPC's codec interface, at four response sizes, five runs each. The dots are the five runs and the line runs through their medians, so the gap between the lines is the speedup at every size: about 7.5× to encode and 3.5× to decode. The lines stay parallel because the saving is per map entry, and entries scale with candidates. Pick a metric, then a size, and the readout gives that column's numbers.

Encoding is 7.5x faster and decoding 3.5x, constant across sizes because the saving is per map entry and entries scale with candidates.

Encode gains more because the generated encoder removes a whole pass and every allocation in it, while both decoders still allocate the key and value strings, which Go strings own. Decode’s floor is 28,018 allocations at 2,000 candidates; only a typed schema removes them.

the raw benchmark output
A benchmark run listing encoded size, encode and decode times, allocated bytes and allocation counts for 100, 500, 2,000 and 5,000 candidates, under the default codec and the generated one.
One run of the size sweep through gRPC's codec interface, with the encoded size printed for each codec and size. The medians of the five repeats are in the explorer above, and the capture beside this post has all of them. Both codecs print the same size at every candidate count.

The bytes on the wire do not change

Both encoders write the wire format, so the output is the same message. Three checks:

check result
Encoded length at 100, 500, 2,000 and 5,000 candidates, both codecs same number at every size: 26,933, 134,933, 540,934, 1,353,934 bytes
Messages encoded by one codec and decoded by the other, compared with proto.Equal: empty, one candidate, 2,000 candidates, a request with a field that has no generated methods, and a candidate with no metadata equal in every case, in both directions
A real gRPC call with the generated codec on the server only, the client only, and both request and response equal in all three

The second is the one that matters for a live service. Go iterates maps in a random order, so two encodes of the same response differ in byte order with the same library. What has to hold is that the parsed message is the same.

Two behaviours differ, neither of them wire format.

  • A string field with invalid UTF-8 passes through the generated codec. Protobuf-go rejects it on encode and on decode, with string field contains invalid UTF-8. The generated codec copies the bytes and says nothing. Calls that fail today succeed, and no call that succeeds today starts failing.
  • Decoding into a message that already has data merges instead of clearing. gRPC always decodes into a fresh message, so this cannot happen in production, and a test pins that.

Turning it on

gRPC keeps one codec registry per process, and every RPC and client call looks up the codec named proto. At startup the service calls a RegisterGRPCCodec() that reads one config key. vtproto registers the new codec under that name; any other value, or none, keeps the default. The active codec is logged, because a process-wide swap nobody can see is a bad thing to ship.

Two properties made this a config change instead of a migration.

  • It is opt-in per process. The codec is registered at startup and never changes at runtime, so turning it on is a config change and a restart, and turning it off is the same.
  • It is invisible to the schema. No .proto file changes, no generated message changes, and the descriptor the service serves stays the same.

What it is worth

The saving is not one number. In the workload where the response is most of the job, 40.05% of CPU sits in the encoder and the codec gives back 38.4% of it. Where the CPU goes into similarity work and feature decoding, the encoder sits at the edge of the response and the saving is 2.8%.

Across the workloads that serve this shape, that is 65.8 of the 668.8 cores that serve it each day. The core totals come from Prometheus, and the profile shares above are what put a saving on them.

The busiest caller saves 37 of its own cores. It spends 11.06% of its CPU in gRPC’s proto unmarshal, and 99.51% of that time arrives through the client’s receive path, where a downstream response lands. The generated decoder removes 37 of the 469 cores it uses. That is a change in the caller’s own repository, made when that team wants it, because the wire format does not move.

What I got wrong

  • Generating from the upstream proto repository produced code for a schema the service does not run. The committed .pb.go files carry fields no branch of that repository has. The fix was to generate from the descriptors those files register at startup, which is now a checked-in script: dump the descriptors, run the plugin, git diff comes back empty.
  • The decoder will not approach the encoder’s speedup. Both decoders must allocate a string per key and per value, so the generated decoder removes the reflection and map machinery around those allocations, not the allocations.

What this does not show

  • One service, one message shape. Every number here is a metadata-heavy response: many small string fields, a few thousand per message. A message of a few scalars gains far less, because the engine’s cost per field is small and its cost per map entry is not.
  • No schema change, so no ceiling on decode. Typed metadata fields would remove the key and value strings, and that is a proto change with a much longer tail.
  • No comparison with other generators. gogoproto and the newer codegen avoid the same reflection. I benchmarked one replacement, not the best one.
  • One normal day. Traffic mix and load move, and the profile shares of that day are what the saving arithmetic rests on.

The data

The captures are committed beside this post, and the tests recompute every number in it from them.

How it was measured
part what I did
Benchmarks go test -bench -benchmem -count=5 through encoding.CodecV2, medians of the five runs, on an Apple M4 Pro with Go 1.24.4
Benchmark message 2,000 candidates, each an id and 6 metadata strings shaped like production output, 540,934 bytes on the wire
Libraries google.golang.org/protobuf v1.36.6, google.golang.org/grpc v1.73.0, github.com/planetscale/vtprotobuf v0.6.1-0.20240319094008-0393e58bdf10
Profiles Google Cloud Profiler, 302 of 604 hourly CPU profiles for one day merged, plus that day’s heap allocation profiles
Profile read go tool pprof -top -cum, cumulative shares; encode is everything under grpc.encode, decode is the proto unmarshal frames, GC is runtime.gcBgMarkWorker plus runtime.bgsweep
Cores Prometheus container_cpu_usage_seconds_total, 5-minute rates summed over the workloads that serve this shape, for one day
Caller side Each caller’s own merged CPU profile, decode taken as the cumulative share under the proto unmarshal frame, and the part of it that arrives through the client receive path reported separately
Parity Wire sizes compared at every benchmarked size, cross-decoding compared with proto.Equal, and a gRPC call with the new codec on one side only, all from the codec’s own test suite
The medians, every size
candidates on the wire encode, default encode, generated decode, default decode, generated
100 26,933 B 0.118 ms 0.016 ms 0.089 ms 0.025 ms
500 134,933 B 0.579 ms 0.079 ms 0.438 ms 0.121 ms
2,000 540,934 B 2.296 ms 0.306 ms 1.765 ms 0.498 ms
5,000 1,353,934 B 5.742 ms 0.751 ms 4.428 ms 1.256 ms
Allocations per response
candidates encode, default encode, generated decode, default decode, generated
100 3,601 1 3,613 1,413
500 18,001 1 18,015 7,015
2,000 72,002 1 72,018 28,018
5,000 180,003 1 180,022 70,021

Allocations per operation, as reported by the benchmark harness. Encoding’s count is 36 per candidate plus two: six keys, two allocations per key per walk, three walks.