An introduction to the DB2 UDB trace facility
When using DB2 UDB you might on occasion encounter an error message that directs you to "get a trace and call IBM Support", "[turn] on trace [and] examine the trace record", or to "contact your technical [support] representative with the following information: problem description, SQLCODE, SQLCA contents (if possible), and trace file (if possible)". Or, when you report a problem to IBM Support, you might be asked to perform a trace to capture detailed information about your environment.
DB2 traces can be especially useful when analyzing recurring and reproducible
problems, and greatly facilitate the support representative's job of problem
determination. But exactly what is a trace, and how do you take one? This
article introduces you to the DB2 trace facility and the
command, and shows you (by way of actual examples) how to capture trace information,
should you ever need to do so.
Understanding DB2 traces
A DB2 trace is essentially a log of control flow information (functions and associated parameter values) that is captured while the trace facility is on. Traces are very useful to DB2 technical support representatives who are trying to diagnose a problem that may be difficult to solve with only the information that is returned in error messages.
Tracing can be restricted to a particular component (such as buffer pool services). This action is known as masking. Masking a trace helps to minimize the amount of information that is captured. When taking a trace, try to use the smallest scenario possible to reproduce your problem; otherwise, the amount of data that is captured might be prohibitive.
Note that trace information is not always helpful when diagnosing an error; for example, it might not capture the error condition if:
- The trace buffer has not been set large enough to hold a complete set of relevant trace events
- The trace does not encompass the re-created error situation
The DB2 trace facility is controlled by means of the
which is used to start and stop a trace, and to format captured trace information.
Using the db2trc command
You can use the
db2trc command to capture trace information and to
format this information into readable text. Issue the
db2trc command at
an operating-system command prompt or from a shell script. Although you have the
option of tracing to a file (instead of to memory), tracing to a file is slower;
nevertheless, this may be your only option if the problem being re-created prevents
you from "dumping" the trace (from memory) to a file. The idea is to dump the trace
immediately after the problem occurs, then to turn tracing off and, finally, to
format the event data either chronologically or by process or thread.
The syntax of the
db2trc command is shown in Figure
1. The command options can be grouped into two broad categories: collection
- Collection options include turning a trace on or off; specifying the trace buffer size; specifying or changing trace options; dumping a trace; and clearing the trace buffer.
- Parsing options include sorting the formatted trace records chronologically or by process or thread.
Trace options include the ability to specify a mask to capture trace records that satisfy specified criteria (for example, only records that are associated with a particular function or component); the ability to trace only specified process and thread combinations; and the ability to request (relative) timestamp data.
You can trace a DB2 instance or a DB2 Administration Server (DAS) instance; tracing a
DB2 instance is the default behavior. To do this, you don't have to specify the
db2 clause. The examples in this article pertain to tracing the
default DB2 instance only.
Note that the
-u option is a handy way to access command line help for
most of the options on the
Figure 1. Syntax diagram showing the principal options of the db2trc command
Starting a trace
An excellent way to understand the main options on the
db2trc command is
to try them. We will explore a very simple example using the SAMPLE database that
comes with DB2 UDB. First, we will turn the trace facility on, specifying an 8-MB
trace buffer. We will be tracing into shared memory (rather than to a file), using
-i option, which stops the trace as soon as the buffer is full.
-l option, on the other hand, preserves the last trace records,
because the buffer is allowed to wrap, or overwrite existing records. This is the
default behavior.) The buffer size can be specified in bytes or megabytes. To
specify megabytes, append
m) to the value.
We will also specify a trace mask to limit the number of trace records that will be
captured. In this case, we will trace only the buffer pool services component. This
can be done in one of two ways. We can simply specify the
followed by the component name enclosed by double quotation marks (
pool services"), or we can specify the component number (in this case, 2)
within the full mask syntax. A trace mask has five elements that are delimited by
- Type. This element refers to the trace record type, and includes entry (1), exit (2), data (3), error (4), and fatal error (5).
- Product. DB2 is product 3.
- Component. This element refers to a component name; for example, buffer pool services (2). The component's short name can also be specified; for example, sqlb.
- Function. This element refers to a function name; for example, sqlbpfDbheapSize (404).
- Function category. This element specifies whether the function is an internal function (fnc, 0), component external interface (cei, 2), or external API (api, 3).
Each element can consist of a comma-delimited list, a hyphenated range, or a single entry. An asterisk can be used to match anything. Values can be specified by their names or corresponding numbers. Setting a mask to "*.*.*.*.*" is equivalent to not specifying a mask. It is recommended that you enclose the trace mask with double quotation marks to avoid possible misinterpretation of the asterisk character by the operating-system shell.
Component and function names and their associated numbers are listed in several internal header files, which you will not be able to see. If you need to find some names or numbers to set up a particular mask, it is recommended that you look in a sample of formatted trace output. (More about that later.)
The last option that we will specify is the
-t option, which will direct
the trace facility to capture relative timestamps associated with each trace record.
We are now ready to start the trace. We will issue the
start the default DB2 instance, clear the trace buffer, connect to the SAMPLE
database, write the contents of the trace buffer to a file named
and then turn tracing off, as shown in Listing 1.
Listing 1. Turning on the trace facility
db2trc on -i 8m -m "*.*.2.*.*" -t db2start db2trc clear db2 connect to sample db2trc dump dmp db2trc off
There are some important things that you should note about the trace buffer:
- When you specify a buffer size, the value must be a power of 2. For example, if you request a 7-MB buffer, the value is rounded down to 4 megabytes; if you request an 8000000-byte buffer, the value is rounded down to 4194304 bytes.
- The minimum buffer size is 1 megabyte. The default buffer size is 8 megabytes on Windows® operating systems, and 4 megabytes on UNIX®-based systems. The default and minimum trace buffer sizes depend on the version of DB2, and the maximum trace buffer size depends on the platform.
- For performance reasons, the trace facility does not allow you to change the
trace buffer size dynamically. As long as there is a single process attached to
the shared trace buffer, you will not be able to change the buffer size. The
best way to specify a different buffer size is to issue the
db2trccommand before starting the instance (that is, before issuing the
- If you are tracing to shared memory, the size of the trace buffer controls the size of the dump file. If you are tracing to a file, the size of the dump file is limited only by the free space and maximum allowable file size on the system.
Formatting the trace
The trace that we have just dumped from memory to a file named
be parsed or formated into readable text using one or both of the parsing options on
db2trc command. Listing 2 shows an example
of each parsing request, including the summary information that is returned to
standard output. In our example, the trace is small enough that truncation does not
occur. Listing 2 also shows the sizes of the various output
files. As expected, the dump file (
dmp) is approximately 8 MB in size,
corresponding to the trace buffer size that was specified on the
Listing 2. Parsing the trace
db2trc format dmp fmt Trace truncated : NO Trace wrapped : NO Total number of trace records : 2846 Number of trace records formatted : 2846 db2trc flow dmp flw Total number of trace records : 2846 Trace truncated : NO Trace wrapped : NO Number of trace records formatted : 2771 (pid: 23494 tid 1 node: 0) Number of trace records formatted : 15 (pid: 19834 tid 1 node: 0) Number of trace records formatted : 15 (pid: 28780 tid 1 node: 0) Number of trace records formatted : 15 (pid: 28396 tid 1 node: 0) Number of trace records formatted : 30 (pid: 26332 tid 1 node: 0) ls -l ... -rw-r----- 1 melnyk staff 8393432 Aug 20 15:43 dmp -rw-r----- 1 melnyk staff 121489 Aug 20 15:44 flw -rw-r----- 1 melnyk staff 541845 Aug 20 15:44 fmt ...
format option creates a plain text trace output file in which the
trace records appear in chronological order. An example of such output in shown in
Listing 3. Each record represents a trace point with its
own identifying number. Trace point numbers appear consecutively in a
chronologically formatted output file. If you examine the first record (trace point
1), you'll see that it contains the trace record type ("entry"), the product ("DB2
UDB"), the component ("buffer pool services"), the function
("sqlbGetTotalBufferPoolMemSize"), and the function category ("cei"). You will
recall that this information maps to elements that can be used to define a mask. The
numeric equivalents of these elements also appears in the trace record;
"(18.104.22.1687.2)", for example. If a trace point also happens to be a probe point (an
explicitly identified precise location within a function), the probe number is also
included in this string (see trace point 4, for example).
The formatted trace record also identifies the process ("23494"), the thread ("1"), the companion process, if applicable ("-1"), and the node ("0"). Because we specified the -t option on the db2trc command, relative timestamps are also included in the output. A relative timestamp shows the time that has elapsed since the beginning of the trace. In this case, the entire trace covers a period of 361,858,476 nanoseconds, or just over one-third of a second.
As shown in the syntax diagram (Figure 1), the
format option can be used to parse only those trace points that are
associated with one or more specific processes; for example:
db2trc format dmp
fmt1 -p 19834.
Listing 3. Formatted trace records in chronological order. This partial output shows the first six and the last trace point in the file.
1 entry DB2 UDB buffer pool services sqlbGetTotalBufferPoolMemSize cei (22.214.171.1247.2) pid 23494 tid 1 cpid -1 node 0 sec 0 nsec 0 2 entry DB2 UDB buffer pool services sqlbpfDbheapSize fnc (126.96.36.1994.0) pid 23494 tid 1 cpid -1 node 0 sec 0 nsec 5659 3 entry DB2 UDB buffer pool services sqlbGetBPConfig cei (188.8.131.520.2) pid 23494 tid 1 cpid -1 node 0 sec 0 nsec 10319 4 data DB2 UDB buffer pool services sqlbGetBPConfig cei (184.108.40.2060.2.0) pid 23494 tid 1 cpid -1 node 0 sec 0 nsec 11629 probe 0 bytes 12 Data1 (PD_TYPE_HEXDUMP,4) Hexdump: 0000 0000 .... 5 exit DB2 UDB buffer pool services sqlbGetBPConfig cei (220.127.116.110.2) pid 23494 tid 1 cpid -1 node 0 sec 0 nsec 19329 rc = 0 6 exit DB2 UDB buffer pool services sqlbpfDbheapSize fnc (18.104.22.1684.0) pid 23494 tid 1 cpid -1 node 0 sec 0 nsec 22358 rc = 0x000448BC = 280764 ... 2846 exit DB2 UDB buffer pool services sqlbCheckBPFConsistancy fnc (22.214.171.1243.0) pid 23494 tid 1 cpid -1 node 0 sec 0 nsec 361858476 rc = 0
flow option creates a plain text trace output file in which the
trace records are ordered chronologically by process; it creates what is
essentially a control flow diagram. An example of such output in shown in Listing 4. Information contained in this output includes
process, thread, and node number, as well as trace point numbers, function names,
trace record types and, in some cases, probe numbers. A nice feature is that each
new function entry is indented for clarity.
Once again, as shown in the syntax diagram (Figure 1), the
flow option can also be used to parse only those trace points that
are associated with one or more specific processes; for example:
dmp flw1 -p 19834.
Listing 4. Part of a control flow diagram
... pid = 19834 tid = 1 node = 0 846 sqlbPFPrefetcherEntryPoint entry 847 sqlbPFPrefetcherEntryPoint data [probe 0] 848 | sqlbPFInitPrefetcher entry 849 | sqlbPFInitPrefetcher data [probe 0] 850 | | sqlbConnectToSharedMemory entry 851 | | sqlbConnectToSharedMemory exit 852 | | sqlbInitEDU entry 853 | | | sqlbGetBPConfig entry 854 | | | sqlbGetBPConfig data [probe 0] 855 | | | sqlbGetBPConfig exit 856 | | | SqlbFileTbl::SqlbFileTbl entry 857 | | | SqlbFileTbl::SqlbFileTbl exit 858 | | sqlbInitEDU exit 859 | sqlbPFInitPrefetcher exit 860 | sqlbpfRemoveFromQ entry ...
info option on the
db2trc command returns a handy
summary of the trace parameters that are associated with a particular dump file.
Using our dump file named
dmp, the command
db2trc info dmp
Listing 5. Information returned by the "info" option on the db2trc command
Marker : @TRACE@ Trace version : 6.0 Platform : AIX Build level : s040811 maxBufferSize : 8388608 bytes (8 MB) auxBufferSize : 6291456 bytes (6 MB) allocationCount : 2 DB2TRCD pid : 0 Trace destination : <shared memory buffer> crash : disabled crash runtime passno : 0 numSuspended : 0 Buffer size : 8388608 bytes (8 MB) Allow buffer to wrap : no Mask : *.*.2.*.* Timestamps : enabled PID.TID mask : all Fixed data mask #1 : all Fixed data mask #2 : all Max system errors : infinite Treat this rc as sys err: none
Exploring other trace options
Some of the other options that are available on the
db2trc command (and
that are shown in Figure 1) include:
-perfcount. The performance counter is a collection option that records the total number of times each function is called; its associated
-toption specifies that the total amount of time spent in each function is also to be captured. The performance counter also supports the
-moption, which allows you to specify a mask.
perffmt. The performance trace formatter is a parsing option that formats a dump file containing performance counter data into readable text (see Listing 6).
change. This collection option lets you change the trace options that are in effect.
-resume. This collection option lets you resume execution of a suspended process. You cannot resume if
-suspendwas not enabled (see below).
dump -q. The
-q(quiet mode) option disables printing of the message "Trace has been dumped to file..." to standard output.
stop. This collection option stops tracing on demand; all processes suspend tracing, but the contents of the trace buffer are preserved so that they can be dumped later. This action is in contrast to the
offoption, which disables the trace facility altogether.
-c cpid. This trace option requests that only the specified companion process be traced.
-rc return-code. This trace option requests that the specified value (which must be a signed integer) be treated as a system error.
-e max-sys-errors. This trace option requests that tracing be stopped once the specified number of system errors has occurred.
-crash point. This trace option requests that a process be crashed at a specified trace point. The trace point can be specified as follows: "product-name.component-short-name.function-name.entry | exit | probe". For example: "DB2.SQLE.sqleFirstConnect.entry". The probe element represents any trace point in the function other than an entry or an exit trace point. DB2 UDB Version 8.2 introduces the
-debugoption as a synonym for
Note: Use the
-crashoption with care, and only when directed to do so by a DB2 technical support representative.
-passno i. This trace option requests that a process be crashed after the crash point has executed i times.
-sleep s. This trace option requests that a process sleep for s seconds instead of crashing.
-signum n. This trace option requests that a process raise signal n instead of crashing.
-pause. This trace option requests that a process pause until signalled instead of crashing.
-suspend. This trace option requests that a process suspend execution instead of crashing.
-softcrash. This trace option requests that a process interrupt the agent instead of crashing.
Listing 6. Turning on the performance counter and formatting the captured data. Sample output shows the first five formatted records.
db2 connect reset db2stop db2trc on -i 8m -perfcount -t -m "*.*.2.*.*" db2start db2trc clear db2 connect to sample db2trc dump dmp1 db2trc off db2trc perffmt dmp1 pfmt 13 (0 sec, 28978 nanosec) sqlbReducePagesPinned 8 (0 sec, 114614 nanosec) sqlbLoadContainerList 1 (0 sec, 6309 nanosec) sqlbAllocateBuckets 1 (0 sec, 28228 nanosec) sqlbpfCreateQ 4 (0 sec, 195840 nanosec) sqlbConnectToSharedMemory ...
This article introduces you to the basics of DB2 tracing, and shows you, by way of
working examples, how to use the
db2trc command if you are ever
requested to capture trace information by a DB2 technical support representative.
You can try some of these examples yourself in a test (not production!) environment
to acquire a better understanding and appreciation of the DB2 trace facility.
- DB2 Technical Support is the ideal place to locate resources such as the Version 8 Information Center and PDF product manuals.