Home » RDBMS Server » Server Utilities » How to run TKPROF on Oracle9i(9.0.1)
How to run TKPROF on Oracle9i(9.0.1) [message #74222] Wed, 13 October 2004 20:29 Go to next message
Gurinder Mann
Messages: 7
Registered: October 2004
Junior Member
How can i run TKProf utility on Oracle9i(9.0.1)
version
Thanx Gurinder
Re: How to run TKPROF on Oracle9i(9.0.1) [message #74228 is a reply to message #74222] Thu, 14 October 2004 06:34 Go to previous messageGo to next message
Frank Naude
Messages: 4502
Registered: April 1998
Senior Member
Hi,

Same as with previous versions - use the tkprof command. Example:

tkprof orcl_ora_4930.trc report.out SYS=NO EXPLAIN=SCOTT/TIGER


Best regards.

Frank
Re: How to run TKPROF on Oracle9i(9.0.1) [message #74360 is a reply to message #74222] Thu, 25 November 2004 00:24 Go to previous messageGo to next message
hemanth
Messages: 4
Registered: September 2000
Junior Member
Using SQL Trace and TKPROF
The SQL Trace facility and TKPROF are two basic performance diagnostic tools that can help you monitor and tune applications running against the Oracle Server.
This chapter contains the following sections:
Understanding SQL Trace and TKPROF
Using the SQL Trace Facility and TKPROF
Avoiding Pitfalls in TKPROF Interpretation
Sample TKPROF Output
Understanding SQL Trace and TKPROF
The SQL Trace facility and TKPROF let you accurately assess the efficiency of the SQL statements an application runs. For best results, use these tools with EXPLAIN PLAN rather than using EXPLAIN PLAN alone.
Understanding the SQL Trace Facility
The SQL Trace facility provides performance information on individual SQL statements. It generates the following statistics for each statement:
Parse, execute, and fetch counts
CPU and elapsed times
Physical reads and logical reads
Number of rows processed
Misses on the library cache
Username under which each parse occurred
Each commit and rollback
You can enable the SQL Trace facility for a session or for an instance. When the SQL Trace facility is enabled, performance statistics for all SQL statements executed in a user session or in the instance are placed into trace files.
The additional overhead of running the SQL Trace facility against an application with performance problems is normally insignificant compared with the inherent overhead caused by the application's inefficiency.
Note: Try to enable SQL Trace only for statistics collection and on specific sessions. If you must enable the facility on an entire production environment, then you can minimize performance impact with the following: Maintain at least 25% idle CPU capacity. Maintain adequate disk space for the USER_DUMP_DEST location. Stripe disk space over sufficient disks.
Understanding TKPROF
You can run the TKPROF program to format the contents of the trace file and place the output into a readable output file. Optionally, TKPROF can also:
Determine the execution plans of SQL statements
Create a SQL script that stores the statistics in the database
TKPROF reports each statement executed with the resources it has consumed, the number of times it was called, and the number of rows which it processed. This information lets you easily locate those statements that are using the greatest resource. With experience or with baselines available, you can assess whether the resources used are reasonable given the work done.
Using the SQL Trace Facility and TKPROF
Follow these steps to use the SQL Trace facility and TKPROF:
1. Set initialization parameters for trace file management.
See "Step 1: Setting Initialization Parameters for Trace File Management".
2. Enable the SQL Trace facility for the desired session, and run the application. This step produces a trace file containing statistics for the SQL statements issued by the application.
See "Step 2: Enabling the SQL Trace Facility".
3. Run TKPROF to translate the trace file created in Step 2 into a readable output file. This step can optionally create a SQL script that can be used to store the statistics in a database.
See "Step 3: Formatting Trace Files with TKPROF".
4. Interpret the output file created in Step 3.
See "Step 4: Interpreting TKPROF Output".
5. Optionally, run the SQL script produced in Step 3 to store the statistics in the database.
See "Step 5: Storing SQL Trace Facility Statistics".
In the following sections, each of these steps is discussed in depth.
Step 1: Setting Initialization Parameters for Trace File Management
When the SQL Trace facility is enabled for a session, Oracle generates a trace file containing statistics for traced SQL statements for that session. When the SQL Trace facility is enabled for an instance, Oracle creates a separate trace file for each process. Before enabling the SQL Trace facility:
1. Check the settings of the TIMED_STATISTICS, MAX_DUMP_FILE_SIZE, and USER_DUMP_DEST initialization parameters. See Table 10-1.
Table 10-1 Initialization Parameters to Check Before Enabling SQL Trace
Parameter Description
TIMED_STATISTICS This enables and disables the collection of timed statistics, such as CPU and elapsed times, by the SQL Trace facility, as well as the collection of various statistics in the dynamic performance tables. The default value of false disables timing. A value of true enables timing. Enabling timing causes extra timing calls for low-level operations. This is a dynamic parameter. It is also a session parameter.
MAX_DUMP_FILE_SIZE When the SQL Trace facility is enabled at the instance level, every call to the server produces a text line in a file in the operating system's file format. The maximum size of these files (in operating system blocks) is limited by this initialization parameter. The default is 500. If you find that the trace output is truncated, then increase the value of this parameter before generating another trace file. This is a dynamic parameter. It is also a session parameter.
USER_DUMP_DEST This must fully specify the destination for the trace file according to the conventions of the operating system. The default value is the default destination for system dumps on the operating system.This value can be modified with ALTER SYSTEM SET USER_DUMP_DEST= newdir. This is a dynamic parameter. It is also a session parameter.
Note: Timed statistics are automatically collected for the database if the initialization parameter STATISTICS_LEVEL is set to TYPICAL or ALL. If STATISTICS_LEVEL is set to BASIC, then you must set TIMED_STATISTICS to TRUE to enable collection of timed statistics. If you explicitly set DB_CACHE_ADVICE, TIMED_STATISTICS, or TIMED_OS_STATISTICS, either in the initialization parameter file or by using ALTER_SYSTEM or ALTER SESSION, the explicitly set value overrides the value derived from STATISTICS_LEVEL.
2. Devise a way of recognizing the resulting trace file.
Be sure you know how to distinguish the trace files by name. Oracle writes them to the user dump destination specified by USER_DUMP_DEST. However, this directory can soon contain many hundreds of files, usually with generated names. It might be difficult to match trace files back to the session or process that created them. You can tag trace files by including in your programs a statement like SELECT program_name FROM DUAL. You can then trace each file back to the process that created it.
3. If the operating system retains multiple versions of files, then be sure that the version limit is high enough to accommodate the number of trace files you expect the SQL Trace facility to generate.
4. The generated trace files can be owned by an operating system user other than yourself. This user must make the trace files available to you before you can use TKPROF to format them.
Step 2: Enabling the SQL Trace Facility
Enable the SQL Trace facility for the session by using one of the following:
DBMS_SESSION.SET_SQL_TRACE procedure
ALTER SESSION SET SQL_TRACE = TRUE;
You can enable SQL Trace in another session by using the DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION procedure.
Caution: Because running the SQL Trace facility increases system overhead, enable it only when tuning SQL statements, and disable it when you are finished. You might need to modify an application to contain the ALTER SESSION statement. For example, to issue the ALTER SESSION statement in Oracle Forms, invoke Oracle Forms using the -s option, or invoke Oracle Forms (Design) using the statistics option. For more information on Oracle Forms, see the Oracle Forms Reference.
To disable the SQL Trace facility for the session, enter:
ALTER SESSION SET SQL_TRACE = FALSE;

The SQL Trace facility is automatically disabled for the session when the application disconnects from Oracle.
You can enable the SQL Trace facility for an instance by setting the value of the SQL_TRACE initialization parameter to TRUE in the initialization file.
SQL_TRACE = TRUE

After the instance has been restarted with the updated initialization parameter file, SQL Trace is enabled for the instance and statistics are collected for all sessions. If the SQL Trace facility has been enabled for the instance, you can disable it for the instance by setting the value of the SQL_TRACE parameter to FALSE.
Note: Setting SQL_TRACE to TRUE can have a severe performance impact. For more information.
Step 3: Formatting Trace Files with TKPROF
TKPROF accepts as input a trace file produced by the SQL Trace facility, and it produces a formatted output file. TKPROF can also be used to generate execution plans.
After the SQL Trace facility has generated a number of trace files, you can:
Run TKPROF on each individual trace file, producing a number of formatted output files, one for each session.
Concatenate the trace files, and then run TKPROF on the result to produce a formatted output file for the entire instance.
TKPROF does not report COMMITs and ROLLBACKs that are recorded in the trace file.
Sample TKPROF Output
Sample output from TKPROF is as follows:
SELECT * FROM emp, dept
WHERE emp.deptno = dept.deptno;

call count cpu elapsed disk query current rows
---- ------- ------- --------- -------- -------- ------- ------
Parse 1 0.16 0.29 3 13 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.03 0.26 2 2 4 14

Misses in library cache during parse: 1
Parsing user id: (8) SCOTT

Rows Execution Plan
------- ---------------------------------------------------
14 MERGE JOIN
4 SORT JOIN
4 TABLE ACCESS (FULL) OF 'DEPT'
14 SORT JOIN
14 TABLE ACCESS (FULL) OF 'EMP'
For this statement, TKPROF output includes the following information:
The text of the SQL statement
The SQL Trace statistics in tabular form
The number of library cache misses for the parsing and execution of the statement.
The user initially parsing the statement.
The execution plan generated by EXPLAIN PLAN.
TKPROF also provides a summary of user level statements and recursive SQL calls for the trace file.
Syntax of TKPROF
TKPROF::=

Text description of the illustration sqltracea.gif
If you invoke TKPROF without arguments, then online help is displayed. Use the arguments in Table 10-2 with TKPROF.
Table 10-2 TKPROF Arguments
Argument Description
filename1 Specifies the input file, a trace file containing statistics produced by the SQL Trace facility. This file can be either a trace file produced for a single session, or a file produced by concatenating individual trace files from multiple sessions.
filename2 Specifies the file to which TKPROF writes its formatted output.
WAITS Specifies whether to record summary for any wait events found in the trace file. Values are YES or NO.
SORTS Sorts traced SQL statements in descending order of specified sort option before listing them into the output file. If more than one option is specified, then the output is sorted in descending order by the sum of the values specified in the sort options. If you omit this parameter, then TKPROF lists statements into the output file in order of first use. Sort options are listed as follows:
PRSCNT Number of times parsed.
PRSCPU CPU time spent parsing.
PRSELA Elapsed time spent parsing.
PRSDSK Number of physical reads from disk during parse.
PRSQRY Number of consistent mode block reads during parse.
PRSCU Number of current mode block reads during parse.
PRSMIS Number of library cache misses during parse.
EXECNT Number of executes.
EXECPU CPU time spent executing.
EXEELA Elapsed time spent executing.
EXEDSK Number of physical reads from disk during execute.
EXEDSK Number of physical reads from disk during execute.
EXEQRY Number of consistent mode block reads during execute.
EXECU Number of current mode block reads during execute.
EXEROW Number of rows processed during execute.
EXEMIS Number of library cache misses during execute.
FCHCNT Number of fetches.
FCHCPU CPU time spent fetching.
FCHELA Elapsed time spent fetching.
FCHDSK Number of physical reads from disk during fetch.
FCHQRY Number of consistent mode block reads during fetch.
FCHCU Number of current mode block reads during fetch.
FCHROW Number of rows fetched.
PRINT Lists only the first integer sorted SQL statements from the output file. If you omit this parameter, then TKPROF lists all traced SQL statements. This parameter does not affect the optional SQL script. The SQL script always generates insert data for all traced SQL statements.
AGGREGATE If you specify AGGREGATE = NO, then TKPROF does not aggregate multiple users of the same SQL text.
INSERT Creates a SQL script that stores the trace file statistics in the database. TKPROF creates this script with the name filename3. This script creates a table and inserts a row of statistics for each traced SQL statement into the table.
SYS Enables and disables the listing of SQL statements issued by the user SYS, or recursive SQL statements, into the output file. The default value of YES causes TKPROF to list these statements. The value of NO causes TKPROF to omit them. This parameter does not affect the optional SQL script. The SQL script always inserts statistics for all traced SQL statements, including recursive SQL statements.
TABLE Specifies the schema and name of the table into which TKPROF temporarily places execution plans before writing them to the output file. If the specified table already exists, then TKPROF deletes all rows in the table, uses it for the EXPLAIN PLAN statement (which writes more rows into the table), and then deletes those rows. If this table does not exist, then TKPROF creates it, uses it, and then drops it. The specified user must be able to issue INSERT, SELECT, and DELETE statements against the table. If the table does not already exist, then the user must also be able to issue CREATE TABLE and DROP TABLE statements. For the privileges to issue these statements, see the Oracle9i SQL Reference. This option allows multiple individuals to run TKPROF concurrently with the same user in the EXPLAIN value. These individuals can specify different TABLE values and avoid destructively interfering with each other's processing on the temporary plan table. If you use the EXPLAIN parameter without the TABLE parameter, then TKPROF uses the table PROF$PLAN_TABLE in the schema of the user specified by the EXPLAIN parameter. If you use the TABLE parameter without the EXPLAIN parameter, then TKPROF ignores the TABLE parameter. If no plan table exists, TKPROF creates the table PROF$PLAN_TABLE and then drops it at the end.
EXPLAIN Determines the execution plan for each SQL statement in the trace file and writes these execution plans to the output file. TKPROF determines execution plans by issuing the EXPLAIN PLAN statement after connecting to Oracle with the user and password specified in this parameter. The specified user must have CREATE SESSION system privileges. TKPROF takes longer to process a large trace file if the EXPLAIN option is used.
RECORD Creates a SQL script with the specified filename with all of the nonrecursive SQL in the trace file. This can be used to replay the user events from the trace file.
WIDTH An integer that controls the output line width of some TKPROF output, such as the explain plan. This parameter is useful for post-processing of TKPROF output.
Examples of TKPROF Statement
This section provides two brief examples of TKPROF usage. For an complete example of TKPROF output, see "Sample TKPROF Output".
TKPROF Example 1
If you are processing a large trace file using a combination of SORT parameters and the PRINT parameter, then you can produce a TKPROF output file containing only the highest resource-intensive statements. For example, the following statement prints the 10 statements in the trace file that have generated the most physical I/O:
TKPROF ora53269.trc ora53269.prf SORT = (PRSDSK, EXEDSK, FCHDSK) PRINT = 10
TKPROF Example 2
This example runs TKPROF, accepts a trace file named dlsun12_jane_fg_sqlplus_007.trc, and writes a formatted output file named outputa.prf:
TKPROF dlsun12_jane_fg_sqlplus_007.trc OUTPUTA.PRF
EXPLAIN=scott/tiger TABLE=scott.temp_plan_table_a INSERT=STOREA.SQL SYS=NO
SORT=(EXECPU,FCHCPU)

This example is likely to be longer than a single line on the screen, and you might need to use continuation characters, depending on the operating system.
Note the other parameters in this example:
The EXPLAIN value causes TKPROF to connect as the user scott and use the EXPLAIN PLAN statement to generate the execution plan for each traced SQL statement. You can use this to get access paths and row source counts.
The TABLE value causes TKPROF to use the table temp_plan_table_a in the schema scott as a temporary plan table.
The INSERT value causes TKPROF to generate a SQL script named STOREA.SQL that stores statistics for all traced SQL statements in the database.
The SYS parameter with the value of NO causes TKPROF to omit recursive SQL statements from the output file. In this way, you can ignore internal Oracle statements such as temporary table operations.
The SORT value causes TKPROF to sort the SQL statements in order of the sum of the CPU time spent executing and the CPU time spent fetching rows before writing them to the output file. For greatest efficiency, always use SORT parameters.
Step 4: Interpreting TKPROF Output
This section provides pointers for interpreting TKPROF output.
Tabular Statistics in TKPROF
Library Cache Misses in TKPROF
Statement Truncation in SQL Trace
Identification of User Issuing the SQL Statement in TKPROF
Execution Plan in TKPROF
Deciding Which Statements to Tune
While TKPROF provides a very useful analysis, the most accurate measure of efficiency is the actual performance of the application in question. At the end of the TKPROF output is a summary of the work done in the database engine by the process during the period that the trace was running.
Tabular Statistics in TKPROF
TKPROF lists the statistics for a SQL statement returned by the SQL Trace facility in rows and columns. Each row corresponds to one of three steps of SQL statement processing. Statistics are identified by the value of the CALL column. See Table 10-3.
Table 10-3 CALL Column Values
CALL Value Meaning
PARSE Translates the SQL statement into an execution plan, including checks for proper security authorization and checks for the existence of tables, columns, and other referenced objects.
EXECUTE Actual execution of the statement by Oracle. For INSERT, UPDATE, and DELETE statements, this modifies the data. For SELECT statements, this identifies the selected rows.
FETCH Retrieves rows returned by a query. Fetches are only performed for SELECT statements.
The other columns of the SQL Trace facility output are combined statistics for all parses, all executes, and all fetches of a statement. The sum of query and current is the total number of buffers accessed, also called Logical I/Os (LIOs). See Table 10-4.
Table 10-4 SQL Trace Statistics for Parses, Executes, and Fetches.
SQL Trace Statistic Meaning
COUNT Number of times a statement was parsed, executed, or fetched.
CPU Total CPU time in seconds for all parse, execute, or fetch calls for the statement. This value is zero (0) if TIMED_STATISTICS is not turned on.
ELAPSED Total elapsed time in seconds for all parse, execute, or fetch calls for the statement. This value is zero (0) if TIMED_STATISTICS is not turned on.
DISK Total number of data blocks physically read from the datafiles on disk for all parse, execute, or fetch calls.
QUERY Total number of buffers retrieved in consistent mode for all parse, execute, or fetch calls. Usually, buffers are retrieved in consistent mode for queries.
CURRENT Total number of buffers retrieved in current mode. Buffers are retrieved in current mode for statements such as INSERT, UPDATE, and DELETE.
Statistics about the processed rows appear in the ROWS column. See Table 10-5.
Table 10-5 SQL Trace Statistics for the ROWS Column
SQL Trace Statistic Meaning
ROWS Total number of rows processed by the SQL statement. This total does not include rows processed by subqueries of the SQL statement.
For SELECT statements, the number of rows returned appears for the fetch step. For UPDATE, DELETE, and INSERT statements, the number of rows processed appears for the execute step.
Note: The row source counts are displayed when a cursor is closed. In SQL*Plus, there is only one user cursor, so each statement executed causes the previous cursor to be closed; therefore, the row source counts are displayed. PL/SQL has its own cursor handling and does not close child cursors when the parent cursor is closed. Exiting (or reconnecting) causes the counts to be displayed.
Interpreting the Resolution of Statistics
Timing statistics have a resolution of one hundredth of a second; therefore, any operation on a cursor that takes a hundredth of a second or less might not be timed accurately. Keep this in mind when interpreting statistics. In particular, be careful when interpreting the results from simple queries that execute very quickly.
Understanding Recursive Calls
Sometimes, in order to execute a SQL statement issued by a user, Oracle must issue additional statements. Such statements are called recursive calls or recursive SQL statements. For example, if you insert a row into a table that does not have enough space to hold that row, then Oracle makes recursive calls to allocate the space dynamically. Recursive calls are also generated when data dictionary information is not available in the data dictionary cache and must be retrieved from disk.
If recursive calls occur while the SQL Trace facility is enabled, then TKPROF produces statistics for the recursive SQL statements and marks them clearly as recursive SQL statements in the output file. You can suppress the listing of Oracle internal recursive calls (for example, space management) in the output file by setting the SYS command-line parameter to NO. The statistics for a recursive SQL statement are included in the listing for that statement, not in the listing for the SQL statement that caused the recursive call. So, when you are calculating the total resources required to process a SQL statement, consider the statistics for that statement as well as those for recursive calls caused by that statement.
Note: Recursive SQL statistics are not included for SQL-level operations. However, recursive SQL statistics are included for operations done under the SQL level, such as triggers. For more information, see "Avoiding the Trigger Trap".
Library Cache Misses in TKPROF
TKPROF also lists the number of library cache misses resulting from parse and execute steps for each SQL statement. These statistics appear on separate lines following the tabular statistics. If the statement resulted in no library cache misses, then TKPROF does not list the statistic. In "Sample TKPROF Output", the statement resulted in one library cache miss for the parse step and no misses for the execute step.
Statement Truncation in SQL Trace
The following SQL statements are truncated to 25 characters in the SQL Trace file:
SET ROLE
GRANT
ALTER USER
ALTER ROLE
CREATE USER
CREATE ROLE
Identification of User Issuing the SQL Statement in TKPROF
TKPROF also lists the user ID of the user issuing each SQL statement. If the SQL Trace input file contained statistics from multiple users and the statement was issued by more than one user, then TKPROF lists the ID of the last user to parse the statement. The user ID of all database users appears in the data dictionary in the column ALL_USERS.USER_ID.
Execution Plan in TKPROF
If you specify the EXPLAIN parameter on the TKPROF statement line, then TKPROF uses the EXPLAIN PLAN statement to generate the execution plan of each SQL statement traced. TKPROF also displays the number of rows processed by each step of the execution plan.
Note: Trace files generated immediately after instance startup contain data that reflects the activity of the startup process. In particular, they reflect a disproportionate amount of I/O activity as caches in the system global area (SGA) are filled. For the purposes of tuning, ignore such trace files.
Deciding Which Statements to Tune
You need to find which SQL statements use the most CPU or disk resource. If the TIMED_STATISTICS parameter is on, then you can find high CPU activity in the CPU column. If TIMED_STATISTICS is not on, then check the QUERY and CURRENT columns.
See Also: "Examples of TKPROF Statement" for examples of finding resource intensive statements
With the exception of locking problems and inefficient PL/SQL loops, neither the CPU time nor the elapsed time is necessary to find problem statements. The key is the number of block visits, both query (that is, subject to read consistency) and current (that is, not subject to read consistency). Segment headers and blocks that are going to be updated are acquired in current mode, but all query and subquery processing requests the data in query mode. These are precisely the same measures as the instance statistics CONSISTENT GETS and DB BLOCK GETS. You can find high disk activity in the disk column.
The following listing shows TKPROF output for one SQL statement as it appears in the output file:
SELECT *
FROM emp, dept
WHERE emp.deptno = dept.deptno;

call count cpu elapsed disk query current rows
---- ------- ------- --------- -------- -------- ------- ------
Parse 11 0.08 0.18 0 0 0 0
Execute 11 0.23 0.66 0 3 6 0
Fetch 35 6.70 6.83 100 12326 2 824
------------------------------------------------------------------
total 57 7.01 7.67 100 12329 8 826

Misses in library cache during parse: 0

If it is acceptable to have 7.01 CPU seconds and to retrieve 824 rows, then you need not look any further at this trace output. In fact, a major use of TKPROF reports in a tuning exercise is to eliminate processes from the detailed tuning phase.
You can also see that 10 unnecessary parse call were made (because there were 11 parse calls for this one statement) and that array fetch operations were performed. You know this because more rows were fetched than there were fetches performed. A large gap between CPU and elapsed timings indicates Physical I/Os (PIOs).
Step 5: Storing SQL Trace Facility Statistics
You might want to keep a history of the statistics generated by the SQL Trace facility for an application, and compare them over time. TKPROF can generate a SQL script that creates a table and inserts rows of statistics into it. This script contains:
A CREATE TABLE statement that creates an output table named TKPROF_TABLE.
INSERT statements that add rows of statistics, one for each traced SQL statement, to the TKPROF_TABLE.
After running TKPROF, you can run this script to store the statistics in the database.
Generating the TKPROF Output SQL Script
When you run TKPROF, use the INSERT parameter to specify the name of the generated SQL script. If you omit this parameter, then TKPROF does not generate a script.
Editing the TKPROF Output SQL Script
After TKPROF has created the SQL script, you might want to edit the script before running it. If you have already created an output table for previously collected statistics and you want to add new statistics to this table, then remove the CREATE TABLE statement from the script. The script then inserts the new rows into the existing table.
If you have created multiple output tables, perhaps to store statistics from different databases in different tables, then edit the CREATE TABLE and INSERT statements to change the name of the output table.
Querying the Output Table
The following CREATE TABLE statement creates the TKPROF_TABLE:
CREATE TABLE TKPROF_TABLE (
DATE_OF_INSERT DATE,
CURSOR_NUM NUMBER,
DEPTH NUMBER,
USER_ID NUMBER,
PARSE_CNT NUMBER,
PARSE_CPU NUMBER,
PARSE_ELAP NUMBER,
PARSE_DISK NUMBER,
PARSE_QUERY NUMBER,
PARSE_CURRENT NUMBER,
PARSE_MISS NUMBER,
EXE_COUNT NUMBER,
EXE_CPU NUMBER,
EXE_ELAP NUMBER,
EXE_DISK NUMBER,
EXE_QUERY NUMBER,
EXE_CURRENT NUMBER,
EXE_MISS NUMBER,
EXE_ROWS NUMBER,
FETCH_COUNT NUMBER,
FETCH_CPU NUMBER,
FETCH_ELAP NUMBER,
FETCH_DISK NUMBER,
FETCH_QUERY NUMBER,
FETCH_CURRENT NUMBER,
FETCH_ROWS NUMBER,
CLOCK_TICKS NUMBER,
SQL_STATEMENT LONG);
Most output table columns correspond directly to the statistics that appear in the formatted output file. For example, the PARSE_CNT column value corresponds to the count statistic for the parse step in the output file.
The columns in Table 10-6 help you identify a row of statistics.
Table 10-6 TKPROF_TABLE Columns for Identifying a Row of Statistics
Column Description
SQL_STATEMENT This is the SQL statement for which the SQL Trace facility collected the row of statistics. Because this column has datatype LONG, you cannot use it in expressions or WHERE clause conditions.
DATE_OF_INSERT This is the date and time when the row was inserted into the table. This value is not exactly the same as the time the statistics were collected by the SQL Trace facility.
DEPTH This indicates the level of recursion at which the SQL statement was issued. For example, a value of 0 indicates that a user issued the statement. A value of 1 indicates that Oracle generated the statement as a recursive call to process a statement with a value of 0 (a statement issued by a user). A value of n indicates that Oracle generated the statement as a recursive call to process a statement with a value of n-1.
USER_ID This identifies the user issuing the statement. This value also appears in the formatted output file.
CURSOR_NUM Oracle uses this column value to keep track of the cursor to which each SQL statement was assigned.
The output table does not store the statement's execution plan. The following query returns the statistics from the output table. These statistics correspond to the formatted output shown in the section "Sample TKPROF Output".
SELECT * FROM TKPROF_TABLE;

Oracle responds with something similar to:
DATE_OF_INSERT CURSOR_NUM DEPTH USER_ID PARSE_CNT PARSE_CPU PARSE_ELAP
-------------- ---------- ----- ------- --------- --------- ----------
21-DEC-1998 1 0 8 1 16 22

PARSE_DISK PARSE_QUERY PARSE_CURRENT PARSE_MISS EXE_COUNT EXE_CPU
---------- ----------- ------------- ---------- --------- -------
3 11 0 1 1 0

EXE_ELAP EXE_DISK EXE_QUERY EXE_CURRENT EXE_MISS EXE_ROWS FETCH_COUNT
-------- -------- --------- ----------- -------- -------- -----------
0 0 0 0 0 0 1

FETCH_CPU FETCH_ELAP FETCH_DISK FETCH_QUERY FETCH_CURRENT FETCH_ROWS
--------- ---------- ---------- ----------- ------------- ----------
2 20 2 2 4 10

SQL_STATEMENT
---------------------------------------------------------------------
SELECT * FROM EMP, DEPT WHERE EMP.DEPTNO = DEPT.DEPTNO
Avoiding Pitfalls in TKPROF Interpretation
This section describes some fine points of TKPROF interpretation:
Avoiding the Argument Trap
Avoiding the Read Consistency Trap
Avoiding the Schema Trap
Avoiding the Time Trap
Avoiding the Trigger Trap
Avoiding the Argument Trap
If you are not aware of the values being bound at run time, then it is possible to fall into the argument trap. EXPLAIN PLAN cannot determine the type of a bind variable from the text of SQL statements, and it always assumes that the type is varchar. If the bind variable is actually a number or a date, then TKPROF can cause implicit data conversions, which can cause inefficient plans to be executed. To avoid this, experiment with different data types in the query.
To avoid this problem, perform the conversion yourself.
See Also: "EXPLAIN PLAN Restrictions" for information about TKPROF and bind variables
Avoiding the Read Consistency Trap
The next example illustrates the read consistency trap. Without knowing that an uncommitted transaction had made a series of updates to the NAME column, it is very difficult to see why so many block visits would be incurred.
Cases like this are not normally repeatable: if the process were run again, it is unlikely that another transaction would interact with it in the same way.
SELECT name_id
FROM cq_names
WHERE name = 'FLOOR';

call count cpu elapsed disk query current rows
---- ----- --- ------- ---- ----- ------- ----
Parse 1 0.10 0.18 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.11 0.21 2 101 0 1

Misses in library cache during parse: 1
Parsing user id: 01 (USER1)

Rows Execution Plan
---- --------- ----
0 SELECT STATEMENT
1 TABLE ACCESS (BY ROWID) OF 'CQ_NAMES'
2 INDEX (RANGE SCAN) OF 'CQ_NAMES_NAME' (NON_UNIQUE)
Avoiding the Schema Trap
This example shows an extreme (and thus easily detected) example of the schema trap. At first, it is difficult to see why such an apparently straightforward indexed query needs to look at so many database blocks, or why it should access any blocks at all in current mode.
SELECT name_id
FROM cq_names
WHERE name = 'FLOOR';

call count cpu elapsed disk query current rows
-------- ------- -------- --------- ------- ------ ------- ----
Parse 1 0.06 0.10 0 0 0 0
Execute 1 0.02 0.02 0 0 0 0
Fetch 1 0.23 0.30 31 31 3 1

Misses in library cache during parse: 0
Parsing user id: 02 (USER2)

Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT
2340 TABLE ACCESS (BY ROWID) OF 'CQ_NAMES'
0 INDEX (RANGE SCAN) OF 'CQ_NAMES_NAME' (NON-UNIQUE)

Two statistics suggest that the query might have been executed with a full table scan. These statistics are the current mode block visits, plus the number of rows originating from the Table Access row source in the execution plan. The explanation is that the required index was built after the trace file had been produced, but before TKPROF had been run.
Generating a new trace file gives the following data:
SELECT name_id
FROM cq_names
WHERE name = 'FLOOR';

call count cpu elapsed disk query current rows
----- ------ ------ -------- ----- ------ ------- -----
Parse 1 0.01 0.02 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 2 0 1

Misses in library cache during parse: 0
Parsing user id: 02 (USER2)

Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT
1 TABLE ACCESS (BY ROWID) OF 'CQ_NAMES'
2 INDEX (RANGE SCAN) OF 'CQ_NAMES_NAME' (NON-UNIQUE)

One of the marked features of this correct version is that the parse call took 10 milliseconds of CPU time and 20 milliseconds of elapsed time, but the query apparently took no time at all to execute and perform the fetch. These anomalies arise because the clock tick of 10 milliseconds is too long relative to the time taken to execute and fetch the data. In such cases, it is important to get lots of executions of the statements, so that you have statistically valid numbers.
Avoiding the Time Trap
Sometimes, as in the following example, you might wonder why a particular query has taken so long.
UPDATE cq_names SET ATTRIBUTES = lower(ATTRIBUTES)
WHERE ATTRIBUTES = :att

call count cpu elapsed disk query current rows
-------- ------- -------- --------- -------- -------- ------- ----------
Parse 1 0.06 0.24 0 0 0 0
Execute 1 0.62 19.62 22 526 12 7
Fetch 0 0.00 0.00 0 0 0 0

Misses in library cache during parse: 1
Parsing user id: 02 (USER2)

Rows Execution Plan
------- ---------------------------------------------------
0 UPDATE STATEMENT
2519 TABLE ACCESS (FULL) OF 'CQ_NAMES'

Again, the answer is interference from another transaction. In this case, another transaction held a shared lock on the table cq_names for several seconds before and after the update was issued. It takes a fair amount of experience to diagnose that interference effects are occurring. On the one hand, comparative data is essential when the interference is contributing only a short delay (or a small increase in block visits in the previous example). On the other hand, if the interference is contributing only a modest overhead, and the statement is essentially efficient, then its statistics might not need to be analyzed.
Avoiding the Trigger Trap
The resources reported for a statement include those for all of the SQL issued while the statement was being processed. Therefore, they include any resources used within a trigger, along with the resources used by any other recursive SQL (such as that used in space allocation). With the SQL Trace facility enabled, TKPROF reports these resources twice. Avoid trying to tune the DML statement if the resource is actually being consumed at a lower level of recursion.
If a DML statement appears to be consuming far more resources than you would expect, then check the tables involved in the statement for triggers and constraints that could be greatly increasing the resource usage.
Sample TKPROF Output
This section provides an extensive example of TKPROF output. Portions have been edited out for the sake of brevity.
Sample TKPROF Header
Copyright (c) Oracle Corporation 1979, 1999. All rights reserved.
Trace file: v80_ora_2758.trc
Sort options: default
********************************************************************************
count = number of times OCI procedure was executed
cpu = cpu time in seconds executing
elapsed = elapsed time in seconds executing
disk = number of physical reads of buffers from disk
query = number of buffers gotten for consistent read
current = number of buffers gotten in current mode (usually for update)
rows = number of rows processed by the fetch or execute call
********************************************************************************
The following statement encountered a error during parse:
select deptno, avg(sal) from emp e group by deptno
having exists (select deptno from dept
where dept.deptno = e.deptno
and dept.budget > avg(e.sal)) order by 1
Error encountered: ORA-00904
********************************************************************************
Sample TKPROF Body
ALTER SESSION SET SQL_TRACE = true
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.10 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1 0.00 0.10 0 0 0 0
Misses in library cache during parse: 0
Misses in library cache during execute: 1
Optimizer goal: CHOOSE
Parsing user id: 02 (USER02)
********************************************************************************
SELECT emp.ename, dept.dname
FROM emp, dept
WHERE emp.deptno = dept.deptno

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.11 0.13 2 0 1 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 2 2 4 14
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.11 0.13 4 2 5 14

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 02 (USER02)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT GOAL: CHOOSE
14 MERGE JOIN
4 SORT (JOIN)
4 TABLE ACCESS (FULL) OF 'DEPT'
14 SORT (JOIN)
14 TABLE ACCESS (FULL) OF 'EMP'

********************************************************************************
SELECT a.ename name, b.ename manager
FROM emp a, emp b
WHERE a.mgr = b.empno(+)

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.01 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.01 0.01 1 50 2 14
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.02 0.02 1 50 2 14

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 01 (USER01)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT GOAL: CHOOSE
13 NESTED LOOPS (OUTER)
14 TABLE ACCESS (FULL) OF 'EMP'
13 TABLE ACCESS (BY ROWID) OF 'EMP'
26 INDEX (RANGE SCAN) OF 'EMP_IND' (NON-UNIQUE)
********************************************************************************
SELECT ename, job, sal
FROM emp
WHERE sal =
(SELECT max(sal)
FROM emp)

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 12 4 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 0 12 4 1

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 01 (USER01)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT GOAL: CHOOSE
14 FILTER
14 TABLE ACCESS (FULL) OF 'EMP'
14 SORT (AGGREGATE)
14 TABLE ACCESS (FULL) OF 'EMP'
********************************************************************************
SELECT deptno
FROM emp
WHERE job = 'clerk'
GROUP BY deptno
HAVING COUNT(*) >= 2

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 1 1 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 0 1 1 0

Misses in library cache during parse: 13
Optimizer goal: CHOOSE
Parsing user id: 01 (USER01)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT GOAL: CHOOSE
0 FILTER
0 SORT (GROUP BY)
14 TABLE ACCESS (FULL) OF 'EMP'
********************************************************************************
SELECT dept.deptno, dname, job, ename
FROM dept,emp
WHERE dept.deptno = emp.deptno(+)
ORDER BY dept.deptno

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 3 3 10
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 0 3 3 10

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 01 (USER01)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT GOAL: CHOOSE
14 MERGE JOIN (OUTER)
4 SORT (JOIN)
4 TABLE ACCESS (FULL) OF 'DEPT'
14 SORT (JOIN)
14 TABLE ACCESS (FULL) OF 'EMP'
********************************************************************************
SELECT grade, job, ename, sal
FROM emp, salgrade
WHERE sal BETWEEN losal AND hisal
ORDER BY grade, job

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.04 0.06 2 16 1 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.01 0.01 1 10 12 10
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.05 0.07 3 26 13 10

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 02 (USER02)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT GOAL: CHOOSE
14 SORT (ORDER BY)
14 NESTED LOOPS
5 TABLE ACCESS (FULL) OF 'SALGRADE'
70 TABLE ACCESS (FULL) OF 'EMP'
********************************************************************************

SELECT LPAD(' ',level*2)||ename org_chart, level, empno, mgr, job, deptno
FROM emp
CONNECT BY prior empno = mgr
START WITH ename = 'clark'
OR ename = 'blake'
ORDER BY deptno

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.01 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.01 0.01 0 1 2 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.02 0.02 0 1 2 0

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 02 (USER02)

Rows Execution Plan
------- --------------------------------------------------
0 SELECT STATEMENT GOAL: CHOOSE
0 SORT (ORDER BY)
0 CONNECT BY
14 TABLE ACCESS (FULL) OF 'EMP'
0 TABLE ACCESS (BY ROWID) OF 'EMP'
0 TABLE ACCESS (FULL) OF 'EMP'
********************************************************************************
CREATE TABLE TKOPTKP (a number, b number)

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.01 0.01 1 0 1 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.01 0.01 1 0 1 0

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 02 (USER02)
Rows Execution Plan
------- ---------------------------------------------------
0 CREATE TABLE STATEMENT GOAL: CHOOSE

********************************************************************************
INSERT INTO TKOPTKP
VALUES (1,1)

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.07 0.09 0 0 0 0
Execute 1 0.01 0.20 2 2 3 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.08 0.29 2 2 3 1

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 02 (USER02)
Rows Execution Plan
------- ---------------------------------------------------
0 INSERT STATEMENT GOAL: CHOOSE

********************************************************************************
INSERT INTO TKOPTKP SELECT * FROM TKOPTKP
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.02 0.02 0 2 3 11
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.02 0.02 0 2 3 11

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 02 (USER02)
Rows Execution Plan
------- ---------------------------------------------------
0 INSERT STATEMENT GOAL: CHOOSE
12 TABLE ACCESS (FULL) OF 'TKOPTKP'
********************************************************************************
SELECT *
FROM TKOPTKP
WHERE a > 2

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.01 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 1 2 10
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.01 0.01 0 1 2 10

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 02 (USER02)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT GOAL: CHOOSE
24 TABLE ACCESS (FULL) OF 'TKOPTKP'
********************************************************************************
Sample TKPROF Summary
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 18 0.40 0.53 30 182 3 0
Execute 19 0.05 0.41 3 7 10 16
Fetch 12 0.05 0.06 4 105 66 78
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 49 0.50 1.00 37 294 79 94

Misses in library cache during parse: 18
Misses in library cache during execute: 1

OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 69 0.49 0.60 9 12 8 0
Execute 103 0.13 0.54 0 0 0 0
Fetch 213 0.12 0.27 40 435 0 162
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 385 0.74 1.41 49 447 8 162

Misses in library cache during parse: 13
19 user SQL statements in session.
69 internal SQL statements in session.
88 SQL statements in session.
17 statements EXPLAINed in this session.
********************************************************************************
Trace file: v80_ora_2758.trc
Trace file compatibility: 7.03.02

Sort options: default
1 session in tracefile.
19 user SQL statements in trace file.
69 internal SQL statements in trace file.
88 SQL statements in trace file.
41 unique SQL statements in trace file.
17 SQL statements EXPLAINed using schema:
SCOTT.prof$plan_table
Default table was used.
Table was created.
Table was dropped.
1017 lines in trace file.
Re: How to run TKPROF on Oracle9i(9.0.1) [message #74466 is a reply to message #74360] Thu, 16 December 2004 03:14 Go to previous messageGo to next message
Neeraj Shrivastava
Messages: 1
Registered: December 2004
Junior Member
The document is pretty good since it gives a complete
idea abot SQL Trace and TKPROF, but how to invoke TKPROF i.e the command with an example is not given.
Re: How to run TKPROF on Oracle9i(9.0.1) [message #404546 is a reply to message #74222] Fri, 22 May 2009 04:12 Go to previous messageGo to next message
sreerpriya
Messages: 8
Registered: May 2009
Junior Member
Hi
we have 9i Database and when we try to run the TKPROF it is running fine but shows the below text in the LOG file.

*****************************************************************
TKPROF: Release 8.0.6.3.0 - Production on Thu May 21 04:53:05 2009

(c) Copyright 1999 Oracle Corporation. All rights reserved.

Trace file: /oracle/admin/tst/udump/tst_ora_6938.trc
Sort options: prsela exeela fchela
*****************************************************************

Can anyone explain me why the version is 8.0.6.3.0. How to get the tkprof output in 9i version?

Regards,
Sree
Re: How to run TKPROF on Oracle9i(9.0.1) [message #404555 is a reply to message #404546] Fri, 22 May 2009 04:41 Go to previous messageGo to next message
Littlefoot
Messages: 20897
Registered: June 2005
Location: Croatia, Europe
Senior Member
Account Moderator
Do you have two (or more) Oracle software products installed? If so, system path variable might be responsible for that in a way that ver. 8 TKPROF's directory is in front of the ver. 9 TKPROF's one.

What you might do is to specify the full path to TKPROF (such as (on MS Windows) c:\oracle\ora9i\bin\tkprof) or change directory to the one that contains the desired version and run TKPROF from the current (working) directory.
Re: How to run TKPROF on Oracle9i(9.0.1) [message #404556 is a reply to message #74222] Fri, 22 May 2009 04:47 Go to previous messageGo to next message
sreerpriya
Messages: 8
Registered: May 2009
Junior Member
Hi

Thanks for your reply.
Im running the TKPROF in UNIX.
path: /oracle/admin/tst/udump.
does this affect the version numbering?

Regards,
Sree
Re: How to run TKPROF on Oracle9i(9.0.1) [message #404565 is a reply to message #404556] Fri, 22 May 2009 05:13 Go to previous messageGo to next message
Littlefoot
Messages: 20897
Registered: June 2005
Location: Croatia, Europe
Senior Member
Account Moderator
My UNIX knowledge is really very poor, but I guess that the principle should/might remain the same. You still didn't answer whether there are
LF
two (or more) Oracle software products installed
Re: How to run TKPROF on Oracle9i(9.0.1) [message #404572 is a reply to message #74222] Fri, 22 May 2009 05:42 Go to previous messageGo to next message
sreerpriya
Messages: 8
Registered: May 2009
Junior Member
Sorry..

I have only one Oracle installed in my machine
Re: How to run TKPROF on Oracle9i(9.0.1) [message #405845 is a reply to message #404572] Sat, 30 May 2009 01:02 Go to previous message
vamsi kasina
Messages: 2107
Registered: October 2003
Location: Riyadh, Saudi Arabia
Senior Member
Not on your machine..
Whether there are more installations on the UNIX server or not?

try the command "which TKPROF". It will tell you from which location it is getting the TKPROF executable.
Then locate 9i home and get the TKPROF executable from there.

By
Vamsi
Previous Topic: Need Suggestion
Next Topic: dividing by 100 in sql loader
Goto Forum:
  


Current Time: Wed Dec 07 06:37:07 CST 2016

Total time taken to generate the page: 0.17089 seconds