Issue 132440043: code review 132440043: runtime: convert cpuprof from C to Go (Closed)
Descriptionruntime: convert cpuprof from C to Go
Patch Set 1 #Patch Set 2 : diff -r 25ae16c918f65ca0e0039d74109aaeefa716d987 https://code.google.com/p/go #Patch Set 3 : diff -r 25ae16c918f65ca0e0039d74109aaeefa716d987 https://code.google.com/p/go #Patch Set 4 : diff -r 25ae16c918f65ca0e0039d74109aaeefa716d987 https://code.google.com/p/go #Patch Set 5 : diff -r 25ae16c918f65ca0e0039d74109aaeefa716d987 https://code.google.com/p/go #Patch Set 6 : diff -r 25ae16c918f65ca0e0039d74109aaeefa716d987 https://code.google.com/p/go #
Total comments: 21
Patch Set 7 : diff -r 25ae16c918f65ca0e0039d74109aaeefa716d987 https://code.google.com/p/go #Patch Set 8 : diff -r 25ae16c918f65ca0e0039d74109aaeefa716d987 https://code.google.com/p/go #Patch Set 9 : diff -r 25ae16c918f65ca0e0039d74109aaeefa716d987 https://code.google.com/p/go #Patch Set 10 : diff -r 25ae16c918f65ca0e0039d74109aaeefa716d987 https://code.google.com/p/go #
Total comments: 5
Patch Set 11 : diff -r e5c87cefb57fffc5767209542be5c4e58123e3c6 https://code.google.com/p/go #
Total comments: 16
Patch Set 12 : diff -r e5c87cefb57fffc5767209542be5c4e58123e3c6 https://code.google.com/p/go #Patch Set 13 : diff -r 5e03333d2dcf88e92c0be0b560032f3272959c11 https://code.google.com/p/go #
Total comments: 2
Patch Set 14 : diff -r 5e03333d2dcf88e92c0be0b560032f3272959c11 https://code.google.com/p/go #Patch Set 15 : diff -r 5e03333d2dcf88e92c0be0b560032f3272959c11 https://code.google.com/p/go #Patch Set 16 : diff -r 6aabcc1ffb70dbe0cca91f8f46176a26012ba2e9 https://code.google.com/p/go #Patch Set 17 : diff -r 6aabcc1ffb70dbe0cca91f8f46176a26012ba2e9 https://code.google.com/p/go #
Total comments: 2
Patch Set 18 : diff -r 17b5fc2aa130ef7c32cbbdf95620862610d7773e https://code.google.com/p/go #
MessagesTotal messages: 26
Hello golang-codereviews@googlegroups.com, I'd like you to review this change to https://code.google.com/p/go
Sign in to reply to this message.
https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.go File src/pkg/runtime/cpuprof.go (right): https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:62: type entry struct { these are not runtime-global, give them more unique names e.g. cpuprofEntry and cpuProfile, or something similar https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:97: var cpuprofLock mutex make it member var of profile https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:100: var eod = [3]uintptr{0, 1, 0} make a single var ( ) block https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:111: f := *(**funcval)(unsafe.Pointer(&p)) instead of this function and the var, you can just do where it is used: f = lostProfileData ... = **(**uintptr)(unsafe.Pointer(&p)) https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:145: // cpuprof binary header format. s/cpuprof/pprof/ https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:151: p[3] = uintptr(1000000 / hz) // period (microseconds) s/1000000/1e6/ https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:185: func tick(pc *uintptr, n int32) { it was a file-local static function, so the short name was fine now it's global, so please rename it to something more descriptive, e.g. cpuproftick https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:244: e.stack[i] = pc[i] perhaps copy(e.stack[:], pc) https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:409: return ret s/return ret/return/ https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/proc.c File src/pkg/runtime/proc.c (right): https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/proc.c#n... src/pkg/runtime/proc.c:2394: void (*fn)(uintptr*, int32); remove https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/proc.c#n... src/pkg/runtime/proc.c:2539: extern void runtime·tick(uintptr*, int32); we generally do not do this, declare it somewhere on top level
Sign in to reply to this message.
https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.go File src/pkg/runtime/cpuprof.go (right): https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:62: type entry struct { On 2014/08/29 18:59:14, dvyukov wrote: > these are not runtime-global, give them more unique names > e.g. cpuprofEntry and cpuProfile, or something similar Done. https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:97: var cpuprofLock mutex On 2014/08/29 18:59:13, dvyukov wrote: > make it member var of profile The existing code requires the mutex to exist before the profile struct has been allocated. https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:100: var eod = [3]uintptr{0, 1, 0} On 2014/08/29 18:59:13, dvyukov wrote: > make a single var ( > ) > block Done. https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:111: f := *(**funcval)(unsafe.Pointer(&p)) On 2014/08/29 18:59:13, dvyukov wrote: > instead of this function and the var, you can just do where it is used: > > f = lostProfileData > ... = **(**uintptr)(unsafe.Pointer(&p)) Done. https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:145: // cpuprof binary header format. On 2014/08/29 18:59:13, dvyukov wrote: > s/cpuprof/pprof/ Oops, done. https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:151: p[3] = uintptr(1000000 / hz) // period (microseconds) On 2014/08/29 18:59:13, dvyukov wrote: > s/1000000/1e6/ Done. https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:185: func tick(pc *uintptr, n int32) { On 2014/08/29 18:59:14, dvyukov wrote: > it was a file-local static function, so the short name was fine > now it's global, so please rename it to something more descriptive, e.g. > cpuproftick Done. https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:244: e.stack[i] = pc[i] On 2014/08/29 18:59:13, dvyukov wrote: > perhaps copy(e.stack[:], pc) Done. https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/proc.c File src/pkg/runtime/proc.c (right): https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/proc.c#n... src/pkg/runtime/proc.c:2539: extern void runtime·tick(uintptr*, int32); On 2014/08/29 18:59:14, dvyukov wrote: > we generally do not do this, declare it somewhere on top level Done.
Sign in to reply to this message.
https://codereview.appspot.com/132440043/diff/180001/src/pkg/runtime/cpuprof.go File src/pkg/runtime/cpuprof.go (right): https://codereview.appspot.com/132440043/diff/180001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:197: h += (x*4+x)*8 + x N.B., I've changed this from "x*31 + x*7 + x*3" to "(x*4+x)*8+x", which is equivalent and more representative of how GCC would optimize this expression. 5c and 8c recognized the x*(2^n-1) pattern and compiled it like (x<<n)-x, but 6c and gc do not and instead emit multiplication instructions. (Or in this case, three multiplication instructions.) The new form can be optimized to just two LEA (386/amd64) or ADD (arm) instructions, and the cc compilers do this, but the gc compilers currently do not. However, they still emit slightly shorter code than for "x*32 + x*8 + x", and much better code than for "x*31 + x*7 + x*3".
Sign in to reply to this message.
LGTM https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.go File src/pkg/runtime/cpuprof.go (right): https://codereview.appspot.com/132440043/diff/100001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:97: var cpuprofLock mutex On 2014/08/29 19:37:47, mdempsky wrote: > On 2014/08/29 18:59:13, dvyukov wrote: > > make it member var of profile > > The existing code requires the mutex to exist before the profile struct has been > allocated. You are right. https://codereview.appspot.com/132440043/diff/180001/src/pkg/runtime/proc.c File src/pkg/runtime/proc.c (right): https://codereview.appspot.com/132440043/diff/180001/src/pkg/runtime/proc.c#n... src/pkg/runtime/proc.c:2538: if(prof.hz != 0) { remove {}
Sign in to reply to this message.
https://codereview.appspot.com/132440043/diff/180001/src/pkg/runtime/proc.c File src/pkg/runtime/proc.c (right): https://codereview.appspot.com/132440043/diff/180001/src/pkg/runtime/proc.c#n... src/pkg/runtime/proc.c:2538: if(prof.hz != 0) { On 2014/08/30 04:20:44, dvyukov wrote: > remove {} Done.
Sign in to reply to this message.
https://codereview.appspot.com/132440043/diff/180001/src/pkg/runtime/cpuprof.go File src/pkg/runtime/cpuprof.go (right): https://codereview.appspot.com/132440043/diff/180001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:197: h += (x*4+x)*8 + x This CL should only do translation. It should not apply optimizations. It is fine to send us optimization as SEPARATE CLs. Translations are big and hard enough to review without unnecessary changes being made. Please restore the expression to what it was before.
Sign in to reply to this message.
https://codereview.appspot.com/132440043/diff/180001/src/pkg/runtime/cpuprof.go File src/pkg/runtime/cpuprof.go (right): https://codereview.appspot.com/132440043/diff/180001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:197: h += (x*4+x)*8 + x On 2014/08/30 04:33:21, rsc wrote: > This CL should only do translation. It should not apply optimizations. > It is fine to send us optimization as SEPARATE CLs. > Translations are big and hard enough to review without unnecessary changes being > made. > Please restore the expression to what it was before. Done.
Sign in to reply to this message.
looks pretty good. bunch of small things. https://codereview.appspot.com/132440043/diff/200001/src/pkg/runtime/cpuprof.go File src/pkg/runtime/cpuprof.go (right): https://codereview.appspot.com/132440043/diff/200001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:130: cpuprof = &cpuProfile{} cpuprof = (*cpuProfile)(sysAlloc(unsafe.Sizeof(cpuProfile{}), &mstats.other_sys)) if cpuprof == nil { ... } There is surely a reason we do not call malloc in the C code. Don't change that here. https://codereview.appspot.com/140060043 renames it sysAlloc for you. https://codereview.appspot.com/132440043/diff/200001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:133: printstring("runtime: cannot set cpu profile rate until previous profile has finished.\n") print is fine https://codereview.appspot.com/132440043/diff/200001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:165: printstring("runtime: setcpuprofile(off) twice") print. and add a \n while you are here https://codereview.appspot.com/132440043/diff/200001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:197: h += (x*4+x)*8 + x Same. https://codereview.appspot.com/132440043/diff/200001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:307: printstring("runtime: phase error during cpu profile handoff\n") global search and replace printTYPE with print https://codereview.appspot.com/132440043/diff/200001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:336: { we don't do this. declare n above goto and remove these braces or do something that actually uses braces, like switch n := p.handoff; { case n == 0: case n == 0x80000000: default: n &^= 0x8000000 ... } https://codereview.appspot.com/132440043/diff/200001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:358: flush: Flush: https://codereview.appspot.com/132440043/diff/200001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:395: func asByteSlice(p []uintptr) (ret []byte) { rename to uintptrBytes
Sign in to reply to this message.
On 2014/08/30 04:50:20, rsc wrote: > looks pretty good. Thanks. https://codereview.appspot.com/132440043/diff/200001/src/pkg/runtime/cpuprof.go File src/pkg/runtime/cpuprof.go (right): https://codereview.appspot.com/132440043/diff/200001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:130: cpuprof = &cpuProfile{} On 2014/08/30 04:50:19, rsc wrote: > cpuprof = (*cpuProfile)(sysAlloc(unsafe.Sizeof(cpuProfile{}), > &mstats.other_sys)) > if cpuprof == nil { > ... > } Done. https://codereview.appspot.com/132440043/diff/200001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:133: printstring("runtime: cannot set cpu profile rate until previous profile has finished.\n") On 2014/08/30 04:50:19, rsc wrote: > print is fine Done. https://codereview.appspot.com/132440043/diff/200001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:165: printstring("runtime: setcpuprofile(off) twice") On 2014/08/30 04:50:20, rsc wrote: > print. and add a \n while you are here Done. https://codereview.appspot.com/132440043/diff/200001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:197: h += (x*4+x)*8 + x On 2014/08/30 04:50:19, rsc wrote: > Same. (Already fixed in a later patch set.) https://codereview.appspot.com/132440043/diff/200001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:307: printstring("runtime: phase error during cpu profile handoff\n") On 2014/08/30 04:50:19, rsc wrote: > global search and replace printTYPE with print Done. https://codereview.appspot.com/132440043/diff/200001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:336: { On 2014/08/30 04:50:19, rsc wrote: > we don't do this. Noted. > declare n above goto and remove these braces > or do something that actually uses braces, like Done. I used the switch block you suggested. https://codereview.appspot.com/132440043/diff/200001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:358: flush: On 2014/08/30 04:50:19, rsc wrote: > Flush: Done. https://codereview.appspot.com/132440043/diff/200001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:395: func asByteSlice(p []uintptr) (ret []byte) { On 2014/08/30 04:50:19, rsc wrote: > rename to uintptrBytes Done. https://codereview.appspot.com/132440043/diff/240001/src/pkg/runtime/proc.c File src/pkg/runtime/proc.c (right): https://codereview.appspot.com/132440043/diff/240001/src/pkg/runtime/proc.c#n... src/pkg/runtime/proc.c:2537: runtime·cpuproftick(stk, n); Just to confirm: it's okay to call into Go code from an async signal handler context? E.g., there won't be any issues with the Go functions deciding they need to resize the stack? Looking at how Go's signal handlers are setup, it seems like it should be okay, but my understanding of stack handling in Go is still a bit iffy so I thought I'd ask.
Sign in to reply to this message.
https://codereview.appspot.com/132440043/diff/240001/src/pkg/runtime/proc.c File src/pkg/runtime/proc.c (right): https://codereview.appspot.com/132440043/diff/240001/src/pkg/runtime/proc.c#n... src/pkg/runtime/proc.c:2537: runtime·cpuproftick(stk, n); On 2014/08/30 05:53:17, mdempsky wrote: > Just to confirm: it's okay to call into Go code from an async signal handler > context? E.g., there won't be any issues with the Go functions deciding they > need to resize the stack? > > Looking at how Go's signal handlers are setup, it seems like it should be okay, > but my understanding of stack handling in Go is still a bit iffy so I thought > I'd ask. Yes, it is OK to call Go code in signal handler. In fact, C code also has split stack checks. So Go is not different here. Obviously it's not OK to call malloc in signal handler. But the compiler does not emit implicit malloc calls into Go code in runtime. So unless you write 'new' or '&Foo{}', you are safe. But still run something real with cpuprof, e.g. go test -cpuprofile=prof -cpu=1,2,4,8 -bench=.* {runtime,net,net/http,reflect,encoding/json}
Sign in to reply to this message.
On 2014/08/30 05:53:18, mdempsky wrote: > Just to confirm: it's okay to call into Go code from an async signal handler > context? E.g., there won't be any issues with the Go functions deciding they > need to resize the stack? > > Looking at how Go's signal handlers are setup, it seems like it should be okay, > but my understanding of stack handling in Go is still a bit iffy so I thought > I'd ask. Possibly related, I just noticed this on linux/amd64: $ go test -race runtime/pprof signal: segmentation fault (core dumped) FAIL runtime/pprof 0.199s I'll investigate.
Sign in to reply to this message.
On 2014/08/30 06:16:03, mdempsky wrote:
> Possibly related, I just noticed this on linux/amd64:
>
> $ go test -race runtime/pprof
> signal: segmentation fault (core dumped)
> FAIL runtime/pprof 0.199s
>
> I'll investigate.
Still unknown, but here's what I've been able to determine so far with gdb.
Maybe someone else will have an idea what's going on.
It looks like it's triggering a NULL pointer dereference near the start of
__tsan_func_enter:
(gdb) info registers
rax 0x55e160 5628256
rbx 0x0 0
rcx 0x40360b 4208139
rdx 0x40 64
rsi 0x40360b 4208139
rdi 0x0 0
rbp 0x3ffffffffff 0x3ffffffffff
rsp 0x7fffffffe1f0 0x7fffffffe1f0
r8 0x7ffff6d62898 140737334618264
r9 0x630 1584
r10 0xff7860 16742496
r11 0x1 1
r12 0xc20800b588 833357919624
r13 0xff7c40 16743488
r14 0xc208002000 833357881344
r15 0x40 64
rip 0x55e175 0x55e175 <__tsan_func_enter+21>
eflags 0x10206 [ PF IF RF ]
cs 0x33 51
ss 0x2b 43
ds 0x0 0
es 0x0 0
fs 0x0 0
gs 0x0 0
(gdb) x/8i $pc-21
0x55e160 <__tsan_func_enter>: push %r12
0x55e162 <__tsan_func_enter+2>: push %rbp
0x55e163 <__tsan_func_enter+3>: movabs $0x3ffffffffff,%rbp
0x55e16d <__tsan_func_enter+13>: push %rbx
0x55e16e <__tsan_func_enter+14>: mov %rdi,%rbx
0x55e171 <__tsan_func_enter+17>: sub $0x10,%rsp
=> 0x55e175 <__tsan_func_enter+21>: mov (%rdi),%rax
0x55e178 <__tsan_func_enter+24>: lea 0x1(%rax),%r12
Unfortunately, gdb's normal bt functionality is broken by racecall switching the
stacks underneath us:
(gdb) bt
#0 0x000000000055e175 in __tsan_func_enter ()
#1 0x000000c208056138 in ?? ()
#2 0x00000000000186a0 in ?? ()
#3 0x0000000000000010 in ?? ()
#4 0x0000000000000002 in ?? ()
#5 0x000000c20800b588 in ?? ()
#6 0x0000000000436c26 in racecall () at
/usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/race_amd64.s:204
#7 0x0000000000ff7888 in runtime.g0 ()
#8 0x0000000000433c8e in _rt0_go () at
/usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/asm_amd64.s:104
#9 0x0000000000000001 in ?? ()
#10 0x00007fffffffe268 in ?? ()
#11 0x0000000000000001 in ?? ()
#12 0x00007fffffffe268 in ?? ()
#13 0x0000000000000000 in ?? ()
But after manually unwinding the instructions and restoring %rip and %rsp, I get
a slightly more helpful stacktrace:
(gdb) set $rsp = 0xc20800b588
(gdb) set $rip = 0x436c10
(gdb) bt
#0 racecall () at
/usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/race_amd64.s:197
#1 0x0000000000436bb4 in runtime.racefuncenter ()
at /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/race_amd64.s:166
#2 0x0000000000429410 in runtime.racewriterangepc ()
at /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/race.c:142
#3 0x000000000040f893 in runtime.slicecopy (to=..., fm=..., width=8, ~r3=0)
at /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/slice.go:110
#4 0x000000000040360b in runtime.(*cpuProfile).add (p=0x7ffff6c45000, pc=...)
at /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/cpuprof.go:240
#5 0x00000000004033f7 in runtime.cpuproftick (pc=0xc20800b700, n=2)
at /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/cpuprof.go:187
#6 0x0000000000426f89 in runtime.sigprof () at
/usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.c:2537
#7 0x000000000042ab70 in runtime.sighandler ()
at /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/signal_amd64x.c:51
#8 0x0000000000436f66 in runtime.sigtramp ()
at
/usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/sys_linux_amd64.s:218
#9 0x0000000000436f80 in runtime.sigtramp ()
at
/usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/sys_linux_amd64.s:224
#10 0x0000000000000001 in ?? ()
#11 0x0000000000000000 in ?? ()
So perhaps running Go code in a signal handler by itself is okay, but the TSAN
instrumentation doesn't know how to handle this yet?
Sign in to reply to this message.
On 2014/08/30 06:52:52, mdempsky wrote: > On 2014/08/30 06:16:03, mdempsky wrote: > > Possibly related, I just noticed this on linux/amd64: > > > > $ go test -race runtime/pprof > > signal: segmentation fault (core dumped) > > FAIL runtime/pprof 0.199s > > > > I'll investigate. > > Still unknown, but here's what I've been able to determine so far with gdb. > Maybe someone else will have an idea what's going on. > > It looks like it's triggering a NULL pointer dereference near the start of > __tsan_func_enter: > > (gdb) info registers > rax 0x55e160 5628256 > rbx 0x0 0 > rcx 0x40360b 4208139 > rdx 0x40 64 > rsi 0x40360b 4208139 > rdi 0x0 0 > rbp 0x3ffffffffff 0x3ffffffffff > rsp 0x7fffffffe1f0 0x7fffffffe1f0 > r8 0x7ffff6d62898 140737334618264 > r9 0x630 1584 > r10 0xff7860 16742496 > r11 0x1 1 > r12 0xc20800b588 833357919624 > r13 0xff7c40 16743488 > r14 0xc208002000 833357881344 > r15 0x40 64 > rip 0x55e175 0x55e175 <__tsan_func_enter+21> > eflags 0x10206 [ PF IF RF ] > cs 0x33 51 > ss 0x2b 43 > ds 0x0 0 > es 0x0 0 > fs 0x0 0 > gs 0x0 0 > > (gdb) x/8i $pc-21 > 0x55e160 <__tsan_func_enter>: push %r12 > 0x55e162 <__tsan_func_enter+2>: push %rbp > 0x55e163 <__tsan_func_enter+3>: movabs $0x3ffffffffff,%rbp > 0x55e16d <__tsan_func_enter+13>: push %rbx > 0x55e16e <__tsan_func_enter+14>: mov %rdi,%rbx > 0x55e171 <__tsan_func_enter+17>: sub $0x10,%rsp > => 0x55e175 <__tsan_func_enter+21>: mov (%rdi),%rax > 0x55e178 <__tsan_func_enter+24>: lea 0x1(%rax),%r12 > > Unfortunately, gdb's normal bt functionality is broken by racecall switching the > stacks underneath us: > > (gdb) bt > #0 0x000000000055e175 in __tsan_func_enter () > #1 0x000000c208056138 in ?? () > #2 0x00000000000186a0 in ?? () > #3 0x0000000000000010 in ?? () > #4 0x0000000000000002 in ?? () > #5 0x000000c20800b588 in ?? () > #6 0x0000000000436c26 in racecall () at > /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/race_amd64.s:204 > #7 0x0000000000ff7888 in runtime.g0 () > #8 0x0000000000433c8e in _rt0_go () at > /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/asm_amd64.s:104 > #9 0x0000000000000001 in ?? () > #10 0x00007fffffffe268 in ?? () > #11 0x0000000000000001 in ?? () > #12 0x00007fffffffe268 in ?? () > #13 0x0000000000000000 in ?? () > > But after manually unwinding the instructions and restoring %rip and %rsp, I get > a slightly more helpful stacktrace: > > (gdb) set $rsp = 0xc20800b588 > (gdb) set $rip = 0x436c10 > (gdb) bt > #0 racecall () at > /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/race_amd64.s:197 > #1 0x0000000000436bb4 in runtime.racefuncenter () > at /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/race_amd64.s:166 > #2 0x0000000000429410 in runtime.racewriterangepc () > at /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/race.c:142 > #3 0x000000000040f893 in runtime.slicecopy (to=..., fm=..., width=8, ~r3=0) > at /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/slice.go:110 > #4 0x000000000040360b in runtime.(*cpuProfile).add (p=0x7ffff6c45000, pc=...) > at /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/cpuprof.go:240 > #5 0x00000000004033f7 in runtime.cpuproftick (pc=0xc20800b700, n=2) > at /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/cpuprof.go:187 > #6 0x0000000000426f89 in runtime.sigprof () at > /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.c:2537 > #7 0x000000000042ab70 in runtime.sighandler () > at /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/signal_amd64x.c:51 > #8 0x0000000000436f66 in runtime.sigtramp () > at > /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/sys_linux_amd64.s:218 > #9 0x0000000000436f80 in runtime.sigtramp () > at > /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/sys_linux_amd64.s:224 > #10 0x0000000000000001 in ?? () > #11 0x0000000000000000 in ?? () > > > So perhaps running Go code in a signal handler by itself is okay, but the TSAN > instrumentation doesn't know how to handle this yet? You conclusions look right. I guess you need to replace copy back with manual loop. Copy function is instrumented.
Sign in to reply to this message.
On 2014/08/30 07:01:56, dvyukov wrote: > You conclusions look right. I guess you need to replace copy back with manual > loop. Copy function is instrumented. Done. Thanks for the confirmation.
Sign in to reply to this message.
On Sat, Aug 30, 2014 at 11:08 AM, <mdempsky@google.com> wrote: > On 2014/08/30 07:01:56, dvyukov wrote: >> >> You conclusions look right. I guess you need to replace copy back with > > manual >> >> loop. Copy function is instrumented. > > > Done. Thanks for the confirmation. > Does -race -cpuprofile work now?
Sign in to reply to this message.
On Sat, Aug 30, 2014 at 12:22 AM, Dmitry Vyukov <dvyukov@google.com> wrote: > Does -race -cpuprofile work now? > Sorry, yes, "go test -race runtime/pprof" and "go test -race -cpuprofile=prof.out runtime" both work now on linux/amd64.
Sign in to reply to this message.
The failure in tsan_func_enter was not a bug in your code. It was a bug in the race detector. I fixed it (CL 137910043). Please put the use of copy back.
Sign in to reply to this message.
LGTM https://codereview.appspot.com/132440043/diff/320001/src/pkg/runtime/cpuprof.go File src/pkg/runtime/cpuprof.go (right): https://codereview.appspot.com/132440043/diff/320001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:242: for i := range pc { use copy https://codereview.appspot.com/132440043/diff/320001/src/pkg/runtime/cpuprof.... src/pkg/runtime/cpuprof.go:265: log[q] = e.count too much math log[q] = e.count q++ log[q] = d q++ for ... { log[q] = ... q++ } p.nlog = q
Sign in to reply to this message.
On Mon, Sep 1, 2014 at 8:50 PM, <rsc@golang.org> wrote: > The failure in tsan_func_enter was not a bug in your code. It was a bug > in the race detector. I fixed it (CL 137910043). Please put the use of > copy back. I just tried, and it still fails on linux/amd64. I believe because at least gsignal->racectx needs to be initialized too. However, applying the same fix from CL 137910043 for gsignal to either proc.c:newm or os_linux.c:runtime.mpreinit doesn't seem sufficient. I still reliably get an "unexpected signal during runtime execution" SIGSEGV panic from "go test -race -run TestGoroutineSwitch runtime/pprof" (see below). $ go test -race -run TestGoroutineSwitch runtime/pprof fatal error: unexpected signal during runtime execution [signal 0xb code=0x2 addr=0xc20806b590 pc=0xc20806b590] runtime stack: runtime.throw(0x10792e5) /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/panic.c:515 +0x79 fp=0x7f8db8cc4e68 sp=0x7f8db8cc4e50 runtime: unexpected return pc for runtime.sigpanic called from 0xc20806b590 runtime.sigpanic() /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/os_linux.c:226 +0x44 fp=0x7f8db8cc4e80 sp=0x7f8db8cc4e68 goroutine 5 [running]: runtime.Gosched() /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.go:57 +0x29 fp=0xc20804be40 sp=0xc20804be30 runtime/pprof_test.TestGoroutineSwitch(0xc208058000) /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/pprof/pprof_test.go:241 +0x1f3 fp=0xc20804bf48 sp=0xc20804be40 testing.tRunner(0xc208058000, 0x1078308) /usr/local/google/home/mdempsky/wd/go4/src/pkg/testing/testing.go:427 +0x113 fp=0xc20804bf98 sp=0xc20804bf48 runtime.goexit() /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.c:1624 fp=0xc20804bfa0 sp=0xc20804bf98 created by testing.RunTests /usr/local/google/home/mdempsky/wd/go4/src/pkg/testing/testing.go:509 +0xb6d goroutine 1 [chan receive]: runtime.gopark(0x426c90, 0xc208050238, 0x5fbd70, 0xc) /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.go:79 +0xb3 fp=0xc20801bc00 sp=0xc20801bbd8 runtime.goparkunlock(0xc208050238, 0x5fbd70, 0xc) /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.go:84 +0x47 fp=0xc20801bc28 sp=0xc20801bc00 runtime.chanrecv(0x5803c0, 0xc2080501e0, 0xc20801bde8, 0x456801, 0x0) /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/chan.go:412 +0x37c fp=0xc20801bca0 sp=0xc20801bc28 runtime.chanrecv1(0x5803c0, 0xc2080501e0, 0xc20801bde8) /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/chan.go:314 +0x2b fp=0xc20801bcd0 sp=0xc20801bca0 testing.RunTests(0x63cc88, 0x10782c0, 0x6, 0x6, 0x5c0701) /usr/local/google/home/mdempsky/wd/go4/src/pkg/testing/testing.go:510 +0xbe2 fp=0xc20801be70 sp=0xc20801bcd0 testing.Main(0x63cc88, 0x10782c0, 0x6, 0x6, 0x1084f80, 0x0, 0x0, 0x1084f80, 0x0, 0x0) /usr/local/google/home/mdempsky/wd/go4/src/pkg/testing/testing.go:440 +0xa3 fp=0xc20801bee8 sp=0xc20801be70 main.main() runtime/pprof/_test/_testmain.go:57 +0xd8 fp=0xc20801bf40 sp=0xc20801bee8 runtime.main() /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.c:255 +0x10c fp=0xc20801bfa8 sp=0xc20801bf40 runtime.goexit() /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.c:1624 fp=0xc20801bfb0 sp=0xc20801bfa8 goroutine 2 [GC sweep wait]: runtime.park(0x426c90, 0x107cc50, 0x107b3d3, 0xd) /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.c:1550 +0x82 fp=0xc20801df50 sp=0xc20801df40 runtime.parkunlock(0x107cc50, 0x107b3d3, 0xd) /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.c:1566 +0x47 fp=0xc20801df78 sp=0xc20801df50 bgsweep() /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/mgc0.c:1071 +0xd0 fp=0xc20801dfa8 sp=0xc20801df78 runtime.goexit() /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.c:1624 fp=0xc20801dfb0 sp=0xc20801dfa8 created by gc /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/mgc0.c:1305 goroutine 3 [force gc (idle)]: runtime.gopark(0x426c90, 0x107d2b0, 0x5fcb90, 0xf) /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.go:79 +0xb3 fp=0xc208017f60 sp=0xc208017f38 runtime.goparkunlock(0x107d2b0, 0x5fcb90, 0xf) /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.go:84 +0x47 fp=0xc208017f88 sp=0xc208017f60 runtime.func·001() /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.go:43 +0xba fp=0xc208017fa8 sp=0xc208017f88 runtime.goexit() /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.c:1624 fp=0xc208017fb0 sp=0xc208017fa8 created by runtime.init·3 /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.go:50 +0x24 goroutine 4 [finalizer wait]: runtime.gopark(0x426c90, 0x107cd50, 0x5fc610, 0xe) /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.go:79 +0xb3 fp=0xc20804df10 sp=0xc20804dee8 runtime.goparkunlock(0x107cd50, 0x5fc610, 0xe) /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.go:84 +0x47 fp=0xc20804df38 sp=0xc20804df10 runtime.runfinq() /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/malloc.go:704 +0xab fp=0xc20804dfa8 sp=0xc20804df38 runtime.goexit() /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.c:1624 fp=0xc20804dfb0 sp=0xc20804dfa8 created by runtime.createfing /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/malloc.go:684 +0x5d goroutine 6 [syscall]: runtime.notetsleepg(0x7f8dc07ea008, 0xffffffffffffffff, 0x0) /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/lock_futex.go:202 +0x51 fp=0xc208019e98 sp=0xc208019e70 runtime.(*cpuProfile).getprofile(0x7f8dc07ea000, 0x0, 0x0, 0x0) /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/cpuprof.go:336 +0x4e0 fp=0xc208019f10 sp=0xc208019e98 runtime.CPUProfile(0x0, 0x0, 0x0) /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/cpuprof.go:416 +0x44 fp=0xc208019f38 sp=0xc208019f10 runtime/pprof.profileWriter(0x7f8dd8c6cf30, 0xc20805c000) /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/pprof/pprof.go:594 +0x31 fp=0xc208019f98 sp=0xc208019f38 runtime.goexit() /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/proc.c:1624 fp=0xc208019fa0 sp=0xc208019f98 created by runtime/pprof.StartCPUProfile /usr/local/google/home/mdempsky/wd/go4/src/pkg/runtime/pprof/pprof.go:588 +0x197 FAIL runtime/pprof 0.088s
Sign in to reply to this message.
Okay, leave the copy out and we can leave this for Dmitriy to fix. I am worried that the current situation is fragile, in that if copy fails, what's to stop any other instrumented thing from failing too. But if it works, we can leave that fragility for Dmitriy. Russ
Sign in to reply to this message.
*** Submitted as https://code.google.com/p/go/source/detail?r=bc9245d02338 *** runtime: convert cpuprof from C to Go LGTM=dvyukov, rsc R=golang-codereviews, dvyukov, rsc CC=golang-codereviews https://codereview.appspot.com/132440043 Committer: Russ Cox <rsc@golang.org>
Sign in to reply to this message.
This CL appears to have broken the windows-amd64 builder. See http://build.golang.org/log/5c8913d5e81b95c3ee4b03ad36fb3229414b0737
Sign in to reply to this message.
On Mon, Sep 1, 2014 at 9:13 PM, Russ Cox <rsc@golang.org> wrote: > Okay, leave the copy out and we can leave this for Dmitriy to fix. > I am worried that the current situation is fragile, in that if copy fails, > what's to stop any other instrumented thing from failing too. > But if it works, we can leave that fragility for Dmitriy. > Agreed and SGTM. I've filed http://code.google.com/p/go/issues/detail?id=8627 to track the issue.
Sign in to reply to this message.
On Mon, Sep 1, 2014 at 9:22 PM, <gobot@golang.org> wrote: > This CL appears to have broken the windows-amd64 builder. > See http://build.golang.org/log/5c8913d5e81b95c3ee4b03ad36fb3229414b0737 Looks like an unrelated flake. --- FAIL: TestReset (2.08s) sleep_test.go:360: resetting unfired timer returned false FAIL FAIL time 6.695s
Sign in to reply to this message.
Something is really screwed with timers on windows. On Tue, Sep 2, 2014 at 2:25 PM, 'Matthew Dempsky' via golang-codereviews <golang-codereviews@googlegroups.com> wrote: > On Mon, Sep 1, 2014 at 9:22 PM, <gobot@golang.org> wrote: >> >> This CL appears to have broken the windows-amd64 builder. >> See http://build.golang.org/log/5c8913d5e81b95c3ee4b03ad36fb3229414b0737 > > > Looks like an unrelated flake. > > --- FAIL: TestReset (2.08s) > sleep_test.go:360: resetting unfired timer returned false > FAIL > FAIL time 6.695s > > -- > You received this message because you are subscribed to the Google Groups > "golang-codereviews" group. > To unsubscribe from this group and stop receiving emails from it, send an > email to golang-codereviews+unsubscribe@googlegroups.com. > For more options, visit https://groups.google.com/d/optout.
Sign in to reply to this message.
|
||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
