Using log4j to ensure each portlet has it's own log file

Recently I was at a client site, who had just over 30 portlets deployed. When debugging was enabled, catalina.out was so saturated with log statements that it was nearly impossible to track what needed to be tracked. I changed their portlets to log to both the console like normal, and also to log to it's own file. After looking around a bit, I see this is a somewhat common quesiton in the Liferay forums, so I've decided to paste my solution here for all to use. I always use the Liferay plugins sdk, so this example will reflect those paths. If you do something different, just keep that in mind.

Goal:

To have a portlet log to both catalina.out (the console) and to it's own file, in bundles/logs/porlet-name-(date).log

Solution:

Create: /path/to/plugins/sdk/portlets/myloggingexample-portlet/docroot/WEB-INF/src/

inside the src folder, I added two files: log4j.xml and log4j.dtd

I grabbed the log4j.dtd from the liferay portal source

Content of log4j.xml
<?xml version="1.0"?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
 
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">
 
    <appender name="CONSOLE" class="org.apache.log4j.ConsoleAppender">
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%d{ABSOLUTE} %-5p [%c{1}:%L] %m%n" />
        </layout>
    </appender>
 
    <appender name="FILE" class="org.apache.log4j.rolling.RollingFileAppender">
        <rollingPolicy class="org.apache.log4j.rolling.TimeBasedRollingPolicy">
            <param name="FileNamePattern" value="../../logs/ portlet-name.%d{yyyy-MM-dd}.log" />
        </rollingPolicy>
 
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%d{ABSOLUTE} %-5p [%c{1}:%L] %m%n" />
        </layout>
    </appender>
 
    <category name="com.myclient" >
        <priority value="TRACE" />
    </category>
 
    <root>
        <priority value="INFO" />
        <appender-ref ref="CONSOLE" />
        <appender-ref ref="FILE" />
    </root>
</log4j:configuration>
 
--------
 
We have now configured log4j, but we don't have the jars yet! To get those modify  liferay-plugin-package.properties and add:
 
portal-dependency-jars=\
    log4j.jar,\
    log4j-extras.jar
 
Now, when the portlet is deployed those jars will automatically be taken from Liferay to ensure version consistency. 
 
Lastly, you need to setup your logger in your class. Add:
 
import org.apache.log4j.Logger;
 
to your imports, and inside your class (I do is as the last line), add:
 
private static Logger _log = Logger.getLogger(MyClassName.class);
 
and with that, you can call _log.fatal("test"); and see that it shows up both in the console and one directory above tomcat, in the logs folder. I set it up that way because we have bundles/logs and bundles/tomcat, so my file will show up in bundles/logs/myportlet-name-date.log
 
Hopefully this will make debugging and log viewing a little less messy for you!

 

Blogs
I always used the log com.liferay.portal.kernel.log.Log. like this:

private static Log logger = LogFactoryUtil.getLog(Clase.class);

What is the difference between them and what is the recommended log to log our developed portlets?

Thanks.
I don't recommend using the ConsoleAppender in production environment at all. It uses the System.out which will be redirected to catalina.out in Tomcat. Since this method does not use the logging facility, this file can't be rotated or compressed. The catalina.out will grow huge very quickly.

Unfortunately we have a legacy project which does not use proper logging. In this environment we have to shut down Tomcat every night to rotate and compress the catalina.out file.
Thanks and good information.

@David

Using the logger from Liferay API classes has couple of disadvantages

1. It affects portability
2.If any chanegs made to the Liferay logging API may have impact on the custom Portlet logging
@David

A lot of people use that, and there really isn't anything wrong with that. There are plusses and minuses to everything.

Pros:
You can adjust the logging on the fly in the console
You are guaranteed future compatibility if Liferay were to ever stop using log4j for some reason
You don't have to setup anything, it's extremely easy to just log and go

Cons:
Somewhat inflexible configs for storing logs anywhere other than the console
As @Kamesh said, it's Liferay specific. I always hear that argument though, and I've yet to actually see somebody go through all the work of building out a system on Liferay, then saying oh never mind and taking all those portlets and moving them to another system. In theory, yes it's Liferay specific, in reality, I've never really seen it matter.
@Kamesh

In regards to your statement 2, that's actually the reason I would say TO use it. You are safe, because you are using our logging system. My worry would be if you are depending on log4j and we change that, THEN you might have issues depending on what was changed. The coolest part about our utils is that we keep you insulated from future changes.
Thanks Brett, ideally my argument with #2 I agree its a theoriticaly statement but i dont say its not inevitable though i have seen clients doing the same for may portals emoticon ..
I would rather put this way when you put this way when i use Liferay logger utils then formats of logging , levels are controlled by the Liferay server either i have to use the *-ext mechanisms to override them or use the Liferay admin console.
If we tend you use the way said above we are in absolute control of the logging.
@István

I agree with you in a production environment, but for any other env I love being able to tail just one file and seeing everything fly by. I basically have a monitor dedicated to production logs so I can see if anything happens that shouldn't. I'm not 100% sure how they do it, but the client that I work for has a way to blow away the catalina.out file nightly without bouncing the server. I'll see if I can figure out how today and post it here for you.
Thanks, that would be great. Earlier I google'd it but others also said there was no other solution.
@István

They have a cron job that does this (as the deploy user)
cat /dev/null > /path/to/liferay/bundles/tomcat-7.0.21/logs/catalina.out

I just tested it locally and it worked perfectly. Give it a shot!
There is one small issue with this approach (at least in 6.0.12 EE). When you use Log4j inside of a ServiceBuilder Impl class (i.e. *LocalServiceImpl.java) you get the Exception described here: http://issues.liferay.com/browse/LPS-9376
But anyway... the workaround given in the issue comment will "solve" the problem.
Right, I actually just ran into that issue myself! I just added:

-Dlog4j.ignoreTCL=true

to setenv.sh and that cleaned it up for me.

The error this fixes is:

log4j:ERROR A "org.apache.log4j.xml.DOMConfigurator" object is not assignable to a "org.apache.log4j.spi.Configurator" variable.
log4j:ERROR The class "org.apache.log4j.spi.Configurator" was loaded by
log4j:ERROR [WebappClassLoader
context: /cisco-webservices-hook
delegate: false
repositories:
/WEB-INF/classes/
----------> Parent Classloader:
org.apache.catalina.loader.StandardClassLoader@3e4a9a7d
] whereas object of type
log4j:ERROR "org.apache.log4j.xml.DOMConfigurator" was loaded by [WebappClassLoader
context:
delegate: false
repositories:
/WEB-INF/classes/
----------> Parent Classloader:
org.apache.catalina.loader.StandardClassLoader@3e4a9a7d
].
log4j:ERROR Could not instantiate configurator [org.apache.log4j.xml.DOMConfigurator].
Hi Brett,

thanks for your article I found it really useful. Can you explain me why, even though in my sources are not included, after a portlet deployment I found the following log4j and commons-logging related files? (it's a dependecy to get Liferay logging works)?

WEB-INF\lib\log4j.jar
WEB-INF\lib\commons-logging.jar
WEB-INF\classes\log4j.properties
WEB-INF\classes\logging.properties

Thanks,
Denis.
I answer by myself to my previous question. Duting auto deployment Liferay prepare a new "real" war package that will be deployed to your application server. Auto deployment adds by default portal tld, portal dependecies jar and log4j and common logging jars.

If you want to avoid it, from Liferay 6.1, you can disable log4j and common logging using these properties: auto.deploy.copy.log4j=false and auto.deploy.copy.commons.logging=false
<rollingPolicy class="org.apache.log4j.rolling.TimeBasedRollingPolicy">
<param name="FileNamePattern" value="../../logs/portlet-name.%d{yyyy-MM-dd}.log" />
</rollingPolicy>
The <appender> tag is not accepting this <rollingPolicy> tag in Eclipse.

The content of element type "appender" must match "(errorHandler?,param*,layout?,filter*,appender-ref*)".
This is the error that it is showing.
Thank you for this info.
I have used it for a hook, and worked.

Péter
One of the way is this->
-create two files under/tomcat-7.0.40/webapps/ROOT/WEB-INF/classes/META-INF
1. portal-log4j-ext.xml
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">

<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">

<appender name="MY_APPENDER" class="org.apache.log4j.RollingFileAppender">
<param name="File" value="${catalina.home}/logs/log_name.log"/>
<param name="MaxFileSize" value="10000KB"/>
<param name="MaxBackupIndex" value="10"/>
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="----- %n%d{yyyy/MM/dd HH:mm:ss} %p%n%l [%x][%t] %n%m%n" />
</layout>
</appender>

<root>
<priority value="INFO" />
<appender-ref ref="CONSOLE" /> <!-- This being the default appender inside portal-log4j.xml -->
<appender-ref ref="MY_APPENDER" />
</root>
</log4j:configuration>

2. log4j.dtd
Copy code from->https://github.com/liferay/liferay-portal/blob/master/portal-impl/test/META-INF/log4j.dtd
Note-: creating portal-log4j-ext.xml instead of log4j.xml is best in practice as it override portal-log4j.properties file.
Hi First of all thanks for such a helpful post,

i have implemented log4j in this way and its working fine in for single portlet but when i try same implementation in more then one portlet in same plugin sdk and its not working.

for each and every portlet wise logs, is there any other configuration ?
As long as the portlet name differs in your xml, it should be fine. Do you get any errors or does logging just totally stop working?
given below error i am getting in console.

log4j:ERROR A "org.apache.log4j.xml.DOMConfigurator" object is not assignable to a "org.apache.log4j.spi.Configurator" variable.
log4j:ERROR The class "org.apache.log4j.spi.Configurator" was loaded by
log4j:ERROR [WebappClassLoader
context: /manage-portlet
delegate: false
repositories:
/WEB-INF/classes/
----------> Parent Classloader:
org.apache.catalina.loader.StandardClassLoader@53dc5341
] whereas object of type
log4j:ERROR "org.apache.log4j.xml.DOMConfigurator" was loaded by [WebappClassLoader
context:
delegate: false
repositories:
/WEB-INF/classes/
----------> Parent Classloader:
org.apache.catalina.loader.StandardClassLoader@53dc5341



where i have follow the same steps which you have mention in the blog.