7.5.  Enable diagnostic tracing of WebSphere runtime components.

[Note]

Tracing gives users the ability to review the sequence of events and methods executing at the WebSphere Application Server code level to help determine where problems are occurring so you can diagnose and resolve them. WebSphere Application Server tracing is based on the java.util.logging package.The level of detail of the trace is controlled by the trace string, in which you can specify whether you want to trace a single class file, the entire WebSphere Application Server code library, or any level in between. Here are a couple of examples:

In general, the WebSphere Application Server support team recommends using =all for the trace level. However, there are other options such as =fine, =entry, =debug, and so on. If performance overhead is an issue, then setting a more specific trace specification (down to a single class or component) or a less detailed log level is a good way to ensure the server is minimally impacted.

In WebSphere Application Server V8.0, the default trace string is *=info. The logging level of the SystemOut.log file can be controlled with this setting. For example, if you only want errors in the logs, you might use *=fatal or *=severe. However, if you want as much detail as possible, you might change this to *=detail. The settings *=fine through *=all will produce trace output to a trace.log file.

The log levels defined by WAS

How to enable tracing

WebSphere Application Server tracing can be enabled as follows:

  1. Through the administrative console select Troubleshooting > Logs and trace

    Figure 7.27. 


  2. Click the server name:

    Figure 7.28. 


  3. Click the Change log detail levels link.

    Figure 7.29. 


  4. Specifying the trace settings under the Configuration tab will require a server restart for the tracing to take effect. However, enabling the tracing under the Runtime tab will take effect immediately (which can be very useful for tracing environments such as a production environment, which can rarely afford a server restart). However, it is important to know that after a server restart, the runtime settings are lost unless the Save runtime changes to configuration as well box is checked. Also, runtime traces only report the current system information; if the server is already having issues, enabling runtime traces will not report what caused the problem to begin, only why current actions fail. Therefore, IBM Support recommends that the trace settings be made under the Configuration tab so that server startup can be reviewed and the root cause of the problem can be determined.

    In the Change log detail levels window, you can select from a list of predefined trace strings, or enter your own trace string directly into the entry field, as shown in figure below.

    Figure 7.30. 


    For example, to enable tracing for the Web Container, you would enter *=info: com.ibm.ws.webcontainer=all in the entry field, as shown in figure below:

    Figure 7.31. 


    Save the changes and restart server.

Trace file viewing

If you have HPEL enabled, open trace as follows:

test317:/opt/IBM/WebSphere/AppServer/profiles/AppSrv01/bin # ./logViewer.sh -includeLoggers "com.ibm.ws.webcontainer"

Using /opt/IBM/WebSphere/AppServer/profiles/AppSrv01/logs/server1 as repository directory.
************ Start Display Current Environment ************
WebSphere Platform 8.0.0.4 [ND 8.0.0.4 cf041228.02] running with process name test317Cell01\exampleNode01\server1 and process id 58067
Host Operating System is Linux, version 3.0.34-0.7-default
Java version = 1.6.0, Java Compiler = j9jit26, Java VM name = IBM J9 VM
was.install.root = /opt/IBM/WebSphere/AppServer
user.install.root = /opt/IBM/WebSphere/AppServer/profiles/AppSrv01
Java Home = /opt/IBM/WebSphere/AppServer/java/jre
ws.ext.dirs = /opt/IBM/WebSphere/AppServer/java/lib:/opt/IBM/WebSphere/AppServer/profiles/AppSrv01/classes:/opt/IBM/WebSphere/AppServer/classes:/opt/IBM/WebSphere/AppServer/lib:/opt/IBM/WebSphere/AppServer/installedChannels:/opt/IBM/WebSphere/AppServer/lib/ext:/opt/IBM/WebSphere/AppServer/web/help:/opt/IBM/WebSphere/AppServer/deploytool/itp/plugins/com.ibm.etools.ejbdeploy/runtime
Classpath = /opt/IBM/WebSphere/AppServer/profiles/AppSrv01/properties:/opt/IBM/WebSphere/AppServer/properties:/opt/IBM/WebSphere/AppServer/lib/startup.jar:/opt/IBM/WebSphere/AppServer/lib/bootstrap.jar:/opt/IBM/WebSphere/AppServer/lib/jsf-nls.jar:/opt/IBM/WebSphere/AppServer/lib/lmproxy.jar:/opt/IBM/WebSphere/AppServer/lib/urlprotocols.jar:/opt/IBM/WebSphere/AppServer/deploytool/itp/batchboot.jar:/opt/IBM/WebSphere/AppServer/deploytool/itp/batch2.jar:/opt/IBM/WebSphere/AppServer/java/lib/tools.jar
Java Library path = /opt/IBM/WebSphere/AppServer/lib/native/linux/x86_64/:/opt/IBM/WebSphere/AppServer/java/jre/lib/amd64/default:/opt/IBM/WebSphere/AppServer/java/jre/lib/amd64:/opt/IBM/WebSphere/AppServer/bin:/usr/lib:
Orb Version = IBM Java ORB build orb626ifx-20120410.00 (SR2FP1+191257)
************* End Display Current Environment *************
[7/6/13 8:40:28:520 EDT] 00000010 webcontainer  I com.ibm.ws.webcontainer.internal.WebContainer addExtensionFactory SRVE0239I: Extension Factory [class com.ibm.ws.websvcs.extension.WASAxis2ExtensionFactory] was registered successfully.
[7/6/13 8:40:28:520 EDT] 00000010 webcontainer  I com.ibm.ws.webcontainer.internal.WebContainer addExtensionFactory SRVE0240I: Extension Factory [class com.ibm.ws.websvcs.extension.WASAxis2ExtensionFactory] has been associated with patterns [].
[7/6/13 8:40:28:521 EDT] 00000010 webcontainer  I com.ibm.ws.webcontainer.internal.WebContainer addExtensionFactory SRVE0239I: Extension Factory [class com.ibm.ws.websvcs.extension.AsyncServletExtensionFactory] was registered successfully.
[7/6/13 8:40:28:521 EDT] 00000010 webcontainer  I com.ibm.ws.webcontainer.internal.WebContainer addExtensionFactory SRVE0240I: Extension Factory [class com.ibm.ws.websvcs.extension.AsyncServletExtensionFactory] has been associated with patterns [].
[7/6/13 8:40:29:284 EDT] 00000010 webcontainer  I com.ibm.ws.webcontainer.internal.WebContainer addExtensionFactory SRVE0239I: Extension Factory [class com.ibm.ws.container.binding.http.HTTPExtensionFactory] was registered successfully.
[7/6/13 8:40:29:285 EDT] 00000010 webcontainer  I com.ibm.ws.webcontainer.internal.WebContainer addExtensionFactory SRVE0240I: Extension Factory [class com.ibm.ws.container.binding.http.HTTPExtensionFactory] has been associated with patterns [].
[7/6/13 8:40:29:365 EDT] 00000010 webcontainer  I com.ibm.ws.webcontainer.internal.WebContainer addExtensionFactory SRVE0239I: Extension Factory [class com.ibm.ws.jsf.extprocessor.JSFExtensionFactory] was registered successfully.
[7/6/13 8:40:29:392 EDT] 00000010 webcontainer  I com.ibm.ws.webcontainer.internal.WebContainer addExtensionFactory SRVE0240I: Extension Factory [class com.ibm.ws.jsf.extprocessor.JSFExtensionFactory] has been associated with patterns [].
[7/6/13 8:40:29:485 EDT] 00000010 webcontainer  I com.ibm.ws.webcontainer.internal.WebContainer addExtensionFactory SRVE0239I: Extension Factory [class com.ibm.ws.portletcontainer.webextension.PortletExtensionFactory] was registered successfully.
[7/6/13 8:40:29:485 EDT] 00000010 webcontainer  I com.ibm.ws.webcontainer.internal.WebContainer addExtensionFactory SRVE0240I: Extension Factory [class com.ibm.ws.portletcontainer.webextension.PortletExtensionFactory] has been associated with patterns [].
[7/6/13 8:40:29:485 EDT] 00000010 webcontainer  I com.ibm.ws.webcontainer.internal.WebContainer addExtensionFactory SRVE0239I: Extension Factory [class com.ibm.ws.portletcontainer.portletserving.PortletServingExtensionFactory] was registered successfully.
[7/6/13 8:40:29:486 EDT] 00000010 webcontainer  I com.ibm.ws.webcontainer.internal.WebContainer addExtensionFactory SRVE0240I: Extension Factory [class com.ibm.ws.portletcontainer.portletserving.PortletServingExtensionFactory] has been associated with patterns [].
[7/6/13 8:40:29:617 EDT] 00000010 webcontainer  I com.ibm.ws.webcontainer.internal.WebContainer addExtensionFactory SRVE0239I: Extension Factory [class com.ibm.ws.jsp.webcontainerext.ws.WASJSPExtensionFactory] was registered successfully.
[7/6/13 8:40:29:618 EDT] 00000010 webcontainer  I com.ibm.ws.webcontainer.internal.WebContainer addExtensionFactory SRVE0240I: Extension Factory [class com.ibm.ws.jsp.webcontainerext.ws.WASJSPExtensionFactory] has been associated with patterns [*.jsp *.jspx *.jsw *.jsv ].
[7/6/13 8:40:31:694 EDT] 0000000f webcontainer  I com.ibm.ws.webcontainer.WSWebContainer initialize SRVE0161I: IBM WebSphere Application Server - Web Container.  Copyright IBM Corp. 1998-2008
[7/6/13 8:40:31:695 EDT] 0000000f webcontainer  I com.ibm.ws.webcontainer.WSWebContainer initialize SRVE0162I: Servlet Specification Level: 2.5
[7/6/13 8:40:31:695 EDT] 0000000f webcontainer  I com.ibm.ws.webcontainer.WSWebContainer initialize SRVE0163I: Supported JSP Specification Level: 2.1
...
...
[7/6/13 16:33:26:639 EDT] 00000000 webcontainer  1 com.ibm.ws.webcontainer.WSWebContainer startChains startChains
[7/6/13 16:33:26:679 EDT] 00000000 webcontainer  1 com.ibm.ws.webcontainer.WebContainerWorkloadRegulator started
[7/6/13 16:34:54:253 EDT] 00000023 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest Handling request with virtual host key of --> test317.java.boot.by:9080
[7/6/13 16:34:54:256 EDT] 00000023 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest webcontainer.handleRequest request uri --> (not decoded=/testdsweb/test.jsp), (decoded=/testdsweb/test.jsp), (encoding=UTF-8)
[7/6/13 16:34:54:256 EDT] 00000023 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest webcontainer.handleRequest uri_non_decoded --> /testdsweb/test.jsp
[7/6/13 16:34:54:256 EDT] 00000023 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest PathInfoHelper strippedRequestURI --> /testdsweb/test.jsp extraPath --> null
[7/6/13 16:34:54:257 EDT] 00000023 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest Looking for vhost with key --> test317.java.boot.by:9080/testdsweb/test.jsp
[7/6/13 16:34:54:259 EDT] 00000023 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest request processor handling request --> com.ibm.ws.webcontainer.webapp.WebGroupImpl@a18cb345
[7/6/13 16:34:54:308 EDT] 00000023 webcontainer  1 com.ibm.ws.webcontainer.WebAppPmiListener isStatisticsEnabled pmi enabled for the servlet-->[/test.jsp]
[7/6/13 16:36:02:467 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest Handling request with virtual host key of --> test317.java.boot.by:9080
[7/6/13 16:36:02:471 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest webcontainer.handleRequest request uri --> (not decoded=/testdsweb/test.jsp), (decoded=/testdsweb/test.jsp), (encoding=UTF-8)
[7/6/13 16:36:02:471 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest webcontainer.handleRequest uri_non_decoded --> /testdsweb/test.jsp
[7/6/13 16:36:02:472 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest PathInfoHelper strippedRequestURI --> /testdsweb/test.jsp extraPath --> null
[7/6/13 16:36:02:472 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest Looking for vhost with key --> test317.java.boot.by:9080/testdsweb/test.jsp
[7/6/13 16:36:02:472 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest request processor handling request --> com.ibm.ws.webcontainer.webapp.WebGroupImpl@a18cb345
[7/6/13 16:36:02:848 EDT] 00000023 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest Handling request with virtual host key of --> test317.java.boot.by:9080
[7/6/13 16:36:02:848 EDT] 00000023 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest webcontainer.handleRequest request uri --> (not decoded=/testdsweb/test.jsp), (decoded=/testdsweb/test.jsp), (encoding=UTF-8)
[7/6/13 16:36:02:848 EDT] 00000023 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest webcontainer.handleRequest uri_non_decoded --> /testdsweb/test.jsp
[7/6/13 16:36:02:848 EDT] 00000023 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest PathInfoHelper strippedRequestURI --> /testdsweb/test.jsp extraPath --> null
[7/6/13 16:36:02:848 EDT] 00000023 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest Looking for vhost with key --> test317.java.boot.by:9080/testdsweb/test.jsp
[7/6/13 16:36:02:848 EDT] 00000023 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest request processor handling request --> com.ibm.ws.webcontainer.webapp.WebGroupImpl@a18cb345
[7/6/13 16:36:04:734 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest Handling request with virtual host key of --> test317.java.boot.by:9080
[7/6/13 16:36:04:734 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest webcontainer.handleRequest request uri --> (not decoded=/testdsweb/test.jsp), (decoded=/testdsweb/test.jsp), (encoding=UTF-8)
[7/6/13 16:36:04:745 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest webcontainer.handleRequest uri_non_decoded --> /testdsweb/test.jsp
[7/6/13 16:36:04:745 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest PathInfoHelper strippedRequestURI --> /testdsweb/test.jsp extraPath --> null
[7/6/13 16:36:04:745 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest Looking for vhost with key --> test317.java.boot.by:9080/testdsweb/test.jsp
[7/6/13 16:36:04:745 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest request processor handling request --> com.ibm.ws.webcontainer.webapp.WebGroupImpl@a18cb345
					

If you have HPEL disabled (basic logging mode), the trace file location can be looked up via ISC:

Figure 7.32. 


Open trace file as follows:

test317:/opt/IBM/WebSphere/AppServer/profiles/AppSrv01/logs/server1 # ls -lrt
total 1556
-rw-r--r-- 1 root root   51072 Jul  1 10:14 SystemErr.log
-rw-r--r-- 1 root root 1046393 Jul  1 11:29 SystemOut_13.07.01_11.29.54.log
drwxr-xr-x 4 root root    4096 Jul  6 16:33 logdata
drwxr-xr-x 3 root root    4096 Jul  6 16:33 tracedata
-rw-r--r-- 1 root root   30633 Jul  6 17:48 stopServer.log
-rw-r--r-- 1 root root   38950 Jul  6 17:56 startServer.log
-rw-r--r-- 1 root root   37046 Jul  6 17:57 native_stdout.log
-rw-r--r-- 1 root root    5276 Jul  6 17:57 native_stderr.log
-rw-r--r-- 1 root root   13050 Jul  6 17:58 trace.log
-rw-r--r-- 1 root root  330793 Jul  6 17:58 SystemOut.log
					

test317:/opt/IBM/WebSphere/AppServer/profiles/AppSrv01/logs/server1 # tail -30 trace.log
[7/6/13 18:01:11:895 EDT] 00000000 webcontainer  1 com.ibm.ws.webcontainer.WSWebContainer startChains startChains
[7/6/13 18:01:11:914 EDT] 00000010 SchedulerServ I   SCHD0077I: The Scheduler Service is starting the Schedulers.
[7/6/13 18:01:11:915 EDT] 00000010 SchedulerServ I   SCHD0078I: The Scheduler Service has completed starting the Schedulers.
[7/6/13 18:01:12:002 EDT] 00000000 GridConfigura I   GridConfiguratorMBean activated successfully
[7/6/13 18:01:12:010 EDT] 00000000 webcontainer  1 com.ibm.ws.webcontainer.WebContainerWorkloadRegulator started
[7/6/13 18:01:12:239 EDT] 00000000 RMIConnectorC A   ADMC0026I: The RMI Connector is available at port 9810
[7/6/13 18:01:12:327 EDT] 00000000 JMXConnectors I   ADMC0058I: The JMX JSR160RMI connector is available at port 9810
[7/6/13 18:01:12:380 EDT] 00000000 ModelMgr      I   WSVR0801I: Initializing all server configuration models
[7/6/13 18:01:13:740 EDT] 00000013 UserManagemen I   CWWIM6002I Received notification that the server has finished starting.
[7/6/13 18:01:18:849 EDT] 00000000 WsServerImpl  A   WSVR0001I: Server server1 open for e-business
[7/6/13 18:01:27:421 EDT] 00000020 WSChannelFram A   CHFW0019I: The Transport Channel Service has started chain IPCCOutboundChain.
[7/6/13 18:01:28:206 EDT] 00000023 DiscoveryMBea I   ADMD0023I: The system discovered process (name: nodeagent, type: NodeAgent, pid: 7427)
[7/6/13 18:03:11:041 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest Handling request with virtual host key of --> test317.java.boot.by:9080
[7/6/13 18:03:11:041 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest webcontainer.handleRequest request uri --> (not decoded=/testdsweb/test.jsp), (decoded=/testdsweb/test.jsp), (encoding=UTF-8)
[7/6/13 18:03:11:041 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest webcontainer.handleRequest uri_non_decoded --> /testdsweb/test.jsp
[7/6/13 18:03:11:041 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest PathInfoHelper strippedRequestURI --> /testdsweb/test.jsp extraPath --> null
[7/6/13 18:03:11:042 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest Looking for vhost with key --> test317.java.boot.by:9080/testdsweb/test.jsp
[7/6/13 18:03:11:042 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer handleRequest request processor handling request --> com.ibm.ws.webcontainer.webapp.WebGroupImpl@f0a15131
[7/6/13 18:03:11:208 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.WebAppPmiListener isStatisticsEnabled pmi enabled for the servlet-->[/test.jsp]
[7/6/13 18:03:11:413 EDT] 00000024 servlet       I com.ibm.ws.webcontainer.servlet.ServletWrapper init SRVE0242I: [testdsweb_war] [/testdsweb] [/test.jsp]: Initialization successful.
[7/6/13 18:03:21:737 EDT] 00000024 PrivExAction  W   J2CA0144W: No mappingConfigAlias found for ConnectionFactory or DataSource jdbc/TestDS.
[7/6/13 18:03:21:739 EDT] 00000024 PrivExAction  W   J2CA0114W: No container-managed authentication alias found for ConnectionFactory or DataSource jdbc/TestDS.
[7/6/13 18:03:24:757 EDT] 00000024 InternalGener I   DSRA8203I: Database product name : DB2
[7/6/13 18:03:24:841 EDT] 00000024 InternalGener I   DSRA8204I: Database product version : DSN09015
[7/6/13 18:03:24:842 EDT] 00000024 InternalGener I   DSRA8205I: JDBC driver name  : IBM DB2 JDBC Universal Driver Architecture
[7/6/13 18:03:24:842 EDT] 00000024 InternalGener I   DSRA8206I: JDBC driver version  : 3.57.82
[7/6/13 18:03:24:845 EDT] 00000024 InternalDB2Un I   DSRA8212I: DataStoreHelper name is: com.ibm.websphere.rsadapter.DB2UniversalDataStoreHelper@4e238e22.
[7/6/13 18:03:24:846 EDT] 00000024 WSRdbDataSour I   DSRA8208I: JDBC driver type  : 4
[7/6/13 18:03:25:063 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer addToCache WebApp = com.ibm.ws.webcontainer.webapp.WebAppImpl@b0ae80ba
[7/6/13 18:03:25:064 EDT] 00000024 webcontainer  1 com.ibm.ws.webcontainer.internal.WebContainer addToCache Adding to cache cacheKey --> test317.java.boot.by:9080/testdsweb/test.jsp uri -->/testdsweb/test.jsp servletWrapper -->/test.jsp
test317:/opt/IBM/WebSphere/AppServer/profiles/AppSrv01/logs/server1 #
					

Professional hosting         Free 'Oracle Certified Expert Web Services Developer 6' Guide     Free SCDJWS 5.0 Guide