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

runtime: 'fatal error: traceback did not unwind completely' in debugCall #71144

Open
JohnDoe117 opened this issue Jan 7, 2025 · 4 comments
Open
Labels
BugReport Issues describing a possible bug in the Go implementation. compiler/runtime Issues related to the Go compiler and/or runtime. NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Milestone

Comments

@JohnDoe117
Copy link

JohnDoe117 commented Jan 7, 2025

Go version

go1.23.0/amd64
This issue also exists in the latest version.

Output of go env in your module/workspace:

GO111MODULE='on'
GOARCH='amd64'
GOBIN=''
GOCACHE='/Users/ht/Library/Caches/go-build'
GOENV='/Users/ht/Library/Application Support/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFLAGS=''
GOHOSTARCH='amd64'
GOHOSTOS='darwin'
GOINSECURE=''
GOMODCACHE='/Users/ht/go/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='darwin'
GOPATH='/Users/ht/go'
GOPRIVATE=''
GOPROXY='https://goproxy.cn'
GOROOT='/usr/local/go'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/usr/local/go/pkg/tool/darwin_amd64'
GOVCS=''
GOVERSION='go1.23.1'
GODEBUG=''
GOTELEMETRY='local'
GOTELEMETRYDIR='/Users/ht/Library/Application Support/go/telemetry'
GCCGO='gccgo'
GOAMD64='v1'
AR='ar'
CC='clang'
CXX='clang++'
CGO_ENABLED='1'
GOMOD='/Users/ht/lefei/lfapi/go.mod'
GOWORK=''
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
PKG_CONFIG='pkg-config'
GOGCCFLAGS='-fPIC -arch x86_64 -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -ffile-prefix-map=/var/folders/42/w71mmjcx7kq4xd94lstqhp_r0000gn/T/go-build225208816=/tmp/go-build -gno-record-gcc-switches -fno-common'

What did you do?

package main

import (
	"fmt"
	"time"
)

func main() {
	StartTime := "2025-01-06T12:00:00Z"
	startTime, err := time.Parse(time.RFC3339, StartTime)
	if err != nil {
		return
	}
	// The program crashes when I execute this line of code with Evaluate Expression
	// time.Now().Sub(startTime).Seconds()
	loacl := time.Now()
	//However, there is no issue when I execute this line of code with Evaluate Expression.
	// loacl.Sub(time.Now()).Seconds()
	fmt.Println(loacl.Sub(startTime).Seconds())

}

This is a reproducible piece of code.

When I use Evaluate Expression to execute time.Now().Sub(), the program crashes. However, if I create the object in advance, there is no such issue.

I suspect that using Evaluate Expression might disrupt the order of method chaining or trigger some strange garbage collection behavior.

What's even more bizarre is that the code works perfectly fine when run directly, and the problem only occurs in the Evaluate Expression environment.

What I'm concerned about now is whether such an issue could be triggered in a production environment. If it can, that would be really scary.
image

What did you see happen?

runtime: g7: frame.sp=0xc000056f40 top=0xc000056fe0
        stack=[0xc000056800-0xc000057000
fatal error: traceback did not unwind completely

runtime stack:
runtime.throw({0x60bd544?, 0x0?})
        /usr/local/go/src/runtime/panic.go:1067 +0x48 fp=0x7ff7baf17430 sp=0x7ff7baf17400 pc=0x6054ea8
runtime.(*unwinder).finishInternal(0x7ff7baf17528)
        /usr/local/go/src/runtime/traceback.go:566 +0x14a fp=0x7ff7baf17470 sp=0x7ff7baf17430 pc=0x60435ca
runtime.(*unwinder).next(0x7ff7baf17528)
        /usr/local/go/src/runtime/traceback.go:447 +0x265 fp=0x7ff7baf174f8 sp=0x7ff7baf17470 pc=0x60433c5
runtime.(*_panic).nextFrame.func1()
        /usr/local/go/src/runtime/panic.go:962 +0x96 fp=0x7ff7baf175b0 sp=0x7ff7baf174f8 pc=0x601f176
runtime.systemstack(0x7ff7baf175d8)
        /usr/local/go/src/runtime/asm_amd64.s:514 +0x4a fp=0x7ff7baf175c0 sp=0x7ff7baf175b0 pc=0x6059cca

goroutine 7 gp=0xc0000076c0 m=0 mp=0x6174aa0 [running, locked to thread]:
runtime.systemstack_switch()
        /usr/local/go/src/runtime/asm_amd64.s:479 +0x8 fp=0xc000056e00 sp=0xc000056df0 pc=0x6059c68
runtime.(*_panic).nextFrame(0xc000056e98?)
        /usr/local/go/src/runtime/panic.go:935 +0x65 fp=0xc000056e40 sp=0xc000056e00 pc=0x601f0a5
runtime.(*_panic).start(0xc000056e98, 0x601e37e, 0xc000056f20)
        /usr/local/go/src/runtime/panic.go:849 +0x1c5 fp=0xc000056e70 sp=0xc000056e40 pc=0x601ee25
panic({0x60d5fc0?, 0x616ea50?})
        /usr/local/go/src/runtime/panic.go:779 +0x12c fp=0xc000056f20 sp=0xc000056e70 pc=0x6054bac
runtime.panicmem()
        /usr/local/go/src/runtime/panic.go:262 +0x3e fp=0xc000056f40 sp=0xc000056f20 pc=0x601e37e
runtime.sigpanic()
        /usr/local/go/src/runtime/signal_unix.go:900 +0x245 fp=0xc000056f70 sp=0xc000056f40 pc=0x60564a5
created by runtime.debugCallWrap in goroutine 6
        <autogenerated>:1 +0x1f

goroutine 1 gp=0xc0000061c0 m=nil [debug call]:
runtime.debugCallWrap(0x60594e0)
        /usr/local/go/src/runtime/debugcall.go:163 +0x7e fp=0xc000104d80 sp=0xc000104d20 pc=0x5fefd5e
runtime.debugCallWrap(0x60594e0)
        <autogenerated>:1 +0x1f fp=0xc000104d98 sp=0xc000104d80 pc=0x605e13f
runtime.debugCallV2()
        /usr/local/go/src/runtime/asm_amd64.s:1953 +0xbd fp=0xc000104e40 sp=0xc000104d98 pc=0x605bd1d
main.main()
        /Users/ht/lefei/lfapi/apps/aa/main.go:16 +0x146 fp=0xc000104f78 sp=0xc000104e40 pc=0x60b6f86
runtime.main()
        /usr/local/go/src/runtime/proc.go:272 +0x247 fp=0xc000104fe0 sp=0xc000104f78 pc=0x6022707
runtime.goexit({})
        /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000104fe8 sp=0xc000104fe0 pc=0x605bb21

goroutine 2 gp=0xc000006700 m=nil [force gc (idle)]:
runtime.gopark(0x60ea970, 0x6173a70, 0x11, 0xa, 0x1)
        /usr/local/go/src/runtime/proc.go:424 +0xfc fp=0xc000054f80 sp=0xc000054f50 pc=0x6054fbc
runtime.goparkunlock(0x6173a70?, 0x0?, 0x0?, 0x0?)
        /usr/local/go/src/runtime/proc.go:430 +0x25 fp=0xc000054fb0 sp=0xc000054f80 pc=0x6022b65
runtime.forcegchelper()
        /usr/local/go/src/runtime/proc.go:337 +0xb5 fp=0xc000054fe0 sp=0xc000054fb0 pc=0x6022a55
runtime.goexit({})
        /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000054fe8 sp=0xc000054fe0 pc=0x605bb21
created by runtime.init.7 in goroutine 1
        /usr/local/go/src/runtime/proc.go:325 +0x1a

goroutine 3 gp=0xc000006c40 m=nil [GC sweep wait]:
runtime.gopark(0x60ea970, 0x6173be0, 0xc, 0x9, 0x1)
        /usr/local/go/src/runtime/proc.go:424 +0xfc fp=0xc000055758 sp=0xc000055728 pc=0x6054fbc
runtime.goparkunlock(0x6173be0?, 0x0?, 0x0?, 0x0?)
        /usr/local/go/src/runtime/proc.go:430 +0x25 fp=0xc000055788 sp=0xc000055758 pc=0x6022b65
runtime.bgsweep(0xc00006c000)
        /usr/local/go/src/runtime/mgcsweep.go:277 +0xa5 fp=0xc0000557c8 sp=0xc000055788 pc=0x600c9a5
runtime.gcenable.gowrap1()
        /usr/local/go/src/runtime/mgc.go:203 +0x25 fp=0xc0000557e0 sp=0xc0000557c8 pc=0x60006a5
runtime.goexit({})
        /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000557e8 sp=0xc0000557e0 pc=0x605bb21
created by runtime.gcenable in goroutine 1
        /usr/local/go/src/runtime/mgc.go:203 +0x66

goroutine 4 gp=0xc000006e00 m=nil [GC scavenge wait]:
runtime.gopark(0x60ea970, 0x6173d00, 0xd, 0xa, 0x2)
        /usr/local/go/src/runtime/proc.go:424 +0xfc fp=0xc000055f48 sp=0xc000055f18 pc=0x6054fbc
runtime.goparkunlock(0x6173d00?, 0x1?, 0x3d?, 0xc000006e00?)
        /usr/local/go/src/runtime/proc.go:430 +0x25 fp=0xc000055f78 sp=0xc000055f48 pc=0x6022b65
runtime.(*scavengerState).park(0x6173d00)
        /usr/local/go/src/runtime/mgcscavenge.go:425 +0x45 fp=0xc000055fa0 sp=0xc000055f78 pc=0x6009e85
runtime.bgscavenge(0xc00006c000)
        /usr/local/go/src/runtime/mgcscavenge.go:653 +0x45 fp=0xc000055fc8 sp=0xc000055fa0 pc=0x600a405
runtime.gcenable.gowrap2()
        /usr/local/go/src/runtime/mgc.go:204 +0x25 fp=0xc000055fe0 sp=0xc000055fc8 pc=0x6000645
runtime.goexit({})
        /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000055fe8 sp=0xc000055fe0 pc=0x605bb21
created by runtime.gcenable in goroutine 1
        /usr/local/go/src/runtime/mgc.go:204 +0xa5

goroutine 5 gp=0xc000007340 m=nil [finalizer wait]:
runtime.gopark(0x60ea6e0, 0x61936e8, 0x10, 0xa, 0x1)
        /usr/local/go/src/runtime/proc.go:424 +0xfc fp=0xc000054628 sp=0xc0000545f8 pc=0x6054fbc
runtime.runfinq()
        /usr/local/go/src/runtime/mfinal.go:193 +0x107 fp=0xc0000547e0 sp=0xc000054628 pc=0x5fff6e7
runtime.goexit({})
        /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000547e8 sp=0xc0000547e0 pc=0x605bb21
created by runtime.createfing in goroutine 1
        /usr/local/go/src/runtime/mfinal.go:163 +0x45

goroutine 6 gp=0xc000007500 m=nil [debug call]:
runtime.debugCallWrap(0x60594e0)
        /usr/local/go/src/runtime/debugcall.go:163 +0x7e fp=0xc000056678 sp=0xc000056618 pc=0x5fefd5e
runtime.debugCallWrap(0x60594e0)
        <autogenerated>:1 +0x1f fp=0xc000056690 sp=0xc000056678 pc=0x605e13f
runtime.debugCallV2()
        /usr/local/go/src/runtime/asm_amd64.s:1953 +0xbd fp=0xc000056738 sp=0xc000056690 pc=0x605bd1d
debugCall32()
        /usr/local/go/src/runtime/asm_amd64.s:2012 +0x22 fp=0xc000056768 sp=0xc000056738 pc=0x6059502
runtime.debugCallWrap2(0x0?)
        /usr/local/go/src/runtime/debugcall.go:274 +0x6f fp=0xc0000567b0 sp=0xc000056768 pc=0x5ff000f
runtime.debugCallWrap1()
        /usr/local/go/src/runtime/debugcall.go:217 +0x53 fp=0xc0000567e0 sp=0xc0000567b0 pc=0x5feff73
runtime.goexit({})
        /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000567e8 sp=0xc0000567e0 pc=0x605bb21
created by runtime.debugCallWrap in goroutine 1
        <autogenerated>:1 +0x1f
Exiting.

What did you expect to see?

The program crashes when this situation occurs

@JohnDoe117 JohnDoe117 changed the title import/path: issue An error occurred when I was using Evaluate Expression to debug the code, causing the process to exit. debug: issue An error occurred when I was using Evaluate Expression to debug the code, causing the process to exit. Jan 7, 2025
@prattmic prattmic changed the title debug: issue An error occurred when I was using Evaluate Expression to debug the code, causing the process to exit. runtime: 'fatal error: traceback did not unwind completely' in debugCall Jan 7, 2025
@gopherbot gopherbot added the compiler/runtime Issues related to the Go compiler and/or runtime. label Jan 7, 2025
@prattmic
Copy link
Member

prattmic commented Jan 7, 2025

cc @golang/runtime @golang/tools-team (for VS Code) @aarzilli @derekparker (for Delve)

Is the debugger you are using in VS Code? (Or is that Goland?). Under the hood I think both use Delve, but I'm not sure.

From the stack trace, we can see that it is running the injected call (via runtime.debugCallV2). It isn't immediately clear to me why this call panics, or why unwinding breaks.

On the latter point, I wouldn't be surprised if unwinding of panics within a debug call is just completely broken.

@prattmic prattmic added this to the Backlog milestone Jan 7, 2025
@prattmic prattmic added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Jan 7, 2025
@aarzilli
Copy link
Contributor

aarzilli commented Jan 7, 2025

I tried reproducing this with delve from the command line and couldn't (from the screenshot this happens in goland but it's delve either way). I get this:

Type 'help' for list of commands.
(dlv) b test.go:19
Breakpoint 1 set at 0x4c8a3a for main.main() ./test.go:19
(dlv) c
> [Breakpoint 1] main.main() ./test.go:19 (hits goroutine(1):1 total:1) (PC: 0x4c8a3a)
    14:         // The program crashes when I execute this line of code with Evaluate Expression
    15:         // time.Now().Sub(startTime).Seconds()
    16:         loacl := time.Now()
    17:         //However, there is no issue when I execute this line of code with Evaluate Expression.
    18:         // loacl.Sub(time.Now()).Seconds()
=>  19:         fmt.Println(loacl.Sub(startTime).Seconds())
    20:
    21: }
(dlv) call loacl.Sub(time.Now()).Seconds()
> main.main() ./test.go:19 (PC: 0x4c8a3a)
Values returned:
        ~r0: -9.725972829

    14:         // The program crashes when I execute this line of code with Evaluate Expression
    15:         // time.Now().Sub(startTime).Seconds()
    16:         loacl := time.Now()
    17:         //However, there is no issue when I execute this line of code with Evaluate Expression.
    18:         // loacl.Sub(time.Now()).Seconds()
=>  19:         fmt.Println(loacl.Sub(startTime).Seconds())
    20:
    21: }

Did I evaluate the right expression? I'm not sure what you mean by "When I use Evaluate Expression to execute time.Now().Sub(), the program crashes. However, if I create the object in advance, there is no such issue."

I tried with go 1.23.4 and 1.23.0 and delve version 1.24.0, there were changes around call injection in delve recently so maybe that's why. Is this crash deterministic or not?

What I'm concerned about now is whether such an issue could be triggered in a production environment. If it can, that would be really scary.

Call injection is a really weird thing, unless you use it on a production environment it won't happen.

@aarzilli
Copy link
Contributor

aarzilli commented Jan 7, 2025

PS. goland uses its own copy of delve, if you want to try updating you have to replace the dlv binary somewhere inside goland's install directory (I don't remember where it is, sorry).

@gabyhelp gabyhelp added the BugReport Issues describing a possible bug in the Go implementation. label Jan 7, 2025
@mknyszek mknyszek added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Jan 8, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
BugReport Issues describing a possible bug in the Go implementation. compiler/runtime Issues related to the Go compiler and/or runtime. NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Projects
Development

No branches or pull requests

6 participants