Skip to content

Maybe an infinite loop occurs during gc? #35302

Closed
@crazycomputer

Description

@crazycomputer

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

$ go version go1.12.4 linux/arm64

Does this issue reproduce with the latest release?

sorry, I didn't try to reproduce it with the latest release

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

go env Output
$ go env
GOARCH="arm64"
GOBIN=""
GOCACHE="/root/.cache/go-build"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="arm64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/usr/local/gopkg"
GOPROXY=""
GORACE=""
GOROOT="/usr/local/go"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_arm64"
GCCGO="gccgo"
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 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build266632096=/tmp/go-build -gno-record-gcc-switches"

What did you do?

I compiled an executable file and executed it.But looks like that it didn't enter the main function.And I checked the CPU usage of this process with command "pidstat -P", I found that one thread of the process occupied 100% of the CPU in user space. So I tried to debug it with gdb.

The call stack I saw is as follows:

#0  runtime.pidleget () at /usr/local/go/src/runtime/proc.go:4711
#1  runtime.stopTheWorldWithSema () at /usr/local/go/src/runtime/proc.go:1036
#2  0x0000000000459ff8 in runtime.systemstack () at /usr/local/go/src/runtime/asm_arm64.s:237
#3  0x0000000000433938 in runtime.startTheWorldWithSema (emitTraceEvent=224, ~r1=<optimized out>) at /usr/local/go/src/runtime/proc.go:1082
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
![image](https://user-images.githubusercontent.com/34932896/68009045-bf4ba380-fcbb-11e9-9de6-cc5addc6aa75.png)

I made a breakpoint at runtime.pidleget (),and saw that it always enter this method.It looks like a infiniteloop.It always can get idle p when call runtime.pidleget ().Then I printed the runtime.sched to see why an infinite loop occurs.

(gdb) p 'runtime.sched'
$22 = {goidgen = 81, lastpoll = 0, lock = {key = 2}, midle = 274881896448, nmidle = 2, nmidlelocked = 1, mnext = 14, maxmcount = 10000, nmsys = 2, nmfreed = 0, ngsys = 17, **pidle = 274878131968**, npidle = 2895823215, nmspinning = 0, runq = {head = 0, tail = 0}, 
  runqsize = 0, disable = {user = false, runnable = {head = 0, tail = 0}, n = 0}, gFree = {lock = {key = 0}, stack = {head = 0}, noStack = {head = 0}, n = 0}, sudoglock = {key = 0}, sudogcache = 0x0, deferlock = {key = 0}, deferpool = {0x0, 0x0, 0x0, 0x0, 0x0}, 
  freem = 0x0, gcwaiting = 1, stopwait = -1399144080, stopnote = {key = 0}, sysmonwait = 0, sysmonnote = {key = 0}, safePointFn = {void (runtime.p *)} 0x1335600 <runtime.sched>, safePointWait = 0, safePointNote = {key = 0}, profilehz = 0, 
  procresizetime = 97197470357832, totaltime = 0}
(gdb) c
Continuing.

Thread 1 "*****" hit Breakpoint 1, runtime.pidleget () at /usr/local/go/src/runtime/proc.go:4711
4711		if _p_ != nil {
(gdb) p 'runtime.sched'
$23 = {goidgen = 81, lastpoll = 0, lock = {key = 2}, midle = 274881896448, nmidle = 2, nmidlelocked = 1, mnext = 14, maxmcount = 10000, nmsys = 2, nmfreed = 0, ngsys = 17, **pidle = 274878103552,** npidle = 2895823214, nmspinning = 0, runq = {head = 0, tail = 0}, 
  runqsize = 0, disable = {user = false, runnable = {head = 0, tail = 0}, n = 0}, gFree = {lock = {key = 0}, stack = {head = 0}, noStack = {head = 0}, n = 0}, sudoglock = {key = 0}, sudogcache = 0x0, deferlock = {key = 0}, deferpool = {0x0, 0x0, 0x0, 0x0, 0x0}, 
  freem = 0x0, gcwaiting = 1, stopwait = -1399144081, stopnote = {key = 0}, sysmonwait = 0, sysmonnote = {key = 0}, safePointFn = {void (runtime.p *)} 0x1335600 <runtime.sched>, safePointWait = 0, safePointNote = {key = 0}, profilehz = 0, 
  procresizetime = 97197470357832, totaltime = 0}
(gdb) c
Continuing.

Thread 1 "*****" hit Breakpoint 1, runtime.pidleget () at /usr/local/go/src/runtime/proc.go:4711
4711		if _p_ != nil {
(gdb) p 'runtime.sched'
$24 = {goidgen = 81, lastpoll = 0, lock = {key = 2}, midle = 274881896448, nmidle = 2, nmidlelocked = 1, mnext = 14, maxmcount = 10000, nmsys = 2, nmfreed = 0, ngsys = 17, **pidle = 274878113024**, npidle = 2895823213, nmspinning = 0, runq = {head = 0, tail = 0}, 
  runqsize = 0, disable = {user = false, runnable = {head = 0, tail = 0}, n = 0}, gFree = {lock = {key = 0}, stack = {head = 0}, noStack = {head = 0}, n = 0}, sudoglock = {key = 0}, sudogcache = 0x0, deferlock = {key = 0}, deferpool = {0x0, 0x0, 0x0, 0x0, 0x0}, 
  freem = 0x0, gcwaiting = 1, stopwait = -1399144082, stopnote = {key = 0}, sysmonwait = 0, sysmonnote = {key = 0}, safePointFn = {void (runtime.p *)} 0x1335600 <runtime.sched>, safePointWait = 0, safePointNote = {key = 0}, profilehz = 0, 
  procresizetime = 97197470357832, totaltime = 0}
(gdb) c
Continuing.

Thread 1 "*****" hit Breakpoint 1, runtime.pidleget () at /usr/local/go/src/runtime/proc.go:4711
4711		if _p_ != nil {
(gdb) p 'runtime.sched'
$25 = {goidgen = 81, lastpoll = 0, lock = {key = 2}, midle = 274881896448, nmidle = 2, nmidlelocked = 1, mnext = 14, maxmcount = 10000, nmsys = 2, nmfreed = 0, ngsys = 17, **pidle = 274878141440**, npidle = 2895823212, nmspinning = 0, runq = {head = 0, tail = 0}, 
  runqsize = 0, disable = {user = false, runnable = {head = 0, tail = 0}, n = 0}, gFree = {lock = {key = 0}, stack = {head = 0}, noStack = {head = 0}, n = 0}, sudoglock = {key = 0}, sudogcache = 0x0, deferlock = {key = 0}, deferpool = {0x0, 0x0, 0x0, 0x0, 0x0}, 
  freem = 0x0, gcwaiting = 1, stopwait = -1399144083, stopnote = {key = 0}, sysmonwait = 0, sysmonnote = {key = 0}, safePointFn = {void (runtime.p *)} 0x1335600 <runtime.sched>, safePointWait = 0, safePointNote = {key = 0}, profilehz = 0, 
  procresizetime = 97197470357832, totaltime = 0}
(gdb) c
Continuing.

Thread 1 "*****" hit Breakpoint 1, runtime.pidleget () at /usr/local/go/src/runtime/proc.go:4711
4711		if _p_ != nil {
(gdb) p 'runtime.sched'
$26 = {goidgen = 81, lastpoll = 0, lock = {key = 2}, midle = 274881896448, nmidle = 2, nmidlelocked = 1, mnext = 14, maxmcount = 10000, nmsys = 2, nmfreed = 0, ngsys = 17, **pidle = 274878131968**, npidle = 2895823211, nmspinning = 0, runq = {head = 0, tail = 0}, 
  runqsize = 0, disable = {user = false, runnable = {head = 0, tail = 0}, n = 0}, gFree = {lock = {key = 0}, stack = {head = 0}, noStack = {head = 0}, n = 0}, sudoglock = {key = 0}, sudogcache = 0x0, deferlock = {key = 0}, deferpool = {0x0, 0x0, 0x0, 0x0, 0x0}, 
  freem = 0x0, gcwaiting = 1, stopwait = -1399144084, stopnote = {key = 0}, sysmonwait = 0, sysmonnote = {key = 0}, safePointFn = {void (runtime.p *)} 0x1335600 <runtime.sched>, safePointWait = 0, safePointNote = {key = 0}, profilehz = 0, 
  procresizetime = 97197470357832, totaltime = 0}

The pidle pointer looks like a circular linked list,the npidle has been reduced to a reversal.
I don't think this should ever happen.In this case .It will circulate infinitely and never end.

Can anyone help me?
3ks

What did you expect to see?

What did you see instead?

Activity

ianlancetaylor

ianlancetaylor commented on Nov 1, 2019

@ianlancetaylor
Contributor

Looks like you have memory corruption. Does this problem happen consistently? Does your program use unsafe or call C code?

crazycomputer

crazycomputer commented on Nov 1, 2019

@crazycomputer
Author

@ianlancetaylor
Thanks for your reply. Program don't use usafe or C code.And I didn't access runtime.sched directly. This problem happens Accidentally.
I can't make sure it would happen in which case.
But when I compiled and ran the same code on arch amd64,this problem never happen.

ianlancetaylor

ianlancetaylor commented on Nov 1, 2019

@ianlancetaylor
Contributor

Is there a way that we can reproduce the problem ourselves?

ianlancetaylor

ianlancetaylor commented on Nov 1, 2019

@ianlancetaylor
Contributor

Also, is it possible for you try Go 1.13.4?

added
NeedsInvestigationSomeone must examine and confirm this is a valid issue and not a duplicate of an existing one.
WaitingForInfoIssue is not actionable because of missing required information, which needs to be provided.
on Nov 5, 2019
added this to the Unplanned milestone on Nov 5, 2019
gopherbot

gopherbot commented on Dec 5, 2019

@gopherbot
Contributor

Timed out in state WaitingForInfo. Closing.

(I am just a bot, though. Please speak up if this is a mistake or you have the requested information.)

locked and limited conversation to collaborators on Dec 4, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    FrozenDueToAgeNeedsInvestigationSomeone must examine and confirm this is a valid issue and not a duplicate of an existing one.WaitingForInfoIssue is not actionable because of missing required information, which needs to be provided.

    Type

    No type

    Projects

    No projects

    Relationships

    None yet

      Development

      No branches or pull requests

        Participants

        @FiloSottile@ianlancetaylor@gopherbot@crazycomputer

        Issue actions

          Maybe an infinite loop occurs during gc? · Issue #35302 · golang/go