https://pact.io logo
#libpact_ffi-users
Title
# libpact_ffi-users
n

Nuno Frias

06/07/2022, 11:00 AM
Hello. I don't know if this is the correct venue to ask for help but here we go. I am using
pact-go
and when running the provider verification I am noticing that the test hangs after the call to
libpact_ffi
.
Copy code
2022/06/02 13:09:55 [INFO] package libpact_ffi found
2022/06/02 13:09:55 [INFO] checking version 0.3.3 for lib libpact_ffi within semver range >= 0.1.2, < 1.0.0
2022/06/02 13:09:55 [INFO] checking version 0.3.3 of libpact_ffi against semver constraint >= 0.1.2, < 1.0.0
2022/06/02 13:09:55 [DEBUG] 0.3.3 satisfies constraints 0.3.3 >= 0.1.2, < 1.0.0
2022/06/02 13:09:55 [DEBUG] version check completed
2022/06/02 13:10:21 [DEBUG] starting new proxy with opts {http localhost:8080  0 [0x1036d5910] /__setup <nil>}
2022/06/02 13:10:21 [DEBUG] starting reverse proxy on port 49359
2022/06/02 13:10:21 [DEBUG] waiting for port 49359 to become available
2022/06/02 13:10:21 [DEBUG] pact provider verification
2022/06/02 13:10:21 [DEBUG] initialising rust mock server interface
2022/06/02 13:10:22 [DEBUG] waiting for port 49359 to become available
2022/06/02 13:10:24 [DEBUG] executing verifier FFI with args [--file /Users/nunofrias/Documents/repos/entitlement-orchestrator/cmd/pacts/reseller-entitlement-service-entitlement-orchestrator.json --hostname localhost --port 49359 --provider-name entitlement-orchestrator --loglevel trace]

Hangs here !
I proceeded to debug the rust ffi code and found that the exact point where it hangs is in the
make_provider_request
function in
<http://provider_client.rs|provider_client.rs>
, more precisely in:
Copy code
let response = request.send()
    .map_err(|err| anyhow!(err))
    .and_then(native_response_to_pact_response)
    .await?;
More curiously I have also noticed that the first time I run the provider verification after I start the terminal application, it succeeds. Subsequent verifications fails more often than not -- if I restart the command line the verification succeeds. I would dearly appreciate some help as my knowledge of rust is rather basic. Thank you.
m

Matt (pactflow.io / pact-js / pact-go)

06/07/2022, 11:50 AM
Hi Nuno, thanks for diving into this
what would be great to know: • Does it only do this on certain OS’s (e.g. Mac but not linux)? • Which version of Pact Go are you running
The “it works once” makes me wonder if any processes are up and about. For example, when it hangs above, can you send http calls to the provider? eg.
curl localhost:49359
or to the proxied target (the actual provider)?
n

Nuno Frias

06/07/2022, 11:54 AM
Hi Matt I am using
go version go1.17.6 darwin/arm64
I am running on Mac OS 12 (and it is an M1 chip) I suspect there are some processes outstanding. I am about to enable
dtruss
(strace equivalent) to try and pinpoint the error.
I can send calls to
localhost:49359
and I see the server responses.
m

Matt (pactflow.io / pact-js / pact-go)

06/07/2022, 11:55 AM
Thanks! What version of pact go?
n

Nuno Frias

06/07/2022, 11:57 AM
v2.0.0-beta.11
👍 1
I am using the
v2.x.x
branch.
m

Matt (pactflow.io / pact-js / pact-go)

06/07/2022, 11:58 AM
🤔
have you got a github actions / some build we can see running that reproduces the issue? Does it only happen on M1 (FYI I’m running an M1)
n

Nuno Frias

06/07/2022, 12:02 PM
I don't have a build you can test. What I can do is actually run the examples on pact-go and see if the problem occurs. I'll try on Linux (raspberry py) to see if I can see the issue there.
On it
I managed to reproduce it with the examples in Pact go. I am sending a patch file with some very minor changes to the default examples namely to the provider test. Essentially I am commenting out the ProviderVersion BrokerURL ConsumerVersionSelectors PublishVerificationResults as I am using a local pact file and to simplify this scenario I am bypassing the communication with the broker. I also comment out the StateHandlers bit as it caused the test to hang on the state change rather than on running the actual provider request -- the underlying issue seems identical. To set up the example you only need to:
Copy code
git checkout 2.x.x
 git pull
 git apply pact_go_examples.diff
 cd pact-go/examples
 go test -run ^TestConsumerV3$ .
 go test -tags provider -run ^TestV3HTTPProvider$
I am still working on setting up the GitHub actions (but let me know if the above suffices).
I should have a github action ready briefly.
Here it is. This project contains a minimal example. Apologies for taking this long, I am not used to github actions. https://github.com/nsfrias/pact-go-issue-repro-20220607
As of now I am still waiting for the results of the
macos-12
(which I hope behave similarly to my Mac). https://github.com/nsfrias/pact-go-issue-repro-20220607/actions/runs/2456922279
In ubuntu the issue does not occur.
m

Matt (pactflow.io / pact-js / pact-go)

06/07/2022, 10:57 PM
Thanks Nuno. I can see that it worked on linux too, but the mac build is hanging 🤷‍♂️
n

Nuno Frias

06/08/2022, 12:47 PM
I am having difficulty running the build against even a x86 macos https://github.com/nsfrias/pact-go-issue-repro-20220607/runs/6793692978?check_suite_focus=true Would it be possible for you to install the project locally on an M1 platform and run the test?
👍 1
I added some manual reproduction steps on the README
m

Matt (pactflow.io / pact-js / pact-go)

06/09/2022, 5:56 AM
Copy code
➜  /tmp git clone <https://github.com/nsfrias/pact-go-issue-repro-20220607.git>
Cloning into 'pact-go-issue-repro-20220607'...
remote: Enumerating objects: 63, done.
remote: Counting objects: 100% (63/63), done.
remote: Compressing objects: 100% (31/31), done.
remote: Total 63 (delta 22), reused 48 (delta 11), pack-reused 0
Receiving objects: 100% (63/63), 26.85 KiB | 8.95 MiB/s, done.
Resolving deltas: 100% (22/22), done.
➜  /tmp cd pact-go-issue-repro-20220607
➜  pact-go-issue-repro-20220607 git:(main) go install <http://github.com/pact-foundation/pact-go/v2@2.x.x|github.com/pact-foundation/pact-go/v2@2.x.x>

go: downloading <http://github.com/pact-foundation/pact-go/v2|github.com/pact-foundation/pact-go/v2> v2.0.0-beta.11.0.20220607035712-b017cad30d3d
➜  pact-go-issue-repro-20220607 git:(main) pact-go -l DEBUG install
2022/06/09 15:54:22 [INFO] package libpact_ffi found
2022/06/09 15:54:22 [INFO] checking version 0.3.2 of libpact_ffi against semver constraint >= 0.3.0, < 1.0.0
2022/06/09 15:54:22 [DEBUG] 0.3.2 satisfies constraints 0.3.2 >= 0.3.0, < 1.0.0
2022/06/09 15:54:22 [INFO] package libpact_ffi is correctly installed
2022/06/09 15:54:22 [DEBUG] skip checking ffi version() call because FFI not loaded. This is expected when running the 'pact-go' command.

➜  pact-go-issue-repro-20220607 git:(main) go test -run "^TestConsumerV3$" consumer_test.go
go: downloading github.com/stretchr/testify v1.7.2
go: downloading github.com/golang/protobuf v1.3.3
ok  	command-line-arguments	0.846s
➜  pact-go-issue-repro-20220607 git:(main) go test -timeout 30s -run "^TestV3HTTPProvider$" .
ok  	example.com/m	3.618s
➜  pact-go-issue-repro-20220607 git:(main) go test -v -timeout 30s -run "^TestV3HTTPProvider$" .
=== RUN   TestV3HTTPProvider
2022/06/09 15:55:26 [INFO] package libpact_ffi found
2022/06/09 15:55:26 [INFO] checking version 0.3.2 for lib libpact_ffi within semver range >= 0.1.2, < 1.0.0
2022/06/09 15:55:26 [INFO] checking version 0.3.2 of libpact_ffi against semver constraint >= 0.1.2, < 1.0.0
2022/06/09 15:55:26 [DEBUG] 0.3.2 satisfies constraints 0.3.2 >= 0.1.2, < 1.0.0
2022/06/09 15:55:26 [DEBUG] version check completed
2022/06/09 15:55:26 [DEBUG] starting new proxy with opts {http localhost:8111  0 [0x4390e60 0x4391160 0x461c1c0] /__setup <nil>}
2022/06/09 15:55:26 [DEBUG] starting reverse proxy on port 64647
2022/06/09 15:55:26 [DEBUG] waiting for port 64647 to become available
2022/06/09 15:55:26 [DEBUG] pact provider verification
2022/06/09 15:55:26 [DEBUG] initialising rust mock server interface
2022/06/09 15:55:26 [DEBUG] waiting for port 64647 to become available
2022/06/09 15:55:26 [DEBUG] executing verifier FFI with args [--file /tmp/pact-go-issue-repro-20220607/pacts/PactGoV3Consumer-V3Provider.json --hostname localhost --port 64647 --provider-name V3Provider --loglevel trace]
  Given User foo exists
    WARNING: State Change ignored as there is no state change URL provided
2022/06/09 15:55:28 [DEBUG] HOOK request filter
2022/06/09 15:55:28 [DEBUG] http reverse proxy received connection from [::1]:64653 on path /foobar?baz=bar&baz=bat&baz=baz
2022/06/09 15:55:28 [DEBUG] setting proxy to target
2022/06/09 15:55:28 [DEBUG] incoming request /foobar?baz=bar&baz=bat&baz=baz
2022/06/09 15:55:28 [DEBUG] outgoing request to target <http://localhost:8111/foobar?baz=bar&baz=bat&baz=baz>
2022/06/09 15:55:28 [TRACE] proxy outgoing request
 POST /foobar?baz=bar&baz=bat&baz=baz HTTP/1.1
Host: localhost:8111
User-Agent: Pact Go
Content-Length: 76
Accept: */*
Accept-Encoding: gzip, deflate
Authorization: Bearer 1234
Authorization: Bearer 1234-dynamic-value
Content-Type: application/json
X-Forwarded-For: ::1


2022/06/09 15:55:28 [TRACE] proxied server response
 HTTP/1.1 200 OK
Content-Length: 458
Content-Type: application/json
Date: Thu, 09 Jun 2022 05:55:28 GMT


			{
				"accountBalance": 123.76,
				"datetime": "2020-01-01",
				"equality": "a thing",
				"id": 12,
				"itemsMin": [
					"thereshouldbe3ofthese",
					"thereshouldbe3ofthese",
					"thereshouldbe3ofthese"
				],
				"itemsMinMax": [
					27,
					27,
					27,
					27,
					27
				],
				"lastName": "Sampson",
				"name": "Billy",
				"superstring": "foo",
				"arrayContaining": [
					"string",
					1,
					{
						"foo": "bar"
					}
				]
			}
2022/06/09 15:55:28 [DEBUG] executing after hook
2022/06/09 15:55:28 [DEBUG] HOOK after each
  Given User foo exists
    WARNING: State Change ignored as there is no state change URL provided
2022/06/09 15:55:28 [DEBUG] HOOK request filter
2022/06/09 15:55:28 [DEBUG] http reverse proxy received connection from [::1]:64656 on path /foobar?baz=bar&baz=bat&baz=baz
2022/06/09 15:55:28 [DEBUG] setting proxy to target
2022/06/09 15:55:28 [DEBUG] incoming request /foobar?baz=bar&baz=bat&baz=baz
2022/06/09 15:55:28 [DEBUG] outgoing request to target <http://localhost:8111/foobar?baz=bar&baz=bat&baz=baz>
2022/06/09 15:55:28 [TRACE] proxy outgoing request
 POST /foobar?baz=bar&baz=bat&baz=baz HTTP/1.1
Host: localhost:8111
User-Agent: Pact Go
Content-Length: 76
Accept: */*
Accept-Encoding: gzip, deflate
Authorization: Bearer 1234
Authorization: Bearer 1234-dynamic-value
Content-Type: application/json
X-Forwarded-For: ::1


2022/06/09 15:55:28 [TRACE] proxied server response
 HTTP/1.1 200 OK
Content-Length: 458
Content-Type: application/json
Date: Thu, 09 Jun 2022 05:55:28 GMT


			{
				"accountBalance": 123.76,
				"datetime": "2020-01-01",
				"equality": "a thing",
				"id": 12,
				"itemsMin": [
					"thereshouldbe3ofthese",
					"thereshouldbe3ofthese",
					"thereshouldbe3ofthese"
				],
				"itemsMinMax": [
					27,
					27,
					27,
					27,
					27
				],
				"lastName": "Sampson",
				"name": "Billy",
				"superstring": "foo",
				"arrayContaining": [
					"string",
					1,
					{
						"foo": "bar"
					}
				]
			}
2022/06/09 15:55:28 [DEBUG] executing after hook
2022/06/09 15:55:28 [DEBUG] HOOK after each
  Given User foo exists
    WARNING: State Change ignored as there is no state change URL provided
2022/06/09 15:55:29 [DEBUG] HOOK request filter
2022/06/09 15:55:29 [DEBUG] http reverse proxy received connection from [::1]:64659 on path /foobar?baz=bar&baz=bat&baz=baz
2022/06/09 15:55:29 [DEBUG] setting proxy to target
2022/06/09 15:55:29 [DEBUG] incoming request /foobar?baz=bar&baz=bat&baz=baz
2022/06/09 15:55:29 [DEBUG] outgoing request to target <http://localhost:8111/foobar?baz=bar&baz=bat&baz=baz>
2022/06/09 15:55:29 [TRACE] proxy outgoing request
 POST /foobar?baz=bar&baz=bat&baz=baz HTTP/1.1
Host: localhost:8111
User-Agent: Pact Go
Content-Length: 76
Accept: */*
Accept-Encoding: gzip, deflate
Authorization: Bearer 1234
Authorization: Bearer 1234-dynamic-value
Content-Type: application/json
X-Forwarded-For: ::1


2022/06/09 15:55:29 [TRACE] proxied server response
 HTTP/1.1 200 OK
Content-Length: 458
Content-Type: application/json
Date: Thu, 09 Jun 2022 05:55:29 GMT


			{
				"accountBalance": 123.76,
				"datetime": "2020-01-01",
				"equality": "a thing",
				"id": 12,
				"itemsMin": [
					"thereshouldbe3ofthese",
					"thereshouldbe3ofthese",
					"thereshouldbe3ofthese"
				],
				"itemsMinMax": [
					27,
					27,
					27,
					27,
					27
				],
				"lastName": "Sampson",
				"name": "Billy",
				"superstring": "foo",
				"arrayContaining": [
					"string",
					1,
					{
						"foo": "bar"
					}
				]
			}
2022/06/09 15:55:29 [DEBUG] executing after hook
2022/06/09 15:55:29 [DEBUG] HOOK after each

Verifying a pact between PactGoV3Consumer and V3Provider

  A request to do a foo
    returns a response which
      has status code 200 (OK)
      includes headers
        "Content-Type" with value "application/json" (OK)
      has a matching body (OK)


Verifying a pact between PactGoV3Consumer and V3Provider

  A request to do a foo
    returns a response which
      has status code 200 (OK)
      includes headers
        "Content-Type" with value "application/json" (OK)
      has a matching body (OK)


Verifying a pact between V3Consumer and V3Provider

  A request to do a foo
    returns a response which
      has status code 200 (OK)
      includes headers
        "Content-Type" with value "application/json" (OK)
      has a matching body (OK)


=== RUN   TestV3HTTPProvider/Provider_pact_verification
--- PASS: TestV3HTTPProvider (3.10s)
    --- PASS: TestV3HTTPProvider/Provider_pact_verification (0.00s)
PASS
ok  	<http://example.com/m|example.com/m>	3.663s
output from `go env`:
Copy code
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/Users/matthew.fellows/Library/Caches/go-build"
GOENV="/Users/matthew.fellows/Library/Application Support/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOINSECURE=""
GOMODCACHE="/Users/matthew.fellows/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="darwin"
GOPATH="/Users/matthew.fellows/go"
GOPRIVATE=""
GOPROXY="<https://proxy.golang.org>,direct"
GOROOT="/usr/local/Cellar/go/1.18.2/libexec"
GOSUMDB="<http://sum.golang.org|sum.golang.org>"
GOTMPDIR=""
GOTOOLDIR="/usr/local/Cellar/go/1.18.2/libexec/pkg/tool/darwin_amd64"
GOVCS=""
GOVERSION="go1.18.2"
GCCGO="gccgo"
GOAMD64="v1"
AR="ar"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD="/tmp/pact-go-issue-repro-20220607/go.mod"
GOWORK=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -arch x86_64 -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/gl/c3f3yhws1mg754r_t7l5hfm80000gp/T/go-build2365344512=/tmp/go-build -gno-record-gcc-switches -fno-common"
message has been deleted
n

Nuno Frias

06/10/2022, 8:54 AM
Thank you very much
I still encounter the same issue, so does a colleague with M1.
The only difference is the
go env
m

Matt (pactflow.io / pact-js / pact-go)

06/10/2022, 9:17 AM
Are you running in Rosetta mode or normal? Have you tried both?
Are they work machines or personal? Is it possible there is AV or endpoint security interference?
n

Nuno Frias

06/10/2022, 9:17 AM
I am running in normal mode. I have had some issues with rosetta in the past.
Work machines
👍 1
m

Matt (pactflow.io / pact-js / pact-go)

06/10/2022, 9:20 AM
I wish we could run builds on M1 to create a reproducible environment. Unfortunately there are no real options to do so at the moment
n

Nuno Frias

06/10/2022, 9:20 AM
I am trying to run in rosetta mode
That said I manage to workaround the issue by running the tests on a linux VM running on my mac
Btw I add to add another
cgo
config to run pact-go in linux arm64.
Copy code
diff --git a/internal/native/lib.go b/internal/native/lib.go
index 9ece6b7..d4324ff 100644
--- a/internal/native/lib.go
+++ b/internal/native/lib.go
@@ -6,5 +6,6 @@ package native
 #cgo darwin,amd64 LDFLAGS: -L/tmp -L/usr/local/lib -Wl,-rpath -Wl,/tmp -Wl,-rpath -Wl,/usr/local/lib -lpact_ffi
 #cgo windows,amd64 LDFLAGS: -lpact_ffi
 #cgo linux,amd64 LDFLAGS: -L/tmp -L/opt/pact/lib -L/usr/local/lib -Wl,-rpath -Wl,/opt/pact/lib -Wl,-rpath -Wl,/tmp -Wl,-rpath -Wl,/usr/local/lib -lpact_ffi
+#cgo linux,arm64 LDFLAGS: -L/tmp -L/opt/pact/lib -L/usr/local/lib -Wl,-rpath -Wl,/opt/pact/lib -Wl,-rpath -Wl,/tmp -Wl,-rpath -Wl,/usr/local/lib -lpact_ffi
 */
 import "C"
Will submit a merge request for that asap
👍 1
m

Matt (pactflow.io / pact-js / pact-go)

06/10/2022, 9:30 AM
Does it work on Linux arm? I don't think it should, to my knowledge we don't compile for it: https://github.com/pact-foundation/pact-reference/releases/tag/libpact_ffi-v0.3.2
n

Nuno Frias

06/10/2022, 9:30 AM
I compiled for it locally
m

Matt (pactflow.io / pact-js / pact-go)

06/10/2022, 9:35 AM
Ah, got it.
Fair enough we can definitely bring that in
n

Nuno Frias

06/10/2022, 9:40 AM
I feel sheepish now. I gave it a try with rosetta and it is passing consistently.
😆 1
Thank you very much for all the help.
🙌 1
m

Matt (pactflow.io / pact-js / pact-go)

06/10/2022, 9:41 AM
But it should be able to work outside of Rosetta. That's a good clue though. I should be able to repro that situation
🙌 1