runtime: LockOSThread: unexpected gopreempt

[ChenYahui2019]

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

$ go version
go version go1.13.4 linux/amd64

Does this issue reproduce with the latest release?

NA

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

go env Output

$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/root/.cache/go-build"
GOENV="/root/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/root/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/lib/golang"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/lib/golang/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build467654165=/tmp/go-build -gno-record-gcc-switches"

What did you do?

I am trying to use runtime.LockOSThread() bind G and M, unexpectedly, I discover gopreempt actions on this G.

Here's the code:

package main

import "runtime"
import "time"

// go build -gcflags '-N -l'
func a() {
        i := 10000000
        j := 0
        k := 0

        for i > 0 {
                i--
                j++
        }
        if i > j {
                k++
        }
        if i < j {
                k++
        }
        b(i,j,k)
}

func b(i,j,k int) int{
        temp:=i*j+k
        temp = temp+1
        return temp
}

func main() {
        go func() {
                runtime.LockOSThread()
                i := 0
                for true {
                        i++
                        a()
                }
        }()
        time.Sleep(time.Hour)
}

What did you expect to see?

No preempt, G keep running always

What did you see instead?

Belows are my debugging steps:

$ pidstat -p 12692 -t 1
Linux 3.10.0-862.el7.x86_64 (openstack-22) 12/13/2019 x86_64 (24 CPU)

03:42:47 PM UID TGID TID %usr %system %guest %CPU CPU Command
03:42:48 PM 0 12692 - 100.00 0.00 0.00 100.00 8 lockosthread
03:42:48 PM 0 - 12692 0.00 0.00 0.00 0.00 8 |__lockosthread
03:42:48 PM 0 - 12693 0.00 0.00 0.00 0.00 11 |__lockosthread
03:42:48 PM 0 - 12694 100.00 0.00 0.00 100.00 21 |__lockosthread
03:42:48 PM 0 - 12695 0.00 0.00 0.00 0.00 23 |__lockosthread
03:42:48 PM 0 - 12696 0.00 0.00 0.00 0.00 11 |__lockosthread
03:42:48 PM 0 - 12697 0.00 0.00 0.00 0.00 23 |__lockosthread

03:42:48 PM UID TGID TID %usr %system %guest %CPU CPU Command
03:42:49 PM 0 12692 - 100.00 0.00 0.00 100.00 8 lockosthread
03:42:49 PM 0 - 12692 0.00 0.00 0.00 0.00 8 |__lockosthread
03:42:49 PM 0 - 12693 0.00 0.00 0.00 0.00 11 |__lockosthread
03:42:49 PM 0 - 12694 100.00 0.00 0.00 100.00 21 |__lockosthread
03:42:49 PM 0 - 12695 0.00 0.00 0.00 0.00 23 |__lockosthread
03:42:49 PM 0 - 12696 0.00 0.00 0.00 0.00 11 |__lockosthread
03:42:49 PM 0 - 12697 0.00 0.00 0.00 0.00 23 |__lockosthread
^C

Average: UID TGID TID %usr %system %guest %CPU CPU Command
Average: 0 12692 - 100.00 0.00 0.00 100.00 - lockosthread
Average: 0 - 12692 0.00 0.00 0.00 0.00 - |__lockosthread
Average: 0 - 12693 0.00 0.00 0.00 0.00 - |__lockosthread
Average: 0 - 12694 100.00 0.00 0.00 100.00 - |__lockosthread
Average: 0 - 12695 0.00 0.00 0.00 0.00 - |__lockosthread
Average: 0 - 12696 0.00 0.00 0.00 0.00 - |__lockosthread
Average: 0 - 12697 0.00 0.00 0.00 0.00 - |__lockosthread

$ strace -p 12694 -ttT
strace: Process 12694 attached
15:43:17.197854 futex(0xc000078148, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000021>
15:43:17.229295 futex(0xc000078148, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000017>
15:43:17.260622 futex(0xc000078148, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000018>
15:43:17.291778 futex(0xc000078148, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000017>
15:43:17.323010 futex(0xc000078148, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000014>
15:43:17.354231 futex(0xc000078148, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000018>
15:43:17.385496 futex(0xc000078148, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000021>
15:43:17.416749 futex(0xc000078148, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000021>
15:43:17.448026 futex(0xc000078148, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000021>
15:43:17.479394 futex(0xc000078148, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000021>
15:43:17.510628 futex(0xc000078148, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000021>
15:43:17.541912 futex(0xc000078148, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000020>
15:43:17.573335 futex(0xc000078148, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000021>
15:43:17.604672 futex(0xc000078148, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000021>

// as above show, about every 31ms has a futex
// as below show, goroutine preempt happened when calling futex

(dlv) bt
0 0x000000000042d88f in runtime.gopreempt_m
at /usr/lib/golang/src/runtime/proc.go:2649
1 0x0000000000456ba5 in main.a
at ./lockosthread.go:7
2 0x0000000000456c9e in main.main.func1
at ./lockosthread.go:37
3 0x000000000044d191 in runtime.goexit
at /usr/lib/golang/src/runtime/asm_amd64.s:1357
(dlv) goroutine
Thread 12694 at /usr/lib/golang/src/runtime/proc.go:2649
Goroutine 5:
Runtime: /usr/lib/golang/src/runtime/proc.go:2649 runtime.gopreempt_m (0x42d88f)
User: ./lockosthread.go:7 main.a (0x456ba5)
Go: ./lockosthread.go:32 main.main (0x456c35)
Start: ./lockosthread.go:32 main.main.func1 (0x456c60)

[toothrot]

/cc @aclements

[ianlancetaylor]

Locking a goroutine to a thread does not mean that the thread will not be preempted. It means that when the goroutine is scheduled to run, it will only run on the thread to which it has been locked. And it means that that thread will only run the goroutine that has been locked to it. LockOSThread has nothing to do with preemption.

[reusee]

A G will be force preempted after running for 10ms:

go/src/runtime/proc.go

Line 4564 in 7d30af8

// forcePreemptNS is the time slice given to a G before it is

and

go/src/runtime/proc.go

Line 4535 in 7d30af8

// and preempt long running G's

[ChenYahui2019]

@ianlancetaylor Thank for your response. LockOSThread means only this G could be able to run on the M. You could take a try for these code below, two OS thread's CPU usage are both 50%.

package main

import "runtime"
import "time"

// go build -gcflags '-N -l'
func a() {
        i := 1000
        j := 0
        k := 0

        for i > 0 {
                i--
                j++
        }
        if i > j {
                k++
        }
        if i < j {
                k++
        }
        b(i,j,k)
}

func b(i,j,k int) int{
        temp:=i*j+k
        temp = temp+1
        return temp
}

func main() {
        runtime.GOMAXPROCS(1)
        go func() {
                runtime.LockOSThread()
                i := 0
                for true {
                        i++
                        a()
                }
        }()

        go func() {
                //runtime.LockOSThread()
                i := 0
                for true {
                        i++
                        a()
                }
        }()
        time.Sleep(time.Hour)
}

[ianlancetaylor]

Both threads using 50% of the CPU is what I would expect from that code. You write as though you expect something different. What do you expect?

[ChenYahui2019]

If I delete runtime.LockOSThread() , only one OS thread with 100% CPU. So the G and the M bind together one by one through LockOSThread. Go back to the code at the beginning of the page, there should be no gopreempt.

[ianlancetaylor]

Go back to the code at the beginning of the page, there should be no gopreempt.

Why?

Again, gopreempt has nothing to do with LockOSThread. They do different things.

[networkimprov]

Maybe the question is "why does the periodic preempt policy apply if the M cannot run any other G?"

And @ChenYahui2019 why do you care if there is a gopreempt in this case?

[ChenYahui2019]

Performance sensitive scenarios such as DPDK, we hope specific G monopolize a cpu, which has been configured CPU isolation and binded the OS thread using pthread_setaffinity_np with CGO, without any preempt.

[networkimprov]

This? https://en.wikipedia.org/wiki/Data_Plane_Development_Kit

[ianlancetaylor]

@ChenYahui2019 Unfortunately that's not how Go works. One issue is that the concurrent garbage collector requires the ability to briefly stop all threads while moving to the next stage of collection. So the garbage collector can stop any thread. Another, probably more important, issue is that the Go scheduler only permits up to GOMAXPROCS threads to be running Go code at one time. It enforces that restriction even on goroutines that are locked to threads using LockOSThread. So the scheduler will also preempt locked threads in order to let other goroutines run.

[beoran]

So, if i understand correctly LockOSThread only locks a goroutine to run exclusively on the current OS thread. This is useful, for, say, GUI libraries or games on certain platforms where it is required that drawing and rendering must be done on the main thread of the program. However, this does not does not change anything about scheduling? The documentation of LockOsThread could be expanded to clearly state that.

[ChenYahui2019]

@ianlancetaylor If GOMAXPROCS is zero or big enough, sysmon do not preempt the LockOSThread goroutine. Except GC or the GOMAXPROCS, LockOSThread goroutine just keeps running. Is this solution feasible?

[ianlancetaylor]

@beoran Yes. LockOSThread does not affect goroutine scheduling. I guess if people find this to be confusing we could add a sentence to the docs.

@ChenYahui2019 If I understand you correctly, then what you describe is how the scheduler works. If GOMAXPROCS is large enough for all goroutines to run simultaneously, then goroutines will only be preempted for the garbage collector.

[ChenYahui2019]

@ianlancetaylor Yep, what you say is exactly what I mean.