On Dec 7, 2007, at 1:12 PM, Paul Duffy wrote:
Folks,
Scenario is app running on multi core hardware at high clock rates.
Millisecond time resolution for LoggingEvent is not going to cut
it. Need a monotonically increasing sequence number in the
LoggingEvent to distinguish order for events occurring w/ the same
time stamp. Rather not go through a lot of twisted mumbo jumbo to
accommodate what appears to be a basic feature need. IMO this
sequence number should be set in the ctor along with the timestamp.
Thoughts?
Cheers
The sequence number that was implemented in log4j 1.3 was problematic
on several fronts. In the implementation in the last release, the
same sequence number could be repeated since it wasn't guarded with a
synchronization block. I believe that it was fixed in the SVN, but
didn't make it into a release. Been a couple of years since we went
round and round on it, but search the log4j-dev archives and Bugzilla
for earlier discussions.
There are a slew of things in log4j 1.2 that "don't cut it" for multi-
core hence the desire to develop a log4j 2.0 that uses finer locking
and only targets Java 5 and later. If you were targeting Java 5 and
later, the most obvious approach would be use System.nanoTime, however
log4j 1.2.x targets earlier JVMs.
One of the issues that needs to be considered is that the order of the
logging calls and their order of processing by appenders can be
substantially different since there are intervening synchronization
blocks and being first to wait does not mean that you will be first to
wake up. Using a RewriteAppender would suffer from this since it would
only add its sequence number after the thread may have been blocked
for a substantial time period. If you were to take this approach,
you'd probably do just as well just numbering the entries through a
custom layout or appender.
There have been repeated "bugs" (http://issues.apache.org/bugzilla/show_bug.cgi?id=40303
for example) filed when the timestamp (same would happen even more
so to sequence number) are not monotonically increasing in a log
file. This is due to the potential for reordering between the
creation of LoggingEvent and the eventual processing by the Appenders.
For the big picture:
log4j 2.0 intends to target Java 5 and later and follow modern
concurrency best practices, but currently it is only a concept and
some very early experimental code. While I'd love to flesh out the
framework and energize a team to built it, keeping log4j 1.2 running
and getting log4cxx is taking all my open source cycles at the moment
and nobody seems anxious to work on it.
log4j 1.3 is dead. It didn't address key concurrency issues and
wasn't binary compatible with log4j 1.2.
log4j 1.2 is in maintenance and many users are many versions back. It
is more effective to add a new feature in an companion so that users
who are running log4j 1.2.8 or so because that is hard wired into
their app server can have the new feature. Sequence number would
likely need to be done in the core log4j and would need changes to
LoggingEvent, the layouts, SocketAppender, database appenders,
corresponding changes to Chainsaw to be as ubiquitous as timeStamp. A
pretty big set of changes to work into the tail end of series and
would only benefit those who could upgrade to 1.2.17 or so. Would
still suffer from the cosmetic reordering problem from Bug 40303.
Anything done on log4j 1.2 would then force log4j 2.0 to follow, so it
would be much better to spend that effort on log4j 2.0 and do it right.
You seem to have an immediate need and adding sequenceNumber or any
alternative finely grained alternative isn't going to happen quickly
enough to be useful to you. Your have a couple of options that will
work depending on your priorities. If you are trying to follow the
order of logging calls and are understand that order in log files
might be ordered slightly differently, then you could pass a custom
message object instead of a string that captured a sequence number or
nano time at its construction, something that resolves to:
logger.info(new MyMessage("Hello, World"));
You could either then have its .toString() message include the
sequence number or use a custom layout that understands your object
and can extract the sequence number or nanoTime. You'd likely want to
avoid creating your message object when the level was disabled, you
can see an example of using a static helper class to create custom
message objects in the LogMF class (http://svn.apache.org/repos/asf/logging/log4j/companions/extras/trunk/src/main/java/org/apache/log4j/LogMF.java
) in the extras. Something like:
MyHelper.info(logger, "Hello, World");
that resolves to:
void info(final Logger logger, Object msg) {
if (logger.isInfoEnabled()) {
forcedLog(logger, Level.INFO, new MyMessage(msg));
}
}
If just want to document the order of processing by the appender, then
a custom layout would work.
---------------------------------------------------------------------
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]
