Skip to content

Commit 3e4ece7

Browse files
authored
🐛 Fix publishing all pending AnonCreds revocations (#3626)
* 🎨 Improve logging for `revoke_pending_credentials` Signed-off-by: ff137 <[email protected]> * 🐛 Fix `limit_crids=[]` skipping all revocations Signed-off-by: ff137 <[email protected]> * 🎨 Replace unnecessary json.dumps Signed-off-by: ff137 <[email protected]> * 🧪 Expand test coverage Signed-off-by: ff137 <[email protected]> --------- Signed-off-by: ff137 <[email protected]>
1 parent abc31d3 commit 3e4ece7

File tree

2 files changed

+210
-27
lines changed

2 files changed

+210
-27
lines changed

acapy_agent/anoncreds/revocation.py

Lines changed: 88 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -1208,19 +1208,33 @@ async def revoke_pending_credentials(
12081208
Tuple with the update revocation list, list of cred rev ids not revoked
12091209
12101210
"""
1211+
LOGGER.info(
1212+
"Starting revocation process for registry %s with "
1213+
"additional_crids=%s, limit_crids=%s",
1214+
revoc_reg_id,
1215+
additional_crids,
1216+
limit_crids,
1217+
)
12111218
updated_list = None
12121219
failed_crids = set()
12131220
max_attempt = 5
12141221
attempt = 0
12151222

12161223
while True:
12171224
attempt += 1
1225+
LOGGER.debug("Revocation attempt %d/%d", attempt, max_attempt)
12181226
if attempt >= max_attempt:
1227+
LOGGER.error(
1228+
"Max attempts (%d) reached while trying to update registry %s",
1229+
max_attempt,
1230+
revoc_reg_id,
1231+
)
12191232
raise AnonCredsRevocationError(
12201233
"Repeated conflict attempting to update registry"
12211234
)
12221235
try:
12231236
async with self.profile.session() as session:
1237+
LOGGER.debug("Fetching revocation registry data for %s", revoc_reg_id)
12241238
rev_reg_def_entry = await session.handle.fetch(
12251239
CATEGORY_REV_REG_DEF, revoc_reg_id
12261240
)
@@ -1231,6 +1245,11 @@ async def revoke_pending_credentials(
12311245
CATEGORY_REV_REG_DEF_PRIVATE, revoc_reg_id
12321246
)
12331247
except AskarError as err:
1248+
LOGGER.error(
1249+
"Failed to retrieve revocation registry data for %s: %s",
1250+
revoc_reg_id,
1251+
str(err),
1252+
)
12341253
raise AnonCredsRevocationError(
12351254
"Error retrieving revocation registry"
12361255
) from err
@@ -1240,41 +1259,53 @@ async def revoke_pending_credentials(
12401259
or not rev_list_entry
12411260
or not rev_reg_def_private_entry
12421261
):
1262+
missing_data = []
1263+
if not rev_reg_def_entry:
1264+
missing_data.append("revocation registry definition")
1265+
if not rev_list_entry:
1266+
missing_data.append("revocation list")
1267+
if not rev_reg_def_private_entry:
1268+
missing_data.append("revocation registry private definition")
1269+
LOGGER.error(
1270+
"Missing required revocation registry data for %s: %s",
1271+
revoc_reg_id,
1272+
", ".join(missing_data),
1273+
)
12431274
raise AnonCredsRevocationError(
1244-
(
1245-
"Missing required revocation registry data: "
1246-
"revocation registry definition"
1247-
if not rev_reg_def_entry
1248-
else ""
1249-
),
1250-
"revocation list" if not rev_list_entry else "",
1251-
(
1252-
"revocation registry private definition"
1253-
if not rev_reg_def_private_entry
1254-
else ""
1255-
),
1275+
f"Missing required revocation registry data: {' '.join(missing_data)}"
12561276
)
12571277

12581278
try:
12591279
async with self.profile.session() as session:
1280+
cred_def_id = rev_reg_def_entry.value_json["credDefId"]
1281+
LOGGER.debug("Fetching credential definition %s", cred_def_id)
12601282
cred_def_entry = await session.handle.fetch(
1261-
CATEGORY_CRED_DEF, rev_reg_def_entry.value_json["credDefId"]
1283+
CATEGORY_CRED_DEF, cred_def_id
12621284
)
12631285
except AskarError as err:
1286+
LOGGER.error(
1287+
"Failed to retrieve credential definition %s: %s",
1288+
cred_def_id,
1289+
str(err),
1290+
)
12641291
raise AnonCredsRevocationError(
1265-
f"Error retrieving cred def {rev_reg_def_entry.value_json['credDefId']}" # noqa: E501
1292+
f"Error retrieving cred def {cred_def_id}"
12661293
) from err
12671294

12681295
try:
12691296
# TODO This is a little rough; stored tails location will have public uri
12701297
# but library needs local tails location
1298+
LOGGER.debug("Deserializing revocation registry data")
12711299
rev_reg_def = RevRegDef.deserialize(rev_reg_def_entry.value_json)
12721300
rev_reg_def.value.tails_location = self.get_local_tails_path(rev_reg_def)
12731301
cred_def = CredDef.deserialize(cred_def_entry.value_json)
12741302
rev_reg_def_private = RevocationRegistryDefinitionPrivate.load(
12751303
rev_reg_def_private_entry.value_json
12761304
)
12771305
except AnoncredsError as err:
1306+
LOGGER.error(
1307+
"Failed to load revocation registry definition: %s", str(err)
1308+
)
12781309
raise AnonCredsRevocationError(
12791310
"Error loading revocation registry definition"
12801311
) from err
@@ -1286,21 +1317,29 @@ async def revoke_pending_credentials(
12861317
cred_revoc_ids = (rev_info["pending"] or []) + (additional_crids or [])
12871318
rev_list = RevList.deserialize(rev_info["rev_list"])
12881319

1320+
LOGGER.info(
1321+
"Processing %d credential revocation IDs for registry %s",
1322+
len(cred_revoc_ids),
1323+
revoc_reg_id,
1324+
)
1325+
12891326
for rev_id in cred_revoc_ids:
12901327
if rev_id < 1 or rev_id > max_cred_num:
12911328
LOGGER.error(
12921329
"Skipping requested credential revocation "
1293-
"on rev reg id %s, cred rev id=%s not in range",
1330+
"on rev reg id %s, cred rev id=%s not in range (1-%d)",
12941331
revoc_reg_id,
12951332
rev_id,
1333+
max_cred_num,
12961334
)
12971335
failed_crids.add(rev_id)
12981336
elif rev_id >= rev_info["next_index"]:
12991337
LOGGER.warning(
13001338
"Skipping requested credential revocation "
1301-
"on rev reg id %s, cred rev id=%s not yet issued",
1339+
"on rev reg id %s, cred rev id=%s not yet issued (next_index=%d)",
13021340
revoc_reg_id,
13031341
rev_id,
1342+
rev_info["next_index"],
13041343
)
13051344
failed_crids.add(rev_id)
13061345
elif rev_list.revocation_list[rev_id] == 1:
@@ -1315,15 +1354,26 @@ async def revoke_pending_credentials(
13151354
rev_crids.add(rev_id)
13161355

13171356
if not rev_crids:
1357+
LOGGER.info(
1358+
"No valid credentials to revoke for registry %s", revoc_reg_id
1359+
)
13181360
break
13191361

1320-
if limit_crids is None:
1362+
if limit_crids is None or limit_crids == []:
13211363
skipped_crids = set()
13221364
else:
13231365
skipped_crids = rev_crids - set(limit_crids)
13241366
rev_crids = rev_crids - skipped_crids
13251367

1368+
LOGGER.info(
1369+
"Revoking %d credentials, skipping %d credentials for registry %s",
1370+
len(rev_crids),
1371+
len(skipped_crids),
1372+
revoc_reg_id,
1373+
)
1374+
13261375
try:
1376+
LOGGER.debug("Updating revocation list with new revocations")
13271377
updated_list = await asyncio.get_event_loop().run_in_executor(
13281378
None,
13291379
lambda: rev_list.to_native().update(
@@ -1336,25 +1386,31 @@ async def revoke_pending_credentials(
13361386
),
13371387
)
13381388
except AnoncredsError as err:
1389+
LOGGER.error("Failed to update revocation registry: %s", str(err))
13391390
raise AnonCredsRevocationError(
13401391
"Error updating revocation registry"
13411392
) from err
13421393

13431394
try:
13441395
async with self.profile.transaction() as txn:
1396+
LOGGER.debug("Saving updated revocation list")
13451397
rev_info_upd = await txn.handle.fetch(
13461398
CATEGORY_REV_LIST, revoc_reg_id, for_update=True
13471399
)
13481400
if not rev_info_upd:
13491401
LOGGER.warning(
1350-
f"Revocation registry missing, skipping update: {revoc_reg_id}" # noqa: E501
1402+
"Revocation registry %s missing during update, skipping",
1403+
revoc_reg_id,
13511404
)
13521405
updated_list = None
13531406
break
13541407
tags = rev_info_upd.tags
13551408
rev_info_upd = rev_info_upd.value_json
13561409
if rev_info_upd != rev_info:
1357-
# handle concurrent update to the registry by retrying
1410+
LOGGER.debug(
1411+
"Concurrent update detected for registry %s, retrying",
1412+
revoc_reg_id,
1413+
)
13581414
continue
13591415
rev_info_upd["rev_list"] = updated_list.to_dict()
13601416
rev_info_upd["pending"] = (
@@ -1368,18 +1424,30 @@ async def revoke_pending_credentials(
13681424
tags=tags,
13691425
)
13701426
await txn.commit()
1427+
LOGGER.info(
1428+
"Successfully updated revocation list for registry %s",
1429+
revoc_reg_id,
1430+
)
13711431
except AskarError as err:
1432+
LOGGER.error("Failed to save revocation registry: %s", str(err))
13721433
raise AnonCredsRevocationError(
13731434
"Error saving revocation registry"
13741435
) from err
13751436
break
13761437

1377-
return RevokeResult(
1438+
result = RevokeResult(
13781439
prev=rev_list,
13791440
curr=RevList.from_native(updated_list) if updated_list else None,
13801441
revoked=list(rev_crids),
13811442
failed=[str(rev_id) for rev_id in sorted(failed_crids)],
13821443
)
1444+
LOGGER.info(
1445+
"Completed revocation process for registry %s: %d revoked, %d failed",
1446+
revoc_reg_id,
1447+
len(result.revoked),
1448+
len(result.failed),
1449+
)
1450+
return result
13831451

13841452
async def mark_pending_revocations(self, rev_reg_def_id: str, *crids: int):
13851453
"""Cred rev ids stored to publish later."""

acapy_agent/anoncreds/tests/test_revocation.py

Lines changed: 122 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1,10 +1,11 @@
11
import http
2-
import json
32
import os
43
from unittest import IsolatedAsyncioTestCase
54

65
import pytest
76
from anoncreds import (
7+
AnoncredsError,
8+
AnoncredsErrorCode,
89
Credential,
910
CredentialDefinition,
1011
RevocationRegistryDefinition,
@@ -1220,15 +1221,15 @@ async def test_revoke_pending_credentials(
12201221
AskarError(code=AskarErrorCode.UNEXPECTED, message="test"),
12211222
# missing rev reg def
12221223
None,
1223-
MockEntry(value_json=json.dumps({})),
1224-
MockEntry(value_json=json.dumps({})),
1224+
MockEntry(value_json="{}"),
1225+
MockEntry(value_json="{}"),
12251226
# missing rev list
1226-
MockEntry(value_json=json.dumps({})),
1227+
MockEntry(value_json="{}"),
12271228
None,
1228-
MockEntry(value_json=json.dumps({})),
1229+
MockEntry(value_json="{}"),
12291230
# missing rev private
1230-
MockEntry(value_json=json.dumps({})),
1231-
MockEntry(value_json=json.dumps({})),
1231+
MockEntry(value_json="{}"),
1232+
MockEntry(value_json="{}"),
12321233
None,
12331234
]
12341235
)
@@ -1297,6 +1298,120 @@ async def test_revoke_pending_credentials(
12971298
assert mock_deserialize_cred_def.called
12981299
assert isinstance(result, test_module.RevokeResult)
12991300

1301+
@mock.patch.object(AskarAnoncredsProfileSession, "handle")
1302+
@mock.patch.object(RevList, "to_native")
1303+
@mock.patch.object(RevList, "from_native", return_value=None)
1304+
@mock.patch.object(RevRegDef, "to_native")
1305+
@mock.patch.object(CredDef, "deserialize")
1306+
@mock.patch.object(RevocationRegistryDefinitionPrivate, "load")
1307+
async def test_revoke_pending_credentials_cred_def_error(
1308+
self,
1309+
mock_load_rev_reg,
1310+
mock_deserialize_cred_def,
1311+
mock_rev_reg_to_native,
1312+
mock_rev_list_from_native,
1313+
mock_rev_list_to_native,
1314+
mock_handle,
1315+
):
1316+
"""Test error handling when fetching credential definition fails."""
1317+
mock_handle.fetch = mock.CoroutineMock(
1318+
side_effect=[
1319+
MockEntry(value_json=MOCK_REV_REG_DEF),
1320+
MockEntry(
1321+
value_json={
1322+
"pending": [0, 1, 4, 3],
1323+
"next_index": 4,
1324+
"rev_list": rev_list.serialize(),
1325+
}
1326+
),
1327+
MockEntry(),
1328+
AskarError(code=AskarErrorCode.UNEXPECTED, message="test error"),
1329+
]
1330+
)
1331+
1332+
with self.assertRaises(test_module.AnonCredsRevocationError) as cm:
1333+
await self.revocation.revoke_pending_credentials(
1334+
revoc_reg_id="test-rev-reg-id",
1335+
)
1336+
assert "Error retrieving cred def" in str(cm.exception)
1337+
1338+
@mock.patch.object(AskarAnoncredsProfileSession, "handle")
1339+
@mock.patch.object(RevList, "to_native")
1340+
@mock.patch.object(RevList, "from_native", return_value=None)
1341+
@mock.patch.object(RevRegDef, "to_native")
1342+
@mock.patch.object(CredDef, "deserialize")
1343+
@mock.patch.object(RevocationRegistryDefinitionPrivate, "load")
1344+
async def test_revoke_pending_credentials_anoncreds_error(
1345+
self,
1346+
mock_load_rev_reg,
1347+
mock_deserialize_cred_def,
1348+
mock_rev_reg_to_native,
1349+
mock_rev_list_from_native,
1350+
mock_rev_list_to_native,
1351+
mock_handle,
1352+
):
1353+
"""Test error handling when loading revocation registry definition fails."""
1354+
mock_handle.fetch = mock.CoroutineMock(
1355+
side_effect=[
1356+
MockEntry(value_json=MOCK_REV_REG_DEF),
1357+
MockEntry(
1358+
value_json={
1359+
"pending": [0, 1, 4, 3],
1360+
"next_index": 4,
1361+
"rev_list": rev_list.serialize(),
1362+
}
1363+
),
1364+
MockEntry(),
1365+
MockEntry(),
1366+
]
1367+
)
1368+
mock_deserialize_cred_def.side_effect = AnoncredsError(
1369+
AnoncredsErrorCode.UNEXPECTED, "Failed to load"
1370+
)
1371+
1372+
with self.assertRaises(test_module.AnonCredsRevocationError) as cm:
1373+
await self.revocation.revoke_pending_credentials(
1374+
revoc_reg_id="test-rev-reg-id",
1375+
)
1376+
assert "Error loading revocation registry definition" in str(cm.exception)
1377+
1378+
@mock.patch.object(AskarAnoncredsProfileSession, "handle")
1379+
@mock.patch.object(RevList, "to_native")
1380+
@mock.patch.object(RevList, "from_native", return_value=None)
1381+
@mock.patch.object(RevRegDef, "to_native")
1382+
@mock.patch.object(CredDef, "deserialize")
1383+
@mock.patch.object(RevocationRegistryDefinitionPrivate, "load")
1384+
async def test_revoke_pending_credentials_no_valid_credentials(
1385+
self,
1386+
mock_load_rev_reg,
1387+
mock_deserialize_cred_def,
1388+
mock_rev_reg_to_native,
1389+
mock_rev_list_from_native,
1390+
mock_rev_list_to_native,
1391+
mock_handle,
1392+
):
1393+
"""Test handling when there are no valid credentials to revoke."""
1394+
mock_handle.fetch = mock.CoroutineMock(
1395+
side_effect=[
1396+
MockEntry(value_json=MOCK_REV_REG_DEF),
1397+
MockEntry(
1398+
value_json={
1399+
"pending": [], # No pending revocations
1400+
"next_index": 4,
1401+
"rev_list": rev_list.serialize(),
1402+
}
1403+
),
1404+
MockEntry(),
1405+
MockEntry(),
1406+
]
1407+
)
1408+
1409+
result = await self.revocation.revoke_pending_credentials(
1410+
revoc_reg_id="test-rev-reg-id",
1411+
)
1412+
assert result.revoked == [] # No credentials were revoked
1413+
assert result.failed == [] # No failures
1414+
13001415
@mock.patch.object(AskarAnoncredsProfileSession, "handle")
13011416
async def test_mark_pending_revocations(self, mock_handle):
13021417
mock_handle.fetch = mock.CoroutineMock(

0 commit comments

Comments
 (0)