Java EE Servlet/JSP tutorial : Adding an error page, logging, and other forms of debugging
From Resin 4.0 Wiki
In progress....
Contents
|
Logging
Background on logging
Background information on logging
http://www.vogella.com/articles/Logging/article.html
http://onjava.com/onjava/2002/06/19/log.html
http://tutorials.jenkov.com/java-logging/index.html
http://docs.oracle.com/javase/7/docs/api/java/util/logging/SimpleFormatter.html
Common problem with logging
http://stackoverflow.com/questions/6315699/why-are-my-level-fine-logging-messages-not-showing
Understandng the outptut for logging
http://docs.oracle.com/javase/7/docs/technotes/guides/logging/index.html
http://docs.oracle.com/javase/7/docs/technotes/guides/logging/overview.html
http://docs.oracle.com/javase/7/docs/api/java/util/Formatter.html#syntax
Resin and logging
Logging in Resin
http://www.caucho.com/resin-4.0/admin/logging.xtp
http://www.caucho.com/resin-4.0/admin/resin-admin-command-line.xtp#loglevelsettingloglevel
Changing log levels in Resin:
~/workspace/javaee/Servers/Resin 4.0 at localhost-config/resin.xml
...
<!-- Logging configuration for the JDK logging API -->
<log-handler name="" level="all" path="stdout:"
timestamp="[%y-%m-%d %H:%M:%S.%s]"
format=" {${thread}} ${log.message}"/>
...
<!--
- level='info' for production
- 'fine' or 'finer' for development and troubleshooting
-->
<logger name="" level="${log_level?:'info'}"/>
<logger name="com.caucho.java" level="config"/>
<logger name="com.caucho.loader" level="config"/>
Changing log levels in Resin:
~/workspace/javaee/Servers/Resin 4.0 at localhost-config/resin.properties
# log_level : info # app-0.log_level : finest
Using log class
http://docs.oracle.com/javase/1.4.2/docs/api/java/util/logging/Logger.html
Using Java log API
package com.bookstore;
...
import java.util.logging.Level;
import java.util.logging.Logger;
public class Book implements Cloneable {
private transient Logger log = Logger.getLogger(Book.class.getName());
...
public Book cloneMe() {
try {
return (Book) super.clone();
} catch (CloneNotSupportedException e) {
log.logp(Level.WARNING,
this.getClass().getName(),
"cloneMe", "Unable to clone", e);
return null;
}
}
...
Info about logp http://docs.oracle.com/javase/6/docs/api/java/util/logging/Logger.html#logp(java.util.logging.Level, java.lang.String, java.lang.String, java.lang.String, java.lang.Throwable)
Why you should not use static http://wiki.apache.org/commons/Logging/StaticLog
Another example:
package com.bookstore;
...
import java.util.logging.Logger;
import javax.enterprise.context.ApplicationScoped;
@ApplicationScoped @InMemory
public class BookRepositoryCollectionsImpl implements BookRepository {
...
private Book book(String title, String description, String aPrice,
String aPubDate) {
Date pubDate = null;
BigDecimal price = null;
try {
price = new BigDecimal(aPrice);
}catch (Exception ex) {
log.throwing(this.getClass().getName(), "book", ex);
}
try {
pubDate = dateFormat.parse(aPubDate);
}catch (Exception ex) {
log.throwing(this.getClass().getName(), "book", ex);
}
return new Book("" + (count++), title, description, price, pubDate);
}
Info about throwing http://docs.oracle.com/javase/6/docs/api/java/util/logging/Logger.html#throwing(java.lang.String, java.lang.String, java.lang.Throwable)
package com.bookstore;
...
import java.util.logging.Level;
import java.util.logging.Logger;
...
@ApplicationScoped @JDBC
public class BookRepositoryJDBCImpl implements BookRepository {
private transient Logger log = Logger.getLogger(Book.class.getName());
...
private <T> T withDB(JDBCRunner<T> runner) {
log.entering("BookRepositoryJDBCImpl", "withDB");
Connection connection = null;
try {
connection = dataSource.getConnection();
boolean auto = connection.getAutoCommit();
connection.setAutoCommit(false);
T result = runner.run(connection);
log.finest("about to commit");
connection.commit();
log.finest("committed");
connection.setAutoCommit(auto); //set it to what it was previously.
log.exiting("BookRepositoryJDBCImpl", "withDB");
return result;
}catch (Exception ex) {
log.log(Level.WARNING, "Transaction did not succeed", ex);
try {
log.finest("About to rollback transaction");
connection.rollback();
} catch (SQLException e) {
log.log(Level.WARNING, "Unable to rollback", ex);
}
throw new BookStoreException(ex);
} finally {
if (connection!=null) {
try {
connection.close();
} catch (Exception ex) {
log.log(Level.WARNING, "Unable to cleanup", ex);
}
}
}
}
}
http://docs.oracle.com/javase/6/docs/api/java/util/logging/Logger.html#exiting(java.lang.String, java.lang.String) http://docs.oracle.com/javase/6/docs/api/java/util/logging/Logger.html#entering(java.lang.String, java.lang.String, java.lang.Object[])
public class BookRepositoryJDBCImpl implements BookRepository {
private transient Logger log = Logger.getLogger(Book.class.getName());
...
@Override
public void updateBook(final String id, final String title, final String description,
final String price, final String pubDate) {
if (log.isLoggable(Level.FINER)) {
log.entering(this.getClass().getName(), "updateBook", new Object[]{id, title, description, price, pubDate});
}
withDB(new JDBCRunner<Book>(){
@Override
public Book run(Connection connection) throws Exception {
PreparedStatement prepareStatement = connection.prepareStatement("update book set title=?, " +
"description=?, price=?, pubdate=? where id = ?");
prepareStatement.setString(1, title);
prepareStatement.setString(2, description);
prepareStatement.setBigDecimal(3, new BigDecimal(price));
Calendar calendar = Calendar.getInstance();
calendar.setTime(dateFormat.parse(pubDate));
prepareStatement.setDate(4, new Date(calendar.getTimeInMillis()));
prepareStatement.setLong(5, Long.parseLong(id));
int rowCount = prepareStatement.executeUpdate();
if (rowCount!=1) {
throw new BookStoreException("Unable to update book into bookstore");
}
return null;
}});
if (log.isLoggable(Level.FINER)) {
log.exiting(this.getClass().getName(), "updateBook", new Object[]{id, title, description, price, pubDate});
}
}
Not so nice, too much duplicate names.
format="${log.level}, ${log.name}, ${log.shortName}, ${log.message}, ${log.sourceClassName}, ${log.sourceMethodName}, ${log.thrown}
[12-05-09 22:45:01.521], INFO, com.caucho.server.webapp.WebApp, WebApp, WebApp[production/webapp/admin.resin/ROOT] stopping, com.caucho.lifecycle.Lifecycle, toStopping, [12-05-09 22:37:56.811], FINER, com.bookstore.BookRepositoryJDBCImpl, BookRepositoryJDBCImpl, ENTRY, BookRepositoryJDBCImpl, withDB,
Log Levels and formatting
Better but still ugly
format="${log.level}, ${log.shortName}, ${log.message}, ${log.sourceClassName}, ${log.sourceMethodName}, ${log.thrown}"
[12-05-09 22:50:55.074]FINEST, BookRepositoryJDBCImpl, committed, com.bookstore.BookRepositoryJDBCImpl, withDB, , [12-05-09 22:50:55.074]FINER, BookRepositoryJDBCImpl, RETURN, BookRepositoryJDBCImpl, withDB, ,
Not so great for production but good for debugging and development
<log-handler name="" level="all" path="stdout:"
timestamp="[%y-%m-%d %H:%M:%S.%s]"
format="${fmt.sprintf('%-7s %-12s %-12s msg=%45s %s',log.level,log.shortName,log.sourceMethodName,log.message,log.thrown ? log.thrown : '')}"/>
[12-05-09 23:01:21.535]FINER BookRepositoryJDBCImpl withDB msg= ENTRY [12-05-09 23:01:21.681]FINEST BookRepositoryJDBCImpl withDB msg= about to commit [12-05-09 23:01:21.681]FINEST BookRepositoryJDBCImpl withDB msg= committed [12-05-09 23:01:21.681]FINER BookRepositoryJDBCImpl withDB msg= RETURN [12-05-09 23:01:23.550]FINER BookRepositoryJDBCImpl withDB msg= ENTRY [12-05-09 23:01:23.560]FINEST BookRepositoryJDBCImpl withDB msg= about to commit [12-05-09 23:01:23.561]FINEST BookRepositoryJDBCImpl withDB msg= committed [12-05-09 23:01:23.561]FINER BookRepositoryJDBCImpl withDB msg= RETURN [12-05-09 23:01:26.750]FINER BookRepositoryJDBCImpl updateBook msg= ENTRY 6 Vampire Diaries 22 05/05/1945 [12-05-09 23:01:26.751]FINER BookRepositoryJDBCImpl withDB msg= ENTRY [12-05-09 23:01:26.754]FINEST BookRepositoryJDBCImpl withDB msg= about to commit [12-05-09 23:01:26.755]FINEST BookRepositoryJDBCImpl withDB msg= committed [12-05-09 23:01:26.755]FINER BookRepositoryJDBCImpl withDB msg= RETURN [12-05-09 23:01:26.755]FINER BookRepositoryJDBCImpl updateBook msg= RETURN [Ljava.lang.Object;@549b6976
Logging methods for important classes without tons of boiler plate code
problem too much boiler plate code
@Override
public void updateBook(final String id, final String title, final String description,
final String price, final String pubDate) {
if (log.isLoggable(Level.FINER)) {
log.entering(this.getClass().getName(), "updateBook", new Object[]{id, title, description, price, pubDate});
}
//do stuff
if (log.isLoggable(Level.FINER)) {
log.exiting(this.getClass().getName(), "updateBook", new Object[]{id, title, description, price, pubDate});
}
}
A lot of code.... too much for basic trace logging.
background http://java.dzone.com/articles/cdi-aop
package com.bookstore;
import java.lang.annotation.Retention;
import java.lang.annotation.Target;
import static java.lang.annotation.ElementType.*;
import static java.lang.annotation.RetentionPolicy.*;
import javax.interceptor.InterceptorBinding;
@InterceptorBinding
@Retention(RUNTIME) @Target({TYPE, METHOD})
public @interface Debuggable {
}
package com.bookstore;
...
@ApplicationScoped @JDBC @Debuggable
public class BookRepositoryJDBCImpl implements BookRepository {
...
package com.bookstore;
import java.util.logging.Level;
import java.util.logging.Logger;
import javax.interceptor.AroundInvoke;
import javax.interceptor.Interceptor;
import javax.interceptor.InvocationContext;
@Debuggable @Interceptor
public class LoggingAdvice {
@AroundInvoke
public Object checkSecurity(InvocationContext joinPoint) throws Exception {
String methodName = joinPoint.getMethod().getName();
String className = joinPoint.getTarget().getClass().getName();
Object[] parameters = joinPoint.getParameters();
/*Find logger*/
Logger log = Logger.getLogger(className);
/* Only debug if not FINEST */
if (!log.isLoggable(Level.FINEST)) {
return joinPoint.proceed();
}
log.entering(className, methodName, parameters);
Object returnObject = joinPoint.proceed();
log.exiting(className, methodName, parameters);
return returnObject;
}
}
<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://java.sun.com/xml/ns/javaee"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="http://java.sun.com/xml/ns/javaee http://java.sun.com/xml/ns/javaee/beans_1_0.xsd">
<interceptors>
<class>com.bookstore.LoggingAdvice</class>
</interceptors>
</beans>
