Error processing attestation code :: No issuer found for attestion code

[cmcewen]

Expected Behavior

Users able to complete verification

Current Behavior

One of the three text messages resulted in this error.

Info [2020-07-16T17:14:11.355Z] identity/verification@attestationCodeReceiver :: Error processing attestation code :: No issuer found for attestion code in index.android.bundle:1884:11497

Can provide more specific information if needed

[aslawson]

Update:
Issuer 0xDdbca691842FD452d8F53575FdFdC2314eb3AD57 did not trigger an AttestationCompleted event for mobile and it's history in the attestation data shows IsCompleted = false

The error is coming from here which seems like it could only be caused by the signature being incorrect since it appears to include all three issuers when retrieving them from onchain

When running the function that caused the area with each code, all the results responded successfully and returns one of the three issuers as its source.

[aslawson]

This leads us to suspect its something specific to the lightnode running on the user's phone. We confirmed that the user has a 64 bit device. Next step is to to build geth for a 64 bit arm and run this test in a 64 bit arm docker container.

[aslawson]

We confirmed this is not a signature verification issue or anything related to the 64-bit geth client when calling findMatchingIssuer. Ivan tested on an android ARM64 bit device, and I did so with geth-linux-arm64 build running on docker. Both instances returned the expected message mapping to each of the attestation services.

Issuer1: 0xDdbca691842FD452d8F53575FdFdC2314eb3AD57
Msg1: celo://wallet/v/5vuL14KNEbtiGJb0rMTxorAEvxoZ/s+FGNXJ+F/1pVF87CMLSlo68dFaC+NeIiLmEsA3U0yt8mjM66LT7NqeDBs=

Issuer2: 0x7b3859147B1C173FfF7182E58A4Ec81C1d287224
Msg2: celo://wallet/v/lNeEQhZ2lyq+5ltsLHAl/KvjTMubBrS7NMpPMFaTCsosDS1Q3KaJeL74kEFN4nXZBy4nIc/5E6qIapGKgzNxnRw=

Issuer3: 0x48aC52662CBF32f8FC0cd8c1122c7560b482c2AD
Msg3: celo://wallet/v/g24qWPX2qL9Wyut2wX47EBh9Wa/7L+LvvpWaYbswZFEMOgN//GeCjnNBk3b15h+24bQLHka2bLyw+kF0Eg9lkxw=

I confirmed on-chain that Issuer1 is the issuer that is still in the INCOMPLETE state.

I dug further into Martin’s logs. Unfortunately, we do not have logs from the original verification flow, but we have logs from a re-attempt with just the missing attestation. In this attempt, it identifies that 2/3 attestations are complete and that Issuer1 is remaining.

Info [2020-07-16T17:14:00.517Z] ValoraAnalytics/Tracking event verification_fetch_status_complete with properties: {"timestamp":1594919640513,"sessionId":"65d5d1c0e8619ad2ce3be53e8323ffa245e72f07d960b31d5d0be3ee8955d8","userAddress":"0xe76313cd887929044a472e0cfa48c9e47d15b69a","**isVerified":false,"numAttestationsRemaining":1,"total":3,"completed":2}**

According to the slack discussion, the user was confident that he was sending Msg2 even though it corresponds to a COMPLETED issuer (Issuer2). Based on the slack conversation the other two messages return "Code already exists" errors.

This message in this logged attempt did not receive a "Code already exists" error and moved to the next line in the code where it called findMatchingIssuer passing in Issuer1 only -- confirmed from the logs:

verification_request_all_attestations_complete with properties: {"timestamp":1594919642821,"sessionId":"65d5d1c0e8619ad2ce3be53e8323ffa245e72f07d960b31d5d0be3ee8955d8","userAddress":"0xe76313cd887929044a472e0cfa48c9e47d15b69a","issuers":["**0xDdbca691842FD452d8F53575FdFdC2314eb3AD57**”]}

If this was indeed called with Msg2, that would explain why findMatchingIssuer returns "No issuer found for attestion code" error, since only Issuer1 was in the array to compare and that is not a match.

I cannot explain how Msg1 was marked as an acceptedAttestationCodes in the user state and Msg2 was incorrectly unmarked. I’ve tried to dig into the mobile flow to see where there could have been a race condition that would allow them to be mixed up, but I can’t find anything. Any ideas from mobile folks @cmcewen @i1skn? I’ll can try to see if there are different logs/events I can dig into to understand what initially happened on the first verification attempt.

[i1skn]

[UPDATE] After I've talked with the user it seems that scenario I've described below is very similar to what has happened, so I've opened #4557 to fix this.

I've done some small investigation and found something, that might be related to this issue.

If we look here:

celo-monorepo/packages/mobile/src/identity/reducer.ts

Lines 132 to 137 in 938730c

	case Actions.INPUT_ATTESTATION_CODE:
	return {
	...state,
	attestationCodes: [...state.attestationCodes, action.code],
	acceptedAttestationCodes: [...state.acceptedAttestationCodes, action.code],
	}

we see that we add code to both attestationCodes and acceptedAttestationCodes on INPUT_ATTESTATION_CODE, which triggered right after some basic checks for the code and before actual smart contract call. If something goes wrong between INPUT_ATTESTATION_CODE and COMPLETE_ATTESTATION_CODE we would have wrong state (failed code would be in acceptedAttestationCodes).

There is a workaround to prevent this:

celo-monorepo/packages/mobile/src/identity/reducer.ts

Lines 122 to 125 in 938730c

	// Reset accepted codes on fail otherwise there's no way for user
	// to try again with same codes
	acceptedAttestationCodes:
	action.status === VerificationStatus.Failed ? [] : state.acceptedAttestationCodes,

but what if a failed code did not trigger VerificationStatus.Failed because one of try { ... } catch has handle it?

I assume that earlier any error during the code entering should've lead to VerificationStatus.Failed, but we actually want to change it, so more and more errors become recoverable.

I think that this might be related to the issue, because if we look at the log:

• 1st code - we got No issuer found for attestation code error
• 2nd and 3rd - we got Code already exists error. This means, that acceptedAttestationCodes was not empty, which means VerificationStatus.Failed was not triggered earlier.

In the following scenario this issue could occur:

• User enters the 1st code successfully. acceptedAttestationCodes = [code1].
• User enters the 2nd code and we got an error, which leads to VerificationStatus.Failed status. Hence acceptedAttestationCodes = [].
• User tries again the 2nd code and this time successfully. acceptedAttestationCodes = [code2]
• User enters the 3rd code and we got an error, which we handle and it DOES NOT lead to VerificationStatus.Failed. acceptedAttestationCodes = [code2, code3].
• Some time later
• User enters code3 and code2, but we say they have been already used. acceptedAttestationCodes = [code2, code3]
• User enters code1, but we say No issuer found for attestation code, because we have finished with it and erased this fact from the state.

[jmrossy]

@aslawson @i1skn Great work hunting this down so far.

I think Ivan's assessment just above is probably right.

earlier any error during the code entering should've lead to VerificationStatus.Failed

@i1skn that's correct. Given that the interplay between UI + Saga for verification is quite complex, we need to be careful about any changes to state management and error handling.