Aled Sage created BROOKLYN-576:
----------------------------------
Summary: Excessive debug logging
Key: BROOKLYN-576
URL: https://issues.apache.org/jira/browse/BROOKLYN-576
Project: Brooklyn
Issue Type: Bug
Reporter: Aled Sage
There is excessive (debug) logging in Brooklyn.
As an example, I took a QA test that deploys a medium-sized blueprint, runs a
few assertions against it, and tears it down (within an hour). That test has
280,724 lines at debug or above. As another example, in a long-running Brooklyn
server the debug log rolls frequently (with 10 rolling log files of 100MB each,
we have only 9 hours of logs).
Taking that first example, here are a few counts of line numbers that appear a
lot.
There are 3352 lines during startup of the form:
{noformat}
2018-01-16T10:18:39,356 DEBUG 120 o.a.b.c.b.s.c.BrooklynEntityMatcher
[tures-1-thread-1] Item Service[name=Quarantine Group,description=A grouping
for entities that are in quarantine (i.e. removed from the main
cluster),serviceType=org.apache.brooklyn.entity.group.QuarantineGroup,characteristics=[],customAttributes={}]
being instantiated with org.apache.brooklyn.entity.group.QuarantineGroup
{noformat}
There are 3068 lines (after startup) of the form:
{noformat}
2018-01-12T05:42:59.816Z :
\{"timeMillis":1515735779816,"thread":"qtp1674002381-61","level":"DEBUG","loggerName":"org.apache.brooklyn.camp.brooklyn.spi.creation.BrooklynEntityMatcher","message":"Item
Service[name=<null>,
description=<null>,serviceType=org.apache.brooklyn.test.framework.TestCase,characteristics=[],customAttributes={}]
being instantiated with
org.apache.brooklyn.test.framework.TestCase","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.
logging.slf4j.Slf4jLogger","threadId":61,"threadPriority":5}
{noformat}
108,415 lines like:
{noformat}
2018-01-12T05:46:22.092Z :
\{"timeMillis":1515735982091,"thread":"brooklyn-execmanager-iBsynVU6-90","level":"DEBUG","loggerName":"org.apache.brooklyn.camp.brooklyn.spi.dsl.BrooklynDslDeferredSupplier","message":"Queuing
task to resolve $brooklyn:attributeWhenReady(\"datastore.url.public\"), called
by Task[Resolving dependent value of deferred
supplier]@FNwydrle","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.logging.slf4j.Slf4jLogger","threadId":247,"threadPriority":5}
{noformat}
3058 lines like:
{noformat}
2018-01-12T05:43:01.903Z :
\{"timeMillis":1515735781900,"thread":"qtp1674002381-61","level":"DEBUG","loggerName":"org.apache.brooklyn.camp.brooklyn.spi.creation.BrooklynAssemblyTemplateInstantiator","message":"CAMP
creating application instance for O877QU60
(org.apache.brooklyn.camp.spi.AssemblyTemplate@1a325d93[id=O877QU60;
type=AssemblyTemplate])","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.logging.slf4j.Slf4jLogger","threadId":61,"threadPriority":5}
{noformat}
5448 lines like that below (but these might well be genuinely
interesting/important!):
{noformat}
2018-01-12T05:43:23.766Z :
\{"timeMillis":1515735802656,"thread":"qtp1674002381-61","level":"DEBUG","loggerName":"org.apache.brooklyn.core.entity.AbstractEntity","message":"Emitting
sensor notification entity.config_key.added value
target[ConfigKey:org.apache.brooklyn.api.entity.Entity] on
TestCaseImpl{id=iy82c13e94}","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.logging.slf4j.Slf4jLogger","threadId":61,"threadPriority":5}
{noformat}
994 lines like:
{noformat}
2018-01-12T05:43:28.542Z :
\{"timeMillis":1515735807437,"thread":"qtp1674002381-61","level":"DEBUG","loggerName":"org.apache.brooklyn.core.mgmt.internal.LocalSubscriptionManager","message":"Creating
subscription efYp1mKH for TestCaseImpl{id=t5834ewp2e} on
TestCaseImpl\{id=t5834ewp2e} Sensor: service.state.expected
(org.apache.brooklyn.core.entity.lifecycle.Lifecycle$Transition) in
SubscriptionContext(SSENK)","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.
logging.slf4j.Slf4jLogger","threadId":61,"threadPriority":5}
{noformat}
5124 lines like:
{noformat}
2018-01-12T05:51:48.161Z :
\{"timeMillis":1515736308162,"thread":"brooklyn-execmanager-iBsynVU6-43","level":"DEBUG","loggerName":"org.apache.brooklyn.core.location.access.BrooklynAccessUtils","message":"No
PortForwardManager, using
default","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.logging.slf4j.Slf4jLogger","threadId":186,"threadPriority":5}
{noformat}
5147 lines like:
{noformat}
2018-01-12T05:51:48.164Z :
\{"timeMillis":1515736308163,"thread":"brooklyn-execmanager-iBsynVU6-43","level":"DEBUG","loggerName":"org.apache.brooklyn.core.objs.proxy.InternalLocationFactory","message":"Location-factory
returning pre- existing location; skipping initialization of
PortForwardManagerImpl{id=wmkmgbrd45, name=localhost, scope=global,
mappingsSize=0}","endOfBatch":false,"loggerFqcn":"org.ops4j.pax.logging.slf4j.Slf4jLogger","threadId":186,"threadPriority":
5}
{noformat}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
