Prevent a log-and-throw situation where errors appear in the log that are handled #39344
Conversation
|
@vmuzikar - this is using the Quarkus log filtering. IMHO this is the appropriate concept to use here, please object if you think otherwise. @pedroigor - FYI, this is then preventing a log-and-throw scenario where something is logged as either an error or warning, and then later handled. This should lead to clean log files when there is actually nothing to report. |
Unreported flaky test detectedIf the flaky tests below are affected by the changes, please review and update the changes accordingly. Otherwise, a maintainer should report the flaky tests prior to merging the PR. org.keycloak.testsuite.broker.KcOidcBrokerTest#loginWithExistingUserWithBruteForceEnabledKeycloak CI - Java Distribution IT (windows-latest - temurin - 24) |
… are handled Closes keycloak#39173 Signed-off-by: Alexander Schwartz <aschwart@redhat.com>
b528bb6 to
323fda9
Compare
|
@vmuzikar - I updated the log filter to compare the log level warn first, which should be faster than comparing strings. The comparison is done only for log messages that are logged, not all log messages that are generated, so we should be fine here. |
|
@mhajas - please review when you have the time. Anyone else who wants to review is fine to review it as well. Will merge it on the first approving review :D |
|
Steps to reproduce this locally, follow these 12 steps:
|
| # SqlExceptionHelper will log-and-throw error messages. | ||
| # As those messages might later be caught and handled, this is an antipattern so we prevent logging them | ||
| # https://hibernate.zulipchat.com/#narrow/channel/132096-hibernate-user/topic/Feature.20Request.3A.20Disable.20logging.20of.20SqlExceptionHelper.20for | ||
| quarkus.log.category."org.hibernate.engine.jdbc.spi.SqlExceptionHelper".level=off |
There was a problem hiding this comment.
Based on these messages, are we sure we want to disable all Hibernate exceptions logging?
If there is a place where we incorrectly handle an exception it could save us a lot of time investigating it if we have the exception printed in the log.
Don't get me wrong I am all in with minimizing log-and-throw pattern but I like the idea to filter one specific exception that is causing confusion the users based on the report rather than disabling logging for all Hibernate exceptions.
There was a problem hiding this comment.
In Keycloak, we have the KeycloakErrorHandler that is handling this: The exception is either presented to the user and then it is logged in debug mode, or it is logged as an error.
In a situation that you describe, we could still enable debug logging (at least for the class KeycloakErrorHandler).
As this has been raised several times when we write to the DB in the persistent session worker, I'd rather proceed and hide those logs.
There was a problem hiding this comment.
Ah, ok. I forgot all of the exceptions would end up in the Handler. Sorry for confusion.
There was a problem hiding this comment.
Ah, ok. I forgot all of the exceptions would end up in the
Handler.
There might still be corner cases, but most of them should show in the handler.
| # SqlExceptionHelper will log-and-throw error messages. | ||
| # As those messages might later be caught and handled, this is an antipattern so we prevent logging them | ||
| # https://hibernate.zulipchat.com/#narrow/channel/132096-hibernate-user/topic/Feature.20Request.3A.20Disable.20logging.20of.20SqlExceptionHelper.20for | ||
| quarkus.log.category."org.hibernate.engine.jdbc.spi.SqlExceptionHelper".level=off |
There was a problem hiding this comment.
Ah, ok. I forgot all of the exceptions would end up in the Handler. Sorry for confusion.
… are handled (keycloak#39344) Closes keycloak#39173 Signed-off-by: Alexander Schwartz <aschwart@redhat.com>
… are handled (keycloak#39344) Closes keycloak#39173 Signed-off-by: Alexander Schwartz <aschwart@redhat.com>
Closes #39173
Example log messages that are suppressed by this filtering: