Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

strings: QEncodeWord benchmark regression due to strings.Builder #25379

Closed
quasilyte opened this issue May 14, 2018 · 2 comments
Closed

strings: QEncodeWord benchmark regression due to strings.Builder #25379

quasilyte opened this issue May 14, 2018 · 2 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. release-blocker
Milestone

Comments

@quasilyte
Copy link
Contributor

quasilyte commented May 14, 2018

Compared with go1.10.2, tip shows performance regression in mime:

QEncodeWord-4   638ns ± 2%      787ns ± 1%    +23.28%  (p=0.008 n=5+5)

Change that affected it: CL102479/encodedword.go

sync.Pool+bytes.Buffer are replaced with strings.Builder.

I've changed strings.Builder to bytes.Buffer again, without using pool (and by the way, it was on different machine, so this issue is reproducible on both server and desktop hardware):

name           old time/op    new time/op    delta
QEncodeWord-8     481ns ±14%     599ns ±11%   +24.64%  (p=0.008 n=5+5)

name           old alloc/op   new alloc/op   delta
QEncodeWord-8      160B ± 0%      152B ± 0%    -5.00%  (p=0.008 n=5+5)

name           old allocs/op  new allocs/op  delta
QEncodeWord-8      2.00 ± 0%      5.00 ± 0%  +150.00%  (p=0.008 n=5+5)

The results are more noisy on my laptop, but the delta still stands.

cpuprofiles:

with bytes.Buffer

      flat  flat%   sum%        cum   cum%
    2090ms 21.05% 21.05%     2090ms 21.05%  bytes.(*Buffer).WriteByte
    1250ms 12.59% 33.64%     5080ms 51.16%  mime.WordEncoder.qEncode
    1230ms 12.39% 46.02%     3040ms 30.61%  mime.writeQString
    1130ms 11.38% 57.40%     2290ms 23.06%  runtime.mallocgc
     510ms  5.14% 62.54%      510ms  5.14%  runtime.memmove
     420ms  4.23% 66.77%      450ms  4.53%  strings.EqualFold
     410ms  4.13% 70.90%      950ms  9.57%  bytes.(*Buffer).WriteString
     400ms  4.03% 74.92%      400ms  4.03%  runtime.heapBitsSetType
     270ms  2.72% 77.64%      270ms  2.72%  unicode/utf8.DecodeRuneInString
     220ms  2.22% 79.86%      230ms  2.32%  runtime.scanobject

with strings.Builder

      flat  flat%   sum%        cum   cum%
    1560ms 13.03% 13.03%     5090ms 42.52%  strings.(*Builder).WriteByte
    1490ms 12.45% 25.48%     3460ms 28.91%  runtime.mallocgc
    1380ms 11.53% 37.01%     7070ms 59.06%  mime.WordEncoder.qEncode
     920ms  7.69% 44.70%     4880ms 40.77%  mime.writeQString
     880ms  7.35% 52.05%      880ms  7.35%  strings.(*Builder).copyCheck
     720ms  6.02% 58.06%     3530ms 29.49%  runtime.growslice
     550ms  4.59% 62.66%      550ms  4.59%  runtime.nextFreeFast (inline)
     450ms  3.76% 66.42%     1510ms 12.61%  strings.(*Builder).WriteString
     440ms  3.68% 70.09%      440ms  3.68%  strings.EqualFold
     380ms  3.17% 73.27%      380ms  3.17%  runtime.memmove

memprofiles:

with bytes.Buffer

ROUTINE ======================== mime.WordEncoder.encodeWord in $GOROOT/src/bytes/buffer.go
    1.15GB     1.15GB (flat, cum) 29.81% of Total
         .          .     61:func (b *Buffer) String() string {
         .          .     62:	if b == nil {
         .          .     63:		// Special case, useful in debugging.
         .          .     64:		return "<nil>"
         .          .     65:	}
    1.15GB     1.15GB     66:	return string(b.buf[b.off:])
         .          .     67:}
         .          .     68:
         .          .     69:// empty returns whether the unread portion of the buffer is empty.
         .          .     70:func (b *Buffer) empty() bool { return len(b.buf) <= b.off }
         .          .     71:
ROUTINE ======================== mime.WordEncoder.encodeWord in $GOROOT/src/mime/encodedword.go
    2.71GB     2.71GB (flat, cum) 70.19% of Total
         .          .     48:	return false
         .          .     49:}
         .          .     50:
         .          .     51:// encodeWord encodes a string into an encoded-word.
         .          .     52:func (e WordEncoder) encodeWord(charset, s string) string {
    2.71GB     2.71GB     53:	var buf bytes.Buffer
         .          .     54:
         .          .     55:	e.openWord(&buf, charset)
         .          .     56:	if e == BEncoding {
         .          .     57:		e.bEncode(&buf, charset, s)
         .          .     58:	} else {

with strings.Builder

      flat  flat%   sum%        cum   cum%
 2138.10MB 73.98% 73.98%  2138.10MB 73.98%  strings.(*Builder).WriteByte
  591.52MB 20.47% 94.45%  2890.12MB   100%  mime.WordEncoder.encodeWord
  160.50MB  5.55%   100%   160.50MB  5.55%  strings.(*Builder).WriteString

ROUTINE ======================== strings.(*Builder).WriteByte in $GOROOT/src/strings/builder.go
    2.09GB     2.09GB (flat, cum) 73.98% of Total
         .          .     87:
         .          .     88:// WriteByte appends the byte c to b's buffer.
         .          .     89:// The returned error is always nil.
         .          .     90:func (b *Builder) WriteByte(c byte) error {
         .          .     91:	b.copyCheck()
    2.09GB     2.09GB     92:	b.buf = append(b.buf, c)
         .          .     93:	return nil
         .          .     94:}
ROUTINE ======================== mime.WordEncoder.encodeWord in $GOROOT/src/mime/encodedword.go
  591.52MB     2.82GB (flat, cum)   100% of Total
         .          .     48:	return false
         .          .     49:}
         .          .     50:
         .          .     51:// encodeWord encodes a string into an encoded-word.
         .          .     52:func (e WordEncoder) encodeWord(charset, s string) string {
  591.52MB   591.52MB     53:	var buf strings.Builder
         .          .     54:
         .   457.51MB     55:	e.openWord(&buf, charset)
         .          .     56:	if e == BEncoding {
         .          .     57:		e.bEncode(&buf, charset, s)
         .          .     58:	} else {
         .     1.80GB     59:		e.qEncode(&buf, charset, s)
         .          .     60:	}
         .          .     61:	closeWord(&buf)
         .          .     62:
         .          .     63:	return buf.String()
         .          .     64:}
ROUTINE ======================== strings.(*Builder).WriteString in $GOROOT/src/strings/builder.go
  160.50MB   160.50MB (flat, cum)  5.55% of Total
         .          .    112:
         .          .    113:// WriteString appends the contents of s to b's buffer.
         .          .    114:// It returns the length of s and a nil error.
         .          .    115:func (b *Builder) WriteString(s string) (int, error) {
         .          .    116:	b.copyCheck()
  160.50MB   160.50MB    117:	b.buf = append(b.buf, s...)
         .          .    118:	return len(s), nil
         .          .    119:}

I haven't found any open strings.Builder performance issues.
My understanding is that strings.Builder is intended to be at least on par with bytes.Buffer, preferably even faster.

If this slowdown is expected and acceptable, this issue can be closed right away.

@ianlancetaylor ianlancetaylor changed the title mime: QEncodeWord benchmark regression strings: QEncodeWord benchmark regression due to strings.Builder May 14, 2018
@ianlancetaylor ianlancetaylor added NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. release-blocker labels May 14, 2018
@ianlancetaylor ianlancetaylor added this to the Go1.11 milestone May 14, 2018
@quasilyte
Copy link
Contributor Author

I have a fix; will send CL today.

@gopherbot
Copy link

Change https://golang.org/cl/113235 mentions this issue: mime: do a pre-allocation in encodeWord

@golang golang locked and limited conversation to collaborators May 15, 2019
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. release-blocker
Projects
None yet
Development

No branches or pull requests

3 participants