String concatenation regression

[davecheney]

What version of Go are you using (go version)?

Go 1.11

Does this issue reproduce with the latest release?

Yes

What operating system and processor architecture are you using (go env)?

Darwin/amd64

What did you do?

package main

import (
	"bytes"
	"fmt"
	"net"
	"testing"
	"time"
)

// sink to ensure the compiler does not optimise away dead assignments.
var Result string

// fake up some values for request and client.
func setup(b *testing.B) (struct{ ID string }, net.Listener) {
	request := struct {
		ID string
	}{"9001"}
	client, err := net.Listen("tcp", ":0")
	if err != nil {
		b.Fatal(err)
	}
	return request, client
}

func BenchmarkConcatenate(b *testing.B) {
	request, client := setup(b)
	defer client.Close()

	b.ResetTimer()
	b.ReportAllocs()
	var r string
	for n := 0; n < b.N; n++ {
		// START1 OMIT
		s := request.ID
		s += " " + client.Addr().String()
		s += " " + time.Now().String()
		r = s
		// END1 OMIT
	}
	Result = r
}

func BenchmarkFprintf(b *testing.B) {
	request, client := setup(b)
	defer client.Close()

	b.ResetTimer()
	b.ReportAllocs()
	var r string
	for n := 0; n < b.N; n++ {
		// START2 OMIT
		var b bytes.Buffer
		fmt.Fprintf(&b, "%s %v %v", request.ID, client.Addr(), time.Now())
		r = b.String()
		// END2 OMIT
	}
	Result = r
}

func BenchmarkSprintf(b *testing.B) {
	request, client := setup(b)
	defer client.Close()

	b.ResetTimer()
	b.ReportAllocs()
	var r string
	for n := 0; n < b.N; n++ {
		// START3 OMIT
		r = fmt.Sprintf("%s %v %v", request.ID, client.Addr(), time.Now())
		// END3 OMIT
	}
	Result = r
}

func BenchmarkStrconv(b *testing.B) {
	request, client := setup(b)
	defer client.Close()

	b.ResetTimer()
	b.ReportAllocs()
	var r string
	for n := 0; n < b.N; n++ {
		// START4 OMIT
		b := make([]byte, 0, 40)
		b = append(b, request.ID...)
		b = append(b, ' ')
		b = append(b, client.Addr().String()...)
		b = append(b, ' ')
		b = time.Now().AppendFormat(b, "2006-01-02 15:04:05.999999999 -0700 MST")
		r = string(b)
		// END4 OMIT
	}
	Result = r
}

What did you expect to see?

Equal results between go 1.10 and go 1.11

What did you see instead?

Between a 6.88% and 15.63% regression across four different kinds of string concatenation.

% benchstat go1.10.txt  go1.11.txt
name           old time/op    new time/op    delta
Concatenate-8     810ns ± 2%     886ns ± 2%   +9.46%  (p=0.000 n=10+10)
Fprintf-8        1.39µs ± 1%    1.48µs ± 1%   +7.06%  (p=0.000 n=10+10)
Sprintf-8        1.20µs ± 0%    1.28µs ± 3%   +6.88%  (p=0.000 n=8+10)
Strconv-8         573ns ± 2%     662ns ± 1%  +15.63%  (p=0.000 n=10+9)

name           old alloc/op   new alloc/op   delta
Concatenate-8      272B ± 0%      272B ± 0%     ~     (p=0.087 n=10+10)
Fprintf-8          496B ± 0%      496B ± 0%     ~     (all equal)
Sprintf-8          304B ± 0%      304B ± 0%     ~     (all equal)
Strconv-8          165B ± 0%      165B ± 0%     ~     (all equal)

name           old allocs/op  new allocs/op  delta
Concatenate-8      10.0 ± 0%      10.0 ± 0%     ~     (all equal)
Fprintf-8          13.0 ± 0%      13.0 ± 0%     ~     (all equal)
Sprintf-8          11.0 ± 0%      11.0 ± 0%     ~     (all equal)
Strconv-8          5.00 ± 0%      5.00 ± 0%     ~     (all equal)

[martisch]

All the benchmarks call time.Now().String() and client.Addr().String() are we sure calling those (in parallel) did not get slower instead of the string concatenation?

If I replace those calls with package global variables then I get nearly equal benchmarks (within noise and maybe slightly faster for byte appends in Strconv):

name         old time/op    new time/op    delta
Concatenate     124ns ± 2%     126ns ± 0%  +1.43%  (p=0.001 n=9+8)
Fprintf         404ns ± 4%     411ns ± 2%    ~     (p=0.158 n=10+10)
Sprintf         329ns ± 2%     334ns ± 5%  +1.58%  (p=0.033 n=10+10)
Strconv        43.3ns ± 3%    41.8ns ± 1%  -3.56%  (p=0.000 n=9+10)

[davecheney]

Oh, excellent point, I'm sorry for the noise.