pact-go icon indicating copy to clipboard operation
pact-go copied to clipboard

Unable to Call AddSynchronousMessage() Multiple Times within the same Go Test

Open wesley-newcomb-hpe opened this issue 11 months ago • 0 comments

Software versions

  • OS: Debian GNU/Linux
  • Consumer Pact library: github.com/pact-foundation/pact-go/v2 v2.0.0-beta.22
  • Provider Pact library: github.com/pact-foundation/pact-go/v2 v2.0.0-beta.22
  • Golang Version: go version go1.20.3 linux/amd64
  • Golang environment: GO111MODULE="" GOARCH="amd64" GOBIN="" GOCACHE="/home/dev/.cache/go-build" GOENV="/home/dev/.config/go/env" GOEXE="" GOEXPERIMENT="" GOFLAGS="" GOHOSTARCH="amd64" GOHOSTOS="linux" GOINSECURE="" GOMODCACHE="/home/dev/go/pkg/mod" GONOPROXY="github.hpe.com" GONOSUMDB="github.hpe.com" GOOS="linux" GOPATH="/home/dev/go" GOPRIVATE="github.hpe.com" GOPROXY="https://proxy.golang.org,direct" GOROOT="/usr/local/go" GOSUMDB="sum.golang.org" GOTMPDIR="" GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64" GOVCS="" GOVERSION="go1.20.3" GCCGO="gccgo" GOAMD64="v1" AR="ar" CC="gcc" CXX="g++" CGO_ENABLED="1" GOMOD="/dev/null" 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 -fdebug-prefix-map=/tmp/go-build2062648544=/tmp/go-build -gno-record-gcc-switches"

Expected behaviour

Using gRPC workflow. When calling (*message.SynchronousPact).AddSynchronousMessage() twice or multiple times within the same test the test should pass and a contract should be generated.

Actual behaviour

if you have multiple (*message.SynchronousPact).AddSynchronousMessage() calls within the same go test, e.g. func TestConsumer(t *testing.T){…} you will get the following errors.

2023-07-13T16:02:55.872397Z ERROR ThreadId(01) pact_mock_server::server_manager: Failed to shutdown plugin mock server with ID 97fa0c1e-3e37-4199-807f-3c16e3c0a94c - transport error

2023-07-13T16:02:56.418779Z ERROR ThreadId(01) pact_ffi::plugins: Mock server is already started

Steps to reproduce

From example https://github.com/pact-foundation/pact-go/blob/master/examples/grpc/grpc_consumer_test.go. If you add a second call to p.AddSynchronousMessage()... within the func TestGrpcInteraction(t *testing.T) {...} and change log level to "ERROR" this should reproduce the issue.

Relevent logs

2023-07-17T14:36:14.723148Z  INFO ThreadId(14) pact_mock_server: Writing pact out to '/home/dev/ws/settings/test/contract-ci/consumer/grpc/../../pacts/settings-grpc-consumer-dualauth-grpc.json'
2023-07-17T14:36:14.726784Z DEBUG ThreadId(14) pact_models::pact: Merging pact with file "/home/dev/ws/settings/test/contract-ci/consumer/grpc/../../pacts/settings-grpc-consumer-dualauth-grpc.json"
2023/07/17 14:36:14 [DEBUG] mock server cleaning up port: 34821
2023-07-17T14:36:14.736261Z DEBUG ThreadId(14) pact_matching::metrics: Could not get the tokio runtime, will not send metrics - there is no reactor running, must be called from the context of a Tokio 1.x runtime
2023-07-17T14:36:14.736291Z DEBUG ThreadId(14) pact_plugin_driver::plugin_manager: Sending shutdownMockServer request to plugin plugin_name="protobuf" plugin_version="0.3.4" server_key="24c28c6e-a883-4cf3-9697-bb30af72c8e6"
2023-07-17T14:36:14.736330Z DEBUG ThreadId(14) hyper::client::connect::http: connecting to [::1]:40995
2023-07-17T14:36:14.736404Z DEBUG ThreadId(14) pact_plugin_driver::plugin_models: IP6 connection failed, will try IP4 address - transport error
2023-07-17T14:36:14.736465Z DEBUG ThreadId(14) hyper::client::connect::http: connecting to 127.0.0.1:40995
2023-07-17T14:36:14.736821Z ERROR ThreadId(14) pact_mock_server::server_manager: Failed to shutdown plugin mock server with ID 1e482b06-4946-4907-89c7-119ad24d74a8 - transport error
2023/07/17 14:36:14 [DEBUG] add sync message
2023-07-17T14:36:14.736886Z DEBUG ThreadId(14) pact_ffi::plugins: pact_ffi::plugins::pactffi_using_plugin FFI function invoked
2023-07-17T14:36:14.736919Z DEBUG ThreadId(14) pact_plugin_driver::plugin_manager: Loading plugin PluginDependency { name: "protobuf", version: Some("0.3.4"), dependency_type: Plugin }
2023-07-17T14:36:14.736927Z DEBUG ThreadId(14) pact_plugin_driver::plugin_manager: Did not find plugin, will attempt to start it
2023-07-17T14:36:14.736929Z DEBUG ThreadId(14) pact_plugin_driver::plugin_manager: Loading plugin manifest for plugin PluginDependency { name: "protobuf", version: Some("0.3.4"), dependency_type: Plugin }
2023-07-17T14:36:14.736940Z DEBUG ThreadId(14) pact_plugin_driver::plugin_manager: Starting plugin with manifest PactPluginManifest { plugin_dir: "/home/dev/.pact/plugins/protobuf-0.3.4", plugin_interface_version: 1, name: "protobuf", version: "0.3.4", executable_type: "exec", minimum_required_version: None, entry_point: "pact-protobuf-plugin", entry_points: {}, args: None, dependencies: None, plugin_config: {"downloadUrl": String("https://github.com/protocolbuffers/protobuf/releases/download"), "hostToBindTo": String("127.0.0.1"), "protocVersion": String("3.19.1")} }
2023-07-17T14:36:14.737469Z  WARN tokio-runtime-worker pact_plugin_driver::metrics:

Please note:
We are tracking this plugin load anonymously to gather important usage statistics.
To disable tracking, set the 'PACT_DO_NOT_TRACK' environment variable to 'true'.


2023-07-17T14:36:14.737523Z DEBUG tokio-runtime-worker pact_plugin_driver::metrics: Sending event to GA - {"aid": "pact-plugins-rust", "ds": "pact-plugins-rust", "tid": "UA-117778936-1", "el": "Plugin loaded", "ea": "Loaded", "cd2": "unknown", "av": "0.4.4", "ev": "1", "cd4": "protobuf", "ec": "Plugin", "cd3": "linux-x86_64", "cd5": "0.3.4", "v": "1", "t": "event", "cid": "49ba4cc7dfe11f8511543582286d62fe", "an": "pact-plugins-rust", "aip": "true"}
2023-07-17T14:36:14.738448Z DEBUG tokio-runtime-worker reqwest::connect: starting new connection: https://www.google-analytics.com/
2023-07-17T14:36:14.738689Z DEBUG tokio-runtime-worker hyper::client::connect::dns: resolving host="www.google-analytics.com"
2023-07-17T14:36:14.748209Z DEBUG tokio-runtime-worker hyper::client::connect::http: connecting to 142.250.138.138:443
2023-07-17T14:36:14.779303Z DEBUG ThreadId(14) pact_plugin_driver::plugin_manager: Detected OS: Debian 11 (bullseye) [64-bit]
2023-07-17T14:36:14.779359Z DEBUG ThreadId(14) pact_plugin_driver::plugin_manager: Starting plugin using "/home/dev/.pact/plugins/protobuf-0.3.4/pact-protobuf-plugin"
2023-07-17T14:36:14.779831Z DEBUG ThreadId(14) pact_plugin_driver::plugin_manager: Plugin protobuf started with PID 5098
2023-07-17T14:36:14.788468Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 5098, STDOUT) || {"port":44847, "serverKey":"ee7aab73-b5a6-4d74-ac2a-304c77980133"}
2023-07-17T14:36:14.788577Z DEBUG ThreadId(14) pact_plugin_driver::plugin_manager: Plugin process started OK (port = 44847), sending init message
2023-07-17T14:36:14.788844Z DEBUG ThreadId(14) hyper::client::connect::http: connecting to [::1]:44847
2023-07-17T14:36:14.789042Z DEBUG ThreadId(14) pact_plugin_driver::plugin_models: IP6 connection failed, will try IP4 address - transport error
2023-07-17T14:36:14.789106Z DEBUG ThreadId(14) hyper::client::connect::http: connecting to 127.0.0.1:44847
2023-07-17T14:36:14.789853Z DEBUG ThreadId(14) hyper::client::connect::http: connected to 127.0.0.1:44847
2023-07-17T14:36:14.789891Z DEBUG ThreadId(14) h2::client: binding client connection
2023-07-17T14:36:14.789957Z DEBUG ThreadId(14) h2::client: client connection bound
2023-07-17T14:36:14.789965Z DEBUG ThreadId(14) h2::codec::framed_write: send frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 }

...

2023-07-17T14:36:15.066294Z DEBUG tokio-runtime-worker Connection{peer=Client}: rustls::common_state: Sending warning alert CloseNotify
2023-07-17T14:36:15.293009Z ERROR ThreadId(14) pact_ffi::plugins: Mock server is already started
2023/07/17 14:36:15 [DEBUG] mock server starting on address: 127.0.0.1 0
2023-07-17T14:36:15.293154Z DEBUG ThreadId(14) pact_ffi::mock_server: pact_ffi::mock_server::pactffi_create_mock_server_for_transport FFI function invoked
2023-07-17T14:36:15.293278Z DEBUG ThreadId(14) pact_plugin_driver::plugin_manager: Sending startMockServer request to plugin plugin_name="protobuf" plugin_version="0.3.4"
2023-07-17T14:36:15.293377Z DEBUG ThreadId(14) hyper::client::connect::http: connecting to [::1]:44847
2023-07-17T14:36:15.293551Z DEBUG ThreadId(14) pact_plugin_driver::plugin_models: IP6 connection failed, will try IP4 address - transport error
2023-07-17T14:36:15.293612Z DEBUG ThreadId(14) hyper::client::connect::http: connecting to 127.0.0.1:44847
2023-07-17T14:36:15.293895Z DEBUG ThreadId(14) hyper::client::connect::http: connected to 127.0.0.1:44847
2023-07-17T14:36:15.293994Z DEBUG ThreadId(14) h2::client: binding client connection
2023-07-17T14:36:15.294051Z DEBUG ThreadId(14) h2::client: client connection bound
2023-07-17T14:36:15.294082Z DEBUG ThreadId(14) h2::codec::framed_write: send frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 }

...

2023/07/17 14:36:15 [DEBUG] mock server running on port: 39529
2023/07/17 14:36:15 [DEBUG] GetMessageRequestContents
2023-07-17T14:36:15.298129Z DEBUG ThreadId(14) pact_ffi::mock_server::handles: pact_ffi::mock_server::handles::pactffi_pact_handle_get_sync_message_iter FFI function invoked
2023-07-17T14:36:15.298178Z DEBUG ThreadId(14) pact_ffi::models::iterators: pact_ffi::models::iterators::pactffi_pact_sync_message_iter_next FFI function invoked
2023-07-17T14:36:15.298189Z DEBUG ThreadId(14) pact_ffi::models::iterators: pact_ffi::models::iterators::pactffi_pact_sync_message_iter_next FFI function invoked
2023-07-17T14:36:15.298193Z DEBUG ThreadId(14) pact_ffi::models::sync_message: pact_ffi::models::sync_message::pactffi_sync_message_get_request_contents_length FFI function invoked
2023/07/17 14:36:15 [DEBUG] message body is empty
2023-07-17T14:36:15.298201Z DEBUG ThreadId(14) pact_ffi::mock_server::handles: pact_ffi::mock_server::handles::pactffi_pact_handle_get_sync_message_iter FFI function invoked
2023-07-17T14:36:15.298219Z DEBUG ThreadId(14) pact_ffi::models::iterators: pact_ffi::models::iterators::pactffi_pact_sync_message_iter_next FFI function invoked
2023-07-17T14:36:15.298222Z DEBUG ThreadId(14) pact_ffi::models::sync_message: pact_ffi::models::sync_message::pactffi_sync_message_get_response_contents_length FFI function invoked
2023-07-17T14:36:15.298225Z DEBUG ThreadId(14) pact_ffi::models::sync_message: pact_ffi::models::sync_message::pactffi_sync_message_get_response_contents_bin FFI function invoked
2023-07-17T14:36:15.298227Z DEBUG ThreadId(14) pact_ffi::models::iterators: pact_ffi::models::iterators::pactffi_pact_sync_message_iter_next FFI function invoked
2023-07-17T14:36:15.298229Z DEBUG ThreadId(14) pact_ffi::models::sync_message: pact_ffi::models::sync_message::pactffi_sync_message_get_response_contents_length FFI function invoked
2023-07-17T14:36:15.298494Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_write: send frame=GoAway { error_code: NO_ERROR, last_stream_id: StreamId(0) }

wesley-newcomb-hpe avatar Jul 17 '23 14:07 wesley-newcomb-hpe