You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@brooklyn.apache.org by ahgittin <gi...@git.apache.org> on 2014/11/06 03:07:02 UTC
[GitHub] incubator-brooklyn pull request: Persistence better logging and op...
GitHub user ahgittin opened a pull request:
https://github.com/apache/incubator-brooklyn/pull/303
Persistence better logging and optimization
see commits for details
logging is now quite elegant (and code more elegant too). at `MASTER` we log this for all persistence:
```
2014-11-06 01:53:24,484 DEBUG b.e.r.PeriodicDeltaChangeListener [brooklyn-execmanager-cPHPyZLD-49]: Checkpointing delta of memento: updating entities=[NginxControllerImpl{id=yj1CnqgS}, TomcatServerImpl{id=jFLN539t}, DynamicWebAppClusterImpl{id=mOp5gagc}, ControlledDynamicWebAppClusterImpl{id=cuPk22K9}], locations=[], policies=[], enrichers=[], catalog items=[]; removing entities=[], locations=[], policies=[], enrichers=[], catalog items=[]
2014-11-06 01:53:24,510 DEBUG b.e.r.p.BrooklynMementoPersisterToObjectStore [brooklyn-execmanager-cPHPyZLD-49]: Checkpointed delta of memento in 15ms: updated 4 entities, 3 locations, 2 policies, 35 enrichers, 0 catalog items; removed 0 entities, 0 locations, 0 policies, 0 enrichers, 0 catalog items
```
at `HOT_STANDBY` you see the following most of the time (much more detail on first 5 rebinds and every 1000th, which is about every ~15m):
```
2014-11-06 01:53:24,221 DEBUG b.e.rebind.RebindManagerImpl [brooklyn-execmanager-IEUSHnfF-1]: Rebinding (HOT_STANDBY, iteration 12) from /tmp/mms-amp-data/master...
2014-11-06 01:53:24,223 DEBUG b.e.r.p.BrooklynMementoPersisterToObjectStore [brooklyn-execmanager-IEUSHnfF-1]: Loaded rebind lists; took 1ms: 7 entities, 3 locations, 2 policies, 48 enrichers, 0 feeds, 0 catalog items; from /tmp/mms-amp-data/master
2014-11-06 01:53:24,292 DEBUG b.e.r.p.BrooklynMementoPersisterToObjectStore [brooklyn-execmanager-IEUSHnfF-1]: Loaded rebind raw data; took 69ms; 7 entities, 3 locations, 2 policies, 48 enrichers, 0 feeds, 0 catalog items, from /tmp/mms-amp-data/master
2014-11-06 01:53:24,467 DEBUG b.e.r.p.BrooklynMementoPersisterToObjectStore [brooklyn-execmanager-IEUSHnfF-1]: Loaded rebind manifests; took 174ms: 7 entities, 3 locations, 2 policies, 48 enrichers, 0 feeds, 0 catalog items; from /tmp/mms-amp-data/master
2014-11-06 01:53:24,533 DEBUG b.e.r.p.BrooklynMementoPersisterToObjectStore [brooklyn-execmanager-IEUSHnfF-1]: Loaded rebind mementos; took 5ms: 7 entities, 3 locations, 2 policies, 48 enrichers, 0 feeds, 0 catalog items, from /tmp/mms-amp-data/master
2014-11-06 01:53:24,570 DEBUG b.e.rebind.RebindManagerImpl [brooklyn-execmanager-IEUSHnfF-1]: Rebind complete (HOT_STANDBY, iteration 12) in 349ms: 1 app, 7 entities, 3 locations, 2 policies, 48 enrichers, 0 feeds, 0 catalog items
```
and all nodes get such entries as this:
```
2014-11-06 01:53:24,371 DEBUG b.m.h.ManagementPlaneSyncRecordPersisterToObjectStore [brooklyn-execmanager-IEUSHnfF-3]: Checkpointed delta of manager-memento in 1ms: brooklyn.management.ha.ManagementPlaneSyncRecordDeltaImpl[nodes: [BasicManagementNodeSyncRecord{nodeId=IEUSHnfF, status=HOT_STANDBY}]]
```
each appears once per second, meaning in happy path neither standby nor master logs too much.
there is some slight hack to prevent rebind over-logging, but i don't think it's too bad!
`trace` level restores full logging
You can merge this pull request into a Git repository by running:
$ git pull https://github.com/ahgittin/incubator-brooklyn persistence-better-logging
Alternatively you can review and apply these changes as the patch at:
https://github.com/apache/incubator-brooklyn/pull/303.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 #303
----
commit 28150112ebf66c1caef1c281a3589a32e1299148
Author: Alex Heneveld <al...@cloudsoftcorp.com>
Date: 2014-11-05T22:16:32Z
improve logging for persistence and rebind
a few more detailed messages, including timings;
and lots of suppression of messages during redind-read-only
commit 283d17067f1b5eb5954708a2f9a106dec6ef0bfc
Author: Alex Heneveld <al...@cloudsoftcorp.com>
Date: 2014-11-05T22:39:37Z
set entity RO status much earlier when known
mainly to enable suppression of log messages that are hugely noisy in read-only mode
commit f6316ea4fad0905362b384ed86a08f17a5f87d7e
Author: Alex Heneveld <al...@cloudsoftcorp.com>
Date: 2014-11-06T02:01:31Z
optimize rebind process
remove extraneous obj store lists+reads from process, and a bunch of code/redundancy tidy, and a bit more log tidy
----
---
If your project is set up for it, you can reply to this email and have your
reply appear on GitHub as well. If your project does not have this feature
enabled and wishes so, or if the feature is enabled but not working, please
contact infrastructure at infrastructure@apache.org or file a JIRA ticket
with INFRA.
---
[GitHub] incubator-brooklyn pull request: Persistence better logging and op...
Posted by asfgit <gi...@git.apache.org>.
Github user asfgit closed the pull request at:
https://github.com/apache/incubator-brooklyn/pull/303
---
If your project is set up for it, you can reply to this email and have your
reply appear on GitHub as well. If your project does not have this feature
enabled and wishes so, or if the feature is enabled but not working, please
contact infrastructure at infrastructure@apache.org or file a JIRA ticket
with INFRA.
---
[GitHub] incubator-brooklyn pull request: Persistence better logging and op...
Posted by neykov <gi...@git.apache.org>.
Github user neykov commented on a diff in the pull request:
https://github.com/apache/incubator-brooklyn/pull/303#discussion_r19935772
--- Diff: core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java ---
@@ -1235,7 +1249,20 @@ public void onUnmanaged(BrooklynObject instance) {
}
}
}
+
+ /** logs at debug, except during subsequent read-only rebinds, in which it logs trace */
+ private void logRebindingDebug(String message, Object... args) {
+ if (shouldLogRebinding()) {
+ LOG.debug(message, args);
+ } else {
+ LOG.trace(message, args);
+ }
+ }
+ protected boolean shouldLogRebinding() {
+ return (readOnlyRebindCount < 5) || (readOnlyRebindCount%1000==0);
--- End diff --
I'd explicitly compare to MIN_INTEGER to make it explicit (for documentation)
---
If your project is set up for it, you can reply to this email and have your
reply appear on GitHub as well. If your project does not have this feature
enabled and wishes so, or if the feature is enabled but not working, please
contact infrastructure at infrastructure@apache.org or file a JIRA ticket
with INFRA.
---
[GitHub] incubator-brooklyn pull request: Persistence better logging and op...
Posted by aledsage <gi...@git.apache.org>.
Github user aledsage commented on the pull request:
https://github.com/apache/incubator-brooklyn/pull/303#issuecomment-61963932
+1; only minor comments. Happy for this to be merged once you've gone through the comments @ahgittin
---
If your project is set up for it, you can reply to this email and have your
reply appear on GitHub as well. If your project does not have this feature
enabled and wishes so, or if the feature is enabled but not working, please
contact infrastructure at infrastructure@apache.org or file a JIRA ticket
with INFRA.
---
[GitHub] incubator-brooklyn pull request: Persistence better logging and op...
Posted by aledsage <gi...@git.apache.org>.
Github user aledsage commented on a diff in the pull request:
https://github.com/apache/incubator-brooklyn/pull/303#discussion_r19937753
--- Diff: core/src/main/java/brooklyn/config/BrooklynLogging.java ---
@@ -25,4 +30,45 @@
public static final String REST = "brooklyn.REST";
+ /** For convenience here, since SLF4J does not define such an enum */
+ public static enum LoggingLevel { ERROR, WARN, INFO, DEBUG, TRACE }
+
+ /** As methods on {@link Logger} but taking the level as an argument */
+ public static final void log(Logger logger, LoggingLevel level, String message, Object... args) {
+ switch (level) {
--- End diff --
Always a good idea to have a `default: ` as well, in case someone changes it later.
---
If your project is set up for it, you can reply to this email and have your
reply appear on GitHub as well. If your project does not have this feature
enabled and wishes so, or if the feature is enabled but not working, please
contact infrastructure at infrastructure@apache.org or file a JIRA ticket
with INFRA.
---
[GitHub] incubator-brooklyn pull request: Persistence better logging and op...
Posted by ahgittin <gi...@git.apache.org>.
Github user ahgittin commented on a diff in the pull request:
https://github.com/apache/incubator-brooklyn/pull/303#discussion_r19936585
--- Diff: core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterToObjectStore.java ---
@@ -96,6 +93,10 @@
"Maximum number of attempts to serialize a memento (e.g. if first attempts fail because of concurrent modifications of an entity)",
5);
+ static final BrooklynObjectType[] PERSISTED_OBJECT_TYPES_IN_ORDER = new BrooklynObjectType[] {
--- End diff --
+1
---
If your project is set up for it, you can reply to this email and have your
reply appear on GitHub as well. If your project does not have this feature
enabled and wishes so, or if the feature is enabled but not working, please
contact infrastructure at infrastructure@apache.org or file a JIRA ticket
with INFRA.
---
[GitHub] incubator-brooklyn pull request: Persistence better logging and op...
Posted by aledsage <gi...@git.apache.org>.
Github user aledsage commented on a diff in the pull request:
https://github.com/apache/incubator-brooklyn/pull/303#discussion_r19937661
--- Diff: core/src/main/java/brooklyn/catalog/internal/CatalogUtils.java ---
@@ -89,14 +92,18 @@ public static void installLibraries(ManagementContext managementContext, @Nullab
if (osgi.isAbsent()) {
throw new IllegalStateException("Unable to load bundles "+bundles+" because OSGi is not running.");
}
- if (log.isDebugEnabled()) log.debug("Loading bundles in {}: {}",
+ if (log.isDebugEnabled())
+ logDebugOrTraceIfRebinding(log,
+ "Loading bundles in {}: {}",
--- End diff --
I much prefer 8 character indent for wrapped lines. In general, it makes stand out much clearer that this is not just an indent for the next statement. Most of our other code uses that convention.
---
If your project is set up for it, you can reply to this email and have your
reply appear on GitHub as well. If your project does not have this feature
enabled and wishes so, or if the feature is enabled but not working, please
contact infrastructure at infrastructure@apache.org or file a JIRA ticket
with INFRA.
---
[GitHub] incubator-brooklyn pull request: Persistence better logging and op...
Posted by neykov <gi...@git.apache.org>.
Github user neykov commented on a diff in the pull request:
https://github.com/apache/incubator-brooklyn/pull/303#discussion_r19935730
--- Diff: core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java ---
@@ -527,20 +540,19 @@ protected BrooklynMementoRawData loadMementoRawData(final RebindExceptionHandler
//The manifest contains full catalog items mementos. Reading them at this stage means that
//we don't support references to entities/locations withing tags.
+
+ LOG.debug("Rebinding ("+mode+", iteration "+readOnlyRebindCount+") from "+getPersister().getBackingStoreDescription()+"...");
--- End diff --
Hide readOnlyRebindCount when negative?
---
If your project is set up for it, you can reply to this email and have your
reply appear on GitHub as well. If your project does not have this feature
enabled and wishes so, or if the feature is enabled but not working, please
contact infrastructure at infrastructure@apache.org or file a JIRA ticket
with INFRA.
---
[GitHub] incubator-brooklyn pull request: Persistence better logging and op...
Posted by neykov <gi...@git.apache.org>.
Github user neykov commented on a diff in the pull request:
https://github.com/apache/incubator-brooklyn/pull/303#discussion_r19940751
--- Diff: core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java ---
@@ -1235,7 +1249,20 @@ public void onUnmanaged(BrooklynObject instance) {
}
}
}
+
+ /** logs at debug, except during subsequent read-only rebinds, in which it logs trace */
+ private void logRebindingDebug(String message, Object... args) {
+ if (shouldLogRebinding()) {
+ LOG.debug(message, args);
+ } else {
+ LOG.trace(message, args);
+ }
+ }
+ protected boolean shouldLogRebinding() {
+ return (readOnlyRebindCount < 5) || (readOnlyRebindCount%1000==0);
--- End diff --
It's duplication, but makes the code more readable. Makes the different possible states explicit. Even better would be `!readOnlyRunning || (readOnlyRebindCount < 5) || (readOnlyRebindCount%1000==0);`.
---
If your project is set up for it, you can reply to this email and have your
reply appear on GitHub as well. If your project does not have this feature
enabled and wishes so, or if the feature is enabled but not working, please
contact infrastructure at infrastructure@apache.org or file a JIRA ticket
with INFRA.
---
[GitHub] incubator-brooklyn pull request: Persistence better logging and op...
Posted by ahgittin <gi...@git.apache.org>.
Github user ahgittin commented on a diff in the pull request:
https://github.com/apache/incubator-brooklyn/pull/303#discussion_r19938071
--- Diff: core/src/main/java/brooklyn/config/BrooklynLogging.java ---
@@ -25,4 +30,45 @@
public static final String REST = "brooklyn.REST";
+ /** For convenience here, since SLF4J does not define such an enum */
+ public static enum LoggingLevel { ERROR, WARN, INFO, DEBUG, TRACE }
+
+ /** As methods on {@link Logger} but taking the level as an argument */
+ public static final void log(Logger logger, LoggingLevel level, String message, Object... args) {
+ switch (level) {
--- End diff --
i think in places like this we *don't* want a default, because we want the compiler to direct us that the new case needs to be handled.
---
If your project is set up for it, you can reply to this email and have your
reply appear on GitHub as well. If your project does not have this feature
enabled and wishes so, or if the feature is enabled but not working, please
contact infrastructure at infrastructure@apache.org or file a JIRA ticket
with INFRA.
---
[GitHub] incubator-brooklyn pull request: Persistence better logging and op...
Posted by neykov <gi...@git.apache.org>.
Github user neykov commented on the pull request:
https://github.com/apache/incubator-brooklyn/pull/303#issuecomment-61958640
Just nitpicking comments, so good to merge. Great work on removing existing code duplication!
---
If your project is set up for it, you can reply to this email and have your
reply appear on GitHub as well. If your project does not have this feature
enabled and wishes so, or if the feature is enabled but not working, please
contact infrastructure at infrastructure@apache.org or file a JIRA ticket
with INFRA.
---
[GitHub] incubator-brooklyn pull request: Persistence better logging and op...
Posted by ahgittin <gi...@git.apache.org>.
Github user ahgittin commented on a diff in the pull request:
https://github.com/apache/incubator-brooklyn/pull/303#discussion_r19936671
--- Diff: core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java ---
@@ -527,20 +540,19 @@ protected BrooklynMementoRawData loadMementoRawData(final RebindExceptionHandler
//The manifest contains full catalog items mementos. Reading them at this stage means that
//we don't support references to entities/locations withing tags.
+
+ LOG.debug("Rebinding ("+mode+", iteration "+readOnlyRebindCount+") from "+getPersister().getBackingStoreDescription()+"...");
--- End diff --
if `==MIN_VALUE` yes. have left it in if it hits any other value (eg if it's ever `MIN_VALUE+1`)
---
If your project is set up for it, you can reply to this email and have your
reply appear on GitHub as well. If your project does not have this feature
enabled and wishes so, or if the feature is enabled but not working, please
contact infrastructure at infrastructure@apache.org or file a JIRA ticket
with INFRA.
---
[GitHub] incubator-brooklyn pull request: Persistence better logging and op...
Posted by ahgittin <gi...@git.apache.org>.
Github user ahgittin commented on a diff in the pull request:
https://github.com/apache/incubator-brooklyn/pull/303#discussion_r19936699
--- Diff: core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java ---
@@ -1235,7 +1249,20 @@ public void onUnmanaged(BrooklynObject instance) {
}
}
}
+
+ /** logs at debug, except during subsequent read-only rebinds, in which it logs trace */
+ private void logRebindingDebug(String message, Object... args) {
+ if (shouldLogRebinding()) {
+ LOG.debug(message, args);
+ } else {
+ LOG.trace(message, args);
+ }
+ }
+ protected boolean shouldLogRebinding() {
+ return (readOnlyRebindCount < 5) || (readOnlyRebindCount%1000==0);
--- End diff --
it looks funny to check equals min_value and then check or < 5 ! leaving this as is, unless you meant something else?
---
If your project is set up for it, you can reply to this email and have your
reply appear on GitHub as well. If your project does not have this feature
enabled and wishes so, or if the feature is enabled but not working, please
contact infrastructure at infrastructure@apache.org or file a JIRA ticket
with INFRA.
---
[GitHub] incubator-brooklyn pull request: Persistence better logging and op...
Posted by ahgittin <gi...@git.apache.org>.
Github user ahgittin commented on a diff in the pull request:
https://github.com/apache/incubator-brooklyn/pull/303#discussion_r19942150
--- Diff: core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java ---
@@ -1235,7 +1249,20 @@ public void onUnmanaged(BrooklynObject instance) {
}
}
}
+
+ /** logs at debug, except during subsequent read-only rebinds, in which it logs trace */
+ private void logRebindingDebug(String message, Object... args) {
+ if (shouldLogRebinding()) {
+ LOG.debug(message, args);
+ } else {
+ LOG.trace(message, args);
+ }
+ }
+ protected boolean shouldLogRebinding() {
+ return (readOnlyRebindCount < 5) || (readOnlyRebindCount%1000==0);
--- End diff --
I like that!
---
If your project is set up for it, you can reply to this email and have your
reply appear on GitHub as well. If your project does not have this feature
enabled and wishes so, or if the feature is enabled but not working, please
contact infrastructure at infrastructure@apache.org or file a JIRA ticket
with INFRA.
---
[GitHub] incubator-brooklyn pull request: Persistence better logging and op...
Posted by aledsage <gi...@git.apache.org>.
Github user aledsage commented on a diff in the pull request:
https://github.com/apache/incubator-brooklyn/pull/303#discussion_r19935450
--- Diff: core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterToObjectStore.java ---
@@ -96,6 +93,10 @@
"Maximum number of attempts to serialize a memento (e.g. if first attempts fail because of concurrent modifications of an entity)",
5);
+ static final BrooklynObjectType[] PERSISTED_OBJECT_TYPES_IN_ORDER = new BrooklynObjectType[] {
--- End diff --
Personal preference for `ImmutableList.of(...)`. Then it really is an immutable constant.
---
If your project is set up for it, you can reply to this email and have your
reply appear on GitHub as well. If your project does not have this feature
enabled and wishes so, or if the feature is enabled but not working, please
contact infrastructure at infrastructure@apache.org or file a JIRA ticket
with INFRA.
---
[GitHub] incubator-brooklyn pull request: Persistence better logging and op...
Posted by ahgittin <gi...@git.apache.org>.
Github user ahgittin commented on a diff in the pull request:
https://github.com/apache/incubator-brooklyn/pull/303#discussion_r19938100
--- Diff: core/src/main/java/brooklyn/catalog/internal/CatalogUtils.java ---
@@ -89,14 +92,18 @@ public static void installLibraries(ManagementContext managementContext, @Nullab
if (osgi.isAbsent()) {
throw new IllegalStateException("Unable to load bundles "+bundles+" because OSGi is not running.");
}
- if (log.isDebugEnabled()) log.debug("Loading bundles in {}: {}",
+ if (log.isDebugEnabled())
+ logDebugOrTraceIfRebinding(log,
+ "Loading bundles in {}: {}",
--- End diff --
me too :) will try to be more diligent in this respect
---
If your project is set up for it, you can reply to this email and have your
reply appear on GitHub as well. If your project does not have this feature
enabled and wishes so, or if the feature is enabled but not working, please
contact infrastructure at infrastructure@apache.org or file a JIRA ticket
with INFRA.
---