Stuck at QVI Issues LE vLEI Credential Step in running the reg-pilot test scenario workflow

[ronakseth96]

While executing the reg-pilot scenarios for the verification test against the RootsID keria instance (using rootsid-test profiles in resolve-env.ts with no witnesses), the workflow halts at the credential issuance phase. The AIDs and the registry are created successfully, but the process fails at the QVI issues LE vLEI credential step, preventing the issuance from completing.

Steps to reproduce:

• Run the reg-pilot workflow scenarios using the rootsid-test profile, with the WORKFLOW set to issue-credentials-singlesig-single-user.yaml
• AIDs are created successfully.
• Registry is created successfully.
• The workflow enters the credential issuance phase.
• The process halts with the following message:

Executing: QVI issues LE vLEI credential
at executeStep (run-vlei-issuance-workflow.test.ts:35:13)

The test fails with the following console log error:

FAIL  test/run-vlei-issuance-workflow.test.ts (94.791 s)
  ✕ issue-credentials (76705 ms)

  ● issue-credentials

    assert(received)

    Expected value to be equal to:
      true
    Received:
      false

      349 |       credHolder = await retry(async () => {
      350 |         const cCred = await getReceivedCredential(recipientClient, cred.sad.d);
    > 351 |         assert(cCred !== undefined);
          |               ^
      352 |         return cCred;
      353 |       }, CRED_RETRY_DEFAULTS);
      354 |     }

      at ../src/vlei-issuance.ts:351:15
      at async retry (utils/retry.ts:34:22)
      at async SingleSigVleiIssuance.getOrIssueCredential (../src/vlei-issuance.ts:349:20)
      at async executeStep (run-vlei-issuance-workflow.test.ts:37:7)
      at async runWorkflow (run-vlei-issuance-workflow.test.ts:30:7)
      at async Object.run (run-vlei-issuance-workflow.test.ts:56:5)
Test Suites: 1 failed, 1 total
Tests:       1 failed, 1 total
Snapshots:   0 total
Time:        95.335 s

[ronakseth96]

We also tried to inspect the cred object returned by the getOrIssueCredential function. We could see the start of the credential issuance, followed by a display of the detailed contents of the issued credential. Attached below, it seems that the function returned a properly structured credential, which leads us to believe that the issuance process was successful.

console.log
  Executing: QVI issues LE vLEI credential

    at executeStep (run-vlei-issuance-workflow.test.ts:35:13)

console.log
  cred

    at SingleSigVleiIssuance.getOrIssueCredential (../src/vlei-issuance.ts:329:13)

console.log
  {
    sad: {
      v: 'ACDC10JSON0005c8_',
      d: 'ENVhiP799NREM6mAfdWCNaDwntPFsMbFEoFVmKxkB9hT',
      i: 'ECc9rtWqndns6wj3x9sulFXcorz3UtScN7OoljPcHQR9',
      ri: 'EEiItVBrHd5JfrZoh6kLIlk9c66lEq9b6-vNgFpT1GNP',
      s: 'ENPXp1vQzRF6JwIuS-mp2U8Uf1MoADoP_GqQ62VsDZWY',
      a: {
        d: 'EK7xtsWiJFmZaZ9_UmxIH0DOEU4pg-QhqZV8jgApjDck',
        i: 'EJOCPg_UR_8AtHUcusYGzxFXbfI0vivRjnpeIAyWogtZ',
        LEI: '875500ELOZEL05BVXV37',
        dt: '2024-10-04T15:40:51.242000+00:00'
      },
      e: {
        d: 'EFSWdzos7KxRwWneZie6329s0ZeVwTvc9o2aaWt1_uk0',
        qvi: [Object]
      },
      r: {
        d: 'EGZ97EjPSINR-O-KHDN_uw4fdrTxeuRXrqT5ZHHQJujQ',
        usageDisclaimer: [Object],
        issuanceDisclaimer: [Object]
      }
    },
    atc: '-IABENVhiP799NREM6mAfdWCNaDwntPFsMbFEoFVmKxkB9hT0AAAAAAAAAAAAAAAAAAAAAAAENVhiP799NREM6mAfdWCNaDwntPFsMbFEoFVmKxkB9hT',
    ...
  }

However, the test case is failing with the error:

✕ issue-credentials (76705 ms)

assert(received)
Expected value to be equal to:
  true
Received:
  false

[ronakseth96]

Keria instance logs:

keri: Verifier unescrow failed: credential identifier EMZmfu8j7kpTvZ29f_8jqEclQEEqav0nValnmCWw0_P_ not in Tevers

keri: Verifier unescrow failed: Failure to verify credential ENVhiP799NREM6mAfdWCNaDwntPFsMbFEoFVmKxkB9hT chain qvi(
EMZmfu8j7kpTvZ29f_8jqEclQEEqav0nValnmCWw0_P_)

keri: Tevery unescrow failed: Failure verify event = {'v': 'KERI10JSON0000ed_', 't': 'iss', 'd': 'EML14KIe1cdl07sXJ89JSfmpCkRvCO5y15sV1q9lva2F', 
'i': 'EMZmfu8j7kpTvZ29f_8jqEclQEEqav0nValnmCWw0_P_', 's': '0', 'ri': 'EEy1Q86GEukuDAOXGOyHEZ_QSUhjzoVfQ960G8IJu2Fr', 
'dt': '2024-10-04T15:40:31.433000+00:00'}

[ronakseth96]

Additional KERIA instance logs:

keri: Kevery unescrow failed: keri.kering.QueryNotFoundError: Query not found error={'v': 'KERI10JSON000110_', 't': 'qry', 'd': 'EMoIdAqDblDIU424VjW91MZt5dpv_6gpmyI4xkD4Jt5h', 'dt': '2024-11-06T00:27:32.483113+00:00', 'r': 'logs', 'rr': '', 'q': {'s': '0', 'fn': '0', 'i': 'EEsjnPxiIvuEI8AtP-frV_0ilvAr-Y8X2zoovCmEAbAd', 'src': 'EEDJrpPKX2re_l-YH6yQbOhLW1N2stMXxixuxJSO_bow'}}. 
Traceback (most recent call last): 
File "/keria/venv/lib/python3.12/site-packages/keri/core/eventing.py", line 6020, in processQueryNotFound 
self.processQuery(serder=eserder, source=source, sigers=sigers, cigars=cigars) 
File "/keria/venv/lib/python3.12/site-packages/keri/core/eventing.py", line 4614, in processQuery 
raise QueryNotFoundError("Query not found error={}.".format(ked)) 
keri.kering.QueryNotFoundError: Query not found error={'v': 'KERI10JSON000110_', 't': 'qry', 'd': 'EMoIdAqDblDIU424VjW91MZt5dpv_6gpmyI4xkD4Jt5h', 'dt': '2024-11-06T00:27:32.483113+00:00', 'r': 'logs', 'rr': '', 'q': {'s': '0', 'fn': '0', 'i': 'EEsjnPxiIvuEI8AtP-frV_0ilvAr-Y8X2zoovCmEAbAd', 'src': 'EEDJrpPKX2re_l-YH6yQbOhLW1N2stMXxixuxJSO_bow'}}.

keri: Kevery process: escrowed query not found event=
{
"v": "KERI10JSON000110_",
"t": "qry",
"d": "EMoIdAqDblDIU424VjW91MZt5dpv_6gpmyI4xkD4Jt5h",
"dt": "2024-11-06T00:27:32.483113+00:00",
"r": "logs",
"rr": "",
"q": {
"s": "0",
"fn": "0",
"i": "EEsjnPxiIvuEI8AtP-frV_0ilvAr-Y8X2zoovCmEAbAd",
"src": "EEDJrpPKX2re_l-YH6yQbOhLW1N2stMXxixuxJSO_bow"
}
}

keri: Tever state: Escrowed anchorless event event = {'v': 'KERI10JSON0000ed_', 't': 'iss', 'd': 'EIxxmJm3NFkHU3AAksD8uUJ4QbXexh_ihczln8-kQqxa', 'i': 'EJ1z9SEkYdhO1v2u2XxzQfytwuUAhm1F86Y5rnvquAgK', 's': '0', 'ri': 'EEuCXNG2eaDHdqn5a3V27JY08d9rjzURUE7FLpsdejBC', 'dt': '2024-11-06T01:07:13.827000+00:00'}
keri: Tevery unescrow failed: Failure verify event = {'v': 'KERI10JSON0000ed_', 't': 'iss', 'd': 'EIxxmJm3NFkHU3AAksD8uUJ4QbXexh_ihczln8-kQqxa', 'i': 'EJ1z9SEkYdhO1v2u2XxzQfytwuUAhm1F86Y5rnvquAgK', 's': '0', 'ri': 'EEuCXNG2eaDHdqn5a3V27JY08d9rjzURUE7FLpsdejBC', 'dt': '2024-11-06T01:07:13.827000+00:00'} 
Traceback (most recent call last):
   File "/keria/venv/lib/python3.12/site-packages/keri/vdr/eventing.py", line 2132, in processEscrowAnchorless
     self.processEvent(serder=tserder, seqner=seqner, saider=saider, wigers=bigers)
   File "/keria/venv/lib/python3.12/site-packages/keri/vdr/eventing.py", line 1597, in processEvent
     tever.update(serder=serder, seqner=seqner, saider=saider, bigers=wigers)
   File "/keria/venv/lib/python3.12/site-packages/keri/vdr/eventing.py", line 926, in update
     self.issue(serder, seqner=seqner, saider=saider, sn=sn, bigers=bigers)
   File "/keria/venv/lib/python3.12/site-packages/keri/vdr/eventing.py", line 1063, in issue
     raise MissingAnchorError("Failure verify event = {} "
 keri.kering.MissingAnchorError: Failure verify event = {'v': 'KERI10JSON0000ed_', 't': 'iss', 'd': 'EIxxmJm3NFkHU3AAksD8uUJ4QbXexh_ihczln8-kQqxa', 'i': 'EJ1z9SEkYdhO1v2u2XxzQfytwuUAhm1F86Y5rnvquAgK', 's': '0', 'ri': 'EEuCXNG2eaDHdqn5a3V27JY08d9rjzURUE7FLpsdejBC', 'dt': '2024-11-06T01:07:13.827000+00:00'}