Pact tests fail with unexpected request which is the same as missing request

[nishalparbhu]

Apologies I accidently pressed enter before filling in the first time 😭

So I've been using Python PACT for a while and normally everything works fine. Recently however I've been getting this issue where sometimes I try and run a test and I can't decipher what is going wrong based on the pact-mock-service.log or the stack trace

For this I've been using pact-python==1.2.6

This is my code I've used to create the test in Python:

class TestGetUsersImpl:

    def test_no_valid_user_ids(self):
        expected_body = []

        (PACT
         .given('A list of user_ids which do not have any matching users in the database')
         .upon_receiving('A request to get a list of users')
         .with_request('get', f'{API_FOLDER}{USERS_ENDPOINT}?user_id_1=500&user_id_2=501')
         .will_respond_with(200, body=expected_body))

        with PACT:
            result = REQUEST_OBJECT.get_users([500, 501])

        assert result.status_code == 200
        assert result.json() == expected_body

REQUEST_OBJECT above is based on a class I've created to just send python requests (using requests package)

This is the stack trace output:

Testing started at 12:44 ...
31dd53f61050:python -u /opt/.pycharm_helpers/pycharm/_jb_pytest_runner.py --target test_authentication.py::TestGetUsersImpl.test_no_valid_user_ids
Launching pytest with arguments test_authentication.py::TestGetUsersImpl::test_no_valid_user_ids in /opt/project/test/pact_contract_testing

============================= test session starts ==============================
platform linux -- Python 3.8.5, pytest-6.0.2, py-1.9.0, pluggy-0.13.1 -- /usr/local/bin/python
cachedir: .pytest_cache
rootdir: /opt/project
plugins: cov-2.10.1
collecting ... collected 1 item

test_authentication.py::TestGetUsersImpl::test_no_valid_user_ids FAILED  [100%]
test/pact_contract_testing/test_authentication.py:405 (TestGetUsersImpl.test_no_valid_user_ids)
self = <test.pact_contract_testing.test_authentication.TestGetUsersImpl object at 0x7fc6c265c970>

    def test_no_valid_user_ids(self):
        expected_body = []

        (PACT
         .given('A list of user_ids which do not have any matching users in the database')
         .upon_receiving('A request to get a list of users')
         .with_request('get', f'{API_FOLDER}{USERS_ENDPOINT}?user_id_1=500&user_id_2=501')
         .will_respond_with(200, body=expected_body))

        with PACT:
>           result = REQUEST_OBJECT.get_users([500, 501])

test_authentication.py:416: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
/usr/local/lib/python3.8/site-packages/pact/pact.py:394: in __exit__
    self.verify()
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <pact.pact.Pact object at 0x7fc6c2746eb0>

    def verify(self):
        """
        Have the mock service verify all interactions occurred.

        Calls the mock service to verify that all interactions occurred as
        expected, and has it write out the contracts to disk.

        :raises AssertionError: When not all interactions are found.
        """
        self._interactions = []
        resp = requests.get(
            self.uri + '/interactions/verification',
            headers=self.HEADERS, verify=False)
>       assert resp.status_code == 200, resp.text
E       AssertionError: Actual interactions do not match expected interactions for mock MockService.
E       
E       Missing requests:
E           GET /api/authentication/users?user_id_1=500&user_id_2=501
E       
E       Unexpected requests:
E           GET /api/authentication/users?user_id_1=500&user_id_2=501
E       
E       See pact-mock-service.log for details.

/usr/local/lib/python3.8/site-packages/pact/pact.py:293: AssertionError

Assertion failed

Assertion failed

Assertion failed

Assertion failed

Assertion failed

Assertion failed

This is the pact-mock-service.log output which is what is confusing me because it seems I am making the right request but it still fails:

I, [2020-09-18T11:44:19.638582 #10]  INFO -- : Cleared interactions
I, [2020-09-18T11:44:19.646298 #10]  INFO -- : Registered expected interaction GET /api/authentication/users?user_id_1=500&user_id_2=501
D, [2020-09-18T11:44:19.647450 #10] DEBUG -- : {
  "description": "A request to get a list of users",
  "providerState": "A list of user_ids which do not have any matching users in the database",
  "request": {
    "method": "get",
    "path": "/api/authentication/users?user_id_1=500&user_id_2=501"
  },
  "response": {
    "status": 200,
    "headers": {
    },
    "body": [

    ]
  },
  "metadata": null
}
I, [2020-09-18T11:44:19.655855 #10]  INFO -- : Received request GET /api/authentication/users?user_id_1=500&user_id_2=501
D, [2020-09-18T11:44:19.656853 #10] DEBUG -- : {
  "path": "/api/authentication/users",
  "query": "user_id_1=500&user_id_2=501",
  "method": "get",
  "headers": {
    "Host": "localhost:1234",
    "User-Agent": "python-requests/2.24.0",
    "Accept-Encoding": "gzip, deflate",
    "Accept": "*/*",
    "Connection": "keep-alive",
    "Version": "HTTP/1.1"
  }
}
E, [2020-09-18T11:44:19.657851 #10] ERROR -- : No matching interaction found for GET /api/authentication/users?user_id_1=500&user_id_2=501
E, [2020-09-18T11:44:19.658744 #10] ERROR -- : Interaction diffs for that route:
E, [2020-09-18T11:44:19.659454 #10] ERROR -- : 
W, [2020-09-18T11:44:19.666233 #10]  WARN -- : Verifying - actual interactions do not match expected interactions. 
Missing requests:
    GET /api/authentication/users?user_id_1=500&user_id_2=501

Unexpected requests:
    GET /api/authentication/users?user_id_1=500&user_id_2=501

W, [2020-09-18T11:44:19.666971 #10]  WARN -- : Missing requests:
    GET /api/authentication/users?user_id_1=500&user_id_2=501

Unexpected requests:
    GET /api/authentication/users?user_id_1=500&user_id_2=501

I'm happy to add further to this thread with anything else that is needed 😄

[elliottmurray]

That's a little strange. Is it always failing for this test and it's not obvious why or it is intermittently failing (and not obvious why!)? I'm suspecting some space or encoding issue when passing to the ruby bit.

[nishalparbhu]

I've run this test in isolation with Pytest. I have a whole suite of tests (around 50 PACT tests) which all pass but I created this test yesterday and every time (5-10 times) I've run it, it fails. In all occasions the pact-mock-service.log appears to be the same from what I've seen.

[bethesque]

This "missing request x"/"unexpected request x" happens when the request is fired off before the expectation is put into the mock service.

1. send request x to mock service (register the "unexpected request")
2. set up expectation
3. end test
4. verify requests (calculate that the expected request from step 2 was never received).

[elliottmurray]

If you hit me up on Slack I'll try and help you solve it next week.

[nishalparbhu]

This "missing request x"/"unexpected request x" happens when the request is fired off before the expectation is put into the mock service.

1. send request x to mock service (register the "unexpected request")
2. set up expectation
3. end test
4. verify requests (calculate that the expected request from step 2 was never received).

I understand what you're saying, I'm just unaware how I would need to change the code so that the expectation is set up before the request is fired off (I have a similar structure for most of my tests and I've not had this issue on the others). How do I restructure the test?

[nishalparbhu]

If you hit me up on Slack I'll try and help you solve it next week.

This would be great. Apologies I'm still a bit new to Slack, how do I add/message you on Slack?

[mikelingtao]

Hi @nishalparbhu, I am facing exact same issue, I was wondering if your issue was resolved. If it was, do you mind posting your solution? Thanks

[nishalparbhu]

Hi there, apologies I have not yet, I think if you join the slack channel they will help but for my particular case I just had to exclude those tests for the time being (it only occurred for a small set of tests for me at this point) but I think if you request to join the slack channel and post on there, they will help you 👍

[mikelingtao]

Hi there, apologies I have not yet, I think if you join the slack channel they will help but for my particular case I just had to exclude those tests for the time being (it only occurred for a small set of tests for me at this point) but I think if you request to join the slack channel and post on there, they will help you 👍

Hi @nishalparbhu, thanks for the reply. While my issue was resolved. I made the test case as async and things started working fine. 👍 !