[jira] [Commented] (BROOKLYN-576) Excessive debug logging
[ https://issues.apache.org/jira/browse/BROOKLYN-576?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16490813#comment-16490813 ] Aled Sage commented on BROOKLYN-576: Marking this as resolved, as there were significant improvements. We can open another jira issue if we want to make/track additional improvements. > Excessive debug logging > --- > > Key: BROOKLYN-576 > URL: https://issues.apache.org/jira/browse/BROOKLYN-576 > Project: Brooklyn > Issue Type: Bug >Reporter: Aled Sage >Priority: Major > > 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=, > description=,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-execmanag
[jira] [Commented] (BROOKLYN-576) Excessive debug logging
[ https://issues.apache.org/jira/browse/BROOKLYN-576?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16365328#comment-16365328 ] ASF GitHub Bot commented on BROOKLYN-576: - Github user asfgit closed the pull request at: https://github.com/apache/brooklyn-server/pull/948 > Excessive debug logging > --- > > Key: BROOKLYN-576 > URL: https://issues.apache.org/jira/browse/BROOKLYN-576 > Project: Brooklyn > Issue Type: Bug >Reporter: Aled Sage >Priority: Major > > 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=, > description=,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","l
[jira] [Commented] (BROOKLYN-576) Excessive debug logging
[ https://issues.apache.org/jira/browse/BROOKLYN-576?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16365327#comment-16365327 ] ASF GitHub Bot commented on BROOKLYN-576: - Github user tbouron commented on the issue: https://github.com/apache/brooklyn-server/pull/948 LGTM, thanks @aledsage, merging > Excessive debug logging > --- > > Key: BROOKLYN-576 > URL: https://issues.apache.org/jira/browse/BROOKLYN-576 > Project: Brooklyn > Issue Type: Bug >Reporter: Aled Sage >Priority: Major > > 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=, > description=,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-execman
[jira] [Commented] (BROOKLYN-576) Excessive debug logging
[ https://issues.apache.org/jira/browse/BROOKLYN-576?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16364075#comment-16364075 ] ASF GitHub Bot commented on BROOKLYN-576: - GitHub user aledsage opened a pull request: https://github.com/apache/brooklyn-server/pull/948 BROOKLYN-576: decrease debug logging for resolved DSL We ran a test in QA that lasted 1 hour. There were 98,275 of these debug log messages (out of 226,712 total log messages at debug or above). You can merge this pull request into a Git repository by running: $ git pull https://github.com/aledsage/brooklyn-server BROOKLYN-576-decrease-logging Alternatively you can review and apply these changes as the patch at: https://github.com/apache/brooklyn-server/pull/948.patch To close this pull request, make a commit to your master/trunk branch with (at least) the following in the commit message: This closes #948 commit 33e0eeaaf43e3209cc16b7c5e531c1bccdd1589b Author: Aled Sage Date: 2018-02-14T13:56:05Z BROOKLYN-576: decrease debug logging for resolved DSL > Excessive debug logging > --- > > Key: BROOKLYN-576 > URL: https://issues.apache.org/jira/browse/BROOKLYN-576 > Project: Brooklyn > Issue Type: Bug >Reporter: Aled Sage >Priority: Major > > 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=, > description=,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:
[jira] [Commented] (BROOKLYN-576) Excessive debug logging
[ https://issues.apache.org/jira/browse/BROOKLYN-576?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16336022#comment-16336022 ] ASF GitHub Bot commented on BROOKLYN-576: - Github user asfgit closed the pull request at: https://github.com/apache/brooklyn-server/pull/939 > Excessive debug logging > --- > > Key: BROOKLYN-576 > URL: https://issues.apache.org/jira/browse/BROOKLYN-576 > Project: Brooklyn > Issue Type: Bug >Reporter: Aled Sage >Priority: Major > > 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=, > description=,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","l
[jira] [Commented] (BROOKLYN-576) Excessive debug logging
[ https://issues.apache.org/jira/browse/BROOKLYN-576?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16336013#comment-16336013 ] ASF GitHub Bot commented on BROOKLYN-576: - Github user tbouron commented on the issue: https://github.com/apache/brooklyn-server/pull/939 LGTM, thanks @aledsage. Merging > Excessive debug logging > --- > > Key: BROOKLYN-576 > URL: https://issues.apache.org/jira/browse/BROOKLYN-576 > Project: Brooklyn > Issue Type: Bug >Reporter: Aled Sage >Priority: Major > > 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=, > description=,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-execman
[jira] [Commented] (BROOKLYN-576) Excessive debug logging
[ https://issues.apache.org/jira/browse/BROOKLYN-576?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16335952#comment-16335952 ] ASF GitHub Bot commented on BROOKLYN-576: - GitHub user aledsage opened a pull request: https://github.com/apache/brooklyn-server/pull/939 BROOKLYN-576: decrease amount of debug logging You can merge this pull request into a Git repository by running: $ git pull https://github.com/aledsage/brooklyn-server BROOKLYN-576-decrease-debug-logging Alternatively you can review and apply these changes as the patch at: https://github.com/apache/brooklyn-server/pull/939.patch To close this pull request, make a commit to your master/trunk branch with (at least) the following in the commit message: This closes #939 commit 4e3d4d08039df00d5a19e9d933c9b03ab6da6d4c Author: Aled Sage Date: 2018-01-23T15:51:05Z BROOKLYN-576: decrease amount of debug logging > Excessive debug logging > --- > > Key: BROOKLYN-576 > URL: https://issues.apache.org/jira/browse/BROOKLYN-576 > Project: Brooklyn > Issue Type: Bug >Reporter: Aled Sage >Priority: Major > > 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=, > description=,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,"logg