Upgrade the Mediator's ACA-Py instance to Release 0.8.1 #25

swcurran · 2023-03-21T21:39:13Z

Please do a normal upgrade (through Dev, Test and then Prod) of the ACA-Py released used in the BC Wallet mediator to release 0.8.0. This will pick up change PR #2147 - Fix: messages stuck in mediator.

~~Once done, please~~ During the upgrade, it is required to apply the upgrade outlined in the 0.8.0 Release notes to do with PR #2116. Suggest confirming with an ACA-Py dev that the upgrade can be applied later versus as the update is made. Here are the upgrade notes from the 0.8.0 Release Notes about this:

UPGRADE PR 2116 - UPGRADE: Fix multi-use invitation performance

The way that multiuse invitations in previous versions of ACA-Py caused performance to degrade over time. An update was made to add state into the tag names that eliminated the need to scan the tags when querying storage for the invitation.

If you are using multiuse invitations in your existing (pre-0.8.0 deployment of ACA-Py, you can run an upgrade to apply this change. To run upgrade from previous versions, use the following command using the 0.8.0 version of ACA-Py, adding you wallet settings:

aca-py upgrade <other wallet config settings> --from-version=v0.7.5 --upgrade-config-path ./upgrade.yml

The text was updated successfully, but these errors were encountered:

ianco · 2023-03-21T21:49:01Z

The upgrade should be run pretty soon after the upgrade. It just re-saves the connection records (in order to add a new tag) - I'm not sure what is the impact if the new tags aren't available, possibly it won't be able to find the connection it's looking for,

swcurran · 2023-03-21T22:18:23Z

I'm not sure it matters, but better to be safe than sorry. I think this search only happens in the midst of the invitation process, and the fix is to return only the invitation uses that are at that state.

WadeBarnes · 2023-03-23T15:33:44Z

I'm getting an error running the upgrade:

FileNotFoundError: [Errno 2] No such file or directory: './upgrade.yml'

I don't see that file or the default_version_upgrade_config.yml file on the container. Does that file need to be added manually or should it be included in the aca-py install?

ianco · 2023-03-23T15:38:40Z

The default path is setup here: https://github.com/hyperledger/aries-cloudagent-python/blob/main/aries_cloudagent/commands/upgrade.py#L25

You should be able to run the upgrade without providing a --upgrade-config-path

WadeBarnes · 2023-03-23T15:45:47Z

default_version_upgrade_config.yml does not exit either.

WadeBarnes · 2023-03-23T15:46:41Z

1004460000@aries-mediator-agent-37-nsnw9-debug:~/.local/lib/python3.9/site-packages/aries_cloudagent/commands$ ls -1
__init__.py
__pycache__
help.py
provision.py
start.py
tests
upgrade.py

ianco · 2023-03-23T15:50:28Z

Hmmm that's an issue with the docker build I think ...

ianco · 2023-03-23T15:51:09Z

Do you have a way to manually copy the file to the mediator image?

WadeBarnes · 2023-03-23T15:53:58Z

The issue looks more like and issue with the aca-py python package. The file is missing from the bcgovimages/aries-cloudagent:py36-1.16-1_0.8.0 image too. That one does a pip install of aca-py, while the one we're using from the aca-py repo builds the wheel and then installs it.

WadeBarnes · 2023-03-23T15:54:27Z

Do you have a way to manually copy the file to the mediator image?

Yeah, just a pain.

WadeBarnes · 2023-03-23T15:58:18Z

Confirmed, the file is not included in either the source or wheel distribution on PyPi:

ianco · 2023-03-23T15:58:36Z

I'll create an issue in the aca-py repo to make sure this file getting included in the release

WadeBarnes · 2023-03-23T15:59:20Z

Thanks

ianco · 2023-03-23T16:00:47Z

openwallet-foundation/acapy#2178

WadeBarnes · 2023-03-23T16:20:48Z

Running into issues with the upgrade. Seems to be connectivity issues with the wallet database. Investigating. Edit: Issue was security policy related, the required labels were not applied to the debug pod I'm using.

1004460000@aries-mediator-agent-37-nsnw9-debug:/acapy-mediator$ $(echo aca-py upgrade \
  --wallet-type indy \
  --wallet-storage-type postgres_storage \
  --wallet-storage-config "$(eval echo \"${WALLET_STORAGE_CONFIGURATION}\")" \
  --wallet-storage-creds "$(eval echo \"${WALLET_STORAGE_CREDENTIALS}\")" \
  --from-version=v0.7.5 \
  --upgrade-config-path /tmp/default_version_upgrade_config.yml \
);
2023-03-23 16:16:03,870 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.actionmenu
2023-03-23 16:16:03,871 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.basicmessage
2023-03-23 16:16:03,871 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.connections
2023-03-23 16:16:03,962 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.coordinate_mediation
2023-03-23 16:16:03,963 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.didexchange
2023-03-23 16:16:03,963 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.discovery
2023-03-23 16:16:03,964 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.endorse_transaction
2023-03-23 16:16:03,965 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.introduction
2023-03-23 16:16:03,965 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.issue_credential
2023-03-23 16:16:04,170 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.notification
2023-03-23 16:16:04,171 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.out_of_band
2023-03-23 16:16:04,171 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.present_proof
2023-03-23 16:16:04,663 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.problem_report
2023-03-23 16:16:04,664 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.revocation_notification
2023-03-23 16:16:04,664 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.routing
2023-03-23 16:16:04,665 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.trustping
2023-03-23 16:16:04,666 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.holder
2023-03-23 16:16:05,963 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.ledger
2023-03-23 16:16:06,163 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.messaging.credential_definitions
2023-03-23 16:16:06,263 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.messaging.schemas
2023-03-23 16:16:06,268 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.messaging.jsonld
2023-03-23 16:16:06,271 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.revocation
2023-03-23 16:16:06,371 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.resolver
2023-03-23 16:16:06,462 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.wallet
2023-03-23 16:16:07,065 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::core::startup?$'), processor <function on_startup_event at 0x7f9734cda550>
2023-03-23 16:16:07,065 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::core::shutdown?$'), processor <function on_shutdown_event at 0x7f9734cda5e0>
2023-03-23 16:16:07,669 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::REVOCATION::published.*'), processor <function on_revocation_published at 0x7f9734b31a60>
2023-03-23 16:16:07,670 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::REVOCATION::clear-pending.*'), processor <function on_pending_cleared at 0x7f9734b31f70>
2023-03-23 16:16:07,763 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::REVOCATION::published.*'), processor <function on_revocation_published at 0x7f9734adc280>
2023-03-23 16:16:07,763 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::REVOCATION::clear-pending.*'), processor <function on_pending_cleared at 0x7f9734adc9d0>
2023-03-23 16:16:07,766 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::CRED_DEF::(.*)?$'), processor <function on_cred_def_event at 0x7f9734f81b80>
2023-03-23 16:16:07,766 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::SCHEMA::(.*)?$'), processor <function on_schema_event at 0x7f9734f1a550>
2023-03-23 16:16:07,766 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::REVOCATION::REGISTRY_INIT.*'), processor <function on_revocation_registry_init_event at 0x7f9734e88040>
2023-03-23 16:16:07,767 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::REVOCATION::REGISTRY_ENDORSED.*'), processor <function on_revocation_registry_endorsed_event at 0x7f9734e88940>
2023-03-23 16:16:07,767 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::REVOCATION::SEND_ENTRY.*'), processor <function on_revocation_entry_event at 0x7f9734e880d0>
2023-03-23 16:16:07,768 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::ENDORSE_DID::(.*)?$'), processor <function on_register_nym_event at 0x7f9734eb6430>
2023-03-23 16:16:07,862 aries_cloudagent.core.profile INFO Create profile manager: indy
2023-03-23 16:16:07,864 aries_cloudagent.indy.sdk.wallet_plugin INFO Checking input postgres storage_config and storage_creds arguments
2023-03-23 16:16:07,864 aries_cloudagent.indy.sdk.wallet_plugin INFO Initializing postgres wallet
2023-03-23 16:16:07,962 aries_cloudagent.indy.sdk.wallet_plugin INFO Success, loaded postgres wallet storage
2023-03-23 16:16:07,962 indy.wallet DEBUG open_wallet: >>> config: '{"id": "aries-mediator-agent-wallet", "freshness_time": false, "storage_type": "postgres_storage", "storage_config": {"url": "aries-mediator-db:5432", "wallet_scheme": "DatabasePerWallet"}}', credentials: '{"key": "8mwXbYBRqlCerDqGjPN3AaiK2pvkekrD", "key_derivation_method": "ARGON2I_MOD", "storage_credentials": {"account": "VVNFUl9ZbzVI", "password": "aXVuN09YUGh1VUZ1WXIySg==", "admin_account": "postgres", "admin_password": "UldrMzlzbGdyaml6VGQ4cw=="}}'
2023-03-23 16:16:07,962 indy.wallet DEBUG open_wallet: Creating callback
2023-03-23 16:16:07,962 indy.libindy DEBUG create_cb: >>> cb_type: <class 'ctypes.CFUNCTYPE.<locals>.CFunctionType'>
2023-03-23 16:16:07,964 indy.libindy DEBUG create_cb: <<< res: <CFunctionType object at 0x7f9734b1df40>
2023-03-23 16:16:07,964 indy.libindy DEBUG do_call: >>> name: indy_open_wallet, args: (c_char_p(140287400351120), c_char_p(140287401309680), <CFunctionType object at 0x7f9734b1df40>)
2023-03-23 16:16:07,965 indy.libindy DEBUG _load_cdll: >>>
2023-03-23 16:16:07,965 indy.libindy DEBUG _load_cdll: Detected OS name: linux
2023-03-23 16:16:07,965 indy.libindy DEBUG _load_cdll: Resolved libindy name is: libindy.so
2023-03-23 16:16:07,965 indy.libindy DEBUG _load_cdll: <<< res: <CDLL 'libindy.so', handle 55e7d4849f30 at 0x7f9734aecc70>
2023-03-23 16:16:07,965 indy.libindy DEBUG set_logger: >>>
2023-03-23 16:16:07,965 indy.libindy DEBUG do_call_sync: >>> name: indy_set_logger, args: (None, None, <CFunctionType object at 0x7f9734b1dc40>, None)
2023-03-23 16:16:07,965 indy.libindy DEBUG do_call_sync: <<< 0
2023-03-23 16:16:07,966 indy.libindy DEBUG set_logger: <<<
2023-03-23 16:16:07,966 indy.libindy DEBUG do_call: Function indy_open_wallet returned err: 0
2023-03-23 16:16:07,966 indy.libindy DEBUG do_call: <<< <Future pending>

2023-03-23 16:18:19,329 indy.libindy DEBUG _get_error_details: >>>
2023-03-23 16:18:19,329 indy.libindy DEBUG _get_error_details: <<< error_details: {'backtrace': '', 'message': 'Error: Wallet not found\n  Caused by: Plugin returned error\n'}
2023-03-23 16:18:19,329 indy.libindy DEBUG _indy_callback: >>> command_handle: 0, err , args: (0,)
2023-03-23 16:18:19,329 indy.libindy DEBUG _indy_callback: <<<
2023-03-23 16:18:19,329 indy.libindy DEBUG _indy_loop_callback: >>> command_handle: 0, err , args: (0,)
2023-03-23 16:18:19,330 indy.libindy WARNING _indy_loop_callback: Function returned error 
2023-03-23 16:18:19,330 indy.libindy DEBUG _indy_loop_callback <<<
Traceback (most recent call last):
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/indy/sdk/wallet_setup.py", line 167, in open_wallet
    handle = await indy.wallet.open_wallet(
  File "/usr/local/lib/python3.9/site-packages/indy/wallet.py", line 124, in open_wallet
    res = await do_call('indy_open_wallet',
  File "/usr/local/lib/python3.9/asyncio/futures.py", line 284, in __await__
    yield self  # This tells Task to wait for completion.
  File "/usr/local/lib/python3.9/asyncio/tasks.py", line 328, in __wakeup
    future.result()
  File "/usr/local/lib/python3.9/asyncio/futures.py", line 201, in result
    raise self._exception
indy.error.WalletNotFoundError

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

Traceback (most recent call last):
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/commands/upgrade.py", line 107, in upgrade
    root_profile, public_did = await wallet_config(context)
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/config/wallet.py", line 54, in wallet_config
    yield self  # This tells Task to wait for completion.
  File "/usr/local/lib/python3.9/asyncio/tasks.py", line 328, in __wakeup
    future.result()
  File "/usr/local/lib/python3.9/asyncio/futures.py", line 201, in result
    raise self._exception
aries_cloudagent.core.error.ProfileNotFoundError: Wallet 'aries-mediator-agent-wallet' not found: Error: Wallet not found
  Caused by: Plugin returned error


During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.9/runpy.py", line 197, in _run_module_as_main
    return _run_code(code, main_globals, None,
  File "/usr/local/lib/python3.9/runpy.py", line 87, in _run_code
    exec(code, run_globals)
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/__main__.py", line 74, in <module>
    main(sys.argv)
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/__main__.py", line 71, in main
    run(args)
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/__main__.py", line 64, in run
    run_command(command, args)
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/commands/__init__.py", line 38, in run_command
    module.execute(argv)
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/commands/upgrade.py", line 241, in execute
    loop.run_until_complete(upgrade(settings))
  File "/home/indy/.local/lib/python3.9/site-packages/nest_asyncio.py", line 90, in run_until_complete
    return f.result()
  File "/usr/local/lib/python3.9/asyncio/futures.py", line 201, in result
    raise self._exception
  File "/usr/local/lib/python3.9/asyncio/tasks.py", line 258, in __step
    result = coro.throw(exc)
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/commands/upgrade.py", line 218, in upgrade
    raise UpgradeError(f"Error during upgrade: {e}")
aries_cloudagent.commands.upgrade.UpgradeError: Error during upgrade: Wallet 'aries-mediator-agent-wallet' not found: Error: Wallet not found
  Caused by: Plugin returned error

WadeBarnes · 2023-03-23T16:27:58Z

Error is now:

Traceback (most recent call last):
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/commands/upgrade.py", line 147, in upgrade
    raise UpgradeError(
aries_cloudagent.commands.upgrade.UpgradeError: No upgrade configuration found for v0.7.5

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.9/runpy.py", line 197, in _run_module_as_main
    return _run_code(code, main_globals, None,
  File "/usr/local/lib/python3.9/runpy.py", line 87, in _run_code
    exec(code, run_globals)
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/__main__.py", line 74, in <module>
    main(sys.argv)
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/__main__.py", line 71, in main
    run(args)
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/__main__.py", line 64, in run
    run_command(command, args)
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/commands/__init__.py", line 38, in run_command
    module.execute(argv)
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/commands/upgrade.py", line 241, in execute
    loop.run_until_complete(upgrade(settings))
  File "/home/indy/.local/lib/python3.9/site-packages/nest_asyncio.py", line 90, in run_until_complete
    return f.result()
  File "/usr/local/lib/python3.9/asyncio/futures.py", line 201, in result
    raise self._exception
  File "/usr/local/lib/python3.9/asyncio/tasks.py", line 256, in __step
    result = coro.send(None)
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/commands/upgrade.py", line 218, in upgrade
    raise UpgradeError(f"Error during upgrade: {e}")
aries_cloudagent.commands.upgrade.UpgradeError: Error during upgrade: No upgrade configuration found for v0.7.5
2023-03-23 16:24:22,363 aries_cloudagent.indy.sdk.profile DEBUG Profile finalizer called; closing wallet

Looks like you can only specify versions that are explicitly listed in the upgrade configuration yaml.

WadeBarnes · 2023-03-23T16:42:29Z

This seemed to work:

1004460000@aries-mediator-agent-37-nsnw9-debug:/acapy-mediator$ $(echo aca-py upgrade \
  --wallet-type indy \
  --wallet-storage-type postgres_storage \
  --wallet-storage-config "$(eval echo \"${WALLET_STORAGE_CONFIGURATION}\")" \
  --wallet-storage-creds "$(eval echo \"${WALLET_STORAGE_CREDENTIALS}\")" \
  --from-version=v0.8.0 \
  --upgrade-config-path /tmp/default_version_upgrade_config.yml \
);
2023-03-23 16:39:51,967 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.actionmenu
2023-03-23 16:39:51,967 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.basicmessage
2023-03-23 16:39:51,968 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.connections
2023-03-23 16:39:51,968 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.coordinate_mediation
2023-03-23 16:39:51,969 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.didexchange
2023-03-23 16:39:51,969 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.discovery
2023-03-23 16:39:51,970 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.endorse_transaction
2023-03-23 16:39:51,971 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.introduction
2023-03-23 16:39:51,971 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.issue_credential
2023-03-23 16:39:52,265 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.notification
2023-03-23 16:39:52,266 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.out_of_band
2023-03-23 16:39:52,266 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.present_proof
2023-03-23 16:39:52,862 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.problem_report
2023-03-23 16:39:52,863 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.revocation_notification
2023-03-23 16:39:52,864 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.routing
2023-03-23 16:39:52,865 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.protocols.trustping
2023-03-23 16:39:52,866 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.holder
2023-03-23 16:39:54,166 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.ledger
2023-03-23 16:39:54,364 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.messaging.credential_definitions
2023-03-23 16:39:54,470 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.messaging.schemas
2023-03-23 16:39:54,565 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.messaging.jsonld
2023-03-23 16:39:54,568 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.revocation
2023-03-23 16:39:54,669 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.resolver
2023-03-23 16:39:54,669 aries_cloudagent.core.plugin_registry DEBUG Loaded module: aries_cloudagent.wallet
2023-03-23 16:39:55,362 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::core::startup?$'), processor <function on_startup_event at 0x7f60e1fe0550>
2023-03-23 16:39:55,362 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::core::shutdown?$'), processor <function on_shutdown_event at 0x7f60e1fe05e0>
2023-03-23 16:39:55,962 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::REVOCATION::published.*'), processor <function on_revocation_published at 0x7f60e1e37a60>
2023-03-23 16:39:55,963 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::REVOCATION::clear-pending.*'), processor <function on_pending_cleared at 0x7f60e1e37f70>
2023-03-23 16:39:55,965 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::REVOCATION::published.*'), processor <function on_revocation_published at 0x7f60e1de1280>
2023-03-23 16:39:55,965 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::REVOCATION::clear-pending.*'), processor <function on_pending_cleared at 0x7f60e1de19d0>
2023-03-23 16:39:55,967 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::CRED_DEF::(.*)?$'), processor <function on_cred_def_event at 0x7f60e2287b80>
2023-03-23 16:39:55,967 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::SCHEMA::(.*)?$'), processor <function on_schema_event at 0x7f60e2220550>
2023-03-23 16:39:55,968 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::REVOCATION::REGISTRY_INIT.*'), processor <function on_revocation_registry_init_event at 0x7f60e218f040>
2023-03-23 16:39:55,968 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::REVOCATION::REGISTRY_ENDORSED.*'), processor <function on_revocation_registry_endorsed_event at 0x7f60e218f940>
2023-03-23 16:39:55,968 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::REVOCATION::SEND_ENTRY.*'), processor <function on_revocation_entry_event at 0x7f60e218f0d0>
2023-03-23 16:39:55,969 aries_cloudagent.core.event_bus DEBUG Subscribed: topic re.compile('^acapy::ENDORSE_DID::(.*)?$'), processor <function on_register_nym_event at 0x7f60e21bc430>
2023-03-23 16:39:56,063 aries_cloudagent.core.profile INFO Create profile manager: indy
2023-03-23 16:39:56,065 aries_cloudagent.indy.sdk.wallet_plugin INFO Checking input postgres storage_config and storage_creds arguments
2023-03-23 16:39:56,065 aries_cloudagent.indy.sdk.wallet_plugin INFO Initializing postgres wallet
2023-03-23 16:39:56,070 aries_cloudagent.indy.sdk.wallet_plugin INFO Success, loaded postgres wallet storage
2023-03-23 16:39:56,070 indy.wallet DEBUG open_wallet: >>> config: '{"id": "aries-mediator-agent-wallet", "freshness_time": false, "storage_type": "postgres_storage", "storage_config": {"url": "aries-mediator-db:5432", "wallet_scheme": "DatabasePerWallet"}}', credentials: '{"key": "8mwXbYBRqlCerDqGjPN3AaiK2pvkekrD", "key_derivation_method": "ARGON2I_MOD", "storage_credentials": {"account": "VVNFUl9ZbzVI", "password": "aXVuN09YUGh1VUZ1WXIySg==", "admin_account": "postgres", "admin_password": "UldrMzlzbGdyaml6VGQ4cw=="}}'
2023-03-23 16:39:56,070 indy.wallet DEBUG open_wallet: Creating callback
2023-03-23 16:39:56,070 indy.libindy DEBUG create_cb: >>> cb_type: <class 'ctypes.CFUNCTYPE.<locals>.CFunctionType'>
2023-03-23 16:39:56,163 indy.libindy DEBUG create_cb: <<< res: <CFunctionType object at 0x7f60e1e23f40>
2023-03-23 16:39:56,163 indy.libindy DEBUG do_call: >>> name: indy_open_wallet, args: (c_char_p(140054082778512), c_char_p(140054083737072), <CFunctionType object at 0x7f60e1e23f40>)
2023-03-23 16:39:56,163 indy.libindy DEBUG _load_cdll: >>>
2023-03-23 16:39:56,163 indy.libindy DEBUG _load_cdll: Detected OS name: linux
2023-03-23 16:39:56,163 indy.libindy DEBUG _load_cdll: Resolved libindy name is: libindy.so
2023-03-23 16:39:56,163 indy.libindy DEBUG _load_cdll: <<< res: <CDLL 'libindy.so', handle 55a711a09720 at 0x7f60e210c040>
2023-03-23 16:39:56,163 indy.libindy DEBUG set_logger: >>>
2023-03-23 16:39:56,164 indy.libindy DEBUG do_call_sync: >>> name: indy_set_logger, args: (None, None, <CFunctionType object at 0x7f60e1e23c40>, None)
2023-03-23 16:39:56,164 indy.libindy DEBUG do_call_sync: <<< 0
2023-03-23 16:39:56,164 indy.libindy DEBUG set_logger: <<<
2023-03-23 16:39:56,164 indy.libindy DEBUG do_call: Function indy_open_wallet returned err: 0
2023-03-23 16:39:56,164 indy.libindy DEBUG do_call: <<< <Future pending>
2023-03-23 16:39:56,192 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:901 | executing query: 
2023-03-23 16:39:56,192 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:489 | preparing query with name ``: SELECT value FROM metadata
2023-03-23 16:39:56,193 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:608 | executing statement  with parameters: []       
2023-03-23 16:40:03,970 indy.libindy DEBUG _indy_callback: >>> command_handle: 0, err , args: (2,)
2023-03-23 16:40:03,971 indy.libindy DEBUG _indy_callback: <<<
2023-03-23 16:40:03,971 indy.libindy DEBUG _indy_loop_callback: >>> command_handle: 0, err , args: (2,)
2023-03-23 16:40:04,062 indy.libindy DEBUG _indy_loop_callback: Function returned 2
2023-03-23 16:40:04,062 indy.libindy DEBUG _indy_loop_callback <<<
2023-03-23 16:40:04,062 indy.wallet DEBUG open_wallet: <<< res: 2
2023-03-23 16:40:04,062 aries_cloudagent.indy.sdk.wallet_setup INFO Creating master secret...
2023-03-23 16:40:04,062 indy.anoncreds DEBUG prover_create_master_secret: >>> wallet_handle: 2, master_secret_name: 'aries-mediator-agent-wallet'
2023-03-23 16:40:04,062 indy.anoncreds DEBUG prover_create_master_secret: Creating callback
2023-03-23 16:40:04,062 indy.libindy DEBUG create_cb: >>> cb_type: <class 'ctypes.CFUNCTYPE.<locals>.CFunctionType'>
2023-03-23 16:40:04,062 indy.libindy DEBUG create_cb: <<< res: <CFunctionType object at 0x7f60e09a21c0>
2023-03-23 16:40:04,063 indy.libindy DEBUG do_call: >>> name: indy_prover_create_master_secret, args: (c_int(2), c_char_p(140054100331024), <CFunctionType object at 0x7f60e09a21c0>)
2023-03-23 16:40:04,063 indy.libindy DEBUG do_call: Function indy_prover_create_master_secret returned err: 0
2023-03-23 16:40:04,063 indy.libindy DEBUG do_call: <<< <Future pending>
2023-03-23 16:40:04,063 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:901 | executing query:
2023-03-23 16:40:04,064 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:489 | preparing query with name ``: SELECT id, value, key FROM items where type = $1 AND name = $2
2023-03-23 16:40:04,065 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:608 | executing statement  with parameters: [[99, 77, 115, 75, 108, 72, 106, 79, 98, 76, 49, 53, 80, 76, 53, 72, 87, 52, 73, 99, 50, 49, 73, 100, 101, 106, 84, 79, 85, 90, 52, 53, 111, 54, 68, 97, 111, 72, 119, 114, 70, 107, 122, 105, 47, 72, 72, 86, 72, 49, 57, 104, 72, 115, 112, 53, 97, 109, 73, 71, 49, 103, 61, 61], [111, 55, 75, 85, 72, 53, 50, 72, 99, 109, 112, 112, 51, 98, 56, 101, 97, 83, 69, 102, 81, 89, 76, 111, 114, 70, 112, 75, 116, 79, 107, 67, 54, 84, 106, 97, 119, 108, 43, 111, 85, 98, 76, 97, 119, 90, 84, 73, 68, 97, 84, 120, 51, 70, 102, 82, 89, 66, 54, 118, 112, 71, 84, 103, 120, 57, 114, 71, 76, 100, 51, 89, 106, 119, 61, 61]]       
2023-03-23 16:40:04,066 indy.libindy DEBUG _get_error_details: >>>
2023-03-23 16:40:04,066 indy.libindy DEBUG _get_error_details: <<< error_details: {'backtrace': '', 'message': 'Error: Duplicated master secret\n  Caused by: MasterSecret already exists aries-mediator-agent-wallet\n'}
2023-03-23 16:40:04,066 indy.libindy DEBUG _indy_callback: >>> command_handle: 1, err , args: (b'',)
2023-03-23 16:40:04,066 indy.libindy DEBUG _indy_callback: <<<
2023-03-23 16:40:04,066 indy.libindy DEBUG _indy_loop_callback: >>> command_handle: 1, err , args: (b'',)
2023-03-23 16:40:04,066 indy.libindy WARNING _indy_loop_callback: Function returned error
2023-03-23 16:40:04,067 indy.libindy DEBUG _indy_loop_callback <<<
2023-03-23 16:40:04,067 aries_cloudagent.indy.sdk.wallet_setup INFO Master secret already exists
2023-03-23 16:40:04,067 indy.non_secrets DEBUG get_wallet_record: >>> wallet_handle: 2, type_: 'config', id: 'default_public_did', options_json: '{"retrieveType": false, "retrieveValue": true, "retrieveTags": true}'
2023-03-23 16:40:04,067 indy.non_secrets DEBUG get_wallet_record: Creating callback
2023-03-23 16:40:04,067 indy.libindy DEBUG create_cb: >>> cb_type: <class 'ctypes.CFUNCTYPE.<locals>.CFunctionType'>
2023-03-23 16:40:04,067 indy.libindy DEBUG create_cb: <<< res: <CFunctionType object at 0x7f60e09a2400>
2023-03-23 16:40:04,067 indy.libindy DEBUG do_call: >>> name: indy_get_wallet_record, args: (c_int(2), c_char_p(140054061828576), c_char_p(140054061848464), c_char_p(140054083049408), <CFunctionType object at 0x7f60e09a2400>)
2023-03-23 16:40:04,068 indy.libindy DEBUG do_call: Function indy_get_wallet_record returned err: 0
2023-03-23 16:40:04,068 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:901 | executing query:
2023-03-23 16:40:04,068 indy.libindy DEBUG do_call: <<< <Future pending>
2023-03-23 16:40:04,068 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:489 | preparing query with name ``: SELECT id, value, key FROM items where type = $1 AND name = $2
2023-03-23 16:40:04,068 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:608 | executing statement  with parameters: [[67, 115, 55, 67, 57, 80, 68, 74, 55, 65, 101, 73, 76, 48, 86, 115, 78, 51, 114, 85, 55, 122, 77, 72, 103, 102, 83, 101, 87, 70, 116, 48, 70, 69, 67, 48, 106, 109, 120, 121, 79, 104, 86, 52, 49, 65, 61, 61], [104, 116, 121, 80, 65, 84, 79, 71, 56, 113, 101, 56, 120, 98, 73, 68, 100, 100, 104, 53, 66, 109, 69, 103, 122, 56, 107, 83, 112, 74, 84, 106, 110, 87, 74, 120, 77, 50, 48, 67, 82, 99, 57, 73, 66, 49, 54, 83, 119, 83, 84, 68, 70, 89, 109, 88, 108, 67, 65, 102, 79, 65, 61, 61]]
2023-03-23 16:40:04,069 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:489 | preparing query with name `s0`: SELECT name, value FROM tags_encrypted WHERE item_id = $1
2023-03-23 16:40:04,069 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:608 | executing statement s0 with parameters: [2]    
2023-03-23 16:40:04,070 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:489 | preparing query with name `s1`: SELECT name, value FROM tags_plaintext WHERE item_id = $1
2023-03-23 16:40:04,070 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:608 | executing statement s1 with parameters: [2]    
2023-03-23 16:40:04,071 indy.libindy DEBUG _indy_callback: >>> command_handle: 2, err , args: (b'{"type":null,"id":"default_public_did","value":"{\\"did\\": \\"JL9J2evqRDykVQB1xEZwDr\\"}","tags":{}}',) 
2023-03-23 16:40:04,071 indy.libindy DEBUG _indy_callback: <<<
2023-03-23 16:40:04,071 indy.libindy DEBUG _indy_loop_callback: >>> command_handle: 2, err , args: (b'{"type":null,"id":"default_public_did","value":"{\\"did\\": \\"JL9J2evqRDykVQB1xEZwDr\\"}","tags":{}}',)
2023-03-23 16:40:04,071 indy.libindy DEBUG _indy_loop_callback: Function returned b'{"type":null,"id":"default_public_did","value":"{\\"did\\": \\"JL9J2evqRDykVQB1xEZwDr\\"}","tags":{}}'
2023-03-23 16:40:04,071 indy.libindy DEBUG _indy_loop_callback <<<
2023-03-23 16:40:04,071 indy.non_secrets DEBUG get_wallet_record: <<< res: '{"type":null,"id":"default_public_did","value":"{\\"did\\": \\"JL9J2evqRDykVQB1xEZwDr\\"}","tags":{}}'
2023-03-23 16:40:04,071 indy.did DEBUG get_my_did_with_meta: >>> wallet_handle: 2, did: 'JL9J2evqRDykVQB1xEZwDr'
2023-03-23 16:40:04,071 indy.did DEBUG get_my_did_with_meta: Creating callback
2023-03-23 16:40:04,071 indy.libindy DEBUG create_cb: >>> cb_type: <class 'ctypes.CFUNCTYPE.<locals>.CFunctionType'>
2023-03-23 16:40:04,071 indy.libindy DEBUG create_cb: <<< res: <CFunctionType object at 0x7f60e09a2580>
2023-03-23 16:40:04,162 indy.libindy DEBUG do_call: >>> name: indy_get_my_did_with_meta, args: (c_int(2), c_char_p(140054082776144), <CFunctionType object at 0x7f60e09a2580>)
2023-03-23 16:40:04,162 indy.libindy DEBUG do_call: Function indy_get_my_did_with_meta returned err: 0
2023-03-23 16:40:04,162 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:901 | executing query:
2023-03-23 16:40:04,162 indy.libindy DEBUG do_call: <<< <Future pending>
2023-03-23 16:40:04,169 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:489 | preparing query with name ``: SELECT id, value, key FROM items where type = $1 AND name = $2
2023-03-23 16:40:04,169 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:608 | executing statement  with parameters: [[68, 48, 120, 75, 109, 87, 87, 52, 74, 99, 112, 103, 79, 115, 83, 108, 52, 70, 100, 78, 75, 98, 115, 84, 74, 74, 103, 119, 50, 110, 78, 78, 69, 50, 76, 74, 99, 118, 86, 83, 112, 83, 73, 54, 48, 119, 72, 56, 111, 81, 61, 61], [81, 98, 84, 116, 57, 67, 57, 121, 47, 89, 110, 52, 72, 117, 54, 99, 55, 85, 115, 97, 75, 87, 80, 99, 101, 57, 110, 78, 90, 115, 54, 43, 65, 118, 84, 53, 74, 65, 105, 102, 47, 110, 108, 107, 105, 70, 51, 109, 82, 100, 84, 105, 54, 56, 54, 78, 120, 75, 50, 101, 50, 113, 100, 75, 50, 81, 111, 61]]
2023-03-23 16:40:04,170 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:901 | executing query:
2023-03-23 16:40:04,170 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:489 | preparing query with name ``: SELECT id, value, key FROM items where type = $1 AND name = $2
2023-03-23 16:40:04,170 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:608 | executing statement  with parameters: [[84, 73, 98, 77, 65, 47, 110, 47, 57, 97, 118, 121, 67, 105, 99, 110, 116, 105, 101, 80, 99, 52, 71, 48, 106, 117, 54, 112, 113, 109, 82, 88, 47, 115, 105, 82, 73, 82, 55, 79, 47, 83, 98, 113, 80, 116, 116, 120, 98, 83, 80, 43, 99, 115, 114, 79, 101, 49, 76, 105], [81, 98, 84, 116, 57, 67, 57, 121, 47, 89, 110, 52, 72, 117, 54, 99, 55, 85, 115, 97, 75, 87, 80, 99, 101, 57, 110, 78, 90, 115, 54, 43, 65, 118, 84, 53, 74, 65, 105, 102, 47, 110, 108, 107, 105, 70, 51, 109, 82, 100, 84, 105, 54, 56, 54, 78, 120, 75, 50, 101, 50, 113, 100, 75, 50, 81, 111, 61]]
2023-03-23 16:40:04,171 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:901 | executing query: 
2023-03-23 16:40:04,171 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:489 | preparing query with name ``: SELECT id, value, key FROM items where type = $1 AND name = $2
2023-03-23 16:40:04,171 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:608 | executing statement  with parameters: [[68, 112, 52, 82, 90, 101, 55, 99, 117, 56, 67, 82, 70, 51, 111, 76, 108, 88, 105, 105, 97, 55, 78, 98, 78, 75, 51, 49, 69, 85, 86, 108, 101, 90, 101, 52, 84, 86, 48, 48, 108, 107, 57, 69, 111, 55, 87, 104, 121, 84, 72, 69, 52, 66, 97, 90, 66, 120, 67, 120, 115, 103, 61, 61], [81, 98, 84, 116, 57, 67, 57, 121, 47, 89, 110, 52, 72, 117, 54, 99, 55, 85, 115, 97, 75, 87, 80, 99, 101, 57, 110, 78, 90, 115, 54, 43, 65, 118, 84, 53, 74, 65, 105, 102, 47, 110, 108, 107, 105, 70, 51, 109, 82, 100, 84, 105, 54, 56, 54, 78, 120, 75, 50, 101, 50, 113, 100, 75, 50, 81, 111, 61]]
2023-03-23 16:40:04,172 indy.libindy DEBUG _indy_callback: >>> command_handle: 3, err , args: (b'{"did":"JL9J2evqRDykVQB1xEZwDr","verkey":"ASqYzN3iqHsBZiPcmBRuc6aQrTpWLm8QufYKEZqN71G9","tempVerkey":null,"metadata":"{\\"posted\\": true}"}',)
2023-03-23 16:40:04,172 indy.libindy DEBUG _indy_callback: <<<
2023-03-23 16:40:04,172 indy.libindy DEBUG _indy_loop_callback: >>> command_handle: 3, err , args: (b'{"did":"JL9J2evqRDykVQB1xEZwDr","verkey":"ASqYzN3iqHsBZiPcmBRuc6aQrTpWLm8QufYKEZqN71G9","tempVerkey":null,"metadata":"{\\"posted\\": true}"}',)
2023-03-23 16:40:04,172 indy.libindy DEBUG _indy_loop_callback: Function returned b'{"did":"JL9J2evqRDykVQB1xEZwDr","verkey":"ASqYzN3iqHsBZiPcmBRuc6aQrTpWLm8QufYKEZqN71G9","tempVerkey":null,"metadata":"{\\"posted\\": true}"}'
2023-03-23 16:40:04,172 indy.libindy DEBUG _indy_loop_callback <<<
2023-03-23 16:40:04,172 indy.did DEBUG get_my_did_with_meta: <<< res: '{"did":"JL9J2evqRDykVQB1xEZwDr","verkey":"ASqYzN3iqHsBZiPcmBRuc6aQrTpWLm8QufYKEZqN71G9","tempVerkey":null,"metadata":"{\\"posted\\": true}"}'
2023-03-23 16:40:04,173 indy.non_secrets DEBUG open_wallet_search: >>> wallet_handle: 2, type_: 'acapy_version', query_json: '{}', options_json: '{"retrieveRecords": true, "retrieveTotalCount": false, "retrieveType": false, "retrieveValue": true, "retrieveTags": true}'
2023-03-23 16:40:04,173 indy.non_secrets DEBUG open_wallet_search: Creating callback
2023-03-23 16:40:04,173 indy.libindy DEBUG create_cb: >>> cb_type: <class 'ctypes.CFUNCTYPE.<locals>.CFunctionType'>
2023-03-23 16:40:04,173 indy.libindy DEBUG create_cb: <<< res: <CFunctionType object at 0x7f60e09a27c0>
2023-03-23 16:40:04,173 indy.libindy DEBUG do_call: >>> name: indy_open_wallet_search, args: (c_int(2), c_char_p(140054061829488), c_char_p(140054061829536), c_char_p(140054083045968), <CFunctionType object at 0x7f60e09a27c0>)
2023-03-23 16:40:04,173 indy.libindy DEBUG do_call: Function indy_open_wallet_search returned err: 0
2023-03-23 16:40:04,173 indy.libindy DEBUG do_call: <<< <Future pending>
2023-03-23 16:40:04,173 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:901 | executing query:
2023-03-23 16:40:04,179 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:901 | executing query:
2023-03-23 16:40:04,179 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:489 | preparing query with name `s0`: SELECT i.id, i.name, i.value, i.key, i.type FROM items as i WHERE i.type = $1
2023-03-23 16:40:04,185 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:901 | executing query: 
2023-03-23 16:40:04,185 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:489 | preparing query with name `s0`: SELECT name, value from tags_plaintext where item_id = $1
2023-03-23 16:40:04,186 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:489 | preparing query with name `s1`: SELECT name, value from tags_encrypted where item_id = $1
2023-03-23 16:40:04,186 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:608 | executing statement s0 with parameters: [[97, 115, 90, 75, 68, 52, 80, 72, 114, 74, 110, 48, 72, 108, 53, 84, 87, 120, 68, 105, 74, 101, 74, 113, 77, 84, 102, 98, 111, 85, 47, 103, 57, 118, 56, 66, 120, 65, 48, 104, 86, 90, 105, 84, 48, 80, 77, 71, 111, 78, 88, 50, 82, 86, 81, 61]]
2023-03-23 16:40:04,262 indy.libindy DEBUG _indy_callback: >>> command_handle: 4, err , args: (3,)
2023-03-23 16:40:04,262 indy.libindy DEBUG _indy_callback: <<<
2023-03-23 16:40:04,263 indy.libindy DEBUG _indy_loop_callback: >>> command_handle: 4, err , args: (3,)
2023-03-23 16:40:04,263 indy.libindy DEBUG _indy_loop_callback: Function returned 3
2023-03-23 16:40:04,263 indy.libindy DEBUG _indy_loop_callback <<<
2023-03-23 16:40:04,263 indy.non_secrets DEBUG open_wallet_search: <<< res: 3
2023-03-23 16:40:04,263 indy.non_secrets DEBUG fetch_wallet_search_next_records: >>> wallet_handle: 2, wallet_search_handle: 3, count: 2
2023-03-23 16:40:04,263 indy.non_secrets DEBUG fetch_wallet_search_next_records: Creating callback
2023-03-23 16:40:04,263 indy.libindy DEBUG create_cb: >>> cb_type: <class 'ctypes.CFUNCTYPE.<locals>.CFunctionType'>
2023-03-23 16:40:04,263 indy.libindy DEBUG create_cb: <<< res: <CFunctionType object at 0x7f60e09a2700>
2023-03-23 16:40:04,263 indy.libindy DEBUG do_call: >>> name: indy_fetch_wallet_search_next_records, args: (c_int(2), c_int(3), c_uint(2), <CFunctionType object at 0x7f60e09a2700>)
2023-03-23 16:40:04,263 indy.libindy DEBUG do_call: Function indy_fetch_wallet_search_next_records returned err: 0
2023-03-23 16:40:04,263 indy.libindy DEBUG _indy_callback: >>> command_handle: 5, err , args: (b'{"totalCount":null,"records":null}',)
2023-03-23 16:40:04,263 indy.libindy DEBUG do_call: <<< <Future pending>
2023-03-23 16:40:04,263 indy.libindy DEBUG _indy_callback: <<<
2023-03-23 16:40:04,263 indy.libindy DEBUG _indy_loop_callback: >>> command_handle: 5, err , args: (b'{"totalCount":null,"records":null}',)
2023-03-23 16:40:04,264 indy.libindy DEBUG _indy_loop_callback: Function returned b'{"totalCount":null,"records":null}'
2023-03-23 16:40:04,264 indy.libindy DEBUG _indy_loop_callback <<<
2023-03-23 16:40:04,264 indy.non_secrets DEBUG fetch_wallet_search_next_records: <<< res: '{"totalCount":null,"records":null}'
2023-03-23 16:40:04,264 indy.non_secrets DEBUG close_wallet_search: >>> wallet_search_handle: 3
2023-03-23 16:40:04,264 indy.non_secrets DEBUG close_wallet_search: Creating callback
2023-03-23 16:40:04,264 indy.libindy DEBUG create_cb: >>> cb_type: <class 'ctypes.CFUNCTYPE.<locals>.CFunctionType'>
2023-03-23 16:40:04,264 indy.libindy DEBUG create_cb: <<< res: <CFunctionType object at 0x7f60e09a2ac0>
2023-03-23 16:40:04,264 indy.libindy DEBUG do_call: >>> name: indy_close_wallet_search, args: (c_int(3), <CFunctionType object at 0x7f60e09a2ac0>)
2023-03-23 16:40:04,264 indy.libindy DEBUG do_call: Function indy_close_wallet_search returned err: 0
2023-03-23 16:40:04,265 indy.libindy DEBUG do_call: >>> name: indy_add_wallet_record, args: (c_int(2), c_char_p(140054061828432), c_char_p(140054061915744), c_char_p(140054061827856), None, <CFunctionType object at 0x7f60e09a2d00>)
2023-03-23 16:40:04,265 indy.libindy DEBUG do_call: Function indy_add_wallet_record returned err: 0
2023-03-23 16:40:04,266 indy.libindy DEBUG do_call: <<< <Future pending>
2023-03-23 16:40:04,266 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:901 | executing query:
2023-03-23 16:40:04,266 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:901 | executing query: START TRANSACTION
2023-03-23 16:40:04,266 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:489 | preparing query with name `s2`: INSERT INTO items (type, name, value, key) VALUES ($1, $2, $3, $4) RETURNING id
2023-03-23 16:40:04,267 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:608 | executing statement s2 with parameters: [[97, 115, 90, 75, 68, 52, 80, 72, 114, 74, 110, 48, 72, 108, 53, 84, 87, 120, 68, 105, 74, 101, 74, 113, 77, 84, 102, 98, 111, 85, 47, 103, 57, 118, 56, 66, 120, 65, 48, 104, 86, 90, 105, 84, 48, 80, 77, 71, 111, 78, 88, 50, 82, 86, 81, 61], [69, 97, 114, 77, 118, 81, 56, 101, 105, 81, 83, 100, 66, 89, 68, 52, 101, 54, 120, 104, 97, 43, 73, 103, 112, 88, 106, 48, 55, 88, 102, 71, 47, 119, 86, 113, 120, 76, 106, 85, 48, 47, 50, 73, 111, 101, 71, 88, 89, 75, 84, 107, 52, 107, 49, 121, 103, 88, 117, 89, 77, 102, 43, 117, 53, 101, 102, 117, 87, 76, 57, 73, 53, 68, 77, 55, 80, 88, 115, 81], [45, 206, 99, 173, 173, 74, 111, 32, 6, 25, 140, 116, 113, 215, 31, 57, 197, 177, 61, 9, 221, 13, 43, 36, 162, 194, 30, 221, 93, 102, 78, 255, 255, 143], [142, 153, 126, 125, 162, 250, 12, 168, 57, 60, 69, 95, 155, 70, 223, 55, 65, 34, 23, 80, 208, 37, 43, 54, 159, 64, 141, 206, 208, 40, 19, 111, 188, 125, 146, 16, 79, 16, 238, 106, 23, 20, 222, 63, 133, 176, 179, 40, 195, 197, 224, 58, 97, 47, 172, 36, 209, 179, 46, 69]]
2023-03-23 16:40:04,268 indy.libindy.native.postgres DEBUG      /usr/local/cargo/registry/src/github.aaakk.us.kg-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:901 | executing query: COMMIT
2023-03-23 16:40:04,273 indy.libindy DEBUG _indy_callback: >>> command_handle: 7, err , args: ()
2023-03-23 16:40:04,273 indy.libindy DEBUG _indy_callback: <<<
2023-03-23 16:40:04,273 indy.libindy DEBUG _indy_loop_callback: >>> command_handle: 7, err , args: ()2023-03-23 16:40:04,273 indy.libindy DEBUG _indy_loop_callback: Function returned None
2023-03-23 16:40:04,273 indy.libindy DEBUG _indy_loop_callback <<<2023-03-23 16:40:04,273 indy.non_secrets DEBUG add_wallet_record: <<< res: None2023-03-23 16:40:04,273 indy.wallet DEBUG close_wallet: >>> handle: 22023-03-23 16:40:04,273 indy.wallet DEBUG close_wallet: Creating callback2023-03-23 16:40:04,273 indy.libindy DEBUG create_cb: >>> cb_type: <class 'ctypes.CFUNCTYPE.<locals>.CFunctionType'>2023-03-23 16:40:04,273 indy.libindy DEBUG create_cb: <<< res: <CFunctionType object at 0x7f60e09a2f40>2023-03-23 16:40:04,273 indy.libindy DEBUG do_call: >>> name: indy_close_wallet, args: (c_int(2), <CFunctionType object at 0x7f60e09a2f40>)
2023-03-23 16:40:04,273 indy.libindy DEBUG do_call: Function indy_close_wallet returned err: 0
2023-03-23 16:40:04,273 indy.libindy DEBUG do_call: <<< <Future pending>
2023-03-23 16:40:04,273 indy.libindy DEBUG _indy_callback: >>> command_handle: 8, err , args: ()
2023-03-23 16:40:04,273 indy.libindy DEBUG _indy_callback: <<<
2023-03-23 16:40:04,273 indy.libindy DEBUG _indy_loop_callback: >>> command_handle: 8, err , args: ()
2023-03-23 16:40:04,273 indy.libindy DEBUG _indy_loop_callback: Function returned None
2023-03-23 16:40:04,274 indy.libindy DEBUG _indy_loop_callback <<<
2023-03-23 16:40:04,274 indy.wallet DEBUG close_wallet: <<<
2023-03-23 16:40:04,274 aries_cloudagent.indy.sdk.profile DEBUG Profile finalizer called; closing wallet

swcurran · 2023-03-23T16:50:56Z

Any notes about an upgrade to the documentation on upgrade would be appreciated. Current “docs” are here in the Changelog for the 0.8.0 release. I don’t see any general documentation on “Upgrade”, but I didn’t look too hard.

It sounds like we need to do a new 0.8.1 immediately with the missing file. Please let me know what needs to be in that file.

Please put details in: openwallet-foundation/acapy#2178

Or open a PR to add the necessary documents that would have helped you.

Thanks.

WadeBarnes · 2023-03-23T17:45:07Z

Any notes about an upgrade to the documentation on upgrade would be appreciated. Current “docs” are here in the Changelog for the 0.8.0 release. I don’t see any general documentation on “Upgrade”, but I didn’t look too hard.

The only tripping points were the default_version_upgrade_config.yml not existing in the release, knowing you could exclude --upgrade-config-path if it existed, having to specify a version for --from-version that exists in the file, and having to specify --from-version=v0.8.0 when upgrading to v0.8.0.

WadeBarnes · 2023-03-23T17:59:31Z

Our Aries Mediator Service dev environment has been upgrade to aca-py v0.8.0. Waiting for feedback on when this should be promoted to test.

WadeBarnes · 2023-03-24T13:35:59Z

I've run into a problem upgrading the test environment. When running the upgrade I get the following output, which indicates the upgrade will not be run.

1004440000@aries-mediator-agent-24-v626k-debug:/acapy-mediator$ $(echo aca-py upgrade \
  --wallet-type indy \
  --wallet-storage-type postgres_storage \
  --wallet-storage-config "$(eval echo \"${WALLET_STORAGE_CONFIGURATION}\")" \
  --wallet-storage-creds "$(eval echo \"${WALLET_STORAGE_CREDENTIALS}\")" \
  --from-version=v0.7.5 \
  --upgrade-config-path /tmp/default_version_upgrade_config.yml \
);
2023-03-24 13:33:29,325 aries_cloudagent.core.profile INFO Create profile manager: indy
2023-03-24 13:33:29,326 aries_cloudagent.indy.sdk.wallet_plugin INFO Checking input postgres storage_config and storage_creds arguments
2023-03-24 13:33:29,327 aries_cloudagent.indy.sdk.wallet_plugin INFO Initializing postgres wallet
2023-03-24 13:33:29,332 aries_cloudagent.indy.sdk.wallet_plugin INFO Success, loaded postgres wallet storage
2023-03-24 13:33:30,259 aries_cloudagent.indy.sdk.wallet_setup INFO Creating master secret...
2023-03-24 13:33:30,261 indy.libindy WARNING _indy_loop_callback: Function returned error
2023-03-24 13:33:30,261 aries_cloudagent.indy.sdk.wallet_setup INFO Master secret already exists
version v0.8.0 found in storage, --from-version will be ignored.
Version v0.8.0 to upgrade from and current version to upgrade to v0.8.0 are same.

@ianco, Any thoughts?

ianco · 2023-03-24T13:49:17Z

It seems to think the wallet database is already at version 0.8.0 ...

swcurran · 2023-03-24T13:55:20Z

The error message is the same as we saw with the test failure, right? Weird that this was not hit in Dev — such fun. Is it because we were running 0.8.0-rc1 there? It’s considered the same as 0.8.0?

ianco · 2023-03-24T14:06:29Z

We need to relax the rules on the upgrade. This upgrade is non-destructive (it just re-saves the connection records to update the tags) so shouldn't be an issue if it's re-run. However it's weird that the storage version was changed to 0.8.0 before the upgrade was run. Also the upgrade shouldn't enforce the exact "from" version to be in the upgrade.yml file.

Not sure about the 0.8.0 vs 0.8.0-rc1 issue why wouldn't the storage version be 0.8.0-rc1 if that's what the aca-py version is?

WadeBarnes · 2023-03-24T14:09:27Z

Both dev and test were running 0.8.0-rc0 previously. I also noticed after looking at the upgrade code that none of the expected log messages from the upgrade are contained in the log output from when I ran the upgrade on dev, so I'm not convinced the upgrade ran successfully there either.

swcurran · 2023-03-24T14:24:40Z

Given that the YML file has never shipped with ACA-Py, it’s doubtful an upgrade has ever been run.

@ianco, can you get the code fixed to work, and explained?

ianco · 2023-03-24T14:32:47Z

I suggest:

add a --force flag to the upgrade command to force the upgrade to run, regardless of the version check
add the version info to the /status/config output so we can see what the version is
when we do a rc release, make sure the version in the version.py reflects the rc number (it looks like 0.8.0-rc0 was recorded as 0.8.0 in the wallet storage) (or wherever this is stored make sure the rc info is included in the version)
add an unencrypted tag to the version record in the wallet so we can inspect the db to figure out what is the version (and which record it is)

Maybe also look at the logic that determines whether the upgrade should run - it looks like it expects the exact from version to be in the upgrade.yml file, which it isn't (we have only been including the version info where there is an actual upgrade in the release).

swcurran · 2023-03-24T14:59:57Z

@WadeBarnes — can you try running the command with --from-version=v0.7.2, since that is the last one in the file?

WadeBarnes · 2023-03-24T15:02:15Z

I did. Because the version is recorded in storage, it ignores anything you pass in via --from-version.

You get:

version vx.x.x found in storage, --from-version will be ignored.

where vx.x.x is the version it finds.

swcurran · 2023-03-24T15:03:47Z

Can you tell from the code (a) what goes into the storage, and (b) if the comparison that is being used would detect 0.8.0-rc0 as later than 0.8.0?

I’m certain that the value is version.py is accurate for each release — that’s the only thing we change, it is verified, and we can confirm that for every release. I can’t see that as the issue.

If a value is recorded in secure storage, we should be able to see that, don’t you think? We don’t really need an unencrypted tag if we assume that no one is sneaking around updating it another way.

ianco · 2023-03-24T15:15:15Z

The version record in the wallet is updated here, in the upgrade command:

https://github.com/hyperledger/aries-cloudagent-python/blob/main/aries_cloudagent/commands/upgrade.py#L202

It looks like it just saves the version from version.py, so it should include the rc part of the version.

There's a helper method here for updating the version in the wallet but it's not called anywhere:

https://github.com/hyperledger/aries-cloudagent-python/blob/main/aries_cloudagent/config/wallet.py#L142

... and it looks like the Conductor will bail on startup if the version doesn't match:

https://github.com/hyperledger/aries-cloudagent-python/blob/main/aries_cloudagent/core/conductor.py#L313

(... unless there is no version record in the wallet, in which case aca-py will startup happily)

ianco · 2023-03-24T15:16:22Z

If a value is recorded in secure storage, we should be able to see that, don’t you think?

All the contents of the wallet are encrypted so we can't inspect anything ... we can't connect to the wallet database directly and see anything, and the version info stored in the wallet isn't exposed anywhere via the api

swcurran · 2023-03-24T15:22:22Z

Just realized @WadeBarnes that you used —from-version 0.8.0 on Dev. That doesn’t really make sense, as the from version should be less than that, right?

The “old” (from) version either comes from Storage, or if not found, comes from the —from-version arg, and the “to” version is set in version.py.

It also looks like the version is never added to storage unless an upgrade has been run at least once — the add record is only (AFAICS) in the upgrade command.

And I certainly can’t see that the value version.py is ever altered — e.g. the -rc0 dropped.

Frustrating...

swcurran · 2023-03-24T15:26:36Z

If a value is recorded in secure storage, we should be able to see that, don’t you think?

All the contents of the wallet are encrypted so we can't inspect anything ... we can't connect to the wallet database directly and see anything, and the version info stored in the wallet isn't exposed anywhere via the api

I mean — we should be able to see where the data is updated in the code such that we don’t have to see the literal value.

ianco · 2023-03-24T15:28:56Z

I mean — we should be able to see where the data is updated in the code such that we don’t have to see the literal value.

Sure but that doesn't tell us what version is currently running, for example what is the storage version in the production mediator right now? We can't tell ...

swcurran · 2023-03-24T15:35:45Z

The only way to get the version into storage is to run the upgrade, and since it is pretty unlikely an upgrade has been run on this instance before, there should be no version in storage. How is that routine returning a value?

This seems like the same issue we had with the integration test just before release. What did you do to fix that @ianco? Is it possible we’re seeing the same thing?

WadeBarnes · 2023-03-24T15:38:32Z

No, having to specify an explicit version contained in a file you can't see easily does not make sense. I mentioned that here. I had originally specified v0.7.5 as recommended in the notes provided but the result was this.

I'm thinking it would be way better if aca-py managed it's own upgrade lifecycle on start-up rather than having to run the upgrade out-of-band. It could warn you if you are running a different version than specified in storage and halt until you confirm, somehow (like an environment variable to flag you want to upgrade/downgrade), that what you're doing is intentional.

I'm a little concerned now about the Conductor bailing on startup when the version in storage does not match the running version. Our automated upgrades have been working to this point because we've never done and upgrade, so there is no version record in storage. Now that we've done an upgrade the version is in storage so all future automated deployments to our (say dev) environments will fail because the Conductor will bail whenever we try to deploy a new version. We'll have to update the deployment configs to include an upgrade step. The question then becomes what happens if we need to roll back to a previous version due to an issue discovered in a new version?

swcurran · 2023-03-24T15:44:00Z

I think we need to be working together on this on a call. I’ll add @shaangill025. @ianco — not sure if you are working today or not, so you may not be able to join.

Completely agree with you about bailing on startup if the upgrade is not done. That seems like a bad idea. But at the same time, if the upgrade is executed by 5 instances of ACA-Py on the same storage, what will happen…?

For now, we need to understand why the query of secure storage is saying we are on version 0.8.0, when an upgrade has never been run...

WadeBarnes · 2023-03-24T15:49:12Z

The version likely got in there when I ran the upgrade the first time. What I posted was not actually the first run. I had originally run it with --from-version=v0.8.0 like I did in dev which seemed to work, but now on further examination I'm not confident it actually did as noted earlier.

The result at that point was something like this simulated log output:

1004440000@aries-mediator-agent-24-v626k-debug:/acapy-mediator$ $(echo aca-py upgrade \
  --wallet-type indy \
  --wallet-storage-type postgres_storage \
  --wallet-storage-config "$(eval echo \"${WALLET_STORAGE_CONFIGURATION}\")" \
  --wallet-storage-creds "$(eval echo \"${WALLET_STORAGE_CREDENTIALS}\")" \
  --from-version=v0.8.0 \
  --upgrade-config-path /tmp/default_version_upgrade_config.yml \
);
2023-03-24 13:33:29,325 aries_cloudagent.core.profile INFO Create profile manager: indy
2023-03-24 13:33:29,326 aries_cloudagent.indy.sdk.wallet_plugin INFO Checking input postgres storage_config and storage_creds arguments
2023-03-24 13:33:29,327 aries_cloudagent.indy.sdk.wallet_plugin INFO Initializing postgres wallet
2023-03-24 13:33:29,332 aries_cloudagent.indy.sdk.wallet_plugin INFO Success, loaded postgres wallet storage
2023-03-24 13:33:30,259 aries_cloudagent.indy.sdk.wallet_setup INFO Creating master secret...
2023-03-24 13:33:30,261 indy.libindy WARNING _indy_loop_callback: Function returned error
2023-03-24 13:33:30,261 aries_cloudagent.indy.sdk.wallet_setup INFO Master secret already exists
Version v0.8.0 to upgrade from and current version to upgrade to v0.8.0 are same.

I then tried running the upgrade command with --from-version=v0.7.5, but obviously by that point the version had been written to storage.

swcurran · 2023-03-24T15:58:20Z

OK — that’s good to know. And that command would have happily skipped the update and updated the storage version. Phew…we know how we got here. Now we need to decide what we need to do, and what to do for the long term.

I think we switch the logic on the check such that the —from-version overrides the storage version (instead of the other way round).

The bigger question that perhaps we don’t have to decide today is how we fix the automated deployment issue that Wade highlights above. That needs safe automation.

Meeting set for this morning.

shaangill025 · 2023-03-24T16:19:35Z

After taking a look at the code for upgrade function, I think the config file for v8.0.0 release [Assuming ConnRecord for all previous 0.7.* versions need to be resaved] should be something like this:

v0.7.5:
  resave_records:
    base_record_path:
      - "aries_cloudagent.connections.models.conn_record.ConnRecord"
  update_existing_records: false
v0.7.4:
  resave_records:
    base_record_path:
      - "aries_cloudagent.connections.models.conn_record.ConnRecord"
  update_existing_records: false
v0.7.3:
  resave_records:
    base_record_path:
      - "aries_cloudagent.connections.models.conn_record.ConnRecord"
  update_existing_records: false
v0.7.2:
  resave_records:
    base_record_path:
      - "aries_cloudagent.connections.models.conn_record.ConnRecord"
  update_existing_records: false
v0.7.1:
  resave_records:
    base_record_path:
      - "aries_cloudagent.connections.models.conn_record.ConnRecord"
  update_existing_records: false
v0.7.0:
  resave_records:
    base_record_path:
      - "aries_cloudagent.connections.models.conn_record.ConnRecord"
  update_existing_records: false
v0.6.0:
  update_existing_records: false

If there was no version record in storage initially then running with --from-version=0.7.* should have worked. But as the version record has already been set as 0.8.0 without the ConnRecord being resaved, I think we implement --force-upgrade like @ianco suggested which ignores the version record from storage and instead uses the --from-version to rerun the upgrade process.

swcurran · 2023-03-24T17:53:57Z

Issue: How to force an upgrade:

Decision is to have both --force-upgrade and --from-version

Issue: What if the from-version is not in the upgrade yaml? It would be nice to have it fallback to the one previous to the --from-version or in secure storage.

Decision: Make the code smarter and have it find the first version equal to or greater than the from version (from args or storage) and apply all the upgrades including and to the current version. This becomes the literal from to use.
Further -- if there is more than one identical update -- run it only once. See the example above -- all of the updates are to resave-ConnRec so it really only needs to be done once.

Issue: Once a version is in storage, cannot move to a newer version without running the upgrade command.

Decision: Change to only stop if there is an upgrade required between versions -- and if not, update the storage version.

Issue: On a new deployment, there is no version put into storage.

Decision: Add to the create storage the additional of the version record.

Issue: No version in storage in existing deployments.

Decision: Recommend that the deployment have an upgrade --from-version... command.

Issue: No warning currently produced when version in storage is not found.

Decision: Add the warning, with details about what to do.

Issue: Can we run an upgrade automatically when deploying a new version. Current behaviour is to abort the startup.

Option: Auto-upgrade.
- Risk: Multiple instances try to run the upgrade could cause unexpected side effects.
  - Same as the next problem -- must be run offline
  - ~~Need a semaphore or equivalent if the upgrade must be run once and only once.~~
- Risk: Some updates MAY require running the upgrade offline.
  - Flag in YML file to say MUST be run as an explicit upgrade.

Issue: The current expectation is that in the YML, the version for the change is the "from" -- e.g. when upgrading from a designated release.

Decision: The version associated with an upgrade command should be the version in when the upgrade should be run. E.g. Any version being upgraded to that version must run the upgrade steps. So:
- If the entry is v0.8.0: Update_Connections -- that command should be run from every pre-0.8.0 version when upgrade to 0.8.0 or beyond. Further, if going from 0.7.5 to 0.9.0, they would run the 0.8.0 upgrade.

WadeBarnes · 2023-04-21T17:52:47Z

All mediator instances have been successfully upgrade to aca-py v0.8.1. Related PR; #28

WadeBarnes self-assigned this Mar 22, 2023

ianco mentioned this issue Mar 23, 2023

default_version_upgrade_config.yml file missing from aca-py release openwallet-foundation/acapy#2178

Closed

WadeBarnes changed the title ~~Upgrade the Mediator's ACA-Py instance to Release 0.8.0~~ Upgrade the Mediator's ACA-Py instance to Release 0.8.1 Apr 21, 2023

WadeBarnes closed this as completed Apr 21, 2023

Upgrade the Mediator's ACA-Py instance to Release 0.8.1 #25

Upgrade the Mediator's ACA-Py instance to Release 0.8.1 #25

Comments

swcurran commented Mar 21, 2023 • edited Loading

ianco commented Mar 21, 2023

swcurran commented Mar 21, 2023

WadeBarnes commented Mar 23, 2023

ianco commented Mar 23, 2023

WadeBarnes commented Mar 23, 2023 • edited Loading

WadeBarnes commented Mar 23, 2023

ianco commented Mar 23, 2023

ianco commented Mar 23, 2023

WadeBarnes commented Mar 23, 2023

WadeBarnes commented Mar 23, 2023

WadeBarnes commented Mar 23, 2023

ianco commented Mar 23, 2023

WadeBarnes commented Mar 23, 2023

ianco commented Mar 23, 2023

WadeBarnes commented Mar 23, 2023 • edited Loading

WadeBarnes commented Mar 23, 2023

WadeBarnes commented Mar 23, 2023

swcurran commented Mar 23, 2023

WadeBarnes commented Mar 23, 2023

WadeBarnes commented Mar 23, 2023

WadeBarnes commented Mar 24, 2023

ianco commented Mar 24, 2023

swcurran commented Mar 24, 2023

ianco commented Mar 24, 2023

WadeBarnes commented Mar 24, 2023

swcurran commented Mar 24, 2023

ianco commented Mar 24, 2023

swcurran commented Mar 24, 2023

WadeBarnes commented Mar 24, 2023 • edited Loading

swcurran commented Mar 24, 2023

ianco commented Mar 24, 2023

ianco commented Mar 24, 2023

swcurran commented Mar 24, 2023

swcurran commented Mar 24, 2023

ianco commented Mar 24, 2023

swcurran commented Mar 24, 2023

WadeBarnes commented Mar 24, 2023 • edited Loading

swcurran commented Mar 24, 2023

WadeBarnes commented Mar 24, 2023 • edited Loading

swcurran commented Mar 24, 2023

shaangill025 commented Mar 24, 2023

swcurran commented Mar 24, 2023

WadeBarnes commented Apr 21, 2023

swcurran commented Mar 21, 2023 •

edited

Loading

WadeBarnes commented Mar 23, 2023 •

edited

Loading

WadeBarnes commented Mar 23, 2023 •

edited

Loading

WadeBarnes commented Mar 24, 2023 •

edited

Loading

WadeBarnes commented Mar 24, 2023 •

edited

Loading

WadeBarnes commented Mar 24, 2023 •

edited

Loading