1 Tools for Troubleshooting TimesTen

The following sections in this chapter describe how to use the TimesTen utilities and other tools that are used to diagnose problems with the TimesTen database:

Using the ttCapture utility

The ttCapture utility captures information about the configuration and state of your TimesTen system into a file that provides TimesTen technical support with a snapshot of your system at the time the ttCapture utility is running. The ttCapture utility generates a file named ttcapture.date.time.log. By default, the file is written to the directory from which you invoke the ttCapture utility. Use the ttCapture -dest option to direct the output file to be written to another directory.

If you run ttCapture again, it writes the information to a new file.

On Windows platforms, running ttCapture also produces an XML file named ttcapture.date.time.nfo that contains output from the msinfo32 utility.

When you experience a problem with a TimesTen database, run ttCapture with the DSN option for the database as soon as possible, either when you are encountering the problem or immediately afterward.

Note:

Always double-quote directory and file names in case there are spaces in the names.

When you contact TimesTen technical support, upload the ttcapture.date.number.log file to the Service Request. Windows users should also upload the ttcapture.date.time.nfo file.

See "ttCapture" in the Oracle TimesTen In-Memory Database Reference for information about additional options.

Using the ttIsql utility

The ttIsql utility enables you to interactively execute SQL statements and report status information on your TimesTen database.

All TimesTen SQL operations can be executed from a ttIsql Command> prompt.

Example 1-1 Using the ttIsql utility

To start the ttIsql utility for the demo database, enter:

% ttIsql demo

You should see output similar to the following:

Copyright (c) 1996, 2013, Oracle and/or its affiliates. All rights reserved.
Type ? or "help" for help, type "exit" to quit ttIsql.

connect "DSN=demo";
Connection successful: DSN=demo;UID=testuser;DataStore=/scratch/testuser/demo;
DatabaseCharacterSet=AL32UTF8;ConnectionCharacterSet=AL32UTF8;PermSize=128;
TypeMode=0;
(Default setting AutoCommit=1)

You can then execute SQL statements or ttIsql commands at the Command> prompt. You can also call TimesTen built-in procedures. One useful procedure is ttConfiguration. When you execute ttConfiguration, TimesTen displays the values of the connection attributes for your current database connection. For more information, see "ttConfiguration" in the Oracle TimesTen In-Memory Database Reference.

"Using the ttIsql Utility" in the Oracle TimesTen In-Memory Database Operations Guide describes how to use the most common ttIsql commands. The following ttIsql commands are commonly used when troubleshooting:

For the full list of ttIsql features, see the lists of options and commands under the description of the ttIsql utility in the Oracle TimesTen In-Memory Database Reference.

Using the ttStatus utility

Use the ttStatus utility to check the status of the TimesTen daemon and the state of all TimesTen connections.

Example 1-2 ttStatus shows TimesTen daemon is not running

In this example, the output from ttStatus indicates that no TimesTen daemon is running. If the daemon has stopped unexpectedly, see "No response from TimesTen daemon or subdaemon" for troubleshooting information.

On Windows:

C:\>ttStatus
ttStatus: Could not connect to the TimesTen service. 
If the TimesTen service is not running, please start it by running 
"ttDaemonAdmin -start".

On UNIX platforms:

$ ttStatus
ttStatus: Could not connect to the TimesTen daemon.
If the TimesTen daemon is not running, please start it
by running "ttDaemonAdmin -start".

Example 1-3 ttStatus shows TimesTen daemon is running

In this example, the output from ttStatus indicates that the TimesTen daemon is running. There is one database named demo.

The first line indicates that the TimesTen daemon is running as process 4579 on port 4738 for the TimesTen instance myinstance. The second line indicates the TimesTen Server is running as process 4588 on port 4740.

There are currently 12 connections to the database: one user and 11 subdaemon connections.

The restart policies for the cache agent and the replication agent in the database are set to manual.

$ ttStatus
TimesTen status report as of Wed May  1 16:37:51 2013
 
Daemon pid 4579 port 4738 instance myinstance
TimesTen server pid 4588 started on port 4740
------------------------------------------------------------------------
Data store /scratch/testuser/demo
There are 12 connections to the data store
Shared Memory KEY 0x02010008 ID 7798789
PL/SQL Memory KEY 0x03010008 ID 7831558 Address 0x7fa0000000
Type            PID     Context             Connection Name              ConnID
Process         4631    0x0000000009b3e800  demo                              1
Subdaemon       4584    0x0000000000616460  Manager                         142
Subdaemon       4584    0x000000000066d210  Rollback                        141
Subdaemon       4584    0x000000000074ea00  Flusher                         140
Subdaemon       4584    0x00000000007a3c90  Monitor                         139
Subdaemon       4584    0x00000000007f8790  Deadlock Detector               138
Subdaemon       4584    0x000000000084f2f0  Aging                           136
Subdaemon       4584    0x0000000000863db0  Log Marker                      135
Subdaemon       4584    0x00000000008fcf70  IndexGC                         132
Subdaemon       4584    0x00002aaabcb008d0  Checkpoint                      137
Subdaemon       4584    0x00002aaabcb555f0  HistGC                          133
Subdaemon       4584    0x00002aaabcc008d0  AsyncMV                         134
Replication policy  : Manual
Cache Agent policy  : Manual
PL/SQL enabled.
------------------------------------------------------------------------
Accessible by group g900
End of report

Example 1-4 ttStatus shows connection to old instance

This example shows a connection to an old instance of a database. This can occur when a database is invalidated, but some users have not disconnected from the invalidated copy of the database still in memory. After all users disconnect, the memory is automatically freed.

C:\>ttStatus

TimesTen status report as of Mon Aug  6 22:03:04 2012
Daemon pid 5088 port 17000 instance MYINSTANCE
TimesTen server pid 4344 started on port 17002
-----------------------------------------------------------------
Data store c:\temp\sample
There are no connections to the data store
Obsolete or not yet active connection(s):
Process  4696 context 0xd08800 name sample connid 1, obsolete connection, shmKey
'Global\DBI45b94c6f.3.SHM.4'
Replication policy : Manual
Cache agent policy : Manual
-----------------------------------------------------------------
End of report

Using the logs generated by the TimesTen daemon

The TimesTen daemon and its subdaemons and agents generate error, warning, and informational messages. These messages may be useful for TimesTen system administration and for debugging applications.

By default, informational messages are stored in:

  • A user error log that contains information you may need to be aware of, including actions you may need to take.

  • A support log containing everything in the user error log plus information for use by TimesTen Customer Support.

See "Modifying informational messages" in the Oracle TimesTen In-Memory Database Operations Guide for information about configuring the logs, including their location and size.

All message categories are enabled by default, but you can also disable or explicitly enable the following categories of user error log messages for all databases or specified databases through options of the ttDaemonLog utility:

  • ALL (default): For all messages

  • CACHE: For messages from the cache agent, designated by CAC

  • DAEMON: For messages from the main daemon and subdaemons

  • DAEMONDBG: For additional information from the main daemon and subdaemons.

  • REPLICATION: For messages from the replication agent, designated by REP

  • SERVER: For messages from TimesTen Server.

See "ttDaemonLog" in Oracle TimesTen In-Memory Database Reference for information about ttDaemonLog options.

Using the ttTraceMon utility

Use the ttTraceMon utility to log various trace information on a number of TimesTen components. Each TimesTen component can be traced at different levels of detail. You can list all of the traceable TimesTen components and their current tracing level by specifying ttTraceMon with the show subcommand. The full list of options for ttTraceMon is described in the "ttTraceMon" section in the Oracle TimesTen In-Memory Database Reference.

TimesTen tracing severely impacts application performance and consumes a great deal of disk space if trace output is directed to a file. In addition, when using AWT cache groups, you must restart the replication agent when trying to trace the ORACON component with ttTraceMon. Use the ttTraceMon utility only when diagnosing problems. When you are finished, reset tracing to the default values.

Example 1-5 Default trace levels for components

This example shows that the levels for most tracing components are set to level 0 (off) for the demo database. Both the ERR and DEADLOCK components are set to 1 for tracing by default. See "ERR tracing".

% ttTraceMon -e show demo
AGING        ... 0
API          ... 0
ASYNCMV      ... 0
AUTOREFRESH  ... 0
CG           ... 0
CGRID        ... 0
CGRIDC       ... 0
CKPT         ... 0
DEADLOCK     ... 1
EE           ... 0
ERR          ... 1
FLOW         ... 0
HEAP         ... 0
LATCH        ... 0
LOCK         ... 0
LOG          ... 0
LOGF         ... 0
OPT          ... 0
ORACON       ... 0
PLOAD        ... 0
PT           ... 0
REPL         ... 0
SM           ... 0
SQL          ... 0
TEST         ... 0
TRACE        ... 0
XA           ... 0
XACT         ... 0

The output for most TimesTen components is of interest only to TimesTen technical support. However, the output for the SQL, API, LOCK, ERR, AGING and AUTOREFRESH components may be useful to you when you are troubleshooting application problems.

The rest of this section includes the following topics:

Starting a trace and reading the trace buffer

Start a new trace by specifying ttTraceMon datastore. For example, to start a trace on the demo database, enter:

%  ttTraceMon demo
Trace monitor; empty line to exit
Trace >

At the Trace prompt, specify the type of trace and its level. For example, to start tracing the SQL component at level 3, enter:

Trace > level sql 3

At this point you can run your application and the TimesTen trace information is written to a trace buffer. There are two ways to read the contents of the trace buffer:

  • From the Trace prompt, use the outfile command to direct the trace buffer data to a file. You must do this before running your application. When writing tracing information to a file, new trace information is concatenated to the existing contents of the file.

  • From the Trace prompt, use the dump command to display the trace buffer data to your screen.

Note:

The contents of the trace buffer accumulate with each new trace. To clear the trace buffer, use the flush command from a ttTraceMon prompt. Clear the buffered trace records for a specific component by specifying the component with the flush command.

Each record from the trace buffer has the following format:

timestamp   sequence   component   level   connection   processid
   operation

The fields in the records are defined as follows:

  • timestamp is the time at which the operation was executed.

  • sequence is the incremental number that identifies the trace line.

  • component is the TimesTen component being traced (such as SQL, API, LOCK, or ERR).

  • level is the trace level associated with the trace line. The range of trace levels differs by component, but for all components, the lowest trace level generates the least verbose output and highest trace level generates the most verbose output. For example, if you are tracing SQL at level 4, your output includes lines for levels 2 (prepare), 3 (execute), and 4 (open, close, fetch).

Note:

Trace levels for some components are not a continuous range of numbers. If you enter a number that does not correspond to a supported level for a component, tracing occurs at the highest supported level that is less than the number you entered. For example, if tracing levels for a component are 1, 2, 3, 4, and 6 and you enter 5, tracing events for level 1, 2, 3, and 4 are generated.
  • connection is the internal connection ID identifying the connection that generated the trace. This number corresponds to the ConnID shown in the ttStatus output. The connection ID is also used as the first element of the transaction ID.

  • processid is the operating system process ID for the process that generated the trace.

  • operation is the operation that occurred (such as SQL statement, API operation, or error message).

For example, a line from the trace buffer after a SQL trace at level 3 might look like this:

10:39:50.231 5281 SQL 2L 1C 3914P Preparing: select cust_num from customer

SQL tracing

Using ttTraceMon with the SQL component provides information about the SQL being prepared or executed by the TimesTen engine. Table 1-1 describes the levels for SQL tracing. Each level with a '+' sign includes the trace information described for that level, plus all levels preceding it.

Table 1-1 SQL tracing levels

Level Output

2

SQL commands being prepared

3

+ SQL commands being executed

4

+ The effect of command pooling (prepares not being done because the prepared command already exists in the pool), the need for reprepares (for example, because an index was created), and commands being destroyed

At this level, ttTraceMon also shows when a query command is being opened, fetched, and closed.

5

+ Some internal data, such as command numbers, which are not generally useful for customer-level debugging


Note:

TimesTen recommends tracing SQL at level 3 or 4. SQL tracing does not show any information about the optimizer. Optimizer tracing is managed by a separate component (OPT) at level 4 only, and is not designed for customer use.

Example 1-6 SQL trace

In this example, execute ttTraceMon to do a SQL trace at level 4 on the demo database. Direct the output from the SQL trace to the SQLtrace.txt file. Then flush the buffer so that the trace does not report past SQL statements.

% ttTraceMon demo
Trace monitor; empty line to exit
Trace > outfile SQLtrace.txt
Trace > level sql 4
Trace > flush

At this point, execute an application that includes the following SQL statement:

SELECT * FROM departments WHERE department_id = 10;

The trace information is written to the SQLtrace.txt file:

12:19:36.582     269 SQL      2L    3C  29570P Preparing: select * from 
departments where department_id = 10
12:19:36.583     270 SQL      4L    3C  29570P sbSqlCmdCompile ()(E): (Found 
already compiled version: refCount:01, bucket:28) cmdType:100, cmdNum:1000146.
12:19:36.583     271 SQL      4L    3C  29570P Opening: select * from departments
where department_id = 10;
12:19:36.583     272 SQL      4L    3C  29570P Fetching: select * from 
departments where department_id = 10;
12:19:36.583     273 SQL      4L    3C  29570P Closing: select * from departments
where department_id = 10;
5 records dumped

When the application has completed, turn off SQL tracing and exit ttTraceMon.

Trace > level sql 0
Trace > {press ENTER – blank line}

API tracing

API traces are generated for database operations such as connecting to a database, changing a connection attribute, and committing a transaction. Table 1-2 describes the levels for API tracing. Each level with a '+' sign includes the trace information described for that level, plus all levels preceding it.

Table 1-2 API tracing levels

Level Output

1

All rollback attempts by the subdaemon

This occurs if an application exits abruptly and the subdaemon recovers its connection.

2

+ Some low-on-space conditions

3

+ Create, connect, disconnect, checkpoint, backup, and compact operations for the database, as well as commit and rollback for each connection, and a few other operations

4

+ Most other operations conducted at TimesTen's internal API level

It does not show numerous operations on the storage manager and indexes that are done internally.


Note:

TimesTen recommends tracing at level 3.

Example 1-7 API trace

In this example, execute ttTraceMon to do a API trace at level 3 on the demo database. The output from the API trace is written to the APItrace.txt file. Before saving the API trace to the buffer, use the flush command to empty the buffer.

% ttTraceMon demo
Trace monitor; empty line to exit
Trace> outfile APItrace.txt
Trace> level api 3
Trace > flush

At this point, execute the application. When the application has completed, turn off API tracing and exit ttTraceMon:

Trace > level api 0
Trace > {press ENTER – blank line}

The contents of APItrace.txt are similar to the sample output shown below. The output shows connection to the database, setting the connection character set, setting the isolation level, and committing a transaction.

11:54:26.796    1016 API      3L    2C   4848P sb_dbConnect()(X)
11:54:26.796    1017 API      3L    2C   4848P sb_dbConnCharsetSet()(E)
11:54:26.796    1018 API      3L    2C   4848P sb_dbConnSetIsoLevel()(E)
11:54:39.795    1019 API      3L    2C   4848P sb_dbConnSetIsoLevel()(E)
11:54:45.253    1020 API      3L    2C   4848P sb_xactCommitQ()(E)

DEADLOCK tracing

Use the DEADLOCK component to trace the occurrences of deadlocks for all applications.

Table 1-3 describes the DEADLOCK tracing levels. Each level with a '+' sign includes the trace information described for that level, plus all levels preceding it.

Table 1-3 DEADLOCK tracing levels

Level Output

1

Deadlock cycles, logged as they are discovered

4, 6

+ Detailed information about how the deadlock is detected


Example 1-8 DEADLOCK trace

In this example, execute ttTraceMon to do a DEADLOCK trace at level 1, which is the default, on myDSN database.

Make two connections to myDSN. For the first connection, autocommit is on. Create table test and insert two rows. Then, set autocommit off and update the x1=1 row of table test. Because autocommit is off, the row is not inserted into the table until the commit. A lock is held until the transaction is committed or rolled back.

Command> create table test (x1 int unique, y1 int);
Command> insert into test values (1,1);
1 row inserted.
Command> insert into test values (2,2);
1 row inserted.
Command> autocommit 0;
Command> update test set y1=y1 where x1=1;
1 row updated.

For the second connection to myDSN, autocommit is set to off. Update the x1=2 row of table test.

Command> autocommit 0;
Command> update test set y1=y1 where x1=2;1 row updated.

Now, create a deadlock situation by executing update statements in both connections for rows that are locked by each other. The first connection executes an update against the row where x1=2.

Command> update test set y1=y1 where x1=2;
 6003: Lock request denied because of time-out
Details: Tran 2.1 (pid 32750) wants Un lock on rowid BMUFVUAAAAaAAAAETk, 
table ME.TEST. But tran 3.2 (pid 32731) has it in Xn (request was Xn).
Holder SQL (update t1 set y1=y1 where x1=2)
The command failed.

The second connection executes an update against the row where x1=1.

Command> update test set y1=y1 where x1=1;
 6002: Lock request denied because of deadlock
Details: Tran 3.2 (pid 32731) wants Un lock on rowid BMUFVUAAAAaAAAADzk, 
table ME.TEST. But tran 2.1 (pid 32750) has it in Xn (request was Xn). 
Holder SQL (update t1 set y1=y1 where x1=1)
The command failed.

Use the flush command to empty the buffer.

% ttTraceMon myDSN
Trace monitor; empty line to exit
Trace> flush

The trace buffer contains the following information showing all level 1 deadlock traces, as evidenced by '1L'.

Trace> dump
09:50:26.444      13 DEADLOCK 1L 2036C   3484P edge 1: xid 3.2, cid 3, 
<Row BMUFVUAAAAaAAAADzk,0x8c5
74(574836)> 0 cnt=1 , Tbl 'T1', SQL='update t1 set y1=y1 where x1=1'
09:50:26.455      14 DEADLOCK 1L 2036C   3484P edge 0: xid 2.1, cid 2, 
<Row BMUFVUAAAAaAAAAETk,0x8c5
74(574836)> 0 cnt=1 , Tbl 'T1', SQL='update t1 set y1=y1 where x1=2'
09:50:26.455      15 DEADLOCK 1L 2036C   3484P Victim: xcb:3.2, 
SQL='update t1 set y1=y1 where x1=1'

If you want more information, set DEADLOCK tracing to a higher value. For example, the following sets DEADLOCK tracing to level 4 in ttTraceMon:

Trace > level deadlock 4

LOCK tracing

Use the LOCK component to trace the locking behavior of your application to detect trouble with deadlocks or lock waits. LOCK tracing generates a great deal of volume, so it is important to choose the appropriate level of tracing. Level 3, for example, begins to generate a large number of traces, as traces are written for fairly common events. Also, the traces themselves may be hard to read in places. If you cannot discern enough information, contact TimesTen technical support for more information.

Table 1-4 describes the LOCK tracing levels. Each level with a '+' sign includes the trace information described for that level, plus all levels preceding it.

Table 1-4 LOCK tracing levels

Level Output

1

Deadlock cycles as they are discovered

2

+ Failures to grant locks for any reason

3

+ Lock waits (which may or may not be granted)

4

+ All lock grants/releases, some routine calls, and the mechanism of the deadlock detector

6

+ Each step in cycle traversal


Example 1-9 LOCK trace

In this example, execute ttTraceMon to do a LOCK trace at level 4 on myDSN database.

Make two connections to myDSN. For the first connection, set autocommit on. Create table test and insert three rows. Create a materialized view using table test.

Turn on tracing at level 4 and use the flush command to empty the buffer.

% ttTraceMon myDSN
Trace monitor; empty line to exit
Trace> level lock 4
Trace> flush

For the second connection to myDSN, set autocommit off. Insert a row into table test. Because autocommit is off, the row is not inserted into the table until the commit. A lock is held until the transaction is committed or rolled back.

If the dump command is used to display the contents of the trace buffer, there are no records in the trace buffer:

Trace> dump
0 records dumped

From the first connection, try to drop the materialized view. The view cannot be dropped because there is a transaction that has not been committed or rolled back:

Command> drop materialized view v;
 6003: Lock request denied because of time-out
Details: Tran 3.71 (pid 24524) wants Sn lock on table TTUSER.TEST. But tran 1.42 
(pid 24263) has it in IXn (request was IXn). Holder SQL (insert into test 
values (100);)
The command failed.

The trace buffer contains the following information:

Trace> dump
20:09:04.789  174759 LOCK     3L    3C  24524P ENQ: xcb:00003 <Tbl 0x9b894,0x0>
0+Sn=>SL activity 0 Sn cnt=0; Holder xcb:00001 IXn
20:09:04.789  174760 LOCK     3L    3C  24524P Connection 3 scheduled for sleep
20:09:04.789  174761 LOCK     3L    3C  24524P Connection 3 sleeping
20:09:14.871  174762 LOCK     3L 2047C  24237P Connection 3 timed out
20:09:14.871  174763 LOCK     3L 2047C  24237P Connection 3 woken up
20:09:14.871  174764 LOCK     3L    3C  24524P Connection 3 awake
20:09:14.871  174765 LOCK     2L    3C  24524P ENQ: xcb:00003 <Tbl 0x9b894,0x0>
0+Sn=>TM activity 0 Sn cnt=1; Holder xcb:00001 IXn
7 records dumped

When finished with the trace, set LOCK tracing back to its default setting (0) and exit ttTraceMon:

Trace > level lock 0
Trace > {press ENTER – blank line}

ERR tracing

It may be useful to trace the ERR component. For example, an ERR trace at level 4 shows all of the error messages that are pushed in the TimesTen direct driver (not all errors are output to the user because they are handled internally). ERR tracing at level 1 is the default. No output is written for ERR tracing at level 2 and 3.

Table 1-5 describes ERR tracing levels. Each level with a '+' sign includes the trace information described for that level, plus all levels preceding it.

Table 1-5 ERR tracing levels

Level Output

1 (set by default)

Fatal errors

4

+ All other error messages, many of which are handled internally by TimesTen


Example 1-10 ERR trace

In this example, execute ttTraceMon to do a ERR trace at level 4 on myDSN database.

First, create a table:

Command> create table test (id tt_integer);

Next, turn on tracing at level 4. Rather than direct the trace output to a file as in the previous examples, read it directly from the trace buffer. Before saving the ERR trace to the buffer, use the flush command to empty the buffer.

% ttTraceMon myDSN
Trace monitor; empty line to exit
Trace> level err 4
Trace> flush

Now execute a SQL script with three errors in it. The errors are:

  • Creating a table with the same name as an existing table

  • Using incorrect syntax to insert values into the table

  • Inserting CHAR data into a TT_INTEGER column

Command> create table test (id tt_integer);
 2207: Table TEST already exists
The command failed.
Command> insert into test values 'abcd');
 1001: Syntax error in SQL statement before or at: "'abcd'", character position:
 25
insert into test values 'abcd');
                        ^^^^^^
The command failed.
Command> insert into test values ('abcd');
 2609: Incompatible types found in expression
The command failed.

The trace information is written to the trace buffer. Display it by using the dump command.

Trace> dump
19:28:40.465  174227 ERR      4L    1C  24263P TT2207: Table TEST already exists
 -- file "eeDDL.c", lineno 2930, procedure "sbEeCrDtblEval()"
19:28:51.399  174228 ERR      4L    1C  24263P TT1001: Syntax error in SQL 
statement before or at: "'abcd'", character position: 25
insert into test values 'abcd');
                        ^^^^^^
 -- file "ptSqlY.y", lineno 6273, procedure "reserved_word_or_syntax_error"
19:29:00.725  174229 ERR      4L    1C  24263P TT2609: Incompatible types found
in expression -- file "saCanon.c", lineno 12618, procedure "sbPtAdjustType()"
3 records dumped

Set ERR tracing back to its default setting (1) and exit ttTraceMon:

Trace > level err 1
Trace > {press ENTER – blank line}

AGING tracing

Use the ttTraceMon utility to obtain the following information:

  • When aging starts and ends

  • How many rows have been deleted by the aging subdaemon

See "Implementing aging in your tables" in the Oracle TimesTen In-Memory Database Operations Guide.

Table 1-6 describes the AGING tracing levels. Each level with a '+' sign includes the trace information described for that level, plus all levels preceding it.

Table 1-6 AGING tracing levels

Level Description

1

Messages about the following events:

  • The aging subdaemon starts least recently used (LRU) or time-based aging.

  • The aging subdaemon repeats LRU aging because the LRU threshold was not met.

  • The aging subdaemon ends LRU or time-based aging.

2

+ Messages about the following events for each table:

  • Aging has started.

  • Aging has ended. The message includes the reason for ending and the total number of rows deleted.

3

+ Detailed report on how many rows were deleted during each aging cycle

4

+ Message every time the aging subdaemon wakes up


Example 1-11 AGING trace

In this example, execute ttTraceMon to do an AGING trace on myDSN database. The database contains TTUSER.MYTAB table, which has a time-based aging policy. The table is described as follows:

Command> describe TTUSER.MYTAB;

Table TTUSER.MYTAB:
  Columns:
   *ID                              TT_INTEGER NOT NULL
    TS                              TIMESTAMP (6) NOT NULL
  Aging use TS lifetime 3 minutes cycle 1 minute on

1 table found.
(primary key columns are indicated with *)

The table contains the following rows before the aging cycle begins:

Command> select * from TTUSER.MYTAB;
< 1, 2007-03-21 12:54:06.000000 >
< 3, 2010-03-17 08:00:00.000000 >
< 4, 2007-03-21 12:59:40.000000 >
< 5, 2007-03-21 13:00:10.000000 >
< 6, 2007-03-21 13:01:22.000000 >
5 rows found.

Execute ttTraceMon to do an AGING trace at level 3. Rather than direct the trace output to a file, read it directly from the trace buffer. Before saving the AGING trace to the buffer, use the flush command to empty the buffer.

% ttTraceMon myDSN
Trace monitor; empty line to exit
Trace> level aging 3
Trace> flush

Display the trace information in the buffer by using the dump command.

Trace> dump
13:16:56.802    1247 AGING    1L 2045C  17373P Entering sbAgingTB(): curTime=78
13:16:56.803    1248 AGING    2L 2045C  17373P Entering sbAgingOneTable(): 
curTime=78, ltblid= 637140
13:16:56.804    1249 AGING    3L 2045C  17373P curTime=78, 4 deleted, 1 
remaining, tbl = TTUSER.MYTAB
13:16:56.804    1250 AGING    2L 2045C  17373P Exiting sbAgingOneTable(): 
curTime=78, reason = 'no more rows', 4 deleted, 1 remaining, tbl = TTUSER.MYTAB
13:16:56.804    1251 AGING    1L 2045C  17373P Exiting sbAgingTB(): curTime=78
5 records dumped

Set AGING tracing back to its default setting (0) and exit ttTraceMon:

Trace > level aging 0
Trace > {press ENTER – blank line}

AUTOREFRESH tracing

Use the ttTraceMon utility to obtain information about the progress of autorefresh operations for cache groups with the AUTOREFRESH cache group attribute.

See "AUTOREFRESH cache group attribute" in the Oracle TimesTen Application-Tier Database Cache User's Guide.

Table 1-7 describes AUTOREFRESH tracing levels. Each level with a '+' sign includes the trace information described for that level, plus all levels preceding it.

Table 1-7 AUTOREFRESH tracing levels

Level Description

1

Autorefresh summary for the interval:

  • The time that autorefresh started

  • Number of autorefreshed rows for the interval

  • Number of autorefreshed root table rows for interval

  • Total number of autorefreshed rows since the cache agent started

  • Total number of autorefreshed rows in the root table since the cache agent started

  • The time that autorefresh ended

Note: Times and information about root table rows are reported for full autorefresh.

2

+ Autorefresh summary at the cache group level:

  • The time that autorefresh started for each cache group

  • Number of autorefreshed rows for each cache group

  • Number of autorefreshed root table rows for each cache group

  • Total number of autorefreshed rows for each cache group since the cache agent started

  • Total number of autorefreshed rows in the root table for each cache group since the cache agent started

  • The time that autorefresh ended for each cache group

Note: Times and information about root table rows are reported for full autorefresh.

3

+ Autorefresh summary at the table level:

  • The time that autorefresh started

  • Number of autorefreshed rows

  • Total number of autorefreshed rows since the cache agent started

  • The time that autorefresh ended

4

+ Autorefresh details for each table:

  • The time that autorefresh started for each table

  • The autorefresh query

  • Query execute time in milliseconds on the Oracle database

  • Query fetch time in milliseconds on the Oracle database

  • Query apply time in milliseconds on TimesTen

  • Query execute time in milliseconds on the Oracle database for child tables

  • Query fetch time in milliseconds on the Oracle database for child tables

  • Query apply time in milliseconds on TimesTen for child tables

  • The time that autorefresh ended for each table

  • The autorefresh bookmark (logseq) to which autorefresh was completed


Example 1-12 AUTOREFRESH trace

In this example, use the ttTraceMon utility to trace autorefresh operations on the cgDSN database. When the trace level is set to 1, the displayed information is similar to the output of the ttCacheAutorefreshStatsGet built-in procedure.

% tttracemon cgDSN
Trace monitor; empty line to exit
Trace> level autorefresh 1
Trace> dump

08:56:57.445 19398 AUTOREFRESH 1L 5C 32246P Autorefresh number 1415 started 
for interval 60000
08:56:57.883 19419 AUTOREFRESH 1L 5C 32246P Duration For Interval 60000ms: 420
08:56:57.883 19420 AUTOREFRESH 1L 5C 32246P Num Rows For Interval 60000ms: 0
08:56:57.883 19421 AUTOREFRESH 1L 5C 32246P Num Root Rows For Interval 
60000ms: 0
08:56:57.883 19422 AUTOREFRESH 1L 5C 32246P Cumulative Rows for Interval 
60000ms: 11587
08:56:57.883 19423 AUTOREFRESH 1L 5C 32246P Cumulative Root Rows for Interval 60000ms: 1697
08:56:57.883 19424 AUTOREFRESH 1L 5C 32246P Autorefresh number 1415 ended for 
interval 60000ms successfully.
7 records dumped

Tracing at level 4 produces additional information about autorefresh operation 1415. Information about autorefresh is provided for the testuser.readcache cache group, the testuser.readtab root table and the autorefresh interval.

Trace> level autorefresh 4
Trace> dump

08:56:57.445 19398 AUTOREFRESH 1L 5C 32246P Autorefresh number 1415 started for 
interval 60000
08:56:57.471 19399 AUTOREFRESH 2L 5C 32246P Autorefresh started for cachegroup 
TESTUSER.READCACHE
08:56:57.471 19400 AUTOREFRESH 3L 5C 32246P Incremental autorefresh started for 
table TESTUSER.READTAB
08:56:57.471 19401 AUTOREFRESH 4L 5C 32246P Autorefresh Query: SELECT L."COL_10", 
X."COL_20", X.ft$NotDelete, Z.rowid FROM (SELECT DISTINCT "COL_10" FROM 
"TESTUSER"."TT_06_454854_L" WHERE logseq >:logseq AND ft_cacheGroup <> 
100000000000*1844259679+-299200618) L,(SELECT "TESTUSER"."READTAB"."COL_10", 
"TESTUSER"."READTAB"."COL_20", 1 AS ft$NotDelete  FROM "TESTUSER"."READTAB", 
"TESTUSER"."T1" WHERE "TESTUSER"."READTAB"."COL_10" = "TESTUSER"."T1"."COL_10") 
X, "TESTUSER"."READTAB" Z WHERE L ."COL_10" = X."COL_10" (+) AND X."COL_10" = 
Z."COL_10" (+), logseq: 7
08:56:57.870 19402 AUTOREFRESH 3L 5C 32246P Duration for table 
TESTUSER.READTAB: 70
08:56:57.870 19403 AUTOREFRESH 3L 5C 32246P Num Rows for table 
TESTUSER.READTAB: 1
08:56:57.870 19404 AUTOREFRESH 3L 5C 32246P Cumulative rows for table 
TESTUSER.READTAB: 1559
08:56:57.870 19405 AUTOREFRESH 4L 5C 32246P Autorefresh Query Execute duration 
for table TESTUSER.READTAB: 60
08:56:57.870 19406 AUTOREFRESH 4L 5C 32246P Autorefresh Query Fetch duration for 
table TESTUSER.READTAB: 0
08:56:57.870 19407 AUTOREFRESH 4L 5C 32246P Autorefresh Query Apply duration for 
table TESTUSER.READTAB: 0
08:56:57.870 19408 AUTOREFRESH 4L 5C 32246P Max logseq applied for table 
TESTUSER.READTAB: 8
08:56:57.870 19409 AUTOREFRESH 4L 5C 32246P Autorefresh Query Execute duration 
for 7 child(ren) table(s): 32
08:56:57.870 19410 AUTOREFRESH 4L 5C 32246P Autorefresh Query Fetch duration for 
7 child(ren) table(s): 0
08:56:57.870 19411 AUTOREFRESH 4L 5C 32246P Autorefresh Query Apply duration for 
7 child(ren) table(s): 0
08:56:57.870 19412 AUTOREFRESH 3L 5C  32246P Incremental autorefresh ended for 
table TESTUSER.READTAB
08:56:57.872 19413 AUTOREFRESH 2L 5C 32246P Duration For Cache Group 
TESTUSER.READCACHE: 1020
08:56:57.872 19414 AUTOREFRESH 2L 5C 32246P Num Rows For Cache Group 
TESTUSER.READCACHE: 1
08:56:57.872 19415 AUTOREFRESH 2L 5C 32246P Num Root Rows For Cache Group 
TESTUSER.READCACHE: 0
08:56:57.872 19416 AUTOREFRESH 2L 5C 32246P Cumulative Rows for Cache Group 
TESTUSER.READCACHE: 11776
08:56:57.872 19417 AUTOREFRESH 2L 5C 32246P Cumulative Root Rows for Cache Group 
TESTUSER.READCACHE: 1697
08:56:57.872 19418 AUTOREFRESH 2L 5C 32246P Autorefresh ended for cache group 
TESTUSER.READCACHE
08:56:57.883 19419 AUTOREFRESH 1L 5C 32246P Duration For Interval 60000ms: 420
08:56:57.883 19420 AUTOREFRESH 1L 5C 32246P Num Rows For Interval 60000ms: 0
08:56:57.883 19421 AUTOREFRESH 1L 5C 32246P Num Root Rows For Interval 
60000ms: 0
08:56:57.883 19422 AUTOREFRESH 1L 5C 32246P Cumulative Rows for Interval 
60000ms: 11587
08:56:57.883 19423 AUTOREFRESH 1L 5C 32246P Cumulative Root Rows for Interval 
60000ms: 1697
08:56:57.883 19424 AUTOREFRESH 1L 5C 32246P Autorefresh number 1415 ended for 
interval 60000ms successfully.
27 records dumped

Set AUTOREFRESH tracing back to its default setting (0) and exit ttTraceMon:

Trace > level autorefresh 0
Trace > {press ENTER – blank line}

Using the ttXactAdmin utility

The ttXactAdmin utility displays ownership, status, log and lock information for each outstanding transaction. You can also use it to show all current connections to a database. The ttXactAdmin utility is useful for troubleshooting problems with replication, XLA, and asynchronous writethrough cache groups.

Example 1-13 Using ttXactAdmin to diagnose a lock timeout

Use ttXactAdmin to diagnose a lock timeout. Consider two connections that are trying to update the same row. The following transaction by Connection 1 is in progress:

UPDATE table1 SET c1 = 2 WHERE c1 = 1;

Connection 2 attempts to make the following update:

UPDATE table1 SET c1 = 3 WHERE c1 = 1;

Connection 2 receives the following error:

6003: Lock request denied because of time-out
  Details: Tran 2.3 (pid 2880) wants Un lock on rowid 0x00156bbc, table
 TTUSER.TABLE1.
  But tran 1.21 (pid 2564) has it in Xn (request was Xn). Holder SQL 
(update table1 set c1 = 2 where c1 = 1;)
  The command failed.

The details of the error indicate that transaction 1.21 has a lock on row 0x00156bbc, the row that transaction 2.3 wants to update. ttXactAdmin displays this information in output that pertains to actions in the entire database:

$ ttXactAdmin myDSN
2011-03-07 12:57:41.237
c:\datastore\myDSN
TimesTen Release 11.2.2.0.0

Outstanding locks

PID   Context   TransID  TransStatus  Resource   ResourceID   Mode Name

Program File Name: ttIsql

2564  0xeeb9a8  1.21     Active       Database   0x01312d00   IX
                                      Row        0x00156bbc   Xn   TTUSER.TABLE1
                                      Table      1910868      IXn  TTUSER.TABLE1

Program File Name: ttIsql

2880  0xeeb9a8  2.3      Active        Database   0x01312d00  IX
                                       Table      1910868     IXn  TTUSER.TABLE1
                                       Command    19972120    S

Awaiting locks

PID  Context   TransID Resource ResourceID  RMode HolderTransID HMode Name
2880 0xeeb9a8  2.3     Row      0x00156bbc  Un    1.21          Xn TTUSER.TABLE1

2 outstanding transactions found

See "ttXactAdmin" in the Oracle TimesTen In-Memory Database Reference.

Using ODBC tracing

On Windows, use the ODBC trace facility to verify the sequence and content of your commands. The ODBC trace facility works only if you have linked your application with the ODBC Driver Manager. Enable tracing by double-clicking ODBC in the Control Panel. This opens the ODBC Data Source Administrator. Choose the Tracing tab.

On UNIX platforms, ODBC tracing is available only when using a driver manager. To turn on tracing, set the Trace and TraceFile attributes.

Using SNMP traps to detect events

Network management software uses SNMP (Simple Network Management Protocol) to query or control the state of network devices such as routers and switches. These devices can generate alerts called traps to inform the network management systems of problems.

TimesTen sends SNMP traps for particular critical events to help facilitate user recovery mechanisms. These events are also recorded in the support log. Exposing them through SNMP traps enables network management software to take immediate action.

How to configure TimesTen to generate SNMP traps and how to receive the traps is described in "Diagnostics through SNMP Traps" in the Oracle TimesTen In-Memory Database Error Messages and SNMP Traps.

Monitoring the TimesTen system tables

Each TimesTen database contains a group of system tables that store metadata about the current state of the database. The system tables are described in "System Tables" in the Oracle TimesTen In-Memory Database System Tables and Views Reference.

Note:

You can execute SELECT statements on a system table, but you cannot execute a statement such as INSERT, UPDATE or DELETE on these tables.

Use the system table SYS.SYSTEMSTATS to view database metrics. In addition, the ttStats utility enables you to monitor database metrics and to take and compare snapshots of metrics. For more information, see "SYS.SYSTEMSTATS" in the Oracle TimesTen In-Memory Database System Tables and Views Reference, "ttStats" in the Oracle TimesTen In-Memory Database Reference, and "TT_STATS" in the Oracle TimesTen In-Memory Database PL/SQL Packages Reference.

You can also view the SYS.MONITOR table, which contains statistics about certain events that have occurred since the first connection to the database. For example, the SYS.MONITOR table contains information about the number of connections to the database; the number of checkpoints taken; the size of the database; and the amount of memory currently in use. Check the contents of the SYS.MONITOR table by executing SELECT statements on the columns or by using the ttIsql monitor command. For an example of how to use the ttIsql monitor command, see "Using the ttIsql Utility" in the Oracle TimesTen In-Memory Database Operations Guide.

Using the query optimizer

The query optimizer is an important tool for performance tuning.

For details about using the query optimizer, see:

If you find that a given query runs more slowly than expected, confirm that the query optimizer has the latest statistics for the tables in your query, as described in "Update query optimizer statistics". If, after updating your statistics, your query still runs too slowly, it is possible that the TimesTen optimizer is not choosing the optimal query plan to answer that query. Under these circumstances, you can adjust how the optimizer generates a plan by using the ttOpt procedures described in "Modifying plan generation" in the Oracle TimesTen In-Memory Database Operations Guide. You can also use statement level optimizer hints to influence the optimizer at the statement level. For more information, see "Statement level optimizer hints" in the Oracle TimesTen In-Memory Database SQL Reference.