Debugging and Logging

Troubleshooting a JSF application can be painful. So many minor details must be just right or your application won't work. Error messages can be hard to find or nonexistent. Minor typos can give rise to an application that simply doesn't start or that seems to get stuck. The items in this section contain some tips to help you out.

How do I decipher a stack trace?

When you see a screen such as the one in Figure 12-17, count yourself lucky.

Figure 12-17. Error Page

[View full size image]

Read the first line (or the first line that seems to make some sense), and correlate it with your JSF file. In this case, there is an illegal tag (inputTaxt instead of inputText) in line 16, column 21, or hopefully somewhere near there.

The error report may also indicate a problem with your code. For example,


java.lang.ClassCastException

     com.corejsf.UploadRenderer.decode(UploadRenderer.java:73)

     javax.faces.component.UIComponentBase.decode(UIComponentBase.java:658)

     javax.faces.component.UIInput.decode(UIInput.java:464)

     javax.faces.component.UIComponentBase.processDecodes(UIComponentBase.java:878)

     javax.faces.component.UIInput.processDecodes(UIInput.java:380)

     javax.faces.component.UIForm.processDecodes(UIForm.java:139)

     javax.faces.component.UIComponentBase.processDecodes(UIComponentBase.java:873)

     javax.faces.component.UIViewRoot.processDecodes(UIViewRoot.java:305)

     com.sun.faces.lifecycle.ApplyRequestValuesPhase.execute(ApplyRequestValuesPhase.java:79)

     com.sun.faces.lifecycle.LifecycleImpl.phase(LifecycleImpl.java:200)

     com.sun.faces.lifecycle.LifecycleImpl.execute(LifecycleImpl.java:90)

     javax.faces.webapp.FacesServlet.service(FacesServlet.java:197)

     com.corejsf.UploadFilter.doFilter(UploadFilter.java:68)

The remedy is straightforward. Have a look at line 73 of UploadRenderer.java and find out what caused the bad cast.

TIP

If your stack trace states that errors in your code are in unknown source locations, compile with debugging on. If you use Ant, add the attribute debug="true" to the javac task.

Sometimes, the situation is not so rosy. Consider this report:



javax.servlet.ServletException: javax.faces.el.EvaluationException: Error getting property

 'password' from bean of type com.corejsf.UserBean: java.lang.NullPointerException

    org.apache.jasper.runtime.PageContextImpl.doHandlePageException(PageContextImpl.java:864)

    org.apache.jasper.runtime.PageContextImpl.handlePageException(PageContextImpl.java:800)

    org.apache.jsp.index_jsp._jspService(index_jsp.java:78)

    org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:133)

    javax.servlet.http.HttpServlet.service(HttpServlet.java:856)

    org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:311)

    org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:301)

    org.apache.jasper.servlet.JspServlet.service(JspServlet.java:248)

    javax.servlet.http.HttpServlet.service(HttpServlet.java:856)

    com.sun.faces.context.ExternalContextImpl.dispatch(ExternalContextImpl.java:322)

    com.sun.faces.application.ViewHandlerImpl.renderView(ViewHandlerImpl.java:142)

    com.sun.faces.lifecycle.RenderResponsePhase.execute(RenderResponsePhase.java:87)

    com.sun.faces.lifecycle.LifecycleImpl.phase(LifecycleImpl.java:200)

    com.sun.faces.lifecycle.LifecycleImpl.render(LifecycleImpl.java:117)

    javax.faces.webapp.FacesServlet.service(FacesServlet.java:198)

Here, the subsystem that evaluates the expression language has wrapped an exception in the bean code inside an EvaluationException. You get to know where the EvaluationException is thrown, but that doesn't help you—you need the location of the NullPointerException that caused it.

Your next step is to inspect the log files. In this case, the log contains a more detailed report:



Caused by: javax.faces.el.EvaluationException: Error getting property 'password' from bean

 of type com.corejsf.UserBean: java.lang.NullPointerException

        at com.sun.faces.el.PropertyResolverImpl.getValue(PropertyResolverImpl.java:89)

        at com.sun.faces.el.impl.ArraySuffix.evaluate(ArraySuffix.java:162)

        at com.sun.faces.el.impl.ComplexValue.evaluate(ComplexValue.java:146)

        at com.sun.faces.el.impl.ExpressionEvaluatorImpl.evaluate(ExpressionEvaluatorImpl

.java:238)

        at com.sun.faces.el.ValueBindingImpl.getValue(ValueBindingImpl.java:155)        ..

. 55 more

Caused by: java.lang.NullPointerException

        at com.corejsf.UserBean.getPassword(UserBean.java:12)

        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl

.java:25)

        at java.lang.reflect.Method.invoke(Method.java:324)

        at com.sun.faces.el.PropertyResolverImpl.getValue(PropertyResolverImpl.java:79)

        ... 59 more

Finally, information you can use: Line 12 of UserBean.java caused the problem.

Unfortunately, sometimes the stack trace gives you no useful information at all. Here is an example of a bad case.


javax.servlet.ServletException: Cannot find FacesContext

     org.apache.jasper.runtime.PageContextImpl.doHandlePageException(PageContextImpl.java:867)

     org.apache.jasper.runtime.PageContextImpl.handlePageException(PageContextImpl.java:800)

     org.apache.jsp.index_jsp._jspService(index_jsp.java:78)

     org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:133)

     javax.servlet.http.HttpServlet.service(HttpServlet.java:856)

     org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:311)

     org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:301)

     org.apache.jasper.servlet.JspServlet.service(JspServlet.java:248)

     javax.servlet.http.HttpServlet.service(HttpServlet.java:856)

What caused this error? Misalignment of the planets? No—the problem was a bad URL: http://localhost:8080/login/index.jsp instead of http://localhost:8080/login/index.faces.

How do I find the logs?

The details depend on your JSF container. Tomcat 5 keeps logs in the tomcat/logs directory. The standard Tomcat log files are

catalina.out
localhost_log.date.log

Here date is a date stamp such as 2003-06-30. The catalina.out file contains all output that was sent to System.out and System.err. The localhost_log.date.log files contain the logging messages that were generated by the servlet context.

NOTE

graphics/note_icon.gif
Both Tomcat and the JSF reference implementation use Apache Commons logging (see http://jakarta.apache.org/commons/logging.html). This logging library is merely a bridge to various logging libraries, in particular the java.util.logging library that was introduced in SDK version 1.4, and the Apache Log4J library (http://logging.apache.org/log4j/docs/). There are religious wars over which logging library is better and whether Commons logging is a good idea—see, for example, http://www.qos.ch/logging/thinkAgain.html. We must admit to a slight preference for java.util.logging. It may not be perfect, but it's good enough, and it is a standard part of Java.

By default, Tomcat is configured to map Commons logging to the java.util.logging package. By default, that package is configured so that all messages with level INFO and higher are sent to System.out. Thus, most Tomcat messages end up in catalina.out. A much smaller number of messages are sent to the servlet context log, another logging facility that is completely unrelated to Commons logging. Therefore, you should check the localhost_log.date.log if catalina.out doesn't have the message you are looking for.

The catalina.out file is specified in the startup script (catalina.sh or catalina.bat in the tomcat/bin directory). The localhost_log.date.log files are configured in tomcat/conf/server.xml.

If you use the Tomcat implementation in the Java Web Services Development Pack, then the files are called launcher.server.log and jwsdp_log.date.log.

How do I find out what parameters my page received?

It is often helpful to know what parameters the client sent back to the server when a form was submitted. Here is a quick and dirty method for logging the request parameters.

Insert this snippet of code on top of the JSF file that receives the request:


<%

java.util.Enumeration e = request.getParameterNames();

while (e.hasMoreElements())

{

   String n = (String) e.nextElement();

   String[] v = request.getParameterValues(n);

   for (int i = 0; v != null && i < v.length; i++)

      java.util.logging.Logger.global.info("name=" + n + ",value=" + v[i]);

}

%>

Then catalina.out will contain entries such as


Apr 2, 2004 12:50:45 PM org.apache.jsp.welcome_jsp _jspService

INFO: name=_id0,value=_id0

Apr 2, 2004 12:50:45 PM org.apache.jsp.welcome_jsp _jspService

INFO: name=_id0:_id1,value=me

Apr 2, 2004 12:50:45 PM org.apache.jsp.welcome_jsp _jspService

INFO: name=_id0:_id2,value=secret

Apr 2, 2004 12:50:45 PM org.apache.jsp.welcome_jsp _jspService

INFO: name=_id0:_id3,value=Login

How do I turn on logging of the JSF container?

The JSF reference implementation contains copious logging statements whose output can be very helpful in tracking down problems with your applications.

Here, we assume that Tomcat has been configured to use the java.util.logging library that was introduced in SDK 1.4. This is the default setting for Tomcat.

Edit the startup script catalina.sh or catalina.bat in the tomcat/bin directory. At the top, add a line that sets the variable CATALINA_OPTS to the following parameter definition:

-Djava.util.logging.config.file=tomcat/conf/logging.properties

In Unix/Linux, use this syntax:

CATALINA_OPTS="-Djava.util.logging.config.file=tomcat/conf/logging.properties"

In Windows, use this syntax:

set CATALINA_OPTS=-Djava.util.logging.config.file=tomcat\conf\logging.properties
```
(As always, tomcat denotes the name of the Tomcat installation such as

/usr/local/jakarta-tomcat-5.0.19 or c:\jakarta-tomcat-5.0.19.)
```
Copy the file logging.properties from the subdirectory jre/lib inside your Java SDK to the tomcat/conf directory.
Edit the file tomcat/conf/logging.properties. Locate the line
```
java.util.logging.ConsoleHandler.level = INFO
```
and change INFO to FINEST. At the end of the file, add a line
```
com.sun.faces.level=FINEST
```

Restart Tomcat and run a JSF application. Then inspect the file tomcat/logs/catalina.out. It will contain messages such as


FINEST: End execute(phaseId=RESTORE_VIEW 1)

Jan 27, 2004 6:57:04 PM com.sun.faces.lifecycle.LifecycleImpl hasPostDataOrQueryParams

FINEST: Request Method: POST/PUT

Jan 27, 2004 6:57:04 PM com.sun.faces.lifecycle.LifecycleImpl execute

FINEST: execute(phaseId=APPLY_REQUEST_VALUES 2)

Jan 27, 2004 6:57:04 PM com.sun.faces.lifecycle.LifecycleImpl execute

FINEST: Begin execute(phaseId=APPLY_REQUEST_VALUES 2)

Jan 27, 2004 6:57:04 PM com.sun.faces.lifecycle.ApplyRequestValuesPhase execute

FINE: Entering ApplyRequestValuesPhase

Jan 27, 2004 6:57:04 PM com.corejsf.UploadRenderer decode

To turn off JSF container logging, simply edit tomcat/conf/logging.properties and change com.sun.faces.level to INFO.

NOTE

graphics/note_icon.gif
If Tomcat finds the Apache Log4J library on the classpath, then it will use that logging library unless you specifically add the following definition to CATALINA_OPTS:

-Dorg.apache.commons.logging.Log=org.apache.commons.logging.impl.Jdk14Logger

How do I replace `catalina.out` with rotating logs?

Again, we assume that Tomcat has been configured to use the java.util.logging library that was introduced in SDK 1.4. This is the default setting for Tomcat.

Edit the startup script catalina.sh or catalina.bat in the tomcat/bin directory. At the top, add a line that sets the variable CATALINA_OPTS to the following parameter definition:

-Djava.util.logging.config.file=tomcat/conf/logging.properties

In Unix/Linux, use this syntax:

CATALINA_OPTS="-Djava.util.logging.config.file=tomcat/conf/logging.properties"

In Windows, use this syntax:

set CATALINA_OPTS=-Djava.util.logging.config.file=tomcat\conf\logging.properties

(As always, tomcat denotes the name of the Tomcat installation such as /usr/local/jakarta-tomcat-5.0.19 or c:\jakarta-tomcat-5.0.19.)
Copy the file logging.properties from the subdirectory jre/lib inside your Java SDK to the tomcat/conf directory.

Edit the file tomcat/conf/logging.properties and make the following changes:

Change the value of…
from
to
handlers
java.util.logging.ConsoleHandler
java.util.logging.FileHandler, java.util.logging.ConsoleHandle
java.util.logging.FileHandler.pattern
%h/java%u.log
tomcat/logs/tomcat%u.log
java.util.logging.FileHandler.formatter
java.util.logging.XMLFormatter
java.util.logging.SimpleFormatter
java.util.logging.ConsoleHandler.level
INFO
NONE

Restart Tomcat. The logs will now be in files tomcat0.log.0, tomcat0.log.1, and so on, inside the tomcat/logs directory. The newest log is always tomcat0.log.0.

How do I find the library source?

You can download the library source from http://www.sun.com/software/communitysource/jsf. The library source can be very helpful for troubleshooting, and to clarify opaque points of the specification.

The library code is organized in four directories:

jsf-api, the documented API classes whose package names start with javax.faces
jsf-ri, the reference implementation classes whose package names start with com.sun.faces
jsf-tools, the tools that mechanically generate tag handlers and renderers
jsf-demo, the demo applications

In order to get a complete set of source files, you must run the Ant script in the jsf-tools directory.

Edit the build.properties file in the jsf-tools directory and supply the settings for tomcat.home and jsf.home.
If you use the standalone version of Tomcat, you also need to modify build.xml and change the correct locations for the commons-logging.jar, commons-digester.jar, commons-collections.jar, and commons-beanutils.jar files to ${tomcat.home}/server/lib.
In the jsf-tools directory, run Ant without any arguments.
The source code is produced in the jsf-tools/build/generate directory.

Finally, it is sometimes useful to find configuration details of the JSF implementation, such as the names of the standard components, renderers, converters, and validators. Look inside the files jsf-ri/src/com/sun/faces/jsf-ri-config.xml and jsf-api/doc/standard-xml-renderkit.xml.

< Day Day Up >