[
https://issues.apache.org/jira/browse/LOG4J2-1401?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Remko Popma updated LOG4J2-1401:
--------------------------------
Description:
Use case:
We have a low-garbage trading system. When a production incident occurs we want
to temporarily increase visibility into what the system is doing by increasing
the log level. However, we want to do this selectively: we want the ability to
turn on detailed logging only for certain orders, for certain instruments, for
a certain user, or for some other attributes.
The system processes many messages, say in the order of hundreds of thousands
of messages per second. When a message is processed it passes through many
components of the system, and when each of these components do logging, the
message context information like order ID, instrument etc. should be available
so the log event can be filtered in the normal case and enabled in case of a
production incident.
We envision this "verbose logging" filtering to be switched on and off manually
by an operations team. In addition to manual operation, it would be nice if the
original verbosity can be restored automatically when some condition no longer
holds. For example, log at some verbose level
* for some period of time (5 minutes)
* for some fixed number of events (10,000 log messages)
* any other user-specified condition
There are two problems to solve:
# efficient and garbage-free log event "tagging"
# dynamic and garbage-free filtering
*Problem 1: Log Event "Tagging"*
Considerations:
* Because of the volume of events we want the mechanism for tagging log events
to be garbage-free.
* Our order IDs and instrument IDs etc are modeled as primitives ({{long}} and
{{int}} values).
Current options in Log4j for "tagging" a log event:
* *ThreadContext map*. (This _almost_ does what we need.) Data in this map is
copied into each Log Event, and downstream components can query the data with
the {{LogEvent.getContextMap() : Map<String, String>}} method. The drawback of
the ThreadContext API is that values must be Strings. We would like to be able
to store {{long}} primitives in the ThreadContext map. We can also take this
opportunity to provide a garbage-free version of the ThreadContext
(LOG4J2-1349) and the LogEvent properties map.
* *Direct user access to the LogEvent properties map*. LOG4J2-1010 suggests
changing the Logger API to accomplish this, but there may be alternatives.
* Update: the idea raised in LOG4J2-1010 to make initialization of the
LogEvent's {{contextMap}} data pluggable is relevant for this ticket also: It
means that context data can come from anywhere, not necessarily only from Log4j
API classes like ThreadContext. Applications can have their own custom
ThreadContext-like class with data that is copied into every log event, without
requiring changes to the Log4j API.
* *Markers*: (Not a good option, mentioned here for completeness.)
String-based, name attribute only (no key-value), hierarchical (may have
parents). Current implementation caches all Markers forever, with an option to
clear the whole cache. Unclear how to use this mechanism to tag a log event
with key-value pairs like order ID, user ID and/or product ID.
* Update: one way to work around this is to create a KeyValueMarker
implementation of the Marker interface. A single instance could contain
multiple tags (key-value pairs of arbitrary type). Instances cannot be cached
by name in the MarkerManager, but instead I imagine we can use a pool of
KeyValueMarkers to reuse (so we would need to call release() or something when
the log event is fully processed). This feels hacky though...
*Problem 2: Dynamic and garbage-free filtering*
It looks like installing a global filter on the Configuration is a good way to
accomplish this. It is straightforward to do this with existing Log4j APIs:
{code}
LoggerContext context = (org.apache.logging.log4j.core.LoggerContext)
LogManager.getContext(false);
context.addFilter(ourFilter);
// when done, call context.removeFilter(ourFilter)
{code}
Installing and removing a filter is rare and it is okay to create temporary
objects when doing this. Once the filter is installed, it should not create
temporary objects during steady state processing.
For the filter implementation, something like
[ThreadContextMapFilter|https://logging.apache.org/log4j/2.x/manual/filters.html#ThreadContextMapFilter]
is very close to what we need.
To do:
* {{ThreadContextMapFilter}} is not garbage-free: it creates a new iterator
every time the {{filter()}} method is called.
* Auto-removal of the Filter after some time has passed or some number of
events have been processed. It may be a useful addition to Log4j to provide a
{{CompositeFilter}} that automatically removes itself from a {{Configuration}}
when some condition is satisfied.
was:
During system operations, it is commonly desirable to temporarily make logging
for a certain domain object more verbose. For example, all log messages related
to processing a certain order, or for a certain user, or for a certain product.
In addition to manually increasing/decreasing verbosity, it would be nice if we
can restore the original verbosity if some condition no longer holds. For
example, log at some verbose level
* for some period of time (5 minutes)
* for some fixed number of events (10,000 log messages)
* any other user-specified condition
*Problem 1: Log Event "Tagging"*
How to efficiently "tag" log messages to select only _some_ log events to be
output at a more verbose level but don't show _all_ log events? Current methods
available for "tagging" a log event are:
* *Markers*: String-based, name attribute only (no key-value), hierarchical
(may have parents). Current implementation caches all Markers forever, with an
option to clear the whole cache. Unclear how to use this mechanism to tag a log
event with things like order ID, user ID and/or product ID.
** Update: one way to address these issues is to create a KeyValueMarker
implementation of the Marker interface. A single instance could contain
multiple tags (key-value pairs of arbitrary type). Instances cannot be cached
by name in the MarkerManager, but instead I imagine we can use a pool of
KeyValueMarkers to reuse (so we would need to call release() or something when
the log event is fully processed).
* *ThreadContext map*: the content of this map is merged into a properties map
for each Log Event. The drawback of the ThreadContext API is that values must
be Strings. We would like the ability to specify arbitrary Object values, or
even primitive values. We can also take this opportunity to provide a
garbage-free version of the ThreadContext (LOG4J2-1349) and the LogEvent
properties map.
* *Direct user access to the LogEvent properties map*. LOG4J2-1010 suggests
changing the Logger API to accomplish this, but there may be alternatives
(needs more thought). Similar to the above, ideally we would like the ability
to specify arbitrary Object values, or even primitive values, not just Strings.
* Other possibilities are *a new MessageFactory or a new LogEventFactory*.
These would require invasive changes in the Log4j design across the board. It
is not clear what the interfaces would look like for both upstream and
downstream components. Improving the other mechanisms seems a better option.
*Problem 2: Dynamic filtering*
* What mechanism to use for increasing verbosity of events matching some
condition? Global filters (on LogEvent properties or markers) may be a good
candidate.
* How can operators enable/disable this on the fly?
* How can we provide convenience features for automatically reverting to the
previous level of verbosity when some condition is met (e.g. after 10,000
events or after 5 minutes etc)
> Support changing the log level for all messages related to some domain object
> -----------------------------------------------------------------------------
>
> Key: LOG4J2-1401
> URL: https://issues.apache.org/jira/browse/LOG4J2-1401
> Project: Log4j 2
> Issue Type: New Feature
> Components: Core, Filters
> Affects Versions: 2.6
> Reporter: Remko Popma
>
> Use case:
> We have a low-garbage trading system. When a production incident occurs we
> want to temporarily increase visibility into what the system is doing by
> increasing the log level. However, we want to do this selectively: we want
> the ability to turn on detailed logging only for certain orders, for certain
> instruments, for a certain user, or for some other attributes.
> The system processes many messages, say in the order of hundreds of thousands
> of messages per second. When a message is processed it passes through many
> components of the system, and when each of these components do logging, the
> message context information like order ID, instrument etc. should be
> available so the log event can be filtered in the normal case and enabled in
> case of a production incident.
> We envision this "verbose logging" filtering to be switched on and off
> manually by an operations team. In addition to manual operation, it would be
> nice if the original verbosity can be restored automatically when some
> condition no longer holds. For example, log at some verbose level
> * for some period of time (5 minutes)
> * for some fixed number of events (10,000 log messages)
> * any other user-specified condition
> There are two problems to solve:
> # efficient and garbage-free log event "tagging"
> # dynamic and garbage-free filtering
> *Problem 1: Log Event "Tagging"*
> Considerations:
> * Because of the volume of events we want the mechanism for tagging log
> events to be garbage-free.
> * Our order IDs and instrument IDs etc are modeled as primitives ({{long}}
> and {{int}} values).
> Current options in Log4j for "tagging" a log event:
> * *ThreadContext map*. (This _almost_ does what we need.) Data in this map is
> copied into each Log Event, and downstream components can query the data with
> the {{LogEvent.getContextMap() : Map<String, String>}} method. The drawback
> of the ThreadContext API is that values must be Strings. We would like to be
> able to store {{long}} primitives in the ThreadContext map. We can also take
> this opportunity to provide a garbage-free version of the ThreadContext
> (LOG4J2-1349) and the LogEvent properties map.
> * *Direct user access to the LogEvent properties map*. LOG4J2-1010 suggests
> changing the Logger API to accomplish this, but there may be alternatives.
> * Update: the idea raised in LOG4J2-1010 to make initialization of the
> LogEvent's {{contextMap}} data pluggable is relevant for this ticket also: It
> means that context data can come from anywhere, not necessarily only from
> Log4j API classes like ThreadContext. Applications can have their own custom
> ThreadContext-like class with data that is copied into every log event,
> without requiring changes to the Log4j API.
> * *Markers*: (Not a good option, mentioned here for completeness.)
> String-based, name attribute only (no key-value), hierarchical (may have
> parents). Current implementation caches all Markers forever, with an option
> to clear the whole cache. Unclear how to use this mechanism to tag a log
> event with key-value pairs like order ID, user ID and/or product ID.
> * Update: one way to work around this is to create a KeyValueMarker
> implementation of the Marker interface. A single instance could contain
> multiple tags (key-value pairs of arbitrary type). Instances cannot be
> cached by name in the MarkerManager, but instead I imagine we can use a pool
> of KeyValueMarkers to reuse (so we would need to call release() or something
> when the log event is fully processed). This feels hacky though...
> *Problem 2: Dynamic and garbage-free filtering*
> It looks like installing a global filter on the Configuration is a good way
> to accomplish this. It is straightforward to do this with existing Log4j APIs:
> {code}
> LoggerContext context = (org.apache.logging.log4j.core.LoggerContext)
> LogManager.getContext(false);
> context.addFilter(ourFilter);
> // when done, call context.removeFilter(ourFilter)
> {code}
> Installing and removing a filter is rare and it is okay to create temporary
> objects when doing this. Once the filter is installed, it should not create
> temporary objects during steady state processing.
> For the filter implementation, something like
> [ThreadContextMapFilter|https://logging.apache.org/log4j/2.x/manual/filters.html#ThreadContextMapFilter]
> is very close to what we need.
> To do:
> * {{ThreadContextMapFilter}} is not garbage-free: it creates a new iterator
> every time the {{filter()}} method is called.
> * Auto-removal of the Filter after some time has passed or some number of
> events have been processed. It may be a useful addition to Log4j to provide a
> {{CompositeFilter}} that automatically removes itself from a
> {{Configuration}} when some condition is satisfied.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
