In VS Code it simply refuses to show most of the logs because the lines are so long:
The info contained in each line is very verbose and is not formatted in a human-readable way. It would be much better if most of that detail was output at DEBUG or TRACE level and the INFO level messages just contained a few important details.
This is the full output from the same example running under FFI 0.3.11 for example:
Verifier Logs
-------------
2023-01-05T17:44:06.123002Z INFO ThreadId(17) pact_verifier: Running provider verification for 'a request to check the api status'
2023-01-05T17:44:06.123199Z INFO ThreadId(17) pact_verifier::provider_client: Sending request to provider at http://localhost:9222/
2023-01-05T17:44:06.123208Z INFO ThreadId(17) pact_verifier::provider_client: Sending request HTTP Request ( method: GET, path: /stats/status, query: None, headers: Some({"Accept": ["application/json"]}), body: Missing )
2023-01-05T17:44:06.209261Z INFO ThreadId(17) pact_verifier::provider_client: Received response: HTTP Response ( status: 200, headers: Some({"date": ["Thu", "05 Jan 2023 17:44:06 GMT"], "transfer-encoding": ["chunked"], "server": ["Kestrel"], "content-type": ["application/json; charset=utf-8"]}), body: Present(127 bytes, application/json;charset=utf-8) )
2023-01-05T17:44:06.209333Z INFO ThreadId(17) pact_matching: comparing to expected response: HTTP Response ( status: 200, headers: Some({"Content-Type": ["application/json; charset=utf-8"]}), body: Present(127 bytes) )
2023-01-05T17:44:06.213190Z INFO ThreadId(17) pact_verifier: Running provider verification for 'a request to check the api uptime'
2023-01-05T17:44:06.213320Z INFO ThreadId(17) pact_verifier::provider_client: Sending request to provider at http://localhost:9222/
2023-01-05T17:44:06.213325Z INFO ThreadId(17) pact_verifier::provider_client: Sending request HTTP Request ( method: GET, path: /stats/uptime, query: None, headers: Some({"Accept": ["application/json"]}), body: Missing )
2023-01-05T17:44:06.218584Z INFO ThreadId(17) pact_verifier::provider_client: Received response: HTTP Response ( status: 200, headers: Some({"date": ["Thu", "05 Jan 2023 17:44:06 GMT"], "transfer-encoding": ["chunked"], "server": ["Kestrel"], "content-type": ["application/json; charset=utf-8"]}), body: Present(77 bytes, application/json;charset=utf-8) )
2023-01-05T17:44:06.218613Z INFO ThreadId(17) pact_matching: comparing to expected response: HTTP Response ( status: 200, headers: Some({"Content-Type": ["application/json; charset=utf-8"]}), body: Present(34 bytes) )
2023-01-05T17:44:06.221694Z INFO ThreadId(17) pact_verifier: Running provider verification for 'a request to create a new event'
2023-01-05T17:44:06.221730Z INFO ThreadId(17) pact_verifier::provider_client: Sending request to provider at http://localhost:9222/
2023-01-05T17:44:06.221731Z INFO ThreadId(17) pact_verifier::provider_client: Sending request HTTP Request ( method: POST, path: /events, query: None, headers: Some({"Content-Type": ["application/json; charset=utf-8"], "Authorization": ["Bearer SomeValidAuthToken"]}), body: Present(118 bytes) )
2023-01-05T17:44:06.336834Z INFO ThreadId(17) pact_verifier::provider_client: Received response: HTTP Response ( status: 201, headers: Some({"content-length": ["0"], "date": ["Thu", "05 Jan 2023 17:44:06 GMT"], "server": ["Kestrel"]}), body: Empty )
2023-01-05T17:44:06.336854Z INFO ThreadId(17) pact_matching: comparing to expected response: HTTP Response ( status: 201, headers: None, body: Missing )
2023-01-05T17:44:06.339494Z INFO ThreadId(17) pact_verifier: Running provider verification for 'a request to retrieve all events'
2023-01-05T17:44:06.339532Z INFO ThreadId(17) pact_verifier::provider_client: Sending request to provider at http://localhost:9222/
2023-01-05T17:44:06.339534Z INFO ThreadId(17) pact_verifier::provider_client: Sending request HTTP Request ( method: GET, path: /events, query: None, headers: Some({"Accept": ["application/json"], "Authorization": ["Bearer SomeValidAuthToken"]}), body: Missing )
2023-01-05T17:44:06.351961Z INFO ThreadId(17) pact_verifier::provider_client: Received response: HTTP Response ( status: 200, headers: Some({"transfer-encoding": ["chunked"], "server": ["Kestrel"], "content-type": ["application/json; charset=utf-8"], "date": ["Thu", "05 Jan 2023 17:44:06 GMT"]}), body: Present(356 bytes, application/json;charset=utf-8) )
2023-01-05T17:44:06.351988Z INFO ThreadId(17) pact_matching: comparing to expected response: HTTP Response ( status: 200, headers: Some({"Content-Type": ["application/json; charset=utf-8"]}), body: Present(119 bytes) )
2023-01-05T17:44:06.355414Z INFO ThreadId(17) pact_verifier: Running setup provider state change handler 'there are events with ids '45D80D13-D5A2-48D7-8353-CBB4C0EAABF5', '83F9262F-28F1-4703-AB1A-8CFD9E8249C9' and '3E83A96B-2A0C-49B1-9959-26DF23F83AEB'' for 'a request to retrieve all events with no authorization'
2023-01-05T17:44:06.362411Z INFO ThreadId(17) pact_verifier: Running provider verification for 'a request to retrieve all events with no authorization'
2023-01-05T17:44:06.362456Z INFO ThreadId(17) pact_verifier::provider_client: Sending request to provider at http://localhost:9222/
2023-01-05T17:44:06.362458Z INFO ThreadId(17) pact_verifier::provider_client: Sending request HTTP Request ( method: GET, path: /events, query: None, headers: Some({"Accept": ["application/json"]}), body: Missing )
2023-01-05T17:44:06.366034Z INFO ThreadId(17) pact_verifier::provider_client: Received response: HTTP Response ( status: 401, headers: Some({"date": ["Thu", "05 Jan 2023 17:44:06 GMT"], "content-length": ["0"], "server": ["Kestrel"], "www-authenticate": ["Bearer"]}), body: Empty )
2023-01-05T17:44:06.366051Z INFO ThreadId(17) pact_matching: comparing to expected response: HTTP Response ( status: 401, headers: None, body: Missing )
2023-01-05T17:44:06.368685Z INFO ThreadId(17) pact_verifier: Running setup provider state change handler 'there is an event with id '83f9262f-28f1-4703-ab1a-8cfd9e8249c9'' for 'a request to retrieve event with id '83f9262f-28f1-4703-ab1a-8cfd9e8249c9''
2023-01-05T17:44:06.372134Z INFO ThreadId(17) pact_verifier: Running provider verification for 'a request to retrieve event with id '83f9262f-28f1-4703-ab1a-8cfd9e8249c9''
2023-01-05T17:44:06.372189Z INFO ThreadId(17) pact_verifier::provider_client: Sending request to provider at http://localhost:9222/
2023-01-05T17:44:06.372191Z INFO ThreadId(17) pact_verifier::provider_client: Sending request HTTP Request ( method: GET, path: /events/83f9262f-28f1-4703-ab1a-8cfd9e8249c9, query: None, headers: Some({"accept": ["application/json"], "authorization": ["Bearer SomeValidAuthToken"]}), body: Missing )
2023-01-05T17:44:06.374012Z INFO ThreadId(17) pact_verifier::provider_client: Received response: HTTP Response ( status: 200, headers: Some({"server": ["Kestrel"], "date": ["Thu", "05 Jan 2023 17:44:06 GMT"], "transfer-encoding": ["chunked"], "content-type": ["application/json; charset=utf-8"]}), body: Present(118 bytes, application/json;charset=utf-8) )
2023-01-05T17:44:06.374032Z INFO ThreadId(17) pact_matching: comparing to expected response: HTTP Response ( status: 200, headers: Some({"content-type": ["application/json; charset=utf-8"]}), body: Present(119 bytes) )
2023-01-05T17:44:06.376912Z INFO ThreadId(17) pact_verifier: Running setup provider state change handler 'there is one event with type 'DetailsView'' for 'a request to retrieve events with type 'DetailsView''
2023-01-05T17:44:06.380191Z INFO ThreadId(17) pact_verifier: Running provider verification for 'a request to retrieve events with type 'DetailsView''
2023-01-05T17:44:06.380254Z INFO ThreadId(17) pact_verifier::provider_client: Sending request to provider at http://localhost:9222/
2023-01-05T17:44:06.380256Z INFO ThreadId(17) pact_verifier::provider_client: Sending request HTTP Request ( method: GET, path: /events, query: Some({"type": ["DetailsView"]}), headers: Some({"Authorization": ["Bearer SomeValidAuthToken"], "Accept": ["application/json"]}), body: Missing )
2023-01-05T17:44:06.384950Z INFO ThreadId(17) pact_verifier::provider_client: Received response: HTTP Response ( status: 200, headers: Some({"content-type": ["application/json; charset=utf-8"], "date": ["Thu", "05 Jan 2023 17:44:06 GMT"], "transfer-encoding": ["chunked"], "server": ["Kestrel"]}), body: Present(120 bytes, application/json;charset=utf-8) )
2023-01-05T17:44:06.384974Z INFO ThreadId(17) pact_matching: comparing to expected response: HTTP Response ( status: 200, headers: Some({"Content-Type": ["application/json; charset=utf-8"]}), body: Present(120 bytes) )
2023-01-05T17:44:06.385559Z WARN ThreadId(17) pact_matching::metrics:
Please note:
We are tracking events anonymously to gather important usage statistics like Pact version and operating system. To disable tracking, set the 'PACT_DO_NOT_TRACK' environment variable to 'true'.
That's much more readable and helps users track down any matching issues.
On FFI v0.3.19 running a very simple example in PactNet (here: https://github.com/pact-foundation/pact-net/tree/master/samples/Messaging/Provider.Tests), the verifier produces a wall of text for logging at INFO level.
There are only 38 lines, but each line is 10-12KB long. For example, here is one line:
In VS Code it simply refuses to show most of the logs because the lines are so long:
The info contained in each line is very verbose and is not formatted in a human-readable way. It would be much better if most of that detail was output at DEBUG or TRACE level and the INFO level messages just contained a few important details.
This is the full output from the same example running under FFI 0.3.11 for example:
That's much more readable and helps users track down any matching issues.