This is an automated email from the ASF dual-hosted git repository. heneveld pushed a commit to branch master in repository https://gitbox.apache.org/repos/asf/brooklyn-server.git
commit 1211969e508cedb34f953c65b67b2e1acfc61525 Author: Alex Heneveld <[email protected]> AuthorDate: Fri Oct 6 15:02:27 2023 +0100 better logging messages and levels, esp during startup --- .../catalog/internal/CatalogInitialization.java | 2 +- .../mgmt/ha/BrooklynBomOsgiArchiveInstaller.java | 20 +++++--- .../brooklyn/launcher/osgi/OsgiConfigLoader.java | 2 +- .../brooklyn/launcher/osgi/OsgiLauncherImpl.java | 57 ++++++++++++++++++++-- .../brooklyn/launcher/common/BasicLauncher.java | 18 +++---- .../resources/brooklyn/logback-logger-excludes.xml | 4 ++ .../rest/filter/CorsImplSupplierFilter.java | 2 +- .../provider/DelegatingSecurityProvider.java | 36 +++++++++----- 8 files changed, 103 insertions(+), 38 deletions(-) diff --git a/core/src/main/java/org/apache/brooklyn/core/catalog/internal/CatalogInitialization.java b/core/src/main/java/org/apache/brooklyn/core/catalog/internal/CatalogInitialization.java index 99597d5737..7b24cec778 100644 --- a/core/src/main/java/org/apache/brooklyn/core/catalog/internal/CatalogInitialization.java +++ b/core/src/main/java/org/apache/brooklyn/core/catalog/internal/CatalogInitialization.java @@ -663,7 +663,7 @@ public class CatalogInitialization implements ManagementContextInjectable { if (catalogUpgrades.isEmpty()) { return persistedState; } else { - rebindLogger.info("Filtering out persisted catalog: removedBundles="+catalogUpgrades.getRemovedBundles()+"; removedLegacyItems="+catalogUpgrades.getRemovedLegacyItems()); + rebindLogger.debug("Filtering out persisted catalog: removedBundles="+catalogUpgrades.getRemovedBundles()+"; removedLegacyItems="+catalogUpgrades.getRemovedLegacyItems()); } Map<VersionedName, InstallableManagedBundle> bundles = new LinkedHashMap<>(); diff --git a/core/src/main/java/org/apache/brooklyn/core/mgmt/ha/BrooklynBomOsgiArchiveInstaller.java b/core/src/main/java/org/apache/brooklyn/core/mgmt/ha/BrooklynBomOsgiArchiveInstaller.java index 2687de7e6b..237249de57 100644 --- a/core/src/main/java/org/apache/brooklyn/core/mgmt/ha/BrooklynBomOsgiArchiveInstaller.java +++ b/core/src/main/java/org/apache/brooklyn/core/mgmt/ha/BrooklynBomOsgiArchiveInstaller.java @@ -821,20 +821,26 @@ public class BrooklynBomOsgiArchiveInstaller { result.deferredStart = startRunnable; log.debug(result.message+" (Brooklyn load deferred)"); } else { + int startBundleCount = mgmt().getOsgiManager().map(o -> o.getManagedBundles().size()).or(0); startRunnable.run(); - if (!result.typesInstalled.isEmpty()) { + int newBundleCount = mgmt().getOsgiManager().map(o -> o.getManagedBundles().size()).or(0) - startBundleCount; + if (!result.typesInstalled.isEmpty() && newBundleCount<=1) { // show fewer info messages, only for 'interesting' and non-deferred installations // (rebind is deferred, as are tests, but REST is not) - final int MAX_TO_LIST_EXPLICITLY = 5; - Iterable<String> firstN = Iterables.transform(MutableList.copyOf(Iterables.limit(result.typesInstalled, MAX_TO_LIST_EXPLICITLY)), + final int LIST_EXPLICITLY_MAX = 5; + final int LIST_EXPLICITLY_IF_MAX_EXCEEDED = 1; + final int listExplicitlyHereCount = result.typesInstalled.size() > LIST_EXPLICITLY_MAX ? LIST_EXPLICITLY_IF_MAX_EXCEEDED : LIST_EXPLICITLY_MAX; + Iterable<String> firstN = Iterables.transform(MutableList.copyOf(Iterables.limit(result.typesInstalled, listExplicitlyHereCount)), input -> input.getVersionedName().toString()); - log.info(result.message+", items: "+firstN+ - (result.typesInstalled.size() > MAX_TO_LIST_EXPLICITLY ? " (and others, "+result.typesInstalled.size()+" total)" : "") ); - if (log.isDebugEnabled() && result.typesInstalled.size()>MAX_TO_LIST_EXPLICITLY) { + log.info(result.message+" (completed), items: "+firstN+ + (result.typesInstalled.size() > listExplicitlyHereCount ? " (and others, "+result.typesInstalled.size()+" total)" : "") ); + if (log.isDebugEnabled() && result.typesInstalled.size()>listExplicitlyHereCount) { log.debug(result.message+", all items: "+result.typesInstalled); } } else { - log.debug(result.message+" (complete): bundle started and now managed by Brooklyn, though no catalog items found (may have installed other bundles though)"); + log.info(result.message+" (completed), "+result.typesInstalled.size()+" item"+(result.typesInstalled.size()!=1 ? "s" : "")+" "+ + (newBundleCount > 1 ? " plus "+(newBundleCount-1)+" other bundle"+(newBundleCount>2 ? "s" :"")+" detected" : "")+ + ", "+Iterables.size(mgmt().getTypeRegistry().getAll())+" total in type registry"); } } diff --git a/karaf/init/src/main/java/org/apache/brooklyn/launcher/osgi/OsgiConfigLoader.java b/karaf/init/src/main/java/org/apache/brooklyn/launcher/osgi/OsgiConfigLoader.java index 73544c279f..7fc40c8ada 100644 --- a/karaf/init/src/main/java/org/apache/brooklyn/launcher/osgi/OsgiConfigLoader.java +++ b/karaf/init/src/main/java/org/apache/brooklyn/launcher/osgi/OsgiConfigLoader.java @@ -88,7 +88,7 @@ public abstract class OsgiConfigLoader implements ConfigLoader { map.putAll(dictToMap(config.getProperties())); } } else { - LOG.info("No OSGi configuration found for {}.cfg", propertiesPath); + LOG.debug("No OSGi configuration found for {}.cfg; ignoring", propertiesPath); } return map; diff --git a/karaf/init/src/main/java/org/apache/brooklyn/launcher/osgi/OsgiLauncherImpl.java b/karaf/init/src/main/java/org/apache/brooklyn/launcher/osgi/OsgiLauncherImpl.java index 76bc0d21af..459d0c8e4a 100644 --- a/karaf/init/src/main/java/org/apache/brooklyn/launcher/osgi/OsgiLauncherImpl.java +++ b/karaf/init/src/main/java/org/apache/brooklyn/launcher/osgi/OsgiLauncherImpl.java @@ -15,16 +15,19 @@ */ package org.apache.brooklyn.launcher.osgi; -import com.google.common.base.Stopwatch; import java.io.IOException; import java.util.List; import java.util.Map; import java.util.concurrent.atomic.AtomicBoolean; +import java.util.stream.Collectors; import javax.annotation.Nullable; +import com.google.common.base.Stopwatch; +import com.google.common.collect.Iterables; import org.apache.brooklyn.api.framework.FrameworkLookup; import org.apache.brooklyn.api.mgmt.ManagementContext; import org.apache.brooklyn.api.mgmt.ha.HighAvailabilityMode; +import org.apache.brooklyn.api.mgmt.ha.ManagementNodeState; import org.apache.brooklyn.core.BrooklynVersionService; import org.apache.brooklyn.core.catalog.internal.CatalogInitialization; import org.apache.brooklyn.core.internal.BrooklynProperties; @@ -36,6 +39,8 @@ import org.apache.brooklyn.launcher.common.BasicLauncher; import org.apache.brooklyn.launcher.common.BrooklynPropertiesFactoryHelper; import org.apache.brooklyn.rest.BrooklynWebConfig; import org.apache.brooklyn.rest.security.provider.BrooklynUserWithRandomPasswordSecurityProvider; +import org.apache.brooklyn.rest.security.provider.DelegatingSecurityProvider; +import org.apache.brooklyn.util.collections.MutableList; import org.apache.brooklyn.util.core.flags.TypeCoercions; import org.apache.brooklyn.util.exceptions.Exceptions; import org.apache.brooklyn.util.exceptions.RuntimeInterruptedException; @@ -94,6 +99,11 @@ public class OsgiLauncherImpl extends BasicLauncher<OsgiLauncherImpl> implements private ConfigurationAdmin configAdmin; private ConfigSupplier configSupplier; + public static String getSoftwareName() { + String name = System.getProperty("karaf.name"); + if (Strings.isNonBlank(name)) return name; + return "apache-brooklyn"; + } @Override public OsgiLauncherImpl startPartOne() { @@ -142,11 +152,11 @@ public class OsgiLauncherImpl extends BasicLauncher<OsgiLauncherImpl> implements synchronized (reloadLock) { final Stopwatch startupTimer = Stopwatch.createStarted(); BrooklynShutdownHooks.resetShutdownFlag(); - LOG.debug("OsgiLauncher init, catalog "+defaultCatalogLocation); + LOG.info(getSoftwareName()+" initialization starting, installing catalog from "+defaultCatalogLocation); catalogInitialization(new CatalogInitialization(String.format("file:%s", defaultCatalogLocation))); startPartOne(); startupTimer.stop(); - LOG.info("Brooklyn initialisation (part one) complete after {}", startupTimer.toString()); + LOG.info(getSoftwareName()+" initialization - part one complete, took {}", startupTimer.toString()); } } @@ -304,10 +314,47 @@ public class OsgiLauncherImpl extends BasicLauncher<OsgiLauncherImpl> implements final Stopwatch startupTimer = Stopwatch.createStarted(); LOG.debug("OsgiLauncher catalog/rebind running initialization (part two)"); startPartTwo(); + // initialize delegate, show any relevant init messages + new DelegatingSecurityProvider(getManagementContext()).getDelegate(); + ((ManagementContextInternal)getManagementContext()).getBrooklynProperties().put(OsgiManager.OSGI_STARTUP_COMPLETE, true); - startupTimer.stop(); - LOG.info("Brooklyn initialization (part two) complete after {}", startupTimer.toString()); FrameworkLookup.invalidateCaches(); + + + StringBuilder interstitial = new StringBuilder(getSoftwareName().toUpperCase()); + interstitial.append(" "); + List<String> notes = MutableList.of(); + + ManagementNodeState state = getManagementContext().getHighAvailabilityManager().getNodeState(); + if (ManagementNodeState.MASTER.equals(state)) { + interstitial.append("RUNNING"); + + int appCount = getManagementContext().getApplications().size(); + if (appCount>0) { + notes.add(appCount+" app" + (appCount!=1 ? "s" : "") +" under management"); + } + + int catalogSize = Iterables.size(getManagementContext().getTypeRegistry().getAll()); + notes.add(catalogSize+" items in type registry"); +// interstitial.append(" - "+notes); + + // URL would be nice but we don't know that + + } else if (ManagementNodeState.FAILED.equals(state)) { + interstitial.append("FAILED - see logs for more information"); + } else { + interstitial.append("in state: "+state.name().toUpperCase()); + } + LOG.info(interstitial.toString().toLowerCase()+(notes.isEmpty() ? "" : " - "+notes.stream().collect(Collectors.joining(", ")))); + + startupTimer.stop(); + LOG.info(getSoftwareName()+" initialization - part two complete, took {}", startupTimer.toString()); + + new Thread(()-> { + // wait 50ms to let other log messages show above us + Time.sleep(Duration.millis(50)); + LOG.info("======== " +interstitial+" ========"); + }, getSoftwareName()+"-start-completion").start(); } } diff --git a/launcher-common/src/main/java/org/apache/brooklyn/launcher/common/BasicLauncher.java b/launcher-common/src/main/java/org/apache/brooklyn/launcher/common/BasicLauncher.java index 0a9742a814..0c581cc460 100644 --- a/launcher-common/src/main/java/org/apache/brooklyn/launcher/common/BasicLauncher.java +++ b/launcher-common/src/main/java/org/apache/brooklyn/launcher/common/BasicLauncher.java @@ -18,16 +18,18 @@ */ package org.apache.brooklyn.launcher.common; -import com.google.common.annotations.VisibleForTesting; -import static com.google.common.base.Preconditions.checkNotNull; - import java.io.File; import java.util.ArrayList; import java.util.List; import java.util.Map; - import javax.annotation.Nullable; +import com.google.common.annotations.Beta; +import com.google.common.annotations.VisibleForTesting; +import com.google.common.base.Splitter; +import com.google.common.collect.ImmutableList; +import com.google.common.collect.Lists; +import com.google.common.collect.Maps; import org.apache.brooklyn.api.entity.Application; import org.apache.brooklyn.api.entity.EntitySpec; import org.apache.brooklyn.api.location.Location; @@ -76,11 +78,7 @@ import org.apache.brooklyn.util.time.Duration; import org.slf4j.Logger; import org.slf4j.LoggerFactory; -import com.google.common.annotations.Beta; -import com.google.common.base.Splitter; -import com.google.common.collect.ImmutableList; -import com.google.common.collect.Lists; -import com.google.common.collect.Maps; +import static com.google.common.base.Preconditions.checkNotNull; /** * Example usage is: @@ -159,7 +157,7 @@ public class BasicLauncher<T extends BasicLauncher<T>> { * The application will not be started as part of this call (callers can * subsequently call {@link #start()} or {@link #getApplications()}. * - * @see #application(Application) + * @see #application(org.apache.brooklyn.api.entity.EntitySpec) */ public T application(String yaml) { this.yamlAppsToManage.add(yaml); diff --git a/logging/logback-includes/src/main/resources/brooklyn/logback-logger-excludes.xml b/logging/logback-includes/src/main/resources/brooklyn/logback-logger-excludes.xml index a23529265e..e2146ac1d3 100644 --- a/logging/logback-includes/src/main/resources/brooklyn/logback-logger-excludes.xml +++ b/logging/logback-includes/src/main/resources/brooklyn/logback-logger-excludes.xml @@ -80,9 +80,13 @@ `o.o.p.w.u.ServletContainerInitializerScanner [pache.cxf.osgi])] failed to parse and instantiate of javax.servlet.ServletContainerInitializer in classpath`; could possibly be fixed with bundle load order but logging from the web bundles seems fine so not worth it --> <logger name="org.ops4j.pax.web.utils.ServletContainerInitializerScanner" level="ERROR"/> + <!-- Verbose at INFO level --> + <logger name="org.ops4j.pax.web.jsp.TldScanner" level="WARN"/> <!-- Again verbose, warning about No HttpConfig Element found in jetty.xml, using default --> <logger name="org.ops4j.pax.web.service.jetty.internal.JettyFactoryImpl" level="ERROR"/> <!-- logs stack traces at info level for commands not found while still initializing --> <logger name="org.apache.karaf.shell.impl.action.osgi.CommandExtension" level="WARN"/> + <!-- NOTE: above need duplicated in features under karaf/features/src/main/resources/resources/etc/org.ops4j.pax.logging.cfg --> + </included> diff --git a/rest/rest-resources/src/main/java/org/apache/brooklyn/rest/filter/CorsImplSupplierFilter.java b/rest/rest-resources/src/main/java/org/apache/brooklyn/rest/filter/CorsImplSupplierFilter.java index 9262c00ac6..f72b3fc517 100644 --- a/rest/rest-resources/src/main/java/org/apache/brooklyn/rest/filter/CorsImplSupplierFilter.java +++ b/rest/rest-resources/src/main/java/org/apache/brooklyn/rest/filter/CorsImplSupplierFilter.java @@ -144,7 +144,7 @@ public class CorsImplSupplierFilter extends CrossOriginResourceSharingFilter { this.enableCors = Boolean.TRUE.equals(enabled); setFindResourceMethod(false); if (enableCors) { - LOGGER.info("CORS brooklyn feature enabled."); + LOGGER.debug("CORS brooklyn feature enabled."); } else { LOGGER.trace("CORS brooklyn feature disabled."); } diff --git a/rest/rest-resources/src/main/java/org/apache/brooklyn/rest/security/provider/DelegatingSecurityProvider.java b/rest/rest-resources/src/main/java/org/apache/brooklyn/rest/security/provider/DelegatingSecurityProvider.java index 08050899eb..318bce0053 100644 --- a/rest/rest-resources/src/main/java/org/apache/brooklyn/rest/security/provider/DelegatingSecurityProvider.java +++ b/rest/rest-resources/src/main/java/org/apache/brooklyn/rest/security/provider/DelegatingSecurityProvider.java @@ -67,7 +67,7 @@ public class DelegatingSecurityProvider implements SecurityProvider { log.trace("Brooklyn security: using pre-set security provider {}", presetDelegate); return presetDelegate; } - + String className = brooklynProperties.getConfig(BrooklynWebConfig.SECURITY_PROVIDER_CLASSNAME); if (delegate != null && BrooklynWebConfig.hasNoSecurityOptions(mgmt.getConfig())) { @@ -78,18 +78,28 @@ public class DelegatingSecurityProvider implements SecurityProvider { try { String bundle = brooklynProperties.getConfig(BrooklynWebConfig.SECURITY_PROVIDER_BUNDLE); - if (bundle!=null) { - String bundleVersion = brooklynProperties.getConfig(BrooklynWebConfig.SECURITY_PROVIDER_BUNDLE_VERSION); - log.info("Brooklyn security: using security provider " + className + " from " + bundle+":"+bundleVersion); - BundleContext bundleContext = ((ManagementContextInternal)mgmt).getOsgiManager().get().getFramework().getBundleContext(); - delegate = loadProviderFromBundle(mgmt, bundleContext, bundle, bundleVersion, className); - saveDelegate(); - } else { - log.info("Brooklyn security: using security provider " + className); - ClassLoaderUtils clu = new ClassLoaderUtils(this, mgmt); - Class<? extends SecurityProvider> clazz = (Class<? extends SecurityProvider>) clu.loadClass(className); - delegate = createSecurityProviderInstance(mgmt, clazz); - saveDelegate(); + // use synch block to prevent multiple instances and messages from loading + synchronized (DelegatingSecurityProvider.class) { + // try again with preset delegate + presetDelegate = brooklynProperties.getConfig(BrooklynWebConfig.SECURITY_PROVIDER_INSTANCE); + if (presetDelegate!=null) { + log.trace("Brooklyn security: using pre-set security provider, found late - {}", presetDelegate); + return presetDelegate; + } + + if (bundle != null) { + String bundleVersion = brooklynProperties.getConfig(BrooklynWebConfig.SECURITY_PROVIDER_BUNDLE_VERSION); + log.info("Brooklyn security: using security provider " + className + " from " + bundle + ":" + bundleVersion); + BundleContext bundleContext = ((ManagementContextInternal) mgmt).getOsgiManager().get().getFramework().getBundleContext(); + delegate = loadProviderFromBundle(mgmt, bundleContext, bundle, bundleVersion, className); + saveDelegate(); + } else { + log.info("Brooklyn security: using security provider " + className); + ClassLoaderUtils clu = new ClassLoaderUtils(this, mgmt); + Class<? extends SecurityProvider> clazz = (Class<? extends SecurityProvider>) clu.loadClass(className); + delegate = createSecurityProviderInstance(mgmt, clazz); + saveDelegate(); + } } } catch (Exception e) { log.warn("Brooklyn security: unable to instantiate security provider " + className + "; all logins are being disallowed", e);
