Verifier.verifyProvider(): Failed Publish Step for Large Contract

[pfesenmeier]

Issue Classification

• Feature request
• [ x] Bug report

Bug Report

Software versions

• OS: Alpine Linux 3.11 (Docker image)
• Consumer Pact library: @pact-foundation/pact 9.11.0, @pact-foundation/pact-node 10.9.4
• Provider Pact library: @pact-foundation/pact 9.14.0
• Node Version: 12.19.0

Issue Checklist

Confirm the following:

• [x ] I have upgraded to the latest
• I have created a reproducable git repository (see below) to illuminate the problem
• [x ] I have the read the FAQs in the Readme
• [x ] I have triple checked, that there are no unhandled promises in my code
• [x ] I have set my log level to debug and attached a log file showing the complete request/response cycle

Expected behaviour

Verify 52 interactions and publish the results

Actual behaviour

Verify 52 interactions and receive an error at the publish step

Steps to reproduce

Unfortunately, my source code is closed source.
In our CI 'Contract Test' step, our provider verifies two consumer contracts, one of ~7 interactions, and then one of ~50 interactions. The smaller one is verified and published successfully, then the larger one is verified and the fails on publication.

Are there any known capability limits to the publish step as this time?

Relevant log files

For the latest version of @pact-foundation/pact:

15:47:03   | DEBUG: Setting up provider state 'redacted' using provider state set up URL http://localhost:42437/_pactSetup
15:47:03   |
15:47:03   | I, [2021-01-19T20:47:02.311870 #41]  INFO -- request: POST http://localhost:42437/_pactSetup
15:47:03   |
15:47:03   | D, [2021-01-19T20:47:02.311977 #41] DEBUG -- request: User-Agent: "Faraday v0.17.3"
15:47:03   | Content-Type: "application/json"
15:47:03   |
15:47:03   | I, [2021-01-19T20:47:02.655719 #41]  INFO -- response: Status 200
15:47:03   |
15:47:03   | D, [2021-01-19T20:47:02.655825 #41] DEBUG -- response: x-powered-by: "Express"
15:47:03   | content-type: "text/plain; charset=utf-8"
15:47:03   | content-length: "2"
15:47:03   | etag: "W/\"2-nOO9QiTIwXgNtWtBJezz8kv3SLc\""
15:47:03   | date: "Tue, 19 Jan 2021 20:47:02 GMT"
15:47:03   | connection: "close"
15:47:03   |
15:47:03   |           has status code 409
15:47:03   |
15:47:03   |           has a matching body
15:47:03   |
15:47:03   |           includes headers
15:47:03   |
15:47:03   |             "Content-Type" which equals "application/json; charset=utf-8"
15:47:03   |
15:47:03   |
15:47:03   | 52 interactions, 0 failures
15:47:03   |
15:47:03   | /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-1.51.1/lib/pact/provider/verification_results/publish.rb:103:in `publish_verification_results': Error returned from verification results publication 500  (Pact::Provider::VerificationResults::PublicationError)
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-1.51.1/lib/pact/provider/verification_results/publish.rb:35:in `call'
15:47:03   |
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-1.51.1/lib/pact/provider/verification_results/publish.rb:21:in `call'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-1.51.1/lib/pact/provider/verification_results/publish_all.rb:22:in `block in call'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-1.51.1/lib/pact/provider/verification_results/publish_all.rb:19:in `collect'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-1.51.1/lib/pact/provider/verification_results/publish_all.rb:19:in `call'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-1.51.1/lib/pact/provider/verification_results/publish_all.rb:10:in `call'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-1.51.1/lib/pact/provider/rspec/pact_broker_formatter.rb:28:in `close'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/rspec-core-3.9.2/lib/rspec/core/reporter.rb:209:in `block in notify'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/rspec-core-3.9.2/lib/rspec/core/reporter.rb:208:in `each'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/rspec-core-3.9.2/lib/rspec/core/reporter.rb:208:in `notify'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/rspec-core-3.9.2/lib/rspec/core/reporter.rb:243:in `close'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/rspec-core-3.9.2/lib/rspec/core/reporter.rb:196:in `close_after'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/rspec-core-3.9.2/lib/rspec/core/reporter.rb:174:in `finish'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/rspec-core-3.9.2/lib/rspec/core/reporter.rb:76:in `report'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/rspec-core-3.9.2/lib/rspec/core/runner.rb:115:in `run_specs'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/rspec-core-3.9.2/lib/rspec/core/runner.rb:89:in `run'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/rspec-core-3.9.2/lib/rspec/core/runner.rb:71:in `run'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-1.51.1/lib/pact/provider/pact_spec_runner.rb:88:in `run_specs'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-1.51.1/lib/pact/provider/pact_spec_runner.rb:34:in `run'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-1.51.1/lib/pact/cli/run_pact_verification.rb:69:in `run_with_pact_uri_object'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-1.51.1/lib/pact/cli/run_pact_verification.rb:50:in `run_specs'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-1.51.1/lib/pact/cli/run_pact_verification.rb:21:in `call'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-1.51.1/lib/pact/cli/run_pact_verification.rb:13:in `call'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-provider-verifier-1.32.1/lib/pact/provider_verifier/app.rb:171:in `verify_pact'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-provider-verifier-1.32.1/lib/pact/provider_verifier/app.rb:43:in `block in call'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-provider-verifier-1.32.1/lib/pact/provider_verifier/app.rb:42:in `collect'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-provider-verifier-1.32.1/lib/pact/provider_verifier/app.rb:42:in `call'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-provider-verifier-1.32.1/lib/pact/provider_verifier/app.rb:34:in `call'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-provider-verifier-1.32.1/lib/pact/provider_verifier/cli/verify.rb:47:in `verify'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/thor-0.20.3/lib/thor/command.rb:27:in `run'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/thor-0.20.3/lib/thor/invocation.rb:126:in `invoke_command'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/thor-0.20.3/lib/thor.rb:387:in `dispatch'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/thor-0.20.3/lib/thor/base.rb:466:in `start'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/vendor/ruby/2.2.0/gems/pact-provider-verifier-1.32.1/lib/pact/provider_verifier/cli/custom_thor.rb:17:in `start'
15:47:03   | 	from /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.88.3/pact/lib/app/pact-provider-verifier.rb:33:in `<main>'
15:47:03   |
15:47:03   | INFO: Tagging version 1.1.0-lc3-6118-investigate-pact-broker-errors.116+8b3ece4 of client-compatibility as "lc3-6118-investigate-pact-broker-errors"
15:47:03   | ]

Earlier, using @pact-foundation/pact 9.11.0, I got a little better output with 'trace' logging:

52 interactions, 0 failures

Error making request - Net::ReadTimeout Net::ReadTimeout , attempt 1 of 3

Error making request - Net::ReadTimeout Net::ReadTimeout , attempt 2 of 3

Error making request - EOFError end of file reached , attempt 3 of 3

/usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.85.0/pact/lib/vendor/ruby/2.2.0/gems/pact-1.49.3/lib/pact/provider/verification_results/publish.rb:96:in `rescue in publish_verification_results': Failed to publish verification results due to: EOFError end of file reached /usr/src/app/node_modules/@pact-foundation/pact-node/standalone/linux-x64-1.85.0/pact/lib/ruby/lib/ruby/2.2.0/openssl/buffering.rb:182:in `sysread_nonblock' (Pact::Provider::VerificationResults::PublicationError)

[mefellows]

Thanks. Do you happen to have the logs for your pact broker? The issue seems remote to Pact itself. It could be a payload size issue or timeout

[pfesenmeier]

We do. We haven't seen any errors in the pact broker logs.
We will take a second look at the Pact logs with 'debug' turned on

[pfesenmeier]

In our Broker logs, we are seeing no errors.
In the Broker's load balancer logs, we are seeing a 500 being returned in the error cases:

https 2021-01-20T16:54:40.419921Z ...redacted url/addr/port info... 0.001 0.000 500 500 33208 132 "POST https://pact-broker.ourdomain.com:123/pacts/provider/our-provider/consumer/our-consumer/pact-version/e858e41cbf2ecc05f1c98160486911ce543c7665/verification-results HTTP/1.1" "Ruby" ... redacted load balance info... 0 2021-01-20T16:54:40.416000Z "forward" "-" "-" "redacted-address:port" "500" "-" "-"

As for our timeout and request size concerns...

This run sent a 32kB request, had a ~1ms response time from the broker, and a 500 response. This has been the behaviour for all but one time:
Just before that, we unexpectedly had a successful run, that time with 121bK request, 88ms response time, and a 201 response.

[pfesenmeier]

Here is the relevant broker logs:

@timestamp,@message
2021-01-20 15:53:53.254,2021-01-20 15:53:53.253742 D [7:puma 002] pact-broker -- (0.000322s) COMMIT
2021-01-20 15:53:53.253,"2021-01-20 15:53:53.252924 D [7:puma 002] pact-broker -- (0.000500s) SELECT * FROM ""pacticipants"" WHERE ""id"" = 7"
2021-01-20 15:53:53.252,"2021-01-20 15:53:53.252158 D [7:puma 002] pact-broker -- (0.000423s) SELECT * FROM ""versions"" WHERE ""id"" = 1345"
2021-01-20 15:53:53.251,"2021-01-20 15:53:53.251203 D [7:puma 002] pact-broker -- (0.001004s) SELECT ""tags"".* FROM ""tags"" INNER JOIN ""versions"" ON (""versions"".""id"" = ""tags"".""version_id"") INNER JOIN ""pacticipants"" ON (""pacticipants"".""id"" = ""versions"".""pacticipant_id"") WHERE ((""tags"".""name"" = 'develop') AND (""versions"".""number"" = '1.1.0-dev.107+c7182da') AND (""pacticipants"".""name"" = 'our-provider')) LIMIT 1"
2021-01-20 15:53:53.250,2021-01-20 15:53:53.248628 D [7:puma 002] pact-broker -- (0.000345s) BEGIN
2021-01-20 15:53:53.248,2021-01-20 15:53:53.248175 D [7:puma 002] pact-broker -- (0.001455s) SELECT NULL
2021-01-20 15:53:53.224,"2021-01-20 15:53:53.223322 D [6:puma 003] pact-broker -- (0.000657s) SELECT * FROM ""labels"" WHERE (""labels"".""pacticipant_id"" = 7) ORDER BY ""name"""
2021-01-20 15:53:53.222,"2021-01-20 15:53:53.182972 D [6:puma 003] pact-broker -- (0.001268s) SELECT * FROM ""versions"" WHERE (""versions"".""pacticipant_id"" = 7) ORDER BY ""order"""
2021-01-20 15:53:53.222,2021-01-20 15:53:53.222612 D [6:puma 003] pact-broker -- (0.000691s) SELECT NULL
2021-01-20 15:53:53.181,"2021-01-20 15:53:53.180801 D [6:puma 003] pact-broker -- (0.000667s) SELECT * FROM ""pacticipants"" WHERE (""name"" = 'our-provider')"
2021-01-20 15:53:53.181,2021-01-20 15:53:53.181656 D [6:puma 003] pact-broker -- (0.000474s) SELECT NULL
2021-01-20 15:53:53.180,2021-01-20 15:53:53.180086 D [6:puma 003] pact-broker -- (0.000516s) SELECT NULL
2021-01-20 15:53:53.179,2021-01-20 15:53:53.178443 D [6:puma 003] pact-broker -- (0.000759s) SELECT NULL
2021-01-20 15:53:41.721,"2021-01-20 15:53:41.714301 D [6:puma 003] pact-broker -- (0.000523s) SELECT * FROM ""tags"" WHERE (""tags"".""version_id"" = 1363)"
2021-01-20 15:53:41.713,"2021-01-20 15:53:41.713511 D [6:puma 003] pact-broker -- (0.001089s) SELECT * FROM ""latest_verifications_for_pact_versions"" WHERE (""latest_verifications_for_pact_versions"".""pact_version_id"" = 119) LIMIT 1"
2021-01-20 15:53:41.712,"2021-01-20 15:53:41.711963 D [6:puma 003] pact-broker -- (0.000818s) SELECT * FROM ""pact_versions"" WHERE ""id"" = 119"
2021-01-20 15:53:41.711,"2021-01-20 15:53:41.711004 D [6:puma 003] pact-broker -- (0.005599s) SELECT ""tag_name"" FROM ""latest_tagged_pact_publications"" WHERE (""id"" = 510)"
// begin info for large contract
2021-01-20 15:53:41.705,"2021-01-20 15:53:41.704908 D [6:puma 003] pact-broker -- (0.002734s) SELECT * FROM ""all_pact_publications"" WHERE ((""pact_version_sha"" = 'e858e41cbf2ecc05f1c98160486911ce543c7665') AND (""consumer_name"" = 'our-consumer-with-large-contract') AND (""provider_name"" = 'our-provider')) ORDER BY ""consumer_version_order"" DESC LIMIT 1"
2021-01-20 15:53:41.702,2021-01-20 15:53:41.702125 D [6:puma 003] pact-broker -- (0.000468s) SELECT NULL
2021-01-20 15:53:41.701,2021-01-20 15:53:41.700979 D [6:puma 003] pact-broker -- (0.000503s) SELECT NULL
2021-01-20 15:53:41.701,2021-01-20 15:53:41.701547 D [6:puma 003] pact-broker -- (0.000479s) SELECT NULL
2021-01-20 15:53:41.700,2021-01-20 15:53:41.700370 D [6:puma 003] pact-broker -- (0.000637s) SELECT NULL
2021-01-20 15:53:41.647,2021-01-20 15:53:41.646927 D [7:puma 002] pact-broker -- (0.003541s) COMMIT
2021-01-20 15:53:41.643,"2021-01-20 15:53:41.642776 D [7:puma 002] pact-broker -- (0.002267s) SELECT * FROM ""latest_pact_publications_by_consumer_versions"" WHERE (""pact_version_id"" = 28) ORDER BY ""consumer_version_order"" DESC LIMIT 1"
2021-01-20 15:53:41.640,"2021-01-20 15:53:41.640134 D [7:puma 002] pact-broker -- (0.000412s) SELECT * FROM ""tags"" WHERE (""tags"".""version_id"" = 1450)"
2021-01-20 15:53:41.639,"2021-01-20 15:53:41.639483 D [7:puma 002] pact-broker -- (0.000945s) SELECT * FROM ""latest_verifications_for_pact_versions"" WHERE (""latest_verifications_for_pact_versions"".""pact_version_id"" = 28) LIMIT 1"
2021-01-20 15:53:41.638,"2021-01-20 15:53:41.638356 D [7:puma 002] pact-broker -- (0.000560s) SELECT * FROM ""pact_versions"" WHERE ""id"" = 28"
2021-01-20 15:53:41.637,"2021-01-20 15:53:41.637693 D [7:puma 002] pact-broker -- (0.004939s) SELECT ""tag_name"" FROM ""latest_tagged_pact_publications"" WHERE (""id"" = 569)"
2021-01-20 15:53:41.632,"2021-01-20 15:53:41.632477 D [7:puma 002] pact-broker -- (0.002079s) SELECT * FROM ""latest_pact_publications_by_consumer_versions"" WHERE (""pact_version_id"" = 28) ORDER BY ""consumer_version_order"" DESC LIMIT 1"
2021-01-20 15:53:41.630,"2021-01-20 15:53:41.630020 D [7:puma 002] pact-broker -- (0.000383s) SELECT * FROM ""pacticipants"" WHERE ""id"" = 6"
2021-01-20 15:53:41.629,"2021-01-20 15:53:41.628722 D [7:puma 002] pact-broker -- (0.000948s) SELECT * FROM ""latest_verifications_for_pact_versions"" WHERE (""latest_verifications_for_pact_versions"".""pact_version_id"" = 28) LIMIT 1"
2021-01-20 15:53:41.629,"2021-01-20 15:53:41.629375 D [7:puma 002] pact-broker -- (0.000398s) SELECT * FROM ""tags"" WHERE (""tags"".""version_id"" = 1450)"
2021-01-20 15:53:41.627,"2021-01-20 15:53:41.626976 D [7:puma 002] pact-broker -- (0.005025s) SELECT ""tag_name"" FROM ""latest_tagged_pact_publications"" WHERE (""id"" = 569)"
2021-01-20 15:53:41.627,"2021-01-20 15:53:41.627552 D [7:puma 002] pact-broker -- (0.000466s) SELECT * FROM ""pact_versions"" WHERE ""id"" = 28"
2021-01-20 15:53:41.622,"2021-01-20 15:53:41.621650 D [7:puma 002] pact-broker -- (0.002211s) SELECT * FROM ""latest_pact_publications_by_consumer_versions"" WHERE (""pact_version_id"" = 28) ORDER BY ""consumer_version_order"" DESC LIMIT 1"
2021-01-20 15:53:41.619,"2021-01-20 15:53:41.619151 D [7:puma 002] pact-broker -- (0.000454s) SELECT * FROM ""pact_versions"" WHERE ""id"" = 28"
2021-01-20 15:53:41.618,"2021-01-20 15:53:41.617686 D [7:puma 002] pact-broker -- (0.000480s) SELECT ""webhooks"".* FROM ""webhooks"" INNER JOIN ""webhook_events"" ON (""webhook_events"".""webhook_id"" = ""webhooks"".""id"") WHERE ((""enabled"" IS TRUE) AND (""consumer_id"" IS NULL) AND (""provider_id"" IS NULL) AND (""webhook_events"".""name"" = 'provider_verification_published'))"
// begin info for small contract
2021-01-20 15:53:41.618,"2021-01-20 15:53:41.617749 I [7:puma 002] pact-broker -- No enabled webhooks found for consumer ""our-consumer-with-small-contract"" and provider ""our-provider"" and event provider_verification_published"
2021-01-20 15:53:41.618,"2021-01-20 15:53:41.618330 D [7:puma 002] pact-broker -- (0.000419s) SELECT * FROM ""pacticipants"" WHERE ""id"" = 7"
2021-01-20 15:53:41.617,"2021-01-20 15:53:41.616948 D [7:puma 002] pact-broker -- (0.000471s) SELECT ""webhooks"".* FROM ""webhooks"" INNER JOIN ""webhook_events"" ON (""webhook_events"".""webhook_id"" = ""webhooks"".""id"") WHERE ((""enabled"" IS TRUE) AND (""consumer_id"" = 6) AND (""provider_id"" IS NULL) AND (""webhook_events"".""name"" = 'provider_verification_published'))"
2021-01-20 15:53:41.616,"2021-01-20 15:53:41.616215 D [7:puma 002] pact-broker -- (0.000490s) SELECT ""webhooks"".* FROM ""webhooks"" INNER JOIN ""webhook_events"" ON (""webhook_events"".""webhook_id"" = ""webhooks"".""id"") WHERE ((""enabled"" IS TRUE) AND (""consumer_id"" IS NULL) AND (""provider_id"" = 7) AND (""webhook_events"".""name"" = 'provider_verification_published'))"
2021-01-20 15:53:41.615,"2021-01-20 15:53:41.614690 D [7:puma 002] pact-broker -- (0.000480s) SELECT ""webhooks"".* FROM ""webhooks"" INNER JOIN ""webhook_events"" ON (""webhook_events"".""webhook_id"" = ""webhooks"".""id"") WHERE ((""enabled"" IS TRUE) AND (""consumer_id"" IS NULL) AND (""provider_id"" IS NULL) AND (""webhook_events"".""name"" = 'provider_verification_succeeded'))"
2021-01-20 15:53:41.615,"2021-01-20 15:53:41.614763 I [7:puma 002] pact-broker -- No enabled webhooks found for consumer ""our-consumer-with-small-contract"" and provider ""our-provider"" and event provider_verification_succeeded"
2021-01-20 15:53:41.615,"2021-01-20 15:53:41.615464 D [7:puma 002] pact-broker -- (0.000476s) SELECT ""webhooks"".* FROM ""webhooks"" INNER JOIN ""webhook_events"" ON (""webhook_events"".""webhook_id"" = ""webhooks"".""id"") WHERE ((""enabled"" IS TRUE) AND (""consumer_id"" = 6) AND (""provider_id"" = 7) AND (""webhook_events"".""name"" = 'provider_verification_published'))"
2021-01-20 15:53:41.614,"2021-01-20 15:53:41.613949 D [7:puma 002] pact-broker -- (0.000509s) SELECT ""webhooks"".* FROM ""webhooks"" INNER JOIN ""webhook_events"" ON (""webhook_events"".""webhook_id"" = ""webhooks"".""id"") WHERE ((""enabled"" IS TRUE) AND (""consumer_id"" = 6) AND (""provider_id"" IS NULL) AND (""webhook_events"".""name"" = 'provider_verification_succeeded'))"
2021-01-20 15:53:41.613,"2021-01-20 15:53:41.613140 D [7:puma 002] pact-broker -- (0.000600s) SELECT ""webhooks"".* FROM ""webhooks"" INNER JOIN ""webhook_events"" ON (""webhook_events"".""webhook_id"" = ""webhooks"".""id"") WHERE ((""enabled"" IS TRUE) AND (""consumer_id"" IS NULL) AND (""provider_id"" = 7) AND (""webhook_events"".""name"" = 'provider_verification_succeeded'))"
2021-01-20 15:53:41.612,"2021-01-20 15:53:41.612143 D [7:puma 002] pact-broker -- (0.000690s) SELECT ""webhooks"".* FROM ""webhooks"" INNER JOIN ""webhook_events"" ON (""webhook_events"".""webhook_id"" = ""webhooks"".""id"") WHERE ((""enabled"" IS TRUE) AND (""consumer_id"" = 6) AND (""provider_id"" = 7) AND (""webhook_events"".""name"" = 'provider_verification_succeeded'))"
2021-01-20 15:53:41.611,"2021-01-20 15:53:41.607921 D [7:puma 002] pact-broker -- (0.007098s) INSERT INTO ""latest_verification_id_for_pact_version_and_provider_version"" (""pact_version_id"", ""provider_version_id"", ""provider_id"", ""verification_id"", ""consumer_id"", ""created_at"") VALUES (28, 1345, 7, 2408, 6, '2021-01-20 15:53:41.597535+0000') ON CONFLICT (""pact_version_id"", ""provider_version_id"") DO UPDATE SET ""pact_version_id"" = 28, ""provider_version_id"" = 1345, ""provider_id"" = 7, ""verification_id"" = 2408, ""consumer_id"" = 6, ""created_at"" = '2021-01-20 15:53:41.597535+0000' RETURNING *"
2021-01-20 15:53:41.611,"2021-01-20 15:53:41.608942 D [7:puma 002] pact-broker -- (0.000564s) SELECT * FROM ""latest_verification_id_for_pact_version_and_provider_version"" WHERE ((""pact_version_id"" = 28) AND (""provider_version_id"" = 1345)) LIMIT 1"
2021-01-20 15:53:41.611,"2021-01-20 15:53:41.609633 D [7:puma 002] pact-broker -- (0.000399s) SELECT * FROM ""tags"" WHERE (""tags"".""version_id"" = 1345) ORDER BY ""created_at"""
2021-01-20 15:53:41.601,"2021-01-20 15:53:41.600212 D [7:puma 002] pact-broker -- (0.002204s) INSERT INTO ""verifications"" (""success"", ""number"", ""pact_version_id"", ""provider_version_id"", ""provider_id"", ""consumer_id"", ""created_at"", ""test_results"", ""execution_date"") VALUES (true, 2492, (SELECT ""pact_version_id"" FROM ""pact_publications"" WHERE (""id"" = 569)), 1345, 7, 6, '2021-01-20 15:53:41.597535+0000', '{""tests"":[{""testDescription"":""has status code 200"",""testFullDescription"":""Verifying a pact between our-consumer-with-small-contract and our-provider Given there exists a client application configuration where applicationName = testAppName, applicationVersionName = testAppVersion, deviceModelName = testAppDevice, operatingSystemName = testAppDeviceOS, operatingSystemVersionName = testAppDeviceOSVersion a request to get if a client application configuration is compatible with GET /client-compatibilities/is-compatible?applicationName=testAppName&applicationVersionName=testAppVersion&deviceModelName=testAppDevice&operatingSystemName=testAppDeviceOS&operatingSystemVersionName=testAppDeviceOSVersion returns a response which has status code 200"",""status"":""passed"",""interactionProviderState"":""there exists a client application configuration where applicationName = testAppName, applicationVersionName = testAppVersion, deviceModelName = testAppDevice, operatingSystemName = testAppDeviceOS, operatingSystemVersionName = testAppDeviceOSVersion"",""interactionDescription"":""a request to get if a client application configuration is compatible"",""actualStatus"":200},{""testDescription"":""has a matching body"",""testFullDescription"":""Verifying a pact between our-consumer-with-small-contract and our-provider Given there exists a client application configuration where applicationName = testAppName, applicationVersionName = testAppVersion, deviceModelName = testAppDevice, operatingSystemName = testAppDeviceOS, operatingSystemVersionName = testAppDeviceOSVersion a request to get if a client application configuration is compatible with GET /client-compatibilities/is-compatible?applicationName=testAppName&applicationVersionName=testAppVersion&deviceModelName=testAppDevice&operatingSystemName=testAppDeviceOS&operatingSystemVersionName=testAppDeviceOSVersion returns a response which has a matching body"",""status"":""passed"",""interactionProviderState"":""there exists a client application configuration where applicationName = testAppName, applicationVersionName = testAppVersion, deviceModelName = testAppDevice, operatingSystemName = testAppDeviceOS, operatingSystemVersionName = testAppDeviceOSVersion"",""interactionDescription"":""a request to get if a client application configuration is compatible"",""actualBody"":{""isCompatible"":true}},{""testDescription"":""\""Content-Type\"" which equals \""application/json; charset=utf-8\"""",""testFullDescription"":""Verifying a pact between our-consumer-with-small-contract and our-provider Given there exists a client application configuration where applicationName = testAppName, applicationVersionName = testAppVersion, deviceModelName = testAppDevice, operatingSystemName = testAppDeviceOS, operatingSystemVersionName = testAppDeviceOSVersion a request to get if a client application configuration is compatible with GET /client-compatibilities/is-compatible?applicationName=testAppName&applicationVersionName=testAppVersion&deviceModelName=testAppDevice&operatingSystemName=testAppDeviceOS&operatingSystemVersionName=testAppDeviceOSVersion returns a response which includes headers \""Content-Type\"" which equals \""application/json; charset=utf-8\"""",""status"":""passed"",""interactionProviderState"":""there exists a client application configuration where applicationName = testAppName, applicationVersionName = testAppVersion, deviceModelName = testAppDevice, operatingSystemName = testAppDeviceOS, operatingSystemVersionName = testAppDeviceOSVersion"",""interactionDescription"":""a request to get if a client application configuration is compatible"",""actualHeaders"":{""X-Powered-By"":""Express"",""Content-Type"":""application/json; charset=utf-8"",""Strict-Transport-Security"":""max-age=15768000"",""X-Frame-Options"":""DENY"",""X-Xss-Protection"":""1; mode=block"",""X-Download-Options"":""noopen"",""X-Content-Type-Options"":""nosniff"",""Cache-Control"":""no-cache"",""Content-Length"":""21"",""Accept-Ranges"":""bytes"",""Date"":""Wed, 20 Jan 2021 15:53:39 GMT"",""Connection"":""close""}},{""testDescription"":""has status code 200"",""testFullDescription"":""Verifying a pact between our-consumer-with-small-contract and our-provider Given there is no client application configuration where applicationName = testAppName, applicationVersionName = testAppVersion, deviceModelName = testAppDevice, operatingSystemName = testAppDeviceOS, operatingSystemVersionName = testAppDeviceOSVersion a request to get if a client application configuration is compatible with GET /client-compatibilities/is-compatible?applicationName=testAppName&applicationVersionName=testAppVersion&deviceModelName=testAppDevice&operatingSystemName=testAppDeviceOS&operatingSystemVersionName=testAppDeviceOSVersion returns a response which has status code 200"",""status"":""passed"",""interactionProviderState"":""there is no client application configuration where applicationName = testAppName, applicationVersionName = testAppVersion, deviceModelName = testAppDevice, operatingSystemName = testAppDeviceOS, operatingSystemVersionName = testAppDeviceOSVersion"",""interactionDescription"":""a request to get if a client application configuration is compatible"",""actualStatus"":200},{""testDescription"":""has a matching body"",""testFullDescription"":""Verifying a pact between our-consumer-with-small-contract and our-provider Given there is no client application configuration where applicationName = testAppName, applicationVersionName = testAppVersion, deviceModelName = testAppDevice, operatingSystemName = testAppDeviceOS, operatingSystemVersionName = testAppDeviceOSVersion a request to get if a client application configuration is compatible with GET /client-compatibilities/is-compatible?applicationName=testAppName&applicationVersionName=testAppVersion&deviceModelName=testAppDevice&operatingSystemName=testAppDeviceOS&operatingSystemVersionName=testAppDeviceOSVersion returns a response which has a matching body"",""status"":""passed"",""interactionProviderState"":""there is no client application configuration where applicationName = testAppName, applicationVersionName = testAppVersion, deviceModelName = testAppDevice, operatingSystemName = testAppDeviceOS, operatingSystemVersionName = testAppDeviceOSVersion"",""interactionDescription"":""a request to get if a client application configuration is compatible"",""actualBody"":{""isCompatible"":false}},{""testDescription"":""\""Content-Type\"" which equals \""application/json; charset=utf-8\"""",""testFullDescription"":""Verifying a pact between our-consumer-with-small-contract and our-provider Given there is no client application configuration where applicationName = testAppName, applicationVersionName = testAppVersion, deviceModelName = testAppDevice, operatingSystemName = testAppDeviceOS, operatingSystemVersionName = testAppDeviceOSVersion a request to get if a client application configuration is compatible with GET /client-compatibilities/is-compatible?applicationName=testAppName&applicationVersionName=testAppVersion&deviceModelName=testAppDevice&operatingSystemName=testAppDeviceOS&operatingSystemVersionName=testAppDeviceOSVersion returns a response which includes headers \""Content-Type\"" which equals \""application/json; charset=utf-8\"""",""status"":""passed"",""interactionProviderState"":""there is no client application configuration where applicationName = testAppName, applicationVersionName = testAppVersion, deviceModelName = testAppDevice, operatingSystemName = testAppDeviceOS, operatingSystemVersionName = testAppDeviceOSVersion"",""interactionDescription"":""a request to get if a client application configuration is compatible"",""actualHeaders"":{""X-Powered-By"":""Express"",""Content-Type"":""application/json; charset=utf-8"",""Strict-Transport-Security"":""max-age=15768000"",""X-Frame-Options"":""DENY"",""X-Xss-Protection"":""1; mode=block"",""X-Download-Options"":""noopen"",""X-Content-Type-Options"":""nosniff"",""Cache-Control"":""no-cache"",""Content-Length"":""22"",""Accept-Ranges"":""bytes"",""Date"":""Wed, 20 Jan 2021 15:53:40 GMT"",""Connection"":""close""}},{""testDescription"":""has status code 200"",""testFullDescription"":""Verifying a pact between our-consumer-with-small-contract and our-provider Given there exists a blacklisted client application configuration where applicationName = testAppName, applicationVersionName = testAppVersion, deviceModelName = testAppDevice, operatingSystemName = testAppDeviceOS, operatingSystemVersionName = testAppDeviceOSVersion a request to get if a client application configuration is compatible with GET /client-compatibilities/is-compatible?applicationName=testAppName&applicationVersionName=testAppVersion&deviceModelName=testAppDevice&operatingSystemName=testAppDeviceOS&operatingSystemVersionName=testAppDeviceOSVersion returns a response which has status code 200"",""status"":""passed"",""interactionProviderState"":""there exists a blacklisted client application configuration where applicationName = testAppName, applicationVersionName = testAppVersion, deviceModelName = testAppDevice, operatingSystemName = testAppDeviceOS, operatingSystemVersionName = testAppDeviceOSVersion"",""interactionDescription"":""a request to get if a client application configuration is compatible"",""actualStatus"":200},{""testDescription"":""has a matching body"",""testFullDescription"":""Verifying a pact between our-consumer-with-small-contract and our-provider Given there exists a blacklisted client application configuration where applicationName = testAppName, applicationVersionName = testAppVersion, deviceModelName = testAppDevice, operatingSystemName = testAppDeviceOS, operatingSystemVersionName = testAppDeviceOSVersion a request to get if a client application configuration is compatible with GET /client-compatibilities/is-compatible?applicationName=testAppName&applicationVersionName=testAppVersion&deviceModelName=testAppDevice&operatingSystemName=testAppDeviceOS&operatingSystemVersionName=testAppDeviceOSVersion returns a response which has a matching body"",""status"":""passed"",""interactionProviderState"":""there exists a blacklisted client application configuration where applicationName = testAppName, applicationVersionName = testAppVersion, deviceModelName = testAppDevice, operatingSystemName = testAppDeviceOS, operatingSystemVersionName = testAppDeviceOSVersion"",""interactionDescription"":""a request to get if a client application configuration is compatible"",""actualBody"":{""isCompatible"":false,""reasonCode"":""testReasonCode""}},{""testDescription"":""\""Content-Type\"" which equals \""application/json; charset=utf-8\"""",""testFullDescription"":""Verifying a pact between our-consumer-with-small-contract and our-provider Given there exists a blacklisted client application configuration where applicationName = testAppName, applicationVersionName = testAppVersion, deviceModelName = testAppDevice, operatingSystemName = testAppDeviceOS, operatingSystemVersionName = testAppDeviceOSVersion a request to get if a client application configuration is compatible with GET /client-compatibilities/is-compatible?applicationName=testAppName&applicationVersionName=testAppVersion&deviceModelName=testAppDevice&operatingSystemName=testAppDeviceOS&operatingSystemVersionName=testAppDeviceOSVersion returns a response which includes headers \""Content-Type\"" which equals \""application/json; charset=utf-8\"""",""status"":""passed"",""interactionProviderState"":""there exists a blacklisted client application configuration where applicationName = testAppName, applicationVersionName = testAppVersion, deviceModelName = testAppDevice, operatingSystemName = testAppDeviceOS, operatingSystemVersionName = testAppDeviceOSVersion"",""interactionDescription"":""a request to get if a client application configuration is compatible"",""actualHeaders"":{""X-Powered-By"":""Express"",""Content-Type"":""application/json; charset=utf-8"",""Strict-Transport-Security"":""max-age=15768000"",""X-Frame-Options"":""DENY"",""X-Xss-Protection"":""1; mode=block"",""X-Download-Options"":""noopen"",""X-Content-Type-Options"":""nosniff"",""Cache-Control"":""no-cache"",""Content-Length"":""52"",""Accept-Ranges"":""bytes"",""Date"":""Wed, 20 Jan 2021 15:53:41 GMT"",""Connection"":""close""}},{""testDescription"":""has status code 401"",""testFullDescription"":""Verifying a pact between our-consumer-with-small-contract and our-provider A request to get if a client application configuration is compatible with bad authentication with GET /client-compatibilities/is-compatible returns a response which has status code 401"",""status"":""passed"",""interactionProviderState"":null,""interactionDescription"":""a request to get if a client application configuration is compatible with bad authentication"",""actualStatus"":401},{""testDescription"":""has a matching body"",""testFullDescription"":""Verifying a pact between our-consumer-with-small-contract and our-provider A request to get if a client application configuration is compatible with bad authentication with GET /client-compatibilities/is-compatible returns a response which has a matching body"",""status"":""passed"",""interactionProviderState"":null,""interactionDescription"":""a request to get if a client application configuration is compatible with bad authentication"",""actualBody"":{""statusCode"":401,""error"":""Unauthorized"",""message"":""Missing authentication""}},{""testDescription"":""\""Content-Type\"" which equals \""application/json; charset=utf-8\"""",""testFullDescription"":""Verifying a pact between our-consumer-with-small-contract and our-provider A request to get if a client application configuration is compatible with bad authentication with GET /client-compatibilities/is-compatible returns a response which includes headers \""Content-Type\"" which equals \""application/json; charset=utf-8\"""",""status"":""passed"",""interactionProviderState"":null,""interactionDescription"":""a request to get if a client application configuration is compatible with bad authentication"",""actualHeaders"":{""X-Powered-By"":""Express"",""Www-Authenticate"":""Token error=\""Invalid token format\"""",""Content-Type"":""application/json; charset=utf-8"",""Strict-Transport-Security"":""max-age=15768000"",""X-Frame-Options"":""DENY"",""X-Xss-Protection"":""1; mode=block"",""X-Download-Options"":""noopen"",""X-Content-Type-Options"":""nosniff"",""Cache-Control"":""no-cache"",""Content-Length"":""76"",""Date"":""Wed, 20 Jan 2021 15:53:41 GMT"",""Connection"":""close""}},{""testDescription"":""has status code 400"",""testFullDescription"":""Verifying a pact between our-consumer-with-small-contract and our-provider A request to get if a client application configuration is compatible with invalid request with GET /client-compatibilities/is-compatible?invalidKey=valueOfInvalidKey returns a response which has status code 400"",""status"":""passed"",""interactionProviderState"":null,""interactionDescription"":""a request to get if a client application configuration is compatible with invalid request"",""actualStatus"":400},{""testDescription"":""has a matching body"",""testFullDescription"":""Verifying a pact between our-consumer-with-small-contract and our-provider A request to get if a client application configuration is compatible with invalid request with GET /client-compatibilities/is-compatible?invalidKey=valueOfInvalidKey returns a response which has a matching body"",""status"":""passed"",""interactionProviderState"":null,""interactionDescription"":""a request to get if a client application configuration is compatible with invalid request"",""actualBody"":{""statusCode"":400,""error"":""Bad Request"",""message"":""child \""applicationName\"" fails because [\""applicationName\"" is required]. child \""applicationVersionName\"" fails because [\""applicationVersionName\"" is required]. child \""deviceModelName\"" fails because [\""deviceModelName\"" is required]. child \""operatingSystemVersionName\"" fails because [\""operatingSystemVersionName\"" is required]. child \""operatingSystemName\"" fails because [\""operatingSystemName\"" is required]. \""invalidKey\"" is not allowed"",""validation"":{""source"":""query"",""keys"":[""applicationName"",""applicationVersionName"",""deviceModelName"",""operatingSystemVersionName"",""operatingSystemName"",""invalidKey""]}}},{""testDescription"":""\""Content-Type\"" which equals \""application/json; charset=utf-8\"""",""testFullDescription"":""Verifying a pact between our-consumer-with-small-contract and our-provider A request to get if a client application configuration is compatible with invalid request with GET /client-compatibilities/is-compatible?invalidKey=valueOfInvalidKey returns a response which includes headers \""Content-Type\"" which equals \""application/json; charset=utf-8\"""",""status"":""passed"",""interactionProviderState"":null,""interactionDescription"":""a request to get if a client application configuration is compatible with invalid request"",""actualHeaders"":{""X-Powered-By"":""Express"",""Content-Type"":""application/json; charset=utf-8"",""Strict-Transport-Security"":""max-age=15768000"",""X-Frame-Options"":""DENY"",""X-Xss-Protection"":""1; mode=block"",""X-Download-Options"":""noopen"",""X-Content-Type-Options"":""nosniff"",""Cache-Control"":""no-cache"",""Content-Length"":""667"",""Date"":""Wed, 20 Jan 2021 15:53:41 GMT"",""Connection"":""close""}}],""summary"":{""testCount"":15,""failureCount"":0},""metadata"":{""warning"":""These test results use a beta format. Do not rely on it, as it will definitely change."",""pactVerificationResultsSpecification"":{""version"":""1.0.0-beta.1""}}}', '2021-01-20 15:53:41.597694+0000') RETURNING *"
2021-01-20 15:53:41.598,"2021-01-20 15:53:41.596009 D [7:puma 002] pact-broker -- (0.000472s) SELECT * FROM ""versions"" WHERE ((""number"" = '1.1.0-dev.107+c7182da') AND (""pacticipant_id"" = 7)) LIMIT 1"
2021-01-20 15:53:41.594,"2021-01-20 15:53:41.594066 D [7:puma 002] pact-broker -- (0.000403s) SELECT * FROM ""pacticipants"" WHERE (""name"" = 'our-consumer-with-small-contract')"
2021-01-20 15:53:41.593,"2021-01-20 15:53:41.592228 D [7:puma 002] pact-broker -- (0.000431s) SELECT * FROM ""verification_sequence_number"" LIMIT 1"
2021-01-20 15:53:41.593,"2021-01-20 15:53:41.592673 I [7:puma 002] pact-broker -- Creating verification 2492 for pact_id=569 from params {""success""=>true, ""providerApplicationVersion""=>""1.1.0-dev.107+c7182da""}"
2021-01-20 15:53:41.593,"2021-01-20 15:53:41.593401 D [7:puma 002] pact-broker -- (0.000430s) SELECT * FROM ""pacticipants"" WHERE (""name"" = 'our-provider')"
2021-01-20 15:53:41.591,"2021-01-20 15:53:41.591053 D [7:puma 002] pact-broker -- (0.000491s) SELECT * FROM ""verification_sequence_number"" LIMIT 1 FOR UPDATE"
2021-01-20 15:53:41.591,"2021-01-20 15:53:41.591692 D [7:puma 002] pact-broker -- (0.000474s) UPDATE ""verification_sequence_number"" SET ""value"" = (""value"" + 1)"
2021-01-20 15:53:41.590,2021-01-20 15:53:41.589643 D [7:puma 002] pact-broker -- (0.000345s) RELEASE SAVEPOINT autopoint_1
2021-01-20 15:53:41.589,"2021-01-20 15:53:41.589142 D [7:puma 002] pact-broker -- (0.001436s) SELECT ""pg_attribute"".""attname"" AS ""name"", CAST(""pg_attribute"".""atttypid"" AS integer) AS ""oid"", CAST(""basetype"".""oid"" AS integer) AS ""base_oid"", format_type(""basetype"".""oid"", ""pg_type"".""typtypmod"") AS ""db_base_type"", format_type(""pg_type"".""oid"", ""pg_attribute"".""atttypmod"") AS ""db_type"", pg_get_expr(""pg_attrdef"".""adbin"", ""pg_class"".""oid"") AS ""default"", NOT ""pg_attribute"".""attnotnull"" AS ""allow_null"", COALESCE((""pg_attribute"".""attnum"" = ANY(""pg_index"".""indkey"")), false) AS ""primary_key"", ""pg_attribute"".""attidentity"" FROM ""pg_class"" INNER JOIN ""pg_attribute"" ON (""pg_attribute"".""attrelid"" = ""pg_class"".""oid"") INNER JOIN ""pg_type"" ON (""pg_type"".""oid"" = ""pg_attribute"".""atttypid"") LEFT OUTER JOIN ""pg_type"" AS ""basetype"" ON (""basetype"".""oid"" = ""pg_type"".""typbasetype"") LEFT OUTER JOIN ""pg_attrdef"" ON ((""pg_attrdef"".""adrelid"" = ""pg_class"".""oid"") AND (""pg_attrdef"".""adnum"" = ""pg_attribute"".""attnum"")) LEFT OUTER JOIN ""pg_index"" ON ((""pg_index"".""indrelid"" = ""pg_class"".""oid"") AND (""pg_index"".""indisprimary"" IS TRUE)) WHERE ((""pg_attribute"".""attisdropped"" IS FALSE) AND (""pg_attribute"".""attnum"" > 0) AND (""pg_class"".""oid"" = CAST(CAST('""latest_verification_id_for_pact_version_and_provider_version""' AS regclass) AS oid))) ORDER BY ""pg_attribute"".""attnum"""
2021-01-20 15:53:41.587,2021-01-20 15:53:41.587117 D [7:puma 002] pact-broker -- (0.000360s) SAVEPOINT autopoint_1
2021-01-20 15:53:41.585,2021-01-20 15:53:41.584670 D [7:puma 002] pact-broker -- (0.000353s) RELEASE SAVEPOINT autopoint_1
2021-01-20 15:53:41.584,"2021-01-20 15:53:41.584182 D [7:puma 002] pact-broker -- (0.001313s) SELECT ""pg_attribute"".""attname"" AS ""name"", CAST(""pg_attribute"".""atttypid"" AS integer) AS ""oid"", CAST(""basetype"".""oid"" AS integer) AS ""base_oid"", format_type(""basetype"".""oid"", ""pg_type"".""typtypmod"") AS ""db_base_type"", format_type(""pg_type"".""oid"", ""pg_attribute"".""atttypmod"") AS ""db_type"", pg_get_expr(""pg_attrdef"".""adbin"", ""pg_class"".""oid"") AS ""default"", NOT ""pg_attribute"".""attnotnull"" AS ""allow_null"", COALESCE((""pg_attribute"".""attnum"" = ANY(""pg_index"".""indkey"")), false) AS ""primary_key"", ""pg_attribute"".""attidentity"" FROM ""pg_class"" INNER JOIN ""pg_attribute"" ON (""pg_attribute"".""attrelid"" = ""pg_class"".""oid"") INNER JOIN ""pg_type"" ON (""pg_type"".""oid"" = ""pg_attribute"".""atttypid"") LEFT OUTER JOIN ""pg_type"" AS ""basetype"" ON (""basetype"".""oid"" = ""pg_type"".""typbasetype"") LEFT OUTER JOIN ""pg_attrdef"" ON ((""pg_attrdef"".""adrelid"" = ""pg_class"".""oid"") AND (""pg_attrdef"".""adnum"" = ""pg_attribute"".""attnum"")) LEFT OUTER JOIN ""pg_index"" ON ((""pg_index"".""indrelid"" = ""pg_class"".""oid"") AND (""pg_index"".""indisprimary"" IS TRUE)) WHERE ((""pg_attribute"".""attisdropped"" IS FALSE) AND (""pg_attribute"".""attnum"" > 0) AND (""pg_class"".""oid"" = CAST(CAST('""verification_sequence_number""' AS regclass) AS oid))) ORDER BY ""pg_attribute"".""attnum"""
2021-01-20 15:53:41.583,2021-01-20 15:53:41.582184 D [7:puma 002] pact-broker -- (0.000338s) SAVEPOINT autopoint_1
2021-01-20 15:53:41.579,"2021-01-20 15:53:41.578900 D [7:puma 002] pact-broker -- (0.000391s) SELECT * FROM ""tags"" WHERE (""tags"".""version_id"" = 1450)"
2021-01-20 15:53:41.578,"2021-01-20 15:53:41.578248 D [7:puma 002] pact-broker -- (0.001089s) SELECT * FROM ""latest_verifications_for_pact_versions"" WHERE (""latest_verifications_for_pact_versions"".""pact_version_id"" = 28) LIMIT 1"
2021-01-20 15:53:41.577,"2021-01-20 15:53:41.576932 D [7:puma 002] pact-broker -- (0.000468s) SELECT * FROM ""pact_versions"" WHERE ""id"" = 28"
2021-01-20 15:53:41.576,"2021-01-20 15:53:41.576331 D [7:puma 002] pact-broker -- (0.005227s) SELECT ""tag_name"" FROM ""latest_tagged_pact_publications"" WHERE (""id"" = 569)"
2021-01-20 15:53:41.571,"2021-01-20 15:53:41.570734 D [7:puma 002] pact-broker -- (0.001930s) SELECT * FROM ""all_pact_publications"" WHERE ((""pact_version_sha"" = 'a0750a59c10671430d5b260ac322266b98aa5340') AND (""consumer_name"" = 'our-consumer-with-small-contract') AND (""provider_name"" = 'our-provider')) ORDER BY ""consumer_version_order"" DESC LIMIT 1"
2021-01-20 15:53:41.563,2021-01-20 15:53:41.558188 D [7:puma 002] pact-broker -- (0.000313s) BEGIN
2021-01-20 15:53:41.558,2021-01-20 15:53:41.557774 D [7:puma 002] pact-broker -- (0.000533s) SELECT NULL
2021-01-20 15:53:41.529,2021-01-20 15:53:41.528983 D [6:puma 002] pact-broker -- (0.000471s) COMMIT
2021-01-20 15:53:41.528,"2021-01-20 15:53:41.527995 D [6:puma 002] pact-broker -- (0.000524s) SELECT * FROM ""pacticipants"" WHERE ""id"" = 7"
2021-01-20 15:53:41.527,"2021-01-20 15:53:41.527173 D [6:puma 002] pact-broker -- (0.000562s) SELECT * FROM ""versions"" WHERE ""id"" = 1345"
2021-01-20 15:53:41.526,"2021-01-20 15:53:41.526123 D [6:puma 002] pact-broker -- (0.001360s) SELECT ""tags"".* FROM ""tags"" INNER JOIN ""versions"" ON (""versions"".""id"" = ""tags"".""version_id"") INNER JOIN ""pacticipants"" ON (""pacticipants"".""id"" = ""versions"".""pacticipant_id"") WHERE ((""tags"".""name"" = 'develop') AND (""versions"".""number"" = '1.1.0-dev.107+c7182da') AND (""pacticipants"".""name"" = 'our-provider')) LIMIT 1"
2021-01-20 15:53:41.523,2021-01-20 15:53:41.522798 D [6:puma 002] pact-broker -- (0.000460s) BEGIN
2021-01-20 15:53:41.522,2021-01-20 15:53:41.522260 D [6:puma 002] pact-broker -- (0.000738s) SELECT NULL
2021-01-20 15:53:41.498,"2021-01-20 15:53:41.497047 D [6:puma 001] pact-broker -- (0.000702s) SELECT * FROM ""labels"" WHERE (""labels"".""pacticipant_id"" = 7) ORDER BY ""name"""
2021-01-20 15:53:41.496,2021-01-20 15:53:41.496296 D [6:puma 001] pact-broker -- (0.000593s) SELECT NULL
2021-01-20 15:53:41.495,"2021-01-20 15:53:41.480664 D [6:puma 001] pact-broker -- (0.001439s) SELECT * FROM ""versions"" WHERE (""versions"".""pacticipant_id"" = 7) ORDER BY ""order"""
2021-01-20 15:53:41.479,2021-01-20 15:53:41.479178 D [6:puma 001] pact-broker -- (0.000475s) SELECT NULL
2021-01-20 15:53:41.478,"2021-01-20 15:53:41.478058 D [6:puma 001] pact-broker -- (0.000770s) SELECT * FROM ""pacticipants"" WHERE (""name"" = 'our-provider')"
2021-01-20 15:53:41.477,2021-01-20 15:53:41.476649 D [6:puma 001] pact-broker -- (0.000728s) SELECT NULL
2021-01-20 15:53:41.477,2021-01-20 15:53:41.477237 D [6:puma 001] pact-broker -- (0.000470s) SELECT NULL
2021-01-20 15:53:38.615,"2021-01-20 15:53:38.613932 D [7:puma 002] pact-broker -- (0.000444s) SELECT * FROM ""tags"" WHERE (""tags"".""version_id"" = 1450)"
2021-01-20 15:53:38.613,"2021-01-20 15:53:38.613016 D [7:puma 002] pact-broker -- (0.001099s) SELECT * FROM ""latest_verifications_for_pact_versions"" WHERE (""latest_verifications_for_pact_versions"".""pact_version_id"" = 28) LIMIT 1"
2021-01-20 15:53:38.612,"2021-01-20 15:53:38.611683 D [7:puma 002] pact-broker -- (0.000499s) SELECT * FROM ""pact_versions"" WHERE ""id"" = 28"
2021-01-20 15:53:38.611,"2021-01-20 15:53:38.610997 D [7:puma 002] pact-broker -- (0.005450s) SELECT ""tag_name"" FROM ""latest_tagged_pact_publications"" WHERE (""id"" = 569)"
2021-01-20 15:53:38.605,"2021-01-20 15:53:38.605025 D [7:puma 002] pact-broker -- (0.001940s) SELECT * FROM ""all_pact_publications"" WHERE ((""pact_version_sha"" = 'a0750a59c10671430d5b260ac322266b98aa5340') AND (""consumer_name"" = 'our-consumer-with-small-contract') AND (""provider_name"" = 'our-provider')) ORDER BY ""consumer_version_order"" DESC LIMIT 1"
2021-01-20 15:53:38.603,2021-01-20 15:53:38.603033 D [7:puma 002] pact-broker -- (0.000345s) SELECT NULL
2021-01-20 15:53:38.602,2021-01-20 15:53:38.601661 D [7:puma 002] pact-broker -- (0.000556s) SELECT NULL
2021-01-20 15:53:38.602,2021-01-20 15:53:38.602162 D [7:puma 002] pact-broker -- (0.000361s) SELECT NULL
2021-01-20 15:53:38.602,2021-01-20 15:53:38.602568 D [7:puma 002] pact-broker -- (0.000329s) SELECT NULL
2021-01-20 15:53:38.461,2021-01-20 15:53:38.461436 D [7:puma 001] pact-broker -- (0.000365s) COMMIT
2021-01-20 15:53:38.459,"2021-01-20 15:53:38.458301 D [7:puma 001] pact-broker -- (0.000758s) SELECT * FROM ""latest_verifications_for_pact_versions"" WHERE (""latest_verifications_for_pact_versions"".""pact_version_id"" = 119) LIMIT 1"
2021-01-20 15:53:38.457,"2021-01-20 15:53:38.457366 D [7:puma 001] pact-broker -- (0.000960s) SELECT * FROM ""pact_versions"" WHERE ""id"" = 119"
2021-01-20 15:53:38.456,"2021-01-20 15:53:38.456211 D [7:puma 001] pact-broker -- (0.000404s) SELECT * FROM ""tags"" WHERE (""tags"".""version_id"" = 1363) ORDER BY ""created_at"""
2021-01-20 15:53:38.455,"2021-01-20 15:53:38.455039 D [7:puma 001] pact-broker -- (0.000384s) SELECT * FROM ""pacticipants"" WHERE ""id"" = 3"
2021-01-20 15:53:38.455,"2021-01-20 15:53:38.455609 D [7:puma 001] pact-broker -- (0.000385s) SELECT * FROM ""versions"" WHERE ""id"" = 1363"
2021-01-20 15:53:38.454,"2021-01-20 15:53:38.453894 D [7:puma 001] pact-broker -- (0.000444s) SELECT * FROM ""pact_publications"" WHERE (""id"" = 510) LIMIT 1"
2021-01-20 15:53:38.454,"2021-01-20 15:53:38.454465 D [7:puma 001] pact-broker -- (0.000402s) SELECT * FROM ""pacticipants"" WHERE ""id"" = 7"
2021-01-20 15:53:38.453,"2021-01-20 15:53:38.453041 D [7:puma 001] pact-broker -- (0.001430s) SELECT * FROM ""latest_verifications_for_pact_versions"" WHERE (""latest_verifications_for_pact_versions"".""pact_version_id"" = 28) LIMIT 1"
2021-01-20 15:53:38.451,"2021-01-20 15:53:38.451209 D [7:puma 001] pact-broker -- (0.000455s) SELECT * FROM ""pact_versions"" WHERE ""id"" = 28"
2021-01-20 15:53:38.450,"2021-01-20 15:53:38.449376 D [7:puma 001] pact-broker -- (0.000431s) SELECT * FROM ""versions"" WHERE ""id"" = 1450"
2021-01-20 15:53:38.450,"2021-01-20 15:53:38.450510 D [7:puma 001] pact-broker -- (0.000647s) SELECT * FROM ""tags"" WHERE (""tags"".""version_id"" = 1450) ORDER BY ""created_at"""
2021-01-20 15:53:38.449,"2021-01-20 15:53:38.448710 D [7:puma 001] pact-broker -- (0.000415s) SELECT * FROM ""pacticipants"" WHERE ""id"" = 6"
2021-01-20 15:53:38.448,"2021-01-20 15:53:38.447982 D [7:puma 001] pact-broker -- (0.000471s) SELECT * FROM ""pacticipants"" WHERE ""id"" = 7"
2021-01-20 15:53:38.447,"2021-01-20 15:53:38.447255 D [7:puma 001] pact-broker -- (0.000521s) SELECT * FROM ""pact_publications"" WHERE (""id"" = 569) LIMIT 1"
2021-01-20 15:53:38.446,"2021-01-20 15:53:38.446267 D [7:puma 001] pact-broker -- (0.007539s) SELECT * FROM ""latest_tagged_pact_publications"" WHERE ((""tag_name"" = 'develop') AND (""provider_name"" = 'our-provider'))"
2021-01-20 15:53:38.437,"2021-01-20 15:53:38.436099 D [7:puma 001] pact-broker -- (0.000780s) SELECT * FROM ""pacticipants"" WHERE (""name"" = 'our-provider')"
2021-01-20 15:53:38.434,2021-01-20 15:53:38.433317 D [7:puma 001] pact-broker -- (0.000366s) BEGIN
2021-01-20 15:53:38.433,2021-01-20 15:53:38.432848 D [7:puma 001] pact-broker -- (0.000621s) SELECT NULL

[mefellows]

Thanks!

In our Broker logs, we are seeing no errors.
In the Broker's load balancer logs, we are seeing a 500 being returned in the error cases:
This run sent a 32kB request, had a ~1ms response time from the broker, and a 500 response. This has been the behaviour for all but one time:

Strange. The 1ms response time strikes me as interesting - are you sure it made it to the broker itself? 1ms is unlikely enough time for it to even speak to the db, so it's either a) failing to parse the body or something else strange.

Is it possible your load balancer is rejecting it?

I think we're going to need to see the verification results themselves (and possible the contract) to be able to reproduce it. In either case, it seems like a downstream issue (i.e. unrelated to Pact JS) - either in the CLI tools we use to send these results, or the broker itself.

[bethesque]

What infrastructure are you using to deploy your broker? Is it the dius Docker image or the pactfoundation one?

[pfesenmeier]

Our broker is deployed on the pactfoundation/pact-broker:2.60.1.0 image.

[bethesque]

Can you try uploading the problem pact with a curl request? The docs are here https://docs.pact.io/pact_broker/publishing_and_retrieving_pacts#publish-using-http-requests

[pfesenmeier]

Uploading the pact to the broker via curl returned 200 OK and I can see the pact in the pact broker webpage.

[mefellows]

My understanding is that the issue is not publishing a pact (this is a provider verification right?), but publishing the provider verification results.

So uploading a pact via curl won't help diagnose this issue.

We need to see the verbose logs of the underlying Ruby process. can you please enable debug and verbose logging https://github.com/pact-foundation/pact-js#verification-options and share that?

[pfesenmeier]

Here is another section of the logs, with the npm installation information left out (it will take more time to clean that up).

10:28:35  our-provider  | [2021-01-25T15:28:34.622Z] DEBUG: pact-node@10.11.1/17 on dac839a9f3fe: 
10:28:35  our-provider  |     opening connection to our-pact-broker.com:123...
10:28:35  our-provider  |     opened
10:28:35  our-provider  |     starting SSL for our-pact-broker.com:123...
10:28:35  our-provider  |     SSL established
10:28:35  our-provider  |     <- "GET / HTTP/1.1\r\nAccept-Encoding: gzip;q=1.0,deflate;q=0.6,identity;q=0.3\r\nAccept: application/hal+json\r\nUser-Agent: Ruby\r\nAuthorization: [redacted]\r\n"
10:28:35  our-provider  |     -> "HTTP/1.1 200 OK\r\n"
10:28:35  our-provider  |     -> "Date: Mon, 25 Jan 2021 15:28:34 GMT\r\n"
10:28:35  our-provider  |     -> "Content-Type: application/hal+json;charset=utf-8\r\n"
10:28:35  our-provider  |     -> "Content-Length: 3763\r\n"
10:28:35  our-provider  |     -> "Connection: keep-alive\r\n"
10:28:35  our-provider  |     -> "Vary: Accept\r\n"
10:28:35  our-provider  |     -> "Server: Webmachine-Ruby/1.5.0 Rack/1.3\r\n"
10:28:35  our-provider  |     -> "X-Pact-Broker-Version: 2.60.1\r\n"
10:28:35  our-provider  |     -> "X-Content-Type-Options: nosniff\r\n"
10:28:35  our-provider  |     -> "\r\n"
10:28:35  our-provider  |     reading 3763 bytes...
10:28:35  our-provider  |     -> "{\"_links\":{\"self\":{\"href\":\"****\",\"title\":\"Index\",\"templated\":false},\"pb:publish-pact\":{\"href\":\"****/pacts/provider/{provider}/consumer/{consumer}/version/{consumerApplicationVersion}\",\"title\":\"Publish a pact\",\"templated\":true},\"pb:latest-pact-versions\":{\"href\":\"****/pacts/latest\",\"title\":\"Latest pact versions\",\"templated\":false},\"pb:tagged-pact-versions\":{\"href\":\"****/pacts/provider/{provider}/consumer/{consumer}/tag/{tag}\",\"title\":\"All versions of a pact for a given consumer, provider and consumer version tag\",\"templated\":false},\"pb:pacticipants\":{\"href\":\"****/pacticipants\",\"title\":\"Pacticipants\",\"templated\":false},\"pb:pacticipant\":{\"href\":\"****/pacticipants/{pacticipant}\",\"title\":\"Fetch pacticipant by name\",\"templated\":true},\"pb:latest-provider-pacts\":{\"href\":\"****/pacts/provider/{provider}/latest\",\"title\":\"Latest pacts by provider\",\"templated\":true},\"pb:latest-provider-pacts-with-tag\":{\"href\":\"****/pacts/provider/{provider}/latest/{tag}\",\"title\":\"Latest pacts for provider with the specified tag\",\"templated\":true},\"pb:provider-pacts-with-tag\":{\"href\":\"****/pacts/provider/{provider}/tag/{tag}\",\"title\":\"All pact versions for the provider with the specified consumer version tag\",\"templated\":true},\"pb:provider-pacts\":{\"href\":\"****/pacts/provider/{provider}\",\"title\":\"All pact versions for the specified provider\",\"templated\":true},\"pb:latest-version\":{\"href\":\"****/pacticipants/{pacticipant}/latest-version\",\"title\":\"Latest pacticipant version\",\"templated\":true},\"pb:latest-tagged-version\":{\"href\":\"****/pacticipants/{pacticipant}/latest-version/{tag}\",\"title\":\"Latest pacticipant version with the specified tag\",\"templated\":true},\"pb:webhooks\":{\"href\":\"****/webhooks\",\"title\":\"Webhooks\",\"templated\":false},\"pb:webhook\":{\"href\":\"****/webhooks/{uuid}\",\"title\":\"Webhook\",\"templated\":true},\"pb:integrations\":{\"href\":\"****/integrations\",\"title\":\"Integrations\",\"templated\":false},\"pb:pacticipant-version-tag\":{\"href\":\"****/pacticipants/{pacticipant}/versions/{version}/tags/{tag}\",\"title\":\"Get, create or delete a tag for a pacti"
10:28:35  our-provider  |     -> "cipant version\",\"templated\":true},\"pb:metrics\":{\"href\":\"****/metrics\",\"title\":\"Get Pact Broker metrics\"},\"pb:can-i-deploy-pacticipant-version-to-tag\":{\"href\":\"****/can-i-deploy?pacticipant={pacticipant}&version={version}&to={tag}\",\"title\":\"Determine if an application can be safely deployed to an environment identified by the given tag\",\"templated\":true},\"pb:provider-pacts-for-verification\":{\"href\":\"****/pacts/provider/{provider}/for-verification\",\"title\":\"Pact versions to be verified for the specified provider\",\"templated\":true},\"beta:provider-pacts-for-verification\":{\"name\":\"beta\",\"href\":\"****/pacts/provider/{provider}/for-verification\",\"title\":\"DEPRECATED - please use pb:provider-pacts-for-verification\",\"templated\":true},\"curies\":[{\"name\":\"pb\",\"href\":\"****/doc/{rel}?context=index\",\"templated\":true},{\"name\":\"beta\",\"href\":\"****/doc/{rel}?context=index\",\"templated\":true}]}}"
10:28:35  our-provider  |     read 3763 bytes
10:28:35  our-provider  |     Conn keep-alive
10:28:35  our-provider  |     INFO: Fetching pacts for our-provider from **** with the selection criteria: latest for tag our-feature-branch-find-pact-broker-errors
10:28:35  our-provider  |     opening connection to our-pact-broker.com:123...
10:28:35  our-provider  |     opened
10:28:35  our-provider  |     starting SSL for our-pact-broker.com:123...
10:28:35  our-provider  |     SSL established
10:28:35  our-provider  |     <- "POST /pacts/provider/our-provider/for-verification HTTP/1.1\r\nAccept-Encoding: gzip;q=1.0,deflate;q=0.6,identity;q=0.3\r\nAccept: application/hal+json\r\nUser-Agent: Ruby\r\nContent-Type: application/json\r\nAuthorization: [redacted]\r\n"
10:28:35  our-provider  |     <- "{\"consumerVersionSelectors\":[{\"tag\":\"our-feature-branch-find-pact-broker-errors\",\"latest\":true}],\"providerVersionTags\":[\"our-feature-branch-investigate-pact-broker-errors\"]}"
10:28:35  our-provider  |     -> "HTTP/1.1 200 OK\r\n"
10:28:35  our-provider  |     -> "Date: Mon, 25 Jan 2021 15:28:34 GMT\r\n"
10:28:35  our-provider  |     -> "Content-Type: application/hal+json;charset=utf-8\r\n"
10:28:35  our-provider  |     -> "Content-Length: 1139\r\n"
10:28:35  our-provider  |     -> "Connection: keep-alive\r\n"
10:28:35  our-provider  |     -> "Vary: Accept\r\n"
10:28:35  our-provider  |     -> "Server: Webmachine-Ruby/1.5.0 Rack/1.3\r\n"
10:28:35  our-provider  |     -> "X-Pact-Broker-Version: 2.60.1\r\n"
10:28:35  our-provider  |     -> "X-Content-Type-Options: nosniff\r\n"
10:28:35  our-provider  |     -> "\r\n"
10:28:35  our-provider  |     reading 1139 bytes...
10:28:35  our-provider  |     -> "{\"_embedded\":{\"pacts\":[{\"shortDescription\":\"latest our-feature-branch-find-pact-broker-errors\",\"verificationProperties\":{\"notices\":[{\"when\":\"before_verification\",\"text\":\"The pact at ****/pacts/provider/our-provider/consumer/our-consumer/pact-version/e858e41cbf2ecc05f1c98160486911ce543c7665 is being verified because it matches the following configured selection criterion: latest pact for a consumer version tagged 'our-feature-branch-find-pact-broker-errors'\"}],\"noteToDevelopers\":\"Please print out the text from the 'notices' rather than using the inclusionReason and the pendingReason fields. These will be removed when this API moves out of beta.\"},\"_links\":{\"self\":{\"href\":\"****/pacts/provider/our-provider/consumer/our-consumer/pact-version/e858e41cbf2ecc05f1c98160486911ce543c7665\",\"name\":\"Pact between our-consumer (1.1.0-our-feature-branch-find-pact-broker-errors.187+76b967f) and our-provider\"}}}]},\"_links\":{\"self\":{\"href\":\"****/pacts/provider/our-provider/for-verification\",\"title\":\"Pacts to be verified\"}}}"
10:28:35  our-provider  |     read 1139 bytes
10:28:35  our-provider  |     Conn keep-alive
10:28:35  our-provider  |     INFO: Reading pact at https://****:*****@our-pact-broker.com/pacts/provider/our-provider/consumer/our-consumer/pact-version/e858e41cbf2ecc05f1c98160486911ce543c7665
10:28:35  our-provider  |     DEBUG: The pact at ****/pacts/provider/our-provider/consumer/our-consumer/pact-version/e858e41cbf2ecc05f1c98160486911ce543c7665 is being verified because it matches the following configured selection criterion: latest pact for a consumer version tagged 'our-feature-branch-find-pact-broker-errors'
10:28:35  our-provider  |     
 Verifying a pact between our-consumer and our-provider
10:28:46  our-provider  |   redacted contract info
10:28:46  our-provider  | DEBUG: Setting up provider state [redacted]
10:28:46  our-provider  | 
10:28:46  our-provider  | I, [2021-01-25T15:28:34.633809 #35]  INFO -- request: POST http://localhost:33481/_pactSetup
10:28:46  our-provider  | 
10:28:46  our-provider  | D, [2021-01-25T15:28:34.634286 #35] DEBUG -- request: User-Agent: "Faraday v0.17.3"
10:28:46  our-provider  | Content-Type: "application/json"
10:28:46  our-provider  | 
10:28:46  our-provider  | I, [2021-01-25T15:28:34.660690 #35]  INFO -- response: Status 200
10:28:46  our-provider  | D, [2021-01-25T15:28:34.660784 #35] DEBUG -- response: x-powered-by: "Express"
10:28:46  our-provider  | content-type: "text/plain; charset=utf-8"
10:28:46  our-provider  | content-length: "2"
10:28:46  our-provider  | etag: "W/\"2-nOO9QiTIwXgNtWtBJezz8kv3SLc\""
10:28:46  our-provider  | date: "Mon, 25 Jan 2021 15:28:34 GMT"
10:28:46  our-provider  | connection: "close"
10:28:46  our-provider  | 
10:28:46  our-provider  |         redacted contract info
10:28:46  our-provider  | DEBUG: Setting up provider state [redacted]
10:28:46  our-provider  | 
10:28:46  our-provider  | I, [2021-01-25T15:28:34.739722 #35]  INFO -- request: POST http://localhost:33481/_pactSetup
10:28:46  our-provider  | 
10:28:46  our-provider  | D, [2021-01-25T15:28:34.740562 #35] DEBUG -- request: User-Agent: "Faraday v0.17.3"
10:28:46  our-provider  | Content-Type: "application/json"
10:28:46  our-provider  | 
10:28:46  our-provider  | I, [2021-01-25T15:28:34.744287 #35]  INFO -- response: Status 200
10:28:46  our-provider  | D, [2021-01-25T15:28:34.712378 #35] DEBUG -- response: x-powered-by: "Express"
10:28:46  our-provider  | content-type: "text/plain; charset=utf-8"
10:28:46  our-provider  | content-length: "2"
10:28:46  our-provider  | etag: "W/\"2-nOO9QiTIwXgNtWtBJezz8kv3SLc\""
10:28:46  our-provider  | date: "Mon, 25 Jan 2021 15:28:34 GMT"
10:28:46  our-provider  | connection: "close"

... logs continue until the stack trace shared above

[bethesque]

Can you include the verbose logs of the actual call that causes the error please.

[pfesenmeier]

Ah, thank you. Unfortunately, I am not seeing any error logs other than the stack trace from my original response.

[bethesque]

Hm, maybe the verbose flag isn't passed through to that call. I'll have a look.

[bethesque]

The flag wasn't being passed through to the verification publication bit. I've updated that, and there will be a new release of the standalone out in a few minutes. We'll need to put out a new release of pact node to get that code.