Skip to content

Instantly share code, notes, and snippets.

@liubin

liubin/chain.go

Last active August 29, 2015 13:56
Show Gist options
  • Save liubin/9130269 to your computer and use it in GitHub Desktop.
Save liubin/9130269 to your computer and use it in GitHub Desktop.
Download ZIP
Go Routine Test
Raw
chain.go
package main
import (
"fmt"
"time"
"runtime"
)
func f(left, right chan int) { left <- 1+<-right }
func main() {
cpu := runtime.NumCPU()
fmt.Println(cpu)
//runtime.GOMAXPROCS(cpu)
now := time.Now()
fmt.Println(now.Format("2006-01-02 15:04:05.000000000"))
leftmost := make(chan int)
var left, right chan int = nil, leftmost
for i := 0; i < 1000000; i++ {
left, right = right, make(chan int)
go f(left, right)
}
// kick off the chain
right <- 0
// wait for the leftmost to complete
_ = <-leftmost
now = time.Now()
fmt.Println(now.Format("2006-01-02 15:04:05.000000000"))
}
Raw
result
GOMAXPROCS set:
>2014-02-21 15:40:57.287118469
2014-02-21 15:41:52.029245088
Total 55s.
GOMAXPROCS NOT set:
>2014-02-21 15:34:58.615314211
2014-02-21 15:35:58.812819967
Total 60s
Raw
sample_GOMAXPROCS_not_set.txt
Sampling process 2254 for 3 seconds with 1 millisecond of run time between samples
Sampling completed, processing symbols...
Analysis of sampling chain (pid 2254) every 1 millisecond
Process: chain [2254]
Path: /private/var/folders/lj/mllcj29n0fx8swzgjwm8rbmw0000gn/T/go-build252697478/command-line-arguments/_obj/exe/chain
Load Address: 0x1000
Identifier: chain
Version: ???
Code Type: X86-64
Parent Process: go [2250]
Date/Time: 2014-02-21 15:35:17.401 +0800
OS Version: Mac OS X 10.9.1 (13B42)
Report Version: 7
Call graph:
2079 Thread_103622: Main Thread DispatchQueue_<multiple>
+ 1745 runtime.SysAlloc (in chain) + 83 [0xb033] mem_darwin.c:16
+ ! 1745 runtime.mmap (in chain) + 36 [0x22e04] sys_darwin_amd64.s:245
+ 218 runtime.memclr (in chain) + 25 [0x225e9] asm_amd64.s:786
+ 30 main.f (in chain) + 25,33 [0x2019,0x2021] chain.go:9
+ 18 stackcacherefill (in chain) + 184 [0x1b1d8] stack.c:43
+ 16 MHeap_AllocLocked (in chain) + 525 [0x1043d] mheap.c:176
+ 5 runtime.mallocgc (in chain) + 281 [0x1d8b9] malloc.goc:73
+ 3 runtime.MSpanList_IsEmpty (in chain) + 8 [0x11128] mheap.c:536
+ 3 runtime.SysMap (in chain) + 108 [0xb1fc] mem_darwin.c:66
+ ! 3 runtime.mmap (in chain) + 36 [0x22e04] sys_darwin_amd64.s:245
+ 2 MHeap_Grow (in chain) + 323 [0x10773] mheap.c:260
+ 2 runtime.casp (in chain) + 20 [0x22304] asm_amd64.s:509
+ 2 runtime.makechan_c (in chain) + 83,79 [0x5463,0x545f] chan.c:104
+ 2 runtime.markspan (in chain) + 173 [0xfa5d] mgc0.c:2435
+ 1 MHeap_AllocLocked (in chain) + 116 [0x102a4] mheap.c:119
+ 1 MHeap_AllocLocked (in chain) + 135 [0x102b7] mheap.c:134
+ 1 MHeap_AllocLocked (in chain) + 434 [0x103e2] mheap.c:171
+ 1 mstackalloc (in chain) + 39 [0x174d7] proc.c:1672
+ 1 runqget (in chain) + 116 [0x192e4] proc.c:2743
+ 1 runqput (in chain) + 113 [0x19251] proc.c:2719
+ 1 runqput (in chain) + 139 [0x1926b] proc.c:2723
+ ! 1 runtime.unlock (in chain) + 175 [0xa23f] lock_sema.c:118
+ 1 runtime.atomicloadp (in chain) + 5 [0x51d5] atomic_amd64.c:24
+ 1 runtime.casp (in chain) + 0 [0x222f0] asm_amd64.s:503
+ 1 runtime.casp (in chain) + 5 [0x222f5] asm_amd64.s:505
+ 1 runtime.casp (in chain) + 15 [0x222ff] asm_amd64.s:507
+ 1 runtime.chanrecv (in chain) + 1138 [0x5e72] chan.c:343
+ 1 runtime.lock (in chain) + 9 [0x9fb9] lock_sema.c:37
+ 1 runtime.malg (in chain) + 252 [0x1760c] proc.c:1698
+ 1 runtime.malg (in chain) + 188 [0x175cc] proc.c:1705
+ ! 1 runtime.memclr (in chain) + 33 [0x225f1] asm_amd64.s:791
+ 1 runtime.mallocgc (in chain) + 581 [0x1d9e5] malloc.goc:147
+ 1 runtime.mallocgc (in chain) + 161 [0x1d841] malloc.goc:65
+ 1 runtime.mallocgc (in chain) + 226 [0x1d882] malloc.goc:70
+ 1 runtime.markallocated (in chain) + 207 [0xf75f] mgc0.c:2348
+ 1 runtime.markspan (in chain) + 138 [0xfa3a] mgc0.c:2433
+ 1 runtime.mheap (in chain) + 32152 [0x180dd8]
+ ! 1 runtime.MCentral_AllocList (in chain) + 204 [0xaa3c] mcentral.c:59
+ 1 runtime.newproc (in chain) + 28 [0x1764c] proc.c:1727
+ ! 1 runtime.getcallerpc (in chain) + 9 [0x22609] asm_amd64.s:796
+ 1 runtime.newproc1 (in chain) + 97 [0x176f1] proc.c:1753
+ 1 runtime.park (in chain) + 21 [0x16825] proc.c:1337
+ 1 runtime.settype_flush (in chain) + 139 [0x1ea1b] malloc.goc:588
+ 1 runtime.stackalloc (in chain) + 251 [0x1b46b] stack.c:103
+ 1 runtime.stackalloc (in chain) + 272 [0x1b480] stack.c:105
+ 1 runtime.unlock (in chain) + 73 [0xa1d9] lock_sema.c:101
+ 1 runtime.xadd64 (in chain) + 0 [0x22330] asm_amd64.s:528
+ 1 runtime.xadd64 (in chain) + 18 [0x22342] asm_amd64.s:534
+ 1 stackcacherefill (in chain) + 123 [0x1b19b] stack.c:40
+ 1 stackcacherefill (in chain) + 188 [0x1b1dc] stack.c:42
+ 1 stackcacherefill (in chain) + 204 [0x1b1ec] stack.c:45
2079 Thread_103623
+ 2076 runtime.usleep (in chain) + 44 [0x22e8c] sys_darwin_amd64.s:281
+ 3 sysmon (in chain) + 112 [0x18740] proc.c:2367
2079 Thread_103624
+ 2079 runtime.semasleep (in chain) + 83 [0x11ce3] os_darwin.c:407
+ 2079 runtime.mach_semaphore_timedwait (in chain) + 19 [0x22fb3] sys_darwin_amd64.s:404
2079 Thread_103625
2079 runtime.semasleep (in chain) + 161 [0x11d31] os_darwin.c:414
2079 runtime.mach_semaphore_wait (in chain) + 11 [0x22f9b] sys_darwin_amd64.s:395
Total number in stack (recursive counted multiple, when >=5):
Sort by top of stack, same collapsed (when >= 5):
runtime.mach_semaphore_timedwait (in chain) 2079
runtime.mach_semaphore_wait (in chain) 2079
runtime.usleep (in chain) 2076
runtime.mmap (in chain) 1748
runtime.memclr (in chain) 219
main.f (in chain) 30
stackcacherefill (in chain) 21
MHeap_AllocLocked (in chain) 19
runtime.mallocgc (in chain) 8
runtime.casp (in chain) 5
Binary Images:
0x1000 - 0x15f07d +chain (???) /var/folders/lj/mllcj29n0fx8swzgjwm8rbmw0000gn/T/go-build252697478/command-line-arguments/_obj/exe/chain
0x7fff69236000 - 0x7fff69269817 dyld (239.3 - ???) <D1DFCF3F-0B0C-332A-BCC0-87A851B570FF> /usr/lib/dyld
Sample analysis of process 2254 written to file /dev/stdout
Raw
sample_GOMAXPROCS_set.txt
Sampling process 2288 for 3 seconds with 1 millisecond of run time between samples
Sampling completed, processing symbols...
Analysis of sampling chain (pid 2288) every 1 millisecond
Process: chain [2288]
Path: /private/var/folders/lj/mllcj29n0fx8swzgjwm8rbmw0000gn/T/go-build748000908/command-line-arguments/_obj/exe/chain
Load Address: 0x1000
Identifier: chain
Version: ???
Code Type: X86-64
Parent Process: go [2284]
Date/Time: 2014-02-21 15:41:18.155 +0800
OS Version: Mac OS X 10.9.1 (13B42)
Report Version: 7
Call graph:
2102 Thread_106667: Main Thread DispatchQueue_<multiple>
+ 2065 runtime.semasleep (in chain) + 161 [0x11d51] os_darwin.c:414
+ ! 2065 runtime.mach_semaphore_wait (in chain) + 11 [0x230db] sys_darwin_amd64.s:395
+ 21 stopm (in chain) + 240 [0x158f0] proc.c:933
+ 6 runtime.mach_semrelease (in chain) + 37 [0x11da5] os_darwin.c:427
+ ! 6 runtime.mach_semaphore_signal (in chain) + 11 [0x2310b] sys_darwin_amd64.s:411
+ 1 ??? (in <unknown binary>) [0x7469622d343620]
+ ! 1 runtime.nanotime (in chain) + 18 [0x22d82] sys_darwin_amd64.s:109
+ 1 findrunnable (in chain) + 505 [0x16269] proc.c:1172
+ 1 findrunnable (in chain) + 1144 [0x164e8] proc.c:1179
+ 1 main.f (in chain) + 33 [0x2021] chain.go:9
+ 1 resetspinning (in chain) + 138 [0x165aa] proc.c:1257
+ 1 runtime.atomicloadp (in chain) + 0 [0x51f0] atomic_amd64.c:24
+ 1 runtime.chanrecv (in chain) + 0 [0x5a20] chan.c:288
+ 1 runtime.mach_semaphore_signal (in chain) + 4 [0x23104] sys_darwin_amd64.s:409
+ 1 runtime.semasleep (in chain) + 161 [0x11d51] os_darwin.c:414
+ 1 runtime.unlock (in chain) + 167 [0xa257] lock_sema.c:117
2102 Thread_106668
+ 2100 runtime.usleep (in chain) + 44 [0x22fcc] sys_darwin_amd64.s:281
+ 2 sysmon (in chain) + 112 [0x18840] proc.c:2367
2102 Thread_106669
+ 2102 runtime.semasleep (in chain) + 83 [0x11d03] os_darwin.c:407
+ 2102 runtime.mach_semaphore_timedwait (in chain) + 19 [0x230f3] sys_darwin_amd64.s:404
2102 Thread_106670
+ 1319 runtime.semasleep (in chain) + 161 [0x11d51] os_darwin.c:414
+ ! 1319 runtime.mach_semaphore_wait (in chain) + 11 [0x230db] sys_darwin_amd64.s:395
+ 619 runtime.SysAlloc (in chain) + 83 [0xb053] mem_darwin.c:16
+ ! 619 runtime.mmap (in chain) + 36 [0x22f44] sys_darwin_amd64.s:245
+ 92 runtime.memclr (in chain) + 25 [0x22729] asm_amd64.s:786
+ 12 MHeap_AllocLocked (in chain) + 525 [0x1045d] mheap.c:176
+ 12 stackcacherefill (in chain) + 184 [0x1b2d8] stack.c:43
+ 11 stopm (in chain) + 240,234 [0x158f0,0x158ea] proc.c:933
+ 9 runtime.mach_semrelease (in chain) + 37 [0x11da5] os_darwin.c:427
+ ! 9 runtime.mach_semaphore_signal (in chain) + 11 [0x2310b] sys_darwin_amd64.s:411
+ 3 runtime.casp (in chain) + 20 [0x22444] asm_amd64.s:509
+ 2 runtime.xadd64 (in chain) + 18 [0x22482] asm_amd64.s:534
+ 1 execute (in chain) + 109 [0x15ffd] proc.c:1117
+ 1 findrunnable (in chain) + 279 [0x16187] proc.c:1165
+ ! 1 runtime.atomicload (in chain) + 7 [0x51d7] atomic_amd64.c:10
+ 1 findrunnable (in chain) + 430 [0x1621e] proc.c:1175
+ 1 main.f (in chain) + 38 [0x2026] chain.go:9
+ 1 runqget (in chain) + 9 [0x19379] proc.c:2728
+ 1 runtime.MSpanList_IsEmpty (in chain) + 8 [0x11148] mheap.c:536
+ 1 runtime.MSpan_Init (in chain) + 5 [0x11085] mheap.c:499
+ 1 runtime.atomicload (in chain) + 0 [0x51d0] atomic_amd64.c:10
+ 1 runtime.makechan_c (in chain) + 208 [0x5500] chan.c:107
+ 1 runtime.malg (in chain) + 193 [0x175f1] proc.c:1707
+ 1 runtime.malloc (in chain) + 57 [0x1dde9] malloc.goc:153
+ ! 1 runtime.mallocgc (in chain) + 588 [0x1daec] malloc.goc:147
+ 1 runtime.mallocgc (in chain) + 46 [0x1d8ce] malloc.goc:50
+ 1 runtime.mallocgc (in chain) + 281 [0x1d9b9] malloc.goc:73
+ 1 runtime.markallocated (in chain) + 111 [0xf71f] mgc0.c:2341
+ 1 runtime.markallocated (in chain) + 118 [0xf726] mgc0.c:2345
+ 1 runtime.markspan (in chain) + 197 [0xfa95] mgc0.c:2435
+ 1 runtime.netpoll (in chain) + 29 [0x1149d] netpoll_kqueue.c:65
+ 1 runtime.newproc1 (in chain) + 245 [0x177a5] proc.c:1776
+ ! 1 runtime.memclr (in chain) + 33 [0x22731] asm_amd64.s:791
+ 1 runtime.notesleep (in chain) + 199 [0xa427] lock_sema.c:164
+ 1 runtime.settype_flush (in chain) + 277 [0x1eba5] malloc.goc:603
+ 1 schedule (in chain) + 275 [0x167a3] proc.c:1331
+ 1 startm (in chain) + 34 [0x159b2] proc.c:958
+ 1 wakep (in chain) + 66 [0x15cc2] proc.c:1034
2102 Thread_106671
+ 1776 runtime.semasleep (in chain) + 161 [0x11d51] os_darwin.c:414
+ ! 1776 runtime.mach_semaphore_wait (in chain) + 11 [0x230db] sys_darwin_amd64.s:395
+ 249 runtime.SysAlloc (in chain) + 83 [0xb053] mem_darwin.c:16
+ ! 249 runtime.mmap (in chain) + 36 [0x22f44] sys_darwin_amd64.s:245
+ 25 runtime.memclr (in chain) + 25 [0x22729] asm_amd64.s:786
+ 19 stopm (in chain) + 240 [0x158f0] proc.c:933
+ 9 runtime.mach_semrelease (in chain) + 37 [0x11da5] os_darwin.c:427
+ ! 9 runtime.mach_semaphore_signal (in chain) + 11 [0x2310b] sys_darwin_amd64.s:411
+ 2 MHeap_AllocLocked (in chain) + 525 [0x1045d] mheap.c:176
+ 2 findrunnable (in chain) + 320,336 [0x161b0,0x161c0] proc.c:1167
+ 2 runqsteal (in chain) + 38,41 [0x19516,0x19519] proc.c:2786
+ 2 runtime.semasleep (in chain) + 161 [0x11d51] os_darwin.c:414
+ 2 stackcacherefill (in chain) + 184 [0x1b2d8] stack.c:43
+ 1 MHeap_AllocLocked (in chain) + 528 [0x10460] mheap.c:177
+ 1 runqget (in chain) + 9 [0x19379] proc.c:2728
+ 1 runtime.MSpanList_IsEmpty (in chain) + 8 [0x11148] mheap.c:536
+ 1 runtime.atomicload (in chain) + 5 [0x51d5] atomic_amd64.c:10
+ 1 runtime.casp (in chain) + 0 [0x22430] asm_amd64.s:503
+ 1 runtime.casp (in chain) + 20 [0x22444] asm_amd64.s:509
+ 1 runtime.chanrecv (in chain) + 1180 [0x5ebc] chan.c:349
+ 1 runtime.lock (in chain) + 14 [0x9fde] lock_sema.c:37
+ 1 runtime.mach_semrelease (in chain) + 37 [0x11da5] os_darwin.c:427
+ 1 runtime.mallocgc (in chain) + 192 [0x1d960] malloc.goc:68
+ 1 runtime.mheap (in chain) + 32152 [0x180dd8]
+ ! 1 runtime.MCentral_AllocList (in chain) + 148 [0xaa24] mcentral.c:53
+ 1 runtime.xadd (in chain) + 5 [0x22455] asm_amd64.s:521
+ 1 stackcacherefill (in chain) + 188 [0x1b2dc] stack.c:42
+ 1 startm (in chain) + 34 [0x159b2] proc.c:958
2102 Thread_106672
+ 2102 runtime.semasleep (in chain) + 161 [0x11d51] os_darwin.c:414
+ 2102 runtime.mach_semaphore_wait (in chain) + 11 [0x230db] sys_darwin_amd64.s:395
2102 Thread_106673
+ 1014 runtime.semasleep (in chain) + 161 [0x11d51] os_darwin.c:414
+ ! 1014 runtime.mach_semaphore_wait (in chain) + 11 [0x230db] sys_darwin_amd64.s:395
+ 885 runtime.SysAlloc (in chain) + 83 [0xb053] mem_darwin.c:16
+ ! 885 runtime.mmap (in chain) + 36 [0x22f44] sys_darwin_amd64.s:245
+ 121 runtime.memclr (in chain) + 25 [0x22729] asm_amd64.s:786
+ 13 MHeap_AllocLocked (in chain) + 525 [0x1045d] mheap.c:176
+ 12 stopm (in chain) + 240,234 [0x158f0,0x158ea] proc.c:933
+ 10 stackcacherefill (in chain) + 184 [0x1b2d8] stack.c:43
+ 9 runtime.mach_semrelease (in chain) + 37 [0x11da5] os_darwin.c:427
+ ! 9 runtime.mach_semaphore_signal (in chain) + 11 [0x2310b] sys_darwin_amd64.s:411
+ 4 runtime.casp (in chain) + 20 [0x22444] asm_amd64.s:509
+ 2 MHeap_AllocLocked (in chain) + 135 [0x102d7] mheap.c:134
+ 2 runqsteal (in chain) + 38 [0x19516] proc.c:2786
+ 2 runtime.MSpanList_IsEmpty (in chain) + 8 [0x11148] mheap.c:536
+ 2 runtime.markallocated (in chain) + 118,171 [0xf726,0xf75b] mgc0.c:2345
+ 2 runtime.markspan (in chain) + 173,170 [0xfa7d,0xfa7a] mgc0.c:2435
+ 2 runtime.usleep (in chain) + 44 [0x22fcc] sys_darwin_amd64.s:281
+ 2 runtime.xadd64 (in chain) + 18 [0x22482] asm_amd64.s:534
+ 1 MHeap_AllocLocked (in chain) + 87 [0x102a7] mheap.c:118
+ 1 MHeap_AllocLocked (in chain) + 163 [0x102f3] mheap.c:136
+ 1 MHeap_AllocLocked (in chain) + 528 [0x10460] mheap.c:177
+ 1 mget (in chain) + 25 [0x190d9] proc.c:2629
+ 1 resetspinning (in chain) + 25 [0x16539] proc.c:1246
+ 1 runqput (in chain) + 61 [0x1931d] proc.c:2715
+ 1 runtime.FixAlloc_Alloc (in chain) + 221 [0xbb5d] mfixalloc.c:50
+ 1 runtime.MSpanList_IsEmpty (in chain) + 0 [0x11140] mheap.c:534
+ 1 runtime.SysMap (in chain) + 108 [0xb21c] mem_darwin.c:66
+ ! 1 runtime.mmap (in chain) + 36 [0x22f44] sys_darwin_amd64.s:245
+ 1 runtime.chanrecv (in chain) + 30 [0x5a3e] chan.c:298
+ 1 runtime.chanrecv (in chain) + 1138 [0x5e92] chan.c:343
+ 1 runtime.gostartcallfn (in chain) + 42 [0x1c01a] stack.c:373
+ 1 runtime.makechan_c (in chain) + 174 [0x54de] chan.c:112
+ 1 runtime.mallocgc (in chain) + 100 [0x1d904] malloc.goc:55
+ 1 runtime.mallocgc (in chain) + 180 [0x1d954] malloc.goc:65
+ 1 runtime.mallocgc (in chain) + 281 [0x1d9b9] malloc.goc:73
+ 1 runtime.netpoll (in chain) + 44 [0x114ac] netpoll_kqueue.c:73
+ 1 runtime.unlock (in chain) + 30 [0xa1ce] lock_sema.c:99
+ 1 schedule (in chain) + 249 [0x16789] proc.c:1324
+ 1 stackcacherefill (in chain) + 188 [0x1b2dc] stack.c:42
2102 Thread_106674
+ 2102 runtime.semasleep (in chain) + 161 [0x11d51] os_darwin.c:414
+ 2102 runtime.mach_semaphore_wait (in chain) + 11 [0x230db] sys_darwin_amd64.s:395
2102 Thread_106675
+ 2102 runtime.semasleep (in chain) + 161 [0x11d51] os_darwin.c:414
+ 2102 runtime.mach_semaphore_wait (in chain) + 11 [0x230db] sys_darwin_amd64.s:395
2102 Thread_106676
2102 runtime.semasleep (in chain) + 161 [0x11d51] os_darwin.c:414
2102 runtime.mach_semaphore_wait (in chain) + 11 [0x230db] sys_darwin_amd64.s:395
Total number in stack (recursive counted multiple, when >=5):
8 runtime.mach_semaphore_wait (in chain) + 0 [0x230d0] sys_darwin_amd64.s:395
8 runtime.semasleep (in chain) + 161 [0x11d51] os_darwin.c:414
Sort by top of stack, same collapsed (when >= 5):
runtime.mach_semaphore_wait (in chain) 14582
runtime.mach_semaphore_timedwait (in chain) 2102
runtime.usleep (in chain) 2102
runtime.mmap (in chain) 1754
runtime.memclr (in chain) 239
stopm (in chain) 63
runtime.mach_semaphore_signal (in chain) 34
MHeap_AllocLocked (in chain) 33
stackcacherefill (in chain) 26
runtime.casp (in chain) 9
runtime.mallocgc (in chain) 7
findrunnable (in chain) 5
runtime.MSpanList_IsEmpty (in chain) 5
Binary Images:
0x1000 - 0x15f3c5 +chain (???) /var/folders/lj/mllcj29n0fx8swzgjwm8rbmw0000gn/T/go-build748000908/command-line-arguments/_obj/exe/chain
0x7fff6d604000 - 0x7fff6d637817 dyld (239.3 - ???) <D1DFCF3F-0B0C-332A-BCC0-87A851B570FF> /usr/lib/dyld
Sample analysis of process 2288 written to file /dev/stdout
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment