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

consumer-go test: connection reset while testing in docker environment #28

Closed
nikplxjt opened this issue Jun 7, 2023 · 9 comments
Closed

Comments

@nikplxjt
Copy link

nikplxjt commented Jun 7, 2023

Hi there

I am currently trying to get the gRPC plugin to work in a Docker container to generate a pact for a Go based application. The problem is that seemingly the mock server that should respond to the gRPC calls of my code is booted in a way that the actual test can not connect to it (or at least this my hypothesis from the logs that I saw). I already tried setting the hostToBindTo parameter in the pact-plugin.json, but this had no effect and the test crashed again.

The definition for my container looks like this

FROM golang:1.20-bullseye

ARG PACT_GO_VERSION=v2.0.0-beta.18
ARG PACT_PLUGIN_CLI_VERSION=v0.0.0
ARG PACT_PLUGIN_PROTOBUF_VERSION=v-0.3.2
ARG BUF_VERSION=v1.21.0

# Install deps
RUN apt clean && apt update
RUN apt install -y git-core gcc wget protobuf-compiler golang-goprotobuf-dev

# Install pact-go
RUN go install github.com/pact-foundation/pact-go/v2@${PACT_GO_VERSION}
RUN pact-go install

# Install buf
RUN go install github.com/bufbuild/buf/cmd/buf@${BUF_VERSION}

# Install pact-plugin-cli + protobuf plugin
RUN wget https://github.com/pact-foundation/pact-plugins/releases/download/pact-plugin-cli-${PACT_PLUGIN_CLI_VERSION}/pact-plugin-cli-linux-x86_64.gz
RUN gunzip pact-plugin-cli-linux-x86_64.gz
RUN mv pact-plugin-cli-linux-x86_64 /usr/local/bin/pact-plugin-cli && chmod +x /usr/local/bin/pact-plugin-cli
RUN pact-plugin-cli -y install https://github.com/pactflow/pact-protobuf-plugin/releases/tag/${PACT_PLUGIN_PROTOBUF_VERSION}

When I build the image and start a container the pact-plugin.json looks like this:

cat ~/.pact/plugins/protobuf-0.3.2/pact-plugin.json
{"pluginInterfaceVersion":1,"name":"protobuf","version":"0.3.2","executableType":"exec","minimumRequiredVersion":null,"entryPoint":"pact-protobuf-plugin","entryPoints":{},"dependencies":null,"pluginConfig":{"downloadUrl":"https://github.com/protocolbuffers/protobuf/releases/download","hostToBindTo":"127.0.0.1","protocVersion":"3.19.1"}}

Which looks like the config described in the README that one should use for a Docker based environment.

When I start the test for go-consumer of the area calculator within the container, instead of generating the pact, I receive the following logs and pact crashes:

root@585454ab6a72:/build/consumer-go# LOG_LEVEL=debug go test .
2023/06/07 13:17:45 [DEBUG] pact synchronous message validate config
2023/06/07 13:17:45 [DEBUG] initialising rust mock server interface
2023/06/07 13:17:45 [DEBUG] log_to_stdout res 0
2023/06/07 13:17:45 [DEBUG] add sync message
2023-06-07T13:17:45.023038Z DEBUG ThreadId(01) pact_ffi::plugins: pact_ffi::plugins::pactffi_using_plugin FFI function invoked
2023-06-07T13:17:45.023173Z DEBUG ThreadId(01) pact_plugin_driver::catalogue_manager: Updated catalogue entries:
core/transport/http
core/transport/https
2023-06-07T13:17:45.023254Z DEBUG ThreadId(01) pact_plugin_driver::catalogue_manager: Updated catalogue entries:
core/content-generator/binary
core/content-generator/json
core/content-matcher/json
core/content-matcher/multipart-form-data
core/content-matcher/text
core/content-matcher/xml
2023-06-07T13:17:45.023349Z DEBUG ThreadId(01) pact_plugin_driver::catalogue_manager: Updated catalogue entries:
core/matcher/v1-equality
core/matcher/v2-max-type
core/matcher/v2-min-type
core/matcher/v2-minmax-type
core/matcher/v2-regex
core/matcher/v2-type
core/matcher/v3-content-type
core/matcher/v3-date
core/matcher/v3-datetime
core/matcher/v3-decimal-type
core/matcher/v3-includes
core/matcher/v3-integer-type
core/matcher/v3-null
core/matcher/v3-number-type
core/matcher/v3-time
core/matcher/v4-array-contains
core/matcher/v4-equals-ignore-order
core/matcher/v4-max-equals-ignore-order
core/matcher/v4-min-equals-ignore-order
core/matcher/v4-minmax-equals-ignore-order
core/matcher/v4-not-empty
core/matcher/v4-semver
2023-06-07T13:17:45.025271Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Loading plugin PluginDependency { name: "protobuf", version: None, dependency_type: Plugin }
2023-06-07T13:17:45.025306Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Did not find plugin, will start it
2023-06-07T13:17:45.025312Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Loading plugin manifest for plugin PluginDependency { name: "protobuf", version: None, dependency_type: Plugin }
2023-06-07T13:17:45.025326Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Looking for plugin in "/root/.pact/plugins"
2023-06-07T13:17:45.025400Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Found plugin manifest: "/root/.pact/plugins/protobuf-0.3.2/pact-plugin.json"
2023-06-07T13:17:45.025492Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Starting plugin with manifest PactPluginManifest { plugin_dir: "/root/.pact/plugins/protobuf-0.3.2", plugin_interface_version: 1, name: "protobuf", version: "0.3.2", executable_type: "exec", minimum_required_version: None, entry_point: "pact-protobuf-plugin", entry_points: {}, args: None, dependencies: None, plugin_config: {"hostToBindTo": String("127.0.0.1"), "protocVersion": String("3.19.1"), "downloadUrl": String("https://github.com/protocolbuffers/protobuf/releases/download")} }
2023-06-07T13:17:45.025527Z  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-06-07T13:17:45.025577Z DEBUG tokio-runtime-worker pact_plugin_driver::metrics: Sending event to GA - {"cd5": "0.3.2", "ev": "1", "t": "event", "v": "1", "aip": "true", "cd2": "unknown", "cd4": "protobuf", "cd3": "linux-x86_64", "av": "0.2.2", "el": "Plugin loaded", "tid": "UA-117778936-1", "cid": "af44999b0efc91ef53762b484f2fcc14", "ec": "Plugin", "an": "pact-plugins-rust", "ds": "pact-plugins-rust", "aid": "pact-plugins-rust", "ea": "Loaded"}
2023-06-07T13:17:45.025942Z DEBUG ThreadId(01) os_info::imp::lsb_release: lsb_release command failed with Os { code: 2, kind: NotFound, message: "No such file or directory" }
2023-06-07T13:17:45.026507Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Detected OS: Linux [64-bit]
2023-06-07T13:17:45.026529Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Starting plugin using "/root/.pact/plugins/protobuf-0.3.2/pact-protobuf-plugin"
2023-06-07T13:17:45.026686Z DEBUG tokio-runtime-worker reqwest::connect: starting new connection: https://www.google-analytics.com/
2023-06-07T13:17:45.026781Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Plugin protobuf started with PID 3373
2023-06-07T13:17:45.026796Z DEBUG tokio-runtime-worker hyper::client::connect::dns: resolving host="www.google-analytics.com"
2023-06-07T13:17:45.030883Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || {"port":42865, "serverKey":"8f4905bf-59d2-4806-9604-cff64e05a037"}
2023-06-07T13:17:45.030943Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Plugin process started OK (port = 42865), sending init message
2023-06-07T13:17:45.031046Z DEBUG ThreadId(01) hyper::client::connect::http: connecting to [::1]:42865
2023-06-07T13:17:45.031101Z DEBUG ThreadId(01) pact_plugin_driver::plugin_models: IP6 connection failed, will try IP4 address - transport error
2023-06-07T13:17:45.031117Z DEBUG ThreadId(01) hyper::client::connect::http: connecting to 127.0.0.1:42865
2023-06-07T13:17:45.031225Z DEBUG ThreadId(01) hyper::client::connect::http: connected to 127.0.0.1:42865
2023-06-07T13:17:45.031244Z DEBUG ThreadId(01) h2::client: binding client connection
2023-06-07T13:17:45.031279Z DEBUG ThreadId(01) h2::client: client connection bound
2023-06-07T13:17:45.031298Z DEBUG ThreadId(01) h2::codec::framed_write: send frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 }
2023-06-07T13:17:45.031341Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.031303Z DEBUG tokio-runtime-worker h2::codec::framed_write: send frame=Settings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384, max_header_list_size: 16777216 }
2023-06-07T13:17:45.031378Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_write: send frame=WindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
2023-06-07T13:17:45.031430Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_read: received frame=Settings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384, max_header_list_size: 16777216 }
2023-06-07T13:17:45.031438Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_write: send frame=Settings { flags: (0x1: ACK) }
2023-06-07T13:17:45.031496Z DEBUG tokio-runtime-worker tower::buffer::worker: service.ready=true processing request
2023-06-07T13:17:45.031519Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.031488Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_read: received frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 }
2023-06-07T13:17:45.031538Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.031518Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_write: send frame=Settings { flags: (0x1: ACK) }
2023-06-07T13:17:45.031560Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.031538Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_read: received frame=WindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
2023-06-07T13:17:45.031562Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_write: send frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
2023-06-07T13:17:45.031572Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.031557Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_read: received frame=Settings { flags: (0x1: ACK) }
2023-06-07T13:17:45.031579Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_write: send frame=Data { stream_id: StreamId(1) }
2023-06-07T13:17:45.031584Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_write: send frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
2023-06-07T13:17:45.031588Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.031572Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::proto::settings: received settings ACK; applying Settings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384, max_header_list_size: 16777216 }
2023-06-07T13:17:45.031635Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.031597Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_write: send frame=WindowUpdate { stream_id: StreamId(0), size_increment: 983041 }
2023-06-07T13:17:45.031647Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_read: received frame=Settings { flags: (0x1: ACK) }
2023-06-07T13:17:45.031669Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::proto::settings: received settings ACK; applying Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 }
2023-06-07T13:17:45.031676Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_read: received frame=WindowUpdate { stream_id: StreamId(0), size_increment: 983041 }
2023-06-07T13:17:45.031723Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.031695Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_read: received frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
2023-06-07T13:17:45.031770Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.031753Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_read: received frame=Data { stream_id: StreamId(1) }
2023-06-07T13:17:45.031780Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.031769Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_read: received frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
2023-06-07T13:17:45.031850Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.031834Z DEBUG tokio-runtime-worker request{method=POST uri=http://127.0.0.1:42865/io.pact.plugin.PactPlugin/InitPlugin version=HTTP/2.0 headers={"te": "trailers", "content-type": "application/grpc", "authorization": Sensitive, "user-agent": "tonic/0.8.3"}}: tower_http::trace::on_request: started processing request
2023-06-07T13:17:45.031924Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.031907Z DEBUG tokio-runtime-worker request{method=POST uri=http://127.0.0.1:42865/io.pact.plugin.PactPlugin/InitPlugin version=HTTP/2.0 headers={"te": "trailers", "content-type": "application/grpc", "authorization": Sensitive, "user-agent": "tonic/0.8.3"}}: pact_protobuf_plugin::server: Init request from plugin-driver-rust/0.2.2
2023-06-07T13:17:45.031958Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.031941Z DEBUG tokio-runtime-worker request{method=POST uri=http://127.0.0.1:42865/io.pact.plugin.PactPlugin/InitPlugin version=HTTP/2.0 headers={"te": "trailers", "content-type": "application/grpc", "authorization": Sensitive, "user-agent": "tonic/0.8.3"}}: tower_http::trace::on_response: finished processing request latency=0 ms
2023-06-07T13:17:45.032022Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.032006Z DEBUG tokio-runtime-worker request{method=POST uri=http://127.0.0.1:42865/io.pact.plugin.PactPlugin/InitPlugin version=HTTP/2.0 headers={"te": "trailers", "content-type": "application/grpc", "authorization": Sensitive, "user-agent": "tonic/0.8.3"}}: tower_http::trace::on_eos: end of stream stream_duration=0 ms status=0
2023-06-07T13:17:45.032056Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.032038Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_write: send frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
2023-06-07T13:17:45.032074Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.032060Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_write: send frame=Data { stream_id: StreamId(1) }
2023-06-07T13:17:45.032091Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.032078Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_write: send frame=Headers { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) }
2023-06-07T13:17:45.048063Z DEBUG tokio-runtime-worker hyper::client::connect::http: connecting to 142.250.186.46:443
2023-06-07T13:17:45.067316Z DEBUG tokio-runtime-worker hyper::client::connect::http: connected to 142.250.186.46:443
2023-06-07T13:17:45.067359Z DEBUG tokio-runtime-worker rustls::client::hs: No cached session for DnsName(DnsName(DnsName("www.google-analytics.com")))
2023-06-07T13:17:45.067402Z DEBUG tokio-runtime-worker rustls::client::hs: Not resuming any session
2023-06-07T13:17:45.072659Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_read: received frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
2023-06-07T13:17:45.072711Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_read: received frame=Data { stream_id: StreamId(1) }
2023-06-07T13:17:45.072729Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_read: received frame=Headers { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) }
2023-06-07T13:17:45.072998Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Got init response InitPluginResponse { catalogue: [CatalogueEntry { r#type: ContentMatcher, key: "protobuf", values: {"content-types": "application/protobuf;application/grpc"} }, CatalogueEntry { r#type: ContentGenerator, key: "protobuf", values: {"content-types": "application/protobuf;application/grpc"} }, CatalogueEntry { r#type: Transport, key: "grpc", values: {} }] } from plugin protobuf
2023-06-07T13:17:45.073061Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_write: send frame=GoAway { error_code: NO_ERROR, last_stream_id: StreamId(0) }
2023-06-07T13:17:45.073077Z DEBUG ThreadId(01) pact_plugin_driver::catalogue_manager: Updated catalogue entries:
core/content-generator/binary
core/content-generator/json
core/content-matcher/json
core/content-matcher/multipart-form-data
core/content-matcher/text
core/content-matcher/xml
core/matcher/v1-equality
core/matcher/v2-max-type
core/matcher/v2-min-type
core/matcher/v2-minmax-type
core/matcher/v2-regex
core/matcher/v2-type
core/matcher/v3-content-type
core/matcher/v3-date
core/matcher/v3-datetime
core/matcher/v3-decimal-type
core/matcher/v3-includes
core/matcher/v3-integer-type
core/matcher/v3-null
core/matcher/v3-number-type
core/matcher/v3-time
core/matcher/v4-array-contains
core/matcher/v4-equals-ignore-order
core/matcher/v4-max-equals-ignore-order
core/matcher/v4-min-equals-ignore-order
core/matcher/v4-minmax-equals-ignore-order
core/matcher/v4-not-empty
core/matcher/v4-semver
core/transport/http
core/transport/https
plugin/protobuf/content-generator/protobuf
plugin/protobuf/content-matcher/protobuf
plugin/protobuf/transport/grpc
2023-06-07T13:17:45.073090Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::proto::connection: Connection::poll; connection error error=GoAway(b"", NO_ERROR, Library)
2023-06-07T13:17:45.073323Z DEBUG tokio-runtime-worker hyper::client::connect::http: connecting to [::1]:42865
2023-06-07T13:17:45.073386Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.073291Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_read: received frame=GoAway { error_code: NO_ERROR, last_stream_id: StreamId(0) }
2023-06-07T13:17:45.073418Z DEBUG tokio-runtime-worker pact_plugin_driver::plugin_models: IP6 connection failed, will try IP4 address - transport error
2023-06-07T13:17:45.073435Z DEBUG tokio-runtime-worker hyper::client::connect::http: connecting to 127.0.0.1:42865
2023-06-07T13:17:45.073638Z DEBUG tokio-runtime-worker hyper::client::connect::http: connected to 127.0.0.1:42865
2023-06-07T13:17:45.073679Z DEBUG tokio-runtime-worker h2::client: binding client connection
2023-06-07T13:17:45.073736Z DEBUG tokio-runtime-worker h2::client: client connection bound
2023-06-07T13:17:45.073761Z DEBUG tokio-runtime-worker h2::codec::framed_write: send frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 }
2023-06-07T13:17:45.073864Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_write: send frame=WindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
2023-06-07T13:17:45.073882Z DEBUG tokio-runtime-worker tower::buffer::worker: service.ready=true processing request
2023-06-07T13:17:45.073888Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.073747Z DEBUG tokio-runtime-worker h2::codec::framed_write: send frame=Settings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384, max_header_list_size: 16777216 }
2023-06-07T13:17:45.073899Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.073869Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_write: send frame=WindowUpdate { stream_id: StreamId(0), size_increment: 983041 }
2023-06-07T13:17:45.073924Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_read: received frame=Settings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384, max_header_list_size: 16777216 }
2023-06-07T13:17:45.073936Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_write: send frame=Settings { flags: (0x1: ACK) }
2023-06-07T13:17:45.073949Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_read: received frame=WindowUpdate { stream_id: StreamId(0), size_increment: 983041 }
2023-06-07T13:17:45.073966Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_write: send frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
2023-06-07T13:17:45.074061Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_write: send frame=Data { stream_id: StreamId(1) }
2023-06-07T13:17:45.074069Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.074001Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_read: received frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 }
2023-06-07T13:17:45.074112Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_write: send frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
2023-06-07T13:17:45.074115Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.074078Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_write: send frame=Settings { flags: (0x1: ACK) }
2023-06-07T13:17:45.074136Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.074115Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_read: received frame=WindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
2023-06-07T13:17:45.074207Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_read: received frame=Settings { flags: (0x1: ACK) }
2023-06-07T13:17:45.074237Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::proto::settings: received settings ACK; applying Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 }
2023-06-07T13:17:45.074262Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.074231Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_read: received frame=Settings { flags: (0x1: ACK) }
2023-06-07T13:17:45.074278Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.074258Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::proto::settings: received settings ACK; applying Settings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384, max_header_list_size: 16777216 }
2023-06-07T13:17:45.074336Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.074313Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_read: received frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
2023-06-07T13:17:45.074377Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.074357Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_read: received frame=Data { stream_id: StreamId(1) }
2023-06-07T13:17:45.074405Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.074384Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_read: received frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
2023-06-07T13:17:45.074505Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.074483Z DEBUG tokio-runtime-worker request{method=POST uri=http://127.0.0.1:42865/io.pact.plugin.PactPlugin/UpdateCatalogue version=HTTP/2.0 headers={"te": "trailers", "content-type": "application/grpc", "authorization": Sensitive, "user-agent": "tonic/0.8.3"}}: tower_http::trace::on_request: started processing request
2023-06-07T13:17:45.074663Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.074640Z DEBUG tokio-runtime-worker request{method=POST uri=http://127.0.0.1:42865/io.pact.plugin.PactPlugin/UpdateCatalogue version=HTTP/2.0 headers={"te": "trailers", "content-type": "application/grpc", "authorization": Sensitive, "user-agent": "tonic/0.8.3"}}: pact_protobuf_plugin::server: Update catalogue request
2023-06-07T13:17:45.074713Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.074692Z DEBUG tokio-runtime-worker request{method=POST uri=http://127.0.0.1:42865/io.pact.plugin.PactPlugin/UpdateCatalogue version=HTTP/2.0 headers={"te": "trailers", "content-type": "application/grpc", "authorization": Sensitive, "user-agent": "tonic/0.8.3"}}: tower_http::trace::on_response: finished processing request latency=0 ms
2023-06-07T13:17:45.074809Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.074786Z DEBUG tokio-runtime-worker request{method=POST uri=http://127.0.0.1:42865/io.pact.plugin.PactPlugin/UpdateCatalogue version=HTTP/2.0 headers={"te": "trailers", "content-type": "application/grpc", "authorization": Sensitive, "user-agent": "tonic/0.8.3"}}: tower_http::trace::on_eos: end of stream stream_duration=0 ms status=0
2023-06-07T13:17:45.074871Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.074847Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_write: send frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
2023-06-07T13:17:45.074908Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.074889Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_write: send frame=Data { stream_id: StreamId(1) }
2023-06-07T13:17:45.074932Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.074914Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_write: send frame=Headers { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) }
2023-06-07T13:17:45.094489Z DEBUG tokio-runtime-worker rustls::client::hs: Using ciphersuite TLS13_AES_256_GCM_SHA384
2023-06-07T13:17:45.094530Z DEBUG tokio-runtime-worker rustls::client::tls13: Not resuming
2023-06-07T13:17:45.100350Z DEBUG tokio-runtime-worker rustls::client::tls13: TLS1.3 encrypted extensions: [Protocols([6832])]
2023-06-07T13:17:45.100383Z DEBUG tokio-runtime-worker rustls::client::hs: ALPN protocol is Some(b"h2")
2023-06-07T13:17:45.101010Z DEBUG tokio-runtime-worker h2::client: binding client connection
2023-06-07T13:17:45.101024Z DEBUG tokio-runtime-worker h2::client: client connection bound
2023-06-07T13:17:45.101042Z DEBUG tokio-runtime-worker h2::codec::framed_write: send frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 }
2023-06-07T13:17:45.101175Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_write: send frame=WindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
2023-06-07T13:17:45.101127Z DEBUG tokio-runtime-worker hyper::client::pool: pooling idle connection for ("https", www.google-analytics.com)
2023-06-07T13:17:45.101366Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_write: send frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
2023-06-07T13:17:45.101401Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_write: send frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
2023-06-07T13:17:45.114732Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_read: received frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
2023-06-07T13:17:45.114798Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_read: received frame=Data { stream_id: StreamId(1) }
2023-06-07T13:17:45.114818Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_read: received frame=Headers { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) }
2023-06-07T13:17:45.114991Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_write: send frame=GoAway { error_code: NO_ERROR, last_stream_id: StreamId(0) }
2023-06-07T13:17:45.115019Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::proto::connection: Connection::poll; connection error error=GoAway(b"", NO_ERROR, Library)
2023-06-07T13:17:45.115203Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.115140Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_read: received frame=GoAway { error_code: NO_ERROR, last_stream_id: StreamId(0) }
2023-06-07T13:17:45.115275Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.115244Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::codec::framed_write: send frame=GoAway { error_code: NO_ERROR, last_stream_id: StreamId(1) }
2023-06-07T13:17:45.115316Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.115283Z DEBUG tokio-runtime-worker Connection{peer=Server}: h2::proto::connection: Connection::poll; connection error error=GoAway(b"", NO_ERROR, Library)
2023-06-07T13:17:45.115409Z DEBUG tokio-runtime-worker pact_plugin_driver::child_process: Plugin(protobuf, 3373, STDOUT) || 2023-06-07T13:17:45.115384Z DEBUG tokio-runtime-worker hyper::server::server::new_svc: connection error: connection error: not connected
2023-06-07T13:17:45.142165Z DEBUG tokio-runtime-worker Connection{peer=Client}: rustls::client::tls13: Ticket saved
2023-06-07T13:17:45.142247Z DEBUG tokio-runtime-worker Connection{peer=Client}: rustls::client::tls13: Ticket saved
2023-06-07T13:17:45.142272Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_read: received frame=Settings { flags: (0x0), max_concurrent_streams: 100, initial_window_size: 1048576, max_header_list_size: 65536 }
2023-06-07T13:17:45.142290Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_write: send frame=Settings { flags: (0x1: ACK) }
2023-06-07T13:17:45.142307Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_read: received frame=WindowUpdate { stream_id: StreamId(0), size_increment: 983041 }
2023-06-07T13:17:45.142322Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_read: received frame=Settings { flags: (0x1: ACK) }
2023-06-07T13:17:45.142330Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::proto::settings: received settings ACK; applying Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 }
2023-06-07T13:17:45.149095Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_read: received frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
2023-06-07T13:17:45.149159Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_read: received frame=Data { stream_id: StreamId(1) }
2023-06-07T13:17:45.149174Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_read: received frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
2023-06-07T13:17:45.149186Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_read: received frame=Ping { ack: false, payload: [0, 0, 0, 0, 0, 0, 0, 0] }
2023-06-07T13:17:45.149198Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_write: send frame=Ping { ack: true, payload: [0, 0, 0, 0, 0, 0, 0, 0] }
2023-06-07T13:17:45.149451Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::codec::framed_write: send frame=GoAway { error_code: NO_ERROR, last_stream_id: StreamId(0) }
2023-06-07T13:17:45.149468Z DEBUG tokio-runtime-worker Connection{peer=Client}: h2::proto::connection: Connection::poll; connection error error=GoAway(b"", NO_ERROR, Library)
2023-06-07T13:17:45.149492Z DEBUG tokio-runtime-worker Connection{peer=Client}: rustls::conn: Sending warning alert CloseNotify
2023-06-07T13:17:45.574861Z DEBUG ThreadId(01) pact_plugin_driver::catalogue_manager: Looking for a content matcher for application/grpc
2023-06-07T13:17:45.575464Z DEBUG ThreadId(01) pact_ffi::plugins: Found a matcher for 'application/grpc': ContentMatcher { catalogue_entry: CatalogueEntry { entry_type: CONTENT_MATCHER, provider_type: PLUGIN, plugin: Some(PactPluginManifest { plugin_dir: "/root/.pact/plugins/protobuf-0.3.2", plugin_interface_version: 1, name: "protobuf", version: "0.3.2", executable_type: "exec", minimum_required_version: None, entry_point: "pact-protobuf-plugin", entry_points: {}, args: None, dependencies: None, plugin_config: {"hostToBindTo": String("127.0.0.1"), "protocVersion": String("3.19.1"), "downloadUrl": String("https://github.com/protocolbuffers/protobuf/releases/download")} }), key: "protobuf", values: {"content-types": "application/protobuf;application/grpc"} } }
2023-06-07T13:17:45.575497Z DEBUG ThreadId(01) pact_ffi::plugins: Plugin matcher, will get the plugin to provide the part contents
2023-06-07T13:17:45.575648Z DEBUG ThreadId(01) pact_plugin_driver::content: Sending ConfigureContents request to plugin CatalogueEntry { entry_type: CONTENT_MATCHER, provider_type: PLUGIN, plugin: Some(PactPluginManifest { plugin_dir: "/root/.pact/plugins/protobuf-0.3.2", plugin_interface_version: 1, name: "protobuf", version: "0.3.2", executable_type: "exec", minimum_required_version: None, entry_point: "pact-protobuf-plugin", entry_points: {}, args: None, dependencies: None, plugin_config: {"hostToBindTo": String("127.0.0.1"), "protocVersion": String("3.19.1"), "downloadUrl": String("https://github.com/protocolbuffers/protobuf/releases/download")} }), key: "protobuf", values: {"content-types": "application/protobuf;application/grpc"} }
2023-06-07T13:17:45.575716Z DEBUG ThreadId(01) hyper::client::connect::http: connecting to [::1]:42865
2023-06-07T13:17:45.575776Z DEBUG ThreadId(01) pact_plugin_driver::plugin_models: IP6 connection failed, will try IP4 address - transport error
2023-06-07T13:17:45.575790Z DEBUG ThreadId(01) hyper::client::connect::http: connecting to 127.0.0.1:42865
2023-06-07T13:17:45.575933Z DEBUG ThreadId(01) hyper::client::connect::http: connected to 127.0.0.1:42865
2023-06-07T13:17:45.575949Z DEBUG ThreadId(01) h2::client: binding client connection
2023-06-07T13:17:45.575980Z DEBUG ThreadId(01) h2::client: client connection bound
2023-06-07T13:17:45.575996Z DEBUG ThreadId(01) h2::codec::framed_write: send frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 }
2023-06-07T13:17:45.576097Z DEBUG   ffi-setup_contents Connection{peer=Client}: h2::codec::framed_write: send frame=WindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
2023-06-07T13:17:45.576158Z DEBUG   ffi-setup_contents tower::buffer::worker: service.ready=true processing request
2023-06-07T13:17:45.576336Z DEBUG   ffi-setup_contents Connection{peer=Client}: h2::codec::framed_write: send frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
2023-06-07T13:17:45.576382Z DEBUG   ffi-setup_contents Connection{peer=Client}: h2::codec::framed_write: send frame=Data { stream_id: StreamId(1) }
2023-06-07T13:17:45.576490Z DEBUG   ffi-setup_contents hyper::client::service: connection error: hyper::Error(Io, Kind(BrokenPipe))
2023-06-07T13:17:45.576506Z DEBUG   ffi-setup_contents hyper::proto::h2::client: connection error: connection reset
2023-06-07T13:17:45.576528Z DEBUG   ffi-setup_contents hyper::proto::h2::client: client response error: broken pipe
2023-06-07T13:17:45.576571Z ERROR ThreadId(01) pact_plugin_driver::content: Call to plugin failed - status: Unknown, message: "transport error", details: [], metadata: MetadataMap { headers: {} }
2023-06-07T13:17:45.576678Z ERROR ThreadId(01) pact_ffi::plugins: Failed to call out to plugin - Call to plugin failed - status: Unknown, message: "transport error", details: [], metadata: MetadataMap { headers: {} }
2023/06/07 13:17:45 [DEBUG] mock server starting on address: 127.0.0.1 0
2023-06-07T13:17:45.576852Z DEBUG ThreadId(01) pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}: pact_ffi::mock_server: pact_ffi::mock_server::pactffi_create_mock_server_for_transport FFI function invoked
2023-06-07T13:17:45.577066Z DEBUG ThreadId(01) pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}: pact_plugin_driver::plugin_manager: Sending startMockServer request to plugin plugin_name="protobuf" plugin_version="0.3.2"
2023-06-07T13:17:45.577211Z DEBUG ThreadId(01) pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}: hyper::client::connect::http: connecting to [::1]:42865
2023-06-07T13:17:45.577284Z DEBUG ThreadId(01) pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}: pact_plugin_driver::plugin_models: IP6 connection failed, will try IP4 address - transport error
2023-06-07T13:17:45.577302Z DEBUG ThreadId(01) pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}: hyper::client::connect::http: connecting to 127.0.0.1:42865
2023-06-07T13:17:45.577425Z DEBUG ThreadId(01) pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}: hyper::client::connect::http: connected to 127.0.0.1:42865
2023-06-07T13:17:45.577447Z DEBUG ThreadId(01) pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}: h2::client: binding client connection
2023-06-07T13:17:45.577482Z DEBUG ThreadId(01) pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}: h2::client: client connection bound
2023-06-07T13:17:45.577497Z DEBUG ThreadId(01) pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}: h2::codec::framed_write: send frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 }
2023-06-07T13:17:45.577545Z DEBUG tokio-runtime-worker pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}:Connection{peer=Client}: h2::codec::framed_write: send frame=WindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
2023-06-07T13:17:45.577622Z DEBUG tokio-runtime-worker pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}:Connection{peer=Client}: h2::proto::connection: Connection::poll; IO error error=ConnectionReset
2023-06-07T13:17:45.577657Z DEBUG tokio-runtime-worker hyper::proto::h2::client: connection error: connection reset
2023-06-07T13:17:45.577672Z DEBUG tokio-runtime-worker hyper::client::service: connection error: hyper::Error(Io, Kind(ConnectionReset))
2023-06-07T13:17:45.577727Z DEBUG tokio-runtime-worker pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}: hyper::client::connect::http: connecting to 127.0.0.1:42865
2023-06-07T13:17:45.577844Z DEBUG tokio-runtime-worker pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}: hyper::client::connect::http: connected to 127.0.0.1:42865
2023-06-07T13:17:45.577862Z DEBUG tokio-runtime-worker pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}: h2::client: binding client connection
2023-06-07T13:17:45.577888Z DEBUG tokio-runtime-worker pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}: h2::client: client connection bound
2023-06-07T13:17:45.577907Z DEBUG tokio-runtime-worker pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}: h2::codec::framed_write: send frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 }
2023-06-07T13:17:45.577950Z DEBUG tokio-runtime-worker pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}: tower::buffer::worker: service.ready=true processing request
2023-06-07T13:17:45.578018Z DEBUG tokio-runtime-worker pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}:Connection{peer=Client}: h2::codec::framed_write: send frame=WindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
2023-06-07T13:17:45.578034Z DEBUG tokio-runtime-worker pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}:Connection{peer=Client}: h2::codec::framed_write: send frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
2023-06-07T13:17:45.578060Z DEBUG tokio-runtime-worker pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}:Connection{peer=Client}: h2::codec::framed_write: send frame=Data { stream_id: StreamId(1) }
2023-06-07T13:17:45.578094Z DEBUG tokio-runtime-worker hyper::proto::h2::client: connection error: connection reset
2023-06-07T13:17:45.578107Z DEBUG tokio-runtime-worker hyper::proto::h2::client: client response error: broken pipe
2023-06-07T13:17:45.578126Z DEBUG tokio-runtime-worker hyper::client::service: connection error: hyper::Error(Io, Kind(BrokenPipe))
2023-06-07T13:17:45.578164Z ERROR ThreadId(01) pactffi_create_mock_server_for_transport{pact=PactHandle { pact_ref: 1 } addr=0x1becf50 port=0 transport=0x1be1910 transport_config=0x7f2348000b60}: pact_ffi::mock_server: Failed to start mock server - status: Unknown, message: "transport error", details: [], metadata: MetadataMap { headers: {} }
2023/06/07 13:17:45 unable to start plugin transport: unable to start the mock server
FAIL	area_calculator/consumer	0.565s
FAIL

I currently don't know if I forgot to configure something the right way or if this is some kind of networking error.
I hope I provided all the necessary info. Thanks for looking into it!

@YOU54F
Copy link
Member

YOU54F commented Jun 7, 2023

TY for providing a Dockerfile

Just tried running the plugin directly in the container which fails

docker run --platform=linux/amd64 --rm pact-go:latest -c 'cat $HOME/.pact/plugins/protobuf-0.3.2/pact-plugin.json'

{
  "pluginInterfaceVersion": 1,
  "name": "protobuf",
  "version": "0.3.2",
  "executableType": "exec",
  "minimumRequiredVersion": null,
  "entryPoint": "pact-protobuf-plugin",
  "entryPoints": {},
  "dependencies": null,
  "pluginConfig": {
    "downloadUrl": "https://github.com/protocolbuffers/protobuf/releases/download",
    "protocVersion": "3.19.1",
    "hostToBindTo": "127.0.0.1"
  }
}

docker run --platform=linux/amd64 --rm pact-go:latest -c '$HOME/.pact/plugins/protobuf-0.3.2/pact-protobuf-plugin'

Error: Failed to bind to host '[::1]'

Caused by:
    Address not available (os error 99)

I tweaked it slightly to lock the platform --platform=linux/amd64 and added an entry point for testing

FROM --platform=linux/amd64 golang:1.20-bullseye

ARG PACT_GO_VERSION=v2.0.0-beta.18
ARG PACT_PLUGIN_CLI_VERSION=v0.0.0
ARG PACT_PLUGIN_PROTOBUF_VERSION=v-0.3.2
ARG BUF_VERSION=v1.21.0

# Install deps
RUN apt clean && apt update
RUN apt install -y git-core gcc wget protobuf-compiler golang-goprotobuf-dev

# Install pact-go
RUN go install github.com/pact-foundation/pact-go/v2@${PACT_GO_VERSION}
RUN pact-go install

# Install buf
RUN go install github.com/bufbuild/buf/cmd/buf@${BUF_VERSION}

# Install pact-plugin-cli + protobuf plugin
RUN wget https://github.com/pact-foundation/pact-plugins/releases/download/pact-plugin-cli-${PACT_PLUGIN_CLI_VERSION}/pact-plugin-cli-linux-x86_64.gz
RUN gunzip pact-plugin-cli-linux-x86_64.gz
RUN mv pact-plugin-cli-linux-x86_64 /usr/local/bin/pact-plugin-cli && chmod +x /usr/local/bin/pact-plugin-cli
RUN pact-plugin-cli -y install https://github.com/pactflow/pact-protobuf-plugin/releases/tag/${PACT_PLUGIN_PROTOBUF_VERSION}
ENTRYPOINT [ "/bin/bash" ]

@YOU54F
Copy link
Member

YOU54F commented Jun 7, 2023

Hmm

It isn't picking up the hostToBindTo from the config but will pick up the --h <host> command

root@5f781238efcb:/go# $HOME/.pact/plugins/protobuf-0.3.2/pact-protobuf-plugin --help
Pact plugin for Protobufs and gRPC

Usage: pact-protobuf-plugin [OPTIONS]

Options:
      --help               Print help and exit
  -v, --version            Print version information and exit
  -t, --timeout <timeout>  Timeout in seconds to use for inactivity to shutdown the plugin process. Default is 600 seconds (10 minutes)
  -h, --host <host>        Host to bind to. Defaults to [::1], which is the IP6 loopback address

root@5f781238efcb:/go# $HOME/.pact/plugins/protobuf-0.3.2/pact-protobuf-plugin -h 127.0.0.1
{"port":35353, "serverKey":"6112dec6-9220-4e35-9d04-8e477b9cef61"}

@YOU54F
Copy link
Member

YOU54F commented Jun 7, 2023

hmm, so it works if you pass it the args directly

FROM --platform=linux/amd64 golang:1.20-bullseye

ARG PACT_GO_VERSION=v2.0.0-beta.18
ARG PACT_PLUGIN_CLI_VERSION=v0.0.0
ARG PACT_PLUGIN_PROTOBUF_VERSION=v-0.3.2
ARG BUF_VERSION=v1.21.0

# Install deps
RUN apt clean && apt update
RUN apt install -y git-core gcc wget protobuf-compiler golang-goprotobuf-dev

# Install pact-go
RUN go install github.com/pact-foundation/pact-go/v2@${PACT_GO_VERSION}
RUN pact-go install

# Install buf
RUN go install github.com/bufbuild/buf/cmd/buf@${BUF_VERSION}

# Install pact-plugin-cli + protobuf plugin
RUN wget https://github.com/pact-foundation/pact-plugins/releases/download/pact-plugin-cli-${PACT_PLUGIN_CLI_VERSION}/pact-plugin-cli-linux-x86_64.gz
RUN gunzip pact-plugin-cli-linux-x86_64.gz
RUN mv pact-plugin-cli-linux-x86_64 /usr/local/bin/pact-plugin-cli && chmod +x /usr/local/bin/pact-plugin-cli
RUN pact-plugin-cli -y install https://github.com/pactflow/pact-protobuf-plugin/releases/tag/${PACT_PLUGIN_PROTOBUF_VERSION}
ENTRYPOINT [ "/bin/bash","-c","~/.pact/plugins/protobuf-0.3.2/pact-protobuf-plugin -h 127.0.0.1" ]

run with

docker run --platform=linux/amd64 --rm -it --init pact-go:latest

docker run --platform=linux/amd64 --rm -it --init pact-go:latest
{"port":41081, "serverKey":"b62ebe99-d27f-462e-9e4d-3935c3203613"}

Now I am sure

  1. The args is documented somewhere, as something you can put in the pact-plugin.json
  2. It really should be reading the config anyway, it seems that it doesn't, this feels like a regression, as it has in the past, 110% in my testing

@YOU54F
Copy link
Member

YOU54F commented Jun 7, 2023

So when we start the mock server here (via the plugin)

let grpc_mock_server = GrpcMockServer::new(pact, &plugin_config, test_context);
let server_key = grpc_mock_server.server_key.clone();
match grpc_mock_server.start_server(request.host_interface.as_str(), request.port, request.tls).await {

we take the plugin_config and pass it to create a new gRPC server

but when we start it, we pass the request.host_interface rather than anything from the plugin_config`

match grpc_mock_server.start_server(request.host_interface.as_str(), request.port, request.tls).await {

@rholshausen
Copy link
Contributor

Just a note, the plugin executable assumes it's current working directory is set to the plugin directory, so running the following works:

❯ docker run --platform=linux/amd64 --rm -it pact-go:latest -c 'cd $HOME/.pact/plugins/protobuf-0.3.2 && $HOME/.pact/plugins/protobuf-0.3.2/pact-protobuf-plugin'
{"port":36319, "serverKey":"4e57f784-90ea-4237-81ef-eae32a3428a3"}

@rholshausen
Copy link
Contributor

This is not only affecting docker environments, looks like our example CI build is failing in the same way.

2023-06-08T01:00:55.190106Z DEBUG tokio-runtime-worker hyper::proto::h2::client: client response error: broken pipe
2023-06-08T01:00:55.190109Z TRACE tokio-runtime-worker want: signal: Closed    
2023-06-08T01:00:55.190110Z DEBUG tokio-runtime-worker hyper::client::service: connection error: hyper::Error(Io, Kind(BrokenPipe))

@rholshausen
Copy link
Contributor

Hmm, it works for me upgrading Pact-Go to the latest:
ARG PACT_GO_VERSION=v2.0.0-beta.18 -> ARG PACT_GO_VERSION=v2.0.0-beta.21

Then:

❯ docker run --rm -it -v $(pwd):/build c5e7e9f56677
root@fb18a1ced615:/go# cd /build/consumer-go/
root@fb18a1ced615:/build/consumer-go# LOG_LEVEL=trace go test .
ok      area_calculator/consumer        2.718s
root@fb18a1ced615:/build/consumer-go# 
exit

@nikplxjt
Copy link
Author

nikplxjt commented Jun 8, 2023

Hey guys

Thanks for looking into the problem. Upgrading to beta.21 also fixed the problem in my case. It might be good to update the documented examples to the latest version too. Anyways I guess we can close this issue.

@YOU54F
Copy link
Member

YOU54F commented May 17, 2024

Thanks for letting us know, will aim to get all the examples updated.

To anyone reading this, we will always be happy to accept updates to our examples!

@YOU54F YOU54F closed this as completed May 17, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants