Firefly is missing identity details, causing all calls to the firefly contract to be rejected

[sapient]

trafficstars

Hi, I am trying to run Firefly with a Besu network, however, when I first call http://localhost:5000/api/v1/network/organizations/self?confirm=true, the request times out. The block browser indicates that the call to the contract was successful, however the FF logs indicate that the result was rejected because the caller key was not recognized.

[2023-06-28T09:47:39.907Z] ERROR Ignoring network action batch_pin from unknown identity 0x66f683f75f726e1d47321d8d0ff3775b5546ee33 ns=default pid=1 role=event-manager

I have reproduced this error over and over again while trying different configurations. However I had an almost exact replica of this setup running on the Polygon Mumbai testnet about a month ago, so I believe this may be caused by a fairly recent regression.

Steps to reproduce

1. Setup a dev Besu network (npx quorum-dev-quickstart, default options, no private transactions)
2. Ensure Besu is started with free gas by checking the QBFT genesis json and adding "zeroBaseFee": true if it is missing
3. Start the Besu network and deploy the Firefly contract using one of the default Besu wallets from the genesis json.
4. Run ff init with the following options

ff init ethereum sdx 1 \
 --multiparty=true \
 -n remote-rpc \
 --remote-node-url http://host.docker.internal:8545 \
 --chain-id 1337 \
 --contract-address ${Contract address from step 2}

5. Start ff, and POST to /api/v1/network/organizations/self?confirm=true

Expected

The org identity should be claimed, and I should be able to claim the network identity next.

Actual result

The transactions executes successfully on the chain, however when the result is returned, it is rejected as being from an unrecognized identity. Nothing is returned from Firefly and the POST times out after 2 minutes.

Logging into the ff-core container and running select * from identities; shows that there are no records at all in the table.

Extra thanks to @matthew1001 who has been helping me debug this error and I believe he has also reproduced it.

[matthew1001]

Thanks for raising this @sapient Yeah I can recreate the same behaviour locally and one of the differences in the logs between the working case (where identities are registered by the ff-cli) and the failing case (where identities are registered manually) is that on processing the batch pin event, in the successful case we see:

[2023-06-29T13:51:51.191Z] DEBUG Verifier '0x44d2885bec70019d7af1f0cb83190bb070da14a2' not found dbtx=CXBrMDu5 ns=default pid=1 role=aggregator
[2023-06-29T13:51:51.191Z]  INFO Processing system definition 'ff_identity_claim' [6f611455-3b81-4ee7-98c3-64e1320ca0d5] dbtx=CXBrMDu5 ns=default pid=1 role=aggregator

So the verifier isn't found (because it's currently being registered) but there is a call showing that it is being treated as a system definition, which ultimately results in the identity and verifier being added to the DB:

[2023-06-29T13:51:51.195Z] DEBUG SQL-> insert verifiers dbtx=CXBrMDu5 ns=default pid=1 role=aggregator
[2023-06-29T13:51:51.196Z] DEBUG SQL<- insert verifiers sequences=[1] dbtx=CXBrMDu5 ns=default pid=1 role=aggregator 
[2023-06-29T13:51:51.196Z] DEBUG SQL-> insert identities dbtx=CXBrMDu5 ns=default pid=1 role=aggregator
[2023-06-29T13:51:51.197Z] DEBUG SQL<- insert identities sequences=[1] dbtx=CXBrMDu5 ns=default pid=1 role=aggregator

In the failing case we simply see:

[2023-06-29T14:16:06.961Z] DEBUG Verifier '0x3c584f63cc838935a4626e07a1ddf90c8df31a1d' not found ns=default pid=1 role=event-manager
[2023-06-29T14:16:06.961Z] ERROR Ignoring network action batch_pin from unknown identity 0x3c584f63cc838935a4626e07a1ddf90c8df31a1d ns=default pid=1 role=event-manager

The ff-cli was changed in https://github.com/hyperledger/firefly-cli/commit/a48eb82f60961ceba59d03dbdfc76c795d726fcf to skip registration at start time if a custom contract address has been passed in. I haven't tried building a branch of ff-cli with auto-registration even if the custom contract address has been provided, because I suspect it was done intentionally and that the bug here is the failure to register successfully by calilng the .../self endpoints.

@nguyer I know you're on vacation currently so ignore this until you're back, but wanted to tag you in as you might be able to shed light on the expected behaviour when you're in the office.

[nguyer]

@sapient Thanks for opening this. Definitely doesn't sound like the expected behavior to me. Is this running on the latest release, or on a newer build from main?

Does the log message: [2023-06-28T09:47:39.907Z] ERROR Ignoring network action batch_pin from unknown identity 0x66f683f75f726e1d47321d8d0ff3775b5546ee33 ns=default pid=1 role=event-manager appear on the FireFly node that is attempting to register, or on another node?

@matthew1001 The only reason the FireFly CLI doesn't automatically register identities on a remote chain, is that it doesn't want to assume that the price of gas is free on that chain. If it is not, you may not have had a chance to add any tokens to pay for gas yet at that point during the startup.

[sapient]

@nguyer The message is appearing on the node which is attempting to register the identity. As for version, I believe its just the newest main version.

❯ ff version
{
  "Version": "v1.2.1",
  "License": "Apache-2.0"
}

[awrichar]

Sounds related to https://github.com/hyperledger/firefly/issues/1221 / https://github.com/hyperledger/firefly/pull/1224