You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-dev@logging.apache.org by Ceki Gülcü <ce...@qos.ch> on 2005/01/31 22:11:36 UTC
Sequence count, WAS: Why concurrency?
At 09:51 PM 1/31/2005, Curt Arnold wrote:
>>>Sorry, "getSequenceCount" was a short-hand reference to a fairly
>>>involved thread about a month ago. A sequence number is currently
>>>being used as a logging event identifier, but there are likely better
>>>ways of meeting the actual requirements. The thread is pretty long and
>>>convoluted, most of it was trying to figure out what the actual
>>>requirements were. Having a monotonically increasing message sequence
>>>number wasn't one of them. Having an implementation of equals and
>>>hasCode were requirements (from the Chainsaw team).
>>
>>I don't see why the Chainsaw team is causing grief for you. If their
>>particular application requires "equals" and "hashCode", they can
>>implement their own wrappers as appropriate for logging events.
>>
>>It appears their requirements are negatively impacting the base
>>architecture of log4j. I'm sure there is a reasonable compromise to be
>>made.
>
>At this point, they have expressed their preference to have equals and
>hashCode with value semantics and have code that depends its presence.
>At this point, I do not have compelling evidence that it is a bad thing
>and its best to proceed under the assumption that they knew their
>requirements. Adding wrappers to Chainsaw would cause an increase in
>total complexity by removing some complexity from the log4j core but
>adding more in Chainsaw.
Independently of Chainsaw's requirements, adding equals and hashCode to
LoggingEvent is a good thing because equals/hashCode also make writing
log4j test cases easier.
The fact that sequenceCount was introduced as a helper data field for the
equals and hashCode methods was *my* choice of optimization. With
hindsight, we can all agree that it was a poor optimization. Future
implementations of equals and hashCode may not rely on sequenceCount (or
eventId) as heavily.
Recently, I stumbled upon an interesting use case for sequenceCount. When
the AsynAppender buffer is full and a event is processed, one of the
waiting threads is notified that a slot became available. The order in
which threads are notified is not specified by the Java language. They can
be notified more or less in random order.
Consequently, events may be output out of order by AsynAppender. Sequence
count can help the user to order the output.
The above should be viewed as a marginally important use case for
sequenceCount, but a use case it is nonetheless.
--
Ceki Gülcü
The complete log4j manual: http://www.qos.ch/log4j/
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org
Re: Sequence count, WAS: Why concurrency?
Posted by Elias Ross <er...@m-qube.com>.
On Mon, 2005-01-31 at 16:27, Curt Arnold wrote:
> and these messages were dispatched to two distinct appenders (possibly
> of different types) and that one instance of Chainsaw was listening to
> both, it could determine that which logging events came from the same
> iteration of the loop.
An assign sequence number method could first check if a sequence number
was already assigned:
class LoggingEvent ... {
public synchronized void assignNewSequenceNumber(long count) {
if (this.sequenceNumber != 0)
return;
this.sequenceNumber = count;
}
}
class ChainsawAppender {
long seq = 0;
public synchronized void doAppend(LoggingEvent le) {
le.assignSequenceNumber(seq++);
}
}
Or:
class LoggingEvent ... {
static long count;
private synchronized void writeObject() {
if (this.sequenceNumber == 0) {
synchronized (LoggingEvent.class) {
this.sequenceNumber = count++;
}
}
}
}
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org
Re: Sequence count, WAS: Why concurrency?
Posted by Curt Arnold <ca...@apache.org>.
On Jan 31, 2005, at 5:19 PM, Elias Ross wrote:
> On Mon, 2005-01-31 at 14:53, Curt Arnold wrote:
>
>> So I think that users
>> will just have to accept that messages in the log from a multithreaded
>> application may appear in a slightly different sequence than the
>> requests were made.
>
> Which is sort of the reasoning behind having the appender generate the
> sequence number -- not the class itself. Then, you be sure that events
> appearing in a file would appear in the correct order. This would be
> part of the contract for Appender.doAppend.
>
> For appenders that don't have any reason to generate the sequence
> number
> (WriterAppender, et all.) you don't generate one. ChainsawAppender and
> SocketAppender would create one.
>
If you go back to the earlier thread on sequence number when I was
trying to find out the motivation behind it, I speculated that it might
have been added to allow detection of dropped messages. If that had
been the case, then an appender based sequence number might have been a
reasonable approach. However that was not the motivation. The
motivation was to have some sort of object ID so you could tell the
difference between two serialized forms of logging events that were
identical in all aspects (message, timestamp, etc) except arose from
distinct requests. For example, if I had a very tight loop like
(assuming each iteration) takes less than 1 ms:
for (int i = 0; i < 10; i++) {
logger.debug("Hello, world");
}
and these messages were dispatched to two distinct appenders (possibly
of different types) and that one instance of Chainsaw was listening to
both, it could determine that which logging events came from the same
iteration of the loop.
Even if the sequenceCount was done on the appender level, it still does
not solve the sequence indeterminacy issue since there would need to be
a synchronization block on its sequenceCount which could still result
in the first request to block on the lock possibly not being the first
to acquire the lock when it becomes available.
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org
Re: Sequence count, WAS: Why concurrency?
Posted by Elias Ross <er...@m-qube.com>.
On Mon, 2005-01-31 at 14:53, Curt Arnold wrote:
> So I think that users
> will just have to accept that messages in the log from a multithreaded
> application may appear in a slightly different sequence than the
> requests were made.
Which is sort of the reasoning behind having the appender generate the
sequence number -- not the class itself. Then, you be sure that events
appearing in a file would appear in the correct order. This would be
part of the contract for Appender.doAppend.
For appenders that don't have any reason to generate the sequence number
(WriterAppender, et all.) you don't generate one. ChainsawAppender and
SocketAppender would create one.
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org
Re: Sequence count, WAS: Why concurrency?
Posted by Curt Arnold <ca...@apache.org>.
On Jan 31, 2005, at 3:11 PM, Ceki Gülcü wrote:
> At 09:51 PM 1/31/2005, Curt Arnold wrote:
> Recently, I stumbled upon an interesting use case for sequenceCount.
> When the AsynAppender buffer is full and a event is processed, one of
> the waiting threads is notified that a slot became available. The
> order in which threads are notified is not specified by the Java
> language. They can be notified more or less in random order.
>
> Consequently, events may be output out of order by AsynAppender.
> Sequence count can help the user to order the output.
>
> The above should be viewed as a marginally important use case for
> sequenceCount, but a use case it is nonetheless.
>
I think the scenario described would affect any appender that needs to
synchronize a shared resource (like the event queue, socket, file etc)
which would include almost all appenders. In the case of an asych
appender, there would be an opportunity to reorder events into request
time instead of dispatch time while in the queue, however you would not
have that opportunity with say a SocketAppender. So I think that users
will just have to accept that messages in the log from a multithreaded
application may appear in a slightly different sequence than the
requests were made.
Then the question becomes what to do if the millisecond timestamp is
not sufficiently precise for the analytical need. Use of a
high-performance timer (like System.nanoTime) might be a better
solution than getSequenceCount. However, if you really need to know
the precise timeline of a multithreaded app, it might be something that
you might have to handle in the calling application. Even without a
synchronization issue, it would be possible for two nearly simultaneous
calls to logger.debug to have the LoggingEvent constructor (where the
timestamp is determined) in a different order since the cost of walking
the tree may vary and the thread priorities may be different.
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org
Re: Sequence count, WAS: Why concurrency?
Posted by Endre Stølsvik <En...@Stolsvik.com>.
|
| Recently, I stumbled upon an interesting use case for sequenceCount. When
| the AsynAppender buffer is full and a event is processed, one of the
| waiting threads is notified that a slot became available. The order in
| which threads are notified is not specified by the Java language. They can
| be notified more or less in random order.
|
| Consequently, events may be output out of order by AsynAppender. Sequence
| count can help the user to order the output.
|
| The above should be viewed as a marginally important use case for
| sequenceCount, but a use case it is nonetheless.
This should be done with a "waiting list" pattern, rather than relying on
this specific "feature" of the actual LoggingEvent. I feel this rather
clearly points out the high synchronization that obviously must have gone
into the sequenceCount when it later can be used to order the actual
output of the LoggingEvents.
Endre
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org