Log4j - dealing with multithreaded invocations?

java-programmer, Log4j - dealing with multithreaded invocations? Hi,

I have a class with 4 methods. I want to use Log4j to log messages for
each of these methods to a common log file.

Ideally I would like the log messages for each method to be seperated
from the others. But if multiple users were to invoke the methods at
the same time, then the messages in my log file would be jumbled up
with the others.

I can probably try making the methods synchronized so i dont get into
this sort of trouble, but logging by itself doesn't seem to be a good
enough reason to be making methods synchronized.

What approach can I use to deal with this?

Thank you,
Rohit.

java-programmer >> Log4j - dealing with multithreaded invocations? email***@***.com wrote:
> Hi,
>
> I have a class with 4 methods. I want to use Log4j to log messages for
> each of these methods to a common log file.
>
> Ideally I would like the log messages for each method to be seperated
> from the others. But if multiple users were to invoke the methods at
> the same time, then the messages in my log file would be jumbled up
> with the others.
>
> I can probably try making the methods synchronized so i dont get into
> this sort of trouble, but logging by itself doesn't seem to be a good
> enough reason to be making methods synchronized.
>
> What approach can I use to deal with this?
>
> Thank you,
> Rohit.
>

How about having the username and the method name as part of the log
message, and then filter the log file by user or by method name or by
anything else... you can even write a small program that reads the log
file and filter it to your liking.

HTH

java-programmer >> Log4j - dealing with multithreaded invocations? Hi,

I do have the username and method name as part of the log message, but
then imagine within each method call, the log looks like this:

username: john method: a()
aaaaaaaaaaaaa
aaaaaaaaaaaaa
end:a()

if someone else invokes b() it should look like this:

username: peter method: b()
bbbbbbbbbbbbbbb
bbbbbbbbbbbbbbb
end:b()

This still doesnt solve my problem, because if I'm writing to a single
file it may come out like this:

username: john method: a()
aaaaaaaaaaaaa
username: peter method: b()
bbbbbbbbbbbbbbb
aaaaaaaaaaaaa
bbbbbbbbbbbbbbb
end:b()
end:a()

java-programmer >> Log4j - dealing with multithreaded invocations? Hi,

I dont think that would solve my problem. Imagine the logging within my
methods looked like this:

method: a() user: john
sometext
sometext
end: a()

if at the same time, someone else invoked a method b(), since they both
end up writing to a common log file - my log may end up looking like
this:

method: a() user: john
sometext
sometext
method: a() user: john
sometext
sometext
end: b()
end: a()

Then i wont be able to differentiate if "sometext" comes from the call
to a() or that to b()..

java-programmer >> Log4j - dealing with multithreaded invocations? Sorry for the multiple posts. IE's giving me trouble.

----------------------------------------------------------------------------

Hi,

I dont think that would solve my problem. Imagine the logging within my
methods looked like this:

method: a() user: john
sometext
sometext
end: a()

if at the same time, someone else invoked a method b(), since they both
end up writing to a common log file - my log may end up looking like
this:

method: a() user: john
sometext
sometext
method: b() user: peter
sometext
sometext
end: b()
end: a()

Then i wont be able to differentiate if "sometext" comes from the call
to a() or that to b()..

java-programmer >> Log4j - dealing with multithreaded invocations? email***@***.com wrote:
> Sorry for the multiple posts. IE's giving me trouble.
>
> ----------------------------------------------------------------------------
>
> Hi,
>
> I dont think that would solve my problem. Imagine the logging within my
> methods looked like this:
>
> method: a() user: john
> sometext
> sometext
> end: a()
>
> if at the same time, someone else invoked a method b(), since they both
> end up writing to a common log file - my log may end up looking like
> this:
>
> method: a() user: john
> sometext
> sometext
> method: b() user: peter
> sometext
> sometext
> end: b()
> end: a()
>
> Then i wont be able to differentiate if "sometext" comes from the call
> to a() or that to b()..
>

how about doing it this way:

method: a() user: john begin
method: a() user: john sometext
method: a() user: john sometext
method: a() user: john end

this way, if the two users called the same method at the same time, you
will still be able to filter them and see what you want.
the only other option i can think of is to synchronize the methods,
which you already mentioned you wanted to avoid.
HTH

java-programmer >> Log4j - dealing with multithreaded invocations? email***@***.com wrote:

> Hi,
>
> I do have the username and method name as part of the log message, but
> then imagine within each method call, the log looks like this:
>
> username: john method: a()
> aaaaaaaaaaaaa
> aaaaaaaaaaaaa
> end:a()
>
> if someone else invokes b() it should look like this:
>
> username: peter method: b()
> bbbbbbbbbbbbbbb
> bbbbbbbbbbbbbbb
> end:b()
>
> This still doesnt solve my problem, because if I'm writing to a single
> file it may come out like this:
>
> username: john method: a()
> aaaaaaaaaaaaa
> username: peter method: b()
> bbbbbbbbbbbbbbb
> aaaaaaaaaaaaa
> bbbbbbbbbbbbbbb
> end:b()
> end:a()

If you insist on logging all the information to the same file this is bound to
happen; it's a fact of life. It leaves you with two alternatives. One, you
synchronize the methods, which slows everything down. Two, you include in every
log message an identifier which allows you to post-filter the log file to get
just the output you want.

As a very trivial example, if you append a string including the thread id in
every message all you need do is filter for that string to see messages from
that thread:

username: john method: a() // thread A
aaaaaaaaaaaaa // thread A
username: peter method: b() // thread B
bbbbbbbbbbbbbbb // thread B
aaaaaaaaaaaaa // thread A
bbbbbbbbbbbbbbb // thread B
end:b() // thread B
end:a() // thread A

To see the output from thread B filter the log file to just show lines which end
in the string "// thread B".

Your log file contains a time sequence of events, which is good, but you can
alter your view of that log file to suit your requirements. In the UNIX world
you could use grep, or one of its close friends. In the Windows world I'm sure
there is some equivalent.

--
Nigel Wade, System Administrator, Space Plasma Physics Group,
University of Leicester, Leicester, LE1 7RH, UK
E-mail : email***@***.com
Phone : +44 (0)116 2523548, Fax : +44 (0)116 2523555

java-programmer >> Log4j - dealing with multithreaded invocations? email***@***.com wrote:
> Hi,
>
> I have a class with 4 methods. I want to use Log4j to log messages for
> each of these methods to a common log file.
>
> Ideally I would like the log messages for each method to be seperated
> from the others. But if multiple users were to invoke the methods at
> the same time, then the messages in my log file would be jumbled up
> with the others.
>
> I can probably try making the methods synchronized so i dont get into
> this sort of trouble, but logging by itself doesn't seem to be a good
> enough reason to be making methods synchronized.
>
> What approach can I use to deal with this?
>

Rohit,

FYI, almost all of the suggestions I've seen in this thread (add
timestamp to log, add thread id to log, add method name to log) are
achievable via log4j configuration. I.e., you do not need to change
your code. For the username thing, you may want to use NDC (nested
diagnostic context), which requires minimal code changes.

If you need to know more, I suggest you contact the log4j users list.
(I think it is email***@***.com and you should subscribe
first. Check on http://logging.apache.org to be sure.)

HTH,
Ray

--
This signature intentionally left blank.

java-programmer >> Log4j - dealing with multithreaded invocations? Thanks for the replies. Looks like adding some sort of an identifier to
the log might be the way to go. This will eventually run on unix, so
i'll probably have awk/grep to sort the file for me.

Ray, thanks for the tip. I'll dig in a little more into log4j to see
what it can do and check out the log4j users list too.

- Rohit.

java-programmer >> Log4j - dealing with multithreaded invocations? Checkout

http://logging.apache.org/log4j/docs/chainsaw.html.

It's a companion program to Log4j that handles filtering and a lot
more. It's a much more flexible option than grep and the like.

- MattC

java-programmer >> Log4j - dealing with multithreaded invocations?
<email***@***.com> wrote in message
news:email***@***.com...
> Hi,
>
> I do have the username and method name as part of the log message, but
> then imagine within each method call, the log looks like this:
>
> username: john method: a()
> aaaaaaaaaaaaa
> aaaaaaaaaaaaa
> end:a()
>
> if someone else invokes b() it should look like this:
>
> username: peter method: b()
> bbbbbbbbbbbbbbb
> bbbbbbbbbbbbbbb
> end:b()
>
> This still doesnt solve my problem, because if I'm writing to a single
> file it may come out like this:
>
> username: john method: a()
> aaaaaaaaaaaaa
> username: peter method: b()
> bbbbbbbbbbbbbbb
> aaaaaaaaaaaaa
> bbbbbbbbbbbbbbb
> end:b()
> end:a()

You need to define what the atomic logging actions are. It sounds like
you don't want the stuff between "username:" and "end:" to get interrupted,
so consider this your atomic unit of a single log entry.

Write your own custom log handlers to receive the logging events and
buffer them. Then have the handler, upon receiving the end of an entry,
acquire a synchronization lock on the file to write to, and then empty its
buffer into the file. So the sequence of events will look like this:

yourCode.sentToHandler("john", "method: a()");
yourCode.sentToHandler("john", "aaaaaaaaaaaaa");
yourCode.sentToHandler("peter", "method: b()");
yourCode.sentToHandler("peter", "bbbbbbbbbbbbbbb");
yourCode.sentToHandler("john", "aaaaaaaaaaaaa");
yourCode.sentToHandler("peter", "bbbbbbbbbbbbbbb");
yourCode.sentToHandler("peter", "end:b()");
handler.locks(logFile);
handler.writes(logFile, "username: peter method: b()");
handler.writes(logFile, "bbbbbbbbbbbbbbb");
yourCode.sentToHandler("john", "end:a()");
handler.writes(logFile, "bbbbbbbbbbbbbbb");
handler.writes(logFile, "end:b()");
handler.releases(logFile);
handler.locks(logFile);
handler.writes(logFile, "username: john method: a()");
handler.writes(logFile, "aaaaaaaaaaaaa");
handler.writes(logFile, "aaaaaaaaaaaaa");
handler.writes(logFile, "end:a()");
handler.releases(logFile);

- Oliver

java-programmer >> Log4j - dealing with multithreaded invocations? Oliver,

I never thought of that approach. That sounds really good. Let me see
how i can put it together.

Thanks
Rohit.