Intermittent test failure with TestContractMigration and FF10277

[peterbroadhurst]

Occurred in https://github.com/hyperledger/firefly/pull/1296 run https://github.com/hyperledger/firefly/actions/runs/4871762457/jobs/8689186525?pr=1296

logs 17.txt

{"name":"test_1683116741440968188","members":[{"identity":"org_9571df"},{"identity":"org_11bbf0"}]}}
    restclient.go:116: 2023-05-03T12:26:00.712068565Z: <== 500
    restclient.go:118: <!! {"error":"FF10277: Identity could not be resolved via lookup string 'org_11bbf0'"}
    restclient.go:119: Headers: map[Content-Length:[83] Content-Type:[application/json] Date:[Wed, 03 May 2023 12:26:00 GMT] Vary:[Origin]]
    restclient.go:499: Sent private message  to [{Identity:org_9571df Node:} {Identity:org_11bbf0 Node:}]
    contract_migration.go:180: 
            Error Trace:    /home/runner/work/firefly/firefly/test/e2e/runners/contract_migration.go:180
                                        /home/runner/work/firefly/firefly/test/e2e/runners/contract_migration.go:51
            Error:          Not equal: 
                            expected: 202
                            actual  : 500
            Test:           TestEthereumMultipartyE2ESuite/TestContractMigration

[awrichar]

Few more notes from a look through the logs...

• This failure happens during TestContractMigration (around 12:26:00)
• This is the first time during this test that it attempts to resolve org_11bbf0
• This identity was resolved correctly during the previous test (around 12:25:40)
• TestContractMigration creates an entirely new namespace and re-registers org/node identities to run the test

Therefore this is likely an issue with identity registration in the new namespace.

[peterbroadhurst]

ok, yeah I can see the registration happened after the error:

firefly_core_0_1  | [2023-05-03T12:26:00.711Z]  INFO <-- POST /api/v1/namespaces/e2e_f186fbebf4/messages/private [500] (1.01ms): FF10277: Identity could not be resolved via lookup string 'org_11bbf0' httpreq=w6E_kNbf pid=1 req=GgLOpacR

firefly_core_0_1  | [2023-05-03T12:26:00.792Z]  INFO Emitted message_confirmed event 78fa04f7-903c-4b71-910b-ac70bc4b1d81 for e2e_f186fbebf4:3a744f1f-f69d-4af1-94a8-123d39df08e9 (correlator=,topic=156a88237266c7317d4d510dec075d6cb9e37dc21d2ed69385ba0e60bac916a2) dbtx=60r1DiHH ns=e2e_f186fbebf4 pid=1 role=aggregator
firefly_core_0_1  | [2023-05-03T12:26:00.792Z]  INFO Emitted message_confirmed event 78fa04f7-903c-4b71-910b-ac70bc4b1d81 for e2e_f186fbebf4:3a744f1f-f69d-4af1-94a8-123d39df08e9 (correlator=,topic=156a88237266c7317d4d510dec075d6cb9e37dc21d2ed69385ba0e60bac916a2) dbtx=60r1DiHH ns=e2e_f186fbebf4 pid=1 role=aggregator
firefly_core_0_1  | [2023-05-03T12:26:00.792Z] DEBUG Queuing rewind for author DID did:firefly:org/org_11bbf0 ns=e2e_f186fbebf4 pid=1 role=aggregator
firefly_core_0_1  | [2023-05-03T12:26:00.792Z] DEBUG Queuing rewind for author DID did:firefly:node/org_11bbf0_node ns=e2e_f186fbebf4 pid=1 role=aggregator

[peterbroadhurst]

ok - this is a test issue, we need to wait for the orgs to propagate to the other node.

[peterbroadhurst]

Created a candidate fix in https://github.com/hyperledger/firefly/pull/1298 🤞