From 969f68ca03745849365811ffbdf7f1a2288e6995 Mon Sep 17 00:00:00 2001 From: Ralph Goers Date: Sat, 16 Mar 2024 17:58:02 -0700 Subject: [PATCH 1/4] 2214 - Add support for ScopedContext --- .../logging/log4j/ScopedContextTest.java | 44 ++++ .../apache/logging/log4j/ScopedContext.java | 224 ++++++++++++++++++ .../apache/logging/log4j/package-info.java | 2 +- .../logging/log4j/simple/SimpleLogger.java | 7 +- .../logging/log4j/core/ScopedContextTest.java | 66 ++++++ .../src/test/resources/log4j-list2.xml | 31 +++ .../core/impl/ScopedContextDataProvider.java | 50 ++++ .../logging/log4j/core/impl/package-info.java | 2 +- src/changelog/.2.x.x/add_scoped_context.xml | 9 + src/site/_release-notes/_2.x.x.adoc | 1 + src/site/asciidoc/manual/scoped-context.adoc | 82 +++++++ src/site/site.xml | 1 + 12 files changed, 515 insertions(+), 4 deletions(-) create mode 100644 log4j-api-test/src/test/java/org/apache/logging/log4j/ScopedContextTest.java create mode 100644 log4j-api/src/main/java/org/apache/logging/log4j/ScopedContext.java create mode 100644 log4j-core-test/src/test/java/org/apache/logging/log4j/core/ScopedContextTest.java create mode 100644 log4j-core-test/src/test/resources/log4j-list2.xml create mode 100644 log4j-core/src/main/java/org/apache/logging/log4j/core/impl/ScopedContextDataProvider.java create mode 100644 src/changelog/.2.x.x/add_scoped_context.xml create mode 100644 src/site/asciidoc/manual/scoped-context.adoc diff --git a/log4j-api-test/src/test/java/org/apache/logging/log4j/ScopedContextTest.java b/log4j-api-test/src/test/java/org/apache/logging/log4j/ScopedContextTest.java new file mode 100644 index 00000000000..609ec0b5ad6 --- /dev/null +++ b/log4j-api-test/src/test/java/org/apache/logging/log4j/ScopedContextTest.java @@ -0,0 +1,44 @@ +/* + * 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.logging.log4j; + +import static org.hamcrest.MatcherAssert.assertThat; +import static org.hamcrest.Matchers.equalTo; +import static org.hamcrest.Matchers.nullValue; + +import org.junit.jupiter.api.Test; + +public class ScopedContextTest { + + @Test + public void testScope() { + ScopedContext.newInstance() + .where("key1", "Log4j2") + .run(() -> assertThat(ScopedContext.get("key1"), equalTo("Log4j2"))); + ScopedContext.newInstance().where("key1", "value1").run(() -> { + assertThat(ScopedContext.get("key1"), equalTo("value1")); + ScopedContext.newInstance(true).where("key2", "value2").run(() -> { + assertThat(ScopedContext.get("key1"), equalTo("value1")); + assertThat(ScopedContext.get("key2"), equalTo("value2")); + }); + ScopedContext.newInstance().where("key2", "value2").run(() -> { + assertThat(ScopedContext.get("key1"), nullValue()); + assertThat(ScopedContext.get("key2"), equalTo("value2")); + }); + }); + } +} diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/ScopedContext.java b/log4j-api/src/main/java/org/apache/logging/log4j/ScopedContext.java new file mode 100644 index 00000000000..d320b708d60 --- /dev/null +++ b/log4j-api/src/main/java/org/apache/logging/log4j/ScopedContext.java @@ -0,0 +1,224 @@ +/* + * 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.logging.log4j; + +import java.util.ArrayDeque; +import java.util.Collections; +import java.util.Deque; +import java.util.HashMap; +import java.util.Map; +import java.util.concurrent.Callable; +import java.util.function.Supplier; + +/** + * Context that can be used for data to be logged in a block of code. + * + * While this is influenced by ScopedValues from Java 21 it does not share the same API. While it can perform a + * similar function as a set of ScopedValues it is really meant to allow a block of code to include a set of keys and + * values in all the log events within that block. The underlying implementation must provide support for + * logging the ScopedContext for that to happen. + * + * The ScopedContext will not be bound to the current thread until either a run or call method is invoked. The + * contexts are nested so creating and running or calling via a second ScopedContext will result in the first + * ScopedContext being hidden until the call is returned. Thus the values from the first ScopedContext need to + * be added to the second to be included. + * + * @since 2.24.0 + */ +public class ScopedContext { + + private static final ThreadLocal>> scopedContext = new ThreadLocal<>(); + + /** + * Returns an immutable Map containing all the key/value pairs as Renderable objects. + * @return An immutable copy of the Map at the current scope. + */ + public static Map getContext() { + Deque> stack = scopedContext.get(); + if (stack != null && !stack.isEmpty()) { + return Collections.unmodifiableMap(stack.getFirst()); + } + return Collections.emptyMap(); + } + + private static void addScopedContext(Map contextMap) { + Deque> stack = scopedContext.get(); + if (stack == null) { + stack = new ArrayDeque<>(); + scopedContext.set(stack); + } + stack.addFirst(contextMap); + } + + private static void removeScopedContext() { + Deque> stack = scopedContext.get(); + if (stack != null) { + if (!stack.isEmpty()) { + stack.removeFirst(); + } + if (stack.isEmpty()) { + scopedContext.remove(); + } + } + } + + /** + * Return a new ScopedContext. + * @return the ScopedContext. + */ + public static ScopedContext newInstance() { + return newInstance(false); + } + + /** + * Return a new ScopedContext. + * @param inherit true if this context should inherit the values of its parent. + * @return the ScopedContext. + */ + public static ScopedContext newInstance(boolean inherit) { + return new ScopedContext(inherit); + } + + /** + * Return the key from the current ScopedContext, if there is one and the key exists. + * @param key The key. + * @return The value of the key in the current ScopedContext. + */ + @SuppressWarnings("unchecked") + public static T get(String key) { + Renderable renderable = getContext().get(key); + if (renderable != null) { + return (T) renderable.getObject(); + } else { + return null; + } + } + + private final Map contextMap = new HashMap<>(); + + private ScopedContext(boolean inherit) { + Map parent = ScopedContext.getContext(); + if (inherit && !parent.isEmpty()) { + contextMap.putAll(parent); + } + } + + /** + * Add all the values in the specified Map to the ScopedContext being constructed. + * + * @param map The Map to add to the ScopedContext being constructed. + * @return the ScopedContext being constructed. + */ + public ScopedContext where(Map map) { + map.forEach(this::addObject); + return this; + } + + /** + * Adds a key/value pair to the ScopedContext being constructed. + * @param key the key to add. + * @param value the value associated with the key. + * @return the ScopedContext being constructed. + */ + public ScopedContext where(String key, Object value) { + addObject(key, value); + return this; + } + + /** + * Adds a key/value pair to the ScopedContext being constructed. + * @param key the key to add. + * @param supplier the function to generate the value. + * @return the ScopedContext being constructed. + */ + public ScopedContext where(String key, Supplier supplier) { + addObject(key, supplier.get()); + return this; + } + + private void addObject(String key, Object obj) { + if (obj != null) { + if (obj instanceof Renderable) { + contextMap.put(key, (Renderable) obj); + } else { + contextMap.put(key, new ObjectRenderable(obj)); + } + } + } + + /** + * Executes a code block that includes all the key/value pairs added to the ScopedContext. + * @param op the code block to execute. + */ + public void run(Runnable op) { + addScopedContext(contextMap); + try { + op.run(); + } finally { + removeScopedContext(); + } + } + + /** + * Executes a code block that includes all the key/value pairs added to the ScopedContext. + * @param op the code block to execute. + * @return the return value from the code block. + */ + public R call(Callable op) throws Exception { + addScopedContext(contextMap); + try { + return op.call(); + } finally { + removeScopedContext(); + } + } + + /** + * Interface for converting Objects stored in the ContextScope to Strings for logging. + */ + public static interface Renderable { + /** + * Render the object as a String. + * @return the String representation of the Object. + */ + default String render() { + return this.toString(); + } + + default Object getObject() { + return this; + } + } + + private static class ObjectRenderable implements Renderable { + private final Object object; + + public ObjectRenderable(Object object) { + this.object = object; + } + + @Override + public String render() { + return object.toString(); + } + + @Override + public Object getObject() { + return object; + } + } +} diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/package-info.java b/log4j-api/src/main/java/org/apache/logging/log4j/package-info.java index 5407f05f619..f1c67c6c86c 100644 --- a/log4j-api/src/main/java/org/apache/logging/log4j/package-info.java +++ b/log4j-api/src/main/java/org/apache/logging/log4j/package-info.java @@ -32,7 +32,7 @@ * @see Log4j 2 API manual */ @Export -@Version("2.20.2") +@Version("2.24.0") package org.apache.logging.log4j; import org.osgi.annotation.bundle.Export; diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/simple/SimpleLogger.java b/log4j-api/src/main/java/org/apache/logging/log4j/simple/SimpleLogger.java index 1690893187f..2c461905171 100644 --- a/log4j-api/src/main/java/org/apache/logging/log4j/simple/SimpleLogger.java +++ b/log4j-api/src/main/java/org/apache/logging/log4j/simple/SimpleLogger.java @@ -21,9 +21,11 @@ import java.text.DateFormat; import java.text.SimpleDateFormat; import java.util.Date; +import java.util.HashMap; import java.util.Map; import org.apache.logging.log4j.Level; import org.apache.logging.log4j.Marker; +import org.apache.logging.log4j.ScopedContext; import org.apache.logging.log4j.ThreadContext; import org.apache.logging.log4j.message.Message; import org.apache.logging.log4j.message.MessageFactory; @@ -294,8 +296,9 @@ public void logMessage( } sb.append(msg.getFormattedMessage()); if (showContextMap) { - final Map mdc = ThreadContext.getImmutableContext(); - if (mdc.size() > 0) { + final Map mdc = new HashMap<>(ThreadContext.getImmutableContext()); + ScopedContext.getContext().forEach((key, value) -> mdc.put(key, value.render())); + if (!mdc.isEmpty()) { sb.append(SPACE); sb.append(mdc.toString()); sb.append(SPACE); diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/ScopedContextTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/ScopedContextTest.java new file mode 100644 index 00000000000..994097a5664 --- /dev/null +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/ScopedContextTest.java @@ -0,0 +1,66 @@ +/* + * 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.logging.log4j.core; + +import static org.hamcrest.MatcherAssert.assertThat; +import static org.hamcrest.Matchers.containsString; +import static org.hamcrest.Matchers.hasSize; + +import java.util.List; +import org.apache.logging.log4j.ScopedContext; +import org.apache.logging.log4j.core.test.appender.ListAppender; +import org.apache.logging.log4j.core.test.junit.LoggerContextSource; +import org.apache.logging.log4j.core.test.junit.Named; +import org.junit.jupiter.api.Test; + +@LoggerContextSource("log4j-list2.xml") +public class ScopedContextTest { + + private final ListAppender app; + + public ScopedContextTest(@Named("List") final ListAppender list) { + app = list.clear(); + } + + @Test + public void testScope(final LoggerContext context) { + final org.apache.logging.log4j.Logger logger = context.getLogger("org.apache.logging.log4j.scoped"); + ScopedContext.newInstance().where("key1", "Log4j2").run(() -> logger.debug("Hello, {}", "World")); + List msgs = app.getMessages(); + assertThat(msgs, hasSize(1)); + String expected = "{key1=Log4j2}"; + assertThat(msgs.get(0), containsString(expected)); + app.clear(); + ScopedContext.newInstance().where("key1", "value1").run(() -> { + logger.debug("Log message 1 will include key1"); + ScopedContext.newInstance(true) + .where("key2", "value2") + .run(() -> logger.debug("Log message 2 will include key1 and key2")); + ScopedContext.newInstance() + .where("key2", "value2") + .run(() -> logger.debug("Log message 2 will include key2")); + }); + msgs = app.getMessages(); + assertThat(msgs, hasSize(3)); + expected = "{key1=value1}"; + assertThat(msgs.get(0), containsString(expected)); + expected = "{key1=value1, key2=value2}"; + assertThat(msgs.get(1), containsString(expected)); + expected = "{key2=value2}"; + assertThat(msgs.get(2), containsString(expected)); + } +} diff --git a/log4j-core-test/src/test/resources/log4j-list2.xml b/log4j-core-test/src/test/resources/log4j-list2.xml new file mode 100644 index 00000000000..c747458fbdb --- /dev/null +++ b/log4j-core-test/src/test/resources/log4j-list2.xml @@ -0,0 +1,31 @@ + + + + + + + + + + + + + + + + diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/ScopedContextDataProvider.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/ScopedContextDataProvider.java new file mode 100644 index 00000000000..7e638a57a82 --- /dev/null +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/ScopedContextDataProvider.java @@ -0,0 +1,50 @@ +/* + * 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.logging.log4j.core.impl; + +import aQute.bnd.annotation.Resolution; +import aQute.bnd.annotation.spi.ServiceProvider; +import java.util.Collections; +import java.util.HashMap; +import java.util.Map; +import org.apache.logging.log4j.ScopedContext; +import org.apache.logging.log4j.core.util.ContextDataProvider; +import org.apache.logging.log4j.util.StringMap; + +/** + * ContextDataProvider for Map data. + */ +@ServiceProvider(value = ContextDataProvider.class, resolution = Resolution.OPTIONAL) +public class ScopedContextDataProvider implements ContextDataProvider { + + @Override + public Map supplyContextData() { + Map contextMap = ScopedContext.getContext(); + if (!contextMap.isEmpty()) { + Map map = new HashMap<>(); + contextMap.forEach((key, value) -> map.put(key, value.render())); + return map; + } else { + return Collections.emptyMap(); + } + } + + @Override + public StringMap supplyStringMap() { + return new JdkMapAdapterStringMap(supplyContextData()); + } +} diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/package-info.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/package-info.java index c50504a8726..0c3b08f43a7 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/package-info.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/package-info.java @@ -18,7 +18,7 @@ * Log4j 2 private implementation classes. */ @Export -@Version("2.23.0") +@Version("2.24.0") package org.apache.logging.log4j.core.impl; import org.osgi.annotation.bundle.Export; diff --git a/src/changelog/.2.x.x/add_scoped_context.xml b/src/changelog/.2.x.x/add_scoped_context.xml new file mode 100644 index 00000000000..06db3eb0d54 --- /dev/null +++ b/src/changelog/.2.x.x/add_scoped_context.xml @@ -0,0 +1,9 @@ + + + + + Add ScopedContext to log4j-api and ScopedContextDataProvider in log4j-core. + diff --git a/src/site/_release-notes/_2.x.x.adoc b/src/site/_release-notes/_2.x.x.adoc index bbcc5b10efd..79d4278c240 100644 --- a/src/site/_release-notes/_2.x.x.adoc +++ b/src/site/_release-notes/_2.x.x.adoc @@ -31,6 +31,7 @@ This releases contains ... [#release-notes-2-x-x-updated] === Updated +* Add ScopedContext to log4j-api and ScopedContextDataProvider in log4j-core. (https://github.com/apache/logging-log4j-kotlin/issues/71[kotlin-71], https://github.com/apache/logging-log4j2/discussions/2214[2214]) * Update `actions/checkout` to version `4.1.2` (https://github.com/apache/logging-log4j2/pull/2370[2370]) * Update `com.fasterxml.jackson:jackson-bom` to version `2.17.0` (https://github.com/apache/logging-log4j2/pull/2372[2372]) * Update `com.google.guava:guava` to version `33.1.0-jre` (https://github.com/apache/logging-log4j2/pull/2377[2377]) diff --git a/src/site/asciidoc/manual/scoped-context.adoc b/src/site/asciidoc/manual/scoped-context.adoc new file mode 100644 index 00000000000..7f9afd21679 --- /dev/null +++ b/src/site/asciidoc/manual/scoped-context.adoc @@ -0,0 +1,82 @@ +//// + 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. +//// += Log4j 2 API +Ralph Goers ; + +== Scoped Context +The link:../log4j-api/apidocs/org/apache/logging/log4j/ScopedContext.html[`ScopedContext`] +is available in Log4j API releases 2.24.0 and greater. + +The `ScopedContext` is similar to the ThreadContextMap in that it allows key/value pairs to be included +in many log events. However, the pairs in a `ScopedContext` are only available to +application code and log events running within the scope of the `ScopeContext` object. + +The `ScopeContext` is essentially a builder that allows key/value pairs to be added to it +prior to invoking a method. The key/value pairs are available to any code running within +that method and will be included in all logging events as if they were part of the `ThreadContextMap`. + +[source,java] +---- +ScopedContext.newInstance() + .where("id", UUID.randomUUID()) + .where("ipAddress", request.getRemoteAddr()) + .where("loginId", session.getAttribute("loginId")) + .where("hostName", request.getServerName()) + .run(new Worker()); + +private class Worker implements Runnable { + private static final Logger LOGGER = LogManager.getLogger(Worker.class); + + public void run() { + LOGGER.debug("Performing work"); + String loginId = ScopedContext.get("loginId"); + } +} + +---- + +The values in the ScopedContext can be any Java object. However, objects stored in the +context Map will be converted to Strings when stored in a LogEvent. To aid in +this Objects may implement the Renderable interface which provides a `render` method +to format the object. By default, objects will have their toString() method called +if they do not implement the Renderable interface. + +Note that in the example above `UUID.randomUUID()` returns a UUID. By default, when it is +included in LogEvents its toString() method will be used. + +=== Nested ScopedContexts + +ScopedContexts may be nested. When creating a nested context the default behavior is to +hide the key/value pairs of the parent context. The may be included by passing `true` to +the newInstance method when creating the child context. + + +[source,java] +---- + ScopedContext.newInstance().where("key1", "value1").run(() -> { + assertThat(ScopedContext.get("key1"), equalTo("value1")); + ScopedContext.newInstance(true).where("key2", "value2").run(() -> { + assertThat(ScopedContext.get("key1"), equalTo("value1")); + assertThat(ScopedContext.get("key2"), equalTo("value2")); + }); + ScopedContext.newInstance().where("key2", "value2").run(() -> { + assertThat(ScopedContext.get("key1"), nullValue()); + assertThat(ScopedContext.get("key2"), equalTo("value2")); + }); + }); + +---- \ No newline at end of file diff --git a/src/site/site.xml b/src/site/site.xml index 75c89e075e4..b044e24a250 100644 --- a/src/site/site.xml +++ b/src/site/site.xml @@ -100,6 +100,7 @@ + From 9ced07ae352b46bc057ab744fbec5851882a6616 Mon Sep 17 00:00:00 2001 From: Ralph Goers Date: Sat, 16 Mar 2024 22:53:46 -0700 Subject: [PATCH 2/4] Fix javadoc error --- .../logging/log4j/core/impl/ScopedContextDataProvider.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/ScopedContextDataProvider.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/ScopedContextDataProvider.java index 7e638a57a82..7822e196d59 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/ScopedContextDataProvider.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/ScopedContextDataProvider.java @@ -26,7 +26,7 @@ import org.apache.logging.log4j.util.StringMap; /** - * ContextDataProvider for Map data. + * ContextDataProvider for {@code Map} data. */ @ServiceProvider(value = ContextDataProvider.class, resolution = Resolution.OPTIONAL) public class ScopedContextDataProvider implements ContextDataProvider { From 1bb1d0e6fc935962afc5dd6c017ba8ec4083a500 Mon Sep 17 00:00:00 2001 From: Ralph Goers Date: Sun, 17 Mar 2024 23:22:28 -0700 Subject: [PATCH 3/4] Made ScopedContext immutable --- .../logging/log4j/ScopedContextTest.java | 8 +- .../apache/logging/log4j/ScopedContext.java | 120 ++++++------------ .../log4j/internal/ScopedContextAnchor.java | 69 ++++++++++ .../logging/log4j/simple/SimpleLogger.java | 2 +- .../logging/log4j/core/ScopedContextTest.java | 9 +- .../core/impl/ScopedContextDataProvider.java | 2 +- .../core/impl/internal/package-info.java | 25 ++++ src/site/asciidoc/manual/scoped-context.adoc | 17 ++- 8 files changed, 154 insertions(+), 98 deletions(-) create mode 100644 log4j-api/src/main/java/org/apache/logging/log4j/internal/ScopedContextAnchor.java create mode 100644 log4j-core/src/main/java/org/apache/logging/log4j/core/impl/internal/package-info.java diff --git a/log4j-api-test/src/test/java/org/apache/logging/log4j/ScopedContextTest.java b/log4j-api-test/src/test/java/org/apache/logging/log4j/ScopedContextTest.java index 609ec0b5ad6..21aa829b785 100644 --- a/log4j-api-test/src/test/java/org/apache/logging/log4j/ScopedContextTest.java +++ b/log4j-api-test/src/test/java/org/apache/logging/log4j/ScopedContextTest.java @@ -26,16 +26,16 @@ public class ScopedContextTest { @Test public void testScope() { - ScopedContext.newInstance() + ScopedContext.INITIAL_CONTEXT .where("key1", "Log4j2") .run(() -> assertThat(ScopedContext.get("key1"), equalTo("Log4j2"))); - ScopedContext.newInstance().where("key1", "value1").run(() -> { + ScopedContext.INITIAL_CONTEXT.where("key1", "value1").run(() -> { assertThat(ScopedContext.get("key1"), equalTo("value1")); - ScopedContext.newInstance(true).where("key2", "value2").run(() -> { + ScopedContext.current().get().where("key2", "value2").run(() -> { assertThat(ScopedContext.get("key1"), equalTo("value1")); assertThat(ScopedContext.get("key2"), equalTo("value2")); }); - ScopedContext.newInstance().where("key2", "value2").run(() -> { + ScopedContext.INITIAL_CONTEXT.where("key2", "value2").run(() -> { assertThat(ScopedContext.get("key1"), nullValue()); assertThat(ScopedContext.get("key2"), equalTo("value2")); }); diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/ScopedContext.java b/log4j-api/src/main/java/org/apache/logging/log4j/ScopedContext.java index d320b708d60..5428bcb0aa4 100644 --- a/log4j-api/src/main/java/org/apache/logging/log4j/ScopedContext.java +++ b/log4j-api/src/main/java/org/apache/logging/log4j/ScopedContext.java @@ -16,13 +16,13 @@ */ package org.apache.logging.log4j; -import java.util.ArrayDeque; import java.util.Collections; -import java.util.Deque; import java.util.HashMap; import java.util.Map; +import java.util.Optional; import java.util.concurrent.Callable; import java.util.function.Supplier; +import org.apache.logging.log4j.internal.ScopedContextAnchor; /** * Context that can be used for data to be logged in a block of code. @@ -41,56 +41,18 @@ */ public class ScopedContext { - private static final ThreadLocal>> scopedContext = new ThreadLocal<>(); + public static final ScopedContext INITIAL_CONTEXT = new ScopedContext(); /** - * Returns an immutable Map containing all the key/value pairs as Renderable objects. - * @return An immutable copy of the Map at the current scope. + * @hidden + * Returns an unmodifiable copy of the current ScopedContext Map. This method should + * only be used by implementations of Log4j API. + * @return the Map of Renderable objects. */ - public static Map getContext() { - Deque> stack = scopedContext.get(); - if (stack != null && !stack.isEmpty()) { - return Collections.unmodifiableMap(stack.getFirst()); - } - return Collections.emptyMap(); - } - - private static void addScopedContext(Map contextMap) { - Deque> stack = scopedContext.get(); - if (stack == null) { - stack = new ArrayDeque<>(); - scopedContext.set(stack); - } - stack.addFirst(contextMap); - } - - private static void removeScopedContext() { - Deque> stack = scopedContext.get(); - if (stack != null) { - if (!stack.isEmpty()) { - stack.removeFirst(); - } - if (stack.isEmpty()) { - scopedContext.remove(); - } - } - } - - /** - * Return a new ScopedContext. - * @return the ScopedContext. - */ - public static ScopedContext newInstance() { - return newInstance(false); - } - - /** - * Return a new ScopedContext. - * @param inherit true if this context should inherit the values of its parent. - * @return the ScopedContext. - */ - public static ScopedContext newInstance(boolean inherit) { - return new ScopedContext(inherit); + public static Map getContextMap() { + Optional context = ScopedContextAnchor.getContext(); + return context.map(scopedContext -> Collections.unmodifiableMap(scopedContext.contextMap)) + .orElse(Collections.emptyMap()); } /** @@ -100,34 +62,28 @@ public static ScopedContext newInstance(boolean inherit) { */ @SuppressWarnings("unchecked") public static T get(String key) { - Renderable renderable = getContext().get(key); - if (renderable != null) { - return (T) renderable.getObject(); - } else { - return null; - } - } - - private final Map contextMap = new HashMap<>(); - - private ScopedContext(boolean inherit) { - Map parent = ScopedContext.getContext(); - if (inherit && !parent.isEmpty()) { - contextMap.putAll(parent); + Optional context = ScopedContextAnchor.getContext(); + if (context.isPresent()) { + Renderable renderable = context.get().contextMap.get(key); + if (renderable != null) { + return (T) renderable.getObject(); + } } + return null; } /** - * Add all the values in the specified Map to the ScopedContext being constructed. - * - * @param map The Map to add to the ScopedContext being constructed. - * @return the ScopedContext being constructed. + * Returns an Optional holding the active ScopedContext. + * @return an Optional containing the active ScopedContext, if there is one. */ - public ScopedContext where(Map map) { - map.forEach(this::addObject); - return this; + public static Optional current() { + return ScopedContextAnchor.getContext(); } + private final Map contextMap = new HashMap<>(); + + private ScopedContext() {} + /** * Adds a key/value pair to the ScopedContext being constructed. * @param key the key to add. @@ -135,8 +91,7 @@ public ScopedContext where(Map map) { * @return the ScopedContext being constructed. */ public ScopedContext where(String key, Object value) { - addObject(key, value); - return this; + return addObject(key, value); } /** @@ -146,18 +101,21 @@ public ScopedContext where(String key, Object value) { * @return the ScopedContext being constructed. */ public ScopedContext where(String key, Supplier supplier) { - addObject(key, supplier.get()); - return this; + return addObject(key, supplier.get()); } - private void addObject(String key, Object obj) { + private ScopedContext addObject(String key, Object obj) { if (obj != null) { + ScopedContext context = new ScopedContext(); + context.contextMap.putAll(this.contextMap); if (obj instanceof Renderable) { - contextMap.put(key, (Renderable) obj); + context.contextMap.put(key, (Renderable) obj); } else { - contextMap.put(key, new ObjectRenderable(obj)); + context.contextMap.put(key, new ObjectRenderable(obj)); } + return context; } + return this; } /** @@ -165,11 +123,11 @@ private void addObject(String key, Object obj) { * @param op the code block to execute. */ public void run(Runnable op) { - addScopedContext(contextMap); + ScopedContextAnchor.addScopedContext(this); try { op.run(); } finally { - removeScopedContext(); + ScopedContextAnchor.removeScopedContext(); } } @@ -179,11 +137,11 @@ public void run(Runnable op) { * @return the return value from the code block. */ public R call(Callable op) throws Exception { - addScopedContext(contextMap); + ScopedContextAnchor.addScopedContext(this); try { return op.call(); } finally { - removeScopedContext(); + ScopedContextAnchor.removeScopedContext(); } } diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/internal/ScopedContextAnchor.java b/log4j-api/src/main/java/org/apache/logging/log4j/internal/ScopedContextAnchor.java new file mode 100644 index 00000000000..2c8b7ec39ba --- /dev/null +++ b/log4j-api/src/main/java/org/apache/logging/log4j/internal/ScopedContextAnchor.java @@ -0,0 +1,69 @@ +/* + * 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.logging.log4j.internal; + +import java.util.ArrayDeque; +import java.util.Deque; +import java.util.Optional; +import org.apache.logging.log4j.ScopedContext; + +/** + * Anchor for the ScopedContext. This class is private and not for public consumption. + */ +public class ScopedContextAnchor { + private static final ThreadLocal> scopedContext = new ThreadLocal<>(); + + /** + * Returns an immutable Map containing all the key/value pairs as Renderable objects. + * @return An immutable copy of the Map at the current scope. + */ + public static Optional getContext() { + Deque stack = scopedContext.get(); + if (stack != null) { + return Optional.of(stack.getFirst()); + } + return Optional.empty(); + } + + /** + * Add the ScopeContext. + * @param context The ScopeContext. + */ + public static void addScopedContext(ScopedContext context) { + Deque stack = scopedContext.get(); + if (stack == null) { + stack = new ArrayDeque<>(); + scopedContext.set(stack); + } + stack.addFirst(context); + } + + /** + * Remove the top ScopeContext. + */ + public static void removeScopedContext() { + Deque stack = scopedContext.get(); + if (stack != null) { + if (!stack.isEmpty()) { + stack.removeFirst(); + } + if (stack.isEmpty()) { + scopedContext.remove(); + } + } + } +} diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/simple/SimpleLogger.java b/log4j-api/src/main/java/org/apache/logging/log4j/simple/SimpleLogger.java index 2c461905171..f5529f4258d 100644 --- a/log4j-api/src/main/java/org/apache/logging/log4j/simple/SimpleLogger.java +++ b/log4j-api/src/main/java/org/apache/logging/log4j/simple/SimpleLogger.java @@ -297,7 +297,7 @@ public void logMessage( sb.append(msg.getFormattedMessage()); if (showContextMap) { final Map mdc = new HashMap<>(ThreadContext.getImmutableContext()); - ScopedContext.getContext().forEach((key, value) -> mdc.put(key, value.render())); + ScopedContext.getContextMap().forEach((key, value) -> mdc.put(key, value.render())); if (!mdc.isEmpty()) { sb.append(SPACE); sb.append(mdc.toString()); diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/ScopedContextTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/ScopedContextTest.java index 994097a5664..ccb90aa8779 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/ScopedContextTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/ScopedContextTest.java @@ -39,18 +39,19 @@ public ScopedContextTest(@Named("List") final ListAppender list) { @Test public void testScope(final LoggerContext context) { final org.apache.logging.log4j.Logger logger = context.getLogger("org.apache.logging.log4j.scoped"); - ScopedContext.newInstance().where("key1", "Log4j2").run(() -> logger.debug("Hello, {}", "World")); + ScopedContext.INITIAL_CONTEXT.where("key1", "Log4j2").run(() -> logger.debug("Hello, {}", "World")); List msgs = app.getMessages(); assertThat(msgs, hasSize(1)); String expected = "{key1=Log4j2}"; assertThat(msgs.get(0), containsString(expected)); app.clear(); - ScopedContext.newInstance().where("key1", "value1").run(() -> { + ScopedContext.INITIAL_CONTEXT.where("key1", "value1").run(() -> { logger.debug("Log message 1 will include key1"); - ScopedContext.newInstance(true) + ScopedContext.current() + .get() .where("key2", "value2") .run(() -> logger.debug("Log message 2 will include key1 and key2")); - ScopedContext.newInstance() + ScopedContext.INITIAL_CONTEXT .where("key2", "value2") .run(() -> logger.debug("Log message 2 will include key2")); }); diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/ScopedContextDataProvider.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/ScopedContextDataProvider.java index 7822e196d59..a4f651b7ea1 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/ScopedContextDataProvider.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/ScopedContextDataProvider.java @@ -33,7 +33,7 @@ public class ScopedContextDataProvider implements ContextDataProvider { @Override public Map supplyContextData() { - Map contextMap = ScopedContext.getContext(); + Map contextMap = ScopedContext.getContextMap(); if (!contextMap.isEmpty()) { Map map = new HashMap<>(); contextMap.forEach((key, value) -> map.put(key, value.render())); diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/internal/package-info.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/internal/package-info.java new file mode 100644 index 00000000000..9d76948fcaf --- /dev/null +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/internal/package-info.java @@ -0,0 +1,25 @@ +/* + * 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. + */ +/** + * Log4j 2 private implementation classes. + */ +@Export +@Version("2.24.0") +package org.apache.logging.log4j.core.impl.internal; + +import org.osgi.annotation.bundle.Export; +import org.osgi.annotation.versioning.Version; diff --git a/src/site/asciidoc/manual/scoped-context.adoc b/src/site/asciidoc/manual/scoped-context.adoc index 7f9afd21679..77cbbde53f4 100644 --- a/src/site/asciidoc/manual/scoped-context.adoc +++ b/src/site/asciidoc/manual/scoped-context.adoc @@ -29,9 +29,12 @@ The `ScopeContext` is essentially a builder that allows key/value pairs to be ad prior to invoking a method. The key/value pairs are available to any code running within that method and will be included in all logging events as if they were part of the `ThreadContextMap`. +ScopedContext is immutable. Each invocation of the `where` method returns a new ScopedContext +with the specified key/value pair added to those defined in previous ScopedContexts. + [source,java] ---- -ScopedContext.newInstance() +ScopedContext.INITIAL_CONTEXT .where("id", UUID.randomUUID()) .where("ipAddress", request.getRemoteAddr()) .where("loginId", session.getAttribute("loginId")) @@ -60,20 +63,20 @@ included in LogEvents its toString() method will be used. === Nested ScopedContexts -ScopedContexts may be nested. When creating a nested context the default behavior is to -hide the key/value pairs of the parent context. The may be included by passing `true` to -the newInstance method when creating the child context. +ScopedContexts may be nested. Becuase ScopedContexts are immutable the `where` method may +be called on the current ScopedContext from within the run or call methods to append new +key/value pairs. [source,java] ---- - ScopedContext.newInstance().where("key1", "value1").run(() -> { + ScopedContext.INITIAL_CONTEXT.where("key1", "value1").run(() -> { assertThat(ScopedContext.get("key1"), equalTo("value1")); - ScopedContext.newInstance(true).where("key2", "value2").run(() -> { + ScopedContext.current().get().where("key2", "value2").run(() -> { assertThat(ScopedContext.get("key1"), equalTo("value1")); assertThat(ScopedContext.get("key2"), equalTo("value2")); }); - ScopedContext.newInstance().where("key2", "value2").run(() -> { + ScopedContext.INITIAL_CONTEXT.where("key2", "value2").run(() -> { assertThat(ScopedContext.get("key1"), nullValue()); assertThat(ScopedContext.get("key2"), equalTo("value2")); }); From 4c0e1a59ad24e2ecb7b9e409ff72ec46a3459e38 Mon Sep 17 00:00:00 2001 From: Ralph Goers Date: Mon, 18 Mar 2024 16:59:21 -0700 Subject: [PATCH 4/4] Minimize map creation --- .../apache/logging/log4j/ScopedContext.java | 130 ++++++++++++++---- 1 file changed, 106 insertions(+), 24 deletions(-) diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/ScopedContext.java b/log4j-api/src/main/java/org/apache/logging/log4j/ScopedContext.java index 5428bcb0aa4..148badda931 100644 --- a/log4j-api/src/main/java/org/apache/logging/log4j/ScopedContext.java +++ b/log4j-api/src/main/java/org/apache/logging/log4j/ScopedContext.java @@ -51,8 +51,12 @@ public class ScopedContext { */ public static Map getContextMap() { Optional context = ScopedContextAnchor.getContext(); - return context.map(scopedContext -> Collections.unmodifiableMap(scopedContext.contextMap)) - .orElse(Collections.emptyMap()); + if (context.isPresent() + && context.get().contextMap != null + && !context.get().contextMap.isEmpty()) { + return Collections.unmodifiableMap(context.get().contextMap); + } + return Collections.emptyMap(); } /** @@ -80,9 +84,31 @@ public static Optional current() { return ScopedContextAnchor.getContext(); } - private final Map contextMap = new HashMap<>(); + private final ScopedContext parent; + private final String key; + private final Renderable value; + private final Map contextMap; + + private ScopedContext() { + this.parent = null; + this.key = null; + this.value = null; + this.contextMap = null; + } - private ScopedContext() {} + private ScopedContext(Map map) { + this.parent = null; + this.key = null; + this.value = null; + this.contextMap = map; + } + + private ScopedContext(ScopedContext parent, String key, Renderable value) { + this.parent = parent; + this.key = key; + this.value = value; + this.contextMap = null; + } /** * Adds a key/value pair to the ScopedContext being constructed. @@ -106,14 +132,8 @@ public ScopedContext where(String key, Supplier supplier) { private ScopedContext addObject(String key, Object obj) { if (obj != null) { - ScopedContext context = new ScopedContext(); - context.contextMap.putAll(this.contextMap); - if (obj instanceof Renderable) { - context.contextMap.put(key, (Renderable) obj); - } else { - context.contextMap.put(key, new ObjectRenderable(obj)); - } - return context; + Renderable renderable = obj instanceof Renderable ? (Renderable) obj : new ObjectRenderable(obj); + return new ScopedContext(this, key, renderable); } return this; } @@ -123,12 +143,7 @@ private ScopedContext addObject(String key, Object obj) { * @param op the code block to execute. */ public void run(Runnable op) { - ScopedContextAnchor.addScopedContext(this); - try { - op.run(); - } finally { - ScopedContextAnchor.removeScopedContext(); - } + new ScopedContextRunner(this, op).run(); } /** @@ -136,12 +151,79 @@ public void run(Runnable op) { * @param op the code block to execute. * @return the return value from the code block. */ - public R call(Callable op) throws Exception { - ScopedContextAnchor.addScopedContext(this); - try { - return op.call(); - } finally { - ScopedContextAnchor.removeScopedContext(); + public R call(Callable op) throws Exception { + return new ScopedContextCaller(this, op).call(); + } + + private static class ScopedContextRunner implements Runnable { + private final Map contextMap = new HashMap<>(); + private final ScopedContext context; + private final Runnable op; + + public ScopedContextRunner(ScopedContext context, Runnable op) { + this.context = context; + this.op = op; + } + + @Override + public void run() { + ScopedContext scopedContext = context; + // If the current context has a Map then we can just use it. + if (context.contextMap == null) { + do { + if (scopedContext.contextMap != null) { + // Once we hit a scope with an already populated Map we won't need to go any further. + contextMap.putAll(scopedContext.contextMap); + break; + } else if (scopedContext.key != null) { + contextMap.putIfAbsent(scopedContext.key, scopedContext.value); + } + scopedContext = scopedContext.parent; + } while (scopedContext != null); + scopedContext = new ScopedContext(contextMap); + } + ScopedContextAnchor.addScopedContext(scopedContext); + try { + op.run(); + } finally { + ScopedContextAnchor.removeScopedContext(); + } + } + } + + private static class ScopedContextCaller implements Callable { + private final Map contextMap = new HashMap<>(); + private final ScopedContext context; + private final Callable op; + + public ScopedContextCaller(ScopedContext context, Callable op) { + this.context = context; + this.op = op; + } + + @Override + public R call() throws Exception { + ScopedContext scopedContext = context; + // If the current context has a Map then we can just use it. + if (context.contextMap == null) { + do { + if (scopedContext.contextMap != null) { + // Once we hit a scope with an already populated Map we won't need to go any further. + contextMap.putAll(scopedContext.contextMap); + break; + } else if (scopedContext.key != null) { + contextMap.putIfAbsent(scopedContext.key, scopedContext.value); + } + scopedContext = scopedContext.parent; + } while (scopedContext != null); + scopedContext = new ScopedContext(contextMap); + } + ScopedContextAnchor.addScopedContext(scopedContext); + try { + return op.call(); + } finally { + ScopedContextAnchor.removeScopedContext(); + } } }