Wednesday, July 12, 2006

Create your own logging level in log4j


If you need to add your own logging level in log4j, then you can do it as follows. You will have to create your own class which will extend from Level. Here's a sample code for the same:

MyTraceLevel.java:

package org.myapp.log;

import org.apache.log4j.Level;
/**
* My own {@link org.apache.log4j.Level} for logging.
*
* @author Jaikiran Pai
*
*/
public class MyTraceLevel extends Level {

/**
* Value of my trace level. This value is lesser than
* {@link org.apache.log4j.Priority#DEBUG_INT}
* and higher than {@link org.apache.log4j.Level#TRACE_INT}
*/
public static final int MY_TRACE_INT = DEBUG_INT - 10;

/**
* {@link Level} representing my log level
*/
public static final Level MY_TRACE = new MyTraceLevel(MY_TRACE_INT,"MY_TRACE",7);

/**
* Constructor
*
* @param arg0
* @param arg1
* @param arg2
*/
protected MyTraceLevel(int arg0, String arg1, int arg2) {
super(arg0, arg1, arg2);

}

/**
* Checks whether sArg is "MY_TRACE" level. If yes then returns
* {@link MyTraceLevel#MY_TRACE}, else calls
* {@link MyTraceLevel#toLevel(String, Level)} passing it
* {@link Level#DEBUG} as the defaultLevel.
*
* @see Level#toLevel(java.lang.String)
* @see Level#toLevel(java.lang.String, org.apache.log4j.Level)
*
*/
public static Level toLevel(String sArg) {
if (sArg != null && sArg.toUpperCase().equals("MY_TRACE")) {
return MY_TRACE;
}
return (Level) toLevel(sArg, Level.DEBUG);
}

/**
* Checks whether val is {@link MyTraceLevel#MY_TRACE_INT}.
* If yes then returns {@link MyTraceLevel#MY_TRACE}, else calls
* {@link MyTraceLevel#toLevel(int, Level)} passing it {@link Level#DEBUG}
* as the defaultLevel
*
* @see Level#toLevel(int)
* @see Level#toLevel(int, org.apache.log4j.Level)
*
*/
public static Level toLevel(int val) {
if (val == MY_TRACE_INT) {
return MY_TRACE;
}
return (Level) toLevel(val, Level.DEBUG);
}

/**
* Checks whether val is {@link MyTraceLevel#MY_TRACE_INT}.
* If yes then returns {@link MyTraceLevel#MY_TRACE},
* else calls {@link Level#toLevel(int, org.apache.log4j.Level)}
*
* @see Level#toLevel(int, org.apache.log4j.Level)
*/
public static Level toLevel(int val, Level defaultLevel) {
if (val == MY_TRACE_INT) {
return MY_TRACE;
}
return Level.toLevel(val,defaultLevel);
}

/**
* Checks whether sArg is "MY_TRACE" level.
* If yes then returns {@link MyTraceLevel#MY_TRACE}, else calls
* {@link Level#toLevel(java.lang.String, org.apache.log4j.Level)}
*
* @see Level#toLevel(java.lang.String, org.apache.log4j.Level)
*/
public static Level toLevel(String sArg, Level defaultLevel) {
if(sArg != null && sArg.toUpperCase().equals("MY_TRACE")) {
return MY_TRACE;
}
return Level.toLevel(sArg,defaultLevel);
}
}

Now, you will have to configure your log4j.xml:

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/"debug="false">
<!-- ================================= -->
<!-- Preserve messages in a local file -->
<!-- ================================= -->
<!-- A size based rolling appender -->
<appender name="FILE" class="org.apache.log4j.FileAppender">
<param name="File" value="D:/log/myLogFile.log"/>
<param name="Append" value="false"/>
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="%d{ISO8601} %-5p [%c] %m%n"/>
</layout>
</appender>
<!-- ============================== -->
<!-- Append messages to the console -->
<!-- ============================== -->
<appender name="CONSOLE" class="org.apache.log4j.ConsoleAppender">
<param name="Target" value="System.out"/>
<param name="Threshold" value="INFO"/>
<layout class="org.apache.log4j.PatternLayout">
<!-- The default pattern: Date Priority [Category] Message\n -->
<param name="ConversionPattern" value="%d{ISO8601} %-5p [%c{1}] %m%n"/>
</layout>
</appender>
<!-- ================ -->
<!-- Limit categories -->
<!-- ================ -->
<category name="org.myapp">
<priority value="MY_TRACE" class="org.myapp.log.MyTraceLevel" />
<appender-ref ref="FILE"/>
</category>
<!-- ======================= -->
<!-- Setup the Root category -->
<!-- ======================= -->
<root>
<appender-ref ref="CONSOLE"/>
</root>
</log4j:configuration>


Here's a test program which can be used for testing whether the new log level that you introduced is being identified or not:

TestMyLogLevel.java:

package org.myapp.core;

import org.apache.log4j.Level;
import org.apache.log4j.Logger;
import org.myapp.log.MyTraceLevel;

/**
* Tests whether the new log level {@link org.myapp.log.MyTraceLevel#MY_TRACE}
* is working
*
* @author Jaikiran Pai
*
*/
public class TestMyLogLevel {

/**
* Writes a log message with {@link org.myapp.log.MyTraceLevel#MY_TRACE}
* and another message with {@link Level#DEBUG}
*
* @param args
*/
public static void main(String[] args) {
Logger logger = Logger.getLogger(TestMyLogLevel.class);
logger.log(MyTraceLevel.MY_TRACE,"I am MY_TRACE log");
logger.log(Level.DEBUG ,"I am a debug message");
}
}


Finally, here's the log file that got generated:

2006-07-12 13:45:40,633 MY_TRACE [org.myapp.core.TestMyLogLevel] I am MY_TRACE log
2006-07-12 13:45:40,633 DEBUG [org.myapp.core.TestMyLogLevel] I am a debug message

Points to note:

- The int value that you specify for your log level is important. Here i have defined "MY_TRACE" log level is to be higher than the DEBUG level but lower than the TRACE level provided by log4j. So whenever you have set a priority level to DEBUG on the category(in your log4j.xml file), the MY_TRACE level logs will *NOT* make it to the log file.

Wednesday, July 05, 2006

I get "log4j:WARN No appenders could be found for logger" message

While using log4j in your application, sometimes you might encounter the following message:

log4j:WARN No appenders could be found for logger(somePackageName.someClassName).
log4j:WARN Please initialize the log4j system properly.


The reason why you see this message is that your log4j configuration file(i.e. log4j.xml or log4j.properties) is NOT found in the classpath. Placing the log4j configuration file in the applications classpath should solve the issue. If you want to find out how log4j tries to configure itself, have a look at my earlier post :

Know how log4j tries to configure itself



Tuesday, July 04, 2006

Know how log4j tries to configure itself

Large number of applications use log4j for logging. Sometimes you may encounter cases where you sense that log4j is using some other configurations, other than the one that you expected it to use. You can debug the same by switching on the debug flag on log4j. Here's how you can do it:

Add -Dlog4j.debug to the command line. log4j will output info to std. out. telling you how it tries to configure itself.


Accessing a secure EJB through a standalone java client

To access a secure resource(may be a EJB), from a standalone client, you need to do a JAAS login. Here's an simple example which shows how to implement the same. But before going to the example, here's the reason why we need to do a login. Consider a secured EJB "MyTestEJB", deployed on a app server. The normal proceedure that you follow in a web-application to lookup the EJB and invoke a method on the same is as follows:

Context context = new InitialContext();
//lookup the home object
Object lookupObj = context.lookup("MyTestEJBHomeJndiName");
MyTestEJBHome home = (MyTestEJBHome) PortableRemoteObject.narrow(lookupObj, MyTestEJBHome.class);
//create the bean object from the home object
MyTestEJB myBean = home.create();
//invoke the method on the bean
myBean.someMethod();


In the steps above, when the method create is called on the home object, the app server internally checks whether the user who is doing this operation, is authenticated and authorised to do the same. If not, it will throw a SecurityException. The above statements will usually work in a web-application where usually you have a login page to carry out the login process.

Now, consider the case with a standalone java client which has just got a main method and which needs to invoke the secure bean. The application server will have no knowledge about which user is trying to do the operations on the bean(is he authenticated or authorised?). This is the reason why the standalone client needs to do a JAAS login, to let the application server know which user is trying to do the operation on the bean. Now lets look at the code for doing the same. Here we have a standalone java client with a main() method:


package myapp;

import javax.ejb.CreateException;
import javax.naming.Context;
import javax.naming.InitialContext;
import javax.naming.NamingException;
import javax.rmi.PortableRemoteObject;
import javax.security.auth.login.LoginContext;
import javax.security.auth.login.LoginException;
import java.io.Serializable;
import java.rmi.RemoteException;

/**
*
* Stand-alone client invoking a method on a secure EJB
*
*/
public final class SomeStandAloneClient {


/**
* Default constructor
*
*/
public SomeStandAloneClient() {

}

/**
* Main method
*
* @param args Command line arguments
*/
public static void main(String[] args) {

//obtain the username and password which are passed as part of command line arguments
String userName = args[0];
String password = args[1];

System.out.println("Logging in user: " + userName);

/*
* The name of the file which will contain the login configurations
*/
final String authFile = "someFilename.someExtension";

/*
* Set the filename above, as part of system property, so that while doing a login,
* this file will be used to check the login configurations
*/
System.setProperty("java.security.auth.login.config", authFile);

/*
* During the login process(i.e. when the login() method on the LoginContext is called),
* the control will be transferred to a CallbackHandler. The CallbackHandler will be
* responsible for populating the Callback object with the username and password, which
* will be later on used by the login process
*
* The "MyCallbackHandler" is your own class and you can give any name to it. MyCallbackHandler
* expects the username and password to be passed through its constructor, but this is NOT
* mandatory when you are writing your own callback handler.
*
*
*/
MyCallbackHandler handler = new MyCallbackHandler(userName,password);

try {

/*
* Create a login context. Here, as the first parameter, you will specify which
* configuration(mentioned in the "authFile" above) will be used. Here we are specifying
* "someXYZLogin" as the configuration to be used. Note: This has to match the configuration
* specified in the someFilename.someExtension authFile above.
* The login context expects a CallbackHandler as the second parameter. Here we are specifying
* the instance of MyCallbackHandler created earlier. The "handle()" method of this handler
* will be called during the login process.
*/
LoginContext lc = new LoginContext("someXYZLogin",handler);

/*
* Do the login
*/
lc.login();

System.out.println("Successfully logged in user: " + userName);


} catch (LoginException le) {

System.out.println("Login failed");
le.printStackTrace();
return;
}

try{

/*
* Now that the user has logged in, invoke the method on the EJB
*/

Context context = new InitialContext();

//lookup the home object
Object lookupObj = context.lookup("MyTestEJBHomeJndiName");
MyTestEJBHome home = (MyTestEJBHome) PortableRemoteObject.narrow(lookupObj, MyTestEJBHome.class);

//create the bean object from the home object
MyTestEJB myBean = home.create();

//invoke the method on the bean
myBean.someMethod();


} catch (RemoteException re) {

System.out.println("Remote exception: ");
re.printStackTrace();
return;

} catch (NamingException ne) {

System.out.println("NamingException: ");
ne.printStackTrace();
return;

} catch (CreateException ce) {

System.out.println("CreateException: ");
ce.printStackTrace();
return;
}


} //end of main()

} //end of SomeStandAloneClient

Now the CallbackHandler:

package myapp;

import java.io.IOException;

import javax.security.auth.callback.Callback;
import javax.security.auth.callback.CallbackHandler;
import javax.security.auth.callback.NameCallback;
import javax.security.auth.callback.PasswordCallback;
import javax.security.auth.callback.UnsupportedCallbackException;

/**
*
* CallbackHandler which will be invoked by the login module during the login
* process of the client. This is a simple CallbackHandler which sets the username
* and password, which will be later used by the Login module for authorizing the
* subject. This class only handles NameCallback and PasswordCallback. It throws
* an UnsupportedCallbackException, if the Callback is other than the two mentioned
* above.
* The username and password are provided as input to this class through its constructor.
*
*
*/
public class MyCallbackHandler implements CallbackHandler {

/**
* Username which will be set in the NameCallback, when NameCallback is handled
*/
private String username;

/**
* Password which will be set in the PasswordCallback, when PasswordCallback is handled
*/
private String password;

/**
* Constructor
* @param username The username
* @param password The password
*/
public MyCallbackHandler(String username, String password) {
this.username = username;
this.password = password;
}

/**
* @param callbacks Instances of Callbacks
* @throws IOException IOException
* @throws UnsupportedCallbackException If Callback is other than NameCallback or PasswordCallback
*/
public void handle(Callback callbacks[]) throws IOException, UnsupportedCallbackException {

for(int i = 0; i < callbacks.length; i++) {
if(callbacks[i] instanceof NameCallback) {
NameCallback nc = (NameCallback)callbacks[i];
nc.setName(username);
} else if(callbacks[i] instanceof PasswordCallback) {
PasswordCallback pc = (PasswordCallback)callbacks[i];
pc.setPassword(password.toCharArray());
} else {
throw new UnsupportedCallbackException(callbacks[i], "Unrecognized Callback");
}

}
}
}

The file containing the login configuration(in our case "someFilename.someExtension"):

someXYZLogin{
org.jboss.security.ClientLoginModule required;
};

Remember, the someXYZLogin configuration name is the same that i provided to the constructor of the LoginContext. The contents of the above file let the LoginContext know, which class will be actually responsible for doing the login. In this case, since i am using jboss, we have specified "org.jboss.security.ClientLoginModule" as the class.

Please make sure that the login configuration file is under the same directory from where you will be running your client.

The command to run your client is the same that you would use to run a normal java class:


java SomeStandAloneClient someUsername somePassword

The someUsername and somePassword will be the arguments that you will pass to the main() method.

This is just a simple example. Internally, there are a lot of things, that go on as part of login. The following link has a great explanation about the same(JAAS related things are explained starting from the "An Introduction to JAAS" section in that article). I highly recommend, to go through it atleast once:

Article on Security

Monday, July 03, 2006

Introductory post

Thought of putting in one place, all the technical stuff that i get to learn while working as a software developer in J2EE field.