Sub-millisecond GC pauses... if you don't allocate

benchmark.txt

$ time GODEBUG=gctrace=1 ./go-mem-stress
gc 1 @0.003s 2%: 0.045+5.7+0.032 ms clock, 0.13+0/0.68/5.2+0.098 ms cpu, 4->4->0 MB, 5 MB goal, 4 P
gc 2 @0.010s 2%: 0.009+11+0.041 ms clock, 0.036+0/0.75/10+0.16 ms cpu, 5->5->1 MB, 6 MB goal, 4 P
gc 3 @0.022s 3%: 0.004+12+0.031 ms clock, 0.018+0.021/3.0/9.6+0.12 ms cpu, 4->4->2 MB, 5 MB goal, 4 P
gc 4 @0.035s 4%: 0.010+19+0.060 ms clock, 0.041+0/3.8/16+0.24 ms cpu, 5->5->2 MB, 6 MB goal, 4 P
gc 5 @0.056s 3%: 0.005+16+0.023 ms clock, 0.020+0/1.3/15+0.092 ms cpu, 6->6->3 MB, 7 MB goal, 4 P
gc 6 @0.075s 3%: 0.007+19+0.042 ms clock, 0.029+0/3.0/16+0.16 ms cpu, 8->8->4 MB, 9 MB goal, 4 P
gc 7 @0.095s 5%: 2.6+25+0.025 ms clock, 10+0.094/3.2/0.043+0.10 ms cpu, 10->10->10 MB, 11 MB goal, 4 P
gc 8 @0.127s 4%: 0.009+45+0.046 ms clock, 0.037+0/5.1/40+0.18 ms cpu, 16->17->6 MB, 20 MB goal, 4 P
gc 9 @0.175s 4%: 0.008+41+0.071 ms clock, 0.032+0/2.9/38+0.28 ms cpu, 15->15->8 MB, 16 MB goal, 4 P
gc 10 @0.220s 3%: 0.007+52+0.028 ms clock, 0.029+0/3.6/48+0.11 ms cpu, 19->19->10 MB, 20 MB goal, 4 P
gc 11 @0.278s 4%: 2.2+43+0.023 ms clock, 9.1+0.052/7.7/0.031+0.092 ms cpu, 24->24->24 MB, 25 MB goal, 4 P
gc 12 @0.335s 4%: 2.8+65+0.018 ms clock, 11+0.085/8.5/6.5+0.073 ms cpu, 41->41->30 MB, 48 MB goal, 4 P
gc 13 @0.412s 9%: 6.2+91+0.028 ms clock, 25+84/7.5/0.033+0.11 ms cpu, 51->51->21 MB, 61 MB goal, 4 P
gc 14 @0.514s 8%: 3.0+93+0.022 ms clock, 12+0.054/13/4.2+0.090 ms cpu, 47->47->47 MB, 48 MB goal, 4 P
gc 15 @0.624s 9%: 9.4+115+0.019 ms clock, 37+0.046/16/9.6+0.078 ms cpu, 80->80->59 MB, 95 MB goal, 4 P
gc 16 @0.760s 7%: 0.005+172+0.070 ms clock, 0.023+0/13/158+0.28 ms cpu, 101->101->41 MB, 119 MB goal, 4 P
gc 17 @0.945s 7%: 5.5+173+0.027 ms clock, 22+0.054/27/15+0.10 ms cpu, 93->93->93 MB, 94 MB goal, 4 P
gc 18 @1.141s 12%: 29+250+0.026 ms clock, 117+235/15/19+0.10 ms cpu, 157->157->64 MB, 186 MB goal, 4 P
gc 19 @1.437s 10%: 2.4+279+0.021 ms clock, 9.9+0.061/33/52+0.087 ms cpu, 145->145->145 MB, 146 MB goal, 4 P
gc 20 @1.749s 11%: 53+341+0.090 ms clock, 214+0.057/37/64+0.36 ms cpu, 246->246->181 MB, 291 MB goal, 4 P
gc 21 @2.245s 9%: 0.005+469+0.054 ms clock, 0.020+0/28/479+0.21 ms cpu, 308->308->126 MB, 363 MB goal, 4 P
gc 22 @2.749s 7%: 0.015+593+0.054 ms clock, 0.061+0/31/620+0.21 ms cpu, 284->284->157 MB, 285 MB goal, 4 P
gc 23 @3.375s 7%: 18+692+0.028 ms clock, 75+0.13/82/121+0.11 ms cpu, 355->355->355 MB, 356 MB goal, 4 P
gc 24 @4.245s 5%: 0.004+1095+0.082 ms clock, 0.019+0/50/1139+0.32 ms cpu, 602->602->246 MB, 710 MB goal, 4 P
gc 25 @5.422s 5%: 0.005+1146+0.020 ms clock, 0.020+0/60/1203+0.080 ms cpu, 555->555->308 MB, 556 MB goal, 4 P
gc 26 @6.718s 4%: 0.005+1430+0.029 ms clock, 0.022+0/76/1505+0.11 ms cpu, 694->694->385 MB, 695 MB goal, 4 P
gc 27 @8.490s 3%: 0.006+1822+0.031 ms clock, 0.027+0.066/95/1917+0.12 ms cpu, 867->867->482 MB, 868 MB goal, 4 P
gc 28 @10.411s 3%: 56+1971+0.022 ms clock, 227+0.13/213/426+0.091 ms cpu, 1084->1084->1084 MB, 1085 MB goal, 4 P
gc 29 @12.620s 5%: 366+2467+0.023 ms clock, 1464+0.11/269/528+0.094 ms cpu, 1837->1837->1355 MB, 2169 MB goal, 4 P
Max diff: 3.19718042s

real	0m20.366s
user	0m27.362s
sys	0m2.889s

main.go

package main

import (
	"fmt"
	"sync"
	"time"
)

type Object struct {
}

func main() {
	var wg sync.WaitGroup
	done := make(chan struct{})
	wg.Add(1)
	go func() {
		defer wg.Done()
		var ts []time.Time
	loop:
		for {
			select {
			case <-done:
				break loop
			case <-time.After(10 * time.Millisecond):
				ts = append(ts, time.Now())
			}
		}
		var maxd time.Duration
		for i := 1; i < len(ts); i++ {
			d := ts[i].Sub(ts[i-1])
			if maxd < d {
				maxd = d
			}
		}
		fmt.Printf("Max diff: %s\n", maxd)
	}()

	var s []*Object
	for i := 0; i < 100000000; i++ {
		s = append(s, &Object{})
	}

	close(done)
	wg.Wait()
}