[
https://issues.apache.org/jira/browse/BROOKLYN-573?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16334416#comment-16334416
]
Aled Sage commented on BROOKLYN-573:
------------------------------------
The problem appears to be the version of slf4j that we're using. Looking in the
debugger, we are using {{org.ops4j.pax.logging.slf4j.Slf4jLogger}}
In the karaf package exports, I see:
{noformat}
org.ops4j.pax.logging.slf4j │ 1.10.1
│ 5 │ org.ops4j.pax.logging.pax-logging-api
org.slf4j.bridge │ 1.6.6
│ 109 │ jul.to.slf4j
org.slf4j.event │ 1.7.25
│ 5 │ org.ops4j.pax.logging.pax-logging-api
org.slf4j.helpers │ 1.4.3
│ 5 │ org.ops4j.pax.logging.pax-logging-api
org.slf4j.helpers │ 1.5.11
│ 5 │ org.ops4j.pax.logging.pax-logging-api
org.slf4j.helpers │ 1.6.6
│ 5 │ org.ops4j.pax.logging.pax-logging-api
org.slf4j.helpers │ 1.7.25
│ 5 │ org.ops4j.pax.logging.pax-logging-api{noformat}
The {{MessageFormatter}} code in ops4j's exported package matches that of slf4j
1.7.* and later. This treats a final exception arg as something whose
stacktrace should be logged. See:
* ops4j code:
[https://github.com/ops4j/org.ops4j.pax.logging/blob/logging-1.10.1/pax-logging-api/src/main/java/org/slf4j/helpers/MessageFormatter.java#L167-L174]
* slf4j1.6 code:
[https://github.com/qos-ch/slf4j/blob/v_1.6.6/slf4j-api/src/main/java/org/slf4j/helpers/MessageFormatter.java#L179-L242]
* slf4j 1.7 code:
[https://github.com/qos-ch/slf4j/blob/v_1.7.25/slf4j-api/src/main/java/org/slf4j/helpers/MessageFormatter.java#L167-L174]
> Repeater logs exception stacktrace many times (at debug)
> --------------------------------------------------------
>
> Key: BROOKLYN-573
> URL: https://issues.apache.org/jira/browse/BROOKLYN-573
> Project: Brooklyn
> Issue Type: Bug
> Reporter: Aled Sage
> Priority: Major
>
> In Brooklyn master, in Karaf:
> The {{Repeater}} logging will repeatedly log the stacktrace of the exception
> (which can result in a huge amount of logging, e.g. when writing qa tests
> using {{TestHttpCall}} etc).
> {noformat}
> 2018-01-22T12:08:40,730 DEBUG 146 o.a.b.u.r.Repeater [er-YWpZfeTr-1226]
> Repeater: repeated failure; excluding stacktrace: {}
> java.lang.AssertionError: body expected contains This request is only
> permitted against an active master Brooklyn server but found []
> at
> org.apache.brooklyn.test.framework.TestFrameworkAssertions.failAssertion(TestFrameworkAssertions.java:387)
> ~[?:?]
> at
> org.apache.brooklyn.test.framework.TestFrameworkAssertions.checkActualAgainstAssertions(TestFrameworkAssertions.java:307)
> ~[?:?]
> at
> org.apache.brooklyn.test.framework.TestFrameworkAssertions$3.call(TestFrameworkAssertions.java:267)
> ~[?:?]
> at
> org.apache.brooklyn.test.framework.TestFrameworkAssertions$3.call(TestFrameworkAssertions.java:257)
> ~[?:?]
> at
> org.apache.brooklyn.util.repeat.Repeater.runKeepingError(Repeater.java:399)
> [146:org.apache.brooklyn.utils-common:1.0.0.20180118_1633]
> at
> org.apache.brooklyn.util.repeat.Repeater.runRequiringTrue(Repeater.java:361)
> [146:org.apache.brooklyn.utils-common:1.0.0.20180118_1633]
> at
> org.apache.brooklyn.test.framework.TestFrameworkAssertions.checkAssertionsEventually(TestFrameworkAssertions.java:280)
> [145:org.apache.brooklyn.test-framework:1.0.0.20180118_1633]
> at
> org.apache.brooklyn.test.framework.TestFrameworkAssertions.checkAssertionsEventually(TestFrameworkAssertions.java:228)
> [145:org.apache.brooklyn.test-framework:1.0.0.20180118_1633]
> at
> org.apache.brooklyn.test.framework.TestHttpCallImpl.doRequestAndCheckAssertions(TestHttpCallImpl.java:107)
> [145:org.apache.brooklyn.test-framework:1.0.0.20180118_1633]
> at
> org.apache.brooklyn.test.framework.TestHttpCallImpl.start(TestHttpCallImpl.java:76)
> [145:org.apache.brooklyn.test-framework:1.0.0.20180118_1633]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> ~[?:?]
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> ~[?:?]
> at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
> at
> org.apache.brooklyn.util.javalang.Reflections.invokeMethodFromArgs(Reflections.java:984)
> [146:org.apache.brooklyn.utils-common:1.0.0.20180118_1633]
> at
> org.apache.brooklyn.util.javalang.Reflections.invokeMethodFromArgs(Reflections.java:871)
> [146:org.apache.brooklyn.utils-common:1.0.0.20180118_1633]
> at
> org.apache.brooklyn.util.javalang.Reflections.invokeMethodFromArgs(Reflections.java:857)
> [146:org.apache.brooklyn.utils-common:1.0.0.20180118_1633]
> at
> org.apache.brooklyn.util.javalang.Reflections.invokeMethodFromArgs(Reflections.java:852)
> [146:org.apache.brooklyn.utils-common:1.0.0.20180118_1633]
> at
> org.apache.brooklyn.core.mgmt.internal.AbstractManagementContext.invokeEffectorMethodLocal(AbstractManagementContext.java:327)
> [123:org.apache.brooklyn.core:1.0.0.20180118_1633]
> at
> org.apache.brooklyn.core.mgmt.internal.AbstractManagementContext.invokeEffectorMethodSync(AbstractManagementContext.java:366)
> [123:org.apache.brooklyn.core:1.0.0.20180118_1633]
> at
> org.apache.brooklyn.core.mgmt.internal.EffectorUtils.invokeMethodEffector(EffectorUtils.java:274)
> [123:org.apache.brooklyn.core:1.0.0.20180118_1633]
> at
> org.apache.brooklyn.core.effector.MethodEffector.call(MethodEffector.java:153)
> [123:org.apache.brooklyn.core:1.0.0.20180118_1633]
> at
> org.apache.brooklyn.core.entity.trait.Startable$StartEffectorBody.call(Startable.java:56)
> [123:org.apache.brooklyn.core:1.0.0.20180118_1633]
> at
> org.apache.brooklyn.core.entity.trait.Startable$StartEffectorBody.call(Startable.java:50)
> [123:org.apache.brooklyn.core:1.0.0.20180118_1633]
> at
> org.apache.brooklyn.core.effector.EffectorTasks$EffectorBodyTaskFactory$1.call(EffectorTasks.java:82)
> [123:org.apache.brooklyn.core:1.0.0.20180118_1633]
> at
> org.apache.brooklyn.util.core.task.DynamicSequentialTask$DstJob.call(DynamicSequentialTask.java:364)
> [123:org.apache.brooklyn.core:1.0.0.20180118_1633]
> at
> org.apache.brooklyn.util.core.task.BasicExecutionManager$SubmissionCallable.call(BasicExecutionManager.java:565)
> [123:org.apache.brooklyn.core:1.0.0.20180118_1633]
> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> [?:?]
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> [?:?]
> at java.lang.Thread.run(Thread.java:748) [?:?]
> {noformat}
>
> In comparison, a simple test in my IDE (i.e. not in karaf) logs it properly
> as expected.
>
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
