Logging of assertion validation is overwriting specific error messages
Basics
Logistics
Basics
Logistics
Description
The assertion validation code used to implement the proxying in the IdP seems to have some problems getting the specific cause of a failure logged properly. In at least one case, where it fails to validate SubjectConfirmations, it overwrites the original “cause” message in the ValidationContext with a generic one at the end of the loop saying “no methods were met”, so you never see the actual cause.
I think we meant to use INFO for this, because all the login methods tend to warn on INFO, but I suspect the best thing to do is to actually build up a collection of messages to eventually log at the end up in a higher layer.
I spotted some cases where the code checks for an existing message and appends it to a new one, but it’s simpler and more general to just let there be multiple.
Environment
None
Activity
Scott Cantor May 18, 2023 at 5:13 PM
Notably, there might have been some thought that we wanted to avoid exposing internal details too freely in the error messages, but I don’t see that as a consideration as these are entirely internal and used for…logging, so it’s the same thing really. We would never directly dump any of this on a page.
Scott Cantor May 18, 2023 at 5:12 PM
Since we can, I just went ahead and altered the ValidationContext API to expose a collection getter to add messages to in place of the get/set singleton.
I changed all the code calling it to add messages, and changed the messages to match the existing log messages better for detail, and then removed all duplicate logging.
The ValidateAssertions action now just logs the whole collection of messages in one go, and that comes out pretty cleanly with good context for what went wrong. Tested this on the address mismatch error and got out what I wanted.
The assertion validation code used to implement the proxying in the IdP seems to have some problems getting the specific cause of a failure logged properly. In at least one case, where it fails to validate SubjectConfirmations, it overwrites the original “cause” message in the ValidationContext with a generic one at the end of the loop saying “no methods were met”, so you never see the actual cause.
I think we meant to use INFO for this, because all the login methods tend to warn on INFO, but I suspect the best thing to do is to actually build up a collection of messages to eventually log at the end up in a higher layer.
I spotted some cases where the code checks for an existing message and appends it to a new one, but it’s simpler and more general to just let there be multiple.