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

RWMutex.Unlock() appearing in mutex contention profiles #19102

Closed
arussellsaw opened this issue Feb 15, 2017 · 1 comment
Closed

RWMutex.Unlock() appearing in mutex contention profiles #19102

arussellsaw opened this issue Feb 15, 2017 · 1 comment

Comments

@arussellsaw
Copy link

arussellsaw commented Feb 15, 2017

Please answer these questions before submitting your issue. Thanks!

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

go1.8rc3

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

GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/alex/dev/go"
GORACE=""
GOROOT="/Users/alex/sdk/go1.8rc3"
GOTOOLDIR="/Users/alex/sdk/go1.8rc3/pkg/tool/darwin_amd64"
GCCGO="gccgo"
CC="clang"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/l5/x43qw4sd10j_459gxsy9h3j80000gn/T/go-build886344651=/tmp/go-build -gno-record-gcc-switches -fno-common"
CXX="clang++"
CGO_ENABLED="1"
PKG_CONFIG="pkg-config"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"

What did you do?

built a contrived test to profile mutex contention using RWMutex (without realising that RWMutex was not supported).

if required i can create a new version using only public code but for now the library being profiled is closed source.

What did you expect to see?

No contention shown in pprof list output for RWMutex

What did you see instead?

(pprof) list
Total: 1.06s
ROUTINE ======================== code.avct.io/services/lru.(*Map).Get in /Users/alex/dev/go/src/code.avct.io/services/lru/lru.go
         0    34.01us (flat, cum) 0.0032% of Total
         .          .    137:	m.em.RLock()
         .          .    138:	if e, exists := m.exist[k]; exists {
         .          .    139:		m.em.RUnlock()
         .          .    140:		m.vm.Lock()
         .          .    141:		m.values.MoveToFront(e)
         .    34.01us    142:		m.vm.Unlock()
         .          .    143:		return e.Value.(mapElement).V, true
         .          .    144:	}
         .          .    145:	m.em.RUnlock()
         .          .    146:	return nil, false
         .          .    147:}
ROUTINE ======================== code.avct.io/services/lru.(*Map).Set in /Users/alex/dev/go/src/code.avct.io/services/lru/lru.go
         0      1.06s (flat, cum)   100% of Total
         .          .    159:
         .          .    160:	// never panics because we always ensure the list has instances of mapElement
         .          .    161:	me := e.Value.(mapElement)
         .          .    162:	delete(m.exist, me.K)
         .          .    163:	m.exist[k] = m.values.PushFront(mapElement{K: k, V: v})
         .      1.01s    164:	m.em.Unlock()
         .          .    165:
         .          .    166:	m.values.Remove(e)
         .    49.82ms    167:	m.vm.Unlock()
         .          .    168:
         .          .    169:	// Run registered eviction function, if any
         .          .    170:	if me.Fn != nil {
         .          .    171:		me.Fn()
         .          .    172:	}
ROUTINE ======================== main.main.func2 in /Users/alex/dev/go/src/code.avct.io/services/cmd/scratch/main.go
         0      1.06s (flat, cum)   100% of Total
         .          .     46:		ctx := context.Background()
         .          .     47:		r.Wait(ctx)
         .          .     48:		go func() {
         .          .     49:			start := time.Now()
         .          .     50:			id := ids[rand.Intn(150000)]
         .    34.01us     51:			v, ok := m.Get(id)
         .          .     52:			if !ok {
         .      1.06s     53:				m.Set(id, users[id], nil)
         .          .     54:			}
         .          .     55:			if v == -1 {
         .          .     56:				panic("no")
         .          .     57:			}
         .          .     58:			tChan <- time.Since(start)
ROUTINE ======================== runtime.goexit in /Users/alex/sdk/go1.8rc3/src/runtime/asm_amd64.s
         0      1.06s (flat, cum)   100% of Total
         .          .   2192:	RET
         .          .   2193:
         .          .   2194:// The top-most function running on a goroutine
         .          .   2195:// returns to goexit+PCQuantum.
         .          .   2196:TEXT runtime·goexit(SB),NOSPLIT,$0-0
         .      1.06s   2197:	BYTE	$0x90	// NOP
         .          .   2198:	CALL	runtime·goexit1(SB)	// does not return
         .          .   2199:	// traceback from goexit1 must hit code range of goexit
         .          .   2200:	BYTE	$0x90	// NOP
         .          .   2201:
         .          .   2202:TEXT runtime·prefetcht0(SB),NOSPLIT,$0-8
ROUTINE ======================== sync.(*Mutex).Unlock in /Users/alex/sdk/go1.8rc3/src/sync/mutex.go
     1.06s      1.06s (flat, cum)   100% of Total
         .          .    121:			return
         .          .    122:		}
         .          .    123:		// Grab the right to wake someone.
         .          .    124:		new = (old - 1<<mutexWaiterShift) | mutexWoken
         .          .    125:		if atomic.CompareAndSwapInt32(&m.state, old, new) {
     1.06s      1.06s    126:			runtime_Semrelease(&m.sema)
         .          .    127:			return
         .          .    128:		}
         .          .    129:		old = m.state
         .          .    130:	}
         .          .    131:}
ROUTINE ======================== sync.(*RWMutex).Unlock in /Users/alex/sdk/go1.8rc3/src/sync/rwmutex.go
         0      1.06s (flat, cum)   100% of Total
         .          .    120:	// Unblock blocked readers, if any.
         .          .    121:	for i := 0; i < int(r); i++ {
         .          .    122:		runtime_Semrelease(&rw.readerSem)
         .          .    123:	}
         .          .    124:	// Allow other writers to proceed.
         .      1.06s    125:	rw.w.Unlock()
         .          .    126:	if race.Enabled {
         .          .    127:		race.Enable()
         .          .    128:	}
         .          .    129:}
@arussellsaw
Copy link
Author

i realised this profiling is just due to the sync.Mutex inside the RWMutex, so this issue is incorrect

@golang golang locked and limited conversation to collaborators Feb 15, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

2 participants