From 283d17067f1b5eb5954708a2f9a106dec6ef0bfc Mon Sep 17 00:00:00 2001 From: Alex Heneveld Date: Wed, 5 Nov 2014 22:39:37 +0000 Subject: [PATCH 1/4] set entity RO status much earlier when known mainly to enable suppression of log messages that are hugely noisy in read-only mode --- .../java/brooklyn/entity/rebind/RebindManagerImpl.java | 4 ++-- .../brooklyn/management/internal/LocalEntityManager.java | 8 +++++++- 2 files changed, 9 insertions(+), 3 deletions(-) diff --git a/core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java b/core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java index 24076f9fce..09101f6131 100644 --- a/core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java +++ b/core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java @@ -646,7 +646,9 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi try { Entity entity = newEntity(entityId, entityManifest.getType(), getLoadingContextFromCatalogItemId(catalogItemId, classLoader, rebindContext)); + ((EntityInternal)entity).getManagementSupport().setReadOnly( rebindContext.isReadOnly(entity) ); rebindContext.registerEntity(entityId, entity); + } catch (Exception e) { exceptionHandler.onCreateFailed(BrooklynObjectType.ENTITY, entityId, entityManifest.getType(), e); } @@ -880,8 +882,6 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi EntityManagerInternal entityManager = (EntityManagerInternal)managementContext.getEntityManager(); Set oldEntities = Sets.newLinkedHashSet(entityManager.getEntityIds()); for (Entity entity: rebindContext.getEntities()) { - ((EntityInternal)entity).getManagementSupport().setReadOnly( rebindContext.isReadOnly(entity) ); - ManagementTransitionMode oldMode = entityManager.getLastManagementTransitionMode(entity.getId()); entityManager.setManagementTransitionMode(entity, computeMode(entity, oldMode, rebindContext.isReadOnly(entity)) ); if (oldMode!=null) diff --git a/core/src/main/java/brooklyn/management/internal/LocalEntityManager.java b/core/src/main/java/brooklyn/management/internal/LocalEntityManager.java index c6a5bcff70..8a10727fdd 100644 --- a/core/src/main/java/brooklyn/management/internal/LocalEntityManager.java +++ b/core/src/main/java/brooklyn/management/internal/LocalEntityManager.java @@ -290,12 +290,18 @@ protected void manageRecursive(Entity e, final ManagementTransitionMode initialM if (mode==null) { setManagementTransitionMode(it, mode = initialMode); } - if (it.getManagementSupport().isReadOnlyRaw()==null) { + + Boolean isReadOnlyFromEntity = it.getManagementSupport().isReadOnlyRaw(); + if (isReadOnlyFromEntity==null) { if (mode.isReadOnly()) { // should have been marked by rebinder log.warn("Read-only entity "+it+" not marked as such on call to manage; marking and continuing"); } it.getManagementSupport().setReadOnly(mode.isReadOnly()); + } else { + if (!isReadOnlyFromEntity.equals(mode.isReadOnly())) { + log.warn("Read-only status at entity "+it+" ("+isReadOnlyFromEntity+") not consistent with management mode "+mode); + } } if (it.getManagementSupport().isDeployed()) { From 28150112ebf66c1caef1c281a3589a32e1299148 Mon Sep 17 00:00:00 2001 From: Alex Heneveld Date: Wed, 5 Nov 2014 22:16:32 +0000 Subject: [PATCH 2/4] improve logging for persistence and rebind a few more detailed messages, including timings; and lots of suppression of messages during redind-read-only --- .../internal/BasicBrooklynCatalog.java | 6 +- .../brooklyn/catalog/internal/CatalogDo.java | 3 +- .../brooklyn/catalog/internal/CatalogDto.java | 11 +- .../catalog/internal/CatalogItemDo.java | 3 +- .../catalog/internal/CatalogLibrariesDto.java | 7 +- .../catalog/internal/CatalogUtils.java | 32 ++++- .../java/brooklyn/config/BrooklynLogging.java | 46 ++++++ .../AbstractMultipleSensorAggregator.java | 7 +- .../brooklyn/enricher/basic/Aggregator.java | 8 +- .../brooklyn/entity/basic/AbstractEntity.java | 32 ++++- .../entity/basic/DynamicGroupImpl.java | 5 +- .../entity/basic/ServiceStateLogic.java | 10 +- .../AbstractMembershipTrackingPolicy.java | 4 +- .../rebind/PeriodicDeltaChangeListener.java | 4 +- .../entity/rebind/RebindManagerImpl.java | 136 +++++++++++------- ...BrooklynMementoPersisterToObjectStore.java | 16 ++- .../brooklyn/event/basic/AttributeMap.java | 6 +- .../ManagementPlaneSyncRecordDeltaImpl.java | 11 ++ ...PlaneSyncRecordPersisterToObjectStore.java | 12 +- .../brooklyn/management/ha/OsgiManager.java | 11 +- .../internal/LocalEntityManager.java | 4 +- .../internal/LocalLocationManager.java | 12 +- .../management/usage/LocationUsage.java | 2 +- .../location/jclouds/JcloudsUtil.java | 2 +- .../java/brooklyn/util/javalang/Equals.java | 59 ++++++++ .../main/java/brooklyn/util/time/Time.java | 4 +- .../java/brooklyn/util/time/TimeTest.java | 4 +- 27 files changed, 344 insertions(+), 113 deletions(-) create mode 100644 utils/common/src/main/java/brooklyn/util/javalang/Equals.java diff --git a/core/src/main/java/brooklyn/catalog/internal/BasicBrooklynCatalog.java b/core/src/main/java/brooklyn/catalog/internal/BasicBrooklynCatalog.java index 0236999a48..4d319646dc 100644 --- a/core/src/main/java/brooklyn/catalog/internal/BasicBrooklynCatalog.java +++ b/core/src/main/java/brooklyn/catalog/internal/BasicBrooklynCatalog.java @@ -123,9 +123,9 @@ public void reset(CatalogDto dto) { mgmt.getRebindManager().getChangeListener().onUnmanaged(toRemove); } CatalogDo catalog = new CatalogDo(mgmt, dto); - log.debug("Resetting "+this+" catalog to "+dto); + CatalogUtils.logDebugOrTraceIfRebinding(log, "Resetting "+this+" catalog to "+dto); catalog.load(mgmt, null); - log.debug("Reloaded catalog for "+this+", now switching"); + CatalogUtils.logDebugOrTraceIfRebinding(log, "Reloaded catalog for "+this+", now switching"); this.catalog = catalog; // Inject management context into and persist all the new entries. @@ -158,7 +158,7 @@ public void reset(CatalogDto dto) { */ @Override public void reset(Collection> entries) { - CatalogDto newDto = CatalogDto.newDtoFromCatalogItems(entries); + CatalogDto newDto = CatalogDto.newDtoFromCatalogItems(entries, "explicit-catalog-reset"); reset(newDto); } diff --git a/core/src/main/java/brooklyn/catalog/internal/CatalogDo.java b/core/src/main/java/brooklyn/catalog/internal/CatalogDo.java index 0ac65fcaf8..33552f0994 100644 --- a/core/src/main/java/brooklyn/catalog/internal/CatalogDo.java +++ b/core/src/main/java/brooklyn/catalog/internal/CatalogDo.java @@ -94,6 +94,7 @@ public synchronized CatalogDo load(ManagementContext mgmt, CatalogDo parent) { protected synchronized void loadThisCatalog(ManagementContext mgmt, CatalogDo parent) { if (isLoaded()) return; + CatalogUtils.logDebugOrTraceIfRebinding(log, "Loading catalog {} into {}", this, parent); if (this.parent!=null && !this.parent.equals(parent)) log.warn("Catalog "+this+" being initialised with different parent "+parent+" when already parented by "+this.parent, new Throwable("source of reparented "+this)); if (this.mgmt!=null && !this.mgmt.equals(mgmt)) @@ -173,7 +174,7 @@ protected Map> getRegisteredTypeNameCache() { @SuppressWarnings({ "unchecked", "rawtypes" }) protected synchronized Map> buildCaches() { if (cacheById != null) return cacheById; - log.debug("Building cache for "+this); + CatalogUtils.logDebugOrTraceIfRebinding(log, "Building cache for {}", this); if (!isLoaded()) log.debug("Catalog not fully loaded when loading cache of "+this); diff --git a/core/src/main/java/brooklyn/catalog/internal/CatalogDto.java b/core/src/main/java/brooklyn/catalog/internal/CatalogDto.java index 88c8901ce4..0d98c82110 100644 --- a/core/src/main/java/brooklyn/catalog/internal/CatalogDto.java +++ b/core/src/main/java/brooklyn/catalog/internal/CatalogDto.java @@ -120,9 +120,16 @@ public static CatalogDto newLinkedInstance(String url) { return result; } - @SuppressWarnings({ "unchecked", "rawtypes" }) + /** @deprecated since 0.7.0 use {@link #newDtoFromCatalogItems(Collection, String)}, supplying a description for tracking */ + @Deprecated public static CatalogDto newDtoFromCatalogItems(Collection> entries) { + return newDtoFromCatalogItems(entries, null); + } + + @SuppressWarnings({ "unchecked", "rawtypes" }) + public static CatalogDto newDtoFromCatalogItems(Collection> entries, String description) { CatalogDto result = new CatalogDto(); + result.contentsDescription = description; // Weird casts because compiler does not seem to like // .copyInto(Lists.>newArrayListWithExpectedSize(entries.size())); result.entries = (List>) (List) FluentIterable.from(entries) @@ -140,7 +147,7 @@ void populate() { LOG.debug("Catalog DTO has no contents and no description; ignoring call to populate it. Description should be set to suppress this message."); return; } else { - LOG.debug("Nothing needs doing (no contents or URL) for catalog with contents described as "+contentsDescription+"."); + LOG.trace("Nothing needs doing (no contents or URL) for catalog with contents described as "+contentsDescription+"."); return; } } diff --git a/core/src/main/java/brooklyn/catalog/internal/CatalogItemDo.java b/core/src/main/java/brooklyn/catalog/internal/CatalogItemDo.java index 7bcf9ec5c1..b3ac88d575 100644 --- a/core/src/main/java/brooklyn/catalog/internal/CatalogItemDo.java +++ b/core/src/main/java/brooklyn/catalog/internal/CatalogItemDo.java @@ -24,6 +24,7 @@ import brooklyn.catalog.CatalogItem; import brooklyn.entity.rebind.RebindSupport; import brooklyn.management.ManagementContext; +import brooklyn.mementos.CatalogItemMemento; import com.google.common.base.Preconditions; @@ -152,7 +153,7 @@ public String getPlanYaml() { } @Override - public RebindSupport getRebindSupport() { + public RebindSupport getRebindSupport() { return itemDto.getRebindSupport(); } } diff --git a/core/src/main/java/brooklyn/catalog/internal/CatalogLibrariesDto.java b/core/src/main/java/brooklyn/catalog/internal/CatalogLibrariesDto.java index ba07c21a37..bcbd25bae9 100644 --- a/core/src/main/java/brooklyn/catalog/internal/CatalogLibrariesDto.java +++ b/core/src/main/java/brooklyn/catalog/internal/CatalogLibrariesDto.java @@ -63,9 +63,11 @@ public static CatalogLibrariesDto from(Collection possibleLibraries) { CatalogLibrariesDto dto = new CatalogLibrariesDto(); for (Object object : possibleLibraries) { if (object instanceof Map) { + @SuppressWarnings("rawtypes") Map entry = (Map) object; - String name = stringValOrNull(entry, "name"); - String version = stringValOrNull(entry, "version"); + // these might be useful in the future +// String name = stringValOrNull(entry, "name"); +// String version = stringValOrNull(entry, "version"); String url = stringValOrNull(entry, "url"); dto.addBundle(url); } else if (object instanceof String) { @@ -77,6 +79,7 @@ public static CatalogLibrariesDto from(Collection possibleLibraries) { return dto; } + @SuppressWarnings("rawtypes") private static String stringValOrNull(Map map, String key) { Object val = map.get(key); return val != null ? String.valueOf(val) : null; diff --git a/core/src/main/java/brooklyn/catalog/internal/CatalogUtils.java b/core/src/main/java/brooklyn/catalog/internal/CatalogUtils.java index 5b6b81d99c..6fd1f94019 100644 --- a/core/src/main/java/brooklyn/catalog/internal/CatalogUtils.java +++ b/core/src/main/java/brooklyn/catalog/internal/CatalogUtils.java @@ -25,6 +25,7 @@ import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import com.google.common.annotations.Beta; import com.google.common.base.Joiner; import com.google.common.base.Stopwatch; @@ -33,7 +34,9 @@ import brooklyn.catalog.CatalogItem; import brooklyn.catalog.CatalogItem.CatalogItemLibraries; import brooklyn.catalog.internal.BasicBrooklynCatalog.BrooklynLoaderTracker; +import brooklyn.config.BrooklynLogging; import brooklyn.entity.Entity; +import brooklyn.entity.rebind.RebindManagerImpl.RebindTracker; import brooklyn.management.ManagementContext; import brooklyn.management.classloading.BrooklynClassLoadingContext; import brooklyn.management.classloading.BrooklynClassLoadingContextSequential; @@ -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 {}: {}", new Object[] {managementContext, Joiner.on(", ").join(bundles)}); Stopwatch timer = Stopwatch.createStarted(); for (String bundleUrl : bundles) { osgi.get().registerBundle(bundleUrl); } - if (log.isDebugEnabled()) log.debug("Registered {} bundles in {}", - new Object[]{bundles.size(), Time.makeTimeStringRounded(timer)}); + if (log.isDebugEnabled()) + logDebugOrTraceIfRebinding(log, + "Registered {} bundles in {}", + new Object[]{bundles.size(), Time.makeTimeStringRounded(timer)}); } } @@ -112,7 +119,9 @@ public static String getCatalogItemIdFromLoader(BrooklynClassLoadingContext load public static void setCatalogItemIdOnAddition(Entity entity, BrooklynObject itemBeingAdded) { if (entity.getCatalogItemId()!=null) { if (itemBeingAdded.getCatalogItemId()==null) { - log.debug("Catalog item addition: "+entity+" from "+entity.getCatalogItemId()+" applying its catalog item ID to "+itemBeingAdded); + if (log.isDebugEnabled()) + BrooklynLogging.log(log, BrooklynLogging.levelDebugOrTraceIfReadOnly(entity), + "Catalog item addition: "+entity+" from "+entity.getCatalogItemId()+" applying its catalog item ID to "+itemBeingAdded); ((BrooklynObjectInternal)itemBeingAdded).setCatalogItemId(entity.getCatalogItemId()); } else { if (!itemBeingAdded.getCatalogItemId().equals(entity.getCatalogItemId())) { @@ -120,9 +129,20 @@ public static void setCatalogItemIdOnAddition(Entity entity, BrooklynObject item log.debug("Cross-catalog item detected: "+entity+" from "+entity.getCatalogItemId()+" has "+itemBeingAdded+" from "+itemBeingAdded.getCatalogItemId()); } } - } else if (itemBeingAdded.getCatalogItemId()==null) { - log.debug("Catalog item addition: "+entity+" without catalog item ID has "+itemBeingAdded+" from "+itemBeingAdded.getCatalogItemId()); + } else if (itemBeingAdded.getCatalogItemId()!=null) { + if (log.isDebugEnabled()) + BrooklynLogging.log(log, BrooklynLogging.levelDebugOrTraceIfReadOnly(entity), + "Catalog item addition: "+entity+" without catalog item ID has "+itemBeingAdded+" from "+itemBeingAdded.getCatalogItemId()); } } + @Beta + public static void logDebugOrTraceIfRebinding(Logger log, String message, Object ...args) { + if (RebindTracker.isRebinding()) + log.trace(message, args); + else + log.debug(message, args); + } + + } diff --git a/core/src/main/java/brooklyn/config/BrooklynLogging.java b/core/src/main/java/brooklyn/config/BrooklynLogging.java index 729d819db9..8a27ebd531 100644 --- a/core/src/main/java/brooklyn/config/BrooklynLogging.java +++ b/core/src/main/java/brooklyn/config/BrooklynLogging.java @@ -18,6 +18,11 @@ */ package brooklyn.config; +import org.slf4j.Logger; + +import brooklyn.entity.Entity; +import brooklyn.entity.basic.EntityInternal; + /** contains common logging categories */ public class BrooklynLogging { @@ -25,4 +30,45 @@ public class BrooklynLogging { 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) { + case ERROR: logger.error(message, args); break; + case WARN: logger.warn(message, args); break; + case INFO: logger.info(message, args); break; + case DEBUG: logger.debug(message, args); break; + case TRACE: logger.trace(message, args); break; + } + } + + /** As methods on {@link Logger} but taking the level as an argument */ + public static final void log(Logger logger, LoggingLevel level, String message, Throwable t) { + switch (level) { + case ERROR: logger.error(message, t); break; + case WARN: logger.warn(message, t); break; + case INFO: logger.info(message, t); break; + case DEBUG: logger.debug(message, t); break; + case TRACE: logger.trace(message, t); break; + } + } + + /** returns one of three log levels depending on the read-only status of the entity; + * unknown should only be the case very early in the management cycle */ + public static LoggingLevel levelDependingIfReadOnly(Entity entity, LoggingLevel levelIfWriting, LoggingLevel levelIfReadOnly, LoggingLevel levelIfUnknown) { + if (entity==null) return levelIfUnknown; + Boolean ro = ((EntityInternal)entity).getManagementSupport().isReadOnlyRaw(); + if (ro==null) return levelIfUnknown; + if (ro) return levelIfReadOnly; + return levelIfWriting; + } + + /** as {@link #levelDependendingIfReadOnly(Entity)} with {@link LoggingLevel#DEBUG} as the default, + * but {@link LoggingLevel#TRACE} for read-only */ + public static LoggingLevel levelDebugOrTraceIfReadOnly(Entity entity) { + return levelDependingIfReadOnly(entity, LoggingLevel.DEBUG, LoggingLevel.TRACE, LoggingLevel.DEBUG); + } + } diff --git a/core/src/main/java/brooklyn/enricher/basic/AbstractMultipleSensorAggregator.java b/core/src/main/java/brooklyn/enricher/basic/AbstractMultipleSensorAggregator.java index 486307c889..b40c2347ee 100644 --- a/core/src/main/java/brooklyn/enricher/basic/AbstractMultipleSensorAggregator.java +++ b/core/src/main/java/brooklyn/enricher/basic/AbstractMultipleSensorAggregator.java @@ -26,6 +26,7 @@ import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import brooklyn.config.BrooklynLogging; import brooklyn.entity.Entity; import brooklyn.event.AttributeSensor; import brooklyn.event.Sensor; @@ -57,7 +58,8 @@ protected void setEntityLoadingConfig() { @Override protected void setEntityBeforeSubscribingProducerChildrenEvents() { - if (LOG.isDebugEnabled()) LOG.debug("{} subscribing to children of {}", new Object[] {this, producer }); + BrooklynLogging.log(LOG, BrooklynLogging.levelDebugOrTraceIfReadOnly(producer), + "{} subscribing to children of {}", this, producer); for (Sensor sourceSensor: getSourceSensors()) { subscribeToChildren(producer, sourceSensor, this); } @@ -84,7 +86,8 @@ protected void addProducerMember(Entity producer) { @Override protected void onProducerAdded(Entity producer) { - if (LOG.isDebugEnabled()) LOG.debug("{} listening to {}", new Object[] {this, producer}); + BrooklynLogging.log(LOG, BrooklynLogging.levelDebugOrTraceIfReadOnly(producer), + "{} listening to {}", this, producer); synchronized (values) { for (Sensor sensor: getSourceSensors()) { Map vs = values.get(sensor.getName()); diff --git a/core/src/main/java/brooklyn/enricher/basic/Aggregator.java b/core/src/main/java/brooklyn/enricher/basic/Aggregator.java index fc20033411..3e896db516 100644 --- a/core/src/main/java/brooklyn/enricher/basic/Aggregator.java +++ b/core/src/main/java/brooklyn/enricher/basic/Aggregator.java @@ -28,7 +28,9 @@ import org.slf4j.LoggerFactory; import brooklyn.catalog.Catalog; +import brooklyn.config.BrooklynLogging; import brooklyn.config.ConfigKey; +import brooklyn.config.BrooklynLogging.LoggingLevel; import brooklyn.entity.Entity; import brooklyn.entity.basic.ConfigKeys; import brooklyn.event.AttributeSensor; @@ -74,7 +76,8 @@ protected void setEntityLoadingConfig() { @Override protected void setEntityBeforeSubscribingProducerChildrenEvents() { - if (LOG.isDebugEnabled()) LOG.debug("{} subscribing to children of {}", new Object[] {this, producer }); + BrooklynLogging.log(LOG, BrooklynLogging.levelDebugOrTraceIfReadOnly(producer), + "{} subscribing to children of {}", this, producer); subscribeToChildren(producer, sourceSensor, this); } @@ -98,7 +101,8 @@ protected void addProducerMember(Entity producer) { @Override protected void onProducerAdded(Entity producer) { - if (LOG.isDebugEnabled()) LOG.debug("{} listening to {}", new Object[] {this, producer}); + BrooklynLogging.log(LOG, BrooklynLogging.levelDebugOrTraceIfReadOnly(producer), + "{} listening to {}", this, producer); synchronized (values) { T vo = values.get(producer); if (vo==null) { diff --git a/core/src/main/java/brooklyn/entity/basic/AbstractEntity.java b/core/src/main/java/brooklyn/entity/basic/AbstractEntity.java index 034bea71a7..c5ca83a252 100644 --- a/core/src/main/java/brooklyn/entity/basic/AbstractEntity.java +++ b/core/src/main/java/brooklyn/entity/basic/AbstractEntity.java @@ -33,6 +33,7 @@ import brooklyn.basic.AbstractBrooklynObject; import brooklyn.catalog.internal.CatalogUtils; +import brooklyn.config.BrooklynLogging; import brooklyn.config.ConfigKey; import brooklyn.config.ConfigKey.HasConfigKey; import brooklyn.config.render.RendererHints; @@ -89,6 +90,7 @@ import brooklyn.util.flags.FlagUtils; import brooklyn.util.flags.TypeCoercions; import brooklyn.util.guava.Maybe; +import brooklyn.util.javalang.Equals; import brooklyn.util.task.DeferredSupplier; import brooklyn.util.text.Strings; @@ -802,10 +804,20 @@ public T setAttribute(AttributeSensor attribute, T val) { LOG.trace(""+this+" setAttribute "+attribute+" "+val); if (Boolean.TRUE.equals(getManagementSupport().isReadOnlyRaw())) { - if (WARNED_READ_ONLY_ATTRIBUTES.add(attribute.getName())) { - LOG.warn(""+this+" setting "+attribute+" = "+val+" in read only mode; will have no effect (future messages for this sensor logged at trace)"); - } else if (LOG.isTraceEnabled()) { - LOG.trace(""+this+" setting "+attribute+" = "+val+" in read only mode; will have no effect"); + T oldVal = getAttribute(attribute); + if (Equals.approximately(val, oldVal)) { + // ignore, probably an enricher resetting values or something on init + } else { + String message = this+" setting "+attribute+" = "+val+" (was "+oldVal+") in read only mode; will have very little effect"; + if (!getManagementSupport().isDeployed()) { + if (getManagementSupport().wasDeployed()) message += " (no longer deployed)"; + else message += " (not yet deployed)"; + } + if (WARNED_READ_ONLY_ATTRIBUTES.add(attribute.getName())) { + LOG.warn(message + " (future messages for this sensor logged at trace)"); + } else if (LOG.isTraceEnabled()) { + LOG.trace(message); + } } } T result = attributesInternal.update(attribute, val); @@ -840,10 +852,15 @@ public T modifyAttribute(AttributeSensor attribute, Function void emit(Sensor sensor, T val) { LOG.warn("Strongly discouraged use of emit with sensor event as value "+sensor+" "+val+"; value should be unpacked!", new Throwable("location of discouraged event "+sensor+" emit")); } - if (LOG.isDebugEnabled()) LOG.debug("Emitting sensor notification {} value {} on {}", new Object[] {sensor.getName(), val, this}); + BrooklynLogging.log(LOG, BrooklynLogging.levelDebugOrTraceIfReadOnly(this), + "Emitting sensor notification {} value {} on {}", sensor.getName(), val, this); emitInternal(sensor, val); } diff --git a/core/src/main/java/brooklyn/entity/basic/DynamicGroupImpl.java b/core/src/main/java/brooklyn/entity/basic/DynamicGroupImpl.java index 2d5a76fab2..5241d749de 100644 --- a/core/src/main/java/brooklyn/entity/basic/DynamicGroupImpl.java +++ b/core/src/main/java/brooklyn/entity/basic/DynamicGroupImpl.java @@ -26,6 +26,8 @@ import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import brooklyn.config.BrooklynLogging; +import brooklyn.config.BrooklynLogging.LoggingLevel; import brooklyn.entity.Entity; import brooklyn.event.Sensor; import brooklyn.event.SensorEvent; @@ -192,7 +194,8 @@ public void rescanEntities() { return; } if (getApplication() == null) { - log.warn("{} not (yet) scanning for children: no application defined", this); + BrooklynLogging.log(log, BrooklynLogging.levelDependingIfReadOnly(this, LoggingLevel.WARN, LoggingLevel.TRACE, LoggingLevel.TRACE), + "{} not (yet) scanning for children: no application defined", this); return; } boolean changed = false; diff --git a/core/src/main/java/brooklyn/entity/basic/ServiceStateLogic.java b/core/src/main/java/brooklyn/entity/basic/ServiceStateLogic.java index 7ceab81189..898de8fb0b 100644 --- a/core/src/main/java/brooklyn/entity/basic/ServiceStateLogic.java +++ b/core/src/main/java/brooklyn/entity/basic/ServiceStateLogic.java @@ -29,7 +29,9 @@ import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import brooklyn.config.BrooklynLogging; import brooklyn.config.ConfigKey; +import brooklyn.config.BrooklynLogging.LoggingLevel; import brooklyn.enricher.Enrichers; import brooklyn.enricher.basic.AbstractEnricher; import brooklyn.enricher.basic.AbstractMultipleSensorAggregator; @@ -142,7 +144,7 @@ public static void updateMapSensorEntry(EntityLocal entity, Attribut public static void setExpectedState(Entity entity, Lifecycle state) { if (state==Lifecycle.RUNNING) { Boolean up = ((EntityInternal)entity).getAttribute(Attributes.SERVICE_UP); - if (!Boolean.TRUE.equals(up)) { + if (!Boolean.TRUE.equals(up) && !Boolean.TRUE.equals(Entities.isReadOnly(entity))) { // pause briefly to allow any recent problem-clearing processing to complete Stopwatch timer = Stopwatch.createStarted(); boolean nowUp = Repeater.create().every(Duration.millis(10)).limitTimeTo(Duration.millis(200)).until(entity, @@ -313,7 +315,8 @@ protected void setActualState(@Nullable Lifecycle state) { if (log.isTraceEnabled()) log.trace("{} setting actual state {}", this, state); if (((EntityInternal)entity).getManagementSupport().isNoLongerManaged()) { // won't catch everything, but catches some - log.debug(entity+" is no longer managed when told to set actual state to "+state+"; suppressing"); + BrooklynLogging.log(log, BrooklynLogging.levelDebugOrTraceIfReadOnly(entity), + entity+" is no longer managed when told to set actual state to "+state+"; suppressing"); return; } emit(SERVICE_STATE_ACTUAL, (state==null ? Entities.REMOVE : state)); @@ -440,7 +443,8 @@ protected Collection> getSourceSensors() { protected void onUpdated() { if (entity==null || !Entities.isManaged(entity)) { // either invoked during setup or entity has become unmanaged; just ignore - if (log.isDebugEnabled()) log.debug("Ignoring {} onUpdated when entity is not in valid state ({})", this, entity); + BrooklynLogging.log(log, BrooklynLogging.levelDebugOrTraceIfReadOnly(entity), + "Ignoring {} onUpdated when entity is not in valid state ({})", this, entity); return; } diff --git a/core/src/main/java/brooklyn/entity/group/AbstractMembershipTrackingPolicy.java b/core/src/main/java/brooklyn/entity/group/AbstractMembershipTrackingPolicy.java index 12100cde07..abc5e9d507 100644 --- a/core/src/main/java/brooklyn/entity/group/AbstractMembershipTrackingPolicy.java +++ b/core/src/main/java/brooklyn/entity/group/AbstractMembershipTrackingPolicy.java @@ -26,6 +26,7 @@ import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import brooklyn.config.BrooklynLogging; import brooklyn.config.ConfigKey; import brooklyn.entity.Entity; import brooklyn.entity.Group; @@ -162,7 +163,8 @@ protected Group getGroup() { protected void subscribeToGroup(final Group group) { Preconditions.checkNotNull(group, "The group must not be null"); - LOG.debug("Subscribing to group "+group+", for memberAdded, memberRemoved, and {}", getSensorsToTrack()); + BrooklynLogging.log(LOG, BrooklynLogging.levelDebugOrTraceIfReadOnly(group), + "Subscribing to group "+group+", for memberAdded, memberRemoved, and {}", getSensorsToTrack()); subscribe(group, DynamicGroup.MEMBER_ADDED, new SensorEventListener() { @Override public void onEvent(SensorEvent event) { diff --git a/core/src/main/java/brooklyn/entity/rebind/PeriodicDeltaChangeListener.java b/core/src/main/java/brooklyn/entity/rebind/PeriodicDeltaChangeListener.java index 3ae6916deb..1696767804 100644 --- a/core/src/main/java/brooklyn/entity/rebind/PeriodicDeltaChangeListener.java +++ b/core/src/main/java/brooklyn/entity/rebind/PeriodicDeltaChangeListener.java @@ -168,7 +168,7 @@ public Void call() { } catch (Exception e) { // Don't rethrow: the behaviour of executionManager is different from a scheduledExecutorService, // if we throw an exception, then our task will never get executed again - LOG.warn("Problem persisting change-delta", e); + LOG.error("Problem persisting change-delta", e); return null; } catch (Throwable t) { LOG.warn("Problem persisting change-delta (rethrowing)", t); @@ -332,7 +332,7 @@ public void persistNow() { addReferencedObjects(prevDeltaCollector); - if (LOG.isDebugEnabled()) LOG.debug("Persister delta with references: " + if (LOG.isTraceEnabled()) LOG.trace("Persister delta with references: " + "updating {} entities, {} locations, {} policies, {} enrichers, {} catalog items; " + "removing {} entities, {} locations, {} policies, {} enrichers, {} catalog items", new Object[] { diff --git a/core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java b/core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java index 09101f6131..c2b271e370 100644 --- a/core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java +++ b/core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java @@ -39,8 +39,10 @@ import brooklyn.catalog.CatalogLoadMode; import brooklyn.catalog.internal.BasicBrooklynCatalog; import brooklyn.catalog.internal.CatalogUtils; +import brooklyn.config.BrooklynLogging; import brooklyn.config.BrooklynServerConfig; import brooklyn.config.ConfigKey; +import brooklyn.config.BrooklynLogging.LoggingLevel; import brooklyn.enricher.basic.AbstractEnricher; import brooklyn.entity.Application; import brooklyn.entity.Entity; @@ -95,10 +97,13 @@ import brooklyn.util.task.Tasks; import brooklyn.util.text.Strings; import brooklyn.util.time.Duration; +import brooklyn.util.time.Time; import com.google.api.client.repackaged.com.google.common.base.Preconditions; +import com.google.common.annotations.Beta; import com.google.common.annotations.VisibleForTesting; import com.google.common.base.Optional; +import com.google.common.base.Stopwatch; import com.google.common.collect.ImmutableMap; import com.google.common.collect.Lists; import com.google.common.collect.Maps; @@ -141,6 +146,7 @@ public class RebindManagerImpl implements RebindManager { private volatile boolean readOnlyRunning = false; private volatile ScheduledTask readOnlyTask = null; private transient Semaphore rebindActive = new Semaphore(1); + private transient int readOnlyRebindCount = Integer.MIN_VALUE; private volatile BrooklynMementoPersister persistenceStoreAccess; @@ -161,6 +167,7 @@ public class RebindManagerImpl implements RebindManager { * * @author aled */ + @Beta public static class RebindTracker { private static ThreadLocal rebinding = new ThreadLocal(); @@ -191,7 +198,7 @@ public RebindManagerImpl(ManagementContextInternal managementContext) { addPolicyFailureMode = managementContext.getConfig().getConfig(ADD_POLICY_FAILURE_MODE); loadPolicyFailureMode = managementContext.getConfig().getConfig(LOAD_POLICY_FAILURE_MODE); - LOG.debug("Persistence in {} of: policies={}, enrichers={}, feeds={}, catalog={}", + LOG.debug("{} initialized, settings: policies={}, enrichers={}, feeds={}, catalog={}", new Object[]{this, persistPoliciesEnabled, persistEnrichersEnabled, persistFeedsEnabled, persistCatalogItemsEnabled}); } @@ -251,15 +258,16 @@ public void startPersistence() { if (readOnlyRunning) { throw new IllegalStateException("Cannot start read-only when already running with persistence"); } - LOG.debug("Starting persistence, mgmt "+managementContext.getManagementNodeId()); + LOG.debug("Starting persistence ("+this+"), mgmt "+managementContext.getManagementNodeId()); persistenceRunning = true; + readOnlyRebindCount = Integer.MIN_VALUE; persistenceStoreAccess.enableWriteAccess(); if (persistenceRealChangeListener != null) persistenceRealChangeListener.start(); } @Override public void stopPersistence() { - LOG.debug("Stopping rebind (persistence), mgmt "+managementContext.getManagementNodeId()); + LOG.debug("Stopping persistence ("+this+"), mgmt "+managementContext.getManagementNodeId()); persistenceRunning = false; if (persistenceRealChangeListener != null) persistenceRealChangeListener.stop(); if (persistenceStoreAccess != null) persistenceStoreAccess.disableWriteAccess(true); @@ -276,12 +284,13 @@ public void startReadOnly() { LOG.warn("Cannot request read-only mode for "+this+" when already running - "+readOnlyTask+"; ignoring"); return; } - LOG.debug("Starting read-only rebinding, mgmt "+managementContext.getManagementNodeId()); + LOG.debug("Starting read-only rebinding ("+this+"), mgmt "+managementContext.getManagementNodeId()); if (persistenceRealChangeListener != null) persistenceRealChangeListener.stop(); if (persistenceStoreAccess != null) persistenceStoreAccess.disableWriteAccess(true); readOnlyRunning = true; + readOnlyRebindCount = 0; try { rebind(null, null, ManagementNodeState.HOT_STANDBY); @@ -295,21 +304,24 @@ public void startReadOnly() { public Void call() { try { rebind(null, null, ManagementNodeState.HOT_STANDBY); + readOnlyRebindCount++; return null; } catch (RuntimeInterruptedException e) { LOG.debug("Interrupted rebinding (re-interrupting): "+e); if (LOG.isTraceEnabled()) - LOG.trace("Interrupted rebinding (re-interrupting): "+e, e); + LOG.trace("Interrupted rebinding (re-interrupting), details: "+e, e); Thread.currentThread().interrupt(); return null; } catch (Exception e) { // Don't rethrow: the behaviour of executionManager is different from a scheduledExecutorService, // if we throw an exception, then our task will never get executed again if (!readOnlyRunning) { - if (LOG.isTraceEnabled()) - LOG.trace("Problem rebinding (read-only running turned off): "+e, e); + LOG.debug("Problem rebinding (read-only running has probably just been turned off): "+e); + if (LOG.isTraceEnabled()) { + LOG.trace("Problem rebinding (read-only running has probably just been turned off), details: "+e, e); + } } else { - LOG.warn("Problem rebinding: "+Exceptions.collapseText(e), e); + LOG.error("Problem rebinding: "+Exceptions.collapseText(e), e); } return null; } catch (Throwable t) { @@ -327,7 +339,7 @@ public Void call() { public void stopReadOnly() { readOnlyRunning = false; if (readOnlyTask!=null) { - LOG.debug("Stopping read-only rebinding, mgmt "+managementContext.getManagementNodeId()); + LOG.debug("Stopping read-only rebinding ("+this+"), mgmt "+managementContext.getManagementNodeId()); readOnlyTask.cancel(true); readOnlyTask.blockUntilEnded(); boolean reallyEnded = Tasks.blockUntilInternalTasksEnded(readOnlyTask, Duration.TEN_SECONDS); @@ -335,7 +347,7 @@ public void stopReadOnly() { LOG.warn("Rebind (read-only) tasks took too long to die after interrupt (ignoring): "+readOnlyTask); } readOnlyTask = null; - LOG.debug("Stopped read-only rebinding, mgmt "+managementContext.getManagementNodeId()); + LOG.debug("Stopped read-only rebinding ("+this+"), mgmt "+managementContext.getManagementNodeId()); } } @@ -476,6 +488,7 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi } catch (InterruptedException e1) { Exceptions.propagate(e1); } RebindTracker.setRebinding(); try { + Stopwatch timer = Stopwatch.createStarted(); exceptionHandler.onStart(); Reflections reflections = new Reflections(classLoader); @@ -527,20 +540,18 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi //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()+"..."); BrooklynMementoManifest mementoManifest = persistenceStoreAccess.loadMementoManifest(exceptionHandler); boolean isEmpty = mementoManifest.isEmpty(); - if (!isEmpty) { - if (mode==ManagementNodeState.HOT_STANDBY) - LOG.debug("Rebinding (read-only) from "+getPersister().getBackingStoreDescription()+"..."); - else + if (mode!=ManagementNodeState.HOT_STANDBY) { + if (!isEmpty) { LOG.info("Rebinding from "+getPersister().getBackingStoreDescription()+"..."); - } else { - if (mode==ManagementNodeState.HOT_STANDBY) - LOG.debug("Rebind check (read-only): no existing state, reading from "+getPersister().getBackingStoreDescription()); - else + } else { LOG.info("Rebind check: no existing state; will persist new items to "+getPersister().getBackingStoreDescription()); + } } // @@ -549,7 +560,7 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi // Instantiate catalog items if (persistCatalogItemsEnabled) { - LOG.debug("RebindManager instantiating catalog items: {}", mementoManifest.getCatalogItemIds()); + logRebindingDebug("RebindManager instantiating catalog items: {}", mementoManifest.getCatalogItemIds()); for (CatalogItemMemento catalogItemMemento : mementoManifest.getCatalogItemMementos().values()) { if (LOG.isDebugEnabled()) LOG.debug("RebindManager instantiating catalog item {}", catalogItemMemento); try { @@ -560,15 +571,15 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi } } } else { - LOG.debug("Not rebinding catalog; feature disabled: {}", mementoManifest.getCatalogItemIds()); + logRebindingDebug("Not rebinding catalog; feature disabled: {}", mementoManifest.getCatalogItemIds()); } // Reconstruct catalog entries if (persistCatalogItemsEnabled) { - LOG.debug("RebindManager reconstructing catalog items"); + logRebindingDebug("RebindManager reconstructing catalog items"); for (CatalogItemMemento catalogItemMemento : mementoManifest.getCatalogItemMementos().values()) { CatalogItem item = rebindContext.getCatalogItem(catalogItemMemento.getId()); - LOG.debug("RebindManager reconstructing catalog item {}", catalogItemMemento); + logRebindingDebug("RebindManager reconstructing catalog item {}", catalogItemMemento); if (item == null) { exceptionHandler.onNotFound(BrooklynObjectType.CATALOG_ITEM, catalogItemMemento.getId()); } else { @@ -593,27 +604,27 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi || (isEmpty && catalogLoadMode == CatalogLoadMode.LOAD_BROOKLYN_CATALOG_URL_IF_NO_PERSISTED_STATE); if (shouldResetCatalog) { // Reset catalog with previously persisted state - LOG.debug("RebindManager resetting management context catalog to previously persisted state"); + logRebindingDebug("RebindManager resetting management context catalog to previously persisted state"); managementContext.getCatalog().reset(rebindContext.getCatalogItems()); } else if (shouldLoadDefaultCatalog) { // Load catalogue as normal // TODO in read-only mode, should do this less frequently than entities etc - LOG.debug("RebindManager loading default catalog"); + logRebindingDebug("RebindManager loading default catalog"); ((BasicBrooklynCatalog) managementContext.getCatalog()).resetCatalogToContentsAtConfiguredUrl(); } else { // Management context should have taken care of loading the catalogue Collection> catalogItems = rebindContext.getCatalogItems(); String message = "RebindManager not resetting catalog to persisted state. Catalog load mode is {}."; - if (!catalogItems.isEmpty()) { + if (!catalogItems.isEmpty() && shouldLogRebinding()) { LOG.info(message + " There {} {} item{} persisted.", new Object[]{ catalogLoadMode, catalogItems.size() == 1 ? "was" : "were", catalogItems.size(), Strings.s(catalogItems)}); } else if (LOG.isDebugEnabled()) { - LOG.debug(message, catalogLoadMode); + logRebindingDebug(message, catalogLoadMode); } } // TODO destroy old (as above) } else { - LOG.debug("RebindManager not resetting catalog because catalog persistence is disabled"); + logRebindingDebug("RebindManager not resetting catalog because catalog persistence is disabled"); } @@ -622,7 +633,7 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi // // Instantiate locations - LOG.debug("RebindManager instantiating locations: {}", mementoManifest.getLocationIdToType().keySet()); + logRebindingDebug("RebindManager instantiating locations: {}", mementoManifest.getLocationIdToType().keySet()); for (Map.Entry entry : mementoManifest.getLocationIdToType().entrySet()) { String locId = entry.getKey(); String locType = entry.getValue(); @@ -637,7 +648,7 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi } // Instantiate entities - LOG.debug("RebindManager instantiating entities: {}", mementoManifest.getEntityIdToManifest().keySet()); + logRebindingDebug("RebindManager instantiating entities: {}", mementoManifest.getEntityIdToManifest().keySet()); for (Map.Entry entry : mementoManifest.getEntityIdToManifest().entrySet()) { String entityId = entry.getKey(); EntityMementoManifest entityManifest = entry.getValue(); @@ -668,9 +679,9 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi // Instantiate policies if (persistPoliciesEnabled) { - LOG.debug("RebindManager instantiating policies: {}", memento.getPolicyIds()); + logRebindingDebug("RebindManager instantiating policies: {}", memento.getPolicyIds()); for (PolicyMemento policyMemento : memento.getPolicyMementos().values()) { - if (LOG.isDebugEnabled()) LOG.debug("RebindManager instantiating policy {}", policyMemento); + logRebindingDebug("RebindManager instantiating policy {}", policyMemento); try { Policy policy = newPolicy(policyMemento, getLoadingContextFromCatalogItemId(policyMemento.getCatalogItemId(), classLoader, rebindContext)); @@ -680,14 +691,14 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi } } } else { - LOG.debug("Not rebinding policies; feature disabled: {}", memento.getPolicyIds()); + logRebindingDebug("Not rebinding policies; feature disabled: {}", memento.getPolicyIds()); } // Instantiate enrichers if (persistEnrichersEnabled) { - LOG.debug("RebindManager instantiating enrichers: {}", memento.getEnricherIds()); + logRebindingDebug("RebindManager instantiating enrichers: {}", memento.getEnricherIds()); for (EnricherMemento enricherMemento : memento.getEnricherMementos().values()) { - if (LOG.isDebugEnabled()) LOG.debug("RebindManager instantiating enricher {}", enricherMemento); + logRebindingDebug("RebindManager instantiating enricher {}", enricherMemento); try { Enricher enricher = newEnricher(enricherMemento, reflections); @@ -697,12 +708,12 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi } } } else { - LOG.debug("Not rebinding enrichers; feature disabled: {}", memento.getEnricherIds()); + logRebindingDebug("Not rebinding enrichers; feature disabled: {}", memento.getEnricherIds()); } // Instantiate feeds if (persistFeedsEnabled) { - LOG.debug("RebindManager instantiating feeds: {}", memento.getFeedIds()); + logRebindingDebug("RebindManager instantiating feeds: {}", memento.getFeedIds()); for (FeedMemento feedMemento : memento.getFeedMementos().values()) { if (LOG.isDebugEnabled()) LOG.debug("RebindManager instantiating feed {}", feedMemento); @@ -714,7 +725,7 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi } } } else { - LOG.debug("Not rebinding feeds; feature disabled: {}", memento.getFeedIds()); + logRebindingDebug("Not rebinding feeds; feature disabled: {}", memento.getFeedIds()); } // @@ -722,10 +733,10 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi // // Reconstruct locations - LOG.debug("RebindManager reconstructing locations"); + logRebindingDebug("RebindManager reconstructing locations"); for (LocationMemento locMemento : sortParentFirst(memento.getLocationMementos()).values()) { Location location = rebindContext.getLocation(locMemento.getId()); - if (LOG.isDebugEnabled()) LOG.debug("RebindManager reconstructing location {}", locMemento); + logRebindingDebug("RebindManager reconstructing location {}", locMemento); if (location == null) { // usually because of creation-failure, when not using fail-fast exceptionHandler.onNotFound(BrooklynObjectType.LOCATION, locMemento.getId()); @@ -740,10 +751,10 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi // Reconstruct policies if (persistPoliciesEnabled) { - LOG.debug("RebindManager reconstructing policies"); + logRebindingDebug("RebindManager reconstructing policies"); for (PolicyMemento policyMemento : memento.getPolicyMementos().values()) { Policy policy = rebindContext.getPolicy(policyMemento.getId()); - if (LOG.isDebugEnabled()) LOG.debug("RebindManager reconstructing policy {}", policyMemento); + logRebindingDebug("RebindManager reconstructing policy {}", policyMemento); if (policy == null) { // usually because of creation-failure, when not using fail-fast @@ -761,10 +772,10 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi // Reconstruct enrichers if (persistEnrichersEnabled) { - LOG.debug("RebindManager reconstructing enrichers"); + logRebindingDebug("RebindManager reconstructing enrichers"); for (EnricherMemento enricherMemento : memento.getEnricherMementos().values()) { Enricher enricher = rebindContext.getEnricher(enricherMemento.getId()); - if (LOG.isDebugEnabled()) LOG.debug("RebindManager reconstructing enricher {}", enricherMemento); + logRebindingDebug("RebindManager reconstructing enricher {}", enricherMemento); if (enricher == null) { // usually because of creation-failure, when not using fail-fast @@ -782,10 +793,10 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi // Reconstruct feeds if (persistFeedsEnabled) { - LOG.debug("RebindManager reconstructing feeds"); + logRebindingDebug("RebindManager reconstructing feeds"); for (FeedMemento feedMemento : memento.getFeedMementos().values()) { Feed feed = rebindContext.getFeed(feedMemento.getId()); - if (LOG.isDebugEnabled()) LOG.debug("RebindManager reconstructing feed {}", feedMemento); + logRebindingDebug("RebindManager reconstructing feed {}", feedMemento); if (feed == null) { // usually because of creation-failure, when not using fail-fast @@ -803,10 +814,10 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi } // Reconstruct entities - LOG.debug("RebindManager reconstructing entities"); + logRebindingDebug("RebindManager reconstructing entities"); for (EntityMemento entityMemento : sortParentFirst(memento.getEntityMementos()).values()) { Entity entity = rebindContext.getEntity(entityMemento.getId()); - if (LOG.isDebugEnabled()) LOG.debug("RebindManager reconstructing entity {}", entityMemento); + logRebindingDebug("RebindManager reconstructing entity {}", entityMemento); if (entity == null) { // usually because of creation-failure, when not using fail-fast @@ -826,10 +837,10 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi // // Associate policies+enrichers+feeds with entities - LOG.debug("RebindManager reconstructing entities"); + logRebindingDebug("RebindManager reconstructing entities"); for (EntityMemento entityMemento : sortParentFirst(memento.getEntityMementos()).values()) { Entity entity = rebindContext.getEntity(entityMemento.getId()); - if (LOG.isDebugEnabled()) LOG.debug("RebindManager reconstructing entity {}", entityMemento); + logRebindingDebug("RebindManager reconstructing entity {}", entityMemento); if (entity == null) { // usually because of creation-failure, when not using fail-fast @@ -853,7 +864,7 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi // PHASE EIGHT // - LOG.debug("RebindManager managing locations"); + logRebindingDebug("RebindManager managing locations"); LocationManagerInternal locationManager = (LocationManagerInternal)managementContext.getLocationManager(); Set oldLocations = Sets.newLinkedHashSet(locationManager.getLocationIds()); for (Location location: rebindContext.getLocations()) { @@ -878,7 +889,7 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi } // Manage the top-level apps (causing everything under them to become managed) - LOG.debug("RebindManager managing entities"); + logRebindingDebug("RebindManager managing entities"); EntityManagerInternal entityManager = (EntityManagerInternal)managementContext.getEntityManager(); Set oldEntities = Sets.newLinkedHashSet(entityManager.getEntityIds()); for (Entity entity: rebindContext.getEntities()) { @@ -909,9 +920,11 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi exceptionHandler.onDone(); - if (!isEmpty && mode!=ManagementNodeState.HOT_STANDBY) { - LOG.info("Rebind complete: {} app{}, {} entit{}, {} location{}, {} polic{}, {} enricher{}, {} feed{}, {} catalog item{}", new Object[]{ - apps.size(), Strings.s(apps), + if (!isEmpty) { + BrooklynLogging.log(LOG, shouldLogRebinding() ? LoggingLevel.INFO : LoggingLevel.DEBUG, + "Rebind complete " + "("+mode+(readOnlyRebindCount>=0 ? ", iteration "+readOnlyRebindCount : "")+")" + + " in {}: {} app{}, {} entit{}, {} location{}, {} polic{}, {} enricher{}, {} feed{}, {} catalog item{}", new Object[]{ + Time.makeTimeStringRounded(timer), apps.size(), Strings.s(apps), rebindContext.getEntities().size(), Strings.ies(rebindContext.getEntities()), rebindContext.getLocations().size(), Strings.s(rebindContext.getLocations()), rebindContext.getPolicies().size(), Strings.ies(rebindContext.getPolicies()), @@ -922,7 +935,7 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi } // Return the top-level applications - LOG.debug("RebindManager complete; return apps: {}", memento.getApplicationIds()); + logRebindingDebug("RebindManager complete; apps: {}", memento.getApplicationIds()); return apps; } catch (Exception e) { @@ -1235,7 +1248,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); + } + @Override public String toString() { return super.toString()+"[mgmt="+managementContext.getManagementNodeId()+"]"; diff --git a/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterToObjectStore.java b/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterToObjectStore.java index 6ab8a7c0f7..8faa80ff1d 100644 --- a/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterToObjectStore.java +++ b/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterToObjectStore.java @@ -301,10 +301,11 @@ public void visit(String contents, BrooklynObjectType type, String subPath) thro BrooklynMementoManifest result = builder.build(); if (LOG.isDebugEnabled()) { - LOG.debug("Loaded memento manifest; took {}; {} entities, {} locations, {} policies, {} enrichers, {} feeds, {} catalog items, from {}", new Object[]{ - Time.makeTimeStringRounded(stopwatch.elapsed(TimeUnit.MILLISECONDS)), result.getEntityIdToManifest().size(), - result.getLocationIdToType().size(), result.getPolicyIdToType().size(), result.getEnricherIdToType().size(), - result.getFeedIdToType().size(), result.getCatalogItemMementos().size(), + LOG.debug("Loaded rebind manifests; took {}: {} entities, {} locations, {} policies, {} enrichers, {} feeds, {} catalog items; from {}", new Object[]{ + Time.makeTimeStringRounded(stopwatch), + result.getEntityIdToManifest().size(), result.getLocationIdToType().size(), + result.getPolicyIdToType().size(), result.getEnricherIdToType().size(), result.getFeedIdToType().size(), + result.getCatalogItemMementos().size(), objectStore.getSummaryName() }); } @@ -343,7 +344,7 @@ public void visit(String contents, BrooklynObjectType type, String subPath) thro BrooklynMemento result = builder.build(); if (LOG.isDebugEnabled()) { - LOG.debug("Loaded memento; took {}; {} entities, {} locations, {} policies, {} enrichers, {} feeds, {} catalog items, from {}", new Object[]{ + LOG.debug("Loaded rebind mementos; took {}: {} entities, {} locations, {} policies, {} enrichers, {} feeds, {} catalog items, from {}", new Object[]{ Time.makeTimeStringRounded(stopwatch.elapsed(TimeUnit.MILLISECONDS)), result.getEntityIds().size(), result.getLocationIds().size(), result.getPolicyIds().size(), result.getEnricherIds().size(), result.getFeedIds().size(), result.getCatalogItemIds().size(), @@ -364,6 +365,7 @@ protected void visitMemento(final Visitor visitor, final RebindExceptionHandler List feedSubPathList; List catalogSubPathList; + Stopwatch stopwatch = Stopwatch.createStarted(); try { entitySubPathList = objectStore.listContentsWithSubPath("entities"); locationSubPathList = objectStore.listContentsWithSubPath("locations"); @@ -377,7 +379,8 @@ protected void visitMemento(final Visitor visitor, final RebindExceptionHandler throw new IllegalStateException("Failed to list memento files in "+objectStore, e); } - LOG.debug("Scanning persisted state: {} entities, {} locations, {} policies, {} enrichers, {} feeds, {} catalog items from {}", new Object[]{ + LOG.debug("Loaded rebind lists; took {}: {} entities, {} locations, {} policies, {} enrichers, {} feeds, {} catalog items; from {}", new Object[]{ + Time.makeTimeStringRounded(stopwatch), entitySubPathList.size(), locationSubPathList.size(), policySubPathList.size(), enricherSubPathList.size(), feedSubPathList.size(), catalogSubPathList.size(), objectStore.getSummaryName() }); @@ -498,7 +501,6 @@ public void checkpoint(BrooklynMementoRawData newMemento, PersistenceExceptionHa Futures.successfulAsList(futures).get(); Futures.allAsList(futures).get(); } catch (Exception e) { - // TODO is the logging here as good as it was prior to https://github.com/apache/incubator-brooklyn/pull/177/files ? throw Exceptions.propagate(e); } diff --git a/core/src/main/java/brooklyn/event/basic/AttributeMap.java b/core/src/main/java/brooklyn/event/basic/AttributeMap.java index 08f1f91b18..da933c7f5a 100644 --- a/core/src/main/java/brooklyn/event/basic/AttributeMap.java +++ b/core/src/main/java/brooklyn/event/basic/AttributeMap.java @@ -27,6 +27,7 @@ import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import brooklyn.config.BrooklynLogging; import brooklyn.entity.Entity; import brooklyn.entity.basic.AbstractEntity; import brooklyn.event.AttributeSensor; @@ -153,9 +154,8 @@ public T modify(AttributeSensor attribute, Function> } public void remove(AttributeSensor attribute) { - if (log.isDebugEnabled()) { - log.debug("removing attribute {} on {}", attribute.getName(), entity); - } + BrooklynLogging.log(log, BrooklynLogging.levelDebugOrTraceIfReadOnly(entity), + "removing attribute {} on {}", attribute.getName(), entity); remove(attribute.getNameParts()); } diff --git a/core/src/main/java/brooklyn/management/ha/ManagementPlaneSyncRecordDeltaImpl.java b/core/src/main/java/brooklyn/management/ha/ManagementPlaneSyncRecordDeltaImpl.java index b54b9ef101..6b026bc77b 100644 --- a/core/src/main/java/brooklyn/management/ha/ManagementPlaneSyncRecordDeltaImpl.java +++ b/core/src/main/java/brooklyn/management/ha/ManagementPlaneSyncRecordDeltaImpl.java @@ -25,6 +25,7 @@ import brooklyn.management.ha.ManagementPlaneSyncRecordPersister.Delta; +import com.google.api.client.repackaged.com.google.common.base.Objects; import com.google.common.annotations.Beta; import com.google.common.collect.Sets; @@ -108,4 +109,14 @@ public String getNewMasterOrNull() { public String getExpectedMasterToClear() { return expectedOldMaster; } + + @Override + public String toString() { + return getClass().getCanonicalName()+"["+ + (masterChange!=null && masterChange != MasterChange.NO_CHANGE ? + masterChange+": "+expectedOldMaster+"->"+masterId+"; " : "")+ + "nodes: "+nodes+ + (removedNodeIds!=null && !removedNodeIds.isEmpty() ? "; removing: "+removedNodeIds : "") + +"]"; + } } diff --git a/core/src/main/java/brooklyn/management/ha/ManagementPlaneSyncRecordPersisterToObjectStore.java b/core/src/main/java/brooklyn/management/ha/ManagementPlaneSyncRecordPersisterToObjectStore.java index 950f2b87c3..b9cf4653cb 100644 --- a/core/src/main/java/brooklyn/management/ha/ManagementPlaneSyncRecordPersisterToObjectStore.java +++ b/core/src/main/java/brooklyn/management/ha/ManagementPlaneSyncRecordPersisterToObjectStore.java @@ -236,7 +236,8 @@ public void delta(Delta delta) { } init(); - if (LOG.isDebugEnabled()) LOG.debug("Checkpointed delta of manager-memento; updating {}", delta); + Stopwatch stopwatch = Stopwatch.createStarted(); + if (LOG.isTraceEnabled()) LOG.trace("Checkpointing delta of manager-memento; updating {}", delta); for (ManagementNodeSyncRecord m : delta.getNodes()) { persist(m); @@ -256,15 +257,18 @@ public void delta(Delta delta) { default: throw new IllegalStateException("Unknown state for master-change: "+delta.getMasterChange()); } + if (LOG.isDebugEnabled()) LOG.debug("Checkpointed delta of manager-memento in "+Time.makeTimeStringRounded(stopwatch)+": "+delta); } private void persistMaster(String nodeId, String optionalExpectedId) { if (optionalExpectedId!=null) { String currentRemoteMaster = masterWriter.get(); if (currentRemoteMaster==null) { - // nothing at remote is okay + // okay to have nothing at remote } else if (!currentRemoteMaster.trim().equals(optionalExpectedId.trim())) { - LOG.warn("Master at server is "+currentRemoteMaster+"; expected "+optionalExpectedId+" in order to set as "+nodeId+", so not applying (yet)"); + LOG.warn("Master at server is "+currentRemoteMaster+"; expected "+optionalExpectedId+" " + + (Strings.isNonBlank(nodeId) ? "and would set as "+nodeId : "and would clear") + + ", so not applying (yet)"); return; } } @@ -333,5 +337,5 @@ private StoreObjectAccessorWithLock getOrCreateNodeWriter(String nodeId) { } return writer; } - + } diff --git a/core/src/main/java/brooklyn/management/ha/OsgiManager.java b/core/src/main/java/brooklyn/management/ha/OsgiManager.java index 7f6ca5274c..3dea979dcc 100644 --- a/core/src/main/java/brooklyn/management/ha/OsgiManager.java +++ b/core/src/main/java/brooklyn/management/ha/OsgiManager.java @@ -35,6 +35,7 @@ import brooklyn.util.exceptions.Exceptions; import brooklyn.util.guava.Maybe; import brooklyn.util.os.Os; +import brooklyn.util.os.Os.DeletionResult; import brooklyn.util.osgi.Osgis; import com.google.common.base.Throwables; @@ -76,7 +77,11 @@ public void stop() { } catch (InterruptedException e) { throw Exceptions.propagate(e); } - osgiTempDir = Os.deleteRecursively(osgiTempDir).asNullOrThrowing(); + DeletionResult deleteRecursively = Os.deleteRecursively(osgiTempDir); + if (deleteRecursively.getThrowable()!=null) { + log.debug("Unable to delete "+osgiTempDir+" (possibly already deleted?): "+deleteRecursively.getThrowable()); + } + osgiTempDir = null; framework = null; } @@ -85,12 +90,14 @@ public void registerBundle(String bundleUrl) { String nv = bundleUrlToNameVersionString.get(bundleUrl); if (nv!=null) { if (Osgis.getBundle(framework, nv).isPresent()) { - log.debug("Bundle from "+bundleUrl+" already installed as "+nv+"; not re-registering"); + log.trace("Bundle from "+bundleUrl+" already installed as "+nv+"; not re-registering"); return; } } Bundle b = Osgis.install(framework, bundleUrl); nv = b.getSymbolicName()+":"+b.getVersion().toString(); + // TODO if there is another entry for name:version we should log a warning at the very least, + // or better provide a way to get back *this* bundle bundleUrlToNameVersionString.put(bundleUrl, nv); log.debug("Bundle from "+bundleUrl+" successfully installed as " + nv + " ("+b+")"); } catch (BundleException e) { diff --git a/core/src/main/java/brooklyn/management/internal/LocalEntityManager.java b/core/src/main/java/brooklyn/management/internal/LocalEntityManager.java index 8a10727fdd..fdb087b205 100644 --- a/core/src/main/java/brooklyn/management/internal/LocalEntityManager.java +++ b/core/src/main/java/brooklyn/management/internal/LocalEntityManager.java @@ -34,6 +34,7 @@ import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import brooklyn.config.BrooklynLogging; import brooklyn.entity.Application; import brooklyn.entity.Entity; import brooklyn.entity.Group; @@ -575,7 +576,8 @@ private synchronized boolean manageNonRecursive(Entity e, ManagementTransitionMo return false; } - if (log.isDebugEnabled()) log.debug("{} starting management of entity {}", this, e); + BrooklynLogging.log(log, BrooklynLogging.levelDebugOrTraceIfReadOnly(e), + "{} starting management of entity {}", this, e); Entity realE = toRealEntity(e); Entity oldProxy = entityProxiesById.get(e.getId()); diff --git a/core/src/main/java/brooklyn/management/internal/LocalLocationManager.java b/core/src/main/java/brooklyn/management/internal/LocalLocationManager.java index bbb5c19b1d..f81cb9808d 100644 --- a/core/src/main/java/brooklyn/management/internal/LocalLocationManager.java +++ b/core/src/main/java/brooklyn/management/internal/LocalLocationManager.java @@ -28,6 +28,8 @@ import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import brooklyn.config.BrooklynLogging; +import brooklyn.config.BrooklynLogging.LoggingLevel; import brooklyn.config.ConfigKey; import brooklyn.entity.basic.ConfigKeys; import brooklyn.entity.basic.Lifecycle; @@ -212,11 +214,13 @@ protected Location manageRecursive(Location loc, final ManagementTransitionMode long count = LOCATION_CNT.incrementAndGet(); if (log.isDebugEnabled()) { String msg = "Managing location " + loc + " ("+initialMode+"), from " + Tasks.current()+" / "+Entitlements.getEntitlementContext(); + LoggingLevel level = (initialMode==ManagementTransitionMode.REBINDING_READONLY ? LoggingLevel.TRACE : LoggingLevel.DEBUG); if (count % 100 == 0) { // include trace periodically in case we get leaks or too much location management - log.debug(msg, new Exception("Informational stack trace of call to manage location "+loc+" ("+count+" calls; "+getLocations().size()+" currently managed)")); + BrooklynLogging.log(log, level, + msg, new Exception("Informational stack trace of call to manage location "+loc+" ("+count+" calls; "+getLocations().size()+" currently managed)")); } else { - log.debug(msg); + BrooklynLogging.log(log, level, msg); } } @@ -240,7 +244,9 @@ protected Location manageRecursive(Location loc, final ManagementTransitionMode it.setManagementContext(managementContext); if (!mode.isReadOnly()) { it.onManagementStarted(); - recordLocationEvent(it, Lifecycle.CREATED); + if (!mode.wasReadOnly()) { + recordLocationEvent(it, Lifecycle.CREATED); + } } managementContext.getRebindManager().getChangeListener().onManaged(it); } diff --git a/core/src/main/java/brooklyn/management/usage/LocationUsage.java b/core/src/main/java/brooklyn/management/usage/LocationUsage.java index 8757404365..f04055e2e3 100644 --- a/core/src/main/java/brooklyn/management/usage/LocationUsage.java +++ b/core/src/main/java/brooklyn/management/usage/LocationUsage.java @@ -47,7 +47,7 @@ public LocationEvent(Lifecycle state, String entityId, String entityType, String this.state = checkNotNull(state, "state"); this.entityId = checkNotNull(entityId, "entityId"); this.entityType = checkNotNull(entityType, "entityType"); - this.applicationId = checkNotNull(applicationId, "applicationId"); + this.applicationId = checkNotNull(applicationId, "applicationId (entity "+entityId+")"); } public Date getDate() { diff --git a/locations/jclouds/src/main/java/brooklyn/location/jclouds/JcloudsUtil.java b/locations/jclouds/src/main/java/brooklyn/location/jclouds/JcloudsUtil.java index 540c707fec..e70749566a 100644 --- a/locations/jclouds/src/main/java/brooklyn/location/jclouds/JcloudsUtil.java +++ b/locations/jclouds/src/main/java/brooklyn/location/jclouds/JcloudsUtil.java @@ -277,7 +277,7 @@ public static ComputeService findComputeService(ConfigBag conf, boolean allowReu if (allowReuse) { ComputeService result = cachedComputeServices.get(cacheKey); if (result!=null) { - LOG.debug("jclouds ComputeService cache hit for compute service, for "+Entities.sanitize(properties)); + LOG.trace("jclouds ComputeService cache hit for compute service, for "+Entities.sanitize(properties)); return result; } LOG.debug("jclouds ComputeService cache miss for compute service, creating, for "+Entities.sanitize(properties)); diff --git a/utils/common/src/main/java/brooklyn/util/javalang/Equals.java b/utils/common/src/main/java/brooklyn/util/javalang/Equals.java new file mode 100644 index 0000000000..89736b4b92 --- /dev/null +++ b/utils/common/src/main/java/brooklyn/util/javalang/Equals.java @@ -0,0 +1,59 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ +package brooklyn.util.javalang; + +import com.google.common.annotations.Beta; +import com.google.common.base.Objects; + + +public class Equals { + + /** Tests whether the objects given are either all null or all equal to the first argument */ + public static boolean objects(Object o1, Object o2, Object... oo) { + if (!Objects.equal(o1, o2)) return false; + for (Object o: oo) + if (!Objects.equal(o1, o)) return false; + return true; + } + + /** Tests whether the two objects given are either all null or all approximately equal + * (tolerance of 0.001 for floating point, but subject to change) */ + // relatively high tolerance mainly due to enrichers such as Tomcat windowed average, in hot standby; + // could make smaller + @Beta + public static boolean approximately(Object o1, Object o2) { + if (o1 instanceof Number) { + if (o2 instanceof Number) { + return Math.abs( ((Number)o2).doubleValue()-((Number)o1).doubleValue() ) < 0.001; + } + } + return Objects.equal(o1, o2); + } + + /** As {@link #approximately(Object, Object)} but testing all the arguments given. */ + @Beta + public static boolean approximately(Object o1, Object o2, Object o3, Object... oo) { + if (!approximately(o1, o2)) return false; + if (!approximately(o1, o3)) return false; + for (Object o: oo) + if (!approximately(o1, o)) return false; + return true; + } + +} diff --git a/utils/common/src/main/java/brooklyn/util/time/Time.java b/utils/common/src/main/java/brooklyn/util/time/Time.java index 60025a4429..7c0612fac7 100644 --- a/utils/common/src/main/java/brooklyn/util/time/Time.java +++ b/utils/common/src/main/java/brooklyn/util/time/Time.java @@ -134,7 +134,9 @@ public static String makeTimeStringNanoRounded(long tn) { /** @see #makeTimeString(long, boolean) */ public static String makeTimeStringNano(long tn, boolean round) { if (tn<0) return "-"+makeTimeStringNano(-tn, round); - if (tn==0) return "0"; + // units don't matter, but since ms is the usual finest granularity let's use it + // (previously was just "0" but that was too ambiguous in contexts like "took 0") + if (tn==0) return "0ms"; long tnm = tn % 1000000; long t = tn/1000000; diff --git a/utils/common/src/test/java/brooklyn/util/time/TimeTest.java b/utils/common/src/test/java/brooklyn/util/time/TimeTest.java index 363abce774..0771b903bf 100644 --- a/utils/common/src/test/java/brooklyn/util/time/TimeTest.java +++ b/utils/common/src/test/java/brooklyn/util/time/TimeTest.java @@ -129,11 +129,11 @@ public void testDateRoundingNull() { } @Test - public void testMakeStringExactZero() { check(0, "0"); } + public void testMakeStringExactZero() { check(0, "0ms"); } @Test public void testMakeStringExactNegative() { check(-1, "-1ms"); } @Test - public void testMakeStringRoundedZero() { checkR(0, "0"); } + public void testMakeStringRoundedZero() { checkR(0, "0ms"); } @Test public void testMakeStringRoundedNegative() { checkR(-1, "-1ms"); } From be5aac2574227c4089e8a8fa45f275a4539368f8 Mon Sep 17 00:00:00 2001 From: Alex Heneveld Date: Thu, 6 Nov 2014 02:01:31 +0000 Subject: [PATCH 3/4] optimize rebind process remove extraneous obj store lists+reads from process, and a bunch of code/redundancy tidy, and a bit more log tidy --- .../entity/rebind/BrooklynObjectType.java | 28 +- .../mementos/BrooklynMementoPersister.java | 35 ++- .../mementos/BrooklynMementoRawData.java | 43 +++ .../rebind/PeriodicDeltaChangeListener.java | 4 +- .../entity/rebind/PersisterDeltaImpl.java | 31 ++ .../rebind/RebindExceptionHandlerImpl.java | 6 +- .../entity/rebind/RebindManagerImpl.java | 5 +- .../dto/BrooklynMementoManifestImpl.java | 15 + .../AbstractBrooklynMementoPersister.java | 18 +- .../BrooklynMementoPersisterInMemory.java | 5 +- .../BrooklynMementoPersisterToMultiFile.java | 16 + ...BrooklynMementoPersisterToObjectStore.java | 292 ++++++++---------- .../ha/HighAvailabilityManagerImpl.java | 10 +- .../entity/rebind/RebindFailuresTest.java | 3 +- .../entity/rebind/RebindTestFixture.java | 2 +- .../RecordingRebindExceptionHandler.java | 6 +- .../BrooklynMementoPersisterTestFixture.java | 2 +- 17 files changed, 325 insertions(+), 196 deletions(-) diff --git a/api/src/main/java/brooklyn/entity/rebind/BrooklynObjectType.java b/api/src/main/java/brooklyn/entity/rebind/BrooklynObjectType.java index d887ffe9cd..b00d3b35be 100644 --- a/api/src/main/java/brooklyn/entity/rebind/BrooklynObjectType.java +++ b/api/src/main/java/brooklyn/entity/rebind/BrooklynObjectType.java @@ -19,14 +19,28 @@ package brooklyn.entity.rebind; import com.google.common.annotations.Beta; +import com.google.common.base.CaseFormat; @Beta public enum BrooklynObjectType { - ENTITY, - LOCATION, - POLICY, - ENRICHER, - FEED, - CATALOG_ITEM, - UNKNOWN; + ENTITY("entities"), + LOCATION("locations"), + POLICY("policies"), + ENRICHER("enrichers"), + FEED("feeds"), + CATALOG_ITEM("catalog"), + UNKNOWN("unknown"); + + private final String subPathName; + + BrooklynObjectType(String subPathName) { + this.subPathName = subPathName; + } + public String toCamelCase() { + return CaseFormat.UPPER_UNDERSCORE.to(CaseFormat.LOWER_CAMEL, this.name()); + } + + public String getSubPathName() { + return subPathName; + } } \ No newline at end of file diff --git a/api/src/main/java/brooklyn/mementos/BrooklynMementoPersister.java b/api/src/main/java/brooklyn/mementos/BrooklynMementoPersister.java index 0317059620..229c7c373e 100644 --- a/api/src/main/java/brooklyn/mementos/BrooklynMementoPersister.java +++ b/api/src/main/java/brooklyn/mementos/BrooklynMementoPersister.java @@ -23,9 +23,13 @@ import java.util.concurrent.TimeUnit; import java.util.concurrent.TimeoutException; +import javax.annotation.Nullable; + +import brooklyn.basic.BrooklynObject; import brooklyn.catalog.CatalogItem; import brooklyn.entity.Entity; import brooklyn.entity.Feed; +import brooklyn.entity.rebind.BrooklynObjectType; import brooklyn.entity.rebind.PersistenceExceptionHandler; import brooklyn.entity.rebind.RebindExceptionHandler; import brooklyn.entity.rebind.RebindManager; @@ -52,13 +56,37 @@ public static interface LookupContext { Feed lookupFeed(String id); CatalogItem lookupCatalogItem(String id); } + + /** + * Loads raw data contents of the mementos. + *

+ * Some classes (esp deprecated ones) may return null here, + * meaning that the {@link #loadMementoManifest(BrooklynMementoRawData, RebindExceptionHandler)} + * and {@link #loadMemento(BrooklynMementoRawData, LookupContext, RebindExceptionHandler)} methods + * will populate the raw data via another source. + */ + BrooklynMementoRawData loadMementoRawData(RebindExceptionHandler exceptionHandler); + /** @deprecated since 0.7.0 use {@link #loadMementoManifest(BrooklynMementoRawData, RebindExceptionHandler)} */ BrooklynMementoManifest loadMementoManifest(RebindExceptionHandler exceptionHandler) throws IOException; - + /** - * Note that this method is *not* thread safe. + * Loads minimal manifest information (almost entirely *not* deserialized). + * Implementations should load the raw data if {@link BrooklynMementoRawData} is not supplied, + * but callers are encouraged to supply that for optimal performance. */ + BrooklynMementoManifest loadMementoManifest(@Nullable BrooklynMementoRawData mementoData, RebindExceptionHandler exceptionHandler) throws IOException; + + /** @deprecated since 0.7.0 use {@link #loadMemento(RebindExceptionHandler)} */ BrooklynMemento loadMemento(LookupContext lookupContext, RebindExceptionHandler exceptionHandler) throws IOException; + /** + * Retrieves the memento class, containing deserialized objects (but not the {@link BrooklynObject} class). + * Implementations should load the raw data if {@link BrooklynMementoRawData} is not supplied, + * but callers are encouraged to supply that for optimal performance. + *

+ * Note that this method is *not* thread safe. + */ + BrooklynMemento loadMemento(@Nullable BrooklynMementoRawData mementoData, LookupContext lookupContext, RebindExceptionHandler exceptionHandler) throws IOException; void checkpoint(BrooklynMemento memento, PersistenceExceptionHandler exceptionHandler); @@ -94,6 +122,9 @@ public interface Delta { Collection removedEnricherIds(); Collection removedFeedIds(); Collection removedCatalogItemIds(); + + Collection getObjectsOfType(BrooklynObjectType type); + Collection getRemovedObjectsOfType(BrooklynObjectType type); } } diff --git a/api/src/main/java/brooklyn/mementos/BrooklynMementoRawData.java b/api/src/main/java/brooklyn/mementos/BrooklynMementoRawData.java index abb61d4d39..32c72323b2 100644 --- a/api/src/main/java/brooklyn/mementos/BrooklynMementoRawData.java +++ b/api/src/main/java/brooklyn/mementos/BrooklynMementoRawData.java @@ -21,6 +21,8 @@ import java.util.Collections; import java.util.Map; +import brooklyn.entity.rebind.BrooklynObjectType; + import com.google.common.annotations.Beta; import com.google.common.collect.Maps; @@ -85,6 +87,34 @@ public Builder catalogItem(String id, String val) { public Builder catalogItems(Map vals) { catalogItems.putAll(vals); return this; } + + public Builder put(BrooklynObjectType type, String id, String val) { + switch (type) { + case ENTITY: return entity(id, val); + case LOCATION: return location(id, val); + case POLICY: return policy(id, val); + case ENRICHER: return enricher(id, val); + case FEED: return feed(id, val); + case CATALOG_ITEM: return catalogItem(id, val); + case UNKNOWN: + default: + throw new IllegalArgumentException(type+" not supported"); + } + } + public Builder putAll(BrooklynObjectType type, Map vals) { + switch (type) { + case ENTITY: return entities(vals); + case LOCATION: return locations(vals); + case POLICY: return policies(vals); + case ENRICHER: return enrichers(vals); + case FEED: return feeds(vals); + case CATALOG_ITEM: return catalogItems(vals); + case UNKNOWN: + default: + throw new IllegalArgumentException(type+" not supported"); + } + } + public BrooklynMementoRawData build() { return new BrooklynMementoRawData(this); } @@ -133,4 +163,17 @@ public Map getCatalogItems() { public boolean isEmpty() { return entities.isEmpty() && locations.isEmpty() && policies.isEmpty() && enrichers.isEmpty() && feeds.isEmpty() && catalogItems.isEmpty(); } + + public Map getObjectsOfType(BrooklynObjectType type) { + switch (type) { + case ENTITY: return getEntities(); + case LOCATION: return getLocations(); + case POLICY: return getPolicies(); + case ENRICHER: return getEnrichers(); + case FEED: return getFeeds(); + case CATALOG_ITEM: return getCatalogItems(); + default: + throw new IllegalArgumentException("Type "+type+" not supported"); + } + } } diff --git a/core/src/main/java/brooklyn/entity/rebind/PeriodicDeltaChangeListener.java b/core/src/main/java/brooklyn/entity/rebind/PeriodicDeltaChangeListener.java index 1696767804..b104365903 100644 --- a/core/src/main/java/brooklyn/entity/rebind/PeriodicDeltaChangeListener.java +++ b/core/src/main/java/brooklyn/entity/rebind/PeriodicDeltaChangeListener.java @@ -323,7 +323,7 @@ public void persistNow() { deltaCollector = new DeltaCollector(); } - if (LOG.isDebugEnabled()) LOG.debug("Persister delta as reported: " + if (LOG.isDebugEnabled()) LOG.debug("Checkpointing delta of memento: " + "updating entities={}, locations={}, policies={}, enrichers={}, catalog items={}; " + "removing entities={}, locations={}, policies={}, enrichers={}, catalog items={}", new Object[] { @@ -332,7 +332,7 @@ public void persistNow() { addReferencedObjects(prevDeltaCollector); - if (LOG.isTraceEnabled()) LOG.trace("Persister delta with references: " + if (LOG.isTraceEnabled()) LOG.trace("Checkpointing delta of memento with references: " + "updating {} entities, {} locations, {} policies, {} enrichers, {} catalog items; " + "removing {} entities, {} locations, {} policies, {} enrichers, {} catalog items", new Object[] { diff --git a/core/src/main/java/brooklyn/entity/rebind/PersisterDeltaImpl.java b/core/src/main/java/brooklyn/entity/rebind/PersisterDeltaImpl.java index fd19ebc2cf..c971a2f255 100644 --- a/core/src/main/java/brooklyn/entity/rebind/PersisterDeltaImpl.java +++ b/core/src/main/java/brooklyn/entity/rebind/PersisterDeltaImpl.java @@ -26,6 +26,7 @@ import brooklyn.mementos.EntityMemento; import brooklyn.mementos.FeedMemento; import brooklyn.mementos.LocationMemento; +import brooklyn.mementos.Memento; import brooklyn.mementos.PolicyMemento; import com.google.common.collect.Sets; @@ -164,4 +165,34 @@ public Collection removedFeedIds() { public Collection removedCatalogItemIds() { return removedCatalogItemIds; } + + @Override + public Collection getObjectsOfType(BrooklynObjectType type) { + switch (type) { + case ENTITY: return entities(); + case LOCATION: return locations(); + case POLICY: return policies(); + case ENRICHER: return enrichers(); + case FEED: return feeds(); + case CATALOG_ITEM: return catalogItems(); + case UNKNOWN: + default: + throw new IllegalArgumentException(type+" not supported"); + } + } + + @Override + public Collection getRemovedObjectsOfType(BrooklynObjectType type) { + switch (type) { + case ENTITY: return removedEntityIds(); + case LOCATION: return removedLocationIds(); + case POLICY: return removedPolicyIds(); + case ENRICHER: return removedEnricherIds(); + case FEED: return removedFeedIds(); + case CATALOG_ITEM: return removedCatalogItemIds(); + case UNKNOWN: + default: + throw new IllegalArgumentException(type+" not supported"); + } + } } diff --git a/core/src/main/java/brooklyn/entity/rebind/RebindExceptionHandlerImpl.java b/core/src/main/java/brooklyn/entity/rebind/RebindExceptionHandlerImpl.java index 870a03118c..f595e54568 100644 --- a/core/src/main/java/brooklyn/entity/rebind/RebindExceptionHandlerImpl.java +++ b/core/src/main/java/brooklyn/entity/rebind/RebindExceptionHandlerImpl.java @@ -222,7 +222,7 @@ public void onNotFound(BrooklynObjectType type, String id) { if (creationFailedIds.contains(id)) { // already know about this; ignore } else { - String errmsg = type+" '"+id+"' not found"; + String errmsg = type.toCamelCase()+" '"+id+"' not found"; exceptions.add(new IllegalStateException(errmsg)); onErrorImpl(errmsg); } @@ -231,7 +231,7 @@ public void onNotFound(BrooklynObjectType type, String id) { @Override public void onRebindFailed(BrooklynObjectType type, BrooklynObject instance, Exception e) { Exceptions.propagateIfFatal(e); - String errmsg = "problem rebinding "+type+" "+instance.getId()+" ("+instance+")"; + String errmsg = "problem rebinding "+type.toCamelCase()+" "+instance.getId()+" ("+instance+")"; switch (type) { case FEED: @@ -318,7 +318,7 @@ public void onAddFeedFailed(EntityLocal entity, Feed feed, Exception e) { @Override public void onManageFailed(BrooklynObjectType type, BrooklynObject instance, Exception e) { Exceptions.propagateIfFatal(e); - String errmsg = "problem managing "+type+" "+instance.getId()+" ("+instance+")"; + String errmsg = "problem managing "+type.toCamelCase()+" "+instance.getId()+" ("+instance+")"; exceptions.add(new IllegalStateException(errmsg, e)); onErrorImpl(errmsg, e); diff --git a/core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java b/core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java index c2b271e370..e29d94f4fb 100644 --- a/core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java +++ b/core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java @@ -543,7 +543,8 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi LOG.debug("Rebinding ("+mode+", iteration "+readOnlyRebindCount+") from "+getPersister().getBackingStoreDescription()+"..."); - BrooklynMementoManifest mementoManifest = persistenceStoreAccess.loadMementoManifest(exceptionHandler); + BrooklynMementoRawData mementoRawData = persistenceStoreAccess.loadMementoRawData(exceptionHandler); + BrooklynMementoManifest mementoManifest = persistenceStoreAccess.loadMementoManifest(mementoRawData, exceptionHandler); boolean isEmpty = mementoManifest.isEmpty(); if (mode!=ManagementNodeState.HOT_STANDBY) { @@ -670,7 +671,7 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi // PHASE FOUR // - BrooklynMemento memento = persistenceStoreAccess.loadMemento(realLookupContext, exceptionHandler); + BrooklynMemento memento = persistenceStoreAccess.loadMemento(mementoRawData, realLookupContext, exceptionHandler); // diff --git a/core/src/main/java/brooklyn/entity/rebind/dto/BrooklynMementoManifestImpl.java b/core/src/main/java/brooklyn/entity/rebind/dto/BrooklynMementoManifestImpl.java index 2b520030e7..485030915d 100644 --- a/core/src/main/java/brooklyn/entity/rebind/dto/BrooklynMementoManifestImpl.java +++ b/core/src/main/java/brooklyn/entity/rebind/dto/BrooklynMementoManifestImpl.java @@ -23,6 +23,7 @@ import java.util.Collections; import java.util.Map; +import brooklyn.entity.rebind.BrooklynObjectType; import brooklyn.mementos.BrooklynMementoManifest; import brooklyn.mementos.CatalogItemMemento; @@ -83,6 +84,20 @@ public Builder catalogItem(CatalogItemMemento val) { catalogItems.put(val.getId(), val); return this; } + public Builder putType(BrooklynObjectType type, String id, String javaType) { + switch (type) { + case ENTITY: throw new IllegalArgumentException(type.toCamelCase()+" requires additional parameters"); + case LOCATION: return location(id, javaType); + case POLICY: return policy(id, javaType); + case ENRICHER: return enricher(id, javaType); + case FEED: return feed(id, javaType); + case CATALOG_ITEM: throw new IllegalArgumentException(type.toCamelCase()+" requires different parameters"); + case UNKNOWN: + default: + throw new IllegalArgumentException(type.toCamelCase()+" not supported"); + } + } + public BrooklynMementoManifest build() { return new BrooklynMementoManifestImpl(this); } diff --git a/core/src/main/java/brooklyn/entity/rebind/persister/AbstractBrooklynMementoPersister.java b/core/src/main/java/brooklyn/entity/rebind/persister/AbstractBrooklynMementoPersister.java index 91baa26e2f..42643abbe4 100644 --- a/core/src/main/java/brooklyn/entity/rebind/persister/AbstractBrooklynMementoPersister.java +++ b/core/src/main/java/brooklyn/entity/rebind/persister/AbstractBrooklynMementoPersister.java @@ -26,6 +26,7 @@ import brooklyn.mementos.BrooklynMemento; import brooklyn.mementos.BrooklynMementoManifest; import brooklyn.mementos.BrooklynMementoPersister; +import brooklyn.mementos.BrooklynMementoRawData; import brooklyn.mementos.CatalogItemMemento; import brooklyn.mementos.EnricherMemento; import brooklyn.mementos.EntityMemento; @@ -42,13 +43,28 @@ public abstract class AbstractBrooklynMementoPersister implements BrooklynMement protected volatile MutableBrooklynMemento memento = new MutableBrooklynMemento(); @Override - public BrooklynMemento loadMemento(LookupContext lookupContext, RebindExceptionHandler exceptionHandler) { + public BrooklynMementoRawData loadMementoRawData(RebindExceptionHandler exceptionHandler) { + return null; + } + + @Override + public BrooklynMemento loadMemento(BrooklynMementoRawData mementoData, LookupContext lookupContext, RebindExceptionHandler exceptionHandler) { // Trusting people not to cast+modify, because the in-memory persister wouldn't be used in production code return memento; } + @Override + public BrooklynMemento loadMemento(LookupContext lookupContext, RebindExceptionHandler exceptionHandler) { + return loadMemento(null, lookupContext, exceptionHandler); + } + @Override public BrooklynMementoManifest loadMementoManifest(RebindExceptionHandler exceptionHandler) { + return loadMementoManifest(null, exceptionHandler); + } + + @Override + public BrooklynMementoManifest loadMementoManifest(BrooklynMementoRawData mementoData, RebindExceptionHandler exceptionHandler) { BrooklynMementoManifestImpl.Builder builder = BrooklynMementoManifestImpl.builder(); for (EntityMemento entity : memento.getEntityMementos().values()) { builder.entity(entity.getId(), entity.getType(), entity.getParent(), entity.getCatalogItemId()); diff --git a/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterInMemory.java b/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterInMemory.java index 847dfa70f2..f4e4fc0740 100644 --- a/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterInMemory.java +++ b/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterInMemory.java @@ -42,7 +42,6 @@ import brooklyn.management.ManagementContext; import brooklyn.mementos.BrooklynMemento; import brooklyn.mementos.BrooklynMementoManifest; -import brooklyn.mementos.BrooklynMementoManifest.EntityMementoManifest; import brooklyn.policy.Enricher; import brooklyn.policy.Policy; import brooklyn.util.collections.MutableList; @@ -116,7 +115,7 @@ private void reserializeMemento() { .build(); PersistenceExceptionHandler persistenceExceptionHandler = PersistenceExceptionHandlerImpl.builder().build(); persister.checkpoint(memento, persistenceExceptionHandler); - final BrooklynMementoManifest manifest = persister.loadMementoManifest(rebindExceptionHandler); + final BrooklynMementoManifest manifest = persister.loadMementoManifest(null, rebindExceptionHandler); LookupContext dummyLookupContext = new LookupContext() { @Override public ManagementContext lookupManagementContext() { @@ -181,7 +180,7 @@ private T invokeConstructor(Class clazz, Object[]... possibleArgs) { }; // Not actually reconstituting, because need to use a real lookupContext to reconstitute all the entities - persister.loadMemento(dummyLookupContext, rebindExceptionHandler); + persister.loadMemento(null, dummyLookupContext, rebindExceptionHandler); } finally { Os.deleteRecursively(tempDir); } diff --git a/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterToMultiFile.java b/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterToMultiFile.java index 2d0fe99ace..392a496abb 100644 --- a/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterToMultiFile.java +++ b/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterToMultiFile.java @@ -40,6 +40,7 @@ import brooklyn.mementos.BrooklynMemento; import brooklyn.mementos.BrooklynMementoManifest; import brooklyn.mementos.BrooklynMementoPersister; +import brooklyn.mementos.BrooklynMementoRawData; import brooklyn.mementos.CatalogItemMemento; import brooklyn.mementos.EnricherMemento; import brooklyn.mementos.EntityMemento; @@ -152,8 +153,18 @@ public void stop(boolean graceful) { } } + @Override + public BrooklynMementoRawData loadMementoRawData(RebindExceptionHandler exceptionHandler) { + return null; + } + @Override public BrooklynMementoManifest loadMementoManifest(RebindExceptionHandler exceptionHandler) throws IOException { + return loadMementoManifest(null, exceptionHandler); + } + + @Override + public BrooklynMementoManifest loadMementoManifest(BrooklynMementoRawData mementoData, RebindExceptionHandler exceptionHandler) throws IOException { if (!running) { throw new IllegalStateException("Persister not running; cannot load memento manifest from "+dir); } @@ -251,6 +262,11 @@ public BrooklynMementoManifest loadMementoManifest(RebindExceptionHandler except @Override public BrooklynMemento loadMemento(LookupContext lookupContext, RebindExceptionHandler exceptionHandler) throws IOException { + return loadMemento(null, lookupContext, exceptionHandler); + } + + @Override + public BrooklynMemento loadMemento(BrooklynMementoRawData mementoData, LookupContext lookupContext, RebindExceptionHandler exceptionHandler) throws IOException { if (!running) { throw new IllegalStateException("Persister not running; cannot load memento from "+dir); } diff --git a/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterToObjectStore.java b/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterToObjectStore.java index 8faa80ff1d..91b738f845 100644 --- a/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterToObjectStore.java +++ b/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterToObjectStore.java @@ -52,12 +52,8 @@ import brooklyn.mementos.BrooklynMementoPersister; import brooklyn.mementos.BrooklynMementoRawData; import brooklyn.mementos.CatalogItemMemento; -import brooklyn.mementos.EnricherMemento; -import brooklyn.mementos.EntityMemento; -import brooklyn.mementos.FeedMemento; -import brooklyn.mementos.LocationMemento; import brooklyn.mementos.Memento; -import brooklyn.mementos.PolicyMemento; +import brooklyn.util.collections.MutableMap; import brooklyn.util.exceptions.CompoundRuntimeException; import brooklyn.util.exceptions.Exceptions; import brooklyn.util.text.Strings; @@ -67,6 +63,7 @@ import com.google.common.annotations.Beta; import com.google.common.annotations.VisibleForTesting; +import com.google.common.base.Objects; import com.google.common.base.Stopwatch; import com.google.common.collect.ImmutableSet; import com.google.common.collect.Lists; @@ -96,6 +93,10 @@ public class BrooklynMementoPersisterToObjectStore implements BrooklynMementoPer "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[] { + BrooklynObjectType.ENTITY, BrooklynObjectType.LOCATION, BrooklynObjectType.POLICY, + BrooklynObjectType.ENRICHER, BrooklynObjectType.FEED, BrooklynObjectType.CATALOG_ITEM }; + private final PersistenceObjectStore objectStore; private final MementoSerializer serializer; @@ -192,46 +193,75 @@ protected StoreObjectAccessorWithLock getWriter(String path) { } } - @Beta - public BrooklynMementoRawData loadMementoRawData(final RebindExceptionHandler exceptionHandler) throws IOException { - final BrooklynMementoRawData.Builder builder = BrooklynMementoRawData.builder(); + private Map makeIdSubPathMap(Iterable subPathLists) { + Map result = MutableMap.of(); + for (String subpath: subPathLists) { + String id = subpath; + id = id.substring(id.lastIndexOf('/')+1); + id = id.substring(id.lastIndexOf('\\')+1); + // assumes id is the filename; should work even if not, as id is later read from xpath + // but you'll get warnings (and possibility of loss if there is a collision) + result.put(id, subpath); + } + return result; + } + + protected BrooklynMementoRawData listMementoSubPathsAsData(final RebindExceptionHandler exceptionHandler) { + final BrooklynMementoRawData.Builder subPathDataBuilder = BrooklynMementoRawData.builder(); - Visitor visitor = new Visitor() { + Stopwatch stopwatch = Stopwatch.createStarted(); + try { + for (BrooklynObjectType type: PERSISTED_OBJECT_TYPES_IN_ORDER) + subPathDataBuilder.putAll(type, makeIdSubPathMap(objectStore.listContentsWithSubPath(type.getSubPathName()))); + + } catch (Exception e) { + Exceptions.propagateIfFatal(e); + exceptionHandler.onLoadMementoFailed(BrooklynObjectType.UNKNOWN, "Failed to list files", e); + throw new IllegalStateException("Failed to list memento files in "+objectStore, e); + } + + BrooklynMementoRawData subPathData = subPathDataBuilder.build(); + LOG.debug("Loaded rebind lists; took {}: {} entities, {} locations, {} policies, {} enrichers, {} feeds, {} catalog items; from {}", new Object[]{ + Time.makeTimeStringRounded(stopwatch), + subPathData.getEntities().size(), subPathData.getLocations().size(), subPathData.getPolicies().size(), subPathData.getEnrichers().size(), + subPathData.getFeeds().size(), subPathData.getCatalogItems().size(), + objectStore.getSummaryName() }); + + return subPathData; + } + + public BrooklynMementoRawData loadMementoRawData(final RebindExceptionHandler exceptionHandler) { + BrooklynMementoRawData subPathData = listMementoSubPathsAsData(exceptionHandler); + + final BrooklynMementoRawData.Builder builder = BrooklynMementoRawData.builder(); + + Visitor loaderVisitor = new Visitor() { @Override - public void visit(String contents, BrooklynObjectType type, String subPath) throws Exception { - switch (type) { - case ENTITY: - builder.entity((String) XmlUtil.xpath(contents, "/entity/id"), contents); - break; - case LOCATION: - builder.location((String) XmlUtil.xpath(contents, "/location/id"), contents); - break; - case POLICY: - builder.policy((String) XmlUtil.xpath(contents, "/policy/id"), contents); - break; - case ENRICHER: - builder.enricher((String) XmlUtil.xpath(contents, "/enricher/id"), contents); - break; - case FEED: - builder.feed((String) XmlUtil.xpath(contents, "/feed/id"), contents); - break; - case CATALOG_ITEM: - builder.catalogItem((String) XmlUtil.xpath(contents, "/catalogItem/id"), contents); - break; - default: - throw new IllegalStateException("Unexpected brooklyn type: "+type); + public void visit(BrooklynObjectType type, String id, String contentsSubpath) throws Exception { + String contents = null; + try { + contents = read(contentsSubpath); + } catch (Exception e) { + Exceptions.propagateIfFatal(e); + exceptionHandler.onLoadMementoFailed(type, "memento "+id+" read error", e); } + + String xmlId = (String) XmlUtil.xpath(contents, "/"+type.toCamelCase()+"/id"); + if (!Objects.equal(id, xmlId)) + LOG.warn("ID mismatch on "+type.toCamelCase()+", "+id+" from path, "+xmlId+" from xml"); + + builder.put(type, xmlId, contents); } }; Stopwatch stopwatch = Stopwatch.createStarted(); - visitMemento(visitor, exceptionHandler); + visitMemento("loading raw", subPathData, loaderVisitor, exceptionHandler); BrooklynMementoRawData result = builder.build(); if (LOG.isDebugEnabled()) { - LOG.debug("Loaded memento manifest; took {}; {} entities, {} locations, {} policies, {} enrichers, {} feeds, {} catalog items, from {}", new Object[]{ + LOG.debug("Loaded rebind raw data; took {}; {} entities, {} locations, {} policies, {} enrichers, {} feeds, {} catalog items, from {}", new Object[]{ Time.makeTimeStringRounded(stopwatch.elapsed(TimeUnit.MILLISECONDS)), result.getEntities().size(), result.getLocations().size(), result.getPolicies().size(), result.getEnrichers().size(), result.getFeeds().size(), result.getCatalogItems().size(), @@ -243,49 +273,49 @@ public void visit(String contents, BrooklynObjectType type, String subPath) thro @Override public BrooklynMementoManifest loadMementoManifest(final RebindExceptionHandler exceptionHandler) throws IOException { + return loadMementoManifest(null, exceptionHandler); + } + + @Override + public BrooklynMementoManifest loadMementoManifest(BrooklynMementoRawData mementoData, final RebindExceptionHandler exceptionHandler) throws IOException { + if (mementoData==null) + mementoData = loadMementoRawData(exceptionHandler); + final BrooklynMementoManifestImpl.Builder builder = BrooklynMementoManifestImpl.builder(); Visitor visitor = new Visitor() { @Override - public void visit(String contents, BrooklynObjectType type, String subPath) throws Exception { + public void visit(BrooklynObjectType type, String objectId, final String contents) throws Exception { + final String prefix = "/"+type.toCamelCase()+"/"; + + class XPathHelper { + private String get(String innerPath) { + return (String) XmlUtil.xpath(contents, prefix+innerPath); + } + } + XPathHelper x = new XPathHelper(); + switch (type) { case ENTITY: - String id = (String) XmlUtil.xpath(contents, "/entity/id"); - String objType = (String) XmlUtil.xpath(contents, "/entity/type"); - String parentId = (String) XmlUtil.xpath(contents, "/entity/parent"); - String catalogItemId = (String) XmlUtil.xpath(contents, "/entity/catalogItemId"); - builder.entity(id, objType, Strings.emptyToNull(parentId), Strings.emptyToNull(catalogItemId)); + builder.entity(x.get("id"), x.get("type"), + Strings.emptyToNull(x.get("parent")), Strings.emptyToNull(x.get("catalogItemId"))); break; case LOCATION: - id = (String) XmlUtil.xpath(contents, "/location/id"); - objType = (String) XmlUtil.xpath(contents, "/location/type"); - builder.location(id, objType); - break; case POLICY: - id = (String) XmlUtil.xpath(contents, "/policy/id"); - objType = (String) XmlUtil.xpath(contents, "/policy/type"); - builder.policy(id, objType); - break; case ENRICHER: - id = (String) XmlUtil.xpath(contents, "/enricher/id"); - objType = (String) XmlUtil.xpath(contents, "/enricher/type"); - builder.enricher(id, objType); - break; case FEED: - id = (String) XmlUtil.xpath(contents, "/feed/id"); - objType = (String) XmlUtil.xpath(contents, "/feed/type"); - builder.feed(id, objType); + builder.putType(type, x.get("id"), x.get("type")); break; case CATALOG_ITEM: try { CatalogItemMemento memento = (CatalogItemMemento) serializer.fromString(contents); if (memento == null) { - LOG.warn("No "+type.toString().toLowerCase()+"-memento deserialized from " + subPath + "; ignoring and continuing"); + LOG.warn("No "+type.toCamelCase()+"-memento deserialized from " + objectId + "; ignoring and continuing"); } else { builder.catalogItem(memento); } } catch (Exception e) { - exceptionHandler.onLoadMementoFailed(type, "Memento "+subPath, e); + exceptionHandler.onLoadMementoFailed(type, "memento "+objectId+" early catalog deserialization error", e); } break; default: @@ -296,7 +326,7 @@ public void visit(String contents, BrooklynObjectType type, String subPath) thro Stopwatch stopwatch = Stopwatch.createStarted(); - visitMemento(visitor, exceptionHandler); + visitMemento("manifests", mementoData, visitor, exceptionHandler); BrooklynMementoManifest result = builder.build(); @@ -314,29 +344,37 @@ public void visit(String contents, BrooklynObjectType type, String subPath) thro @Override public BrooklynMemento loadMemento(LookupContext lookupContext, final RebindExceptionHandler exceptionHandler) throws IOException { + return loadMemento(null, lookupContext, exceptionHandler); + } + + @Override + public BrooklynMemento loadMemento(BrooklynMementoRawData mementoData, LookupContext lookupContext, final RebindExceptionHandler exceptionHandler) throws IOException { + if (mementoData==null) + mementoData = loadMementoRawData(exceptionHandler); + Stopwatch stopwatch = Stopwatch.createStarted(); final BrooklynMementoImpl.Builder builder = BrooklynMementoImpl.builder(); Visitor visitor = new Visitor() { @Override - public void visit(String contents, BrooklynObjectType type, String subPath) throws Exception { + public void visit(BrooklynObjectType type, String objectId, String contents) throws Exception { try { Memento memento = (Memento) serializer.fromString(contents); if (memento == null) { - LOG.warn("No "+type.toString().toLowerCase()+"-memento deserialized from " + subPath + "; ignoring and continuing"); + LOG.warn("No "+type.toCamelCase()+"-memento deserialized from " + objectId + "; ignoring and continuing"); } else { builder.memento(memento); } } catch (Exception e) { - exceptionHandler.onLoadMementoFailed(type, "Memento "+subPath, e); + exceptionHandler.onLoadMementoFailed(type, "memento "+objectId+" deserialization error", e); } } }; serializer.setLookupContext(lookupContext); try { - visitMemento(visitor, exceptionHandler); + visitMemento("deserialization", mementoData, visitor, exceptionHandler); } finally { serializer.unsetLookupContext(); } @@ -355,73 +393,33 @@ public void visit(String contents, BrooklynObjectType type, String subPath) thro } protected interface Visitor { - public void visit(String contents, BrooklynObjectType type, String subPath) throws Exception; + public void visit(BrooklynObjectType type, String id, String contents) throws Exception; } - protected void visitMemento(final Visitor visitor, final RebindExceptionHandler exceptionHandler) throws IOException { - List entitySubPathList; - List locationSubPathList; - List policySubPathList; - List enricherSubPathList; - List feedSubPathList; - List catalogSubPathList; - - Stopwatch stopwatch = Stopwatch.createStarted(); - try { - entitySubPathList = objectStore.listContentsWithSubPath("entities"); - locationSubPathList = objectStore.listContentsWithSubPath("locations"); - policySubPathList = objectStore.listContentsWithSubPath("policies"); - enricherSubPathList = objectStore.listContentsWithSubPath("enrichers"); - feedSubPathList = objectStore.listContentsWithSubPath("feeds"); - catalogSubPathList = objectStore.listContentsWithSubPath("catalog"); - } catch (Exception e) { - Exceptions.propagateIfFatal(e); - exceptionHandler.onLoadMementoFailed(BrooklynObjectType.UNKNOWN, "Failed to list files", e); - throw new IllegalStateException("Failed to list memento files in "+objectStore, e); - } - - LOG.debug("Loaded rebind lists; took {}: {} entities, {} locations, {} policies, {} enrichers, {} feeds, {} catalog items; from {}", new Object[]{ - Time.makeTimeStringRounded(stopwatch), - entitySubPathList.size(), locationSubPathList.size(), policySubPathList.size(), enricherSubPathList.size(), - feedSubPathList.size(), catalogSubPathList.size(), - objectStore.getSummaryName() }); - + + protected void visitMemento(final String phase, final BrooklynMementoRawData rawData, final Visitor visitor, final RebindExceptionHandler exceptionHandler) { List> futures = Lists.newArrayList(); class VisitorWrapper implements Runnable { - private final String subPath; private final BrooklynObjectType type; - public VisitorWrapper(String subPath, BrooklynObjectType type) { - this.subPath = subPath; + private final Map.Entry objectIdAndData; + public VisitorWrapper(BrooklynObjectType type, Map.Entry objectIdAndData) { this.type = type; + this.objectIdAndData = objectIdAndData; } public void run() { try { - String contents = read(subPath); - visitor.visit(contents, type, subPath); + visitor.visit(type, objectIdAndData.getKey(), objectIdAndData.getValue()); } catch (Exception e) { Exceptions.propagateIfFatal(e); - exceptionHandler.onLoadMementoFailed(type, "Memento "+subPath, e); + exceptionHandler.onLoadMementoFailed(type, "memento "+objectIdAndData.getKey()+" "+phase+" error", e); } } } - for (final String subPath : entitySubPathList) { - futures.add(executor.submit(new VisitorWrapper(subPath, BrooklynObjectType.ENTITY))); - } - for (final String subPath : locationSubPathList) { - futures.add(executor.submit(new VisitorWrapper(subPath, BrooklynObjectType.LOCATION))); - } - for (final String subPath : policySubPathList) { - futures.add(executor.submit(new VisitorWrapper(subPath, BrooklynObjectType.POLICY))); - } - for (final String subPath : enricherSubPathList) { - futures.add(executor.submit(new VisitorWrapper(subPath, BrooklynObjectType.ENRICHER))); - } - for (final String subPath : feedSubPathList) { - futures.add(executor.submit(new VisitorWrapper(subPath, BrooklynObjectType.FEED))); - } - for (final String subPath : catalogSubPathList) { - futures.add(executor.submit(new VisitorWrapper(subPath, BrooklynObjectType.CATALOG_ITEM))); + for (BrooklynObjectType type: PERSISTED_OBJECT_TYPES_IN_ORDER) { + for (final Map.Entry entry : rawData.getObjectsOfType(type).entrySet()) { + futures.add(executor.submit(new VisitorWrapper(type, entry))); + } } try { @@ -439,7 +437,7 @@ public void run() { } catch (InterruptedException e2) { throw Exceptions.propagate(e2); } catch (ExecutionException e2) { - LOG.warn("Problem loading memento manifest", e2); + LOG.warn("Problem loading memento ("+phase+"): "+e2, e2); exceptions.add(e2); } future.cancel(true); @@ -449,7 +447,7 @@ public void run() { throw Exceptions.propagate(e); } else { // Normally there should be at lesat one failure; otherwise all.get() would not have failed. - throw new CompoundRuntimeException("Problem loading mementos", exceptions); + throw new CompoundRuntimeException("Problem loading mementos ("+phase+")", exceptions); } } } @@ -476,23 +474,10 @@ public void checkpoint(BrooklynMementoRawData newMemento, PersistenceExceptionHa Stopwatch stopwatch = Stopwatch.createStarted(); List> futures = Lists.newArrayList(); - for (Map.Entry entry : newMemento.getEntities().entrySet()) { - futures.add(asyncPersist("entities", BrooklynObjectType.ENTITY, entry.getKey(), entry.getValue(), exceptionHandler)); - } - for (Map.Entry entry : newMemento.getLocations().entrySet()) { - futures.add(asyncPersist("locations", BrooklynObjectType.LOCATION, entry.getKey(), entry.getValue(), exceptionHandler)); - } - for (Map.Entry entry : newMemento.getPolicies().entrySet()) { - futures.add(asyncPersist("policies", BrooklynObjectType.POLICY, entry.getKey(), entry.getValue(), exceptionHandler)); - } - for (Map.Entry entry : newMemento.getEnrichers().entrySet()) { - futures.add(asyncPersist("enrichers", BrooklynObjectType.ENRICHER, entry.getKey(), entry.getValue(), exceptionHandler)); - } - for (Map.Entry entry : newMemento.getFeeds().entrySet()) { - futures.add(asyncPersist("feeds", BrooklynObjectType.FEED, entry.getKey(), entry.getValue(), exceptionHandler)); - } - for (Map.Entry entry : newMemento.getCatalogItems().entrySet()) { - futures.add(asyncPersist("catalog", BrooklynObjectType.CATALOG_ITEM, entry.getKey(), entry.getValue(), exceptionHandler)); + for (BrooklynObjectType type: PERSISTED_OBJECT_TYPES_IN_ORDER) { + for (Map.Entry entry : newMemento.getObjectsOfType(type).entrySet()) { + futures.add(asyncPersist(type.getSubPathName(), type, entry.getKey(), entry.getValue(), exceptionHandler)); + } } try { @@ -561,42 +546,15 @@ private Stopwatch deltaImpl(Delta delta, PersistenceExceptionHandler exceptionHa Stopwatch stopwatch = Stopwatch.createStarted(); List> futures = Lists.newArrayList(); - for (EntityMemento entity : delta.entities()) { - futures.add(asyncPersist("entities", entity, exceptionHandler)); - } - for (LocationMemento location : delta.locations()) { - futures.add(asyncPersist("locations", location, exceptionHandler)); - } - for (PolicyMemento policy : delta.policies()) { - futures.add(asyncPersist("policies", policy, exceptionHandler)); - } - for (EnricherMemento enricher : delta.enrichers()) { - futures.add(asyncPersist("enrichers", enricher, exceptionHandler)); - } - for (FeedMemento feed : delta.feeds()) { - futures.add(asyncPersist("feeds", feed, exceptionHandler)); - } - for (CatalogItemMemento catalogItem : delta.catalogItems()) { - futures.add(asyncPersist("catalog", catalogItem, exceptionHandler)); - } - - for (String id : delta.removedEntityIds()) { - futures.add(asyncDelete("entities", id, exceptionHandler)); - } - for (String id : delta.removedLocationIds()) { - futures.add(asyncDelete("locations", id, exceptionHandler)); - } - for (String id : delta.removedPolicyIds()) { - futures.add(asyncDelete("policies", id, exceptionHandler)); - } - for (String id : delta.removedEnricherIds()) { - futures.add(asyncDelete("enrichers", id, exceptionHandler)); - } - for (String id : delta.removedFeedIds()) { - futures.add(asyncDelete("feeds", id, exceptionHandler)); + for (BrooklynObjectType type: PERSISTED_OBJECT_TYPES_IN_ORDER) { + for (Memento entity : delta.getObjectsOfType(type)) { + futures.add(asyncPersist(type.getSubPathName(), entity, exceptionHandler)); + } } - for (String id : delta.removedCatalogItemIds()) { - futures.add(asyncDelete("catalog", id, exceptionHandler)); + for (BrooklynObjectType type: PERSISTED_OBJECT_TYPES_IN_ORDER) { + for (String id : delta.getRemovedObjectsOfType(type)) { + futures.add(asyncDelete(type.getSubPathName(), id, exceptionHandler)); + } } try { diff --git a/core/src/main/java/brooklyn/management/ha/HighAvailabilityManagerImpl.java b/core/src/main/java/brooklyn/management/ha/HighAvailabilityManagerImpl.java index 8dd8091cce..852885a8be 100644 --- a/core/src/main/java/brooklyn/management/ha/HighAvailabilityManagerImpl.java +++ b/core/src/main/java/brooklyn/management/ha/HighAvailabilityManagerImpl.java @@ -57,6 +57,7 @@ import brooklyn.util.task.Tasks; import brooklyn.util.text.Strings; import brooklyn.util.time.Duration; +import brooklyn.util.time.Time; import com.google.common.annotations.Beta; import com.google.common.annotations.VisibleForTesting; @@ -634,11 +635,11 @@ protected void checkMaster(boolean initializing) { String message = "Management node "+ownNodeId+" detected "; if (weAreNewMaster) message += "we should be master, changing from "; else message += "master change, from "; - message +=currMasterNodeId + " (" + (currMasterNodeRecord==null ? "?" : currMasterNodeRecord.getRemoteTimestamp()) + ")" + message +=currMasterNodeId + " (" + (currMasterNodeRecord==null ? "?" : timestampString(currMasterNodeRecord.getRemoteTimestamp())) + ")" + " to " + (newMasterNodeId == null ? "" : (weAreNewMaster ? "us " : "") - + newMasterNodeId + " (" + newMasterNodeRecord.getRemoteTimestamp() + ")" + + newMasterNodeId + " (" + timestampString(newMasterNodeRecord.getRemoteTimestamp()) + ")" + (newMasterNodeUri!=null ? " "+newMasterNodeUri : "") ); LOG.warn(message); } @@ -649,6 +650,11 @@ protected void checkMaster(boolean initializing) { } } + private static String timestampString(Long remoteTimestamp) { + if (remoteTimestamp==null) return null; + return remoteTimestamp+" / "+Time.makeTimeStringRounded( Duration.sinceUtc(remoteTimestamp))+" ago"; + } + protected void promoteToMaster() { if (!running) { LOG.warn("Ignoring promote-to-master request, as HighAvailabilityManager is no longer running"); diff --git a/core/src/test/java/brooklyn/entity/rebind/RebindFailuresTest.java b/core/src/test/java/brooklyn/entity/rebind/RebindFailuresTest.java index e070bd0a4d..045d91c8ca 100644 --- a/core/src/test/java/brooklyn/entity/rebind/RebindFailuresTest.java +++ b/core/src/test/java/brooklyn/entity/rebind/RebindFailuresTest.java @@ -179,8 +179,7 @@ public void testFailureRebindingBecauseDirectoryCorrupt() throws Exception { } // exception handler should have been told about failure - // two exceptions: one for loadMementoManifest; one for loadMemento - assertEquals(exceptionHandler.loadMementoFailures.size(), 2, "exceptions="+exceptionHandler.loadMementoFailures); + assertFalse(exceptionHandler.loadMementoFailures.isEmpty(), "exceptions="+exceptionHandler.loadMementoFailures); } protected void assertFailureRebindingError(Exception e) { diff --git a/core/src/test/java/brooklyn/entity/rebind/RebindTestFixture.java b/core/src/test/java/brooklyn/entity/rebind/RebindTestFixture.java index 1466405122..60d245a37c 100644 --- a/core/src/test/java/brooklyn/entity/rebind/RebindTestFixture.java +++ b/core/src/test/java/brooklyn/entity/rebind/RebindTestFixture.java @@ -173,7 +173,7 @@ protected BrooklynMementoManifest loadMementoManifest() throws Exception { ((ManagementContextInternal)newManagementContext).getBrooklynProperties(), classLoader); RebindExceptionHandler exceptionHandler = new RecordingRebindExceptionHandler(RebindManager.RebindFailureMode.FAIL_AT_END, RebindManager.RebindFailureMode.FAIL_AT_END); - BrooklynMementoManifest mementoManifest = persister.loadMementoManifest(exceptionHandler); + BrooklynMementoManifest mementoManifest = persister.loadMementoManifest(null, exceptionHandler); persister.stop(false); return mementoManifest; } diff --git a/core/src/test/java/brooklyn/entity/rebind/RecordingRebindExceptionHandler.java b/core/src/test/java/brooklyn/entity/rebind/RecordingRebindExceptionHandler.java index d2c8b8c089..41cead5016 100644 --- a/core/src/test/java/brooklyn/entity/rebind/RecordingRebindExceptionHandler.java +++ b/core/src/test/java/brooklyn/entity/rebind/RecordingRebindExceptionHandler.java @@ -43,7 +43,7 @@ public RecordingRebindExceptionHandler(RebindManager.RebindFailureMode danglingR @Override public void onLoadMementoFailed(BrooklynObjectType type, String msg, Exception e) { - loadMementoFailures.add(new IllegalStateException("problem loading "+type+" memento: "+msg, e)); + loadMementoFailures.add(new IllegalStateException("problem loading "+type.toCamelCase()+" memento: "+msg, e)); super.onLoadMementoFailed(type, msg, e); } @@ -71,13 +71,13 @@ public void onNotFound(BrooklynObjectType type, String id) { @Override public void onRebindFailed(BrooklynObjectType type, BrooklynObject instance, Exception e) { - rebindFailures.put(instance, new IllegalStateException("problem rebinding "+type+" "+instance.getId()+" ("+instance+")", e)); + rebindFailures.put(instance, new IllegalStateException("problem rebinding "+type.toCamelCase()+" "+instance.getId()+" ("+instance+")", e)); super.onRebindFailed(type, instance, e); } @Override public void onManageFailed(BrooklynObjectType type, BrooklynObject instance, Exception e) { - manageFailures.put(instance, new IllegalStateException("problem managing "+type+" "+instance.getId()+" ("+instance+")", e)); + manageFailures.put(instance, new IllegalStateException("problem managing "+type.toCamelCase()+" "+instance.getId()+" ("+instance+")", e)); super.onManageFailed(type, instance, e); } diff --git a/core/src/test/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterTestFixture.java b/core/src/test/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterTestFixture.java index 0ae2a9ef08..3306a32289 100644 --- a/core/src/test/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterTestFixture.java +++ b/core/src/test/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterTestFixture.java @@ -111,7 +111,7 @@ protected BrooklynMemento loadMemento() throws Exception { rebindContext.registerEntity(app.getId(), app); rebindContext.registerEntity(entity.getId(), entity); - BrooklynMemento reloadedMemento = persister.loadMemento(lookupContext, failFast); + BrooklynMemento reloadedMemento = persister.loadMemento(null, lookupContext, failFast); return reloadedMemento; } From 45fa39b3d4042c3fbc1e9cc870d96e730f133318 Mon Sep 17 00:00:00 2001 From: Alex Heneveld Date: Thu, 6 Nov 2014 10:35:17 +0000 Subject: [PATCH 4/4] minor code review cleanups for rebind/persistence logging --- .../main/java/brooklyn/entity/rebind/RebindManagerImpl.java | 4 +++- .../persister/BrooklynMementoPersisterToObjectStore.java | 5 +++-- 2 files changed, 6 insertions(+), 3 deletions(-) diff --git a/core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java b/core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java index e29d94f4fb..74cfc12dbc 100644 --- a/core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java +++ b/core/src/main/java/brooklyn/entity/rebind/RebindManagerImpl.java @@ -541,7 +541,9 @@ protected List rebindImpl(final ClassLoader classLoader, final Rebi //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()+"..."); + LOG.debug("Rebinding ("+mode+ + (readOnlyRebindCount>Integer.MIN_VALUE ? ", iteration "+readOnlyRebindCount : "")+ + ") from "+getPersister().getBackingStoreDescription()+"..."); BrooklynMementoRawData mementoRawData = persistenceStoreAccess.loadMementoRawData(exceptionHandler); BrooklynMementoManifest mementoManifest = persistenceStoreAccess.loadMementoManifest(mementoRawData, exceptionHandler); diff --git a/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterToObjectStore.java b/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterToObjectStore.java index 91b738f845..0ee9a73d1c 100644 --- a/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterToObjectStore.java +++ b/core/src/main/java/brooklyn/entity/rebind/persister/BrooklynMementoPersisterToObjectStore.java @@ -65,6 +65,7 @@ import com.google.common.annotations.VisibleForTesting; import com.google.common.base.Objects; import com.google.common.base.Stopwatch; +import com.google.common.collect.ImmutableList; import com.google.common.collect.ImmutableSet; import com.google.common.collect.Lists; import com.google.common.util.concurrent.Futures; @@ -93,9 +94,9 @@ public class BrooklynMementoPersisterToObjectStore implements BrooklynMementoPer "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[] { + static final List PERSISTED_OBJECT_TYPES_IN_ORDER = ImmutableList.of( BrooklynObjectType.ENTITY, BrooklynObjectType.LOCATION, BrooklynObjectType.POLICY, - BrooklynObjectType.ENRICHER, BrooklynObjectType.FEED, BrooklynObjectType.CATALOG_ITEM }; + BrooklynObjectType.ENRICHER, BrooklynObjectType.FEED, BrooklynObjectType.CATALOG_ITEM); private final PersistenceObjectStore objectStore; private final MementoSerializer serializer;