Pact mock server error: Request-Mismatch - How do I debug this?

Question

I have a Pact defined but when the specified PUT call is made to the mock, I get a Request-Mismatch error. I've confirmed that the message string that is sent to the mock matches. I've search the web, tried playing with enabling/disabling headers, etc with no luck.

Does anyone know how to debug this OR can you see what I may be doing wrong with my Pact?

var config = new PactConfig
{
    PactDir = PactDir,
    Outputters = new List<IOutput> { new XunitOutput(output), new ConsoleOutput() },
    LogLevel = PactLogLevel.Trace
};

_pact = PactNet.Pact.V3(_consumerName, _providerName, config).WithHttpInteractions();

    // Define overall contract and pact mock behavior
_pact
    // Define request made by consumer to provider
    .UponReceiving("Object has null callback URL")
        .Given("my provider state here")
        .WithRequest(HttpMethod.Put, "/do_thing")
        .WithHeader("Accept", "application/json; charset=utf-8")
        .WithHeader("content-length", "170")
        .WithHeader("Authorization", "Bearer")
        .WithHeader("Host", mockUrl)
        .WithBody(requestBody, "application/json; charset=utf-8")
    // Define response by provider to consumer 
    .WillRespond()
        .WithStatus(HttpStatusCode.OK)
        .WithHeader("Content-Type", "application/json; charset=utf-8")
        .WithJsonBody(expectedJobResponseDyn);

await _pact
    .VerifyAsync(async context =>
    {
        mockUrl = context.MockServerUri.ToString().TrimEnd('/');
        MyObject myObject = new() { CallbackUri = mockUrl};
        requestBody = JsonSerializer.Serialize(myObject);

        // Act //////////
        ResponseObject result = await client.SendRequestAsync(myObject);

        // Assert //////////
        result.Code.Should().Be(someOtherObj.Code);
        result.Message.Should().Be(someOtherObj.Message);
    });

Here is the response message I am getting:

{"error":"Request-Mismatch : HttpRequest { method: \"PUT\", path: \"/do_thing\", query: None, headers: Some({\"host\": [\"127.0.0.1:58615\"], \"authorization\": [\"Bearer\"], \"content-length\": [\"170\"], \"content-type\": [\"application/json; charset=utf-8\"]}), body: Present(b\"{\\\"JobId\\\":\\\"00000000-0000-0000-0000-000000000000\\\",\\\"CallbackUri\\\":\\\"http://127.0.0.1:58615\\\"}\", Some(ContentType { main_type: \"application\", sub_type: \"json\", attributes: {\"charset\": \"utf-8\"}, suffix: None }), None), matching_rules: MatchingRules { rules: {} }, generators: Generators { categories: {} } }"}

Here are the trace logs from the test output...

 Mock driver logs:

2023-11-14T14:01:08.932974Z DEBUG tokio-runtime-worker pact_mock_server::hyper_server: Creating pact request from hyper request
2023-11-14T14:01:08.932979Z DEBUG tokio-runtime-worker pact_mock_server::hyper_server: Extracting query from uri /do_thing
2023-11-14T14:01:08.932983Z TRACE tokio-runtime-worker pact_mock_server::hyper_server: path_and_query -> /do_thing
2023-11-14T14:01:08.933022Z  INFO tokio-runtime-worker pact_mock_server::hyper_server: Received request HTTP Request ( method: PUT, path: /do_thing, query: None, headers: Some({"content-length": ["170"], "authorization": ["Bearer"], "host": ["127.0.0.1:64526"], "content-type": ["application/json; charset=utf-8"]}), body: Present(170 bytes, application/json;charset=utf-8) )
2023-11-14T14:01:08.933034Z DEBUG tokio-runtime-worker pact_mock_server::hyper_server:      body: '{"JobId":"00000000-0000-0000-0000-000000000000","CallbackUri":"http://127.0.0.1:64526"}'
2023-11-14T14:01:08.933065Z  INFO tokio-runtime-worker pact_matching: comparing to expected HTTP Request ( method: PUT, path: /do_thing, query: None, headers: Some({"content-length": ["170"], "Content-Type": ["application/json"]}), body: Present(2 bytes, application/json) )
2023-11-14T14:01:08.933069Z DEBUG tokio-runtime-worker pact_matching:      body: '""'
2023-11-14T14:01:08.933070Z DEBUG tokio-runtime-worker pact_matching:      matching_rules: MatchingRules { rules: {PATH: MatchingRuleCategory { name: PATH, rules: {} }, HEADER: MatchingRuleCategory { name: HEADER, rules: {} }, BODY: MatchingRuleCategory { name: BODY, rules: {} }} }
2023-11-14T14:01:08.933072Z DEBUG tokio-runtime-worker pact_matching:      generators: Generators { categories: {} }
2023-11-14T14:01:08.933076Z TRACE tokio-runtime-worker pact_matching: plugin_data = {}
2023-11-14T14:01:08.933091Z TRACE tokio-runtime-worker matcher_is_defined{self=CoreMatchingContext { matchers: MatchingRuleCategory { name: PATH, rules: {} }, config: NoUnexpectedKeys, matching_spec: V3, plugin_configuration: {} } path=DocPath { path_tokens: [], expr: "" }}: pact_models::matchingrules: matcher_is_defined: for category path and path [] -> false
2023-11-14T14:01:08.933102Z DEBUG tokio-runtime-worker matches_with{self="/do_thing" actual="/do_thing" matcher=Equality cascaded=false}: pact_matching::matchers: String -> String: comparing '/do_thing' to '/do_thing' ==> true cascaded=false matcher=Equality
2023-11-14T14:01:08.933106Z DEBUG tokio-runtime-worker pact_matching: expected content type = 'application/json', actual content type = 'application/json;charset=utf-8'
2023-11-14T14:01:08.933128Z DEBUG tokio-runtime-worker pact_matching: content type header matcher = 'RuleList { rules: [], rule_logic: And, cascaded: false }'
2023-11-14T14:01:08.933132Z DEBUG tokio-runtime-worker pact_plugin_driver::catalogue_manager: Looking for a content matcher for application/json
2023-11-14T14:01:08.933138Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue has 30 entries
2023-11-14T14:01:08.933139Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v3-content-type", values: {} }
2023-11-14T14:01:08.933142Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: CONTENT_MATCHER, provider_type: CORE, plugin: None, key: "json", values: {"content-types": "application/.*json,application/json-rpc,application/jsonrequest"} }
2023-11-14T14:01:08.933144Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry is a content matcher for Some("application/.*json,application/json-rpc,application/jsonrequest")
2023-11-14T14:01:08.933236Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v3-date", values: {} }
2023-11-14T14:01:08.933237Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v1-equality", values: {} }
2023-11-14T14:01:08.933238Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: CONTENT_MATCHER, provider_type: CORE, plugin: None, key: "xml", values: {"content-types": "application/.*xml,text/xml"} }
2023-11-14T14:01:08.933239Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry is a content matcher for Some("application/.*xml,text/xml")
2023-11-14T14:01:08.933289Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v3-decimal-type", values: {} }
2023-11-14T14:01:08.933290Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: TRANSPORT, provider_type: CORE, plugin: None, key: "http", values: {} }
2023-11-14T14:01:08.933290Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v2-max-type", values: {} }
2023-11-14T14:01:08.933291Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v4-not-empty", values: {} }
2023-11-14T14:01:08.933292Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v3-number-type", values: {} }
2023-11-14T14:01:08.933293Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v2-regex", values: {} }
2023-11-14T14:01:08.933293Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v4-semver", values: {} }
2023-11-14T14:01:08.933294Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: CONTENT_GENERATOR, provider_type: CORE, plugin: None, key: "binary", values: {"content-types": "application/octet-stream"} }
2023-11-14T14:01:08.933295Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v2-min-type", values: {} }
2023-11-14T14:01:08.933296Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v3-includes", values: {} }
2023-11-14T14:01:08.933296Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v2-type", values: {} }
2023-11-14T14:01:08.933297Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v3-null", values: {} }
2023-11-14T14:01:08.933298Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v4-max-equals-ignore-order", values: {} }
2023-11-14T14:01:08.933298Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v4-minmax-equals-ignore-order", values: {} }
2023-11-14T14:01:08.933299Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v4-min-equals-ignore-order", values: {} }
2023-11-14T14:01:08.933300Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v3-time", values: {} }
2023-11-14T14:01:08.933301Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: TRANSPORT, provider_type: CORE, plugin: None, key: "https", values: {} }
2023-11-14T14:01:08.933302Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: CONTENT_MATCHER, provider_type: CORE, plugin: None, key: "text", values: {"content-types": "text/plain"} }
2023-11-14T14:01:08.933303Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry is a content matcher for Some("text/plain")
2023-11-14T14:01:08.933328Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v2-minmax-type", values: {} }
2023-11-14T14:01:08.933329Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v3-integer-type", values: {} }
2023-11-14T14:01:08.933330Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: CONTENT_GENERATOR, provider_type: CORE, plugin: None, key: "json", values: {"content-types": "application/.*json,application/json-rpc,application/jsonrequest"} }
2023-11-14T14:01:08.933331Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v4-equals-ignore-order", values: {} }
2023-11-14T14:01:08.933332Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v3-datetime", values: {} }
2023-11-14T14:01:08.933333Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: CONTENT_MATCHER, provider_type: CORE, plugin: None, key: "multipart-form-data", values: {"content-types": "multipart/form-data,multipart/mixed"} }
2023-11-14T14:01:08.933334Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry is a content matcher for Some("multipart/form-data,multipart/mixed")
2023-11-14T14:01:08.933381Z TRACE tokio-runtime-worker pact_plugin_driver::catalogue_manager: Catalogue entry CatalogueEntry { entry_type: MATCHER, provider_type: CORE, plugin: None, key: "v4-array-contains", values: {} }
2023-11-14T14:01:08.933384Z DEBUG tokio-runtime-worker pact_matching: No content matcher defined for content type 'application/json', using core matcher implementation
2023-11-14T14:01:08.933388Z DEBUG tokio-runtime-worker pact_matching: Using body matcher for content type 'application/json'
2023-11-14T14:01:08.933402Z DEBUG tokio-runtime-worker pact_matching::json: compare: Comparing path $
2023-11-14T14:01:08.933406Z TRACE tokio-runtime-worker matcher_is_defined{self=CoreMatchingContext { matchers: MatchingRuleCategory { name: BODY, rules: {} }, config: NoUnexpectedKeys, matching_spec: V3, plugin_configuration: {} } path=DocPath { path_tokens: [Root], expr: "$" }}: pact_models::matchingrules: matcher_is_defined: for category body and path ["$"] -> false
2023-11-14T14:01:08.933416Z DEBUG tokio-runtime-worker pact_matching::json: JSON -> JSON: Comparing '""' to '{"AttemptNumber":0,"CallbackTypes":[],"CallbackUri":"http://127.0.0.1:64526","Comments":null,"Entities":null,"JobId":"00000000-0000-0000-0000-000000000000","Status":null}' using Equality -> Err(Expected '' to be equal to '{"CallbackUri":"http://127.0.0.1:64526","JobId":"00000000-0000-0000-0000-000000000000"}')
2023-11-14T14:01:08.933426Z DEBUG tokio-runtime-worker pact_matching::json: compare_values: Comparing 'String("")' to 'Object {"AttemptNumber": Number(0), "CallbackTypes": Array [], "CallbackUri": String("http://127.0.0.1:64526"), "Comments": Null, "Entities": Null, "JobId": String("00000000-0000-0000-0000-000000000000"), "Status": Null}' at path '$' -> Err(["Expected '' to be equal to '{\"CallbackUri\":\"http://127.0.0.1:64526\",\"JobId\":\"00000000-0000-0000-0000-000000000000\"])
2023-11-14T14:01:08.933476Z TRACE tokio-runtime-worker match_header_value{key="content-length" index=0 expected="170" actual="170" context=CoreMatchingContext { matchers: MatchingRuleCategory { name: HEADER, rules: {} }, config: NoUnexpectedKeys, matching_spec: V3, plugin_configuration: {} } single_value=true}:matcher_is_defined{self=CoreMatchingContext { matchers: MatchingRuleCategory { name: HEADER, rules: {} }, config: NoUnexpectedKeys, matching_spec: V3, plugin_configuration: {} } path=DocPath { path_tokens: [Root, Field("content-length")], expr: "$['content-length']" }}: pact_models::matchingrules: matcher_is_defined: for category header and path ["$", "content-length"] -> false
2023-11-14T14:01:08.933479Z TRACE tokio-runtime-worker match_header_value{key="content-length" index=0 expected="170" actual="170" context=CoreMatchingContext { matchers: MatchingRuleCategory { name: HEADER, rules: {} }, config: NoUnexpectedKeys, matching_spec: V3, plugin_configuration: {} } single_value=true}:matcher_is_defined{self=CoreMatchingContext { matchers: MatchingRuleCategory { name: HEADER, rules: {} }, config: NoUnexpectedKeys, matching_spec: V3, plugin_configuration: {} } path=DocPath { path_tokens: [Root, Field("content-length"), Index(0)], expr: "$['content-length'][0]" }}: pact_models::matchingrules: matcher_is_defined: for category header and path ["$", "content-length", "0"] -> false
2023-11-14T14:01:08.933487Z DEBUG tokio-runtime-worker match_header_value{key="content-length" index=0 expected="170" actual="170" context=CoreMatchingContext { matchers: MatchingRuleCategory { name: HEADER, rules: {} }, config: NoUnexpectedKeys, matching_spec: V3, plugin_configuration: {} } single_value=true}:matches_with{self="170" actual="170" matcher=Equality cascaded=false}:matches_with{self="170" actual="170" matcher=Equality cascaded=false}: pact_matching::matchers: String -> String: comparing '170' to '170' ==> true cascaded=false matcher=Equality
2023-11-14T14:01:08.933500Z TRACE tokio-runtime-worker match_header_value{key="Content-Type" index=0 expected="application/json" actual="application/json; charset=utf-8" context=CoreMatchingContext { matchers: MatchingRuleCategory { name: HEADER, rules: {} }, config: NoUnexpectedKeys, matching_spec: V3, plugin_configuration: {} } single_value=true}:matcher_is_defined{self=CoreMatchingContext { matchers: MatchingRuleCategory { name: HEADER, rules: {} }, config: NoUnexpectedKeys, matching_spec: V3, plugin_configuration: {} } path=DocPath { path_tokens: [Root, Field("Content-Type")], expr: "$['Content-Type']" }}: pact_models::matchingrules: matcher_is_defined: for category header and path ["$", "Content-Type"] -> false
2023-11-14T14:01:08.933503Z TRACE tokio-runtime-worker match_header_value{key="Content-Type" index=0 expected="application/json" actual="application/json; charset=utf-8" context=CoreMatchingContext { matchers: MatchingRuleCategory { name: HEADER, rules: {} }, config: NoUnexpectedKeys, matching_spec: V3, plugin_configuration: {} } single_value=true}:matcher_is_defined{self=CoreMatchingContext { matchers: MatchingRuleCategory { name: HEADER, rules: {} }, config: NoUnexpectedKeys, matching_spec: V3, plugin_configuration: {} } path=DocPath { path_tokens: [Root, Field("Content-Type"), Index(0)], expr: "$['Content-Type'][0]" }}: pact_models::matchingrules: matcher_is_defined: for category header and path ["$", "Content-Type", "0"] -> false
2023-11-14T14:01:08.933516Z DEBUG tokio-runtime-worker pact_matching: --> Mismatches: [BodyMismatch { path: "$", expected: Some(b"\"\""), actual: Some(b"{\"AttemptNumber\":0,\"CallbackTypes\":[],\"CallbackUri\":\"http://127.0.0.1:64526\",\"Comments\":null,\"Entities\":null,\"JobId\":\"00000000-0000-0000-0000-000000000000\",\"Status\":null}"), mismatch: "Expected '' to be equal to '{\"CallbackUri\":\"http://127.0.0.1:64526\",\"JobId\":\"00000000-0000-0000-0000-000000000000\"}]
2023-11-14T14:01:08.933552Z DEBUG tokio-runtime-worker pact_mock_server::hyper_server: Request did not match: Request did not match - HTTP Request ( method: PUT, path: /do_thing, query: None, headers: Some({"content-length": ["170"], "Content-Type": ["application/json"]}), body: Present(2 bytes, application/json) )    0) $ -> Expected '' to be equal to '{"CallbackUri":"http://127.0.0.1:64526","JobId":"00000000-0000-0000-0000-000000000000"}'

Answer 1

There really should be a human-friendly output from that test into stdout, that log message you showed is really a debugging message. If that is all you get, that should be a bug report or feature request for Pact .NET to make it more like other client languages.

It's hard to say, but perhaps the body you're expected to send (requestBody ) doesn't match what you are sending:

{"JobId":"00000000-0000-0000-0000-000000000000","CallbackUri":"http://127.0.0.1:58615"}

UPDATE: it looks like you aren't actually sending the request body:

2023-11-14T14:01:08.933552Z DEBUG tokio-runtime-worker pact_mock_server::hyper_server: Request did not match: Request did not match - HTTP Request ( method: PUT, path: /do_thing, query: None, headers: Some({"content-length": ["170"], "Content-Type": ["application/json"]}), body: Present(2 bytes, application/json) )    0) $ -> Expected '' to be equal to '{"CallbackUri":"http://127.0.0.1:64526","JobId":"00000000-0000-0000-0000-000000000000"}'

I suspect it's because you aren't sending the request body correctly here:

        requestBody = JsonSerializer.Serialize(myObject);

        // Act //////////
        ResponseObject result = await client.SendRequestAsync(myObject); // <- should this be requestBody?

I suspect this is just an experiment, but in real life, I'd expect to see your actual API client in use here - the idea is to unit test your API client and not just check the Pact mock server works.