Fix for handler for postgres

[vinaysingh8866]

No description provided.

[jamshale]

@vinaysingh8866 The logging from the scenario tests has been merged. Could you update this branch please? Hopefully we can see what the current error is now.

[jamshale]

2025-12-25T09:11:09.2006707Z kanon-postgres-1  | 2025-12-25 09:11:08,567 acapy_agent.commands.start ERROR Unexpected exception during execution
2025-12-25T09:11:09.2007736Z kanon-postgres-1  | Traceback (most recent call last):
2025-12-25T09:11:09.2008513Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/wallet/kanon_wallet.py", line 674, in _get_public_did_impl
2025-12-25T09:11:09.2009309Z kanon-postgres-1  |     public_item = await storage.get_record(
2025-12-25T09:11:09.2009838Z kanon-postgres-1  |                   ^^^^^^^^^^^^^^^^^^^^^^^^^
2025-12-25T09:11:09.2010450Z kanon-postgres-1  |         CATEGORY_CONFIG, RECORD_NAME_PUBLIC_DID, session=session
2025-12-25T09:11:09.2011068Z kanon-postgres-1  |         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-12-25T09:11:09.2011551Z kanon-postgres-1  |     )
2025-12-25T09:11:09.2011869Z kanon-postgres-1  |     ^
2025-12-25T09:11:09.2012452Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/storage/kanon_storage.py", line 83, in get_record
2025-12-25T09:11:09.2013324Z kanon-postgres-1  |     return await self._get_record(record_type, record_id, for_update, session)
2025-12-25T09:11:09.2014028Z kanon-postgres-1  |            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-12-25T09:11:09.2014777Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/storage/kanon_storage.py", line 95, in _get_record
2025-12-25T09:11:09.2015677Z kanon-postgres-1  |     raise StorageNotFoundError(f"Record not found: {record_type}/{record_id}")
2025-12-25T09:11:09.2016671Z kanon-postgres-1  | acapy_agent.storage.error.StorageNotFoundError: Record not found: config/default_public_did
2025-12-25T09:11:09.2018211Z kanon-postgres-1  | 
2025-12-25T09:11:09.2018752Z kanon-postgres-1  | During handling of the above exception, another exception occurred:
2025-12-25T09:11:09.2019324Z kanon-postgres-1  | 
2025-12-25T09:11:09.2019687Z kanon-postgres-1  | Traceback (most recent call last):
2025-12-25T09:11:09.2020582Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/database_manager/databases/postgresql_normalized/session.py", line 354, in insert
2025-12-25T09:11:09.2021445Z kanon-postgres-1  |     await handler.insert(
2025-12-25T09:11:09.2022063Z kanon-postgres-1  |         cursor, self.profile_id, category, name, value, tags or {}, expiry_ms
2025-12-25T09:11:09.2022663Z kanon-postgres-1  |     )
2025-12-25T09:11:09.2023666Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/database_manager/databases/postgresql_normalized/handlers/generic_handler.py", line 159, in insert
2025-12-25T09:11:09.2024626Z kanon-postgres-1  |     raise DatabaseError(
2025-12-25T09:11:09.2025133Z kanon-postgres-1  |     ...<2 lines>...
2025-12-25T09:11:09.2025508Z kanon-postgres-1  |     )
2025-12-25T09:11:09.2026353Z kanon-postgres-1  | acapy_agent.database_manager.databases.errors.DatabaseError: Duplicate entry for category 'config' and name 'default_public_did'
2025-12-25T09:11:09.2027423Z kanon-postgres-1  | 
2025-12-25T09:11:09.2027912Z kanon-postgres-1  | During handling of the above exception, another exception occurred:
2025-12-25T09:11:09.2028484Z kanon-postgres-1  | 
2025-12-25T09:11:09.2028854Z kanon-postgres-1  | Traceback (most recent call last):
2025-12-25T09:11:09.2029557Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/database_manager/dbstore.py", line 691, in insert
2025-12-25T09:11:09.2030758Z kanon-postgres-1  |     await self._db_session.insert(category, name, value, tags, expiry_ms)
2025-12-25T09:11:09.2032114Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/database_manager/databases/postgresql_normalized/session.py", line 375, in insert
2025-12-25T09:11:09.2033063Z kanon-postgres-1  |     raise DatabaseError(
2025-12-25T09:11:09.2033460Z kanon-postgres-1  |     ...<3 lines>...
2025-12-25T09:11:09.2033819Z kanon-postgres-1  |     )
2025-12-25T09:11:09.2034633Z kanon-postgres-1  | acapy_agent.database_manager.databases.errors.DatabaseError: Failed to insert item 'default_public_did' in category 'config'
2025-12-25T09:11:09.2035501Z kanon-postgres-1  | 
2025-12-25T09:11:09.2036010Z kanon-postgres-1  | During handling of the above exception, another exception occurred:
2025-12-25T09:11:09.2036700Z kanon-postgres-1  | 
2025-12-25T09:11:09.2037267Z kanon-postgres-1  | Traceback (most recent call last):
2025-12-25T09:11:09.2037954Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/storage/kanon_storage.py", line 55, in _add_record
2025-12-25T09:11:09.2038695Z kanon-postgres-1  |     await self._call_handle_or_session(
2025-12-25T09:11:09.2039369Z kanon-postgres-1  |         session, "insert", record.type, record.id, record.value, record.tags
2025-12-25T09:11:09.2039937Z kanon-postgres-1  |     )
2025-12-25T09:11:09.2040594Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/storage/kanon_storage.py", line 406, in _call_handle_or_session
2025-12-25T09:11:09.2041372Z kanon-postgres-1  |     return await smethod(*args, **kwargs)
2025-12-25T09:11:09.2041882Z kanon-postgres-1  |            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-12-25T09:11:09.2042574Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/database_manager/dbstore.py", line 696, in insert
2025-12-25T09:11:09.2043324Z kanon-postgres-1  |     raise self._db_session.translate_error(e)
2025-12-25T09:11:09.2043985Z kanon-postgres-1  | acapy_agent.database_manager.error.DBStoreError: Query error
2025-12-25T09:11:09.2044550Z kanon-postgres-1  | 
2025-12-25T09:11:09.2045054Z kanon-postgres-1  | The above exception was the direct cause of the following exception:
2025-12-25T09:11:09.2045622Z kanon-postgres-1  | 
2025-12-25T09:11:09.2046010Z kanon-postgres-1  | Traceback (most recent call last):
2025-12-25T09:11:09.2046654Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/commands/start.py", line 129, in execute
2025-12-25T09:11:09.2047819Z kanon-postgres-1  |     asyncio.run(run_app(argv))
2025-12-25T09:11:09.2048399Z kanon-postgres-1  |     ~~~~~~~~~~~^^^^^^^^^^^^^^^
2025-12-25T09:11:09.2049480Z kanon-postgres-1  |   File "/root/.cache/pypoetry/virtualenvs/acapy-agent-VA82Wl8V-py3.13/lib/python3.13/site-packages/nest_asyncio.py", line 30, in run
2025-12-25T09:11:09.2050479Z kanon-postgres-1  |     return loop.run_until_complete(task)
2025-12-25T09:11:09.2050981Z kanon-postgres-1  |            ~~~~~~~~~~~~~~~~~~~~~~~^^^^^^
2025-12-25T09:11:09.2051997Z kanon-postgres-1  |   File "/root/.cache/pypoetry/virtualenvs/acapy-agent-VA82Wl8V-py3.13/lib/python3.13/site-packages/nest_asyncio.py", line 98, in run_until_complete
2025-12-25T09:11:09.2052983Z kanon-postgres-1  |     return f.result()
2025-12-25T09:11:09.2053499Z kanon-postgres-1  |            ~~~~~~~~^^
2025-12-25T09:11:09.2054339Z kanon-postgres-1  |   File "/usr/local/lib/python3.13/asyncio/futures.py", line 199, in result
2025-12-25T09:11:09.2055216Z kanon-postgres-1  |     raise self._exception.with_traceback(self._exception_tb)
2025-12-25T09:11:09.2056110Z kanon-postgres-1  |   File "/usr/local/lib/python3.13/asyncio/tasks.py", line 304, in __step_run_and_handle_result
2025-12-25T09:11:09.2056881Z kanon-postgres-1  |     result = coro.send(None)
2025-12-25T09:11:09.2057736Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/commands/start.py", line 120, in run_app
2025-12-25T09:11:09.2058433Z kanon-postgres-1  |     await start_app(conductor)
2025-12-25T09:11:09.2059139Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/commands/start.py", line 31, in start_app
2025-12-25T09:11:09.2059819Z kanon-postgres-1  |     await conductor.setup()
2025-12-25T09:11:09.2060526Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/core/conductor.py", line 219, in setup
2025-12-25T09:11:09.2061419Z kanon-postgres-1  |     ledger_configured = await ledger_config(
2025-12-25T09:11:09.2062043Z kanon-postgres-1  |                         ^^^^^^^^^^^^^^^^^^^^
2025-12-25T09:11:09.2062808Z kanon-postgres-1  |         self.root_profile, self.setup_public_did and self.setup_public_did.did
2025-12-25T09:11:09.2063574Z kanon-postgres-1  |         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-12-25T09:11:09.2064086Z kanon-postgres-1  |     )
2025-12-25T09:11:09.2064472Z kanon-postgres-1  |     ^
2025-12-25T09:11:09.2065086Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/config/ledger.py", line 154, in ledger_config
2025-12-25T09:11:09.2066124Z kanon-postgres-1  |     taa_info = await ledger.get_txn_author_agreement()
2025-12-25T09:11:09.2066797Z kanon-postgres-1  |                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-12-25T09:11:09.2067774Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/ledger/indy_vdr.py", line 947, in get_txn_author_agreement
2025-12-25T09:11:09.2068764Z kanon-postgres-1  |     self.pool.taa_cache = await self.fetch_txn_author_agreement()
2025-12-25T09:11:09.2069486Z kanon-postgres-1  |                           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-12-25T09:11:09.2070373Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/ledger/indy_vdr.py", line 952, in fetch_txn_author_agreement
2025-12-25T09:11:09.2071306Z kanon-postgres-1  |     public_info = await self.get_wallet_public_did()
2025-12-25T09:11:09.2071983Z kanon-postgres-1  |                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-12-25T09:11:09.2072792Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/ledger/indy_vdr.py", line 1314, in get_wallet_public_did
2025-12-25T09:11:09.2073682Z kanon-postgres-1  |     return await wallet.get_public_did()
2025-12-25T09:11:09.2074230Z kanon-postgres-1  |            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-12-25T09:11:09.2075026Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/wallet/kanon_wallet.py", line 664, in get_public_did
2025-12-25T09:11:09.2075913Z kanon-postgres-1  |     return await self._get_public_did_impl(session)
2025-12-25T09:11:09.2076549Z kanon-postgres-1  |            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2025-12-25T09:11:09.2077579Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/wallet/kanon_wallet.py", line 689, in _get_public_did_impl
2025-12-25T09:11:09.2078446Z kanon-postgres-1  |     await storage.add_record(
2025-12-25T09:11:09.2078859Z kanon-postgres-1  |     ...<6 lines>...
2025-12-25T09:11:09.2079212Z kanon-postgres-1  |     )
2025-12-25T09:11:09.2079815Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/storage/kanon_storage.py", line 51, in add_record
2025-12-25T09:11:09.2080630Z kanon-postgres-1  |     await self._add_record(record, session)
2025-12-25T09:11:09.2081355Z kanon-postgres-1  |   File "/usr/src/app/acapy_agent/storage/kanon_storage.py", line 63, in _add_record
2025-12-25T09:11:09.2082505Z kanon-postgres-1  |     raise StorageError("Error when adding storage record") from err
2025-12-25T09:11:09.2083524Z kanon-postgres-1  | acapy_agent.storage.error.StorageError: Error when adding storage record
2025-12-25T09:11:09.2084589Z kanon-postgres-1  | 2025-12-25 09:11:08,575 aries_askar.native.aries_askar.ffi.log DEBUG 	src/ffi/log.rs:130 | Removing custom logger
2025-12-25T09:11:09.2085875Z kanon-postgres-1  | 2025-12-25 09:11:08,575 aries_askar.native.aries_askar.ffi.store DEBUG 	src/ffi/store.rs:1213 | Session not found for closing: SessionHandle(2)
2025-12-25T09:11:09.2089565Z kanon-postgres-1  | KanonProfileManager Provision store with config: {'key': 'insecure', 'name': 'kanon-postgres-normalized', 'storage_config': '{"url":"wallet-db:5432","max_connections":100,"min_idle_count":5,"max_idle":10.0,"max_lifetime":7200.0}', 'storage_creds': '{"account":"myuser","password":"mypass"}', 'storage_type': 'postgres_storage', 'dbstore_storage_type': 'postgres_storage', 'dbstore_storage_config': '{"url":"wallet-db:5432","connection_timeout":30.0,"max_connections":100,"min_idle_count":5,"max_idle":10.0,"max_lifetime":7200.0}', 'dbstore_storage_creds': '{"account":"myuser","password":"mypass"}', 'dbstore_schema_config': 'normalize', 'auto_recreate': True}

There's this error on start up occurring. I'm not exactly sure what to make of it?

[swcurran]

@jamshale -- I'm wondering if it would be worth making a separate GHA for the Kanon test(s) so that we can separate a fail of that test from the rest of the integration tests. Much easier to see the error we're trying to address, and when to ignore a test failure.

[jamshale]

@jamshale -- I'm wondering if it would be worth making a separate GHA for the Kanon test(s) so that we can separate a fail of that test from the rest of the integration tests. Much easier to see the error we're trying to address, and when to ignore a test failure.

That's probably a good idea. I can do that. I did open a PR to reduce the log level on the other tests which will help a bit.

[jamshale]

I opened another PR to only log the failing tests. Same error there but easier to find. https://github.com/openwallet-foundation/acapy/actions/runs/20606367604/job/59182868970?pr=4005

[vinaysingh8866]

@jamshale updated the code with the fixes can you try running the tests multiple times and see if any issue happens again.

[sonarqubecloud]

Quality Gate failed

Failed conditions
9.5% Coverage on New Code (required ≥ 80%)
13.8% Duplication on New Code (required ≤ 3%)

See analysis details on SonarQube Cloud

[jamshale]

I'm not sure if this has completely solved the problem or not but I have run the scenario tests 8 times now without a fail. I'm going to merge this and we can monitor it. If it does fail at some point we should be able to determine the cause 🤞