New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Only remove Throwable if unconsumed by pattern. #166
base: master
Are you sure you want to change the base?
Conversation
@huxi It is clear that you have given this more thought than I have. I was under the impression that it was generally OK to consume the throwable if it's the last argument regardless of the {} placeholders in the pattern. There have been no complaints about this approach until LOGBACK-1183. Do we really want to support the case covered by LoggerMessageFormattingRegressionTest.formattingRegression ? |
@ceki Counting the tokens is seriously fast, i.e. in no way comparable to the performance impact of actually formatting a message. If you want to optimize message formatting further then try to get rid of I re-implemented the SLF4J I'm 100% OK if you want to "steal" any or all of that code. |
Agreement was reached that this issue (qos-ch/logback#374) need to be fixed here. |
@ceki any help is required with this? I've also faced an issue with throwable trimmed by |
@ceki i'm agree that it's a regression, and needs to be fixed.
If someone uses a placeholder in a template, he expects that placeholder will be replaced with text... @huxi an approach from your patch has a big CPU overhead due to a double parse of the if (L < argArray.length) {
argArray = trimmedCopy(argArray);
} |
@fenik17 I'm not sure what you mean about the big CPU overhead. I was aiming for a minimal change and counting is only performed if the last entry is actually a I think it's more questionable if trimming the array (i.e. creating a copy of the original array minus the last entry) is necessary at all - but I wanted to keep the scope of the PR manageable. |
Can I provide any help with this issue? |
I was hit by this today (via Netty, in their |
@jezovuk Can you please provide a reference/copy of the implicated lines of code in AbstractChannelHandlerContext? |
Copy of problematic code (log warn in
Example output of said log warn:
|
I got a bug report from a user of my library saying that exceptions are not printed correctly and after some investigation log.warn("rolled back transaction because of exception: {}", e, e); Changing the code to the following fixes the problem, but feels like a silly thing to do: log.warn("rolled back transaction because of exception: {}", e.toString(), e); Surely it might be better to not include the exception in the actual message and leave it to the format to decide, but it's something that people do anyway. |
This is a preparation for a LOGBACK-1183 fix while keeping the optimizations of LOGBACK-873 in place.
It replaces the package-private method
Throwable getThrowableCandidate(Object[] argArray)
with a publicThrowable extractUnconsumedThrowable(String messagePattern, Object[] argArray)
method.The unit test that was actually verifying the wrong behavior before has been changed and extended for both cases:
Throwable
at the end of the argument array is removed if is not "consumed" by the message pattern.Throwable
at the end of the argument array is left intact if it is "consumed" by the message pattern."consumed" means that a placeholder in the message pattern exists that will be replaced by the
Throwable
. If we assume an argument array{"bar", new Throwable()}
then the pattern"foo {} {}"
would "consume" theThrowable
resulting in the formatted string"foo bar java.lang.Throwable"
while the pattern"foo {}"
would not consume theThrowable
resulting in the formatted string"foo bar"
. This was the behavior of Logback below 1.1.The
extractUnconsumedThrowable
method would then by used by Logback instead ofEventArgUtil.extractThrowable
.I initially tried to fix LOGBACK-1183 solely in Logback but had to realize that SLF4J would later remove the
Throwable
anyway while formatting the message, regardless of whether or notEventArgUtil.extractThrowable
left it intact in the argument array.LoggingEvent
in Logback would then see the following change:Original code:
New code:
This private method is only called in the constructor.
Original code:
New code:
Applying those two changes in Logback would fix LOGBACK-1183.