Commit 3b3d58e1 authored by Austin Clements's avatar Austin Clements

runtime: remove workbuf logging

Early in Go 1.5 we had bugs with ownership of workbufs, so we added a
system for tracing their ownership to help debug these issues.
However, this system has both CPU and space overhead even when
disabled, it clutters up the workbuf API, the higher level gcWork
abstraction makes it very difficult to mess up the ownership of
workbufs in practice, and the tracing hasn't been enabled or needed
since 5b66e5d0 nine months ago. Hence, remove it.

Benchmarks show the usual noise from changes at this level, but little
overall movement.

name              old time/op  new time/op  delta
XBenchGarbage-12  2.48ms ± 1%  2.47ms ± 0%  -0.68%  (p=0.000 n=21+21)

name                      old time/op    new time/op    delta
BinaryTree17-12              2.98s ± 7%     2.98s ± 6%    ~     (p=0.799 n=20+20)
Fannkuch11-12                2.61s ± 3%     2.55s ± 5%  -2.55%  (p=0.003 n=20+20)
FmtFprintfEmpty-12          52.8ns ± 6%    53.6ns ± 6%    ~     (p=0.228 n=20+20)
FmtFprintfString-12          177ns ± 4%     177ns ± 4%    ~     (p=0.280 n=20+20)
FmtFprintfInt-12             162ns ± 5%     162ns ± 3%    ~     (p=0.347 n=20+20)
FmtFprintfIntInt-12          277ns ± 7%     273ns ± 4%  -1.62%  (p=0.005 n=20+20)
FmtFprintfPrefixedInt-12     237ns ± 4%     242ns ± 4%  +2.13%  (p=0.005 n=20+20)
FmtFprintfFloat-12           315ns ± 4%     312ns ± 4%  -0.97%  (p=0.001 n=20+20)
FmtManyArgs-12              1.11µs ± 3%    1.15µs ± 4%  +3.41%  (p=0.004 n=20+20)
GobDecode-12                8.50ms ± 7%    8.53ms ± 7%    ~     (p=0.429 n=20+20)
GobEncode-12                6.86ms ± 9%    6.93ms ± 7%  +0.93%  (p=0.030 n=20+20)
Gzip-12                      326ms ± 4%     329ms ± 4%  +0.98%  (p=0.020 n=20+20)
Gunzip-12                   43.3ms ± 3%    43.8ms ± 9%  +1.25%  (p=0.003 n=20+20)
HTTPClientServer-12         72.0µs ± 3%    71.5µs ± 3%    ~     (p=0.053 n=20+20)
JSONEncode-12               17.0ms ± 6%    17.3ms ± 7%  +1.32%  (p=0.006 n=20+20)
JSONDecode-12               64.2ms ± 4%    63.5ms ± 3%  -1.05%  (p=0.005 n=20+20)
Mandelbrot200-12            4.00ms ± 3%    3.99ms ± 3%    ~     (p=0.121 n=20+20)
GoParse-12                  3.74ms ± 5%    3.75ms ± 9%    ~     (p=0.383 n=20+20)
RegexpMatchEasy0_32-12       104ns ± 4%     104ns ± 6%    ~     (p=0.392 n=20+20)
RegexpMatchEasy0_1K-12       358ns ± 3%     361ns ± 4%  +0.95%  (p=0.003 n=20+20)
RegexpMatchEasy1_32-12      86.3ns ± 5%    86.1ns ± 6%    ~     (p=0.614 n=20+20)
RegexpMatchEasy1_1K-12       523ns ± 4%     518ns ± 3%  -1.14%  (p=0.008 n=20+20)
RegexpMatchMedium_32-12      137ns ± 3%     134ns ± 4%  -1.90%  (p=0.005 n=20+20)
RegexpMatchMedium_1K-12     41.0µs ± 3%    40.6µs ± 4%  -1.11%  (p=0.004 n=20+20)
RegexpMatchHard_32-12       2.13µs ± 4%    2.11µs ± 5%  -1.31%  (p=0.014 n=20+20)
RegexpMatchHard_1K-12       64.1µs ± 3%    63.2µs ± 5%  -1.38%  (p=0.005 n=20+20)
Revcomp-12                   555ms ±10%     548ms ± 7%  -1.17%  (p=0.011 n=20+20)
Template-12                 84.2ms ± 5%    88.2ms ± 4%  +4.73%  (p=0.000 n=20+20)
TimeParse-12                 365ns ± 4%     371ns ± 5%  +1.77%  (p=0.002 n=20+20)
TimeFormat-12                361ns ± 4%     365ns ± 3%  +1.08%  (p=0.002 n=20+20)
[Geo mean]                  64.7µs         64.8µs       +0.19%

Change-Id: Ib043a7a0d18b588b298873d60913d44cd19f3b44
Reviewed-on: https://go-review.googlesource.com/19887
Run-TryBot: Austin Clements <austin@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: default avatarBrad Fitzpatrick <bradfitz@golang.org>
Reviewed-by: default avatarRick Hudson <rlh@golang.org>
parent 0231f542
...@@ -11,7 +11,6 @@ import ( ...@@ -11,7 +11,6 @@ import (
) )
const ( const (
_Debugwbufs = false // if true check wbufs consistency
_WorkbufSize = 2048 // in bytes; larger values result in less contention _WorkbufSize = 2048 // in bytes; larger values result in less contention
) )
...@@ -86,10 +85,10 @@ type gcWork struct { ...@@ -86,10 +85,10 @@ type gcWork struct {
} }
func (w *gcWork) init() { func (w *gcWork) init() {
w.wbuf1 = wbufptrOf(getempty(101)) w.wbuf1 = wbufptrOf(getempty())
wbuf2 := trygetfull(102) wbuf2 := trygetfull()
if wbuf2 == nil { if wbuf2 == nil {
wbuf2 = getempty(103) wbuf2 = getempty()
} }
w.wbuf2 = wbufptrOf(wbuf2) w.wbuf2 = wbufptrOf(wbuf2)
} }
...@@ -107,8 +106,8 @@ func (w *gcWork) put(obj uintptr) { ...@@ -107,8 +106,8 @@ func (w *gcWork) put(obj uintptr) {
w.wbuf1, w.wbuf2 = w.wbuf2, w.wbuf1 w.wbuf1, w.wbuf2 = w.wbuf2, w.wbuf1
wbuf = w.wbuf1.ptr() wbuf = w.wbuf1.ptr()
if wbuf.nobj == len(wbuf.obj) { if wbuf.nobj == len(wbuf.obj) {
putfull(wbuf, 132) putfull(wbuf)
wbuf = getempty(133) wbuf = getempty()
w.wbuf1 = wbufptrOf(wbuf) w.wbuf1 = wbufptrOf(wbuf)
} }
} }
...@@ -135,11 +134,11 @@ func (w *gcWork) tryGet() uintptr { ...@@ -135,11 +134,11 @@ func (w *gcWork) tryGet() uintptr {
wbuf = w.wbuf1.ptr() wbuf = w.wbuf1.ptr()
if wbuf.nobj == 0 { if wbuf.nobj == 0 {
owbuf := wbuf owbuf := wbuf
wbuf = trygetfull(167) wbuf = trygetfull()
if wbuf == nil { if wbuf == nil {
return 0 return 0
} }
putempty(owbuf, 166) putempty(owbuf)
w.wbuf1 = wbufptrOf(wbuf) w.wbuf1 = wbufptrOf(wbuf)
} }
} }
...@@ -164,11 +163,11 @@ func (w *gcWork) get() uintptr { ...@@ -164,11 +163,11 @@ func (w *gcWork) get() uintptr {
wbuf = w.wbuf1.ptr() wbuf = w.wbuf1.ptr()
if wbuf.nobj == 0 { if wbuf.nobj == 0 {
owbuf := wbuf owbuf := wbuf
wbuf = getfull(185) wbuf = getfull()
if wbuf == nil { if wbuf == nil {
return 0 return 0
} }
putempty(owbuf, 184) putempty(owbuf)
w.wbuf1 = wbufptrOf(wbuf) w.wbuf1 = wbufptrOf(wbuf)
} }
} }
...@@ -189,17 +188,17 @@ func (w *gcWork) get() uintptr { ...@@ -189,17 +188,17 @@ func (w *gcWork) get() uintptr {
func (w *gcWork) dispose() { func (w *gcWork) dispose() {
if wbuf := w.wbuf1.ptr(); wbuf != nil { if wbuf := w.wbuf1.ptr(); wbuf != nil {
if wbuf.nobj == 0 { if wbuf.nobj == 0 {
putempty(wbuf, 212) putempty(wbuf)
} else { } else {
putfull(wbuf, 214) putfull(wbuf)
} }
w.wbuf1 = 0 w.wbuf1 = 0
wbuf = w.wbuf2.ptr() wbuf = w.wbuf2.ptr()
if wbuf.nobj == 0 { if wbuf.nobj == 0 {
putempty(wbuf, 218) putempty(wbuf)
} else { } else {
putfull(wbuf, 220) putfull(wbuf)
} }
w.wbuf2 = 0 w.wbuf2 = 0
} }
...@@ -225,8 +224,8 @@ func (w *gcWork) balance() { ...@@ -225,8 +224,8 @@ func (w *gcWork) balance() {
return return
} }
if wbuf := w.wbuf2.ptr(); wbuf.nobj != 0 { if wbuf := w.wbuf2.ptr(); wbuf.nobj != 0 {
putfull(wbuf, 246) putfull(wbuf)
w.wbuf2 = wbufptrOf(getempty(247)) w.wbuf2 = wbufptrOf(getempty())
} else if wbuf := w.wbuf1.ptr(); wbuf.nobj > 4 { } else if wbuf := w.wbuf1.ptr(); wbuf.nobj > 4 {
w.wbuf1 = wbufptrOf(handoff(wbuf)) w.wbuf1 = wbufptrOf(handoff(wbuf))
} }
...@@ -245,8 +244,6 @@ func (w *gcWork) empty() bool { ...@@ -245,8 +244,6 @@ func (w *gcWork) empty() bool {
type workbufhdr struct { type workbufhdr struct {
node lfnode // must be first node lfnode // must be first
nobj int nobj int
inuse bool // This workbuf is in use by some goroutine and is not on the work.empty/full queues.
log [4]int // line numbers forming a history of ownership changes to workbuf
} }
type workbuf struct { type workbuf struct {
...@@ -259,69 +256,23 @@ type workbuf struct { ...@@ -259,69 +256,23 @@ type workbuf struct {
// workbufs. // workbufs.
// If the GC asks for some work these are the only routines that // If the GC asks for some work these are the only routines that
// make wbufs available to the GC. // make wbufs available to the GC.
// Each of the gets and puts also take an distinct integer that is used
// to record a brief history of changes to ownership of the workbuf.
// The convention is to use a unique line number but any encoding
// is permissible. For example if you want to pass in 2 bits of information
// you could simple add lineno1*100000+lineno2.
// logget records the past few values of entry to aid in debugging.
// logget checks the buffer b is not currently in use.
func (b *workbuf) logget(entry int) {
if !_Debugwbufs {
return
}
if b.inuse {
println("runtime: logget fails log entry=", entry,
"b.log[0]=", b.log[0], "b.log[1]=", b.log[1],
"b.log[2]=", b.log[2], "b.log[3]=", b.log[3])
throw("logget: get not legal")
}
b.inuse = true
copy(b.log[1:], b.log[:])
b.log[0] = entry
}
// logput records the past few values of entry to aid in debugging.
// logput checks the buffer b is currently in use.
func (b *workbuf) logput(entry int) {
if !_Debugwbufs {
return
}
if !b.inuse {
println("runtime: logput fails log entry=", entry,
"b.log[0]=", b.log[0], "b.log[1]=", b.log[1],
"b.log[2]=", b.log[2], "b.log[3]=", b.log[3])
throw("logput: put not legal")
}
b.inuse = false
copy(b.log[1:], b.log[:])
b.log[0] = entry
}
func (b *workbuf) checknonempty() { func (b *workbuf) checknonempty() {
if b.nobj == 0 { if b.nobj == 0 {
println("runtime: nonempty check fails",
"b.log[0]=", b.log[0], "b.log[1]=", b.log[1],
"b.log[2]=", b.log[2], "b.log[3]=", b.log[3])
throw("workbuf is empty") throw("workbuf is empty")
} }
} }
func (b *workbuf) checkempty() { func (b *workbuf) checkempty() {
if b.nobj != 0 { if b.nobj != 0 {
println("runtime: empty check fails",
"b.log[0]=", b.log[0], "b.log[1]=", b.log[1],
"b.log[2]=", b.log[2], "b.log[3]=", b.log[3])
throw("workbuf is not empty") throw("workbuf is not empty")
} }
} }
// getempty pops an empty work buffer off the work.empty list, // getempty pops an empty work buffer off the work.empty list,
// allocating new buffers if none are available. // allocating new buffers if none are available.
// entry is used to record a brief history of ownership.
//go:nowritebarrier //go:nowritebarrier
func getempty(entry int) *workbuf { func getempty() *workbuf {
var b *workbuf var b *workbuf
if work.empty != 0 { if work.empty != 0 {
b = (*workbuf)(lfstackpop(&work.empty)) b = (*workbuf)(lfstackpop(&work.empty))
...@@ -332,16 +283,14 @@ func getempty(entry int) *workbuf { ...@@ -332,16 +283,14 @@ func getempty(entry int) *workbuf {
if b == nil { if b == nil {
b = (*workbuf)(persistentalloc(unsafe.Sizeof(*b), sys.CacheLineSize, &memstats.gc_sys)) b = (*workbuf)(persistentalloc(unsafe.Sizeof(*b), sys.CacheLineSize, &memstats.gc_sys))
} }
b.logget(entry)
return b return b
} }
// putempty puts a workbuf onto the work.empty list. // putempty puts a workbuf onto the work.empty list.
// Upon entry this go routine owns b. The lfstackpush relinquishes ownership. // Upon entry this go routine owns b. The lfstackpush relinquishes ownership.
//go:nowritebarrier //go:nowritebarrier
func putempty(b *workbuf, entry int) { func putempty(b *workbuf) {
b.checkempty() b.checkempty()
b.logput(entry)
lfstackpush(&work.empty, &b.node) lfstackpush(&work.empty, &b.node)
} }
...@@ -349,9 +298,8 @@ func putempty(b *workbuf, entry int) { ...@@ -349,9 +298,8 @@ func putempty(b *workbuf, entry int) {
// putfull accepts partially full buffers so the GC can avoid competing // putfull accepts partially full buffers so the GC can avoid competing
// with the mutators for ownership of partially full buffers. // with the mutators for ownership of partially full buffers.
//go:nowritebarrier //go:nowritebarrier
func putfull(b *workbuf, entry int) { func putfull(b *workbuf) {
b.checknonempty() b.checknonempty()
b.logput(entry)
lfstackpush(&work.full, &b.node) lfstackpush(&work.full, &b.node)
// We just made more work available. Let the GC controller // We just made more work available. Let the GC controller
...@@ -364,10 +312,9 @@ func putfull(b *workbuf, entry int) { ...@@ -364,10 +312,9 @@ func putfull(b *workbuf, entry int) {
// trygetfull tries to get a full or partially empty workbuffer. // trygetfull tries to get a full or partially empty workbuffer.
// If one is not immediately available return nil // If one is not immediately available return nil
//go:nowritebarrier //go:nowritebarrier
func trygetfull(entry int) *workbuf { func trygetfull() *workbuf {
b := (*workbuf)(lfstackpop(&work.full)) b := (*workbuf)(lfstackpop(&work.full))
if b != nil { if b != nil {
b.logget(entry)
b.checknonempty() b.checknonempty()
return b return b
} }
...@@ -386,10 +333,9 @@ func trygetfull(entry int) *workbuf { ...@@ -386,10 +333,9 @@ func trygetfull(entry int) *workbuf {
// This is in fact the termination condition for the STW mark // This is in fact the termination condition for the STW mark
// phase. // phase.
//go:nowritebarrier //go:nowritebarrier
func getfull(entry int) *workbuf { func getfull() *workbuf {
b := (*workbuf)(lfstackpop(&work.full)) b := (*workbuf)(lfstackpop(&work.full))
if b != nil { if b != nil {
b.logget(entry)
b.checknonempty() b.checknonempty()
return b return b
} }
...@@ -408,7 +354,6 @@ func getfull(entry int) *workbuf { ...@@ -408,7 +354,6 @@ func getfull(entry int) *workbuf {
} }
b = (*workbuf)(lfstackpop(&work.full)) b = (*workbuf)(lfstackpop(&work.full))
if b != nil { if b != nil {
b.logget(entry)
b.checknonempty() b.checknonempty()
return b return b
} }
...@@ -438,7 +383,7 @@ func getfull(entry int) *workbuf { ...@@ -438,7 +383,7 @@ func getfull(entry int) *workbuf {
//go:nowritebarrier //go:nowritebarrier
func handoff(b *workbuf) *workbuf { func handoff(b *workbuf) *workbuf {
// Make new buffer with half of b's pointers. // Make new buffer with half of b's pointers.
b1 := getempty(915) b1 := getempty()
n := b.nobj / 2 n := b.nobj / 2
b.nobj -= n b.nobj -= n
b1.nobj = n b1.nobj = n
...@@ -448,6 +393,6 @@ func handoff(b *workbuf) *workbuf { ...@@ -448,6 +393,6 @@ func handoff(b *workbuf) *workbuf {
_g_.m.gcstats.nhandoffcnt += uint64(n) _g_.m.gcstats.nhandoffcnt += uint64(n)
// Put b on full list - let first half of b get stolen. // Put b on full list - let first half of b get stolen.
putfull(b, 942) putfull(b)
return b1 return b1
} }
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment