Closed swcurran closed 1 year ago
Update -- on the Endorser side, there is no connection. I was misreading the Swagger output. No connection request has been received by the Endorser AFAICT.
Some progress. Reviewing the Endorser logs exposed the following (see below).
Got past that by adding requests-through-public-did: true
to the endorser-acapy-args.yml
file. This was added after the previous version of ACA-Py used in Traction was tagged (after 1.0.0-rc1). I'll submit a PR to add it to traction.
scripts-endorser-agent-1 | 2023-06-06 20:16:07,313 aiohttp.access INFO 172.21.0.1 [06/Jun/2023:20:16:07 +0000] "POST / HTTP/1.1" 200 149 "-" "Python/3.6 aiohttp/3.8.4"
scripts-endorser-agent-1 | 2023-06-06 20:16:07,321 aries_cloudagent.connections.base_manager WARNING No corresponding DID found for sender verkey: B3g3C7n9hkPqm53vgP2DLGMWaENGVLiNo2nyq6Fb3N1L
scripts-endorser-agent-1 | 2023-06-06 20:16:07,351 aries_cloudagent.messaging.base_handler ERROR Error receiving RFC 23 connection request
scripts-endorser-agent-1 | Traceback (most recent call last):
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/site-packages/aries_cloudagent/protocols/didexchange/v1_0/handlers/request_handler.py", line 44, in handle
scripts-endorser-agent-1 | else context.message_receipt.recipient_verkey
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/site-packages/aries_cloudagent/protocols/didexchange/v1_0/manager.py", line 488, in receive_request
scripts-endorser-agent-1 | "Unsolicited connection requests to " "public DID is not enabled"
scripts-endorser-agent-1 | aries_cloudagent.protocols.didexchange.v1_0.manager.DIDXManagerError: Unsolicited connection requests to public DID is not enabled
After the previous fix was applied, a problem still exists. When the endorser is trying to respond to the connection request from the Tenant, it is getting a 403. Likely something in the Docker setup.
scripts-endorser-agent-1 | 2023-06-06 20:46:36,203 aries_cloudagent.transport.outbound.manager ERROR >>> Error when posting to: http://endorser-api:5000/webhook/topic/connections/; Error: (<class 'aries_cloudagent.transport.outbound.base.OutboundTransportError'>, OutboundTransportError('Unexpected response status 403, caused by: Forbidden',), <traceback object at 0x7fbee96aeac8>); Re-queue failed message ...
scripts-endorser-agent-1 | 2023-06-06 20:46:36,707 aries_cloudagent.transport.outbound.manager ERROR >>> Error when posting to: http://endorser-api:5000/webhook/topic/connections/; Error: (<class 'aries_cloudagent.transport.outbound.base.OutboundTransportError'>, OutboundTransportError('Unexpected response status 403, caused by: Forbidden',), <traceback object at 0x7fbee96aed48>); Re-queue failed message ...
scripts-endorser-agent-1 | 2023-06-06 20:46:36,759 aries_cloudagent.transport.outbound.manager ERROR >>> Error when posting to: http://endorser-api:5000/webhook/topic/connections/; Error: (<class 'aries_cloudagent.transport.outbound.base.OutboundTransportError'>, OutboundTransportError('Unexpected response status 403, caused by: Forbidden',), <traceback object at 0x7fbee96b4048>); Re-queue failed message ...
scripts-endorser-agent-1 | 2023-06-06 20:46:36,761 aries_cloudagent.transport.outbound.manager ERROR >>> Error when posting to: http://endorser-api:5000/webhook/topic/ping/; Error: (<class 'aries_cloudagent.transport.outbound.base.OutboundTransportError'>, OutboundTransportError('Unexpected response status 403, caused by: Forbidden',), <traceback object at 0x7fbee96b4288>); Re-queue failed message ...
scripts-endorser-agent-1 | 2023-06-06 20:46:46,112 aries_cloudagent.transport.outbound.manager ERROR >>> Error when posting to: http://endorser-api:5000/webhook/topic/connections/; Error: (<class 'aries_cloudagent.transport.outbound.base.OutboundTransportError'>, OutboundTransportError('Unexpected response status 403, caused by: Forbidden',), <traceback object at 0x7fbee96aef48>); Re-queue failed message ...
scripts-endorser-agent-1 | 2023-06-06 20:46:46,212 aries_cloudagent.transport.outbound.manager ERROR >>> Error when posting to: http://endorser-api:5000/webhook/topic/connections/; Error: (<class 'aries_cloudagent.transport.outbound.base.OutboundTransportError'>, OutboundTransportError('Unexpected response status 403, caused by: Forbidden',), <traceback object at 0x7fbee96ae0c8>); Re-queue failed message ...
scripts-endorser-agent-1 | 2023-06-06 20:46:46,716 aries_cloudagent.transport.outbound.manager ERROR >>> Error when posting to: http://endorser-api:5000/webhook/topic/connections/; Error: (<class 'aries_cloudagent.transport.outbound.base.OutboundTransportError'>, OutboundTransportError('Unexpected response status 403, caused by: Forbidden',), <traceback object at 0x7fbee9719688>); Re-queue failed message ...
scripts-endorser-agent-1 | 2023-06-06 20:46:46,768 aries_cloudagent.transport.outbound.manager ERROR >>> Error when posting to: http://endorser-api:5000/webhook/topic/connections/; Error: (<class 'aries_cloudagent.transport.outbound.base.OutboundTransportError'>, OutboundTransportError('Unexpected response status 403, caused by: Forbidden',), <traceback object at 0x7fbee96ac448>); Re-queue failed message ...
scripts-endorser-agent-1 | 2023-06-06 20:46:46,770 aries_cloudagent.transport.outbound.manager ERROR >>> Error when posting to: http://endorser-api:5000/webhook/topic/ping/; Error: (<class 'aries_cloudagent.transport.outbound.base.OutboundTransportError'>, OutboundTransportError('Unexpected response status 403, caused by: Forbidden',), <traceback object at 0x7fbee96acd88>); Re-queue failed message ...
scripts-endorser-agent-1 | 2023-06-06 20:46:56,126 aries_cloudagent.transport.outbound.manager ERROR >>> Outbound message failed to deliver, NOT Re-queued.
scripts-endorser-agent-1 | Traceback (most recent call last):
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/asyncio/tasks.py", line 180, in _step
scripts-endorser-agent-1 | result = coro.send(None)
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/site-packages/aries_cloudagent/transport/outbound/http.py", line 87, in handle_message
scripts-endorser-agent-1 | f"Unexpected response status {response.status}, "
scripts-endorser-agent-1 | aries_cloudagent.transport.outbound.base.OutboundTransportError: Unexpected response status 403, caused by: Forbidden
scripts-endorser-agent-1 | 2023-06-06 20:46:56,170 aries_cloudagent.transport.outbound.manager ERROR Outbound message could not be delivered to http://endorser-api:5000/webhook/topic/connections/
scripts-endorser-agent-1 | Traceback (most recent call last):
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/asyncio/tasks.py", line 180, in _step
scripts-endorser-agent-1 | result = coro.send(None)
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/site-packages/aries_cloudagent/transport/outbound/http.py", line 87, in handle_message
scripts-endorser-agent-1 | f"Unexpected response status {response.status}, "
scripts-endorser-agent-1 | aries_cloudagent.transport.outbound.base.OutboundTransportError: Unexpected response status 403, caused by: Forbidden
scripts-endorser-agent-1 | 2023-06-06 20:46:56,222 aries_cloudagent.transport.outbound.manager ERROR >>> Outbound message failed to deliver, NOT Re-queued.
scripts-endorser-agent-1 | Traceback (most recent call last):
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/asyncio/tasks.py", line 180, in _step
scripts-endorser-agent-1 | result = coro.send(None)
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/site-packages/aries_cloudagent/transport/outbound/http.py", line 87, in handle_message
scripts-endorser-agent-1 | f"Unexpected response status {response.status}, "
scripts-endorser-agent-1 | aries_cloudagent.transport.outbound.base.OutboundTransportError: Unexpected response status 403, caused by: Forbidden
scripts-endorser-agent-1 | 2023-06-06 20:46:56,271 aries_cloudagent.transport.outbound.manager ERROR Outbound message could not be delivered to http://endorser-api:5000/webhook/topic/connections/
scripts-endorser-agent-1 | Traceback (most recent call last):
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/asyncio/tasks.py", line 180, in _step
scripts-endorser-agent-1 | result = coro.send(None)
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/site-packages/aries_cloudagent/transport/outbound/http.py", line 87, in handle_message
scripts-endorser-agent-1 | f"Unexpected response status {response.status}, "
scripts-endorser-agent-1 | aries_cloudagent.transport.outbound.base.OutboundTransportError: Unexpected response status 403, caused by: Forbidden
scripts-endorser-agent-1 | 2023-06-06 20:46:56,728 aries_cloudagent.transport.outbound.manager ERROR >>> Outbound message failed to deliver, NOT Re-queued.
scripts-endorser-agent-1 | Traceback (most recent call last):
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/asyncio/tasks.py", line 180, in _step
scripts-endorser-agent-1 | result = coro.send(None)
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/site-packages/aries_cloudagent/transport/outbound/http.py", line 87, in handle_message
scripts-endorser-agent-1 | f"Unexpected response status {response.status}, "
scripts-endorser-agent-1 | aries_cloudagent.transport.outbound.base.OutboundTransportError: Unexpected response status 403, caused by: Forbidden
scripts-endorser-agent-1 | 2023-06-06 20:46:56,774 aries_cloudagent.transport.outbound.manager ERROR Outbound message could not be delivered to http://endorser-api:5000/webhook/topic/connections/
scripts-endorser-agent-1 | Traceback (most recent call last):
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/asyncio/tasks.py", line 180, in _step
scripts-endorser-agent-1 | result = coro.send(None)
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/site-packages/aries_cloudagent/transport/outbound/http.py", line 87, in handle_message
scripts-endorser-agent-1 | f"Unexpected response status {response.status}, "
scripts-endorser-agent-1 | aries_cloudagent.transport.outbound.base.OutboundTransportError: Unexpected response status 403, caused by: Forbidden
scripts-endorser-agent-1 | 2023-06-06 20:46:56,780 aries_cloudagent.transport.outbound.manager ERROR >>> Outbound message failed to deliver, NOT Re-queued.
scripts-endorser-agent-1 | Traceback (most recent call last):
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/asyncio/tasks.py", line 180, in _step
scripts-endorser-agent-1 | result = coro.send(None)
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/site-packages/aries_cloudagent/transport/outbound/http.py", line 87, in handle_message
scripts-endorser-agent-1 | f"Unexpected response status {response.status}, "
scripts-endorser-agent-1 | aries_cloudagent.transport.outbound.base.OutboundTransportError: Unexpected response status 403, caused by: Forbidden
scripts-endorser-agent-1 | 2023-06-06 20:46:56,781 aries_cloudagent.transport.outbound.manager ERROR Outbound message could not be delivered to http://endorser-api:5000/webhook/topic/connections/
scripts-endorser-agent-1 | Traceback (most recent call last):
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/asyncio/tasks.py", line 180, in _step
scripts-endorser-agent-1 | result = coro.send(None)
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/site-packages/aries_cloudagent/transport/outbound/http.py", line 87, in handle_message
scripts-endorser-agent-1 | f"Unexpected response status {response.status}, "
scripts-endorser-agent-1 | aries_cloudagent.transport.outbound.base.OutboundTransportError: Unexpected response status 403, caused by: Forbidden
scripts-endorser-agent-1 | 2023-06-06 20:46:56,783 aries_cloudagent.transport.outbound.manager ERROR >>> Outbound message failed to deliver, NOT Re-queued.
scripts-endorser-agent-1 | Traceback (most recent call last):
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/asyncio/tasks.py", line 180, in _step
scripts-endorser-agent-1 | result = coro.send(None)
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/site-packages/aries_cloudagent/transport/outbound/http.py", line 87, in handle_message
scripts-endorser-agent-1 | f"Unexpected response status {response.status}, "
scripts-endorser-agent-1 | aries_cloudagent.transport.outbound.base.OutboundTransportError: Unexpected response status 403, caused by: Forbidden
scripts-endorser-agent-1 | 2023-06-06 20:46:56,783 aries_cloudagent.transport.outbound.manager ERROR Outbound message could not be delivered to http://endorser-api:5000/webhook/topic/ping/
scripts-endorser-agent-1 | Traceback (most recent call last):
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/asyncio/tasks.py", line 180, in _step
scripts-endorser-agent-1 | result = coro.send(None)
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/site-packages/aries_cloudagent/transport/outbound/http.py", line 87, in handle_message
scripts-endorser-agent-1 | f"Unexpected response status {response.status}, "
scripts-endorser-agent-1 | aries_cloudagent.transport.outbound.base.OutboundTransportError: Unexpected response status 403, caused by: Forbidden
Further progress -- in my setup, "localhost" must be defined as the IP address of the machine running docker. Updated that, and I now can connect to the Endorser.
Failing on the "Register Public DID". Looking at the logs for the Endorser, it is trying to register the DID, but failing, getting a VDR Timeout. I've confirmed that the genesis file for the ledger is correct.
Sigh...
scripts-endorser-agent-1 | 2023-06-06 22:04:27,865 aries_cloudagent.core.conductor ERROR Exception in message handler:
scripts-endorser-agent-1 | Traceback (most recent call last):
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/site-packages/aries_cloudagent/ledger/indy_vdr.py", line 375, in _submit
scripts-endorser-agent-1 | request_result = await self.pool.handle.submit_request(request)
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/site-packages/indy_vdr/pool.py", line 115, in submit_request
scripts-endorser-agent-1 | result = await fut
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/asyncio/futures.py", line 327, in __iter__
scripts-endorser-agent-1 | yield self # This tells Task to wait for completion.
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/asyncio/tasks.py", line 250, in _wakeup
scripts-endorser-agent-1 | future.result()
scripts-endorser-agent-1 | File "/home/indy/.pyenv/versions/3.6.13/lib/python3.6/asyncio/futures.py", line 243, in result
scripts-endorser-agent-1 | raise self._exception
scripts-endorser-agent-1 | indy_vdr.error.VdrError: Pool timeout
The issue appears to be with BCovrin Test: the ledger is taking too long to respond, and it is causing the VDR timeout error. A similar result is achievable by using the ledger browser and searching for anything, as an example the nym SVfHGCEEvEFmpBPcxgNqRR
(the default endorser DID for the dockerized project). Pointing to BCovrin Dev by updating the references in the .env
file "fixes" the issue (i.e.: it is possible to connect to the endorser and register a public did for the tenant).
I suspect the problem might be the resources assigned to run the test ledger as it has grown in size exponentially. I will need to loop in @WadeBarnes to assess/increase resources as I do not have access to it anymore (new machine, new keys, etc.). We recently bumped the resources by quite a bit, but it seems like it might not be quite enough.
In the meantime, a couple of recommendations/suggestions for your scenario (if you haven't already done so):
ACAPY_ENDORSER_SEED
and ACAPY_ENDORSER_PUBLIC_DID
values in your .env
file, to avoid having another local instance of Traction "steal" your agent endpoint (overwriting it on startup)@swcurran, BCovrin Test was having some issues yesterday. I had to restart a couple nodes over the course of a couple hours. Things are looking better today if you'd like to try again.
I tried submitting a query to the ledger browser and it succeeded this time, although after a LONG wait.
I am, however, getting an error when trying to start-up the agents: it appears that they are unable to fetch the genesis transaction successfully.
I am, however, getting an error when trying to start-up the agents: it appears that they are unable to fetch the genesis transaction successfully.
Everything seems to be working fine now - I just tried and both endorser connection and public DID assignment work as expected.
There is definitely a difference in response time between resolving a DID and querying the ledger via the Ledger Browser. We need to fix up the ledger browser to deal with the volume of entries — e.g. limit the “search” to DIDs and index the transactions by DIDs on the ledger. Or use IndyScan instead.
Logged the ledger browser stuff in its repo: https://github.com/bcgov/von-network/issues/266 Let me know if/when things seem to work so I can close this issue.
I had to restart things again this morning at 7ish. The nodes had lost consensus some time yesterday, so writes weren't happening, and new connections may have been affected.
Cool — I’ll give it a try.
Extending this vs. opening a new issue.
I updated to the latest Traction, and then tried it, using a new DID that is unique to me setup. I registered the DID on BCovrin Test and confirmed it is there. Then I restarted everything and went through this sequence:
I then reverted to before the most recent merge and restarted -- commit bc4558b0. Rebuilt, restarted and repeated the steps and everything worked to the point above. @esune --- should I open a separate issue on that or could it have been something else.
With that working, I went into the Tenant and tried to become an issuer (User -> Profile -> Endorser) and the connection to the Endorser could not be established. Don't know what that was -- perhaps my ngrok had been active too long?
Logs on error with current main branch:
Error is AxiosError: Request fails with status 404 Logs:
scripts-traction-agent-1 | =================
scripts-traction-agent-1 | Traceback (most recent call last):
scripts-traction-agent-1 | File "/home/indy/traction_plugins/traction_innkeeper/v1_0/innkeeper/routes.py", line 69, in wrapper
scripts-traction-agent-1 | ret = await func(request)
scripts-traction-agent-1 | File "/home/indy/traction_plugins/traction_innkeeper/v1_0/innkeeper/routes.py", line 400, in tenant_config_update
scripts-traction-agent-1 | tenant_record = await TenantRecord.retrieve_by_id(session, tenant_id)
scripts-traction-agent-1 | File "/home/indy/.venv/lib/python3.6/site-packages/aries_cloudagent/messaging/models/base_record.py", line 239, in retrieve_by_id
scripts-traction-agent-1 | cls.RECORD_TYPE, record_id, {"forUpdate": for_update, "retrieveTags": False}
scripts-traction-agent-1 | File "/home/indy/.venv/lib/python3.6/site-packages/aries_cloudagent/storage/askar.py", line 95, in get_record
scripts-traction-agent-1 | raise StorageNotFoundError(f"Record not found: {record_type}/{record_id}")
scripts-traction-agent-1 | aries_cloudagent.storage.error.StorageNotFoundError: Record not found: innkeeper_tenant/undefined
@swcurran ngrok
WILL timeout any active tunnel after a certain amount of time. You might be able to work around this by signing-up for a free account and adding your token to the ngrok
container - see here for an example.
I just checked out the latest main (d3c3be5, rebuilt everything and starting from scratch and was able to connect to the endorser and create a public DID without issues. I would suggest trying starting with a clean slate again.
Additionally, if you customized settings in the .env
file let me know what you changed so I can try with similar settings to the best of my possibilities - not sure whether that could cause issues (other than the endorser did change).
The stack trace seems to indicate the id of the innkeeper tenant is undefined in the request, and this is causing an error.
I have Traction running locally using docker compose. I'd like to use the Endorser to be able to write transactions to the BCovrin Network. Here's how far I have gotten so far:
In the Traction Dashboard -> User -> Profile -> Endorser, there is a message
Innkeeper has not approved endorser connections.
In the Innkeeper -> Tenants -> Settings I can activate the Endorser and registering a Public DID.
Back in the Traction Dashboard -> User -> Profile -> Endorser, I can now toggle the "Connect Tenant To Endorser", but after activating it, the status stays at
Connection not Active yet, refresh or come back later. State: request
.I tried looking at the Endorser side, and according to the "Get Connections" endpoint, the Endorser
has one connection and it is activehas no connections.What do I do next? I think the .env settings are all correct, but not sure...what should I be checking?