logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Remko Popma (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (LOG4J2-1342) ReusableParameterizedMessage should preserve parameters when used with Async Loggers
Date Tue, 19 Apr 2016 06:19:25 GMT

     [ https://issues.apache.org/jira/browse/LOG4J2-1342?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Remko Popma updated LOG4J2-1342:
--------------------------------
    Description: 
*Problem*
Some layouts (like CsvParameterLayout) need access to the message parameters. With the current
garbage-free asynchronous logging implementation the formatted message text is passed correctly,
but parameter information is no longer passed on.

*Analysis*
ReusableParameterizedMessage instances are mutable by design and their contents may be overwritten
with the next call to {{Logger.log}}.

For synchronous logging this is not an issue since the message contents will have been fully
processed by the appenders before this happens.

With asynchronous logging, the log event and its contents need to be handed off to the background
thread, and we need to ensure that this data is not modified by another call to {{Logger.log}}
before the background thread can process it. Different async logging mechanisms handle this
in different ways:

*Async Appender*
This appender takes a snapshot of the LogEvent before enqueueing it. This is implemented by
invoking {{Log4jLogEvent.serialize(LogEvent)}}. The Message contents is turned into text with
{{Message.getFormattedString()}} and a new {{SimpleMessage}} is created with this text. In
the process, any parameters of the original message are lost.

This mechanism does not try to be garbage-free, so one solution would be to add a method {{createMemento()
: Message}} to ReusableMessage. ReusableParameterizedMessage could implement this to copy
the parameter values into the memento copy.

*All Loggers Async*
This has a ring buffer with pre-allocated RingBufferLogEvent objects. Values are copied into
these RingBufferLogEvents for each call to {{Logger.log}}. If the message is a ReusableMessage,
RingBufferLogEvent will call {{message.formatTo(StringBuilder}} to copy the formatted message
text to a StringBuilder held by the the RingBufferLogEvent. This only copies the formatted
text, any parameters of the original message are lost.

Potential solution: RingBufferLogEvent could have an Object[] array field to hold parameters.
When the RingBufferLogEvent is populated, the ReusableMessage could swap its parameter array
with the RingBufferLogEvent's parameter array.

There needs to be a method in ReusableMessage to allow this swap.

Consideration: when RingBufferLogEvent.clear() is called, the array elements need to be nulled
out to prevent memory leaks.

*Mixed Sync/Async Loggers*
This has a ring buffer with pre-allocated Log4jEventWrapper objects. In classic mode, when
{{Logger.log}} is called a new Log4jLogEvent is created and set in the Log4jEventWrapper.
In garbage-free mode, the Log4jEventWrapper is pre-allocated with MutableLogEvent objects
and the values from the {{Logger.log}} call are copied into the ringbuffer's MutableLogEvent.
In that case we have the same problem as with _All Loggers Async_: If the message is a ReusableMessage,
RingBufferLogEvent will call {{message.formatTo(StringBuilder}} to copy the formatted message
text to a StringBuilder held by the the RingBufferLogEvent. This only copies the formatted
text, any parameters of the original message are lost.

  was:
AsyncLogger correctly copies the contents of ReusableParameterizedMessages rather than the
instance itself when passing the message to the background thread. 

However the copy in incomplete: the formatted text is copied into the RingbufferLogEvent but
message parameters are not transferred. 

This is a problem because some layouts like CsvParameterLayout need access to the raw parameters.


> ReusableParameterizedMessage should preserve parameters when used with Async Loggers
> ------------------------------------------------------------------------------------
>
>                 Key: LOG4J2-1342
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-1342
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: API
>    Affects Versions: 2.6
>            Reporter: Remko Popma
>            Assignee: Remko Popma
>             Fix For: 2.6
>
>
> *Problem*
> Some layouts (like CsvParameterLayout) need access to the message parameters. With the
current garbage-free asynchronous logging implementation the formatted message text is passed
correctly, but parameter information is no longer passed on.
> *Analysis*
> ReusableParameterizedMessage instances are mutable by design and their contents may be
overwritten with the next call to {{Logger.log}}.
> For synchronous logging this is not an issue since the message contents will have been
fully processed by the appenders before this happens.
> With asynchronous logging, the log event and its contents need to be handed off to the
background thread, and we need to ensure that this data is not modified by another call to
{{Logger.log}} before the background thread can process it. Different async logging mechanisms
handle this in different ways:
> *Async Appender*
> This appender takes a snapshot of the LogEvent before enqueueing it. This is implemented
by invoking {{Log4jLogEvent.serialize(LogEvent)}}. The Message contents is turned into text
with {{Message.getFormattedString()}} and a new {{SimpleMessage}} is created with this text.
In the process, any parameters of the original message are lost.
> This mechanism does not try to be garbage-free, so one solution would be to add a method
{{createMemento() : Message}} to ReusableMessage. ReusableParameterizedMessage could implement
this to copy the parameter values into the memento copy.
> *All Loggers Async*
> This has a ring buffer with pre-allocated RingBufferLogEvent objects. Values are copied
into these RingBufferLogEvents for each call to {{Logger.log}}. If the message is a ReusableMessage,
RingBufferLogEvent will call {{message.formatTo(StringBuilder}} to copy the formatted message
text to a StringBuilder held by the the RingBufferLogEvent. This only copies the formatted
text, any parameters of the original message are lost.
> Potential solution: RingBufferLogEvent could have an Object[] array field to hold parameters.
When the RingBufferLogEvent is populated, the ReusableMessage could swap its parameter array
with the RingBufferLogEvent's parameter array.
> There needs to be a method in ReusableMessage to allow this swap.
> Consideration: when RingBufferLogEvent.clear() is called, the array elements need to
be nulled out to prevent memory leaks.
> *Mixed Sync/Async Loggers*
> This has a ring buffer with pre-allocated Log4jEventWrapper objects. In classic mode,
when {{Logger.log}} is called a new Log4jLogEvent is created and set in the Log4jEventWrapper.
In garbage-free mode, the Log4jEventWrapper is pre-allocated with MutableLogEvent objects
and the values from the {{Logger.log}} call are copied into the ringbuffer's MutableLogEvent.
In that case we have the same problem as with _All Loggers Async_: If the message is a ReusableMessage,
RingBufferLogEvent will call {{message.formatTo(StringBuilder}} to copy the formatted message
text to a StringBuilder held by the the RingBufferLogEvent. This only copies the formatted
text, any parameters of the original message are lost.



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Mime
View raw message