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.
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.
Log file characteristics
There are two main log files:
file is provided and maintained by WebSphere Studio Workbench (which is based on the open source
infrastructure). The Workbench uses the
file to capture Eclipse notifications, errors, and any uncaught exceptions from Application Developer plug-ins.
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
to log various events, errors, and caught exceptions through a logging API.
files are located in the
directory. They are ASCII files, easily read with any text editor.
In Application Developer the
file is cumulative in its behaviour -- each new session of Application Developer appends its messages to the end of the
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
On the other hand, a new
file is created each time Application Developer is started. The previous
file is renamed and saved by appending a unique string such as a timestamp to its filename. At any given time, the
directory contains one
and possibly some additional
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.
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
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
file, the stack traces within it go in
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
, which is compiled code and has no information about source line numbers, calls
, which is a Java method located in
at line 368, and so on.
Interestingly, the above log seems to indicate that the exception occurred in an editor (
), 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
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
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
, 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.
In order to isolate all problem information in the
file, the best approach is to shut down Application Developer, delete the cumulative
file, restart Application Developer, reproduce the problem, and then once again shut down Application Developer. This way the entries in the
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
When looking for problems in
files, it's often helpful to search on the string
. 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
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.
Knowing how to interpret the contents of the Application Developer
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.
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