Java Forum / General / July 2006
Looking for a Multi-Layer "Architecture" pattern for Log4J
etienno@gmail.com - 11 Jul 2006 09:55 GMT Hi,
I have a issu to solve regarding Log4J (or any other logger). This problem is probably quite common in a multi-layer architecture. I have a multilayer software, running on the same JVM (not really multilayer here thaugh, anyway).
Lets say my layers are : View (HttpRequest), Business, Delegates, web service...
The problem is that the logger from the View knows well the "UserId" using the system, but from the Business to the Web Service Layers it lost the "UserId" data because it doesn't need it for its process. But I would like the logger at the Web Service Layer to log a debug trace with the "UserId"! A need that because my system admin need a nice log to do his job efficiently.
View (HttpRequest), [doJob(UserId);] Business, [doJob()] Delegates, [doJob()] web service... [doJob()] -->logger.debug("My userId is..." + "doing web service job");
I have checked many possibility, I want to know what would be the best pattern for this issu:
1- Pass the UserId in the parameter: This is obviouly bad. --- theses next solutions has not be thinked a lot... 2- Put the a kind of ThreadId as a key in a static Map and store UserData...: I dont like that at first glance. 3- Use some listener and Event handling to get the logs events from the lower layer and log it from the upper layer. Use ThreadId as a key of some sort. I prefer that...
It must be a very common problem. There is not common library for this issue? I will check at TheServerSide.com...
Thanks for answering
Etienne Paris
pranshu - 11 Jul 2006 10:32 GMT Ho Etienne,
The least you have to do is to change the method signatures to pass a GUID or some other unique key down from the web layer to subsequent layers. This way, you can associate different log outputs for the same request - by logging and searching for the unique key. Of course you will still need to do a lot of work while analysing the logs as the lines will be spread across different log files in different machines ( if you chose to distribute it) and you will need to do a find/grep across files to create a complete flow.
I would love to see a good implementation for the same - If anyone finds one.
Pranshu
etienno@gmail.com - 11 Jul 2006 10:43 GMT Thanks Pranshu,
I agree with you, this would be the logical way to do it. But I tend to say that the logging requirement is the not a real business requirement, it should not affect the signature of all methods. In a AOP way of looking at it, it is a transversal requirement that do not affect the "base" application behavior. So I think it would be an anti-pattern to pass the UID in all method signature in a _logical_ multi-layer environement.
I agree also that in a (physical) distributed environment this solution (pass the GUID) could be the only way to do resolve the problem.
Etienne.
wrote:
> Ho Etienne, > [quoted text clipped - 12 lines] > > Pranshu etienno@gmail.com - 11 Jul 2006 10:46 GMT I have ask and rephrase a bit this question at The Server Side:
http://www.theserverside.com/discussions/thread.tss?thread_id=41277
Brandon McCombs - 12 Jul 2006 06:35 GMT > Thanks Pranshu, > > I agree with you, this would be the logical way to do it. But I tend to > say that the logging requirement is the not a real business > requirement, it should not affect the signature of all methods. Remember that Microsoft also put logging (read security) as a sub-business requirement and look where it got them.
Chris Uppal - 11 Jul 2006 12:06 GMT > The problem is that the logger from the View knows well the "UserId" > using the system, but from the Business to the Web Service Layers it [quoted text clipped - 8 lines] > web service... [doJob()] -->logger.debug("My userId is..." + "doing web > service job"); If you pass some sort of object from the top of the stack to the bottom, then each layer can use only the data from that object which it needs, and will be unaware of (and thus decoupled from) the other data which it doesn't need.
Such an object might contain a complete description of the job -- thus replacing all other parameters to the invocation methods at each layer. Or it might only contain some sort of description of the job intended primarily for logging purposes.
BTW, it's a mistake, IMO, to think of logging as "not a real business requirement". Try removing the logging and see what happens to the business ;-)
-- chris
etienno@gmail.com - 11 Jul 2006 12:20 GMT Thanks Chris,
here I must also disagree, I think that if we remove the logging, the application (might) still run. The transaction are not affected, the security, the business or persistence functional requirement neither.
So, I still do not think we must design an application and the method signature according to the logging functionality (non-functional requirement). This is one reason it is a good practice not to pass the Log4J logger in the method fields. Classically, the logger instance is a (static) local field of the class using it.
Also, in a IOC or AOP way of saying it (i.e. Spring Framework), we would inject a logger (interface) inside the class, or even do the logging outside the methods using Aspects. This is why in my sens the logging is not part of the business requirements.
Regards,
Etienne
> > The problem is that the logger from the View knows well the "UserId" > > using the system, but from the Business to the Web Service Layers it [quoted text clipped - 23 lines] > > -- chris Chris Uppal - 11 Jul 2006 12:46 GMT > here I must also disagree, I think that if we remove the logging, the > application (might) still run. The transaction are not affected, the > security, the business or persistence functional requirement neither. Well, if logging's not a business requirement, why the Hell are you wasting time implementing it ?
;-)
But, OK yes, I have some sympathy with the idea that it's not a /domain/ requirement.
Anyway, my real point is that you can pass a /job/ or /job description/ from top to bottom of the stack without messing up your domain code. That object can contain logging-specific information, just as it can (and would) contain other information -- it's up to each layer what information it adds to the object and what information it takes out.
-- chris
etienno@gmail.com - 11 Jul 2006 12:55 GMT So, we agree a bit. Logging is not part of the "domain requirement" (or domain model). I think that I could build a "logging" API that would be able to use peripherical way (outside the domain model) to do thisfeature. This logging API (implementing Logger, or the Log4J logger) would be transparent to the system.
I am looking to use ThreadLocal to store the UserData (one per thread), the UserData would be available by the loggers at the lower levels. If I do not use a Web Application, I just hope the thread die at the end of the process (the chain of command).
Regards,
Etienne
> > here I must also disagree, I think that if we remove the logging, the > > application (might) still run. The transaction are not affected, the [quoted text clipped - 15 lines] > > -- chris pranshu - 11 Jul 2006 14:48 GMT Hello Etienne
I have looked at logging variants and even custom code available, and none of them seem to solve the problem of relating messages from different threads or different machines - leaving it the responsibility of the application to provide the "association".
Some of the variant implementations - have solved it for the same JVM - by registering event listeners and invoking events. However the application has been essentially designed that way, and I think passing a GUID is easier and will work across JVMs.
Are you using a particular AOP implementaiton?
This was the first article on googling for AspectJ + Log4J http://www.developer.com/java/other/article.php/10936_3109831_1
- I must put a disclaimer that I dont understand it fully before commenting further -
It looks like even with aspects if you are crossing multiple levels, the least you need to change in your code is to introduce new instance variables across all objects to store the Association ID. The aspects might just be able to copy it over from caller to calee object. The reason I say might is because, I dont know if it will work and its definitely not going to work when you call static methods.
I would definitely love to see this thread reach a conclusion.
Pranshu
pranshu - 11 Jul 2006 15:22 GMT Looking at the options you have proposed:
Using Threadid to sort: It may not work if you have more than 1 log levels. Lets say you log the UserID as a "INFO" or "DEBUG" level in the web layer. And you have the log level set to "ERROR" for a production deployment. Now, in this case, if there is an error in an inner layer, and you get an ERROR log, you will never be able to associate it with a User ID as the useid is never logged (being INFO) and the association / thread id is not going to help. :-(
Among other implementations that you have mentioned - using a Static map - will take a lot of work to make it work across JVMs. - Use some sort of listener and Event handling - will be very difficult to work across JVMs.
Looks like there is no viable solution at all apart from the "bad" option 1- to Pass the UserId/user object in the parameter!!
etienno@gmail.com - 11 Jul 2006 16:34 GMT Hi, thanks all for your replies,
One of the option I forgot to mention is using the ThreadLocal to store the UserData. The TreadLocal is unique for all Thread.
Hibernate is using this "pattern" (named OpenSessionInView) to open a HibernateSession in the "View layer" and to Close it in the View Layer. See at http://www.hibernate.org/hib_docs/reference/en/html/quickstart.html for more detail.
Spring use AOP (HibernateInterceptor) and/or an wrapped implementation of OpenSessionInView to do the same work : see http://www.springframework.org/docs/api/org/springframework/orm/hibernate/suppor t/OpenSessionInViewFilter.html for the latter implementation.
As I see it now, the simple thing to do, when I build a Web App, is to create a "LoggerFilter" as a ServletFilter associated to all Servlets. The job of the LoggerFilter is to add a UserData instance (took from the HttpSession, HttpRequest or elsewhere, DataBase, etc) in a ThreadLocal instance/object. All logger new implementation (overiding the Factory.getLogger(...)) will read the UserData in the ThreadLocal and be able to get back the UserId and write it down without having to read it from the method fields.
In a Java App, I would be force to look at the Spring AOP (Interceptor) and use the same pattern they use with the HibernateSession to manage the UserData.
But at first glance this should only work very well when there is a singe thread per "use case" like in a WebServer environment. Per example, some says that if you use some ThreadPooling in your apps, you might get some problem getting the ThreadLocal... But I am pretty sure that Spring AOP have resolved this problem.
any other idea?
Etienne.
Remco Rotteveel - 11 Jul 2006 17:12 GMT > I have a issu to solve regarding Log4J (or any other logger). This > problem is probably quite common in a multi-layer architecture. I have > a multilayer software, running on the same JVM (not really multilayer > here thaugh, anyway). Have you looked at log4j's NDC/MDC (Nested/Mapped Diagnostic Context)? When each request is handled by one thread, this is probably the way to go (it's probably implemented using ThreadLocal). The business layer can add the user ID to the NDC/MDC and when the web service layer logs a message, the user ID is available to be added to the message, i.e. you can add the (entire) NDC or specific MDC elements to the conversion pattern in your log4j configuration (%x / %X{userId} respectively).
 Signature Regards, Remco.
Ed - 12 Jul 2006 10:09 GMT etienno@gmail.com skrev:
> Hi,
> The problem is that the logger from the View knows well the "UserId" > using the system, but from the Business to the Web Service Layers it > lost the "UserId" data because it doesn't need it for its process. But > I would like the logger at the Web Service Layer to log a debug trace > with the "UserId"! A need that because my system admin need a nice log > to do his job efficiently. (Please forgive if this is double-posted; I posted this yesterday but it didn't show up; think I've, "Destructively reconfigured," my poor newsreader now ...)
I don't know of any Agreed-Upon way of doing this, but when dealing with web-accessed systems (as you seem to be) I usually pass one object to all major parts of the system: an encapsulation of the access itself, as shallow an object as possible than can distinguish this access from all others.
This is just a higher abstraction than passing a UserId everywhere, but I think the abstraction is not at odds a web-accessed system: surely, the system does nothing without being accessed (ignoring timer-expirations, though these, too, could be abstracted to a system access), and so it won't be a pollution of your layers to see some form of access. This access could hold a log that loads the access-specific data (sure as user ID) as header to the real logger to which it delegates, all encapsulated away from the layers that see the access itself.
I think this is better than an artificial mapping between layer-specific entities and an underlying user ID (or access itself); certainly using ThreadIds as keys sound like bring concurrency into your session-identification scheme, which will imply impacts on session identities when you concurrency model changes: don't do that.
As a distant, distant example (as this program is much smaller than yours, and hence much, "Closer," to the access, so the access-encapsulation is much fatter then you need) see the ServletAccess class in the following link, and note that its interface - AccessTechnology, which identifies a specific system access - is also shared with the NormalAccess which encapsulates Swing button accesses of the same system but started as a stand-alone, not a servlet; in other words, the core of your system doesn't have to depend on any particular technology used to make the access, but it does depend on being accessed somehow. http://www.edmundkirwan.com/servlet/fractal/cs1/frac-cs40.html
.ed
-- www.EdmundKirwan.com - Home of The Fractal Class Composition.
Download Fractality, free Java code analyzer: www.EdmundKirwan.com/servlet/fractal/frac-page130.html
etienno@gmail.com - 14 Jul 2006 07:51 GMT Hi,
Thanks all for your replies, they were very instructing, I have learned a lot from each of theses posts. I think this discussion is not over anyway.
Thanks for the guy that point to my attention Log4J MDC/NDC.
Weighting the pro/con of every way of doing it, I will check for the Log4J-MDC way.
I also discovered that some of my cie applications are already using MDC. But I will still need to read a bit more on it. Another point in favor of MDC is that I have used this pattern, the ThreadLocal pattern, for the Hibernate Session in some of my web site, and I never notice any issue using it. I know that this is a way of being couple on the thread model of the AppServer. This is a risk I can deal with it, hoping the risk will be minimal. "It is only the logs!", I think. The problem could easily be isolated and repared by some last minute refactoring and tweaking...
I still think that logging should be a transversal of the application; it should be understand as an Aspect of the application. Therefore It should not affect the domain model or the method signature of the _whole_ application.
And particularly in a client/server application, where the client request interacts with many layer of business, I guess it is feasible to isolate each "client use case" in a single thread, or at least a single path of interaction. For a physically distributed application, involving EJB, JMS or WS per example, yes it should be mandatory to pass a UserData object containing the session data of the user _if_ we want to log everything everywhere. But I would not recommend it even there.
Etienne a canadian working in Paris.
> etienno@gmail.com skrev: > [quoted text clipped - 52 lines] > Download Fractality, free Java code analyzer: > www.EdmundKirwan.com/servlet/fractal/frac-page130.html Ed - 14 Jul 2006 12:38 GMT etienno@gmail.com skrev:
> Hi, > [quoted text clipped - 3 lines] > > Thanks for the guy that point to my attention Log4J MDC/NDC. (Another possibly duplicated post.)
OT, but what the hell ...
And you mentioned that you don't have a problem with this, but what the hell ...
Are you using one thread per client access (per server), and allowing multiple simultaneous client-access? In other words, will you be spawning multiple, simultaneous threads simply to handle multiple users?
(If not, do excuse my misinterpretation and ignore the rest of this post.)
This is seldom a good approach. Threads have nothing fundamentally do to with multi-user access: threads are fundamentally a blocking management mechanism (they can help with multi-user access, by only as a derivative, and when you program to derivatives, you get derivative code).
Certainly, multi-threads can slow your application appreciably, even when you think you're being user-friendly.
Consider you have 10 simultaneous users for you web-application, and all your web application does is calculate PI to the billionth decimal place, which takes your single server exactly 5 seconds.
If all your web-users click the, "Go," button simultaneously then (ignoring network latencies and context-switching), they will all receive their result after 10 * 5 seconds = 50 seconds.
Average execution time as perceived by each user = (50 * 10) / 10 = 50 seconds.
Now consider you have only a single thread in your server to handle all events; simultaneously events are blocked until the thread is ready (again, ignoring the second thread to pull data from your socket).
This time, one lucky user, the first, will perceive a result after 5 seconds. Then the thread will go on to perform the task for the second user: he'll receive a result after 10 seconds; the next: after 15 seconds, and so on.
Average response time as seen by all users = (5 + 10 + 15 + 20 + 25 + 30 + 35 + 40 + 45 + 50) / 10 = 27.5 seconds. And 90% served faster than the multi-thread variant.
Yes, a silly example, but the underlying principle remains.
-- www.EdmundKirwan.com - Home of The Fractal Class Composition.
Download Fractality, free Java code analyzer: www.EdmundKirwan.com/servlet/fractal/frac-page130.html
etienno@gmail.com - 17 Jul 2006 07:01 GMT Hi,
I am not sure to fully understand your question.
I am using a Web server; Tomcat, Jonas, WebSphere depending of the environment. I am not managing the threads directly. So the server must manage only one thread per request, but it is still a multi threaded environement. If there is no real bottleneck in the path of this thread (of the client request) there is no reason to fork the thread. So in practice there should only be one thread per "request", one ThreadLocal "instance".
This is the condition for this pattern to work.
regards,
Etienne.
> etienno@gmail.com skrev: > [quoted text clipped - 61 lines] > Download Fractality, free Java code analyzer: > www.EdmundKirwan.com/servlet/fractal/frac-page130.html
Free MagazinesGet these publications absolutely FREE for up to 12 months. There are no hidden fees and no obligation. Simply choose a title, complete the application form and submit it. Read more ...
|
|
|