Introduction

IBM® WebSphere® Studio Application Developer 5.0 (hereafter called Application Developer) provides logging facilities for plug-in developers to log and trace important events, primarily expected or unexpected errors. Log files are a crucial part of the Application Developer problem determination process. This article describes the log files, tells you where to find them, and uses examples to show you how to use them.

Back to top

When to use log files

The only reason use log files is if you encounter unexpected program behaviour. In some cases, an error message tells you explicitly to look at the error log:

Unfortunately, the error is not always so explicit. Sometimes your application crashes your system or hangs, and sometimes it simply gives unexpected results without any outward signs. In these cases, the log files may contain information that can speed up the problem determination process.

Back to top

Log file characteristics

There are two main log files: .log and LoggingUtil.log .

The .log file is provided and maintained by WebSphere Studio Workbench (which is based on the open source Eclipse infrastructure). The Workbench uses the .log file to capture Eclipse notifications, errors, and any uncaught exceptions from Application Developer plug-ins.

The LoggingUtil.log file is provided by the Application-Developer-specific tools (a set of plug-ins added on top of WebSphere Studio Workbench). The Application Developer plug-ins use LoggingUtil.log to log various events, errors, and caught exceptions through a logging API.

Both the .log and LoggingUtil.log files are located in the <workspace>\.metadata directory. They are ASCII files, easily read with any text editor.

In Application Developer the .log file is cumulative in its behaviour -- each new session of Application Developer appends its messages to the end of the .log file without deleting any previous messages. This enables you to see a history of past messages over multiple Application Developer sessions, each one starting with the !SESSION string.

On the other hand, a new LoggingUtil.log file is created each time Application Developer is started. The previous LoggingUtil.log file is renamed and saved by appending a unique string such as a timestamp to its filename. At any given time, the <workspace>\.metadata directory contains one .log file, one LoggingUtil.log and possibly some additional LoggingUtil.log.* files from previous Application Developer sessions.

Events in the log files are recorded by appending to the end of the file, so the files are in chronological order, with the oldest event at the beginning of the file and the most recent event at the end.

Back to top

Examples of log file content, interpretation, and use

Example using the .log file

This example concerns a situation encountered in Application Developer 4.0.3. I finished editing my EJB project, rebuilt it without errors, and tried to export it into a JAR file to send it to a colleague to test. However, I got a JAR Export Error with a message box that reads Creation of JAR Failed -- Invalid Thread Access . Knowing about the log files, I look in the .log file and see the following trace:

........ 
4 org.eclipse.jdt.ui 566 Creation of JAR failed 
org.eclipse.swt.SWTException: Invalid thread access 
    at org.eclipse.swt.SWT.error(SWT.java:1708) 
    at org.eclipse.swt.SWT.error(SWT.java:1642) 
    at org.eclipse.swt.widgets.Widget.error(Widget.java:368)
    at org.eclipse.swt.widgets.Widget.checkWidget(Widget.java(CompiledCode))
    at org.eclipse.swt.widgets.Widget.getData(Widget.java(CompiledCode))
    at org.eclipse.ui.part.MultiPageEditorPart.getEditor(MultiPageEditorPart.java:265)
    at org.eclipse.ui.part.MultiPageEditorPart.isDirty(MultiPageEditorPart.java:365)
    at org.eclipse.jdt.internal.ui.JavaPlugin.getDirtyEditors(JavaPlugin.java:154)
    at  org.eclipse.jdt.internal.ui.jarpackager.JarFileExportOperation.preconditionsOK
          (JarFileExportOperation.java:484) 
    at org.eclipse.jdt.internal.ui.jarpackager.JarFileExportOperation.singleRun
          (JarFileExportOperation.java:640) 
    at org.eclipse.jdt.internal.ui.jarpackager.JarFileExportOperation.run
          (JarFileExportOperation.java:558) 
    at org.eclipse.jface.operation.ModalContext$ModalContextThread.run
          (ModalContext.java:98) 
.........

In contrast to the overall .log file, the stack traces within it go in reverse chronological order, with the most recent event at the top of the stack trace and the oldest event at the bottom. Thus, in the above trace, the routine org.eclipse.swt.widgets.Widget.checkWidget() , which is compiled code and has no information about source line numbers, calls org.eclipse.swt.widgets.Widget.error() , which is a Java™ method located in Widget.java at line 368, and so on.

Interestingly, the above log seems to indicate that the exception occurred in an editor ( org.eclipse.ui.part.MultiPageEditorPart ), even though I wasn't editing anymore and was trying to export to a JAR file. Based on this information, and since I don't need an editor to do the export, I can close all the editors, retry the export, and see if the exception goes away because no editors are open. This is indeed what happens!

This means two things: I have found a workaround that lets me continue my work, and I have probably found a bug in an Application Developer editor. Since the workaround is inconvenient, I report the problem to IBM Support. The log file and the workaround I found should help them quickly diagnose the exact source of the problem and get a fix in place.

Example using the LoggingUtil.log file

A second example was encountered using Application Developer 5.0 Early Availability. After importing a few tables from a database and activating an EJB bottom-up mapping, I found that no EJBs where created and no error messages were shown on the screen. The LoggingUtil.log file showed the following trace:

<String logging.util.agent_idref="AGENT_CREATE.com.ibm.etools.j2ee.1036797332.22"
logging.util.MsgLoggerLevel="SEVERE"Value="*** ERROR *** Fri Nov08  17:16:27   CST 2002
caller: at  com.ibm.etools.ejbrdbmapping.command.CreateBottomUpMappingCommand.
      execute(CreateBottomUpMappingCommand.java:192)java.lang.NullPointerException
   at com.ibm.etools.ejbrdbmapping.domain.EJBRDBMappingPluginAdapterDomain.
      addAttributeCommand(EJBRDBMappingPluginAdapterDomain.java:214)
   at com.ibm.etools.ejbrdbmapping.command.InitializeCMPAttributeCommand.copyObject
      (InitializeCMPAttributeCommand.java:144)
   at com.ibm.etools.ejbrdbmapping.command.InitializeEjbCopyOverrideCommand.execute
      (InitializeEjbCopyOverrideCommand.java:308)
   at com.ibm.etools.emf.edit.command.AbstractOverrideableCommand.execute
      (AbstractOverrideableCommand.java:122)
   at com.ibm.etools.common.command.CompoundCommand.execute
      (CompoundCommand.java:228)
   at com.ibm.etools.common.command.StrictCompoundCommand.execute
      (StrictCompoundCommand.java:279)
   at com.ibm.etools.emf.edit.command.CopyCommand.execute
      (CopyCommand.java:196)
   at com.ibm.etools.emf.edit.command.DragAndDropCommand.execute
      (DragAndDropCommand.java:779)
   at com.ibm.etools.ejbrdbmapping.command.BottomUpDatabaseCommand.mapTable
      (BottomUpDatabaseCommand.java:231)
   at com.ibm.etools.ejbrdbmapping.command.BottomUpDatabaseCommand.mapTables
      (BottomUpDatabaseCommand.java:192)
   at com.ibm.etools.ejbrdbmapping.command.BottomUpDatabaseCommand.execute
      (BottomUpDatabaseCommand.java:409)
   at com.ibm.etools.j2ee.workbench.ParentCommand.execute
      (ParentCommand.java:69)
   at com.ibm.etools.ejbrdbmapping.command.EjbRdbMappingPersistentCommandStack.
      superSuperExecute(EjbRdbMappingPersistentCommandStack.java:705)
   at com.ibm.etools.ejbrdbmapping.command.WrappingEjbRdbMappingPersistentCommandStack.
      execute(WrappingEjbRdbMappingPersistentCommandStack.java:58)
   at com.ibm.etools.ejbrdbmapping.command.CreateBottomUpMappingCommand.mapTables
      (CreateBottomUpMappingCommand.java:532)
   at com.ibm.etools.ejbrdbmapping.command.CreateBottomUpMappingCommand.execute
      (CreateBottomUpMappingCommand.java:188)
   at com.ibm.etools.common.command.BasicCommandStack.execute
      (BasicCommandStack.java:84)
   at com.ibm.etools.ejb.operations.EjbProgressOperation.execute
      (EjbProgressOperation.java:61)
   at com.ibm.etools.j2ee.operations.HeadlessJ2EEOperation$1.run
      (HeadlessJ2EEOperation.java:73)
   at org.eclipse.core.internal.resources.Workspace.run
      (Workspace.java:1378)
   at com.ibm.etools.j2ee.operations.HeadlessJ2EEOperation.run
      (HeadlessJ2EEOperation.java:87)
   at com.ibm.etools.j2ee.common.ui.RunnableWithProgressWrapper.run
      (RunnableWithProgressWrapper.java:57)
   at org.eclipse.jface.operation.ModalContext.runInCurrentThread
      (ModalContext.java:299)
   at org.eclipse.jface.operation.ModalContext.run(ModalContext.java:249)
   at org.eclipse.jface.wizard.WizardDialog.run(WizardDialog.java:720)
   at com.ibm.etools.ejbrdbmapping.presentation.MappingWizard.performFinish
      (MappingWizard.java:525)
   at org.eclipse.jface.wizard.WizardDialog.finishPressed(WizardDialog.java:577)
   at org.eclipse.jface.wizard.WizardDialog.buttonPressed(WizardDialog.java:312)
   at org.eclipse.jface.dialogs.Dialog$1.widgetSelected(Dialog.java:398)
   at org.eclipse.swt.widgets.TypedListener.handleEvent(TypedListener.java:87)
   at org.eclipse.swt.widgets.EventTable.sendEvent(EventTable.java(CompiledCode))
   at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:827)
   at org.eclipse.swt.widgets.Display.runDeferredEvents(Display.java:1529
   at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:1291)
   at org.eclipse.jface.window.Window.runEventLoop(Window.java:562)
   at org.eclipse.jface.window.Window.open(Window.java:542)
   at com.ibm.etools.ejbrdbmapping.action.CreateMappingAction.
      createAndOpenWizardDialog(CreateMappingAction.java:78)
   at com.ibm.etools.ejbrdbmapping.action.CreateMappingAction.run
      (CreateMappingAction.java:130)
   at org.eclipse.ui.internal.PluginAction.runWithEvent
      (PluginAction.java:210)
   at org.eclipse.jface.action.ActionContributionItem.handleWidgetSelection
      (ActionContributionItem.java:407)
   at org.eclipse.jface.action.ActionContributionItem.handleWidgetEvent
      (ActionContributionItem.java:361)
   at org.eclipse.jface.action.ActionContributionItem.access$0
      (ActionContributionItem.java:352)
   at org.eclipse.jface.action.ActionContributionItem$ActionListener.handleEvent
      (ActionContributionItem.java:47)
   at org.eclipse.swt.widgets.EventTable.sendEvent
      (EventTable.java(CompiledCode))
   at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:827)
   at org.eclipse.swt.widgets.Display.runDeferredEvents(Display.java:1529)
   at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:1291)
   at org.eclipse.ui.internal.Workbench.runEventLoop(Workbench.java:1256)
   at org.eclipse.ui.internal.Workbench.run(Workbench.java:1239)
   at org.eclipse.core.internal.boot.InternalBootLoader.run
      (InternalBootLoader.java:775)
   at org.eclipse.core.boot.BootLoader.run(BootLoader.java:462)
   at java.lang.reflect.Method.invoke(NativeMethod)
   at org.eclipse.core.launcher.Main.basicRun(Main.java:247)
   at org.eclipse.core.launcher.Main.run(Main.java:703)
   at org.eclipse.core.launcher.Main.main(Main.java:539)

Something seems to have gone wrong in the com.ibm.etools.ejbrdbmapping.command.CreateBottomUpMappingCommand.execute() method ( java.lang.NullPointerException at the top of the trace). The method name sounds quite related to what I was doing at the time. In this case, there is no obvious workaround. Based on the java.lang.NullPointerException , it seems that Application Developer wasn't able to handle an unexpected error. I do a Web search for similar problems and notify IBM Support, so that this trace can help them diagnose the problem and get a fix in place.

Back to top

Best practices

In order to isolate all problem information in the .log file, the best approach is to shut down Application Developer, delete the cumulative .log file, restart Application Developer, reproduce the problem, and then once again shut down Application Developer. This way the entries in the .log file apply only to the current session, making the problem easier to isolate. Also, shutting down Application Developer ensures that the entire log buffer will be flushed to the .log file.

When looking for problems in .log files, it's often helpful to search on the string exception . Of course, not all exceptions are signs of irrecoverable errors. As mentioned above in the section When to use log files , you need to pay attention to .log files only in case of unexpected program behaviour.

You also need to be familiar with the concept of nested exceptions. which occur when an exception triggers another exception and possibly a chain of exceptions. In nested exceptions, you need to focus on the first (earliest) exception in the chain, since it is the root cause of the error. The other exceptions are caused by poor handling of the first unexpected error.

Back to top

Conclusion

Knowing how to interpret the contents of the Application Developer .log files can help you find temporary workarounds for unexpected program behaviour, and can also enable you to supply critical information to IBM Support to help them diagnose the problem and get a fix in place.

Acknowledgement

The authors wish to thank Angel Vera, Staff Software Developer, IBM Toronto Lab, for reviewing this article. IBM and WebSphere are trademarks or registered trademarks of IBM Corporation in the United States, other countries, or both. Java and all Java-based trademarks and logos are trademarks or registered trademarks of Sun Microsystems, Inc. in the United States, other countries, or both. Other company, product, and service names may be trademarks or service marks of others. IBM copyright and trademark information

About the authors

Comments (Undergoing maintenance)

Back to top

Trademarks  |  My developerWorks terms and conditions

Table of contents

• Introduction
• When to use log files
• Log file characteristics
• Examples of log file content, interpretation, and use
• Best practices
• Conclusion
• About the authors
• Comments

Local resources

• IBM Innovation Center - Austin, TX
• IBM Innovation Center - Chicago, IL
• IBM Innovation Center - Dallas, TX
• IBM Innovation Center - San Mateo, CA
• IBM Innovation Center - Waltham, MA
• Technical Briefings in North America

My developerWorks community

Dig deeper into WebSphere on developerWorks

Rate a product. Write a review.

Write a review for Rational products today!

Special offers