Skip to content

time.Sleep goroutines locked #2190

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.

Sign up for GitHub

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

Jump to bottom
Closed
gopherbot opened this issue Aug 26, 2011 · 9 comments
Closed

time.Sleep goroutines locked #2190

gopherbot opened this issue Aug 26, 2011 · 9 comments
Labels
FrozenDueToAge

Comments

@gopherbot
Copy link
Contributor

by VisualFC:

The time.Sleep goroutines locked

What steps will reproduce the problem?

{{{

package main

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

var newTimerMutex sync.Mutex

func MutexSleep(ns int64) {
    newTimerMutex.Lock()
    t := time.NewTimer(ns)
    newTimerMutex.Unlock()
    <-t.C
}

func main() {
    ch := make(chan int)
    exit := make(chan bool)
    go func() {
        index := 0
        for {
            i := <-ch
            fmt.Printf("%d.", i)
            index++
            if index >= 100000 {
                break
            }
        }
        exit <- true
    }()
    for i := 0; i < 100000; i++ {
        go func(i int, ch chan int) {
            time.Sleep(1e9)
            //MutexSleep(1e9)
            ch <- i
        }(i, ch)
    }
    <-exit
}

}}}

What is the expected output?

runtime: failed to create new OS thread (have 
941 already; errno=11)
throw: runtime.newosproc

goroutine 942 [syscall]:
syscall.Syscall6()
    /home/win32/go/src/pkg/syscall/asm_linux_amd64.s:40 +0x5
syscall.Select(0x0, 0x0, 0x0, 0x0, 0xf84281c330, ...)
    /home/win32/go/src/pkg/syscall/zsyscall_linux_amd64.go:1008 +0x63
syscall.Sleep(0x3b9aca00, 0x0, 0xf84281c340, 0x41f77d)
    /home/win32/go/src/pkg/syscall/syscall_linux.go:189 +0x7a
time.sysSleep(0x3b9aca00, 0x0, 0x4e571ee8, 0x123d725925d91b70)
    /home/win32/go/src/pkg/time/sys_posix.go:13 +0x25
time.sleep(0x123d7258ea3e5170, 0x3b9aca00, 0x0, 0x0, 0x0, ...)
    /home/win32/go/src/pkg/time/sys.go:44 +0x40
time.Sleep(0x3b9aca00, 0x0, 0x0, 0x40c9f1)
    /home/win32/go/src/pkg/time/sys.go:33 +0x33
main._func_002(0xf8000003ab, 0xf8400019b0, 0x0, 0x0)
    /home/win32/dev/test.go:35 +0x24
created by main.main
    /home/win32/dev/test.go:38 +0xd5

What do you see instead?
application exceptsion

Which compiler are you using (5g, 6g, 8g, gccgo)?
6g,8g

Which operating system are you using?
CentOS6.0 WINDOWS7

Which revision are you using?  (hg identify)
weekly.2011-08-17 and 88744261dd47 tip

Please provide any additional information below.
use MutexSleep(1e9) the application normal
@rsc
Copy link
Contributor

rsc commented Aug 26, 2011

Comment 1:

Are you saying that the program prints that stack trace?
Or are you saying that the program crashes with
an application exception error?

Status changed to WaitingForReply.

@peterGo
Copy link
Contributor

peterGo commented Aug 27, 2011

Comment 2:

linux, 386, hg id 7fec8679f10d tip.
$ 8g 2190.go
$ 8l 2190.8
$ ./8.out 2> 2190.log
SIGTRAP: trace trap
PC=0x8059211
created by main.main
    /tmp/2190.go:38 +0xd6
goroutine 1 [chan receive]:
main.main()
    /tmp/2190.go:40 +0xfb
goroutine 2 [runnable]:
main._func_001(0x97741360, 0x977413f8, 0x0)
    /tmp/2190.go:24 +0x3b
created by main.main
    /tmp/2190.go:32 +0xab
goroutine 3 [runnable]:
syscall.Syscall6()
    /home/peter/go/src/pkg/syscall/asm_linux_386.s:59 +0x5b
syscall.Select(0x0, 0x0, 0x0, 0x0, 0x97741458, ...)
    /home/peter/go/src/pkg/syscall/zsyscall_linux_386.go:1098 +0x5b
syscall.Sleep(0x3b9aca00, 0x0, 0x4e58f8c2, 0x0)
    /home/peter/go/src/pkg/syscall/syscall_linux.go:189 +0x7e
time.sysSleep(0x3b9aca00, 0x0, 0x4e58f8c2, 0x0)
    /home/peter/go/src/pkg/time/sys_unix.go:13 +0x31
time.sleep(0xc777b628, 0x123de0ac, 0x3b9aca00, 0x0, 0x0, ...)
    /home/peter/go/src/pkg/time/sys.go:44 +0x5b
time.Sleep(0x3b9aca00, 0x0, 0x0, 0x0)
    /home/peter/go/src/pkg/time/sys.go:33 +0x45
main._func_002(0x0, 0x977425d0, 0x0)
    /tmp/2190.go:35 +0x31
created by main.main
    /tmp/2190.go:38 +0xd6
<< == SNIP == >>
goroutine 16944 [runnable]:
syscall.Syscall6()
    /home/peter/go/src/pkg/syscall/asm_linux_386.s:59 +0x5b
syscall.Select(0x0, 0x0, 0x0, 0x0, 0xa64bb630, ...)
    /home/peter/go/src/pkg/syscall/zsyscall_linux_386.go:1098 +0x5b
syscall.Sleep(0x3b9aca00, 0x0, 0x4e58f8c5, 0x0)
    /home/peter/go/src/pkg/syscall/syscall_linux.go:189 +0x7e
time.sysSleep(0x3b9aca00, 0x0, 0x4e58f8c5, 0x0)
    /home/peter/go/src/pkg/time/sys_unix.go:13 +0x31
time.sleep(0x727b63d0, 0x123de0ad, 0x3b9aca00, 0x0, 0x0, ...)
    /home/peter/go/src/pkg/time/sys.go:44 +0x5b
time.Sleep(0x3b9aca00, 0x0, 0x0, 0x0)
    /home/peter/go/src/pkg/time/sys.go:33 +0x45
main._func_002(0x422d, 0x977425d0, 0x0)
    /tmp/2190.go:35 +0x31
created by main.main
    /tmp/2190.go:38 +0xd6
goroutine 16946 [runnable]:
main._func_002(0x422f, 0x977425d0, 0x0)
    /tmp/2190.go:38
created by main.main
    /tmp/2190.go:38 +0xd6
<< == SNIP == >>
goroutine 100002 [runnable]:
main._func_002(0x1869f, 0x977425d0, 0x0)
    /tmp/2190.go:38
created by main.main
    /tmp/2190.go:38 +0xd6
eax     0xffffffea
ebx     0x1
ecx     0xafb85f8c
edx     0x10
edi     0x2000
esi     0x80540e7
ebp     0x98a57cb0
esp     0xafb85f7c
eip     0x8059211
eflags  0x202
cs      0x73
fs      0x0
gs      0xffff

@peterGo
Copy link
Contributor

peterGo commented Aug 27, 2011

Comment 3:

linux, amd64, hg id 5e1053337103 tip.
$ 6g 2190.go
$ 6l 2190.6
$ ./6.out > 2190.log 2>&1
runtime: failed to create new OS thread (have 32209 already; errno=12)
throw: runtime.newosproc
goroutine 83327 [syscall]:
syscall.Syscall6()
    /home/peter/go/src/pkg/syscall/asm_linux_amd64.s:40 +0x5
syscall.Select(0x0, 0x0, 0x0, 0x0, 0xf8a4900e10, ...)
    /home/peter/go/src/pkg/syscall/zsyscall_linux_amd64.go:1008 +0x63
syscall.Sleep(0x3b9aca00, 0x0, 0xf8a4900e00, 0x41f77d)
    /home/peter/go/src/pkg/syscall/syscall_linux.go:189 +0x7a
time.sysSleep(0x3b9aca00, 0x0, 0x4e59208b, 0x123de9f04fcc1ec8)
    /home/peter/go/src/pkg/time/sys_unix.go:13 +0x25
time.sleep(0x123de9f0143154c8, 0x3b9aca00, 0x0, 0x0, 0x0, ...)
    /home/peter/go/src/pkg/time/sys.go:44 +0x40
time.Sleep(0x3b9aca00, 0x0, 0x0, 0x40c9f1)
    /home/peter/go/src/pkg/time/sys.go:33 +0x33
main._func_002(0xf80001457c, 0xf8400019b0, 0x0, 0x0)
    /tmp/2190.go:35 +0x24
created by main.main
    /tmp/2190.go:38 +0xd5
goroutine 1 [chan receive]:
main.main()
    /tmp/2190.go:40 +0xfe
goroutine 2 [runnable]:
main._func_001(0xf8400001c8, 0xf8400001f8, 0x0, 0x0)
    /tmp/2190.go:24 +0x39
created by main.main
    /tmp/2190.go:32 +0xaa
goroutine 3 [runnable]:
syscall.Syscall6()
    /home/peter/go/src/pkg/syscall/asm_linux_amd64.s:61 +0x6a
syscall.Select(0x0, 0x0, 0x0, 0x0, 0xf8400025a0, ...)
    /home/peter/go/src/pkg/syscall/zsyscall_linux_amd64.go:1008 +0x63
syscall.Sleep(0x3b9aca00, 0x0, 0xf8400023e0, 0x41f77d)
    /home/peter/go/src/pkg/syscall/syscall_linux.go:189 +0x7a
time.sysSleep(0x3b9aca00, 0x0, 0x4e592088, 0x123de9ef84de0050)
    /home/peter/go/src/pkg/time/sys_unix.go:13 +0x25
time.sleep(0x123de9ef49433650, 0x3b9aca00, 0x0, 0x0, 0x0, ...)
    /home/peter/go/src/pkg/time/sys.go:44 +0x40
time.Sleep(0x3b9aca00, 0x0, 0x0, 0x40c9f1)
    /home/peter/go/src/pkg/time/sys.go:33 +0x33
main._func_002(0xf800000000, 0xf8400019b0, 0x0, 0x0)
    /tmp/2190.go:35 +0x24
created by main.main
    /tmp/2190.go:38 +0xd5
<< == SNIP == >>
goroutine 83326 [syscall]:
syscall.Syscall6()
    /home/peter/go/src/pkg/syscall/asm_linux_amd64.s:61 +0x6a
syscall.Select(0x0, 0x0, 0x0, 0x0, 0xf8a4900c10, ...)
    /home/peter/go/src/pkg/syscall/zsyscall_linux_amd64.go:1008 +0x63
syscall.Sleep(0x3b9aca00, 0x0, 0xf8a4900c00, 0x41f77d)
    /home/peter/go/src/pkg/syscall/syscall_linux.go:189 +0x7a
time.sysSleep(0x3b9aca00, 0x0, 0x4e59208b, 0x123de9f04fcb53a8)
    /home/peter/go/src/pkg/time/sys_unix.go:13 +0x25
time.sleep(0x123de9f0143089a8, 0x3b9aca00, 0x0, 0x0, 0x0, ...)
    /home/peter/go/src/pkg/time/sys.go:44 +0x40
time.Sleep(0x3b9aca00, 0x0, 0x0, 0x40c9f1)
    /home/peter/go/src/pkg/time/sys.go:33 +0x33
main._func_002(0xf80001457b, 0xf8400019b0, 0x0, 0x0)
    /tmp/2190.go:35 +0x24
created by main.main
    /tmp/2190.go:38 +0xd5
goroutine 83328 [runnable]:
main._func_002(0xf80001457d, 0xf8400019b0, 0x0, 0x0)
    /tmp/2190.go:38
created by main.main
    /tmp/2190.go:38 +0xd5
<< == SNIP == >>
goroutine 100002 [runnable]:
main._func_002(0xf80001869f, 0xf8400019b0, 0x0, 0x0)
    /tmp/2190.go:38
created by main.main
    /tmp/2190.go:38 +0xd5

@gopherbot
Copy link
Contributor Author

Comment 4 by VisualFC:

windows7, amd64, hg id 508513bbf607 tip, normal end of the program
Use time.Sleep: Create up to 28,000 up to over at the same time thread
Use MutexSleep: Has maintained 3 threads

@gopherbot
Copy link
Contributor Author

Comment 5 by VisualFC:

windows7, i386, hg id 508513bbf607 tip, exception end
runtime: memory allocated by OS not in usable range
runtime: out of memory: cannot allocate 65536-byte block (641728512 in use)
throw: out of memory
runtime.throw+0x42 /go/src/pkg/runtime/runtime.c:102
    runtime.throw(0x4b5078, 0x20)
runtime.MCache_Alloc+0x8e /go/src/pkg/runtime/mcache.c:26
    runtime.MCache_Alloc(0x734fd5c0, 0x8, 0x70, 0x1, 0x78a8f000, ...)
runtime.mallocgc+0xdf /go/src/pkg/runtime/malloc.c:47
    runtime.mallocgc(0x70, 0x0, 0x0, 0x1, 0x40d9e3, ...)
runtime.malloc+0x41 /go/src/pkg/runtime/malloc.c:97
    runtime.malloc(0x6c, 0x140)
runtime.malg+0x29 /go/src/pkg/runtime/proc.c:824
    runtime.malg(0xffffffff, 0x1)
matchmg+0x12d /go/src/pkg/runtime/proc.c:513
    matchmg()
runtime.entersyscall+0x3e /go/src/pkg/runtime/proc.c:628
    runtime.entersyscall()
runtime.syscall+0x64 /go/src/pkg/runtime/windows/thread.c:238
    runtime.syscall(0x752b1ef4, 0x1, 0x1162a704, 0x1162a718, 0x1, ...)
syscall.Syscall+0x40 /go/src/pkg/runtime/windows/syscall.c:36
    syscall.Syscall(0x752b1ef4, 0x1, 0x78a7eb08, 0x0, 0x0, ...)
syscall.GetSystemTimeAsFileTime+0x4a c:/go/src/pkg/syscall/zsyscall_windows_386.go:464
    syscall.GetSystemTimeAsFileTime(0x78a7eb08, 0x78a7eb08)
syscall.Gettimeofday+0x3a c:/go/src/pkg/syscall/syscall_windows.go:412
    syscall.Gettimeofday(0x78a7eb00, 0x78a7eb00, 0x0)
os.Time+0x60 c:/go/src/pkg/os/time.go:16
    os.Time(0x0, 0x0, 0x0, 0x0, 0x0, ...)
time.Nanoseconds+0x21 C:/go/src/pkg/time/sys.go:24
    time.Nanoseconds(0x0, 0x0)
time.Sleep+0x21 C:/go/src/pkg/time/sys.go:35
    time.Sleep(0x3b9aca00, 0x0, 0x0, 0x0)
main._func_002+0x30 F:/hg/GOBUG/timesleep.go:35
    main._func_002(0x858, 0x109257c0, 0x0)
runtime.goexit /go/src/pkg/runtime/proc.c:178
    runtime.goexit()
----- goroutine created by -----
main.main+0xd5 F:/hg/GOBUG/timesleep.go:38
goroutine 100002 [1]:
main._func_002 F:/hg/GOBUG/timesleep.go:38
    main._func_002(0x1869f, 0x109257c0, 0x0)
runtime.goexit /go/src/pkg/runtime/proc.c:178
    runtime.goexit()
----- goroutine created by -----
main.main+0xd5 F:/hg/GOBUG/timesleep.go:38
goroutine 100001 [1]:
main._func_002 F:/hg/GOBUG/timesleep.go:38
    main._func_002(0x1869e, 0x109257c0, 0x0)
runtime.goexit /go/src/pkg/runtime/proc.c:178
    runtime.goexit()
----- goroutine created by -----
main.main+0xd5 F:/hg/GOBUG/timesleep.go:38
...

@gopherbot
Copy link
Contributor Author

Comment 6 by VisualFC:

windows7-64, hg id 508513bbf607 tip, application crash exit
8g, 8l
runtime: failed to create new OS thread (have 1184 already; errno=8)
throw: runtime.newosproc
runtime.throw+0x42 /go/src/pkg/runtime/runtime.c:111
    runtime.throw(0x4b6ab3, 0x4a0)
runtime.newosproc+0xa5 /go/src/pkg/runtime/windows/thread.c:198
    runtime.newosproc(0x12034000, 0x12033e00)
matchmg+0x14f /go/src/pkg/runtime/proc.c:678
    matchmg()
runtime.entersyscall+0x12e /go/src/pkg/runtime/proc.c:819
    runtime.entersyscall()
runtime.syscall+0x64 /go/src/pkg/runtime/windows/thread.c:240
    runtime.syscall(0x752b10ef, 0x1, 0x327abf20, 0x327abf34, 0x0, ...)
syscall.Syscall+0x40 /go/src/pkg/runtime/windows/syscall.c:36
    syscall.Syscall(0x752b10ef, 0x1, 0x3e8, 0x0, 0x0, ...)
syscall.sleep+0x56 c:/go/src/pkg/syscall/zsyscall_windows_386.go:469
    syscall.sleep(0x3e8, 0x0)
syscall.Sleep+0x65 c:/go/src/pkg/syscall/syscall_windows.go:458
    syscall.Sleep(0x3b9aca00, 0x0, 0x4e5ae765, 0x0)
time.sysSleep+0x30 c:/go/src/pkg/time/sys_posix.go:13
    time.sysSleep(0x3b9aca00, 0x0, 0x4e5ae765, 0x0)
time.sleep+0x5a c:/go/src/pkg/time/sys.go:44
    time.sleep(0x49be39e8, 0x123e53d7, 0x3b9aca00, 0x0, 0x0, ...)
time.Sleep+0x44 c:/go/src/pkg/time/sys.go:33
    time.Sleep(0x3b9aca00, 0x0, 0x0, 0x0)
main._func_002+0x30 F:/hg/GOBUG/2190.go:35
    main._func_002(0x49d, 0x10921bd0, 0x0)
runtime.goexit /go/src/pkg/runtime/proc.c:246
    runtime.goexit()
----- goroutine created by -----
main.main+0xd5 F:/hg/GOBUG/2190.go:38
goroutine 100002 [4]:
runtime.gosched+0x55 /go/src/pkg/runtime/proc.c:769
    runtime.gosched()
runtime.semacquire+0xd8 /go/src/pkg/runtime/sema.c:102
    runtime.semacquire(0x1094f184, 0x0)
runtime.Semacquire+0x28 /go/src/pkg/runtime/sema.c:142
    runtime.Semacquire(0x1094f184, 0x61a79)
sync.(*Mutex).Lock+0xb9 c:/go/src/pkg/sync/mutex.go:61
    sync.(*Mutex).Lock(0x1094f180, 0x4062aa)
syscall.(*LazyProc).Addr+0x41 c:/go/src/pkg/syscall/syscall_windows.go:136
    syscall.(*LazyProc).Addr(0x1094f180, 0x0, 0x1)
syscall.GetSystemTimeAsFileTime+0x2a c:/go/src/pkg/syscall/zsyscall_windows_386.go:464
    syscall.GetSystemTimeAsFileTime(0x1163ee50, 0x1163ee50)
syscall.Gettimeofday+0x3a c:/go/src/pkg/syscall/syscall_windows.go:452
    syscall.Gettimeofday(0x1163ee48, 0x1163ee48, 0x0)
os.Time+0x60 c:/go/src/pkg/os/time.go:15
    os.Time(0x0, 0x0, 0x0, 0x0, 0x0, ...)
time.Nanoseconds+0x21 c:/go/src/pkg/time/sys.go:22
    time.Nanoseconds(0x0, 0x0)
time.Sleep+0x21 c:/go/src/pkg/time/sys.go:33
    time.Sleep(0x3b9aca00, 0x0, 0x0, 0x0)
main._func_002+0x30 F:/hg/GOBUG/2190.go:35
    main._func_002(0x1869f, 0x10921bd0, 0x0)
runtime.goexit /go/src/pkg/runtime/proc.c:246
    runtime.goexit()
----- goroutine created by -----
main.main+0xd5 F:/hg/GOBUG/2190.go:38
goroutine 100001 [4]:
runtime.gosched+0x55 /go/src/pkg/runtime/proc.c:769
    runtime.gosched()
runtime.semacquire+0xd8 /go/src/pkg/runtime/sema.c:102
    runtime.semacquire(0x1094f184, 0x0)
runtime.Semacquire+0x28 /go/src/pkg/runtime/sema.c:142
    runtime.Semacquire(0x1094f184, 0x61a75)
sync.(*Mutex).Lock+0xb9 c:/go/src/pkg/sync/mutex.go:61
    sync.(*Mutex).Lock(0x1094f180, 0x4062aa)
syscall.(*LazyProc).Addr+0x41 c:/go/src/pkg/syscall/syscall_windows.go:136
    syscall.(*LazyProc).Addr(0x1094f180, 0x0, 0x1)
syscall.GetSystemTimeAsFileTime+0x2a c:/go/src/pkg/syscall/zsyscall_windows_386.go:464
    syscall.GetSystemTimeAsFileTime(0x1163ee40, 0x1163ee40)
syscall.Gettimeofday+0x3a c:/go/src/pkg/syscall/syscall_windows.go:452
    syscall.Gettimeofday(0x1163ee38, 0x1163ee38, 0x0)
os.Time+0x60 c:/go/src/pkg/os/time.go:15
    os.Time(0x0, 0x0, 0x0, 0x0, 0x0, ...)
time.Nanoseconds+0x21 c:/go/src/pkg/time/sys.go:22
    time.Nanoseconds(0x0, 0x0)
time.Sleep+0x21 c:/go/src/pkg/time/sys.go:33
    time.Sleep(0x3b9aca00, 0x0, 0x0, 0x0)
main._func_002+0x30 F:/hg/GOBUG/2190.go:35
    main._func_002(0x1869e, 0x10921bd0, 0x0)
runtime.goexit /go/src/pkg/runtime/proc.c:246
    runtime.goexit()
----- goroutine created by -----
main.main+0xd5 F:/hg/GOBUG/2190.go:38

@gopherbot
Copy link
Contributor Author

Comment 7 by VisualFC:

windows7-64, hg id 508513bbf607 tip, application normal exit, but thread locked
6g, 6l
Use time.Sleep: Create up to 28,000 up to over at the same time thread
Use MutexSleep: Has maintained 3 threads

@gopherbot
Copy link
Contributor Author

Comment 8 by VisualFC:

weekly-0901 <-time.After (ns) can work. thanks.

@rsc
Copy link
Contributor

rsc commented Nov 9, 2011

Comment 9:

This issue was closed by revision 3b86026.

Status changed to Fixed.

@golang golang locked and limited conversation to collaborators Jun 24, 2016
This issue was closed.
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@rsc @peterGo @gopherbot