Skip to content

Commit fdb06eb

Browse files
committed
Add detailed logging
1 parent 0df5658 commit fdb06eb

File tree

4 files changed

+190
-57
lines changed

4 files changed

+190
-57
lines changed

matcher-rs/src/credman.rs

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -26,6 +26,7 @@ impl CredmanApi for CredmanApiImpl {
2626
unsafe {
2727
GetRequestSize(&mut size);
2828
}
29+
log::debug!("Host requested request buffer of size: {}", size);
2930
let mut r = vec![0; size as usize];
3031
unsafe {
3132
GetRequestBuffer(r.as_mut_ptr() as *mut c_void);
@@ -37,6 +38,7 @@ impl CredmanApi for CredmanApiImpl {
3738
unsafe {
3839
GetCredentialsSize(&mut size);
3940
}
41+
log::debug!("Host requested registered data buffer of size: {}", size);
4042
let mut r = vec![0; size.try_into().unwrap()];
4143
unsafe {
4244
ReadCredentialsBuffer(r.as_mut_ptr() as *mut c_void, 0, size as usize);
@@ -52,9 +54,16 @@ impl CredmanApi for CredmanApiImpl {
5254
disclaimer: Option<&CStr>,
5355
warning: Option<&CStr>,
5456
) {
57+
log::info!("Adding string ID entry: {:?}", entry_id);
5558
let icon_bytes =
5659
icon.map_or(std::ptr::null(), |x| x.as_ptr()) as *const std::os::raw::c_char;
5760
let icon_length = icon.map_or(0, |x| x.len());
61+
log::trace!(
62+
"Entry details - title: {:?}, subtitle: {:?}, icon_len: {}",
63+
title,
64+
subtitle,
65+
icon_length
66+
);
5867
unsafe {
5968
AddStringIdEntry(
6069
entry_id.as_ptr(),

matcher-rs/src/issuance.rs

Lines changed: 73 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -16,33 +16,83 @@ const ALLOWED_PROTOCOLS: [&str; 4] = [
1616
];
1717

1818
pub fn issuance_main(credman: &mut impl CredmanApi) -> Result<(), Box<dyn std::error::Error>> {
19+
log::info!("Starting issuance matching process");
1920
let matcher_data_buffer = credman.get_registered_data();
21+
log::debug!(
22+
"Retrieved matcher data buffer, size: {}",
23+
matcher_data_buffer.len()
24+
);
25+
2026
let json_start = u32::from_le_bytes(matcher_data_buffer[..size_of::<u32>()].try_into()?);
21-
let matcher_data: IssuanceMatcherData = DeJson::deserialize_json(std::str::from_utf8(
22-
&matcher_data_buffer[json_start.try_into()?..],
23-
)?)?;
24-
let request: DigitalCredentialCreationRequest =
25-
DeJson::deserialize_json(std::str::from_utf8(&credman.get_request_buffer())?)?;
26-
if request.requests.iter().any(|r| {
27-
ALLOWED_PROTOCOLS.iter().any(|s| r.protocol == *s)
28-
&& matcher_data
29-
.filter
30-
.matches(&RegularizedOpenId4VciRequestData::from(&r.data))
31-
}) {
32-
let icon = &matcher_data_buffer[matcher_data.icon.0..matcher_data.icon.1];
33-
let entry_id = CString::new(matcher_data.entry_id)?;
34-
let title = matcher_data.title.map(|s| CString::new(s)).transpose()?;
35-
let subtitle = matcher_data.subtitle.map(|s| CString::new(s)).transpose()?;
36-
credman.add_string_id_entry(
37-
&entry_id,
38-
if icon.is_empty() { None } else { Some(icon) },
39-
title.as_deref(),
40-
subtitle.as_deref(),
41-
None,
42-
None,
43-
);
27+
let matcher_data_str = std::str::from_utf8(&matcher_data_buffer[json_start.try_into()?..])?;
28+
let matcher_data: IssuanceMatcherData = match DeJson::deserialize_json(matcher_data_str) {
29+
Ok(data) => data,
30+
Err(e) => {
31+
log::error!(
32+
"Failed to deserialize matcher data: {:?}. JSON: {}",
33+
e,
34+
matcher_data_str
35+
);
36+
return Err(e.into());
37+
}
38+
};
39+
log::debug!("Parsed matcher data for entry: {}", matcher_data.entry_id);
40+
41+
let request_buffer = credman.get_request_buffer();
42+
let request_str = std::str::from_utf8(&request_buffer)?;
43+
let request: DigitalCredentialCreationRequest = match DeJson::deserialize_json(request_str) {
44+
Ok(req) => req,
45+
Err(e) => {
46+
log::error!(
47+
"Failed to deserialize request: {:?}. JSON: {}",
48+
e,
49+
request_str
50+
);
51+
return Err(e.into());
52+
}
53+
};
54+
log::debug!(
55+
"Parsed request with {} sub-requests",
56+
request.requests.len()
57+
);
58+
59+
for (i, r) in request.requests.iter().enumerate() {
60+
log::trace!("Checking request {}: protocol={}", i, r.protocol);
61+
if ALLOWED_PROTOCOLS.iter().any(|s| r.protocol == *s) {
62+
let regularized = RegularizedOpenId4VciRequestData::from(&r.data);
63+
if matcher_data.filter.matches(&regularized) {
64+
log::info!("Match found for request {} with protocol {}", i, r.protocol);
65+
let icon = &matcher_data_buffer[matcher_data.icon.0..matcher_data.icon.1];
66+
let entry_id = CString::new(matcher_data.entry_id.clone())?;
67+
let title = matcher_data
68+
.title
69+
.as_ref()
70+
.map(|s| CString::new(s.clone()))
71+
.transpose()?;
72+
let subtitle = matcher_data
73+
.subtitle
74+
.as_ref()
75+
.map(|s| CString::new(s.clone()))
76+
.transpose()?;
77+
78+
log::debug!("Adding string ID entry: {}", matcher_data.entry_id);
79+
credman.add_string_id_entry(
80+
&entry_id,
81+
if icon.is_empty() { None } else { Some(icon) },
82+
title.as_deref(),
83+
subtitle.as_deref(),
84+
None,
85+
None,
86+
);
87+
// Assuming we only need to add one entry if any request matches
88+
break;
89+
}
90+
} else {
91+
log::warn!("Unsupported protocol: {}", r.protocol);
92+
}
4493
}
4594

95+
log::info!("Issuance matching process completed");
4696
Ok(())
4797
}
4898

matcher-rs/src/issuance_matcher.rs

Lines changed: 96 additions & 34 deletions
Original file line numberDiff line numberDiff line change
@@ -30,45 +30,107 @@ impl Default for OpenId4VciFilter {
3030

3131
impl OpenId4VciFilter {
3232
pub fn matches(&self, request: &RegularizedOpenId4VciRequestData) -> bool {
33-
match &self {
34-
Self::Unit {} => true,
35-
Self::And { filters } => filters.iter().all(|f| f.matches(request)),
36-
Self::Or { filters } => filters.iter().any(|f| f.matches(request)),
37-
Self::Not { filter } => !filter.matches(request),
38-
Self::AllowsIssuers { issuers } => issuers.contains(request.credential_issuer),
39-
Self::AllowsConfigurationIds { configuration_ids } => request
40-
.credential_configuration_ids
41-
.iter()
42-
.any(|id| configuration_ids.contains(id)),
43-
Self::SupportsAuthCodeFlow {} => request.grants.contains_key("authorization_code"),
44-
Self::SupportsPreAuthFlow {} => request
45-
.grants
46-
.contains_key("urn:ietf:params:oauth:grant-type:pre-authorized_code"),
47-
Self::SupportsNonceEndpoint {} => request
48-
.credential_issuer_metadata
49-
.is_some_and(|m| !m.nonce_endpoint.is_empty()),
50-
Self::SupportsDeferredCredentialEndpoint {} => request
51-
.credential_issuer_metadata
52-
.is_some_and(|m| !m.deferred_credential_endpoint.is_empty()),
53-
Self::SupportsNotificationEndpoint {} => request
54-
.credential_issuer_metadata
55-
.is_some_and(|m| !m.notification_endpoint.is_empty()),
33+
let matched = match &self {
34+
Self::Unit {} => {
35+
log::trace!("Filter Unit matched");
36+
true
37+
}
38+
Self::And { filters } => {
39+
let res = filters.iter().all(|f| f.matches(request));
40+
log::trace!("Filter And matched: {}", res);
41+
res
42+
}
43+
Self::Or { filters } => {
44+
let res = filters.iter().any(|f| f.matches(request));
45+
log::trace!("Filter Or matched: {}", res);
46+
res
47+
}
48+
Self::Not { filter } => {
49+
let res = !filter.matches(request);
50+
log::trace!("Filter Not matched: {}", res);
51+
res
52+
}
53+
Self::AllowsIssuers { issuers } => {
54+
let res = issuers.contains(request.credential_issuer);
55+
log::trace!(
56+
"Filter AllowsIssuers (issuer={}) matched: {}",
57+
request.credential_issuer,
58+
res
59+
);
60+
res
61+
}
62+
Self::AllowsConfigurationIds { configuration_ids } => {
63+
let res = request
64+
.credential_configuration_ids
65+
.iter()
66+
.any(|id| configuration_ids.contains(id));
67+
log::trace!("Filter AllowsConfigurationIds matched: {}", res);
68+
res
69+
}
70+
Self::SupportsAuthCodeFlow {} => {
71+
let res = request.grants.contains_key("authorization_code");
72+
log::trace!("Filter SupportsAuthCodeFlow matched: {}", res);
73+
res
74+
}
75+
Self::SupportsPreAuthFlow {} => {
76+
let res = request
77+
.grants
78+
.contains_key("urn:ietf:params:oauth:grant-type:pre-authorized_code");
79+
log::trace!("Filter SupportsPreAuthFlow matched: {}", res);
80+
res
81+
}
82+
Self::SupportsNonceEndpoint {} => {
83+
let res = request
84+
.credential_issuer_metadata
85+
.is_some_and(|m| !m.nonce_endpoint.is_empty());
86+
log::trace!("Filter SupportsNonceEndpoint matched: {}", res);
87+
res
88+
}
89+
Self::SupportsDeferredCredentialEndpoint {} => {
90+
let res = request
91+
.credential_issuer_metadata
92+
.is_some_and(|m| !m.deferred_credential_endpoint.is_empty());
93+
log::trace!("Filter SupportsDeferredCredentialEndpoint matched: {}", res);
94+
res
95+
}
96+
Self::SupportsNotificationEndpoint {} => {
97+
let res = request
98+
.credential_issuer_metadata
99+
.is_some_and(|m| !m.notification_endpoint.is_empty());
100+
log::trace!("Filter SupportsNotificationEndpoint matched: {}", res);
101+
res
102+
}
56103
Self::RequiresBatchIssuance { min_batch_size } => {
57-
request.credential_issuer_metadata.is_some_and(|m| {
104+
let res = request.credential_issuer_metadata.is_some_and(|m| {
58105
m.batch_credential_issuance
59106
.as_ref()
60107
.is_some_and(|b| b.batch_size >= *min_batch_size)
61-
})
108+
});
109+
log::trace!(
110+
"Filter RequiresBatchIssuance (min={}) matched: {}",
111+
min_batch_size,
112+
res
113+
);
114+
res
115+
}
116+
Self::SupportsMdocDoctype { doctypes } => {
117+
let res = request
118+
.credential_configurations
119+
.iter()
120+
.any(|c| doctypes.contains(&c.doctype));
121+
log::trace!("Filter SupportsMdocDoctype matched: {}", res);
122+
res
123+
}
124+
Self::SupportsSdJwtVct { vcts } => {
125+
let res = request
126+
.credential_configurations
127+
.iter()
128+
.any(|c| vcts.contains(&c.vct));
129+
log::trace!("Filter SupportsSdJwtVct matched: {}", res);
130+
res
62131
}
63-
Self::SupportsMdocDoctype { doctypes } => request
64-
.credential_configurations
65-
.iter()
66-
.any(|c| doctypes.contains(&c.doctype)),
67-
Self::SupportsSdJwtVct { vcts } => request
68-
.credential_configurations
69-
.iter()
70-
.any(|c| vcts.contains(&c.vct)),
71-
}
132+
};
133+
matched
72134
}
73135
}
74136

matcher-rs/src/openid4vci.rs

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -41,16 +41,28 @@ pub struct RegularizedOpenId4VciRequestData<'a> {
4141
// Implement From on a Reference
4242
impl<'a> From<&'a OpenId4VciRequestData> for RegularizedOpenId4VciRequestData<'a> {
4343
fn from(value: &'a OpenId4VciRequestData) -> Self {
44+
log::trace!(
45+
"Regularizing request for issuer: {}",
46+
value.credential_issuer
47+
);
4448
let mut configurations = Vec::with_capacity(value.credential_configuration_ids.len());
4549

4650
if let Some(metadata) = &value.credential_issuer_metadata {
4751
for id in &value.credential_configuration_ids {
4852
if let Some(config) = metadata.credential_configurations_supported.get(id) {
4953
configurations.push(config);
54+
} else {
55+
log::trace!("Configuration ID '{}' not found in metadata", id);
5056
}
5157
}
58+
} else {
59+
log::trace!("No metadata available for regularization");
5260
}
5361

62+
log::trace!(
63+
"Regularization complete: {} configurations matched",
64+
configurations.len()
65+
);
5466
Self {
5567
credential_issuer: &value.credential_issuer,
5668
credential_configuration_ids: &value.credential_configuration_ids,

0 commit comments

Comments
 (0)