`Kanon Profile:` aiohttp request timeouts.

[jamshale]

When creating scenario tests for the kanon profile I ran into an intermittent issue. The test is disabled here https://github.com/openwallet-foundation/acapy/blob/main/scenarios/examples/kanon_issuance_and_presentation/example.py. What it does is create a kanon issuer, a connection with an askar holder, and issue, verify presentation and revoke a credential. Usually it works locally but sometimes it gets aiohttp timeouts when performing an http request. The problem happens more often when it's run with github actions or a low resource docker container.

The scenario tests quickly create storage records and http requests. Much different then manually creating records through the swagger api. I think there's some type of race condition or blocking issue with the storage/wallet transactions.

This same test passes consistently with askar storage.

Steps to reproduce:

• Build a local docker image from root directory. docker build -t acapy-test -f ./docker/Dockerfile.run .
• Uncomment the test in scenarios/examples/kanon_issuance_and_presentation/example.py
• Run the test. cd scenarios/examples/kanon_issuance_and_presentation and docker compose up --build
• The test should hang and timeout if you run it enough times. However, sometimes it would pass many times in a row for me.

Here is a fail in github actions https://github.com/openwallet-foundation/acapy/actions/runs/19216759154/job/54927364677.

Note the hang and then aiohttp timeout failure.

Traceback (most recent call last):
  File "/usr/src/app/.venv/lib/python3.10/site-packages/aiohttp/client_reqrep.py", line 532, in start
    message, payload = await protocol.read()  # type: ignore[union-attr]
  File "/usr/src/app/.venv/lib/python3.10/site-packages/aiohttp/streams.py", line 672, in read
    await self._waiter
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/runpy.py", line 196, in _run_module_as_main
    return _run_code(code, main_globals, None,
  File "/usr/local/lib/python3.10/runpy.py", line 86, in _run_code
    exec(code, run_globals)
  File "/usr/src/app/example.py", line 171, in <module>
    asyncio.run(main())
  File "/usr/local/lib/python3.10/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "/usr/local/lib/python3.10/asyncio/base_events.py", line 649, in run_until_complete
    return future.result()
  File "/usr/src/app/example.py", line 84, in main
    await kanon_postgres.post(
  File "/usr/src/app/.venv/lib/python3.10/site-packages/acapy_controller/controller.py", line 491, in post
    return await self.request(
  File "/usr/src/app/.venv/lib/python3.10/site-packages/acapy_controller/controller.py", line 351, in request
    async with session.request(
  File "/usr/src/app/.venv/lib/python3.10/site-packages/aiohttp/client.py", line 1488, in __aenter__
    self._resp: _RetType = await self._coro
  File "/usr/src/app/.venv/lib/python3.10/site-packages/aiohttp/client.py", line 770, in _request
    resp = await handler(req)
  File "/usr/src/app/.venv/lib/python3.10/site-packages/aiohttp/client.py", line 748, in _connect_and_send_request
    await resp.start(conn)
  File "/usr/src/app/.venv/lib/python3.10/site-packages/aiohttp/client_reqrep.py", line 527, in start
    with self._timer:
  File "/usr/src/app/.venv/lib/python3.10/site-packages/aiohttp/helpers.py", line 685, in __exit__
    raise asyncio.TimeoutError from exc_val
asyncio.exceptions.TimeoutError

I'll see if I can get it to fail with debug logs enabled and get any further information.

I believe this problem could reoccur in production if a controller was quickly creating records and using the admin api.

[jamshale]

@vinaysingh8866 FYI. When trying to create integration tests for the kanon profile I ran into this issue.

[vinaysingh8866]

@jamshale I have made a PR to fix this, i have uncommented the code in examples to test this. Removed the try catch from handlers, finally block was also committing the transactions.
#3950

[swcurran]

Awesome work @vinaysingh8866 -- thank you. I'll update the 1.4.0 change log tomorrow to add the PR and remove the warning.

Good stuff!!

[jamshale]

@vinaysingh8866 Unfortunately after updating main with this fix the scenario tests started failing again, even though they passed multiple times from the PR. This was the intermittent behavior I was seeing before.

It really seemed like you were on to something with the transaction management but the problem does still persist :/ Not sure if you have anymore ideas?

[vinaysingh8866]

@jamshale the timeout should be resolved now there was another call that could be causing issue. If it doesn't we need to recreate it in a vm. I'm not able to recreate it on my device now.
#3951

[jamshale]

Looks like this is still an intermittent issue. I'm going to need to disable the test again...

The test is definitely passing more often then it did before the latest PR got merged so it does seem like the changes are an improvement. Maybe there is still a related problem somewhere else with the transaction management?

[vinaysingh8866]

@jamshale the only remaining deadlocks could be coming from the sessions code will check it out and see if something can be made better. We need someway to recreate this and confirm where the deadlock is happening in single threaded environments.

[jamshale]

I think I may be able to change the scenario docker compose values to limit the agent to a single thread env. I'll try and have a look and see if I can get it to fail more consistently.

[vinaysingh8866]

@jamshale i have opened another PR for fix, can you try on this if you're able to recreate the error
#3958