Logging in Web Dynpro (Java) – a guide and tutorial for beginners [Part 1]

Logging is very crucial thing for application developing and when you are starting with Web Dynpro&Netweaver it’s a valuable activity to watch what’s going on under the hood of your application. But to do this you must get through a lot of pages on i.e. help.sap.com. Of course it is necessary if you want to know how it is exactly working, but if you are beginner you just want to quickly start loging some helpful messages and probably you’re asking yourself ‘where the hell are my logs in this Netweaver??’.

So, this guide will let you start with logging. When you’ll be ready for more details, go here:

1. help.sap.com – logging and tracing.
2. Help in NWDS.
3. Log Configuration for a Web Dynpro application – blog article by Pran Bhas
4. Search SDN – blogs, articles, wiki, forums…

First thing – in Netweaver we distinguish between logging and tracing. Logging is mainly for administrators and log messages are emitted by Category objects. Categories corresponds to administration task areas, for example /System /System/Database etc. and are shared between multiple applications. Tracing is for developers and support staff – trace messages contain program flow and are emitted by Location objects, which refer to certain point in a coding (Location is identified by package/class or function name).

So, in the title of this weblog I used “logging” in the meaning “writing some usefull information to file or console” :). In Netweaver’s terms, this article is about tracing.

1. Basic tracing.

Ok, let’s start. I created simple Web Dynpro project (LoggingTest) in NWDS with one component (TestComp), one view (TestCompView), one window and one app to run my component. All these things I putted in package jwozniczak.log.test. In component controller I added one method doWork and one context attribute finishedStatus (type string). This attribute is mapped to view and binded to TextView. When doWork finishes processing, it will set it’s value and display it in view. Stupid and simple, but all we want is to add some useful code for logging.

Ok, switch to the impelmentation tab for component controller in NWDS.  Look in the code right after public class TestComp… statement – you’ll find a static variable for  Location object.

This Location object logs messages to default traces file. We will use this Location, but we want to have separte file four our messages. This is because default trace files have a lot stuff that don’t interest us – we just want to watch our messages.

We will hardcode log configuration in code – this is only for learning purposes! More about external log configuration in next parts.

So, we’ve got our Location object, but must add a new FileLog to it. On the implementation of the TestComp scroll down to the bottom with lines

//@@begin others

//@@end

Here we can add our custom code for log initialization:

//@@begin others
static {
try {

/* Adding file log to the ocation */
logger.addLog(new FileLog(“./log/testcomp.trc”,”UTF-8″, 1000000,

1, new TraceFormatter()));
} catch (UnsupportedEncodingException e) {
 e.printStackTrace();
}
}
//@@end

What we’re doing – for our location (logger) we’re adding new file log with specified path and name, encoding, limited to  1000000 bytes, with count set to 1 (so there will be only one file) and lastly we’re setting a TraceFormater which (default) prints messages in format: date location thread severity message. This code registers a new destination for our Location but doesn’t remove any other destinations! So in our case messages will be written to default trace and our new trace file.

Now let’s add some trace messages in doWork method.

1. First thing is to set effective severity of your logger (default is none, so no messages will be printed).
2. Use simple method for severity of your message – debugT(String), infoT(String), pathT(String), errorT(String) and so on – for each severity type you have method with name severityT(String).

So assuming you want to print some info message, you’ll must add a code like this:

  //@@begin javadoc:doWork()
  /** Declared method. */
  //@@end
  public void doWork( )
  {
    //@@begin doWork()
    
    /* We want to print messages with any severity */
    logger.setEffectiveSeverity(Severity.ALL);
    
    /* Emit message */
    logger.infoT("This is info message.");
    
    wdContext.currentContextElement().setFinishedStatus("doWork finished!");
    //@@end
  }

Now we must ensure that our method with trace message will be called so add code  to wDoInit method of TestCompView (each time when view will be initiated our message will be emitted).

//@@begin javadoc:wdDoInit()
/** Hook method called to initialize controller. */
//@@end
public void wdDoInit()
{
  //@@begin wdDoInit()
  wdThis.wdGetTestCompController().doWork();
  //@@end
}

Build, deploy project and run it. Fast way for running Web dynpro application is to use dispatcher via url address. For example for my local project (LoggingTest) with application TestApp I’ll use (remember to use your port number and log to the Portal first ):

http://myhost:50000/webdynpro/dispatcher/local/LoggingTest/TestApp

If you create your project as a Development Component Web Dynpro, use this pattern:

http://myhost:50000/webdynpro/dispatcher/vendor_name/dc_name/TestApp

for example:

http://myhost:50000/webdynpro/dispatcher/jwozniczak/log_test/TestApp

Now we can go to see our trace message. There is a several methods to view trace file, we will use “Log and File Viewer” servlet. You can access it directly via address:

http://myhost:50000/irj/servlet/prt/portal/prtroot/com.sap.portal.runtime.admin.logviewer.default

Warning! You must be logged in to Portal (use http://myhost:50000/irj for example)!

Here you can view trace files directly. As you see there is a lot of files listed here, all from a folder displayed in a bar “Files in folder…”. You can enter a different path or  browse to another directory, but this is not necessery for us. Scroll down, find our trace file testcomp.0.trc and view it.

Feb 2, 2010 4:47:34 PM               jwozniczak.log.test.TestComp
[SAPEngine_Application_Thread[impl:3]_8] Info: This is info message

Here is our message, formatted by TraceFormatter – date, location, thread, severity, message.

You can also use search form for finding messages.

But what to search? You can enter a part of message content but propably better thing is to search by location. As I said earlier location is identified by package and class name, so let’s enter our class name where we emitted the trace message – TestComp. In my case trace message was found in our file testcomp.0.trc and defaultTrace.6.trc – this is because our Location object have configured this file as a destination and because we’ve added a new file log, it does not mean that we’ve removed any existing.

2. Step forward – customizing formatter and path tracing.

Ok, we have our trace messages but we want them in simpler format. We can achieve this by customizing TraceFormatter object. Let’s add a new trace file with a new formatter, which will print messages in form date location message. Go to the implementation tab of component controller and modify file log initialization code.

//@@begin others
static {
try {

  /* Adding log to location */
  logger.addLog(
    new FileLog(
    "./log/testcomp-simple.trc",
    "UTF-8",
    1000000,
    1,
    new TraceFormatter("%24d %l %m")));
  } catch (UnsupportedEncodingException e) {
   e.printStackTrace();
  }
}
//@@end

Hint – check logging API for more TraceFormatter pattern placeholders.

Now, run TestApp and go to the Log Viewer servlet, find testcomp-simple.0.trc (refresh page or click Browse and then Select if you don’t see it) and view it. You should see our message in this form:

Feb 3, 2010 9:57:38 AM   jwozniczak.log.test.TestComp This is info message

Now we want to trace when our method starts and when it ends. There are dedicated methods in Netweaver’s logging API for this so let’s use it. Go to doWork() implementation and modify it in the following way:

//@@begin javadoc:doWork()
/** Declared method. */
//@@end
public void doWork( )
{
  //@@begin doWork()
  String method = "doWork()";

  /* Set severity, default is none */
  logger.setEffectiveSeverity(Severity.ALL);

  /* Entering method... */
  logger.entering(method);

  /* Print info */
  logger.infoT("This is info message");

  wdContext.currentContextElement().setFinishedStatus("doWork finished!");

  /* Method finished */
  logger.exiting(method);
//@@end
}

Run TestApp again and view testcomp-simple.0.trc file. It should looks like this:

[ header stuff... ]
Feb 3, 2010 9:57:38 AM jwozniczak.log.test.TestComp This is info message
Feb 3, 2010 10:17:56 AM jwozniczak.log.test.TestComp.doWork() Entering method
Feb 3, 2010 10:17:56 AM jwozniczak.log.test.TestComp This is info message
Feb 3, 2010 10:17:56 AM jwozniczak.log.test.TestComp.doWork() Exiting method

Three new trace messages were appended to our existing trace file and we see when the method was started and when it finished work. Hint – if you need more precise times, use %p (timestamp)instead of %24d when creating TraceFormatter.

3. One FileLog for many classes.

Assume that we want to add some trace messages in TestView (and probably in every next view and controller if we’ll create them…). Adding our code for file log initialization in each class is not a good design and not a comfortable job. But there is a very nice and helpful feature – Location name. As I said earlier locations are named according to the known hierarchical structure from the Java packages and they inherit log properties. Our logger object from TestComp is created in this way:

private static final com.sap.tc.logging.Location logger = 
com.sap.tc.logging.Location.getLocation(TestComp.class);

TestComp class is in jwozniczak.test package, so our Location name is jwozniczak.test.TestComp. Our view is also located in jwozniczak.test package and if you look near class definition, you’ll find code like this:

private static final com.sap.tc.logging.Location logger = 
com.sap.tc.logging.Location.getLocation(TestCompView.class);

Similar as in TestComp – here we’ve got Location object named jwozniczak.test.TestCompView. So, for these two location objects we need a location on higher level in package structure, for example “jwozniczak” and both locations will inherit settings from this new controller. We will initialize it only once – go to the TestComp implementation, scroll down to //@@begin … //@@end section and write this code:

//@@begin others
static {
  Location myLogger = Location.getLocation("jwozniczak");
  try {
    myLogger.addLog(
    new FileLog(
      "./log/commontrace.trc",
      "UTF-8",
      1000000,
      1,
      new TraceFormatter()));
  } catch (UnsupportedEncodingException e) {
    e.printStackTrace();
  }
}
//@@end

Ok, our new location logger is ready and we won’t use it for logging – its settings will be used for loggers that already exists in our classess. First, go to wDoInit in TestComp and add this code:

//@@begin wdDoInit()
logger.setEffectiveSeverity(Severity.ALL);
logger.infoT("Inside TestComp class...");
//@@end

Now, go to the TestCompView implementation, to wDoInit method. Remove the line where we call doWork method and add this code only:

//@@begin
logger.setEffectiveSeverity(Severity.ALL);
logger.infoT("Inside TestView class...");
//@@end

Ok, run TestApp and go to the Log and File view servlet (refresh it ifneeded). You should find our new file common.0.trc:

which contains messages like this:

Feb 4, 2010 3:55:58 PM jwozniczak.log.test.wdp.InternalTestComp entering: wdDoInit
Feb 4, 2010 3:55:58 PM jwozniczak.log.test.TestComp Inside TestComp class…
Feb 4, 2010 3:55:58 PM jwozniczak.log.test.wdp.InternalTestComp exiting: wdDoInit
Feb 4, 2010 3:55:58 PM jwozniczak.log.test.wdp.InternalTestCompView entering: wdDoInit
Feb 4, 2010 3:55:58 PM jwozniczak.log.test.TestCompView Inside TestView class…
Feb 4, 2010 3:55:58 PM jwozniczak.log.test.wdp.InternalTestCompView exiting: wdDoInit
Feb 4, 2010 3:55:58 PM jwozniczak.log.test.wdp.InternalTestCompWindowInterfaceView entering: wdDoInit
Feb 4, 2010 3:55:58 PM jwozniczak.log.test.wdp.InternalTestCompWindowInterfaceView exiting: wdDoInit
Feb 4, 2010 3:55:58 PM jwozniczak.log.test.wdp.InternalTestCompWindowInterfaceView entering: wdInvokeEventHandler
Feb 4, 2010 3:55:58 PM jwozniczak.log.test.wdp.InternalTestCompWindowInterfaceView exiting: wdInvokeEventHandler
Feb 4, 2010 3:55:58 PM jwozniczak.log.test.wdp.InternalTestComp entering: wdDoBeforeNavigation
Feb 4, 2010 3:55:58 PM jwozniczak.log.test.wdp.InternalTestComp exiting: wdDoBeforeNavigation
Feb 4, 2010 3:55:58 PM jwozniczak.log.test.wdp.InternalTestCompView entering: doModifyView
Feb 4, 2010 3:55:58 PM jwozniczak.log.test.wdp.InternalTestCompView exiting: doModifyView
Feb 4, 2010 3:55:58 PM jwozniczak.log.test.wdp.InternalTestComp entering: wdDoPostProcessing
Feb 4, 2010 3:55:58 PM jwozniczak.log.test.wdp.InternalTestComp exiting: wdDoPostProcessing

As you se we captured our messages from view and component controller, also some internal path messages were also logged.