runtime: unexpected return pc for github.com/pact-foundation/pact-go

[m15o]

Go version

go version go1.22.3 linux/amd64

Output of go env in your module/workspace:

GO111MODULE=''
GOARCH='amd64'
GOBIN=''
GOCACHE='/home/runner/.cache/go-build'
GOENV='/home/runner/.config/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFLAGS=''
GOHOSTARCH='amd64'
GOHOSTOS='linux'
GOINSECURE=''
GOMODCACHE='/home/runner/go/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='linux'
GOPATH='/home/runner/go'
GOPRIVATE=''
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/opt/hostedtoolcache/go/1.22.3/x64'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/opt/hostedtoolcache/go/1.22.3/x64/pkg/tool/linux_amd64'
GOVCS=''
GOVERSION='go1.22.3'
GCCGO='gccgo'
GOAMD64='v1'
AR='ar'
CC='gcc'
CXX='g++'
CGO_ENABLED='1'
GOMOD='/home/runner/work/pact-go-on-golang1.22/pact-go-on-golang1.22/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 -m64 -pthread -Wl,--no-gc-sections -fmessage-length=0 -ffile-prefix-map=/tmp/go-build4067027179=/tmp/go-build -gno-record-gcc-switches'

What did you do?

Trying to run test with pact-go library.

Reproducable codes is here:
https://github.com/m15o/pact-go-on-golang1.22

Reproduced on github actions:
https://github.com/m15o/pact-go-on-golang1.22/actions/runs/9261497614

Since version v1.22.0 I get a runtime error when the -race option is present.
This does not happen on darwin/arm64

What did you see happen?

command:

# install pact-go dynamic library
go install github.com/pact-foundation/pact-go/v2@v2.0.4
PACT_GO=$(command -v pact-go)
sudo "$PACT_GO" -l DEBUG install

# run test
go test -v -race ./...

output:

=== RUN   TestConsumerV4
2024/05/28 00:11:43 [DEBUG] pact setup
2024/05/28 00:11:43 [DEBUG] initialising native interface
2024/05/28 00:11:43 [DEBUG] initialised native log level to TRACE (5)
2024/05/28 00:11:43 [DEBUG] initialised native log to log to stdout
2024/05/28 00:11:43 [DEBUG] log_to_stdout res 0
2024/05/28 00:11:43 [DEBUG] pact add V4 interaction
2024-05-28T00:11:43.590743Z TRACE ThreadId(01) pact_ffi::mock_server::handles: with_pact - ref = 1, keys = [1]
2024-05-28T00:11:43.590780Z TRACE ThreadId(01) pact_ffi::mock_server::handles: with_pact before - ref = 1, inner = RefCell { value: PactHandleInner { pact: V4Pact { consumer: Consumer { name: "PactGoV4Consumer" }, provider: Provider { name: "V4Provider" }, interactions: [], metadata: {"pactRust": Object {"ffi": String("0.4.16")}}, plugin_data: [] }, mock_server_started: false, specification_version: V4 } }
2024-05-28T00:11:43.590889Z TRACE ThreadId(01) pact_ffi::mock_server::handles: with_pact after - ref = 1, inner = RefCell { value: PactHandleInner { pact: V4Pact { consumer: Consumer { name: "PactGoV4Consumer" }, provider: Provider { name: "V4Provider" }, interactions: [SynchronousHttp { id: None, key: None, description: "", provider_states: [], request: HttpRequest { method: "GET", path: "/", query: None, headers: None, body: Missing, matching_rules: MatchingRules { rules: {} }, generators: Generators { categories: {} } }, response: HttpResponse { status: 200, headers: None, body: Missing, matching_rules: MatchingRules { rules: {} }, generators: Generators { categories: {} } }, comments: {}, pending: false, plugin_config: {}, interaction_markup: InteractionMarkup { markup: "", markup_type: "" }, transport: None }], metadata: {"pactRust": Object {"ffi": String("0.4.16")}}, plugin_data: [] }, mock_server_started: false, specification_version: V4 } }
2024-05-28T00:11:43.590924Z TRACE ThreadId(01) pact_ffi::mock_server::handles: with_interaction - index = 1, interaction = 1
2024-05-28T00:11:43.590927Z TRACE ThreadId(01) pact_ffi::mock_server::handles: with_interaction - keys = [1]
2024-05-28T00:11:43.590930Z TRACE ThreadId(01) pact_ffi::mock_server::handles: with_interaction - inner = PactHandleInner { pact: V4Pact { consumer: Consumer { name: "PactGoV4Consumer" }, provider: Provider { name: "V4Provider" }, interactions: [SynchronousHttp { id: None, key: None, description: "", provider_states: [], request: HttpRequest { method: "GET", path: "/", query: None, headers: None, body: Missing, matching_rules: MatchingRules { rules: {} }, generators: Generators { categories: {} } }, response: HttpResponse { status: 200, headers: None, body: Missing, matching_rules: MatchingRules { rules: {} }, generators: Generators { categories: {} } }, comments: {}, pending: false, plugin_config: {}, interaction_markup: InteractionMarkup { markup: "", markup_type: "" }, transport: None }], metadata: {"pactRust": Object {"ffi": String("0.4.16")}}, plugin_data: [] }, mock_server_started: false, specification_version: V4 }
2024-05-28T00:11:43.590945Z TRACE ThreadId(01) pact_ffi::mock_server::handles: with_interaction - index = 195, interaction = 38304
2024-05-28T00:11:43.590948Z TRACE ThreadId(01) pact_ffi::mock_server::handles: with_interaction - keys = [1]
runtime: g 21: unexpected return pc for github.com/pact-foundation/pact-go/v2/internal/native.(*Interaction).GivenWithParameter called from 0xe18a8f
stack: frame={sp:0xc00013dbf8, fp:0xc00013dd28} stack=[0xc00013c000,0xc00013e000)
0x000000c00013daf8:  0x0000000002940000  0x000000c00013dac8 
0x000000c00013db08:  0x0000000000c3914c <github.com/pact-foundation/pact-go/v2/internal/native.(*Interaction).GivenWithParameter+0x00000000000000cc>  0x0000000000000000 
0x000000c00013db18:  0x0000000000000000  0x0000000000000000 
0x000000c00013db28:  0x000000c000111180  0x0000000000f32940 
0x000000c00013db38:  0x0000000000e18a8f  0x0000000002952a70 
0x000000c00013db48:  0x0000000002949090  0x0000000002952120 
0x000000c00013db58:  0x000000c000111190  0x000000c000111180 
0x000000c00013db68:  0x000000c00013dda0  0x0000000000000000 
0x000000c00013db78:  0x0000000000c39680 <github.com/pact-foundation/pact-go/v2/internal/native.(*Interaction).GivenWithParameter.deferwrap1+0x0000000000000000>  0x0000000002949090 
0x000000c00013db88:  0x0000000000000000  0x0000000000000000 
0x000000c00013db98:  0x0000000000d5d880  0x000000c00013de28 
0x000000c00013dba8:  0x000000c00013dd18  0x000000c00013dd18 
0x000000c00013dbb8:  0x0000000000000000  0x0000000000000000 
0x000000c00013dbc8:  0x0000000000000000  0x0000000005000104 
0x000000c00013dbd8:  0x0000000000000000  0x0000000000000000 
0x000000c00013dbe8:  0x0000000000000000  0x0000000000000000 
0x000000c00013dbf8: <0x0000000000000000  0x0000000000000000 
0x000000c00013dc08:  0x0000000000000000  0x000000c00013de28 
0x000000c00013dc18:  0x000000000000000f  0x000000c00013de28 
0x000000c00013dc28:  0x000000c0001247b0  0x0000000000e2171c 
0x000000c00013dc38:  0x000000c00013ded8  0x0000000000cac63a <pact-go-test.TestConsumerV4+0x000000000000023a> 
0x000000c00013dc48:  0x000000c000111170  0x0000000000e2171c 
0x000000c00013dc58:  0x0000000000e18a8f  0x000000c00013de28 
0x000000c00013dc68:  0x0000000000000000  0x0000000000000000 
0x000000c00013dc78:  0x0000000000000000  0x0000000000000000 
0x000000c00013dc88:  0x0000000000e1d539  0x0000000000000009 
0x000000c00013dc98:  0x0000000000000000  0x0000000000000000 
0x000000c00013dca8:  0x0000000000000000  0x0000000000000000 
0x000000c00013dcb8:  0x0000000000000001  0x211eb45600000000 
0x000000c00013dcc8:  0x0000000001237c00  0x000000c000122318 
0x000000c00013dcd8:  0x00000000000000e0  0x0000000000000603 
0x000000c00013dce8:  0x0000000001237c00  0x000000c000111170 
0x000000c00013dcf8:  0x0000000001237c00  0x000000c00013dda0 
0x000000c00013dd08:  0x000000c0001247b0  0x0000000000000000 
0x000000c00013dd18:  0x00000000000000e6  0x0000000000e18a8f 
0x000000c00013dd28: >0x0000000000000002  0x0000000000000000 
0x000000c00013dd38:  0x0000000000000000  0x0000000000000000 
0x000000c00013dd48:  0x0000000000000000  0x0000000000000000 
0x000000c00013dd58:  0x0000000000000000  0x0000000000000000 
0x000000c00013dd68:  0x0000000000000000  0x0000000000000000 
0x000000c00013dd78:  0x0000000000000000  0x0000000000000000 
0x000000c00013dd88:  0x0000000000000000  0x0000000000000000 
0x000000c00013dd98:  0x0000000000000000  0x0000000000d2fd40 
0x000000c00013dda8:  0x0000000000f32940  0x0000000000000000 
0x000000c00013ddb8:  0x0000000000000000  0x0000000000000000 
0x000000c00013ddc8:  0x0000000000000000  0x0000000000000000 
0x000000c00013ddd8:  0x0000000000000000  0x0000000000000000 
0x000000c00013dde8:  0x0000000000000000  0x0000000000000000 
0x000000c00013ddf8:  0x0000000000000000  0x0000000000000000 
0x000000c00013de08:  0x0000000000000000  0x0000000000000000 
0x000000c00013de18:  0x0000000000000000  0x0000000000000000 
fatal error: unknown caller pc

runtime stack:
runtime.throw({0xe22fa7?, 0x130deb0?})
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/panic.go:1023 +0x5c fp=0x7ffd6e07fdd8 sp=0x7ffd6e07fda8 pc=0x4423fc
runtime.(*unwinder).next(0x7ffd6e07fe80)
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/traceback.go:469 +0x24c fp=0x7ffd6e07fe50 sp=0x7ffd6e07fdd8 pc=0x46f7ac
runtime.(*_panic).nextFrame.func1()
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/panic.go:938 +0xa6 fp=0x7ffd6e07ff08 sp=0x7ffd6e07fe50 pc=0x442026
runtime.systemstack(0x48233f)
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/asm_amd64.s:509 +0x4a fp=0x7ffd6e07ff18 sp=0x7ffd6e07ff08 pc=0x47d1aa

goroutine 21 gp=0xc000250700 m=0 mp=0x1388a00 [running]:
runtime.systemstack_switch()
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/asm_amd64.s:474 +0x8 fp=0xc00013d848 sp=0xc00013d838 pc=0x47d148
runtime.(*_panic).nextFrame(0xc00013d8a8?)
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/panic.go:911 +0x65 fp=0xc00013d888 sp=0xc00013d848 pc=0x441f45
runtime.(*_panic).nextDefer(0xc00013d8e0)
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/panic.go:898 +0xa9 fp=0xc00013d8b8 sp=0xc00013d888 pc=0x441d69
panic({0xd658e0?, 0x1324330?})
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/panic.go:766 +0x13c fp=0xc00013d968 sp=0xc00013d8b8 pc=0x44191c
runtime.panicmem(...)
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/panic.go:261
runtime.sigpanic()
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/signal_unix.go:881 +0x378 fp=0xc00013d9c8 sp=0xc00013d968 pc=0x45c958
runtime/internal/atomic.(*Pointer[...]).Load(...)
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/internal/atomic/types.go:526
runtime.deferconvert(0xc00013dbe0)
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/panic.go:435 +0x64 fp=0xc00013da08 sp=0xc00013d9c8 pc=0x440de4
runtime.(*_panic).nextDefer(0xc00013da50)
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/panic.go:879 +0x125 fp=0xc00013da38 sp=0xc00013da08 pc=0x441de5
runtime.deferreturn()
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/panic.go:598 +0x68 fp=0xc00013dac8 sp=0xc00013da38 pc=0x441488
github.com/pact-foundation/pact-go/v2/internal/native.(*Interaction).GivenWithParameter(0x0, {0x0, 0x0}, 0xc00013de28)
	/home/runner/go/pkg/mod/github.com/pact-foundation/pact-go/v2@v2.0.4/internal/native/mock_server.go:669 +0x3d1 fp=0xc00013dbf8 sp=0xc00013dac8 pc=0xc39451
created by testing.(*T).Run in goroutine 1
	/opt/hostedtoolcache/go/1.22.3/x64/src/testing/testing.go:1742 +0x826

goroutine 1 gp=0xc0000061c0 m=nil [chan receive]:
runtime.gopark(0x18?, 0x1386f60?, 0x18?, 0x0?, 0x7f4fd0781728?)
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/proc.go:402 +0xce fp=0xc00026b710 sp=0xc00026b6f0 pc=0x4453ce
runtime.chanrecv(0xc00010e690, 0xc00026b7f7, 0x1)
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/chan.go:583 +0x36d fp=0xc00026b788 sp=0xc00026b710 pc=0x40e7ad
runtime.chanrecv1(0x1386f60?, 0xd2fd40?)
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/chan.go:442 +0x12 fp=0xc00026b7b0 sp=0xc00026b788 pc=0x40e412
testing.(*T).Run(0xc000[15](https://github.com/m15o/pact-go-on-golang1.22/actions/runs/9261497614/job/25476960209#step:5:16)aea0, {0xe20c5a, 0xe}, 0xe611e0)
	/opt/hostedtoolcache/go/1.22.3/x64/src/testing/testing.go:1750 +0x851 fp=0xc00026b8d0 sp=0xc00026b7b0 pc=0x5b64b1
testing.runTests.func1(0xc00015aea0)
	/opt/hostedtoolcache/go/1.22.3/x64/src/testing/testing.go:2[16](https://github.com/m15o/pact-go-on-golang1.22/actions/runs/9261497614/job/25476960209#step:5:17)1 +0x86 fp=0xc00026b920 sp=0xc00026b8d0 pc=0x5ba646
testing.tRunner(0xc00015aea0, 0xc00026bb10)
	/opt/hostedtoolcache/go/1.22.3/x64/src/testing/testing.go:1689 +0x21f fp=0xc00026b9e8 sp=0xc00026b920 pc=0x5b49ff
testing.runTests(0xc000124738, {0x1325d90, 0x1, 0x1}, {0xc00026bbb8?, 0xc00026bc00?, 0x1387a80?})
	/opt/hostedtoolcache/go/1.22.3/x64/src/testing/testing.go:2159 +0x8bf fp=0xc00026bb40 sp=0xc00026b9e8 pc=0x5ba49f
testing.(*M).Run(0xc0002803c0)
	/opt/hostedtoolcache/go/1.22.3/x64/src/testing/testing.go:2027 +0xf[18](https://github.com/m15o/pact-go-on-golang1.22/actions/runs/9261497614/job/25476960209#step:5:19) fp=0xc00026bec8 sp=0xc00026bb40 pc=0x5b7a78
main.main()
	_testmain.go:47 +0x2be fp=0xc00026bf50 sp=0xc00026bec8 pc=0xcada3e
runtime.main()
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/proc.go:271 +0x29d fp=0xc00026bfe0 sp=0xc00026bf50 pc=0x444f5d
runtime.goexit({})
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc00026bfe8 sp=0xc00026bfe0 pc=0x47f161

goroutine 2 gp=0xc000006c40 m=nil [force gc (idle)]:
runtime.gopark(0x1344df0?, 0x1388a00?, 0x0?, 0x0?, 0x0?)
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/proc.go:402 +0xce fp=0xc0000587a8 sp=0xc000058788 pc=0x4453ce
runtime.goparkunlock(...)
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/proc.go:408
runtime.forcegchelper()
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/proc.go:326 +0xb3 fp=0xc0000587e0 sp=0xc0000587a8 pc=0x445233
runtime.goexit({})
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0000587e8 sp=0xc0000587e0 pc=0x47f161
created by runtime.init.6 in goroutine 1
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/proc.go:314 +0x1a

goroutine 18 gp=0xc000102380 m=nil [GC sweep wait]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/proc.go:402 +0xce fp=0xc000184f80 sp=0xc000184f60 pc=0x4453ce
runtime.goparkunlock(...)
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/proc.go:408
runtime.bgsweep(0xc00010e000)
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/mgcsweep.go:278 +0x94 fp=0xc000184fc8 sp=0xc000184f80 pc=0x42ed14
runtime.gcenable.gowrap1()
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/mgc.go:203 +0x25 fp=0xc000184fe0 sp=0xc000184fc8 pc=0x423685
runtime.goexit({})
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000184fe8 sp=0xc000184fe0 pc=0x47f161
created by runtime.gcenable in goroutine 1
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/mgc.go:203 +0x66

goroutine [19](https://github.com/m15o/pact-go-on-golang1.22/actions/runs/9261497614/job/25476960209#step:5:20) gp=0xc000102540 m=nil [GC scavenge wait]:
runtime.gopark(0xc00010e000?, 0xf2fc90?, 0x1?, 0x0?, 0xc000102540?)
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/proc.go:402 +0xce fp=0xc000066f78 sp=0xc000066f58 pc=0x4453ce
runtime.goparkunlock(...)
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/proc.go:408
runtime.(*scavengerState).park(0x1387c[20](https://github.com/m15o/pact-go-on-golang1.22/actions/runs/9261497614/job/25476960209#step:5:21))
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/mgcscavenge.go:425 +0x49 fp=0xc000066fa8 sp=0xc000066f78 pc=0x42c729
runtime.bgscavenge(0xc00010e000)
	/opt/hostedtoolcache/go/1.[22](https://github.com/m15o/pact-go-on-golang1.22/actions/runs/9261497614/job/25476960209#step:5:23).3/x64/src/runtime/mgcscavenge.go:653 +0x3c fp=0xc000066fc8 sp=0xc000066fa8 pc=0x42cc9c
runtime.gcenable.gowrap2()
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/mgc.go:204 +0x25 fp=0xc000066fe0 sp=0xc000066fc8 pc=0x423625
runtime.goexit({})
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000066fe8 sp=0xc000066fe0 pc=0x47f161
created by runtime.gcenable in goroutine 1
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/mgc.go:204 +0xa5

goroutine 20 gp=0xc000102a80 m=nil [finalizer wait]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/proc.go:402 +0xce fp=0xc000185e20 sp=0xc000185e00 pc=0x4453ce
runtime.runfinq()
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/mfinal.go:194 +0x145 fp=0xc000185fe0 sp=0xc000185e20 pc=0x4226c5
runtime.goexit({})
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000185fe8 sp=0xc000185fe0 pc=0x47f161
created by runtime.createfing in goroutine 1
	/opt/hostedtoolcache/go/1.22.3/x64/src/runtime/mfinal.go:164 +0x3d
FAIL	pact-go-test	0.019s
FAIL

What did you expect to see?

run test without runtime error

[randall77]

Hmm, that looks like corruption found while processing defers, followed by an inability to unwind correctly.

I can reproduce, although it would be nice to have repro instructions that didn't involve sudo.
Crashes similarly at tip, but not on 1.21. I can try and bisect.

It might be good to audit your use of unsafe and cgo and see if you can find any cases where memory corruption could occur.

[randall77]

Bisect points to https://go-review.googlesource.com/c/go/+/516198 as the cause.

That CL only changes the internal layout of defer records, which shouldn't be observable.
So there is corruption happening, somewhere. Whether it is in C, Go client code, or runtime remains unclear.
I'm going to add some red zones to the defer records and see if I can observe any clobbering.

[randall77]

Ok, some progress. My best guess is that C.pactffi_given is corrupting the stack somehow.

Do the following patch to the runtime (I'm working on tip, but this should also work on 1.22):

diff --git a/src/runtime/panic.go b/src/runtime/panic.go
index 2e15649092..dd5e763511 100644
--- a/src/runtime/panic.go
+++ b/src/runtime/panic.go
@@ -542,6 +542,12 @@ func newdefer() *_defer {
        return d
 }
 
+//go:noinline
+func GetSP() *[15]uintptr {
+       sp := getcallersp()
+       return (*[15]uintptr)(unsafe.Pointer(sp))
+}
+
 // popDefer pops the head of gp's defer list and frees it.
 func popDefer(gp *g) {
        d := gp._defer

Then do the following patch to pact-go/internal/native:

diff --git a/internal/native/mock_server.go b/internal/native/mock_server.go
index 947970f..3bd9c8a 100644
--- a/internal/native/mock_server.go
+++ b/internal/native/mock_server.go
@@ -170,6 +170,7 @@ import (
        "fmt"
        "log"
        "os"
+       "runtime"
        "strings"
        "unsafe"
 )
@@ -646,11 +647,35 @@ func (i *Interaction) Given(state string) *Interaction {
        cState := C.CString(state)
        defer free(cState)
 
+       pre(runtime.GetSP())
        C.pactffi_given(i.handle, cState)
+       post(runtime.GetSP())
 
        return i
 }
 
+var entry2 uintptr
+
+//go:noinline
+func pre(sp *[15]uintptr) {
+       fmt.Printf("pre sp=%p\n", sp)
+       for i := range sp {
+               fmt.Printf("  %d %x\n", i, sp[i])
+       }
+       entry2 = sp[2]
+}
+
+//go:noinline
+func post(sp *[15]uintptr) {
+       fmt.Printf("post sp=%p\n", sp)
+       for i := range sp {
+               fmt.Printf("  %d %x\n", i, sp[i])
+       }
+       if sp[2] != entry2 {
+               panic("bad entry2")
+       }
+}
+
 func (i *Interaction) GivenWithParameter(state string, params map[string]interface{}) *Interaction {
        cState := C.CString(state)
        defer free(cState)

The panic added there in post triggers.

This prints the contents of the stack frame of (*pact-go/internal/native.Interaction).Given, both before and after the call to C.pactffi_given at line 650 (with the patch, 651) of mock_server.go. The stack frame has 15 slots (1 slot = 8 bytes). The first 2 are reserved argument slots, so those can change across the call. But the other 13 slots should not change across that call. There is a defer record which occupies slots 2 through 7 inclusive, and the first slot of that defer record has 4 bytes of it clobbered. Particularly, the problem is the low byte is set from 0 to 1. That change makes the runtime very unhappy.

This bug is very sensitive to the stack frame layout of (*pact-go/internal/native.Interaction).Given, any adjustment of the offset of the defer record from the stack pointer makes the problem go away (or at least, whatever gets clobbered in the stack frame instead turns out not to matter). The code I added to it is very carefully chosen to not affect the stack frame. I think -race is only relevant for this point, as without -race the stack frame gets laid out differently and the problem goes away.

I don't yet understand where the clobbering write is coming from. My best guess is the code for C.pactffi_given itself. It could also be a bug in our cgo calling convention, I suppose, although if cgo is clobbering caller frames I think we would have seen it crop up by now.
It would be great to have a similar hack on the C side to print the stack frames above on both entry and exit to C.pactffi_given. I don't know where that code lives, so I think I have to give up at this point and hand things back to the OP.

[randall77]

Update: gdb watchpoints save the day! A bit of fiddling and they showed who was writing to the slot in question. It's cgo's fault.

github.com/pact-foundation/pact-go/v2/internal/native.(*Interaction).Given:
calls github.com/pact-foundation/pact-go/v2/internal/native._Cfunc_pactffi_given

github.com/pact-foundation/pact-go/v2/internal/native._Cfunc_pactffi_given:
calls runtime.cgocall

runtime.cgocall:
calls runtime.asmcgocall

runtime.asmcgocall:
calls _cgo_74dbbc5dfbe4_Cfunc_pactffi_given (indirectly)

_cgo_74dbbc5dfbe4_Cfunc_pactffi_given:
calls pactffi_given@plt
then at the end, does the bad write!
0x0000000000cdf544 <+36>: mov %ebp,0x10(%rbx,%rax,1)
here rbx is the SP of (*Interaction).Given's stack frame, rax is 0 (the amount the stack moved during the call), and 0x10 is the offset to slot 2.

rbx looks right, the same function uses 0($rbx) and 8($rbx) to get the arguments to pass to pactffi_given@plt. It just thinks there are 4 bytes of results when there are in fact 0, and the calling frame didn't plan for those 4 bytes.

@ianlancetaylor Does any of this sound familiar?

[randall77]

I think I see the problem.
In pact-go/internal/native/mock_server.go, there is the following definition:

void pactffi_given(InteractionHandle interaction, const char *description);

But in pact-go/internal/native/message_server.go, there is a different definition of the same function:

bool pactffi_given(InteractionHandle interaction, const char *description);

Note the different return type.

If you make them both return void, or both return bool, the bug goes away.

Somehow with the different definitions, at the callsite the compiler is assuming a void return value, but the cgo wrapper is assuming the bool return value. Chaos ensues.

So I think this is a bug on pact-go's side. Possibly we should have cgo complain if it sees this inconsistency. It certainly would be helpful to get a compiler error instead of have to trace down this runtime failure.

[randall77]

Closing as this isn't a Go bug. I opened #67699 to track getting better detection of conflicting declarations from cgo.

[YOU54F]

Amazing troubleshooting @randall77 (from a Pact maintainer)

We rely on a shared library built in rust, and consume in various languages. CGO has been a bit of a black-box to me and I struggle to work out where to start with diagnosing so this is really valuable.

Thanks for taking the time to investigate and proposing a fix on pact-go's side.

I'll look through your notes and create some easy to follow steps for our users of the lib to help attach to bug reports.

So I think this is a bug on pact-go's side. Possibly we should have cgo complain if it sees this inconsistency. It certainly would be helpful to get a compiler error instead of have to trace down this runtime failure.

totally agree, thanks for raising that separate issue!

I can reproduce, although it would be nice to have repro instructions that didn't involve sudo.

sorry about that, it requires sudo because it installs the shared library to a well known location for cgo linking without modifying LD_LIBRARY_PATH, but on linux and macos they are root protected. That is configurable though by the user, so we can provide steps that don't require sudo in future.

[mefellows]

Also another Pact maintainer here - echoing Yousaf's sentiments, I just wanted to thank you as well - this was an excellent experience and much appreciated 🙏 .