log: Reuse encoders and buffers for Logfmt logger #253
Conversation
|
Thanks! After a quick read this looks nice. I'll take a careful look soon. |
| if err != nil { | ||
| // Code copied from logfmt.MarshalKeyvals and modified | ||
| // to reuse encoders and buffers with sync.Pool and | ||
| // call EndRecord |
There was a problem hiding this comment.
@ChrisHines Do you think it would make sense to have a MarshalKeyvalsTo (name for debate) in the logfmt package that takes an *Encoder instead of allocating a new one? This way MarshalKeyvals could be implemented by calling MarshalKeyvalsTo with a bytes.Buffer and we could avoid having to duplicate the code here.
Something like this
func MarshalKeyvalsTo(enc *Encoder, keyvals ...interface{}) error
There was a problem hiding this comment.
Yes, although I think adding a method to logfmt.Encoder makes more sense.
func (enc *Encoder) EncodeKeyvals(keyvals ...interface{}) errorSee: go-logfmt/logfmt@a0ff333.
|
@nuss-justin: Please update for the new Also note that I pushed another speed improvement to the logfmt package earlier. See: go-logfmt/logfmt@a5fe813. |
|
Updated commit to use the new EncodeKeyvals method on *logfmt.Encoder. Also updated the benchmarks. |
| // only one call to l.w.Write() for each call to Log. We call Write ourself | ||
| // with buf.Bytes() instead of using buf.WriteTo(l.w) as WriteTo can call | ||
| // Write multiple times. | ||
| if _, err := l.w.Write(enc.buf.Bytes()); err != nil { |
There was a problem hiding this comment.
The last sentence of this comment is incorrect. Please remove.
The current implementation for bytes.Buffer.WriteTo will only make one call to Write. We use buf.Bytes in favor of buf.WriteTo because buf.Bytes is faster. buf.WriteTo updates the read position of buf based on the number of bytes written, while buf.Bytes does not. Since we discard unread data in buf after returning from this method, we don't need to pay the overhead of updating its read position.
|
I'm surprised your new CPU benchmark shows no improvement with the new code. Is that right? On my machine (go1.6.2 windows/amd64) I get: But that is good news. A 10% improvement is nice. When combined with the recent improvement in the logfmt package the total improvement is very nice: |
This uses sync.Pool to avoid always allocating new encoders and buffers. Reduces the number of allocations percall to Log by 2, if a value exists in the pool.
|
@ChrisHines Removed the last sentence and updated my benchmarks again. Also added results for current Go Tip. On my machine there's no change in time/op for 1.6.2. |
|
@nuss-justin Thanks. Good work. LGTM. |
|
@ax-nathan I haven't tagged a new release of go-logfmt/logfmt yet, that could be why glide isn't pulling it in for you. Let me know. I will tag a release when I get a chance (within 24h). |
|
This is the workaround for the bug in Good now. Thanks again! |
log: Reuse encoders and buffers for Logfmt logger
This uses sync.Pool to avoid always allocating new encoders and buffers.
Reduces the number of allocations percall to Log by 2, if a value exists
in the pool.
Benchstat (Go 1.6.2, 5 runs each):
Same for Go TIp (devel +0b6e5e3):
Command:
go test -bench Logfmt -benchmem -count 5Tested on a linux/amd64