<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=utf-8">
</head>
<body text="#000000" bgcolor="#FFFFFF">
<p>Hi Marvin,</p>
<br>
<blockquote type="cite"
cite="mid:CANRrHwhwC+SsGH_NHjCWbejF8zDOZc6KV17aWSHzRCQYcg0GYw@mail.gmail.com">
<pre wrap="">2. Metadata-based credential resolution is complicated by filtering
that can reduce the effective key set from what's patently defined in
metadata XML files.</pre>
</blockquote>
<br>
Yes, absolutely, there's a layer that filters credentials by the
supplied criteria. But I don't think that's what was going on
here... See below<br>
<br>
<blockquote type="cite"
cite="mid:CANRrHwhwC+SsGH_NHjCWbejF8zDOZc6KV17aWSHzRCQYcg0GYw@mail.gmail.com">
<pre wrap="">
3. IdP logging in the credential resolution process could be improved.</pre>
</blockquote>
<br>
Probably, but I'd like to understand exactly what happened<br>
<br>
<blockquote type="cite"
cite="mid:CANRrHwhwC+SsGH_NHjCWbejF8zDOZc6KV17aWSHzRCQYcg0GYw@mail.gmail.com">
<pre wrap="">After I saw that initially, I was satisfied that metadata resolution
was working as intended. That turned out to be a big mistake that cost
a lot of wasted time. The breakthrough came when we revisited the logs
after running out of leads with the vendor and we noticed that no
matter what logging categories we turned up we never saw any log
entries for the actual signature verification attempt. Code review
suggested that could be caused by failure to find any trusted
certificates, then we finally realized that the resolved metadata
entry was being further filtered:
2018-09-17 12:36:58,073 DEBUG
org.opensaml.saml.metadata.resolver.impl.PredicateRoleDescriptorResolver:376
1.2.3.4 Attempting to filter candidate RoleDescriptors via resolved
Predicates
2018-09-17 12:36:58,073 DEBUG
org.opensaml.saml.metadata.resolver.impl.PredicateRoleDescriptorResolver:398
1.2.3.4 After predicate filtering 1 RoleDescriptors remain</pre>
</blockquote>
<br>
Yes. The RoleDescriptorResolver's purpose is to extract
RoleDescriptors from EntityDescriptor, usually just based on role
QName and protocol (and/or theoretically other things, but nothing
else is actually configured by default).<br>
<br>
<blockquote type="cite"
cite="mid:CANRrHwhwC+SsGH_NHjCWbejF8zDOZc6KV17aWSHzRCQYcg0GYw@mail.gmail.com">
<pre wrap="">
There's a similar process for applying role criteria, </pre>
</blockquote>
I think you mean Credential criteria...<br>
<br>
<blockquote type="cite"
cite="mid:CANRrHwhwC+SsGH_NHjCWbejF8zDOZc6KV17aWSHzRCQYcg0GYw@mail.gmail.com">
<pre wrap="">which includes
key usage and key algorithm selectors. Unfortunately there's no
equivalent log output like the one above that indicates how many
elements remain after criteria selection, but we could infer that
something about the key criteria was likely preventing our key from
being resolved. That led us to review metadata where we noticed an
incorrect XML namespace on the KeyInfo element and children;
correcting that problem fixed everything.
</pre>
</blockquote>
<br>
There is indeed an entire layer in most of the CredentialResolver
impls that can further filter the returned Credentials using
Predicate<Credential> (either directly supplied or derived
from Criterion beans. See
AbstractCriteriaFilteringCredentialResolver. I looked and we don't
have any logging on the pre and post filtering numbers. <br>
<br>
However, from what you describe about the erroneous KeyInfo XML
namespace, I don't think that was what was actually happening here.
I think that the MetadataCredentialResolver was fundamentally unable
to "see" the KeyInfo data, since it could not have been unmarshalled
correctly. I think you would see log output from the below about an
unknown child XMLObject from the KeyDescriptorUnmarshaller:<br>
<br>
log.debug("Ignoring unknown child element {}",
childXMLObject.getElementQName());<br>
<br>
Then based on that, the KeyDescriptor's KeyInfo instance would have
been null, and I think this should have resulted in some output from
the KeyInfoCredentialResolver (used by the MCR) like so:<br>
<br>
log.info("KeyInfo was null, any credentials will be resolved by
post-processing hooks only");<br>
<br>
And then later, also from the KICR:<br>
<br>
log.debug("A total of {} credentials were resolved",
credentials.size());<br>
<br>
So in the MCR itself, it would have extracted 0 credentials from
metadata, and therefore there was nothing to filter in the first
place.<br>
<br>
At least I think that's what would have happened. Would be nice to
see the full logs. There's also some caching in there, so possibly
the initial failure to find and extract credentials from KeyInfo
might have been done early on and not appear later on subsequent
attempts.<br>
<br>
<br>
<blockquote type="cite"
cite="mid:CANRrHwhwC+SsGH_NHjCWbejF8zDOZc6KV17aWSHzRCQYcg0GYw@mail.gmail.com">
<pre wrap="">
It would have been immensely helpful for the trust engine to log the
number of resolved trusted certificates at DEBUG prior to attempting
signature validation; summary logging after applying criteria also
would have helped. I intend to file a Jira issue for those logging
improvements because I feel strongly that they would be generally
beneficial.
</pre>
</blockquote>
<br>
That's fine, adding some logging is easy enough. I agree that there
are places where more logging would have been beneficial in this
case, but they're probably around the MetadataCredentialResolver
fundamentally not finding any creds in metadata, vs the
criterion/predicate filtering layer.<br>
<br>
<br>
</body>
</html>