fix: do not warn about a rejection the caller is already given - #12
Merged
Conversation
Three places report the same rejection twice: once by returning it, and once by logging it at warn, at a level the caller does not control. SamlResponse#isValid stores the failure in validationException and returns false, then logs the message at warn. Auth#processResponse adds "invalid_response" or "response_not_success" to getErrors(), keeps the detail in getLastErrorReason() and getLastValidationException(), then logs at warn as well. Both move to debug: what reaches an operator is for the caller to decide, and everything these lines said is still available through the public API. This also matters for a caller that has more than one candidate request id to try -- the InResponseTo comparison is the one failure worth retrying with the next candidate, so a service provider with two browser tabs mid-login rules out candidates as a matter of course. At warn, every ruled-out candidate logged an error, including on the login that then succeeded. Util#loadXML is the opposite case: it answers with null and drops the exception, so nothing else records it and the message stays at warn. Only the stack trace moves to debug. The input there is whatever was posted to an assertion consumer service, which is anonymous, so an unauthenticated client could otherwise write a full trace into the log on every request. Measured against Fess 15.8 with Keycloak: an unparsable SAMLResponse went from 94 stack-trace lines to none, and a two-tab login that answers the older tab first now completes without logging anything. core 415/415 and toolkit 92/92 still pass.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Problem
Three places report the same rejection twice — once by returning it to the caller, and once by
logging it at
warn, at a level the caller does not control.SamlResponse#isValidvalidationException+falsewarn(message)Auth#processResponsegetErrors(),getLastErrorReason(),getLastValidationException()warn("processResponse error. …")Util#loadXMLnull, drops the exceptionwarn(message, e)— full stack traceTwo consequences show up in practice.
A caller with several candidate request ids logs errors on a login that succeeds. The
InResponseTo comparison is the one failure worth retrying with the next candidate, so a service
provider whose user has two browser tabs mid-login rules candidates out as a matter of course. At
warn, every ruled-out candidate producedon the way to a successful authentication.
An anonymous client can write a full stack trace into the log on every request. The assertion
consumer service is unauthenticated by nature, so anything posted there reaches
Util#loadXML. ASAMLResponse that is not parsable produced a 94-line trace per request.
Change
SamlResponse#isValidandAuth#processResponsemove their lines todebug. Everything theysaid is still reachable through the public API, so nothing is lost — the caller decides what an
operator sees.
Util#loadXMLis the opposite case and keeps its message atwarn, because it answers withnulland drops the exception, so nothing else would record it. Only the stack trace moves todebug.Verification
Measured against Fess 15.8 with Keycloak 26.4, before and after:
The consuming service provider still reports both cases itself, so no diagnosis was lost — only
the duplicate.
Note
The repository has no log-capturing test infrastructure, so the level change is not pinned by a
unit test; adding an appender harness for it seemed disproportionate. Say the word if you would
rather have one — the behaviour is covered end to end in the measurement above.