Protobuf plugin can not startup correctly on Windows randomly

[tienvx]

Sometime, on Windows, protobuf plugin can not startup correctly, and then timeout after 60 seconds.

Here is short log:

2024-02-19T02:58:23.844829Z ERROR ThreadId(01) pact_plugin_driver::child_process: Timeout waiting to get plugin startup info: timed out waiting on channel
2024-02-19T02:58:24.360667Z ERROR ThreadId(01) pact_ffi::plugins: Could not load plugin - Plugin process did not output the correct startup message in 60 seconds: timed out waiting on channel

How to reproduce:

I'm afraid that I can't reproduce it because it happen randomly.

Information:

• OS: Windows 10.0.20348 (Windows Server 2022 Datacenter) [64-bit] (Github Actions)
• Plugin version: 0.3.13
• Spec: 4.0.0
• Test: Consumer

Here is longer log:

.2024-02-19T02:57:23.841280Z DEBUG ThreadId(01) pact_ffi::plugins: pact_ffi::plugins::pactffi_using_plugin FFI function invoked
2024-02-19T02:57:23.841395Z DEBUG ThreadId(01) pact_plugin_driver::catalogue_manager: Updated catalogue entries:
core/transport/http
core/transport/https
2024-02-19T02:57:23.841428Z 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
2024-02-19T02:57:23.841483Z 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
2024-02-19T02:57:23.841728Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Loading plugin PluginDependency { name: "protobuf", version: None, dependency_type: Plugin }
2024-02-19T02:57:23.841768Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Did not find plugin, will attempt to start it
2024-02-19T02:57:23.841840Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Loading plugin manifest for plugin PluginDependency { name: "protobuf", version: None, dependency_type: Plugin }
2024-02-19T02:57:23.841886Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Looking for plugin in "C:\\Users\\runneradmin\\.pact/plugins"
2024-02-19T02:57:23.842067Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Found plugin manifest: "C:\\Users\\runneradmin\\.pact/plugins\\csv-0.0.5\\pact-plugin.json"
2024-02-19T02:57:23.842193Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Found plugin manifest: "C:\\Users\\runneradmin\\.pact/plugins\\protobuf-0.3.13\\pact-plugin.json"
2024-02-19T02:57:23.842305Z DEBUG ThreadId(01) pact_plugin_driver::metrics: 'PACT_DO_NOT_TRACK' environment variable is set, will not send metrics
2024-02-19T02:57:23.842314Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Starting plugin with manifest PactPluginManifest { plugin_dir: "C:\\Users\\runneradmin\\.pact/plugins\\protobuf-0.3.13", plugin_interface_version: 1, name: "protobuf", version: "0.3.13", 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")} }
2024-02-19T02:57:23.842371Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Detected OS: Windows 10.0.20348 (Windows Server 2022 Datacenter) [64-bit]
2024-02-19T02:57:23.842382Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Starting plugin using "C:\\Users\\runneradmin\\.pact/plugins\\protobuf-0.3.13\\pact-protobuf-plugin"
2024-02-19T02:57:23.843784Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Plugin protobuf started with PID 6924
2024-02-19T02:58:23.844829Z ERROR ThreadId(01) pact_plugin_driver::child_process: Timeout waiting to get plugin startup info: timed out waiting on channel
2024-02-19T02:58:24.360667Z ERROR ThreadId(01) pact_ffi::plugins: Could not load plugin - Plugin process did not output the correct startup message in 60 seconds: timed out waiting on channel
2024-02-19T02:58:24.360931Z DEBUG ThreadId(01) pact_plugin_driver::catalogue_manager: Looking for a content matcher for application/protobuf
2024-02-19T02:58:24.361601Z DEBUG ThreadId(01) pact_ffi::plugins: No matcher was found, will default to the core framework

Here is the link to the failed pipeline:

(it will be unavailable after a while) https://github.com/tienvx/pact-php/actions/runs/7953938471/job/21710645421

[tienvx]

I have a work around for this: Run tests in different jobs for Windows on Github Actions.

pact-foundation/pact-php#497

[tienvx]

That work around doesn't always work. I revert that work around.

This problem is gone. I'm not sure why and how. Probably because the old plugin was cached in Github Actions CI.