pact-python icon indicating copy to clipboard operation
pact-python copied to clipboard
verified publisher icon pact-foundation

(V3) Verifying a contract with a missing content field is always successful when it should error

Open drmason13 opened this issue 6 months ago • 3 comments

Have you read the Contributing Guidelines on issues?

Prerequisites

  • [x] I'm using the latest version of pact-python.
  • [ ] I have read the console error message carefully (if applicable).

Description

I have two pacts, one is incorrectly setting the content thus:

  "contents": {
      "Payload": "exists"
  }

The other is correctly setting the content thus:

  "contents": {
      "content": {
          "Payload": "exists"
      },
      "contentType": "application/json",
      "encoded": false
  }

When verifying with content that does not match, I expect both pacts to fail to verify. However, the first pact with the incorrect json verifies successfully and there is no error or warning that anything is wrong:

Verifying a pact between my-consumer and my-provider

  This works as expected when verifying my-provider (0s loading, 8ms verification)
     Given When reading a message from the SQS queue
    generates a message which
      includes metadata
        "contentType" with value "application/json" (OK)
      has a matching body (FAILED)


Verifying a pact between other-consumer and my-provider

  This is silently ignored while verifying my-provider (0s loading, 6ms verification)
     Given When reading a message from the SQS queue
    generates a message which
      has a matching body (OK)

I'll see if I can get approval to share a producible demo repo, but for now the pacts are:

pact-missing-contents.json 

{
    "consumer": {
        "name": "other-consumer"
    },
    "provider": {
        "name": "my-provider"
    },
    "interactions": [
        {
            "_id": "1",
            "type": "Asynchronous/Messages",
            "description": "This is silently ignored while verifying my-provider",
            "providerStates": [
                {
                    "name": "When reading a message from the SQS queue"
                }
            ],
            "contents": {
                "Payload": "exists"
            }
        }
    ],
    "metadata": {
        "pactRust": {
            "ffi": "0.4.22",
            "models": "1.2.3"
        },
        "pactSpecification": {
            "version": "4.0"
        }
    }
}
pact-with-contents.json 

{
    "consumer": {
        "name": "my-consumer"
    },
    "provider": {
        "name": "my-provider"
    },
    "interactions": [
        {
            "_id": "2",
            "type": "Asynchronous/Messages",
            "description": "This works as expected when verifying my-provider",
            "providerStates": [
                {
                    "name": "When reading a message from the SQS queue"
                }
            ],
            "contents": {
                "content": {
                    "Payload": "exists"
                },
                "contentType": "application/json",
                "encoded": false
            }
        }
    ],
    "metadata": {
        "pactRust": {
            "ffi": "0.4.22",
            "models": "1.2.3"
        },
        "pactSpecification": {
            "version": "4.0"
        }
    }
}

And here's an idea of running the verification. I actually use a whole pytest setup with fixtures, but for brevity this ought to be able to reproduce the issue. Again, hopefully I'll be able to share a repo soon.

verify.py 

def run_message_handler(name: str, metadata: dict[str, Any] | None) -> Message:
    """This should fail to match due to missing Payload field for **both** pacts"""
    return Message(contents=b"{}", content_type="application/json", metadata=None)

verifier = Verifier("my-provider")
pact_dir = Path(file).parent / "pacts"
verifier = verifier.add_source(pact_dir).set_error_on_empty_pact()


verifier.message_handler(run_message_handler).verify()

*caveat to "I'm using the latest version": I'm using the latest version available on pypi, version 2.3.1 (as opposed to 2.3.2 available via github releases)

Reproducible demo

No response

Steps to reproduce

step 1: copy the two pact jsons and place them in separate files in a pacts/ directory step 2: verify the pacts using pact v3, see verify.py for an example

Expected behavior

it should fail with an error due to missing "content" and/or "contentType" but it does not.

You can also enable logging (before step 3) and confirm there is no warning or error logged.

Actual behavior

"other-consumer" pact (pact-missing-contents.json) is verified successfully. "my-consumer" pact (pact-with-contents.json) fails to verify (due to the mismatched content, as expected).

Your environment

  • Public source code: no
  • Is this a consumer or provider issue? Do you have information about the other side?: provider
  • Pact Python version used: pip list | grep pact: pact-python 2.3.1
  • Information about your Pact broker (version, hosted where, pactflow, ...): N/A
  • Operating system and version (e.g. Ubuntu 20.04.2 LTS, macOS Ventura): Debian GNU/Linux 12 (bookworm)

Self-service

  • [ ] I'd be willing to fix this bug myself.

drmason13 avatar Jul 11 '25 10:07 drmason13

oh, I should also add: I'm using pact specification 4.0 - it's there in the pacts, but just to point it out explicitly

drmason13 avatar Jul 11 '25 10:07 drmason13

I also have the logs (DEBUG verbosity) from my full pytest repro in case that helps

--------------------------------------------------------------------------- Captured stderr setup ----------------------------------------------------------------------------
2025-07-11T07:46:44.008319Z DEBUG ThreadId(01) pact_ffi::verifier: pact_ffi::verifier::pactffi_verifier_new_for_application FFI function invoked
2025-07-11T07:46:44.008473Z DEBUG ThreadId(01) pact_ffi::verifier: pact_ffi::verifier::pactffi_verifier_add_directory_source FFI function invoked
---------------------------------------------------------------------------- Captured stdout call ----------------------------------------------------------------------------

Verifying a pact between my-consumer and my-provider

  This works as expected when verifying my-provider (0s loading, 8ms verification)
     Given When reading a message from the SQS queue
    generates a message which
      includes metadata
        "contentType" with value "application/json" (OK)
      has a matching body (FAILED)


Verifying a pact between other-consumer and my-provider

  This is silently ignored while verifying my-provider (0s loading, 6ms verification)
     Given When reading a message from the SQS queue
    generates a message which
      has a matching body (OK)


Failures:

1) Verifying a pact between my-consumer and my-provider Given When reading a message from the SQS queue - This works as expected when verifying my-provider
    1.1) has a matching body
           $ -> Actual map is missing the following keys: Payload
    -{
  "Payload": "exists"
}
    +{}


There were 1 pact failures

---------------------------------------------------------------------------- Captured stderr call ----------------------------------------------------------------------------
2025-07-11T07:46:44.008956Z DEBUG ThreadId(01) pact_ffi::verifier: pact_ffi::verifier::pactffi_verifier_set_provider_info FFI function invoked
2025-07-11T07:46:44.009634Z DEBUG ThreadId(01) pact_ffi::verifier: pact_ffi::verifier::pactffi_verifier_execute FFI function invoked
2025-07-11T07:46:44.009657Z DEBUG ThreadId(01) pact_ffi::verifier::handle: Pact source to verify = Dir(/workspaces/v3/bug-report/bug_report_tests/bug-report-pacts)
2025-07-11T07:46:44.010543Z 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
2025-07-11T07:46:44.010624Z 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
2025-07-11T07:46:44.010690Z DEBUG ThreadId(01) pact_verifier: Scanning "/workspaces/v3/bug-report/bug_report_tests/bug-report-pacts"
2025-07-11T07:46:44.016515Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_verifier: Executing provider states
2025-07-11T07:46:44.016549Z  INFO ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_verifier: Running setup provider state change handler 'When reading a message from the SQS queue' for 'This works as expected when verifying my-provider'
2025-07-11T07:46:44.016557Z  WARN ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_verifier::callback_executors: State Change ignored as there is no state change URL provided for interaction 53dd17cd2bbbd5c5a8a5e86b544b40ecee8a7c34
2025-07-11T07:46:44.016563Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_verifier: State Change: "ProviderState { name: "When reading a message from the SQS queue", params: {} }" -> Ok({})
2025-07-11T07:46:44.016578Z  INFO ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_verifier: Running provider verification for 'This works as expected when verifying my-provider'
2025-07-11T07:46:44.016591Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_verifier: Verifying an asynchronous message (single shot)
2025-07-11T07:46:44.016627Z  INFO ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_verifier::provider_client: Sending request to provider at http://localhost:55255/_pact/message
2025-07-11T07:46:44.016633Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_verifier::provider_client: Provider details = ProviderInfo { name: "my-provider", protocol: "http", host: "localhost", port: Some(55255), path: "/_pact/message", transports: [ProviderTransport { transport: "http", port: Some(55255), path: Some("/_pact/message"), scheme: Some("http") }] }
2025-07-11T07:46:44.016643Z  INFO ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_verifier::provider_client: Sending request HTTP Request ( method: POST, path: /, query: None, headers: Some({"Content-Type": ["application/json"]}), body: Present(139 bytes, application/json) )
2025-07-11T07:46:44.016654Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_verifier::provider_client: body:
{"description":"This works as expected when verifying my-provider","providerStates":[{"name":"When reading a message from the SQS queue"}]}
2025-07-11T07:46:44.016775Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: reqwest::connect: starting new connection: http://localhost:55255/    
2025-07-11T07:46:44.016915Z DEBUG tokio-runtime-worker hyper_util::client::legacy::connect::dns: resolving host="localhost"
2025-07-11T07:46:44.017101Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: hyper_util::client::legacy::connect::http: connecting to [::1]:55255
2025-07-11T07:46:44.017195Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: hyper_util::client::legacy::connect::http: connecting to 127.0.0.1:55255
2025-07-11T07:46:44.017282Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: hyper_util::client::legacy::connect::http: connected to 127.0.0.1:55255
127.0.0.1 - - [11/Jul/2025 07:46:44] "POST /_pact/message HTTP/1.1" 200 -
2025-07-11T07:46:44.018119Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_verifier::provider_client: Received native response: Response { url: Url { scheme: "http", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("localhost")), port: Some(55255), path: "/_pact/message", query: None, fragment: None }, status: 200, headers: {"server": "Pact Python Message Relay/2.3.1", "date": "Fri, 11 Jul 2025 07:46:44 GMT", "content-type": "application/json", "pact-message-metadata": "eyJjb250ZW50VHlwZSI6ICJhcHBsaWNhdGlvbi9qc29uIn0=", "content-length": "2"} }
2025-07-11T07:46:44.018202Z  INFO ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_verifier::provider_client: Received response: HTTP Response ( status: 200, headers: Some({"date": ["Fri, 11 Jul 2025 07:46:44 GMT"], "content-type": ["application/json"], "server": ["Pact Python Message Relay/2.3.1"], "pact-message-metadata": ["eyJjb250ZW50VHlwZSI6ICJhcHBsaWNhdGlvbi9qc29uIn0="], "content-length": ["2"]}), body: Present(2 bytes, application/json) )
2025-07-11T07:46:44.018218Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_verifier::provider_client: body:
{}
2025-07-11T07:46:44.018241Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_verifier::messages: actual message = AsynchronousMessage { id: None, key: None, description: "Asynchronous/Message Interaction", provider_states: [], contents: MessageContents { contents: Present(b"{}", Some(ContentType { main_type: "application", sub_type: "json", attributes: {}, suffix: None }), None), metadata: {"contentType": String("application/json")}, matching_rules: MatchingRules { rules: {} }, generators: Generators { categories: {} } }, comments: {}, pending: false, plugin_config: {}, interaction_markup: InteractionMarkup { markup: "", markup_type: "" }, transport: None }
2025-07-11T07:46:44.018260Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_matching: comparing to expected message: AsynchronousMessage { id: Some("53dd17cd2bbbd5c5a8a5e86b544b40ecee8a7c34"), key: None, description: "This works as expected when verifying my-provider", provider_states: [ProviderState { name: "When reading a message from the SQS queue", params: {} }], contents: MessageContents { contents: Present(b"{\"Payload\":\"exists\"}", Some(ContentType { main_type: "application", sub_type: "json", attributes: {}, suffix: None }), None), metadata: {}, matching_rules: MatchingRules { rules: {} }, generators: Generators { categories: {} } }, comments: {}, pending: false, plugin_config: {}, interaction_markup: InteractionMarkup { markup: "", markup_type: "" }, transport: None }
2025-07-11T07:46:44.018303Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_matching: expected content type = 'application/json', actual content type = 'application/json'
2025-07-11T07:46:44.018311Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_plugin_driver::catalogue_manager: Looking for a content matcher for application/json
2025-07-11T07:46:44.019094Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_matching: No content matcher defined for content type 'application/json', using core matcher implementation
2025-07-11T07:46:44.019108Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_matching: Using body matcher for content type 'application/json'
2025-07-11T07:46:44.019118Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_matching::json: compare: Comparing path $
2025-07-11T07:46:44.019124Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_matching::json: compare_maps: Comparing maps at $: {"Payload": String("exists")} -> {}
2025-07-11T07:46:44.019257Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_matching: Matching message metadata
2025-07-11T07:46:44.019265Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_matching: Matching message metadata. Expected '{"contentType": String("application/json")}', Actual '{"contentType": String("application/json")}'
2025-07-11T07:46:44.019271Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_matching: Comparing metadata values for key 'contentType'
2025-07-11T07:46:44.019281Z DEBUG ThreadId(01) verify_interaction{interaction="This works as expected when verifying my-provider"}: pact_matching: Comparing message context type '"application/json"' => '"application/json"'
2025-07-11T07:46:44.024545Z DEBUG ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: pact_verifier: Executing provider states
2025-07-11T07:46:44.024575Z  INFO ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: pact_verifier: Running setup provider state change handler 'When reading a message from the SQS queue' for 'This is silently ignored while verifying my-provider'
2025-07-11T07:46:44.024583Z  WARN ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: pact_verifier::callback_executors: State Change ignored as there is no state change URL provided for interaction 53dd17cd2bbbd5c5a8a5e86b544b40ecee8a7c34
2025-07-11T07:46:44.024589Z DEBUG ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: pact_verifier: State Change: "ProviderState { name: "When reading a message from the SQS queue", params: {} }" -> Ok({})
2025-07-11T07:46:44.024601Z  INFO ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: pact_verifier: Running provider verification for 'This is silently ignored while verifying my-provider'
2025-07-11T07:46:44.024610Z DEBUG ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: pact_verifier: Verifying an asynchronous message (single shot)
2025-07-11T07:46:44.024638Z  INFO ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: pact_verifier::provider_client: Sending request to provider at http://localhost:55255/_pact/message
2025-07-11T07:46:44.024643Z DEBUG ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: pact_verifier::provider_client: Provider details = ProviderInfo { name: "my-provider", protocol: "http", host: "localhost", port: Some(55255), path: "/_pact/message", transports: [ProviderTransport { transport: "http", port: Some(55255), path: Some("/_pact/message"), scheme: Some("http") }] }
2025-07-11T07:46:44.024661Z  INFO ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: pact_verifier::provider_client: Sending request HTTP Request ( method: POST, path: /, query: None, headers: Some({"Content-Type": ["application/json"]}), body: Present(142 bytes, application/json) )
2025-07-11T07:46:44.024671Z DEBUG ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: pact_verifier::provider_client: body:
{"description":"This is silently ignored while verifying my-provider","providerStates":[{"name":"When reading a message from the SQS queue"}]}
2025-07-11T07:46:44.024728Z DEBUG ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: reqwest::connect: starting new connection: http://localhost:55255/    
2025-07-11T07:46:44.024767Z DEBUG tokio-runtime-worker hyper_util::client::legacy::connect::dns: resolving host="localhost"
2025-07-11T07:46:44.024927Z DEBUG ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: hyper_util::client::legacy::connect::http: connecting to [::1]:55255
2025-07-11T07:46:44.025043Z DEBUG ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: hyper_util::client::legacy::connect::http: connecting to 127.0.0.1:55255
2025-07-11T07:46:44.025126Z DEBUG ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: hyper_util::client::legacy::connect::http: connected to 127.0.0.1:55255
127.0.0.1 - - [11/Jul/2025 07:46:44] "POST /_pact/message HTTP/1.1" 200 -
2025-07-11T07:46:44.025825Z DEBUG ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: pact_verifier::provider_client: Received native response: Response { url: Url { scheme: "http", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("localhost")), port: Some(55255), path: "/_pact/message", query: None, fragment: None }, status: 200, headers: {"server": "Pact Python Message Relay/2.3.1", "date": "Fri, 11 Jul 2025 07:46:44 GMT", "content-type": "application/json", "pact-message-metadata": "eyJjb250ZW50VHlwZSI6ICJhcHBsaWNhdGlvbi9qc29uIn0=", "content-length": "2"} }
2025-07-11T07:46:44.025894Z  INFO ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: pact_verifier::provider_client: Received response: HTTP Response ( status: 200, headers: Some({"content-length": ["2"], "server": ["Pact Python Message Relay/2.3.1"], "date": ["Fri, 11 Jul 2025 07:46:44 GMT"], "pact-message-metadata": ["eyJjb250ZW50VHlwZSI6ICJhcHBsaWNhdGlvbi9qc29uIn0="], "content-type": ["application/json"]}), body: Present(2 bytes, application/json) )
2025-07-11T07:46:44.025907Z DEBUG ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: pact_verifier::provider_client: body:
{}
2025-07-11T07:46:44.025929Z DEBUG ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: pact_verifier::messages: actual message = AsynchronousMessage { id: None, key: None, description: "Asynchronous/Message Interaction", provider_states: [], contents: MessageContents { contents: Present(b"{}", Some(ContentType { main_type: "application", sub_type: "json", attributes: {}, suffix: None }), None), metadata: {"contentType": String("application/json")}, matching_rules: MatchingRules { rules: {} }, generators: Generators { categories: {} } }, comments: {}, pending: false, plugin_config: {}, interaction_markup: InteractionMarkup { markup: "", markup_type: "" }, transport: None }
2025-07-11T07:46:44.025947Z DEBUG ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: pact_matching: comparing to expected message: AsynchronousMessage { id: Some("53dd17cd2bbbd5c5a8a5e86b544b40ecee8a7c34"), key: None, description: "This is silently ignored while verifying my-provider", provider_states: [ProviderState { name: "When reading a message from the SQS queue", params: {} }], contents: MessageContents { contents: Missing, metadata: {}, matching_rules: MatchingRules { rules: {} }, generators: Generators { categories: {} } }, comments: {}, pending: false, plugin_config: {}, interaction_markup: InteractionMarkup { markup: "", markup_type: "" }, transport: None }
2025-07-11T07:46:44.025977Z DEBUG ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: pact_matching: expected content type = '*/*', actual content type = 'application/json'
2025-07-11T07:46:44.025986Z DEBUG ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: pact_matching: Matching message metadata
2025-07-11T07:46:44.025990Z DEBUG ThreadId(01) verify_interaction{interaction="This is silently ignored while verifying my-provider"}: pact_matching: Matching message metadata. Expected '{}', Actual '{"contentType": String("application/json")}'
2025-07-11T07:46:44.026076Z DEBUG ThreadId(01) pact_matching::metrics: 'PACT_DO_NOT_TRACK' environment variable is set, will not send metrics
2025-07-11T07:46:44.026177Z DEBUG ThreadId(01) pact_plugin_driver::plugin_manager: Shutting down all plugins

drmason13 avatar Jul 11 '25 10:07 drmason13

I'm not sure how I missed this... but I will look into this in the next few days!

JP-Ellis avatar Oct 06 '25 03:10 JP-Ellis