DIDComm Message Decryption + Disruption by eth_getLogs/eth_getChainId calls

[radleylewis]

Problem

In our use case we are decrypting didcomm messages within the context of our custom MetaMask Snap. This process is quite time consuming (up to approx. 100 seconds). Our specific use case does not invoke calls to the network, however, Veramo (via the provider) does invoke the eth_getLogs and eth_getChainId calls using ethers. In the case of their failure (i.e. in the case the RPC provider comes back with an error, for example, a rate limit), the long running decryption process (i.e. the decryption) is interrupted. Therefore, there are two components to this issue we are facing:

1. Decryption Time: Why would the decryption take so long? In our case decrypting the DIDComm message (jwe encoded) takes around or over 100 seconds;
2. Error Handling/Unnecessary Calls: Where calls to the network are not required, such as the case described above, what is the case for these calls?

Solution

As it relates to the decryption time any feedback or insight you can provide on the matter is greatly appreciated. As it pertains to the provider calls on eth_getChainId and eth_getLogs errors bubbling up and cancelling the other processes - even when the aforementioned calls do not appear to be required - it would appear that these could be deactivated.

Other Questions

Any information you can provide on this is greatly appreciated. If we can align on the solution, we would be happy to present a PR, but wanted to sync up here first.

Screenshot
Example of offending calls within the background.html in the MetaMask Snap.

[mirceanis]

I can venture some guesses as to what's happening but without a sample to reproduce the issue it'll be harder to provide a clear solution.

The calls to the network:

• eth_getLogs is needed by the ethr-did-resolver to resolve a did:ethr.
  The more history a did:ethr has, the more calls to getLogs it will require to resolve.
• eth_chainId is used by ethers to confirm that the call is going to the right chain. This can be reduced by creating the provider outside of Veramo and supplying it in the configuration for ethr-did-resolver instead of the rpcUrl. the provider should use the staticNetwork option like so:

import { getResolver } from 'ethr-did-resolver'

// see https://chainlist.org/ for more RPC options
const SEPOLIA_RPC_URL =  `https://ethereum-sepolia-rpc.publicnode.com`;
const SEPOLIA_CHAIN_ID = 11155111;
const network = Network.from(SEPOLIA_CHAIN_ID);
const provider = new JsonRpcProvider(SEPOLIA_RPC_URL, network, { staticNetwork: network });
const ethrResolver = getResolver({
 networks: [{
     chainId: SEPOLIA_CHAIN_ID,
     name: 'sepolia',
     registry: '0x03d5003bf0e79C5F5223588F347ebA39AfbC3818',
     legacyNonce: false,
     provider: provider
   }]
});

The long decrypting time.

This is very hard to pinpoint without a sample JWE+privateKey to try it locally, BUT there may be some things you can do to speed things up.
I suspect that a major slowdown is the DID resolution. For a JWE that's encrypted using authcrypt, at least 2 DID resolutions take place: one for the sender and one for the receiver DID. For anoncrypt only the receiver DID is resolved.
This is compounded by the fact that @veramo/did-comm doesn't use any sort of caching for the DID resolution, as it relies on the functionality from @veramo/did-resolver. Our examples don't show how to use caching for DID resolution as we don't have a smart caching layer (yet) and it may lead to DIDs resolving to older versions even after calls to didManagerAddKey and other methods that should update them.

import { Resolver } from 'did-resolver'

const resolver = new Resolver({ 
  ...ethrResolver,  // use the ethr resolver configured earlier
  // ... other resolvers here
}, { cache: true }); // <<< ENABLE CACHING FOR DID RESOLUTION

const agent = createAgent({
  plugins: [
     new DIDResolverPlugin({ resolver: resolver })
     // ... other plugins
  ],
})

You can implement your own caching mechanism. See how the inMemoryCache is implemented here. Then, instead of supplying { cache: true } to the Resolver options, you use { cache: YourOwnCachingLayer }

Notes

Configuring an agent like above will result in DID documents that are cached for the lifetime of the Resolver instance, which might not be desirable, but you have some options:

• Veramo agents are free to create, so you can create a new agent with DID caching just for JWE decryption (and all other configs can remain the same)
• Implement your own caching mechanism and clear the cache after calling agent.didManager...() methods.

Long term, the did:ethr resolver should have its own caching layer for the results of evm_getLogs as the logs it uses to build up DID documents can be safely cached. Since it's an append-only list of events, there should be no need to invalidate the cache to purge older events.

---

I hope this helps. Please provide updates if you implement these suggestions as you're surely not the only ones encountering this

[mirceanis]

@radleylewis were you able to discover the cause of the slowdown?

[radleylewis]

@mirceanis thanks for the follow up. Your advice was on point and we took the approach of caching the resolved DIDDoc, not only in the context of the MetaMask Snap (with respect to our frontend) but also on the server.

For reference the delay was completely attributable to the resolution of the DIDDoc (as you had suggested) as evidenced by the below:

Our solution for reference (and hopefully that others may use) implemented a derivative of the cache example that you provided (altered for suitablility within the MetaMask Snap):

export const snapCache = (): DIDCache => {
  const state = StorageService.get();

  return async (parsed: ParsedDID, resolve) => {
    if (parsed.params && parsed.params['no-cache'] === 'true') return resolve();
    const rawDid = parsed.didUrl;
    const cached = state.didDocCacheState[did];
    let needResolve = false;
    if (!cached) needResolve = true;

    if (cached) {
      const now = new Date();
      const timeDiffSinceLastResolved =
        now.getTime() - new Date(cached.lastResolvedDate).getTime();
      const minuteInMillisec = 60 * 1000;
      if (timeDiffSinceLastResolved > 10 * minuteInMillisec) needResolve = true;
    }

    if (needResolve) {
      const result = await resolve();
      const onChainEd25519Keys = fetchOnChainEd25519Keys(result);
      const onChainX25519Keys = fetchOnChainX25519Keys(result);

      // !Note: Make sure to have at least 1 ed25519, x22519 key  & service endpoint on chain
      // before caching
      // This is cater for our use case and might not flexible enough for generic use
      if (
        result.didResolutionMetadata.error !== 'notFound' &&
        onChainX25519Keys.length > 0 &&
        onChainEd25519Keys.length > 0 &&
        result.didDocument?.service &&
        result.didDocument.service.length > 0
      ) {
        state.didDocCacheState[did] = {
          lastResolvedDate: new Date(),
          didResolution: result,
        };
        StorageService.set(state);
        await StorageService.save();
      }
      return result;
    } else return cached.didResolution;
  };
};

In the context of the server we have a similar approach but one which uses redis for the memory cache as opposed to the snapManagedState in the MetaMask Snap.