Wicket’s RequestLogger

Wicket provides you with a build-in request logger. It can give you a lot of information. See also example below. To activate this logger you have to enable the logger and setup (in our case) some Log4j configuration. In this post I’ll show you how to get this done.


The example below shows you how to enable the requestLogger when the application is started in “Development” mode.

//Check if we are not in deployment mode.
if (!DEPLOYMENT.equalsIgnoreCase(getConfigurationType())) {
  
  //Get the logger
  IRequestLoggerSettings reqLogger = Application.get().getRequestLoggerSettings();
  
  //Enable the logger
  reqLogger.setRequestLoggerEnabled(true);

  /**
  * Set the window of all the requests that is kept in memory for viewing. Default is 2000, You
  * can set this to 0 then only Sessions data is recorded (number of request, total time, latest
  * size)
  */
  reqLogger.setRequestsWindowSize(3000);
}

If you want to log everything to a specific rolling file you can add the following lines to your log4j.properties file. It will create a file for you with a max. size of 10MB. All Wicket requests will be logged into this file and not in the ‘general’ log.

log4j.category.org.apache.wicket.protocol.http.RequestLogger = info,reqLogger
log4j.additivity.org.apache.wicket.protocol.http.RequestLogger=false
log4j.appender.reqLogger=org.apache.log4j.RollingFileAppender
log4j.appender.reqLogger.File=D:/logs/wicketRequestLogger.txt
log4j.appender.reqLogger.MaxFileSize=10MB
log4j.appender.reqLogger.MaxBackupIndex=10
log4j.appender.reqLogger.layout=org.apache.log4j.PatternLayout
log4j.appender.reqLogger.layout.ConversionPattern=%d %-5p - %-26.26c{1} - %m\n

Example logging:
2009-04-08 16:18:32,878 INFO – RequestLogger-
time=687,
event=Interface[target:Login$LoginForm(bodyTag:loginForm),
page: eu.company.desktop.wicket.ui.login.Login(0),
interface: IFormSubmitListener.onFormSubmitted],
response=org.apache.wicket.request.target.basic.RedirectRequestTarget@1c82b58,
sessionid=C488C8A534D1D853FD1F7A80C5647A52.jvm1,
sessionsize=16239,
sessionstart=Wed Apr 08 14:18:23 GMT 2009,
requests=12,
totaltime=3499,
activerequests=1,
maxmem=532M,
total=163M,
used=93M

That’s it.

Disclaimer: The requestLogger is very powerfull. I just started experimenting with it, so I don’t know all ins and outs yet. 😉

8 comments to Wicket’s RequestLogger

  • Hi Stefan,

    I am also experimenting with the Wicket RequestLogger, triggered by the presentation of Martijn on the Wicket Meetup.

    A few days ago I mailed Martijn if the code for analyzing this logfile is somewhere online. Unfortunately, this isn’t the case.

    Are you guys going to invest time in writing a log file analyzer for Wicket logs? Maybe we can collaborate on that?

    Regards,

    Daan

  • We didn’t plan to do that (yet). Currently we are very busy with a release. I was also thinking to send Martijn a mail. It’s a pitty that it is not open source, because it looked very nice in his presentation.

  • Daan,

    Have you already seen the InspectorBug class? (wicket.examples.debug package) I couldn’t found a demo if this functionallity but I am very curious what it exactly does.

    Regards,
    Stefan

  • Yeah, I have seen the InspectorBug class too. I am building a separate wicket-examples jar (it’s a war now) to check how it works.

    – Daan

  • Avner Linder

    Hi,
    I’ve tried activating the RequestLogger and in many cases duplicate entries appear at the log file for the same request, for example:

    2009-07-26 15:00:32,224 INFO - RequestLogger - time=796,event=null,response=[ResourceStreamRequestTarget[resourceStream=org.apache.wicket.markup.html.DynamicWebResource$1@137937,fileName=null],sessionid=11jxsgdnkz6c4,sessionsize=54608,sessionstart=Sun Jul 26 15:00:26 IDT 2009,requests=7,totaltime=4789,activerequests=1,maxmem=66M,total=32M,used=19M
    2009-07-26 15:00:32,239 INFO - RequestLogger - time=796,event=null,response=[ResourceStreamRequestTarget[resourceStream=org.apache.wicket.markup.html.DynamicWebResource$1@1e8c1ec,fileName=null],sessionid=11jxsgdnkz6c4,sessionsize=54608,sessionstart=Sun Jul 26 15:00:26 IDT 2009,requests=8,totaltime=5585,activerequests=2,maxmem=66M,total=32M,used=19M

    I inspected the call-hierarchy of IRequestLogger.logResponseTarget and found out that it is being called twice by Wicket framework, once for each of the steps: PROCESS_EVENTS and RESPOND


    logResponseTarget(IRequestTarget) - org.apache.wicket.protocol.http.WebApplication
    respond(RequestCycle) - org.apache.wicket.request.AbstractRequestCycleProcessor
    processEventsAndRespond() - org.apache.wicket.RequestCycle
    step() - org.apache.wicket.RequestCycle
    respond() - org.apache.wicket.RequestCycle
    step() - org.apache.wicket.RequestCycle

    any ideas how to prevent the duplicate log entries?

    I plan to extend the default RequestLogger, and then I could log events only at one of the steps.
    However, the RequestLogger doesn’t have access to the RequestCylce.currentStep

    any ideas?

    Avner

  • Avner Linder

    Here’s the call-hierarchy again (copied from eclipse), this time more readable (i hope):

    logResponseTarget(IRequestTarget) - org.apache.wicket.protocol.http.WebApplication
    respond(RequestCycle) - org.apache.wicket.request.AbstractRequestCycleProcessor
    processEventsAndRespond() - org.apache.wicket.RequestCycle
    step() - org.apache.wicket.RequestCycle
    respond() - org.apache.wicket.RequestCycle
    step() - org.apache.wicket.RequestCycle

    You can see that respond() is the only caller of logResponseTarget().
    You can also see that respond() is being called twice from the step() method, once for each step.

  • Hmm I don’t know. Anyone else?

  • Verhage

    Use additivity=false in your log4j.xml.

    Bet you’ve configured some loggers up in the hierarchy along org.apache.wicket.

Leave a Reply

 

 

 

You can use these HTML tags

<a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <s> <strike> <strong>