codec.(*simpleIoEncWriterWriter).WriteByte generating a lot of garbage

[2opremio]

After migrating the codecs of https://github.com/weaveworks/scope/ to github.com/ugorji/go I am looking at the garbage generated:

$ go tool pprof -alloc_objects ~/home-vagrant/scope/prog/scope /Users/fons/pprof/pprof.localhost:4041.alloc_objects.alloc_space.003.pb.gz
Entering interactive mode (type "help" for commands)
(pprof) top10 
18122071 of 30236315 total (59.93%)
Dropped 356 nodes (cum <= 151181)
Showing top 10 nodes out of 192 (cum >= 1331024)
      flat  flat%   sum%        cum   cum%
   3183403 10.53% 10.53%    3183403 10.53%  github.com/weaveworks/scope/vendor/github.com/mndrix/ps.setLowLevel
   3112981 10.30% 20.82%    3113858 10.30%  github.com/weaveworks/scope/vendor/github.com/ugorji/go/codec.(*simpleIoEncWriterWriter).WriteByte
   2763556  9.14% 29.96%    2763556  9.14%  github.com/weaveworks/scope/report.Metrics.Copy
   2064454  6.83% 36.79%    2064454  6.83%  github.com/weaveworks/scope/report.MakeNode
   1802043  5.96% 42.75%    1818743  6.02%  github.com/weaveworks/scope/vendor/github.com/ugorji/go/codec.(*simpleIoEncWriterWriter).WriteString
   1474570  4.88% 47.63%    2623837  8.68%  github.com/weaveworks/scope/report.Sets.Merge
   1026770  3.40% 51.02%    2632536  8.71%  github.com/weaveworks/scope/report.LatestMap.Set
    957579  3.17% 54.19%     957579  3.17%  reflect.unsafe_New
    884739  2.93% 57.12%    1549499  5.12%  github.com/weaveworks/scope/report.LatestMap.Merge
    851976  2.82% 59.93%    1331024  4.40%  github.com/weaveworks/scope/report.EdgeMetadatas.Merge
(pprof) list codec.*.WriteByte                         
Total: 30236315
ROUTINE ======================== github.com/weaveworks/scope/vendor/github.com/ugorji/go/codec.(*simpleIoEncWriterWriter).WriteByte in /go/src/github.com/weaveworks/scope/vendor/github.com/ugorji/go/codec/encode.go
   3112981    3113858 (flat, cum) 10.30% of Total
         .          .    145:
         .          .    146:func (o *simpleIoEncWriterWriter) WriteByte(c byte) (err error) {
         .          .    147:   if o.bw != nil {
         .          .    148:           return o.bw.WriteByte(c)
         .          .    149:   }
   3112981    3113858    150:   _, err = o.w.Write([]byte{c})
         .          .    151:   return
         .          .    152:}
         .          .    153:
         .          .    154:func (o *simpleIoEncWriterWriter) WriteString(s string) (n int, err error) {
         .          .    155:   if o.sw != nil {
(pprof) list codec.*.WriteString
Total: 30236315
ROUTINE ======================== github.com/weaveworks/scope/vendor/github.com/ugorji/go/codec.(*simpleIoEncWriterWriter).WriteString in /go/src/github.com/weaveworks/scope/vendor/github.com/ugorji/go/codec/encode.go
   1802043    1818743 (flat, cum)  6.02% of Total
         .          .    154:func (o *simpleIoEncWriterWriter) WriteString(s string) (n int, err error) {
         .          .    155:   if o.sw != nil {
         .          .    156:           return o.sw.WriteString(s)
         .          .    157:   }
         .          .    158:   // return o.w.Write([]byte(s))
   1802043    1818743    159:   return o.w.Write(bytesView(s))
         .          .    160:}
         .          .    161:
         .          .    162:func (o *simpleIoEncWriterWriter) Write(p []byte) (n int, err error) {
         .          .    163:   return o.w.Write(p)
         .          .    164:}
(pprof) 

(This comes from the Scope probe, weaveworks/scope#812 (comment) for the raw profile file and a complete graph)

It seems we could win a bit by optimizing codec.(*simpleIoEncWriterWriter).WriteByte() (and compiling with -tags unsafe). @ugorji Do you know what is causing bw to be nil? If that's not easily solvable, could you at least cache that slice?

Also, (although it has a lower impact for us) it may be worth optimizing codec.(*msgpackDecDriver).DecodeString():

go tool pprof -alloc_objects ~/home-vagrant/scope/prog/scope /Users/fons/pprof/pprof.localhost:4040.alloc_objects.alloc_space.001.pb.gz
Entering interactive mode (type "help" for commands)
(pprof) top10
135195241 of 176367619 total (76.66%)
Dropped 270 nodes (cum <= 881838)
Showing top 10 nodes out of 111 (cum >= 6147825)
      flat  flat%   sum%        cum   cum%
  32834520 18.62% 18.62%   32834520 18.62%  github.com/weaveworks/scope/vendor/github.com/mndrix/ps.(*list).Cons
  20647273 11.71% 30.32%   20647273 11.71%  github.com/weaveworks/scope/report.Metrics.Copy
  16450026  9.33% 39.65%   48334246 27.41%  github.com/weaveworks/scope/report.Metric.Merge
  15402247  8.73% 48.38%   15402247  8.73%  github.com/weaveworks/scope/vendor/github.com/mndrix/ps.setLowLevel
  14636992  8.30% 56.68%   14636992  8.30%  github.com/weaveworks/scope/report.MakeNode
  10969046  6.22% 62.90%   36690755 20.80%  github.com/weaveworks/scope/report.Nodes.Copy
   7319171  4.15% 67.05%    8174048  4.63%  github.com/weaveworks/scope/vendor/github.com/ugorji/go/codec.(*msgpackDecDriver).DecodeString
   5865541  3.33% 70.38%   14786964  8.38%  github.com/weaveworks/scope/report.Sets.Merge
   5712701  3.24% 73.62%    5712701  3.24%  reflect.unsafe_New
   5357724  3.04% 76.66%    6147825  3.49%  reflect.Value.SetMapIndex
(pprof) list codec.*.DecodeString
Total: 176367619
ROUTINE ======================== github.com/weaveworks/scope/vendor/github.com/ugorji/go/codec.(*msgpackDecDriver).DecodeString in /go/src/github.com/weaveworks/scope/vendor/github.com/ugorji/go/codec/msgpack.go
   7319171    8174048 (flat, cum)  4.63% of Total
         .          .    551:   }
         .          .    552:   return decByteSlice(d.r, clen, bs)
         .          .    553:}
         .          .    554:
         .          .    555:func (d *msgpackDecDriver) DecodeString() (s string) {
   7319171    8174048    556:   return string(d.DecodeBytes(d.b[:], true, true))
         .          .    557:}
         .          .    558:
         .          .    559:func (d *msgpackDecDriver) readNextBd() {
         .          .    560:   d.bd = d.r.readn1()
         .          .    561:   d.bdRead = true
(pprof) 

(This comes from the Scope app, see weaveworks/scope#854 (comment) for the raw profile file and a complete graph).

[ugorji]

Good idea per the WriteByte optimization. Will do. simpleIoEncWriterWriter is not scoped, so we can cache a 1-element byte array, and use it all the time when writing a byte.

We can't do anything for msgpack.DecodeString. We can't control who calls DecodeString, so doing a stringView at that point is not an option. Consequently, we have to do a conversion (which implicitly does an allocation and copy).

Fix coming in a few.

[ugorji]

BTW, bw is nil because the Writer passed to Encode in not a ByteWriter.

[2opremio]

Thanks!!!

On Sunday, February 21, 2016, Ugorji Nwoke notifications@github.com wrote:

Closed #143 #143 via 03b46f3
03b46f3
.

—
Reply to this email directly or view it on GitHub
#143 (comment).

[2opremio]

One final note regarding (*simpleIoEncWriterWriter) WriteString(). I have taken a closer look at the alloc_objects profile and most of the calls to (*simpleIoEncWriterWriter) WriteString() (if not all) are coming from types for which Selfers were generated with codecgen-u (see for instance (Node*).CodecEncodeSelf in the call graph below).

I know that (*simpleIoEncWriterWriter) WriteString() will stop generating garbage when compiling github.com/ugorji/go/codec with -tags unsafe, which makes sense for reflection-based encoding. However, wouldn't it make sense to create a specialized unsafe-version of WriteString() function so that the code generated by codecgen in unsafe mode can invoke it regardless of whether the codec was compiled with -tags unsafe or not?

go tool pprof -focus '.*WriteString.*' -alloc_objects -png pprof.localhost.4041.alloc_objects.alloc_space.003.pb.gz > probe.png

You can find the generated code for most (if not all) the types involved here at: https://gist.github.com/2opremio/0956c1e883b89eba71a9

[2opremio]

We can't do anything for msgpack.DecodeString. We can't control who calls DecodeString, so doing a stringView at that point is not an option. Consequently, we have to do a conversion (which implicitly does an allocation and copy).

I have also taken a deeper look at the Scope app alloc_objects graph, and most (if not all) the calls to msgpack.DecodeString come from Selfers generated by codecgen -u. Isn't it reasonable to provide a specialized unsafe-version of msgpack.DecodeString to be invoked in that case?

This case is particularly bad, since it won't even get fixed when compiling with -tags unsafe. Again, this isn't where our garbage-bottleneck lies but others may benefit from this optimization.

$ go tool pprof -png -alloc_objects -focus '.*DecodeString.*'  pprof.localhost.4040.alloc_objects.alloc_space.001.pb.gz > app.png

[ugorji]

Those calls are likely reading a value to set a struct field e.g. struct {S
string}. There's no magic workaround: you have to read the value as []byte,
and then copy that to a string and set it. We can only do unsafe when we
know that the string is intermittent, and within our control. E.g. if we
are are looking at the string so that we can do a switch/case match, or if
we are just passing it into a WriteString() method, etc.

On Sun, Feb 21, 2016 at 2:17 PM, Alfonso Acosta notifications@github.com
wrote:

We can't do anything for msgpack.DecodeString. We can't control who calls
DecodeString, so doing a stringView at that point is not an option.
Consequently, we have to do a conversion (which implicitly does an
allocation and copy).

I have also taken a deeper look at the Scope app alloc_objects graph, and
most (if not all) the calls to msgpack.DecodeString come from Selfers
generated by codecgen -u. Isn't it reasonable to provide a specialized
unsafe-version of msgpack.DecodeString ?

$ go tool pprof -png -alloc_objects -focus '.DecodeString.' pprof.localhost.4040.alloc_objects.alloc_space.001.pb.gz > app.png

[image: probe]
https://cloud.githubusercontent.com/assets/2362916/13204757/af43e74a-d8cf-11e5-84b6-d965c273214f.png

—
Reply to this email directly or view it on GitHub
#143 (comment).