Add code that gives a working MDC output in test 2018-01-23 11:52:20,118 INFO [i6hk2jll5n, z2scr3kczj, hn242jl6bi] Hello from entity hn242jl6bi 2018-01-23 11:52:20,118 INFO [i6hk2jll5n, z2scr3kczj] Hello from entity z2scr3kczj 2018-01-23 11:52:20,118 INFO [i6hk2jll5n] Hello world 2018-01-23 11:52:20,128 INFO [i6hk2jll5n] Goodbye cruel world 2018-01-23 11:52:20,128 INFO [i6hk2jll5n, z2scr3kczj] Goodbye from entity z2scr3kczj 2018-01-23 11:52:20,129 INFO [i6hk2jll5n, z2scr3kczj, hn242jl6bi] Goodbye from entity hn242jl6bi
Project: http://git-wip-us.apache.org/repos/asf/brooklyn-server/repo Commit: http://git-wip-us.apache.org/repos/asf/brooklyn-server/commit/11740cc6 Tree: http://git-wip-us.apache.org/repos/asf/brooklyn-server/tree/11740cc6 Diff: http://git-wip-us.apache.org/repos/asf/brooklyn-server/diff/11740cc6 Branch: refs/heads/master Commit: 11740cc65a1121a0c272e78f68fd5dac012b8fb9 Parents: 1f9446e Author: Geoff Macartney <geoff.macart...@cloudsoftcorp.com> Authored: Fri Jan 19 18:01:55 2018 +0000 Committer: Geoff Macartney <geoff.macart...@cloudsoftcorp.com> Committed: Fri Feb 9 21:09:20 2018 +0000 ---------------------------------------------------------------------- .../util/core/task/BasicExecutionContext.java | 42 +++++- .../core/entity/ApplicationLoggingTest.java | 151 +++++++++++++++++++ .../brooklyn/logback-appender-stdout.xml | 35 +++++ pom.xml | 2 +- 4 files changed, 227 insertions(+), 3 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/brooklyn-server/blob/11740cc6/core/src/main/java/org/apache/brooklyn/util/core/task/BasicExecutionContext.java ---------------------------------------------------------------------- diff --git a/core/src/main/java/org/apache/brooklyn/util/core/task/BasicExecutionContext.java b/core/src/main/java/org/apache/brooklyn/util/core/task/BasicExecutionContext.java index 32ca5b7..2575464 100644 --- a/core/src/main/java/org/apache/brooklyn/util/core/task/BasicExecutionContext.java +++ b/core/src/main/java/org/apache/brooklyn/util/core/task/BasicExecutionContext.java @@ -19,9 +19,11 @@ package org.apache.brooklyn.util.core.task; import java.lang.reflect.Proxy; +import java.util.ArrayDeque; import java.util.ArrayList; import java.util.Collection; import java.util.Collections; +import java.util.Deque; import java.util.LinkedHashSet; import java.util.Map; import java.util.Set; @@ -33,6 +35,7 @@ import java.util.concurrent.ExecutorService; import java.util.concurrent.Future; import java.util.concurrent.TimeUnit; import java.util.concurrent.TimeoutException; +import java.util.concurrent.atomic.AtomicReference; import org.apache.brooklyn.api.entity.Entity; import org.apache.brooklyn.api.mgmt.ExecutionContext; @@ -55,6 +58,7 @@ import org.apache.brooklyn.util.time.CountdownTimer; import org.apache.brooklyn.util.time.Duration; import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import org.slf4j.MDC; import com.google.common.annotations.Beta; import com.google.common.base.Function; @@ -66,10 +70,12 @@ import com.google.common.collect.Iterables; * (so that it can look like an {@link Executor} and also supply {@link ExecutorService#submit(Callable)} */ public class BasicExecutionContext extends AbstractExecutionContext { - + private static final Logger log = LoggerFactory.getLogger(BasicExecutionContext.class); static final ThreadLocal<BasicExecutionContext> perThreadExecutionContext = new ThreadLocal<BasicExecutionContext>(); + public static final String ENTITY_IDS = "entity.ids"; + public static BasicExecutionContext getCurrentExecutionContext() { return perThreadExecutionContext.get(); } final ExecutionManager executionManager; @@ -221,9 +227,16 @@ public class BasicExecutionContext extends AbstractExecutionContext { SimpleFuture<T> future = new SimpleFuture<>(); Throwable error = null; + final Set<Object> taskTags = task.getTags(); + Entity target = BrooklynTaskTags.getWrappedEntityOfType(taskTags, BrooklynTaskTags.TARGET_ENTITY); + final AtomicReference<MDC.MDCCloseable> loggingContext = new AtomicReference<>(); + try { ((BasicExecutionManager)executionManager).afterSubmitRecordFuture(task, future); ((BasicExecutionManager)executionManager).beforeStartInSameThreadTask(null, task); + if (target != null) { + loggingContext.set(MDC.putCloseable(ENTITY_IDS, idStack(target).toString())); + } return future.set(job.call()); } catch (Exception e) { @@ -237,6 +250,10 @@ public class BasicExecutionContext extends AbstractExecutionContext { try { ((BasicExecutionManager)executionManager).afterEndInSameThreadTask(null, task, error); } finally { + final MDC.MDCCloseable context = loggingContext.get(); + if (context != null) { + context.close(); + } BasicExecutionManager.getPerThreadCurrentTask().set(previousTask); perThreadExecutionContext.set(oldExecutionContext); } @@ -357,12 +374,18 @@ public class BasicExecutionContext extends AbstractExecutionContext { // tag as transient if submitter is transient, unless explicitly tagged as non-transient taskTags.add(BrooklynTaskTags.TRANSIENT_TASK_TAG); } - + + Entity target = BrooklynTaskTags.getWrappedEntityOfType(taskTags, BrooklynTaskTags.TARGET_ENTITY); + final AtomicReference<MDC.MDCCloseable> loggingContext = new AtomicReference<>(); + final Object startCallback = properties.get("newTaskStartCallback"); properties.put("newTaskStartCallback", new Function<Task<?>,Void>() { @Override public Void apply(Task<?> it) { registerPerThreadExecutionContext(); + if (target != null) { + loggingContext.set(MDC.putCloseable(ENTITY_IDS, idStack(target).toString())); + } if (startCallback!=null) BasicExecutionManager.invokeCallback(startCallback, it); return null; }}); @@ -375,6 +398,10 @@ public class BasicExecutionContext extends AbstractExecutionContext { if (endCallback!=null) BasicExecutionManager.invokeCallback(endCallback, it); } finally { clearPerThreadExecutionContext(); + final MDC.MDCCloseable context = loggingContext.get(); + if (context != null) { + context.close(); + } } return null; }}); @@ -390,6 +417,17 @@ public class BasicExecutionContext extends AbstractExecutionContext { } } + private Deque<String> idStack(Entity target) { + Deque<String> ids = new ArrayDeque<>(); + Entity e = target; + ids.push(e.getId()); + while (e.getParent() != null) { + e = e.getParent(); + ids.push(e.getId()); + } + return ids; + } + private static class ContextSwitchingInfo<T> { final ExecutionContext context; final Task<T> wrapperTask; http://git-wip-us.apache.org/repos/asf/brooklyn-server/blob/11740cc6/core/src/test/java/org/apache/brooklyn/core/entity/ApplicationLoggingTest.java ---------------------------------------------------------------------- diff --git a/core/src/test/java/org/apache/brooklyn/core/entity/ApplicationLoggingTest.java b/core/src/test/java/org/apache/brooklyn/core/entity/ApplicationLoggingTest.java new file mode 100644 index 0000000..3fc57ec --- /dev/null +++ b/core/src/test/java/org/apache/brooklyn/core/entity/ApplicationLoggingTest.java @@ -0,0 +1,151 @@ +/* + * 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 org.apache.brooklyn.core.entity; + +import java.util.ArrayDeque; +import java.util.Collection; +import java.util.Deque; + +import org.apache.brooklyn.api.entity.Entity; +import org.apache.brooklyn.api.entity.EntitySpec; +import org.apache.brooklyn.api.entity.ImplementedBy; +import org.apache.brooklyn.api.location.Location; +import org.apache.brooklyn.core.entity.lifecycle.Lifecycle; +import org.apache.brooklyn.core.entity.lifecycle.ServiceStateLogic; +import org.apache.brooklyn.core.entity.trait.StartableMethods; +import org.apache.brooklyn.core.test.BrooklynAppUnitTestSupport; +import org.apache.brooklyn.core.test.entity.TestApplication; +import org.apache.brooklyn.core.test.entity.TestApplicationImpl; +import org.apache.brooklyn.core.test.entity.TestEntity; +import org.apache.brooklyn.core.test.entity.TestEntityImpl; +import org.apache.brooklyn.util.collections.QuorumCheck; +import org.apache.brooklyn.util.exceptions.Exceptions; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.MDC; +import org.testng.annotations.Test; + +import com.google.common.collect.ImmutableList; + +@Test +public class ApplicationLoggingTest extends BrooklynAppUnitTestSupport { + private static final Logger LOG = LoggerFactory.getLogger(ApplicationLoggingTest.class); + + @ImplementedBy(TestApplicationWithLoggingImpl.class) + public interface TestApplicationWithLogging extends TestApplication { + + } + + public static class TestApplicationWithLoggingImpl extends TestApplicationImpl + implements TestApplicationWithLogging { + + @Override + protected void initEnrichers() { + super.initEnrichers(); + ServiceStateLogic.newEnricherFromChildrenUp() + .requireUpChildren(QuorumCheck.QuorumChecks.all()) + .addTo(this); + } + + @Override + protected void doStart(Collection<? extends Location> locations) { + super.doStart(locations); + LOG.info("Hello world"); + } + + @Override + protected void doStop() { + LOG.info("Goodbye cruel world"); + super.doStop(); + } + } + + @ImplementedBy(TestEntityWithLoggingImp.class) + public interface TestEntityWithLogging extends TestEntity { + } + + public static final class TestEntityWithLoggingImp extends TestEntityImpl implements TestEntityWithLogging { + + private String getIndent() { + String indent = ""; + Entity e = this; + while (e.getParent() != null) { + indent += " "; + e = e.getParent(); + } + return indent; + } + + @Override + protected void initEnrichers() { + super.initEnrichers(); + ServiceStateLogic.newEnricherFromChildrenUp() + .requireUpChildren(QuorumCheck.QuorumChecks.all()) + .addTo(this); + } + + @Override + public void start(Collection<? extends Location> locs) { + super.start(locs); + try { + StartableMethods.start(this, locs); + } catch (Exception e) { + Exceptions.propagateIfFatal(e); + throw new RuntimeException(e); + } + LOG.info(getIndent() + "Hello from entity {}", getId()); + } + + @Override + public void stop() { + LOG.info(getIndent() + "Goodbye from entity {}", getId()); + StartableMethods.stop(this); + } + } + + @Override + protected void setUpApp() { + LOG.info("setUpApp"); + EntitySpec<TestApplicationWithLogging> appSpec = EntitySpec.create(TestApplicationWithLogging.class); + if (shouldSkipOnBoxBaseDirResolution()!=null) + appSpec.configure(BrooklynConfigKeys.SKIP_ON_BOX_BASE_DIR_RESOLUTION, shouldSkipOnBoxBaseDirResolution()); + + app = mgmt.getEntityManager().createEntity(appSpec); + } + + @Test + public void testLogging() throws Exception { + + Deque<String> ids = new ArrayDeque<>(); + ids.push(app.getId()); + final TestEntityWithLogging entity = app.createAndManageChild(EntitySpec.create(TestEntityWithLogging.class)); + final TestEntityWithLogging child = entity.addChild(EntitySpec.create(EntitySpec.create(TestEntityWithLogging.class))); + app.start(ImmutableList.of(app.newSimulatedLocation())); + assertHealthEventually(app, Lifecycle.RUNNING, true); + app.stop(); + assertHealthEventually(app, Lifecycle.STOPPED, false); + } + + + private void assertHealthEventually(Entity entity, Lifecycle expectedState, Boolean expectedUp) { + EntityAsserts.assertAttributeEqualsEventually(entity, Attributes.SERVICE_STATE_ACTUAL, expectedState); + EntityAsserts.assertAttributeEqualsEventually(entity, Attributes.SERVICE_UP, expectedUp); + } + +} http://git-wip-us.apache.org/repos/asf/brooklyn-server/blob/11740cc6/core/src/test/resources/brooklyn/logback-appender-stdout.xml ---------------------------------------------------------------------- diff --git a/core/src/test/resources/brooklyn/logback-appender-stdout.xml b/core/src/test/resources/brooklyn/logback-appender-stdout.xml new file mode 100644 index 0000000..e612042 --- /dev/null +++ b/core/src/test/resources/brooklyn/logback-appender-stdout.xml @@ -0,0 +1,35 @@ +<?xml version="1.0" encoding="UTF-8"?> +<!-- + 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. +--> +<included> + + <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> + <encoder> + <pattern>%d %-5level %X{entity.ids} %msg%n%xEx{0}</pattern> + </encoder> + <filter class="ch.qos.logback.classic.filter.ThresholdFilter"> + <level>INFO</level> + </filter> + </appender> + + <root> + <appender-ref ref="STDOUT" /> + </root> + +</included> http://git-wip-us.apache.org/repos/asf/brooklyn-server/blob/11740cc6/pom.xml ---------------------------------------------------------------------- diff --git a/pom.xml b/pom.xml index 62a2bfe..6df2dcf 100644 --- a/pom.xml +++ b/pom.xml @@ -103,7 +103,7 @@ <!-- Dependency Versions --> <jclouds.version>2.0.2</jclouds.version> <!-- JCLOUDS_VERSION --> <logback.version>1.0.7</logback.version> - <slf4j.version>1.6.6</slf4j.version> <!-- used for java.util.logging jul-to-slf4j interception --> + <slf4j.version>1.7.25</slf4j.version> <!-- used for java.util.logging jul-to-slf4j interception --> <!-- Must match jclouds' version. From jclouds 1.9.3+ can be any version in the range [16-20) --> <guava.version>18.0</guava.version> <!--