[QFJ-265] Log4j or commons-logging integration for the FileLog Created: 21/Nov/07  Updated: 15/Nov/12  Resolved: 22/Dec/07

Status: Closed
Project: QuickFIX/J
Component/s: Engine
Affects Version/s: 1.2.1
Fix Version/s: None

Type: Improvement Priority: Default
Reporter: André Malenfant Assignee: Unassigned
Resolution: Won't Fix Votes: 0
Labels: None


 Description   

I am not sure this is part of 1.3 but I don't think so.

It would be nice if the FileStore class uses commons-logging, log4j or slf4j for outputing the message log to a file. This way we could manage the log files the same way we manage our application logs. For example, it would be interesting in a production environment to be able to use a DailyRollingFileAppender to prevent the file from growing too much. We would also benefit from all formatting options such as timestamps in the platform timezone that are easier to read than the time in the header of the message (which may be in a different timezone depending on the other party).



 Comments   
Comment by Steve Bate [ 22/Dec/07 ]

The file store needs to efficiently access it's data when message resends are requested. A regular log file does not provide good support for this type of usage. A rolling log file is a problem because all the messages for the current session must be available in the message store for resend purposes. The message store is truncated at the end of a daily or weekly session.

Comment by André Malenfant [ 23/Dec/07 ]

Sorry, I think I confused quickfix.Log with FileStore when wrtting my issue. My suggestion was to be able to send events and messages logs to commons-loggin or log4j, not to alter the message store functionnality.

I have experimented by writting my own LogFactory that creates a Log instance that outputs to log4j and it works perfectly fine. I did not touch the store files. The only problem (and it is why I submitted this post in the first place) is that the Log interface only has one method that only receives one String parameter, thus cannot distinguish error messages from informational and debug messages nor accept a Throwable object.

It is now common practive at least in Java to use libraries like log4j that gives the flexibility to filter the output to the log based on the originating code or priority level of the message. An offer a variety of output formats. Most importantly, it allows to report a complete stack trace to the log when an error occurs. I think t is unacceptable to only see a message such as: NullPointerException in a log file without the stack trace and some sort of indication of the source of the error. In fact all major open source products or packages use a similar pattern for logging and it has become a criteria of quality that QuickFIX/J would certainly benifit, especially in the type of business it is trying to succeed in.

Comment by Steve Bate [ 23/Dec/07 ]

QuickFIX/J includes an SLF4JLogFactory (see http://www.slf4j.org/) that supports a variety of logging providers, including Log4J. It also has a bridge to Commons Logging. To use a Log4J rolling file appender with QFJ, you just include slf4j-log4j12-1.3.0.jar in your classpath instead of the default slf4j-jdk14-1.3.0.jar and then configure Log4J as you normally would.

The issue with logging levels is a limitation of the QuickFIX JNI API which QFJ is based upon. I agree it would be nice to be able to specify a logging level.

I'm not sure I understand the issue about stack traces. Your application log anything it would like directly to your logging provider of choice. However, this would typically be a separate log file than the session log file. If you specifically want to log a stack trace to the session log file then you can use the quickfix.LogUtil.logThrowable() methods to format a stacktrace and write it to the QFJ Log implementation.

The SLF4JLogFactory also allows you specify category patterns that can have session id-related placeholders. This allows separate categories for each FIX session which would support sending different sessions to different files or specifying different pattern layouts for fix versions or specific counterparties, for example.

Comment by André Malenfant [ 23/Dec/07 ]

I will experiment with the SLF4JLogFactory. It does not fix the level issue but still helpfull.

The stack trace issue is for exceptions thrown from quickfixj code, not applications. For example, when an error occurs, the only indication in the event log is the error message of the underlying exception like: NullPointerException. A lot of developers like myself are now expecting to see a full stack trace of where the error was thrown. A stack trace is a great debugging tool. I agree that with bug free code one can rely on the error message only but bug free code is not something I have come accross very often.

As for JNI, do you think quickfixj will eventually branch from quickfix. What is the benefit of keeping compatibility with quickfix. I imagine you have good reasones but from my perspective it is only creating issues: the log level issue, the fix message packaging issue (as noted by Francis Lalonde), the static session issue (I know I should open another issue on this topic).

Comment by Steve Bate [ 23/Dec/07 ]

Stack traces are logged for several exceptions that internal to the engine. I generally only log a stack trace if the exception is probably caused by a coding error. For example, logging a stack trace for an exception caused by a corrupt incoming FIX message isn't really helpful since the corruption generally occurs in the network or in the counterparty's code.

However, if you have specific places where an exception is logged that would be more useful with a stack trace, let me know. I've added a few more recently and I've started catching all exceptions originating from an Application implementation exception and logging stack traces for those (although the application developer should really be doing it). This is in the trunk, not 1.3.0.

On the branching issue, I don't know if you are a subscriber to the mailing list but someone asked about that recently and I've requested some community discussion about it. So far, nobody has followed up on the topic. If you wanted to share your opinions there that would be great. Thanks.

Comment by André Malenfant [ 23/Dec/07 ]

In my developement team, we have taken the habit of systematically log all exceptions in our application code using log4j. Any exception cached are logged along with a message (except a few irrelevant ones like null pointers that are catched to return a default value for example) . This habbit is simple to take when you use log4j (and other libraries as well) because the log methods all take a throwable as a parameter. An administrator of our applications can then choose not to display them in the logs but at least the possibility is there. I don't understand why quickfixj wraps logging with it's own logging classes where slf4j or comons-logging or log4j have already everything required.

I agree that in some instances the stack trace does not give much more information but in a lot of cases it does and especially with an open source product where one can browse the code imself and try to fix the issue or at least investigate. Considering that it is not more effort that simply writting a message in a log (additional parameter to pass to the logging method), I think it is not a luxury and that it can definitely improve troubleshooting.

I will look for the posts regarding the possibility of branching quickfixj and participate if I have some more data to put into it.

Comment by Steve Bate [ 23/Dec/07 ]

André,

Thanks for your comments. Again, if you have a specific place where a stack trace would have been useful to debug your application or to track down problems in QFJ and it wasn't provided, I'll most likely add the stack trace. However, I won't add stack traces for every exception. I've explained why some of these stack traces are not useful. This would only add needless noise to the log file. The fact that's it's so easy to add this noise is more of a problem than a feature, in my opinion.

Where did you see the NullPointerException without the stack trace? Did the exception arise in QFJ or in your application callbacks?

As you know, the logging approach in QFJ is based on the logging API of the QuickFIX JNI code which was obviously not based on Log4J or any other Java logging provider. If I were writing a Java FIX engine from the ground up I wouldn't use the same design. I also still wouldn't use Log4J directly since various libraries use different logging providers. I'd base it on something like SLF4J or Commons Logging.

Generated at Sat Nov 23 11:08:48 UTC 2024 using JIRA 7.5.2#75007-sha1:9f5725bb824792b3230a5d8716f0c13e296a3cae.