openwallet-foundation / acapy

ACA-Py is a foundation for building decentralized identity applications and services running in non-mobile environments.
https://aca-py.org
Apache License 2.0
420 stars 513 forks source link

Erorr on startup with aca-py 0.8.1-rc0 #2192

Closed WadeBarnes closed 1 year ago

WadeBarnes commented 1 year ago

The following error occurs on startup:

:: BC Mediator (Dev)                        ::
::                                          ::
::                                          ::
:: Inbound Transports:                      ::
::                                          ::
::   - http://0.0.0.0:3000                  ::
::   - ws://0.0.0.0:3001                    ::
::                                          ::
:: Outbound Transports:                     ::
::                                          ::
::   - http                                 ::
::   - https                                ::
::   - ws                                   ::
::   - wss                                  ::
::                                          ::
:: Public DID Information:                  ::
::                                          ::
::   - DID: JL9J2evqRDykVQB1xEZwDr          ::
::                                          ::
:: Administration API:                      ::
::                                          ::
::   - http://0.0.0.0:3002                  ::
::                                          ::
::                           ver: 0.8.1-rc0 ::
::::::::::::::::::::::::::::::::::::::::::::::

Listening...

2023-03-31 18:51:38,230 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-31 18:51:38,230 indy.non_secrets DEBUG open_wallet_search: Creating callback
2023-03-31 18:51:38,230 indy.libindy DEBUG create_cb: >>> cb_type: <class 'ctypes.CFUNCTYPE.<locals>.CFunctionType'>
2023-03-31 18:51:38,230 indy.libindy DEBUG create_cb: <<< res: <CFunctionType object at 0x7f53c67a9640>
2023-03-31 18:51:38,230 indy.libindy DEBUG do_call: >>> name: indy_open_wallet_search, args: (c_int(2), c_char_p(139997753111952), c_char_p(139997753112000), c_char_p(139997751083088), <CFunctionType object at 0x7f53c67a9640>)
2023-03-31 18:51:38,230 indy.libindy DEBUG do_call: Function indy_open_wallet_search returned err: 0
2023-03-31 18:51:38,230 indy.libindy DEBUG do_call: <<< <Future pending>
2023-03-31 18:51:38,231 indy.libindy.native.postgres DEBUG  /usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:901 | executing query: 
2023-03-31 18:51:38,237 indy.libindy.native.postgres DEBUG  /usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:901 | executing query: 
2023-03-31 18:51:38,237 indy.libindy.native.postgres DEBUG  /usr/local/cargo/registry/src/github.com-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-31 18:51:38,243 indy.libindy.native.postgres DEBUG  /usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:901 | executing query: 
2023-03-31 18:51:38,243 indy.libindy.native.postgres DEBUG  /usr/local/cargo/registry/src/github.com-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-31 18:51:38,243 indy.libindy.native.postgres DEBUG  /usr/local/cargo/registry/src/github.com-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-31 18:51:38,244 indy.libindy.native.postgres DEBUG  /usr/local/cargo/registry/src/github.com-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-31 18:51:38,245 indy.libindy.native.postgres DEBUG  /usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:608 | executing statement s0 with parameters: [1438]
2023-03-31 18:51:38,246 indy.libindy.native.postgres DEBUG  /usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/postgres-0.15.2/src/lib.rs:608 | executing statement s1 with parameters: [1438]
2023-03-31 18:51:38,247 indy.libindy DEBUG _indy_callback: >>> command_handle: 4, err , args: (3,)
2023-03-31 18:51:38,247 indy.libindy DEBUG _indy_callback: <<<
2023-03-31 18:51:38,247 indy.libindy DEBUG _indy_loop_callback: >>> command_handle: 4, err , args: (3,)
2023-03-31 18:51:38,247 indy.libindy DEBUG _indy_loop_callback: Function returned 3
2023-03-31 18:51:38,247 indy.libindy DEBUG _indy_loop_callback <<<
2023-03-31 18:51:38,247 indy.non_secrets DEBUG open_wallet_search: <<< res: 3
2023-03-31 18:51:38,247 indy.non_secrets DEBUG fetch_wallet_search_next_records: >>> wallet_handle: 2, wallet_search_handle: 3, count: 2
2023-03-31 18:51:38,247 indy.non_secrets DEBUG fetch_wallet_search_next_records: Creating callback
2023-03-31 18:51:38,248 indy.libindy DEBUG create_cb: >>> cb_type: <class 'ctypes.CFUNCTYPE.<locals>.CFunctionType'>
2023-03-31 18:51:38,248 indy.libindy DEBUG create_cb: <<< res: <CFunctionType object at 0x7f53c67a97c0>
2023-03-31 18:51:38,248 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 0x7f53c67a97c0>)
2023-03-31 18:51:38,248 indy.libindy DEBUG do_call: Function indy_fetch_wallet_search_next_records returned err: 0
2023-03-31 18:51:38,248 indy.libindy DEBUG do_call: <<< <Future pending>
2023-03-31 18:51:38,248 indy.libindy DEBUG _indy_callback: >>> command_handle: 5, err , args: (b'{"totalCount":null,"records":[{"type":null,"id":"d2d454b83d9d4849908ebbea76cb1219","value":"v0.8.0","tags":{}}]}',)
2023-03-31 18:51:38,248 indy.libindy DEBUG _indy_callback: <<<
2023-03-31 18:51:38,248 indy.libindy DEBUG _indy_loop_callback: >>> command_handle: 5, err , args: (b'{"totalCount":null,"records":[{"type":null,"id":"d2d454b83d9d4849908ebbea76cb1219","value":"v0.8.0","tags":{}}]}',)
2023-03-31 18:51:38,248 indy.libindy DEBUG _indy_loop_callback: Function returned b'{"totalCount":null,"records":[{"type":null,"id":"d2d454b83d9d4849908ebbea76cb1219","value":"v0.8.0","tags":{}}]}'
2023-03-31 18:51:38,248 indy.libindy DEBUG _indy_loop_callback <<<
2023-03-31 18:51:38,248 indy.non_secrets DEBUG fetch_wallet_search_next_records: <<< res: '{"totalCount":null,"records":[{"type":null,"id":"d2d454b83d9d4849908ebbea76cb1219","value":"v0.8.0","tags":{}}]}'
2023-03-31 18:51:38,248 indy.non_secrets DEBUG close_wallet_search: >>> wallet_search_handle: 3
2023-03-31 18:51:38,248 indy.non_secrets DEBUG close_wallet_search: Creating callback
2023-03-31 18:51:38,249 indy.libindy DEBUG create_cb: >>> cb_type: <class 'ctypes.CFUNCTYPE.<locals>.CFunctionType'>
2023-03-31 18:51:38,249 indy.libindy DEBUG create_cb: <<< res: <CFunctionType object at 0x7f53c67a9b80>
2023-03-31 18:51:38,249 indy.libindy DEBUG do_call: >>> name: indy_close_wallet_search, args: (c_int(3), <CFunctionType object at 0x7f53c67a9b80>)
2023-03-31 18:51:38,249 indy.libindy DEBUG do_call: Function indy_close_wallet_search returned err: 0
2023-03-31 18:51:38,249 indy.libindy DEBUG do_call: <<< <Future pending>
2023-03-31 18:51:38,249 indy.libindy DEBUG _indy_callback: >>> command_handle: 6, err , args: ()
2023-03-31 18:51:38,249 indy.libindy DEBUG _indy_callback: <<<
2023-03-31 18:51:38,249 indy.libindy DEBUG _indy_loop_callback: >>> command_handle: 6, err , args: ()
2023-03-31 18:51:38,249 indy.libindy DEBUG _indy_loop_callback: Function returned None
2023-03-31 18:51:38,250 indy.libindy DEBUG _indy_loop_callback <<<
2023-03-31 18:51:38,250 indy.non_secrets DEBUG close_wallet_search: <<< res: None
2023-03-31 18:51:38,250 aries_cloudagent.commands.start ERROR Exception during startup:
Traceback (most recent call last):
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/commands/start.py", line 72, in init
    await startup
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/commands/start.py", line 29, in start_app
    await conductor.start()
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/core/conductor.py", line 335, in start
    config_available_list = get_upgrade_version_list(
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/commands/upgrade.py", line 101, in get_upgrade_version_list
    version_upgrade_config_inst = VersionUpgradeConfig(config_path)
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/commands/upgrade.py", line 46, in __init__
    self.setup_version_upgrade_config(DEFAULT_UPGRADE_CONFIG_PATH)
  File "/home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/commands/upgrade.py", line 50, in setup_version_upgrade_config
    with open(path, "r") as stream:
FileNotFoundError: [Errno 2] No such file or directory: './aries_cloudagent/commands/default_version_upgrade_config.yml'

Shutting down
2023-03-31 18:51:38,330 aries_cloudagent.core.event_bus DEBUG Notifying subscribers: <Event topic=acapy::core::shutdown, payload={}>
2023-03-31 18:51:38,332 indy.wallet DEBUG close_wallet: >>> handle: 2
2023-03-31 18:51:38,332 indy.wallet DEBUG close_wallet: Creating callback
2023-03-31 18:51:38,332 indy.libindy DEBUG create_cb: >>> cb_type: <class 'ctypes.CFUNCTYPE.<locals>.CFunctionType'>
2023-03-31 18:51:38,332 indy.libindy DEBUG create_cb: <<< res: <CFunctionType object at 0x7f53c67a9d00>
2023-03-31 18:51:38,332 indy.libindy DEBUG do_call: >>> name: indy_close_wallet, args: (c_int(2), <CFunctionType object at 0x7f53c67a9d00>)
2023-03-31 18:51:38,332 indy.libindy DEBUG do_call: Function indy_close_wallet returned err: 0
2023-03-31 18:51:38,332 indy.libindy DEBUG do_call: <<< <Future pending>
2023-03-31 18:51:38,333 indy.libindy DEBUG _indy_callback: >>> command_handle: 7, err , args: ()
2023-03-31 18:51:38,333 indy.libindy DEBUG _indy_callback: <<<
2023-03-31 18:51:38,333 indy.libindy DEBUG _indy_loop_callback: >>> command_handle: 7, err , args: ()
2023-03-31 18:51:38,333 indy.libindy DEBUG _indy_loop_callback: Function returned None
2023-03-31 18:51:38,333 indy.libindy DEBUG _indy_loop_callback <<<
2023-03-31 18:51:38,333 indy.wallet DEBUG close_wallet: <<<
2023-03-31 18:51:38,334 aries_cloudagent.indy.sdk.profile DEBUG Profile finalizer called; closing wallet

default_version_upgrade_config.yml exists in the container, but it's located at /home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/commands/default_version_upgrade_config.yml. aca-py seems to be looking for the file relative to the working directory, rather than relative to the module trying to access it.

WadeBarnes commented 1 year ago

cc @shaangill025, @swcurran

WadeBarnes commented 1 year ago

This is running in OCP using the ghcr.io/hyperledger/aries-cloudagent-python:py3.9-indy-1.16.0-0.8.1-rc0 image.

shaangill025 commented 1 year ago

Will this work, by updating the following here?

with open(os.path.abspath(path), "r") as stream:
swcurran commented 1 year ago

What about just making it a JSON data structure in code, instead of a file? Same as version in version.py? Same effort to maintain, and minimum overhead to handle.

WadeBarnes commented 1 year ago

os.path.abspath will build the path to the file based on the working directory. Example with working dir /acapy-mediator, like it is on the container:

>>> import os
>>> os.path.abspath('./aries_cloudagent/commands/default_version_upgrade_config.yml')
'/acapy-mediator/aries_cloudagent/commands/default_version_upgrade_config.yml'

Still the wrong path.

shaangill025 commented 1 year ago

How about this? os.getcwd() should get us /home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/commands and then we add the file name to it which gets us the path

import os
file_name = "default_version_upgrade_config.yml"
work_dir_path = os.getcwd()
file_path = os.path.join(work_dir_path, file_name)
WadeBarnes commented 1 year ago

Seeing that it is upgrade.py trying to access default_version_upgrade_config.yml and they are both in the same folder, you'll likely want to use something like os.path.realpath(os.path.dirname(__file__)) to find the absolute directory of the upgrade.py script and then build the path to default_version_upgrade_config.yml from there.

WadeBarnes commented 1 year ago

How about this? os.getcwd() should get us /home/indy/.local/lib/python3.9/site-packages/aries_cloudagent/commands and then we add the file name to it which gets us the path

import os
file_name = "default_version_upgrade_config.yml"
work_dir_path = os.getcwd()
file_path = os.path.join(work_dir_path, file_name)

os.getcwd() will return the working directory, that will change depending on the working directory at the time aca-py is started.

Example with the working directory as set before (to /acapy-mediator):

>>> import os
>>> os.getcwd()
'/acapy-mediator'