Credential Verification Failures

[WadeBarnes]

Credential verification can fail frequently with the following error in the API.

WARNING 2020-03-23 14:27:03,576 views 1 140535789180672 >>> Verify credential
INFO 2020-03-23 14:27:03,678 base 1 140535514212096 BaseAnchor.get_schema: got schema HR6vs6GEZ8rHaVgjg2WodM:2:registration.registries.ca:1.0.42 from cache
INFO 2020-03-23 14:27:03,679 base 1 140535514212096 BaseAnchor.get_cred_def: got cred def for HR6vs6GEZ8rHaVgjg2WodM:3:CL:41051:tag from cache
WARNING 2020-03-23 14:27:03,680 libindy 1 140535514212096 _do_call: Function indy_prover_create_proof returned error 113
ERROR 2020-03-23 14:27:03,681 service 1 140535514212096 Exception while handling request:
Traceback (most recent call last):
  File "/home/indy/.pyenv/versions/3.6.9/lib/python3.6/site-packages/vonx/common/service.py", line 255, in _handle_message
    reply = await self._service_request(request)
  File "/home/indy/.pyenv/versions/3.6.9/lib/python3.6/site-packages/vonx/indy/service.py", line 1492, in _service_request
    request.holder_id, request.proof_req, request.cred_ids)
  File "/home/indy/.pyenv/versions/3.6.9/lib/python3.6/site-packages/vonx/indy/service.py", line 925, in _construct_proof
    request_params,
  File "/home/indy/.pyenv/versions/3.6.9/lib/python3.6/site-packages/von_anchor/anchor/holderprover.py", line 1088, in create_proof
    json.dumps(rr_id2rev_state))
  File "/home/indy/.pyenv/versions/3.6.9/lib/python3.6/site-packages/indy/anoncreds.py", line 1617, in prover_create_proof
    prover_create_proof.cb)
indy.error.CommonInvalidStructure
ERROR 2020-03-23 14:27:03,684 views 1 140535789180672 Credential verification error:
Traceback (most recent call last):
  File "/home/indy/api_indy/tob_anchor/views.py", line 543, in verify_credential
    proof = await proof_manager.construct_proof_async()
  File "/home/indy/api_indy/indy/proof.py", line 46, in construct_proof_async
    self.credential_ids,
  File "/home/indy/.pyenv/versions/3.6.9/lib/python3.6/site-packages/vonx/indy/client.py", line 376, in construct_proof
    messages.ConstructedProof)
  File "/home/indy/.pyenv/versions/3.6.9/lib/python3.6/site-packages/vonx/indy/client.py", line 61, in _fetch
    raise IndyClientError(result.value)
vonx.indy.errors.IndyClientError: Exception while handling request
INFO 2020-03-23 14:27:03,686 helpers 1 140535789180672 172.51.120.1 [23/Mar/2020:14:27:03 +0000] "GET /api/v2/credential/5/verify HTTP/1.0" 200 314 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) 

Uptime robot is indicating downtime on credential verification calls due to the above error. The call to https://orgbook.gov.bc.ca/api/credential/5/verify for example will return 200 regardless of whether the verification fails or succeeds, but when it fails it does not return the verification results that the monitor is looking for, instead it returns error results. A subsequent call to the same URL returns the expected verification results. Making it appear as though the reported downtime is a false positive.

Example of the returned error message:

{"success": false, "result": "Credential verification error: Exception while handling request"}

This issue can be reproduced by repeatedly requesting the same verification over and over (Ctrl-F5). The error will between every 3 to 20 refreshes.

The issue is occurring in dev, test, and prod.

[WadeBarnes]

Here are the error logs with debug logging. Testing performed in the test environment using https://test.orgbook.gov.bc.ca/api/credential/5/verify.

ErrorWithDebugLogging.txt

[swcurran]

Found this in the Indy channel about nonces beginning with 0 being a problem - https://chat.hyperledger.org/channel/indy?msg=ewszhz5mxpno3xfDx

Noticed that the error log above has a nonce beginning with a 0 (or two).

[ianco]

https://github.com/bcgov/TheOrgBook/pull/876