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

syscall: fork blocks the process #5717

Closed
pierrre opened this issue Jun 16, 2013 · 17 comments
Closed

syscall: fork blocks the process #5717

pierrre opened this issue Jun 16, 2013 · 17 comments

Comments

@pierrre
Copy link

@pierrre pierrre commented Jun 16, 2013

What steps will reproduce the problem?
http://play.golang.org/p/cbQIfyHasD


What is the expected output?
Low value for http request duration


What do you see instead?

High value (200-300ms) with GOMAXPROCS=1
Low value (1ms) with GOMAXPROCS=2, but os/exec.Command.Run() takes 300ms

If the command is not executed, the code is fast.


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


Which operating system are you using?
Ubuntu 13.04 64 bits


Which version are you using?  (run 'go version')
go version go1.1.1 linux/amd64


Please provide any additional information below.
Google Groups:
https://groups.google.com/forum/?fromgroups=#!topic/golang-nuts/58_jSKTeSzE
@dvyukov
Copy link
Member

@dvyukov dvyukov commented Jun 17, 2013

Comment 1:

This is related to https://golang.org/issue/5517
Fork takes 15-20ms and it completely blocks process.
@gopherbot
Copy link

@gopherbot gopherbot commented Jun 18, 2013

Comment 2 by jim.robinson:

>> The problem is with fork() call with 2.2GB heap size. It takes 
>> ~10-20ms and is called with RawSyscall, so nothing can happen 
>> meanwhile. 
I was planning on doing something similar with a server I'm  writing, where I would
periodically make calls to uptime(1) to get  ahold of the load average.
Dmitry notes that "things are not that bad with GOMAXPROCS>1, fork block  only 1 thread.
"
@robpike
Copy link
Contributor

@robpike robpike commented Jul 8, 2013

Comment 3:

Forking on every request is expensive.

Labels changed: added priority-later, removed priority-triage.

Status changed to Accepted.

@adg
Copy link
Contributor

@adg adg commented Jul 8, 2013

Comment 4:

The title of this issue is wrong.
Is it a problem with os/exec or the runtime?
@minux
Copy link
Member

@minux minux commented Jul 8, 2013

Comment 5:

one alternative is to fix issue #5838.
@dvyukov
Copy link
Member

@dvyukov dvyukov commented Jul 16, 2013

Comment 6:

>Is it a problem with os/exec or the runtime?
The problem is with os/exec.
>Forking on every request is expensive.
It is unnecessary expensive.
@rsc
Copy link
Contributor

@rsc rsc commented Jul 16, 2013

Comment 7:

It cannot possibly be os/exec's fault. os/exec is a wrapper.
I don't understand the problem, but whatever it is, it must be in package runtime or
package syscall.
@rsc
Copy link
Contributor

@rsc rsc commented Jul 16, 2013

Comment 8:

Also, if this is about the memory usage, is this a dup of 5838?
@dvyukov
Copy link
Member

@dvyukov dvyukov commented Jul 16, 2013

Comment 9:

changed to syscall
it is not about memory usage
the problem is that fork call is "nonblocking" from the point of view of runtime, so it
does not schedule other goroutines during fork. In reality fork can take 20+ms, and I
suspect be mostly blocking (swap or something).
if we just make it a normal syscall, it will hang in child (runtime mutexes can be
locked). however if we skip exitsyscall in child it should do the trick.
@dvyukov
Copy link
Member

@dvyukov dvyukov commented Jul 31, 2013

Comment 10:

Simpler reproducer:
package main
import (
    "fmt"
    "os/exec"
    "time"
)
//var ballast = make([][]byte, 2e8)
func main() {
    go func() {
        prev := time.Now()
        for now := range time.NewTicker(time.Millisecond).C {
            fmt.Println(now.Sub(prev))
            prev = now
        }   
    }()
    for {
        exec.Command("ls").CombinedOutput()
    }
}
With the ballast there are that 15ms delays:
999.337us
996.273us
1.001548ms
1.003009ms
1.000131ms
1.022096ms
15.632691ms
321.769us
995.469us
999.496us
1.000067ms
999.972us
1.000004ms
1.000169ms
999.43us
16.426056ms
583.624us
990.718us
1.012777ms
987.411us
999.783us
999.792us
1.000195ms
999.824us
15.317368ms
687.186us
995.589us
999.954us
@dvyukov
Copy link
Member

@dvyukov dvyukov commented Jul 31, 2013

Comment 11:

The problem is that fork on linux uses RawSyscall, so it completely blocks the process.
One solution may be to carefully use vfork, it should be much faster.
Another solution may be to carefully use entersyscall/exitsyscall
around fork, but the child process must not execute exitsyscall
because it can deadlock.
@dvyukov
Copy link
Member

@dvyukov dvyukov commented Jul 31, 2013

Comment 12:

Unfortunately it's not a problem with Go runtime.
Even if I call entersyscallblock/exitsyscall around fork, OS blocks syscalls in other
threads for the duration of fork:
[pid 29109] 23:18:19.586480 fork( <unfinished ...>
[pid 29114] 23:18:19.586490 <... futex resumed> ) = 0 <0.001167>
[pid 29113] 23:18:19.586500 <... futex resumed> ) = 1 <0.000028>
[pid 29114] 23:18:19.586511 write(1, "1.262156ms\n", 11 <unfinished ...>
[pid 29113]Process 29162 attached (waiting for parent)
 <unfinished ...>
[pid 29114] 23:18:19.602308 <... write resumed> ) = 11 <0.000046>
[pid 29110] 23:18:19.602320 <... select resumed> ) = 0 (Timeout) <0.015898>
Process 29162 resumed (parent 29109 ready)
[pid 29109] 23:18:19.602336 <... fork resumed> ) = 29162 <0.015844>
You can see that fork takes 15ms, and so write in another thread also takes 15ms.
@dvyukov
Copy link
Member

@dvyukov dvyukov commented Aug 8, 2013

Comment 13:

Labels changed: added performance.

@rsc
Copy link
Contributor

@rsc rsc commented Nov 27, 2013

Comment 14:

Labels changed: added go1.3maybe.

@rsc
Copy link
Contributor

@rsc rsc commented Dec 4, 2013

Comment 15:

Labels changed: added release-none, removed go1.3maybe.

@rsc
Copy link
Contributor

@rsc rsc commented Dec 4, 2013

Comment 16:

Labels changed: added repo-main.

@rsc rsc added this to the Unplanned milestone Apr 10, 2015
@bradfitz
Copy link
Contributor

@bradfitz bradfitz commented Feb 2, 2017

I'm going to close this in favor of the more active #5838 currently targeting Go 1.9.

@bradfitz bradfitz closed this Feb 2, 2017
@golang golang locked and limited conversation to collaborators Feb 2, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
8 participants
You can’t perform that action at this time.