From 2ecfb182210e14cb0e1b344a4eda0e8c60f6ee86 Mon Sep 17 00:00:00 2001 From: Sheldon Regular Date: Mon, 12 Jan 2026 11:55:09 -0500 Subject: [PATCH 1/3] DIF presentation debug logging Signed-off-by: Sheldon Regular --- .../present_proof/dif/pres_exch_handler.py | 12 ++ .../present_proof/v2_0/formats/dif/handler.py | 111 ++++++++++++++++++ .../v2_0/formats/dif/tests/test_handler.py | 29 +++++ 3 files changed, 152 insertions(+) diff --git a/acapy_agent/protocols/present_proof/dif/pres_exch_handler.py b/acapy_agent/protocols/present_proof/dif/pres_exch_handler.py index ddede4fb31..78ee692e70 100644 --- a/acapy_agent/protocols/present_proof/dif/pres_exch_handler.py +++ b/acapy_agent/protocols/present_proof/dif/pres_exch_handler.py @@ -1067,6 +1067,12 @@ async def apply_requirements( result = {} # Get all input_descriptors attached to the PresentationDefinition descriptor_list = req.input_descriptors or [] + LOGGER.debug( + "DIF-PRES apply_requirements: descriptors=%s creds=%s records_filter=%s", + len(descriptor_list), + len(credentials), + list(records_filter.keys()) if records_filter else None, + ) for descriptor in descriptor_list: # Filter credentials to apply filtering # upon by matching each credentialSchema.id @@ -1090,6 +1096,12 @@ async def apply_requirements( constraints=descriptor.constraint, credentials=filtered_by_schema, ) + LOGGER.debug( + "DIF-PRES apply_requirements: descriptor=%s schema_filtered=%s constraints_filtered=%s", + descriptor.id, + len(filtered_by_schema), + len(filtered), + ) if len(filtered) != 0: result[descriptor.id] = filtered diff --git a/acapy_agent/protocols/present_proof/v2_0/formats/dif/handler.py b/acapy_agent/protocols/present_proof/v2_0/formats/dif/handler.py index d0cb0d0bef..cb4571c583 100644 --- a/acapy_agent/protocols/present_proof/v2_0/formats/dif/handler.py +++ b/acapy_agent/protocols/present_proof/v2_0/formats/dif/handler.py @@ -167,6 +167,15 @@ async def create_pres( if not challenge: challenge = str(uuid4()) input_descriptors = pres_definition.input_descriptors + LOGGER.debug( + "DIF-PRES create_pres: pres_ex_id=%s thread_id=%s pd_id=%s input_descriptors=%s issuer_id=%s record_ids=%s", + pres_ex_record.pres_ex_id, + pres_ex_record.thread_id, + pres_definition.id if pres_definition else None, + len(input_descriptors) if input_descriptors else 0, + issuer_id, + len(limit_record_ids) if limit_record_ids else 0, + ) claim_fmt = pres_definition.fmt dif_handler_proof_type = None try: @@ -200,6 +209,14 @@ async def create_pres( uri_list = None if len(one_of_uri_groups) == 0: one_of_uri_groups = None + LOGGER.debug( + "DIF-PRES descriptor=%s oneof=%s uri_list=%s uri_groups=%s limit_disclosure=%s", + input_descriptor.id, + bool(one_of_uri_groups), + uri_list, + one_of_uri_groups, + limit_disclosure, + ) if limit_disclosure: proof_type = [BbsBlsSignature2020.signature_type] dif_handler_proof_type = BbsBlsSignature2020.signature_type @@ -321,6 +338,13 @@ async def create_pres( ) max_results = 1000 cred_group = await search.fetch(max_results) + LOGGER.debug( + "DIF-PRES search(oneof): descriptor=%s uris=%s proof_types=%s results=%s", + input_descriptor.id, + uri_group, + proof_type, + len(cred_group), + ) ( cred_group_vcrecord_list, cred_group_vcrecord_ids_set, @@ -337,6 +361,13 @@ async def create_pres( # For now, setting to 1000 max_results = 1000 records = await search.fetch(max_results) + LOGGER.debug( + "DIF-PRES search: descriptor=%s uris=%s proof_types=%s results=%s", + input_descriptor.id, + uri_list, + proof_type, + len(records), + ) # Avoiding addition of duplicate records ( @@ -345,6 +376,12 @@ async def create_pres( ) = await self.process_vcrecords_return_list(records, record_ids) record_ids = vcrecord_ids_set credentials_list = credentials_list + vcrecord_list + LOGGER.debug( + "DIF-PRES candidates: descriptor=%s added=%s total=%s", + input_descriptor.id, + len(vcrecord_list), + len(credentials_list), + ) except StorageNotFoundError as err: raise V20PresFormatHandlerError(err) @@ -376,6 +413,14 @@ async def create_pres( reveal_doc=reveal_doc_frame, ) try: + LOGGER.debug( + "DIF-PRES create_vp: pres_ex_id=%s thread_id=%s proof_type=%s creds=%s records_filter=%s", + pres_ex_record.pres_ex_id, + pres_ex_record.thread_id, + dif_handler_proof_type, + len(credentials_list), + len(limit_record_ids) if limit_record_ids else 0, + ) pres = await dif_handler.create_vp( challenge=challenge, domain=domain, @@ -469,6 +514,14 @@ async def verify_pres(self, pres_ex_record: V20PresExRecord) -> V20PresExRecord: dif_proof = pres_ex_record.pres.attachment(DIFPresFormatHandler.format) pres_request = pres_ex_record.pres_request.attachment(DIFPresFormatHandler.format) pres_ver_result = None + log_details = self._profile.settings.get("debug.presentations") + + LOGGER.debug( + "DIF-PRES verify_pres: pres_ex_id=%s thread_id=%s proof_is_sequence=%s", + pres_ex_record.pres_ex_id, + pres_ex_record.thread_id, + isinstance(dif_proof, Sequence), + ) if isinstance(dif_proof, Sequence): if len(dif_proof) == 0: raise V20PresFormatHandlerError( @@ -476,23 +529,81 @@ async def verify_pres(self, pres_ex_record: V20PresExRecord) -> V20PresExRecord: ) for proof in dif_proof: manager, options = self._get_type_manager_options(proof, pres_request) + proof_type = (proof.get("proof") or {}).get("type") + LOGGER.debug( + "DIF-PRES verify_pres: proof_type=%s manager=%s", + proof_type, + manager.__class__.__name__, + ) pres_ver_result = await manager.verify_presentation( vp=VerifiablePresentation.deserialize(proof), options=options, ) + LOGGER.debug( + "DIF-PRES verify_pres result: verified=%s errors=%s", + pres_ver_result.verified, + pres_ver_result.errors, + ) + if log_details: + LOGGER.debug( + "DIF-PRES verify_pres details: presentation_result=%s credential_results=%s", + self._summarize_doc_result(pres_ver_result.presentation_result), + [ + self._summarize_doc_result(r) + for r in (pres_ver_result.credential_results or []) + ], + ) if not pres_ver_result.verified: break else: manager, options = self._get_type_manager_options(dif_proof, pres_request) + proof_type = (dif_proof.get("proof") or {}).get("type") + LOGGER.debug( + "DIF-PRES verify_pres: proof_type=%s manager=%s", + proof_type, + manager.__class__.__name__, + ) pres_ver_result = await manager.verify_presentation( vp=VerifiablePresentation.deserialize(dif_proof), options=options, ) + LOGGER.debug( + "DIF-PRES verify_pres result: verified=%s errors=%s", + pres_ver_result.verified, + pres_ver_result.errors, + ) + if log_details: + LOGGER.debug( + "DIF-PRES verify_pres details: presentation_result=%s credential_results=%s", + self._summarize_doc_result(pres_ver_result.presentation_result), + [ + self._summarize_doc_result(r) + for r in (pres_ver_result.credential_results or []) + ], + ) assert pres_ver_result is not None pres_ex_record.verified = json.dumps(pres_ver_result.verified) return pres_ex_record + @staticmethod + def _summarize_doc_result(doc_result: Optional["DocumentVerificationResult"]): + if not doc_result: + return None + proof_results = [ + { + "verified": pr.verified, + "error": pr.error, + "purpose_error": getattr(pr.purpose_result, "error", None), + } + for pr in (doc_result.results or []) + ] + return { + "verified": doc_result.verified, + "errors": doc_result.errors, + "proof_results": proof_results, + } + def _get_type_manager_options(self, dif_proof: dict, pres_request: dict): """Get the type of manager and options based on the proof type.""" if dif_proof.get("proof") and dif_proof["proof"]["type"] == "DataIntegrityProof": diff --git a/acapy_agent/protocols/present_proof/v2_0/formats/dif/tests/test_handler.py b/acapy_agent/protocols/present_proof/v2_0/formats/dif/tests/test_handler.py index ed9a6713b2..61577bbf66 100644 --- a/acapy_agent/protocols/present_proof/v2_0/formats/dif/tests/test_handler.py +++ b/acapy_agent/protocols/present_proof/v2_0/formats/dif/tests/test_handler.py @@ -12,6 +12,11 @@ from .......tests import mock from .......utils.testing import create_test_profile, skip_on_jsonld_url_error from .......vc.ld_proofs import DocumentLoader +from .......vc.ld_proofs.validation_result import ( + DocumentVerificationResult, + ProofResult, + PurposeResult, +) from .......vc.vc_di.manager import VcDiManager from .......vc.vc_ld.manager import VcLdpManager from .......vc.vc_ld.validation_result import PresentationVerificationResult @@ -2379,3 +2384,27 @@ async def test_get_type_manager_options(self): manager, options = handler._get_type_manager_options(dif_proof, pres_request) assert isinstance(manager, VcLdpManager) assert options.challenge == "3fa85f64-5717-4562-b3fc-2c963f66afa7" + + async def test_summarize_doc_result_redacts_sensitive_fields(self): + self.profile = await create_test_profile() + handler = DIFPresFormatHandler(self.profile) + doc_result = DocumentVerificationResult( + verified=False, + document={"id": "doc", "proof": {"proofValue": "secret"}}, + results=[ + ProofResult( + verified=False, + proof={"proofValue": "secret"}, + error="bad proof", + purpose_result=PurposeResult(valid=False, error="purpose failed"), + ) + ], + errors=["verification failed"], + ) + summary = handler._summarize_doc_result(doc_result) + assert summary["verified"] is False + assert summary["errors"] == ["verification failed"] + assert "document" not in summary + assert "proof" not in summary["proof_results"][0] + assert summary["proof_results"][0]["error"] == "bad proof" + assert summary["proof_results"][0]["purpose_error"] == "purpose failed" From 57468c0a11f0ecf609639ad6e28b450147042969 Mon Sep 17 00:00:00 2001 From: Sheldon Regular Date: Mon, 12 Jan 2026 16:02:12 -0500 Subject: [PATCH 2/3] fixed ruff failures Signed-off-by: Sheldon Regular --- .../present_proof/dif/pres_exch_handler.py | 3 ++- .../present_proof/v2_0/formats/dif/handler.py | 24 ++++++++++++------- 2 files changed, 18 insertions(+), 9 deletions(-) diff --git a/acapy_agent/protocols/present_proof/dif/pres_exch_handler.py b/acapy_agent/protocols/present_proof/dif/pres_exch_handler.py index 78ee692e70..be32d44d0b 100644 --- a/acapy_agent/protocols/present_proof/dif/pres_exch_handler.py +++ b/acapy_agent/protocols/present_proof/dif/pres_exch_handler.py @@ -1097,7 +1097,8 @@ async def apply_requirements( credentials=filtered_by_schema, ) LOGGER.debug( - "DIF-PRES apply_requirements: descriptor=%s schema_filtered=%s constraints_filtered=%s", + "DIF-PRES apply_requirements: descriptor=%s schema_filtered=%s " + "constraints_filtered=%s", descriptor.id, len(filtered_by_schema), len(filtered), diff --git a/acapy_agent/protocols/present_proof/v2_0/formats/dif/handler.py b/acapy_agent/protocols/present_proof/v2_0/formats/dif/handler.py index cb4571c583..826de355d2 100644 --- a/acapy_agent/protocols/present_proof/v2_0/formats/dif/handler.py +++ b/acapy_agent/protocols/present_proof/v2_0/formats/dif/handler.py @@ -21,6 +21,7 @@ from ......vc.vc_ld.manager import VcLdpManager from ......vc.vc_ld.models.options import LDProofVCOptions from ......vc.vc_ld.models.presentation import VerifiablePresentation +from ......vc.ld_proofs.validation_result import DocumentVerificationResult from .....problem_report.v1_0.message import ProblemReport from ....dif.pres_exch import PresentationDefinition, SchemaInputDescriptor from ....dif.pres_exch_handler import DIFPresExchError, DIFPresExchHandler @@ -168,7 +169,8 @@ async def create_pres( challenge = str(uuid4()) input_descriptors = pres_definition.input_descriptors LOGGER.debug( - "DIF-PRES create_pres: pres_ex_id=%s thread_id=%s pd_id=%s input_descriptors=%s issuer_id=%s record_ids=%s", + "DIF-PRES create_pres: pres_ex_id=%s thread_id=%s pd_id=%s " + "input_descriptors=%s issuer_id=%s record_ids=%s", pres_ex_record.pres_ex_id, pres_ex_record.thread_id, pres_definition.id if pres_definition else None, @@ -210,7 +212,8 @@ async def create_pres( if len(one_of_uri_groups) == 0: one_of_uri_groups = None LOGGER.debug( - "DIF-PRES descriptor=%s oneof=%s uri_list=%s uri_groups=%s limit_disclosure=%s", + "DIF-PRES descriptor=%s oneof=%s uri_list=%s uri_groups=%s " + "limit_disclosure=%s", input_descriptor.id, bool(one_of_uri_groups), uri_list, @@ -339,7 +342,8 @@ async def create_pres( max_results = 1000 cred_group = await search.fetch(max_results) LOGGER.debug( - "DIF-PRES search(oneof): descriptor=%s uris=%s proof_types=%s results=%s", + "DIF-PRES search(oneof): descriptor=%s uris=%s " + "proof_types=%s results=%s", input_descriptor.id, uri_group, proof_type, @@ -362,7 +366,8 @@ async def create_pres( max_results = 1000 records = await search.fetch(max_results) LOGGER.debug( - "DIF-PRES search: descriptor=%s uris=%s proof_types=%s results=%s", + "DIF-PRES search: descriptor=%s uris=%s proof_types=%s " + "results=%s", input_descriptor.id, uri_list, proof_type, @@ -414,7 +419,8 @@ async def create_pres( ) try: LOGGER.debug( - "DIF-PRES create_vp: pres_ex_id=%s thread_id=%s proof_type=%s creds=%s records_filter=%s", + "DIF-PRES create_vp: pres_ex_id=%s thread_id=%s proof_type=%s " + "creds=%s records_filter=%s", pres_ex_record.pres_ex_id, pres_ex_record.thread_id, dif_handler_proof_type, @@ -546,7 +552,8 @@ async def verify_pres(self, pres_ex_record: V20PresExRecord) -> V20PresExRecord: ) if log_details: LOGGER.debug( - "DIF-PRES verify_pres details: presentation_result=%s credential_results=%s", + "DIF-PRES verify_pres details: presentation_result=%s " + "credential_results=%s", self._summarize_doc_result(pres_ver_result.presentation_result), [ self._summarize_doc_result(r) @@ -574,7 +581,8 @@ async def verify_pres(self, pres_ex_record: V20PresExRecord) -> V20PresExRecord: ) if log_details: LOGGER.debug( - "DIF-PRES verify_pres details: presentation_result=%s credential_results=%s", + "DIF-PRES verify_pres details: presentation_result=%s " + "credential_results=%s", self._summarize_doc_result(pres_ver_result.presentation_result), [ self._summarize_doc_result(r) @@ -587,7 +595,7 @@ async def verify_pres(self, pres_ex_record: V20PresExRecord) -> V20PresExRecord: return pres_ex_record @staticmethod - def _summarize_doc_result(doc_result: Optional["DocumentVerificationResult"]): + def _summarize_doc_result(doc_result: Optional[DocumentVerificationResult]): if not doc_result: return None proof_results = [ From 770f229a704c4264848706bb7343c274787fca1a Mon Sep 17 00:00:00 2001 From: Sheldon Regular Date: Mon, 12 Jan 2026 16:15:46 -0500 Subject: [PATCH 3/3] more ruff lint fixes Signed-off-by: Sheldon Regular --- acapy_agent/protocols/present_proof/v2_0/formats/dif/handler.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/acapy_agent/protocols/present_proof/v2_0/formats/dif/handler.py b/acapy_agent/protocols/present_proof/v2_0/formats/dif/handler.py index 826de355d2..41aa4b40dd 100644 --- a/acapy_agent/protocols/present_proof/v2_0/formats/dif/handler.py +++ b/acapy_agent/protocols/present_proof/v2_0/formats/dif/handler.py @@ -17,11 +17,11 @@ Ed25519Signature2018, Ed25519Signature2020, ) +from ......vc.ld_proofs.validation_result import DocumentVerificationResult from ......vc.vc_di.manager import VcDiManager from ......vc.vc_ld.manager import VcLdpManager from ......vc.vc_ld.models.options import LDProofVCOptions from ......vc.vc_ld.models.presentation import VerifiablePresentation -from ......vc.ld_proofs.validation_result import DocumentVerificationResult from .....problem_report.v1_0.message import ProblemReport from ....dif.pres_exch import PresentationDefinition, SchemaInputDescriptor from ....dif.pres_exch_handler import DIFPresExchError, DIFPresExchHandler