使用SQLT来构建Oracle测试用例

在进行性能优化尤其是SQL优化时不能在生产环境进行测试，或者在升级时对SQL语句性能进行测试时，构建一个测试环境很重要，这篇文章介绍使用SQLT工具来快速简单的构建测试用例的方法。其实要使用SQLT来构建一个测试用例不需要额外执行SQLT报告。运行SQLTXTRACT或SQLTXECUTE就能为测试用例创建足够的信息。Oracle 11g 在RedHat Linux 5.8_x64平台的安装手册 http://www.linuxidc.com/Linux/2014-07/104745.htmLinux-6-64下安装Oracle 12C笔记 http://www.linuxidc.com/Linux/2013-07/86805.htm在CentOS 6.4下安装Oracle 11gR2（x64） http://www.linuxidc.com/Linux/2014-02/97374.htmOracle 11gR2 在VMWare虚拟机中安装步骤 http://www.linuxidc.com/Linux/2013-09/89579p2.htmDebian 下安装 Oracle 11g XE R2 http://www.linuxidc.com/Linux/2014-03/98881.htm

例如我要将在aix系统上Oracle 10g中运行的SQL语句在linux系统上Oracle 11g中来测试它的性能时，这就需要构建一个测试用例。要进行测试的语句如下: select
nvl（sum（real_pay）, 0） as dYearA131
from mt_biz_fin a, mt_pay_record_fin b, mt_apply c
where a.hospital_id = b.hospital_id
and a.serial_no = b.serial_no
and a.treatment_type = "131"
and a.indi_id = 5609194
and a.serial_apply = 135888
and a.valid_flag = "1"
and b.valid_flag = "1"
and a.serial_apply = c.serial_apply
and c.valid_flag = "1"
and b.POLICY_ITEM_CODE in （"C000", "C001", "C004"）
and exists （select 1
from mt_pay_record_fin b
where b.fund_id not in （"003", "999"）
and a.serial_no = b.serial_no）;

为sqltxecute.sql脚本创建一个来测试的sql文件
[IBMP740-1:oracle:/oracle/sqlt/input/sample]$vi mysql2.sql-- execute sqlt xecute as sh passing script name
-- cd sqlt
-- #sqlplus sh
-- SQL> start run/sqltxecute.sql input/sample/script1.sqlREM Optional ALTER SESSION commands
REM ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~--ALTER SESSION SET statistics_level = ALL;REM Optional Binds
REM ~~~~~~~~~~~~~~VAR b1 NUMBER;
EXEC :b1 := 10;REM SQL statement to be executed
REM ~~~~~~~~~~~~~~~~~~~~~~~~~~~~SELECT /*+ gather_plan_statistics monitor bind_aware */
/* ^^unique_id */
"mysql2.sql" 35 lines, 756 characters
/* ^^unique_id */nvl（sum（real_pay）, 0） as dYearA131
from mt_biz_fin a, mt_pay_record_fin b, mt_apply c
where a.hospital_id = b.hospital_id
and a.serial_no = b.serial_no
and a.treatment_type = "131"
and a.indi_id = 5609194
and a.serial_apply = 135888
and a.valid_flag = "1"
and b.valid_flag = "1"
and a.serial_apply = c.serial_apply
and c.valid_flag = "1"
and b.POLICY_ITEM_CODE in （"C000", "C001", "C004"）
and exists （select 1
from mt_pay_record_fin b
where b.fund_id not in （"003", "999"）
and a.serial_no = b.serial_no）;/
/REM Notes:
/
/REM Notes:
REM 1. SQL must contain token: /* ^^unique_id */
"mysql2.sql" 48 lines, 1259 characters
现在在Oracle 10g中对上面的SQL语句执行sqltxectue.sql来进行性能分析
[IBMP740-1:oracle:/oracle/sqlt/run]$sqlplus /nologSQL*Plus: Release 10.2.0.4.0 - Production on Tue Aug 26 09:29:40 2014Copyright （c） 1982, 2007, Oracle. All Rights Reserved.SQL> conn / as sysdba
Connected.
SQL> @sqltxecute.sql /oracle/sqlt/input/sample/mysql2.sql PL/SQL procedure successfully completed. Parameter 1:
SCRIPT name which contains SQL and its binds （required）
Paremeter 2:
SQLTXPLAIN password （required）Enter value for 2: sqltPL/SQL procedure successfully completed. PL/SQL procedure successfully completed.
Value passed to sqltxecute:
SCRIPT_WITH_SQL: "/oracle/sqlt/input/sample/mysql2.sql"
PL/SQL procedure successfully completed.***
*** NOTE:
*** If you get error below it means SQLTXPLAIN is not installed:
*** PLS-00201: identifier "SQLTXADMIN.SQLT$A" must be declared.
*** In such case look for errors in NN_*.log files created during install.
*** SQLT_VERSION
----------------------------------------
SQLT version number: 12.1.09
SQLT version date : 2014-06-13
Installation date : 2014-07-29/15:45:43... please wait ...
adding: alert_RLZY.log （deflated 93%）NOTE:
You used the XECUTE method connected as INSUR_CHANGDE.In case of a session disconnect please verify the following:
1. There are no errors in sqltxecute.log or sqltxecute2.log.
2. Your SQL contains token "^^unique_id" within a comment.
3. Your SQL ends with a semi-colon ";".
4. You connected as the application user that issued original SQL.
5. Script /oracle/sqlt/input/sample/mysql2.sql can execute stand-alone connected as INSUR_CHANGDE
6. User INSUR_CHANGDE has been granted SQLT_USER_ROLE.In case of errors ORA-03113, ORA-03114 or ORA-07445 please just
re-try this SQLT method. This tool handles some of the errors behind
a disconnect when executed a second time.To actually diagnose the problem behind the disconnect, read ALERT
log and provide referenced traces to Support. After the root cause
of the disconnect is fixed then reset SQLT corresponding parameter.... executing /oracle/sqlt/input/sample/mysql2.sql ...In case of a disconnect review sqltxecute2.log and mysql2_output_s34879.txt
To monitor progress, login into another session and execute:
SQL> SELECT * FROM SQLTXADMIN.sqlt$_log_v;... collecting diagnostics details, please wait ...In case of a disconnect review log file in current directory
If running as SYS in 12c make sure to review sqlt_instructions.html first09:30:47 17 sqlt$a: ALTER SESSION SET EVENTS "10053 TRACE NAME CONTEXT OFF"
09:30:47 0 sqlt$a: ALTER SESSION SET EVENTS "10046 TRACE NAME CONTEXT FOREVER, LEVEL 8"
09:30:47 0 sqlt$a: skip 10241, 10032, 10033, 10104, 10730, 46049 off as per parameter event_others
09:31:18 31 sqlt$d: collect_gv$sesstat
09:31:18 0 sqlt$d: 760 rows collected
09:31:18 0 sqlt$d: collect_gv$cell_state
09:31:18 0 sqlt$d: 0 rows collected
09:31:18 0 sqlt$d: collect_gv$session_event
09:31:18 0 sqlt$d: 19 rows collected
09:31:18 0 sqlt$d: collect_gv$segment_statistics
09:31:18 0 sqlt$d: 510 rows collected
09:31:18 0 sqlt$d: collect_gv$statname
09:31:18 0 sqlt$d: 380 rows collected
09:31:18 0 sqlt$d: collect_gv$pq_slave
09:31:18 0 sqlt$d: 0 rows collected
09:31:18 0 sqlt$d: collect_gv$pq_sysstat
09:31:18 0 sqlt$d: 32 rows collected
09:31:18 0 sqlt$d: collect_gv$px_process_sysstat
09:31:18 0 sqlt$d: 30 rows collected
09:31:18 0 sqlt$d: collect_gv$px_process
09:31:18 0 sqlt$d: 0 rows collected
09:31:18 0 sqlt$d: collect_gv$px_session
09:31:18 0 sqlt$d: 0 rows collected
09:31:18 0 sqlt$d: collect_gv$pq_sesstat
09:31:18 0 sqlt$d: 22 rows collected
09:31:18 0 sqlt$d: collect_gv$px_sesstat
09:31:18 0 sqlt$d: 0 rows collected
09:31:18 0 sqlt$d: collect_gv$px_instance_group
09:31:18 0 sqlt$d: 0 rows collected
09:31:18 0 sqlt$d: collect_gv$pq_tqstat
09:31:18 0 sqlt$d: 0 rows collected
09:31:18 0 sqlt$d: < = collect_perf_stats_post 09:31:18 0 sqlt$a: ALTER SESSION SET STATISTICS_LEVEL = "TYPICAL" 09:31:18 0 sqlt$a: -> session_trace_filename
09:31:18 0 sqlt$a: session_trace_filename, current trace_filename
09:31:18 0 sqlt$a: session_trace_filename, current process_name ora
09:31:18 0 sqlt$a: < - session_trace_filename rlzy_ora_3081178_s34879_10046_10053.trc
09:31:18 0 sqlt$a: in udump: "rlzy_ora_3081178_s34879_10046_10053.trc"
09:31:18 0 sqlt$a: in local: "sqlt_s34879_10046_10053_execute.trc"
09:31:18 0 sqlt$a: ALTER SESSION SET TRACEFILE_IDENTIFIER = "S34879_SQLT_TRACE"
09:31:18 0 sqlt$a: timestamp_before: 26-AUG-14 09.30.30.240238 AM +08:00
09:31:18 0 sqlt$a: timestamp_after: 26-AUG-14 09.30.47.115196 AM +08:00
09:31:18 0 sqlt$a: statement_response_time: +00 00:00:16.874958
09:31:18 0 sqlt$a: <= event_10046_10053_off 09:31:18 0 sqlt$d: => capture_sqltext
09:31:18 0 sqlt$d: -> capture_statement
09:31:18 0 sqlt$a: -> find_sql_in_memory_or_awr
09:31:18 0 sqlt$a: -> get_sql_id_or_hash_value
09:31:18 0 sqlt$a: sql_id = "7fv05tum90t4j"
09:31:18 0 sqlt$a: < - get_sql_id_or_hash_value 09:31:18 0 sqlt$a: -> sql_in_memory_or_awr
09:31:18 0 sqlt$a: sql found in memory using sql_id = "7fv05tum90t4j" and string = "sqlt_s34879" （excludes PL/SQL EXECUTE）
09:31:18 0 sqlt$a: hash_value = "2794480785"
09:31:18 0 sqlt$a: SELECT /*+ gather_plan_statistics monitor bind_aware */ /* sqlt_s34879 */ nvl（sum（real_pay）, 0） as dYearA131 from mt_biz_fin a, mt_pay_record_fin b, mt_apply c where a.hospital_id = b.hospital_id and a.serial_no = b.seri
al_no and a.treatment_type = "131" and a.indi_id = 5609194 and a.serial_apply = 135888 and a.valid_flag = "1" and b.valid_flag = "1" and a.serial_apply = c.serial_apply and c.valid_flag = "1" and b.POLICY_ITEM_CODE in （"C000", "C00
1", "C004"） and exists （select 1 from mt_pay_record_fin b where b.fund_id not in （"003", "999"） and a.serial_no = b.serial_no）
09:31:18 0 sqlt$a: sql not found in awr using sql_id = "7fv05tum90t4j"
09:31:18 0 sqlt$a: < - sql_in_memory_or_awr
09:31:18 0 sqlt$a: explain_plan_and_10053
09:31:19 0 sqlt$i: sql_length = "631"
09:31:19 0 sqlt$i: => remote_trace_begin
09:31:19 0 sqlt$i: no remote db_links were found/activated at this step
09:31:19 0 sqlt$i: < = remote_trace_begin 09:31:19 0 sqlt$a: -> event_10053_on
09:31:19 0 sqlt$a: ALTER SESSION SET MAX_DUMP_FILE_SIZE = "200M"
09:31:19 0 sqlt$a: ALTER SESSION SET TRACEFILE_IDENTIFIER = "s34879_10053"
09:31:19 0 sqlt$a: ALTER SESSION SET EVENTS "10053 TRACE NAME CONTEXT FOREVER, LEVEL 1"
09:31:19 0 sqlt$a: ALTER SESSION SET EVENTS "10053 TRACE NAME CONTEXT OFF"
09:31:19 0 sqlt$a: -> session_trace_filename
09:31:19 0 sqlt$a: session_trace_filename, current trace_filename
09:31:19 0 sqlt$a: session_trace_filename, current process_name ora
09:31:19 0 sqlt$a: < - session_trace_filename rlzy_ora_3081178_s34879_10053.trc
09:31:19 0 sqlt$a: in udump: "rlzy_ora_3081178_s34879_10053.trc"
09:31:19 0 sqlt$a: in local: "sqlt_s34879_10053_explain.trc"
09:31:19 0 sqlt$a: ALTER SESSION SET TRACEFILE_IDENTIFIER = "S34879_SQLT_TRACE"
09:31:19 0 sqlt$a: clean_sqlt$_sql_plan_table
09:31:19 0 sqlt$a: < - clean_sqlt$_sql_plan_table 09:31:19 0 sqlt$d: -> capture_xplain_plan_hash_value
09:31:19 0 sqlt$d: < - capture_xplain_plan_hash_value "2582817425" for xplain_sql_id "6kxjb1zyt8qdt" with cost of "83997"
09:31:19 0 sqlt$i: <= explain_plan_and_10053 09:31:19 0 sqlt$i: => remote_trace_end
09:31:19 0 sqlt$i: < = remote_trace_end 09:31:19 0 sqlt$d: collect_gv$parameter_cbo 09:31:19 0 sqlt$d: 190 rows collected 09:31:19 0 sqlt$a: -> reset_init_parameters
09:31:19 0 sqlt$a: optimizer_index_cost_adj was "20"
09:31:19 0 sqlt$a: ALTER SESSION SET optimizer_index_cost_adj = 100
09:31:19 0 sqlt$a: < - reset_init_parameters 09:31:19 0 sqlt$d: => diagnostics_data_collection_1
09:31:19 0 sqlt$d: -> collection from memory
09:31:19 0 sqlt$d: sql_id = "7fv05tum90t4j", hash_value = "2794480785"
09:31:19 0 sqlt$d: collect_gv$sql_shared_cursor
09:31:20 1 sqlt$d: 1 rows collected
09:31:20 0 sqlt$d: collect_gv$sql_bind_capture
09:31:20 0 sqlt$d: 0 rows collected
09:31:20 0 sqlt$d: collect_gv$sql_optimizer_env
09:31:20 0 sqlt$d: 1342040 KB -> 1374248960
09:31:20 0 sqlt$d: 5 rows collected
09:31:20 0 sqlt$d: collect_gv$sql_workarea
09:31:20 0 sqlt$d: 1 rows collected
09:31:20 0 sqlt$d: collect_gv$sql_plan_statistics
09:31:20 0 sqlt$d: 11 rows collected
09:31:20 0 sqlt$d: collect_gv$sql_plan
09:31:20 0 sqlt$d: include predicates on plan table （lock）.
09:31:20 0 sqlt$d: included predicates on plan table （unlock）.
09:31:20 0 sqlt$d: 12 rows collected
09:31:20 0 sqlt$d: collect_gv$sql
09:31:20 0 sqlt$d: 1 rows collected
09:31:20 0 sqlt$d: collect_gv$sqlarea_plan_hash
09:31:20 0 sqlt$d: 1 rows collected
09:31:20 0 sqlt$d: collect_gv$sqlarea
09:31:20 0 sqlt$d: 1 rows collected
09:31:20 0 sqlt$d: collect_gv$sqlstats
09:31:20 0 sqlt$d: 1 rows collected
09:31:20 0 sqlt$d: collect_gv$object_dependency
09:31:20 0 sqlt$d: sql_id="7fv05tum90t4j"
09:31:20 0 sqlt$d: hash_value="2794480785"
09:31:20 0 sqlt$d: xplain_sql_id="6kxjb1zyt8qdt"
09:31:20 0 sqlt$d: root inst_id="1", hash_value="2794480785", address="0700000438927940", depth="0"
09:31:20 0 sqlt$d: root inst_id="1", hash_value="4254357945", address="0700000671675E40", depth="0"
09:31:20 0 sqlt$d: 3 rows collected
09:31:20 0 sqlt$d: collect_gv$vpd_policy
09:31:21 1 sqlt$d: 0 rows collected
09:31:21 0 sqlt$d: collect_gv$active_session_hist
09:31:23 2 sqlt$d: 16 rows collected
09:31:23 0 sqlt$d: collect_dbms_xplan_cursor_last
09:31:24 1 sqlt$d: 0 rows collected
09:31:24 0 sqlt$d: collect_dbms_xplan_cursor_all
09:31:24 0 sqlt$d: 0 rows collected
09:31:24 0 sqlt$d: -> create_tuning_task_memory
09:31:24 0 sqlt$d: task name = "sqlt_s34879_mem"
09:31:24 0 sqlt$d: < - create_tuning_task_memory 09:31:24 0 sqlt$d: -> create_tuning_task_text
09:31:24 0 sqlt$d: parsing_schema_name:INSUR_CHANGDE
09:31:25 1 sqlt$d: task name = "sqlt_s34879_mem"
09:31:25 0 sqlt$d: < - create_tuning_task_text 09:31:25 0 sqlt$d: -> collect_tuning_sets_mem
09:31:25 0 sqlt$d: sqlt$_gv$sql_plan: 2582817425
09:31:25 0 sqlt$d: created sqlset: s34879_2582817425_mem
09:31:26 1 sqlt$d: loaded sqlset: s34879_2582817425_mem
09:31:26 0 sqlt$d: < - collect_tuning_sets_mem
09:31:26 0 sqlt$d: diagnostics_data_collection_2
09:31:26 0 sqlt$d: sql_id = "7fv05tum90t4j"
09:31:26 0 sqlt$d: in_awr = "N"
09:31:26 0 sqlt$d: s_db_link = ""
09:31:26 0 sqlt$d: collect_dba_hist_snapshot
09:31:26 0 sqlt$d: 179 rows collected
09:31:26 0 sqlt$d: collect_dba_hist_parameter
09:31:28 2 sqlt$d: 47793 rows collected
09:31:28 0 sqlt$d: collect_dba_hist_parameter_m
09:31:28 0 sqlt$d: 88 rows collected
09:31:28 0 sqlt$d: -> expanded collection
09:31:28 0 sqlt$d: collect_gv$parameter2
09:31:28 0 sqlt$d: 263 rows collected
09:31:28 0 sqlt$d: collect_gv$nls_parameters
09:31:28 0 sqlt$d: 19 rows collected
09:31:28 0 sqlt$d: collect_gv$system_parameter
09:31:28 0 sqlt$d: 261 rows collected
09:31:28 0 sqlt$d: collect_nls_database_params
09:31:28 0 sqlt$d: 20 rows collected
09:31:28 0 sqlt$d: collect_v$session_fix_control
09:31:28 0 sqlt$d: 115 rows collected
09:31:28 0 sqlt$d: collect_dba_dependencies
09:31:28 0 sqlt$d: 0 rows collected
09:31:28 0 sqlt$d: list_of_objects
09:31:28 0 sqlt$d: preliminary_list_of_tables
09:31:28 0 sqlt$d: preliminary_list_of_indexes
09:31:28 0 sqlt$d: final_list_of_tables
09:31:30 2 sqlt$d: list_of_fixed_objects
09:31:30 0 sqlt$d: final_list_of_indexes
09:31:30 0 sqlt$d: list_of_other_objects
09:31:30 0 sqlt$d: final_list_of_other_objects
09:31:35 5 sqlt$d: 20 rows collected
09:31:35 0 sqlt$d: collect_schema_object_stats
09:31:35 0 sqlt$d: export table stats
09:31:35 0 sqlt$d: 4762 rows collected
09:31:35 0 sqlt$d: export dictionary stats
09:31:35 0 sqlt$d: dictionary objects stats export skipped because of export_dict_stats param
09:31:35 0 sqlt$d: export fixed objects stats
09:31:35 0 sqlt$d: 0 rows collected
09:31:35 0 sqlt$d: collect_dba_tables
09:31:35 0 sqlt$d: 3 rows collected
09:31:35 0 sqlt$d: collect_dba_object_tables
09:31:35 0 sqlt$d: 0 rows collected
09:31:35 0 sqlt$d: collect_dba_nested_tables
09:31:41 6 sqlt$d: 0 rows collected
09:31:41 0 sqlt$d: collect_dba_tab_statistics
09:31:41 0 sqlt$d: 3 rows collected
09:31:41 0 sqlt$d: collect_dba_tab_modifications
09:31:41 0 sqlt$d: 3 rows collected
09:31:41 0 sqlt$d: collect_dba_tab_cols
09:31:41 0 sqlt$d: 190 rows collected
09:31:41 0 sqlt$d: collect_dba_nested_table_cols
09:31:41 0 sqlt$d: 0 rows collected
09:31:41 0 sqlt$d: collect_dba_indexes
09:31:41 0 sqlt$d: 17 rows collected
09:31:41 0 sqlt$d: collect_dba_ind_statistics
09:31:41 0 sqlt$d: 17 rows collected
09:31:41 0 sqlt$d: collect_dba_ind_columns
09:31:41 0 sqlt$d: 39 rows collected
09:31:41 0 sqlt$d: collect_dba_ind_expressions
09:31:41 0 sqlt$d: 0 rows collected
09:31:41 0 sqlt$d: collect_dba_tab_histograms
09:31:42 1 sqlt$d: 4825 rows collected
09:31:42 0 sqlt$d: collect_dba_constraints
09:31:42 0 sqlt$d: 50 rows collected
09:31:42 0 sqlt$d: Skipped gv$im_segments since version is older than 12.1.0.2 or parameter c_inmemory is set to N
09:31:42 0 sqlt$d: Skipped gv$im_column_level since version is older than 12.1.0.2 or parameter c_inmemory is set to N
09:31:42 0 sqlt$d: collect_dba_segments GLOBAL
09:31:51 9 sqlt$d: 20 rows collected
09:31:51 0 sqlt$d: collect_dba_tablespaces
09:31:52 1 sqlt$d: 8 rows collected
09:31:52 0 sqlt$d: collect_dba_objects GLOBAL
09:31:52 0 sqlt$d: 20 rows collected
09:31:52 0 sqlt$d: collect_dba_source
09:31:52 0 sqlt$d: 0 rows collected
09:31:52 0 sqlt$d: collect_dba_col_usage$
09:31:52 0 sqlt$d: 93 rows collected
09:31:52 0 sqlt$d: collect_dba_policies
09:31:52 0 sqlt$d: 0 rows collected
09:31:52 0 sqlt$d: collect_dba_audit_policies
09:31:52 0 sqlt$d: 0 rows collected
09:31:52 0 sqlt$d: capture up to "31" days of CBO statistics versions as per parameter c_cbo_stats_vers_days
09:31:52 0 sqlt$d: collect_dba_optstat_operations
09:31:52 0 sqlt$d: 29 rows collected
09:31:52 0 sqlt$d: collect_dba_tab_stats_versn GLOBAL
09:31:52 0 sqlt$d: 1 rows collected
09:31:52 0 sqlt$d: collect_dba_ind_stats_versn GLOBAL
09:31:52 0 sqlt$d: 9 rows collected
09:31:52 0 sqlt$d: collect_dba_col_stats_versn GLOBAL
09:31:53 1 sqlt$d: 78 rows collected
09:31:53 0 sqlt$d: collect_dba_histgrm_stats_ver GLOBAL
09:31:59 6 sqlt$d: 2758 rows collected
09:31:59 0 sqlt$d: collect_wri$_optstat_aux_hist
09:31:59 0 sqlt$d: 0 rows collected
09:31:59 0 sqlt$d: collect_aux_stats$
09:31:59 0 sqlt$d: 13 rows collected
09:31:59 0 sqlt$d: collect_dbms_xplan_display
09:32:00 1 sqlt$d: 0 rows collected
09:32:00 0 sqlt$d: collect_dba_outlines
09:32:00 0 sqlt$d: 0 rows collected
09:32:00 0 sqlt$d: collect_dba_outline_hints
09:32:00 0 sqlt$d: 0 rows collected
09:32:00 0 sqlt$d: collect_wri$_adv_tasks
09:32:00 0 sqlt$d: 2 rows collected
09:32:00 0 sqlt$d: collect_wri$_adv_rationale
09:32:00 0 sqlt$d: 0 rows collected
09:32:00 0 sqlt$d: collect_dba_sqltune_plans
09:32:00 0 sqlt$d: 0 rows collected
09:32:00 0 sqlt$d: collect_dba_sql_profiles
09:32:00 0 sqlt$d: 0 rows collected
09:32:00 0 sqlt$d: -> collect_dbms_stats_glob_prefs
09:32:00 0 sqlt$d: < - collect_dbms_stats_glob_prefs
09:32:00 0 sqlt$d: collect_sqlprof$attr
09:32:00 0 sqlt$d: 0 rows collected
09:32:00 0 sqlt$d: collect_sqlprof$
09:32:00 0 sqlt$d: 0 rows collected
09:32:00 0 sqlt$d: collect_dba_scheduler_jobs
09:32:00 0 sqlt$d: 1 rows collected
09:32:00 0 sqlt$d: one_plan_per_hv_mem
09:32:00 0 sqlt$d: 1 selected plans on sqlt$_gv$sql
09:32:00 0 sqlt$d: one_plan_per_hv_sta
09:32:00 0 sqlt$d: 0 selected plans on sqlt$_dba_sqltune_plans
09:32:00 0 sqlt$d: collect_plan_extensions
09:32:00 0 sqlt$d: 24 rows collected
09:32:00 0 sqlt$d: sql_tuning_advisor
09:32:01 1 sqlt$i: max_plan_et_secs:5.404 sta_time_limit_secs:1800
09:32:01 0 sqlt$i: -> SYS.DBMS_SQLTUNE.EXECUTE_TUNING_TASK（"sqlt_s34879_mem"）
09:36:56 295 sqlt$i: < - SYS.DBMS_SQLTUNE.EXECUTE_TUNING_TASK（"sqlt_s34879_mem"） 09:36:56 0 sqlt$i: -> SYS.DBMS_SQLTUNE.EXECUTE_TUNING_TASK（"sqlt_s34879_txt"）
09:38:05 69 sqlt$i: < - SYS.DBMS_SQLTUNE.EXECUTE_TUNING_TASK（"sqlt_s34879_txt"） 09:38:05 0 sqlt$a: -> upload_sta_files
09:38:05 0 sqlt$a: "sqlt_s34879_sta_report_mem.txt" was uploaded to repository
09:38:05 0 sqlt$a: "sqlt_s34879_sta_script_mem.sql" was uploaded to repository
09:38:05 0 sqlt$a: "sqlt_s34879_sta_report_txt.txt" was uploaded to repository
09:38:05 0 sqlt$a: "sqlt_s34879_sta_script_txt.sql" was uploaded to repository
09:38:05 0 sqlt$a: < - upload_sta_files
09:38:05 0 sqlt$i: <= sql_tuning_advisor 09:38:05 0 sqlt$i: => test_case_builder
09:38:05 0 sqlt$i: skip test_case_builder since rdbms_release does not provide it
09:38:05 0 sqlt$r: -> tcb_driver
09:38:05 0 sqlt$r: generated sqlt_s34879_tcb_driver.sql
09:38:05 0 sqlt$r: < - tcb_driver
09:38:05 0 sqlt$i: <= test_case_builder 09:38:05 0 sqlt$i: => ebs_application_specific
09:38:05 0 sqlt$i: this is not an EBS application
09:38:05 0 sqlt$i: skip "bde_chk_cbo" since this is not an EBS application
09:38:05 0 sqlt$i: < = ebs_application_specific 09:38:05 0 sqlt$i: => siebel_application_specific
09:38:05 0 sqlt$i: < = siebel_application_specific 09:38:05 0 sqlt$i: => psft_application_specific
09:38:05 0 sqlt$i: < = psft_application_specific 09:38:05 0 sqlt$i: => collect_metadata
09:38:05 0 sqlt$i: -> collect_metadata_objects transformed = "N"
09:38:08 3 sqlt$i: < - collect_metadata_objects transformed = "N" 09:38:08 0 sqlt$i: -> collect_metadata_objects transformed = "Y"
09:38:09 1 sqlt$i: < - collect_metadata_objects transformed = "Y" 09:38:09 0 sqlt$i: -> collect_metadata_constraints transformed = "Y"
09:38:11 2 sqlt$i: < - collect_metadata_constraints transformed = "Y"
09:38:11 0 sqlt$i: <= collect_metadata 09:38:11 0 sqlt$i: => compute_full_table_scan_cost
09:38:11 0 sqlt$i: < = compute_full_table_scan_cost 09:38:11 0 sqlt$i: => perform_count_star
09:38:11 0 sqlt$i: num_rows=119951 sql=SELECT /*+ FULL（t） PARALLEL */ COUNT（*） * 1e2 FROM "INSUR_CHANGDE"."MT_APPLY" SAMPLE （1） t
09:38:11 0 sqlt$i: 121500 rows counted
09:38:11 0 sqlt$i: num_rows=14014679 sql=SELECT /*+ FULL（t） PARALLEL */ COUNT（*） * 1e4 FROM "INSUR_CHANGDE"."MT_BIZ_FIN" SAMPLE （.01） t
09:38:15 4 sqlt$i: 13860000 rows counted
09:38:15 0 sqlt$i: num_rows=35518818 sql=SELECT /*+ FULL（t） PARALLEL */ COUNT（*） * 1e4 FROM "INSUR_CHANGDE"."MT_PAY_RECORD_FIN" SAMPLE （.01） t
09:38:15 0 sqlt$i: 38670000 rows counted
09:38:15 0 sqlt$i: < = perform_count_star 09:38:15 0 sqlt$i: collect_dbms_space 09:38:15 0 sqlt$i: collect_dbms_space.tables 09:38:15 0 sqlt$i: DBMS_SPACE.CREATE_TABLE_COST tablespace_name:HYGEIA avg_row_size:291 row_count:121500 pct_free:10 09:38:16 1 sqlt$i: DBMS_SPACE.CREATE_TABLE_COST tablespace_name:HYGEIA avg_row_size:292 row_count:13860000 pct_free:10 09:38:16 0 sqlt$i: DBMS_SPACE.CREATE_TABLE_COST tablespace_name:HYGEIA avg_row_size:70 row_count:38670000 pct_free:10 09:38:16 0 sqlt$i: collect_dbms_space.indexes 09:38:16 0 sqlt$i: SYS.DBMS_SPACE.CREATE_INDEX_COST index_name:IDX$$_429C0002 09:38:16 0 sqlt$i: SYS.DBMS_SPACE.CREATE_INDEX_COST index_name:IDX$$_429C0001 09:38:16 0 sqlt$i: SYS.DBMS_SPACE.CREATE_INDEX_COST index_name:IDX_MT_BIZ_FIN_END_DATE 09:38:16 0 sqlt$i: SYS.DBMS_SPACE.CREATE_INDEX_COST index_name:IDX_MT_BIZ_FIN_INDI_ID 09:38:16 0 sqlt$i: SYS.DBMS_SPACE.CREATE_INDEX_COST index_name:IDX_MT_APPLY_INDI 09:38:16 0 sqlt$i: SYS.DBMS_SPACE.CREATE_INDEX_COST index_name:IDX_MT_BIZ_FIN_FIN_DATE_01 09:38:16 0 sqlt$i: SYS.DBMS_SPACE.CREATE_INDEX_COST index_name:IDX_MT_APPLY_SERIAL 09:38:16 0 sqlt$i: SYS.DBMS_SPACE.CREATE_INDEX_COST index_name:INDI_MT_BIZ_FIN_H_F 09:38:16 0 sqlt$i: SYS.DBMS_SPACE.CREATE_INDEX_COST index_name:IDX_MT_PAY_RECORD_FIN_2 09:38:16 0 sqlt$i: SYS.DBMS_SPACE.CREATE_INDEX_COST index_name:IDX_MT_PAY_RECORD_FIN_1 09:38:16 0 sqlt$i: SYS.DBMS_SPACE.CREATE_INDEX_COST index_name:PK_MT_PAY_RECORD_FIN 09:38:16 0 sqlt$i: SYS.DBMS_SPACE.CREATE_INDEX_COST index_name:PK_MT_BIZ_FIN 09:38:16 0 sqlt$i: SYS.DBMS_SPACE.CREATE_INDEX_COST index_name:PK_MT_APPLY 09:38:16 0 sqlt$i: SYS.DBMS_SPACE.CREATE_INDEX_COST index_name:IDX_MT_BIZ_FIN_FIN_DATE 09:38:16 0 sqlt$i: SYS.DBMS_SPACE.CREATE_INDEX_COST index_name:IDX_MT_BIZ_FIN_BEGIN_DATE 09:38:16 0 sqlt$i: SYS.DBMS_SPACE.CREATE_INDEX_COST index_name:IDX_MT_BIZ_FIN_1 09:38:16 0 sqlt$i: SYS.DBMS_SPACE.CREATE_INDEX_COST index_name:IDX_MT_APPLY_INPUT 09:38:16 0 sqlt$t: => perm_transformation
09:38:16 0 sqlt$t: put_statid_into_plan_table
09:38:16 0 sqlt$t: 12 rows updated
09:38:16 0 sqlt$t: put_obj_id_into_tables
09:38:16 0 sqlt$t: 3 rows updated
09:38:16 0 sqlt$t: put_obj_id_into_indexes
09:38:16 0 sqlt$t: 17 rows updated
09:38:16 0 sqlt$t: record_cbo_system_stats
09:38:16 0 sqlt$t: remap_metadata
09:38:17 1 sqlt$t: 70 metadata rows remapped in sqlt$_metadata
09:38:17 0 sqlt$t: table_histograms
09:38:17 0 sqlt$t: partition_histograms
09:38:17 0 sqlt$t: subpartition_histograms
09:38:17 0 sqlt$t: cook_low_and_high_values
09:38:17 0 sqlt$t: 170 rows updated in sqlt$_dba_all_table_cols_v
09:38:17 0 sqlt$t: 0 rows updated in sqlt$_dba_part_col_statistics
09:38:17 0 sqlt$t: 0 rows updated in sqlt$_dba_subpart_col_stats
09:38:17 0 sqlt$t: 78 rows updated in sqlt$_dba_col_stats_versions
09:38:17 0 sqlt$t: compute_mutating_ndv
09:38:17 0 sqlt$t: 0 rows updated with mutating_ndv
09:38:17 0 sqlt$t: compute_endpoints_count
09:38:17 0 sqlt$t: 35 rows updated in sqlt$_dba_histgrm_stats_versn with endpoints_count > 0
09:38:17 0 sqlt$t: compute_mutating_endpoints
09:38:17 0 sqlt$t: 0 rows updated with mutating_endpoints
09:38:17 0 sqlt$t: compute_mutating_num_rows
09:38:17 0 sqlt$t: 0 rows updated with mutating_num_rows
09:38:17 0 sqlt$t: compute_mutating_blevel
09:38:17 0 sqlt$t: 0 rows updated with mutating_blevel
09:38:17 0 sqlt$t: index_in_plan
09:38:17 0 sqlt$t: 3 indexes in plan
09:38:17 0 sqlt$t: column_in_indexes
09:38:17 0 sqlt$t: 30 columns in indexes
09:38:17 0 sqlt$t: at_least_1_notnull_col
09:38:18 1 sqlt$t: 14 indexes updated
09:38:18 0 sqlt$t: skip add_column_default
09:38:18 0 sqlt$t: not_shared_cursors
09:38:18 0 sqlt$t: 0 rows inserted into sqlg$_sql_shared_cursor_n
09:38:18 0 sqlt$t: 0 rows inserted into sqlt$_sql_shared_cursor_d
09:38:18 0 sqlt$t: flag_dba_hist_sqlstat
09:38:18 0 sqlt$t: 0 rows flagged in in_plan_extension
09:38:18 0 sqlt$t: 0 plans in in_plan_summary_v
09:38:18 0 sqlt$t: best_and_worst_plans
09:38:18 0 sqlt$t: fix_cardinality_line_0
09:38:18 0 sqlt$t: 1 plans fixed
09:38:18 0 sqlt$t: execution_order
09:38:18 0 sqlt$t: real_depth
09:38:18 0 sqlt$t: real_depth_m
09:38:18 0 sqlt$t: process_other_xml
09:38:18 0 sqlt$t: 0 binds were processed out of other_xml columns
09:38:18 0 sqlt$t: 12 info rows were processed out of other_xml columns
09:38:18 0 sqlt$t: 68 hints were processed out of other_xml columns
09:38:18 0 sqlt$t: plan_operation
09:38:18 0 sqlt$t: top_cost
09:38:18 0 sqlt$t: top_last_cr_buffer_gets
09:38:18 0 sqlt$t: top_cr_buffer_gets
09:38:18 0 sqlt$t: top_last_cu_buffer_gets
09:38:18 0 sqlt$t: top_cu_buffer_gets
09:38:18 0 sqlt$t: top_last_disk_reads
09:38:18 0 sqlt$t: top_disk_reads
09:38:18 0 sqlt$t: top_last_disk_writes
09:38:18 0 sqlt$t: top_disk_writes
09:38:18 0 sqlt$t: top_last_elapsed_time
09:38:18 0 sqlt$t: top_elapsed_time
09:38:18 0 sqlt$t: build_plan_more_html_table
09:38:19 1 sqlt$t: 22 plan more html tables built
09:38:19 0 sqlt$t: build_workarea_html_table
09:38:19 0 sqlt$t: 1 work area html tables built
09:38:19 0 sqlt$t: build_workarea_html_table
09:38:19 0 sqlt$t: 14 go to html tables built
09:38:19 0 sqlt$t: sanitize_reason
09:38:19 0 sqlt$t: 0 reason columns have been sanitized
09:38:19 0 sqlt$t: sanitize_dir_notes
09:38:19 0 sqlt$t: 0 directives notes columns have been sanitized
09:38:19 0 sqlt$t: sanitize_other_xml
09:38:19 0 sqlt$t: 3 other_xml columns have been sanitized
09:38:19 0 sqlt$t: extend_peeked_binds
09:38:19 0 sqlt$t: 0 peeked_binds were extended
09:38:19 0 sqlt$t: extend_gv$sql_bind_capture
09:38:19 0 sqlt$t: 0 captured_binds were extended with phv
09:38:19 0 sqlt$t: 0 captured_binds were extended with value
09:38:19 0 sqlt$t: extend_gv$sql_optimizer_env
09:38:19 0 sqlt$t: 5 optimizer_env were extended
09:38:19 0 sqlt$t: extend_dba_hist_sqlbind
09:38:19 0 sqlt$t: 0 captured_binds were extended with phv
09:38:19 0 sqlt$t: 0 captured_binds were extended with value
09:38:19 0 sqlt$t: binds_in_predicates
09:38:19 0 sqlt$t: 0 binds in predicates
09:38:19 0 sqlt$t: column_in_predicates
09:38:19 0 sqlt$t: 18 columns in predicates
09:38:19 0 sqlt$t: column_in_projection
09:38:19 0 sqlt$t: 10 columns in projection
09:38:19 0 sqlt$t: extend_gv$sql_monitor
09:38:19 0 sqlt$t: 0 sql_monitor rows were extended
09:38:19 0 sqlt$t: extend_sqlt$_aux_stats$
09:38:19 0 sqlt$t: compute_index_range_scan_cost
09:38:19 0 sqlt$t: compute_index_leaf_estimate
09:38:19 0 sqlt$t: new_11g_ndv_algorithm_used
09:38:19 0 sqlt$t: skip col_group_usage_report
09:38:19 0 sqlt$t: add_dv_censored
09:38:19 0 sqlt$t: < = perm_transformation 09:38:19 0 sqlt$r: -> sql_monitor_reports
09:38:19 0 sqlt$r: skip "sql_monitor_reports" since not available in "10.2.0.4.0"
09:38:19 0 sqlt$r: < - sql_monitor_reports 09:38:19 0 sqlt$r: -> sql_detail_report
09:38:19 0 sqlt$r: skip "sql_detail_report" since not available in "10.2.0.4.0"
09:38:19 0 sqlt$r: < - sql_detail_report 09:38:19 0 sqlt$r: -> awrrpt_driver
09:38:19 0 sqlt$r: generated sqlt_s34879_awrrpt_driver.sql
09:38:19 0 sqlt$r: < - awrrpt_driver 09:38:19 0 sqlt$r: -> addmrpt_driver
09:38:19 0 sqlt$r: generated sqlt_s34879_addmrpt_driver.sql
09:38:19 0 sqlt$r: < - addmrpt_driver 09:38:19 0 sqlt$r: -> ashrpt_driver
09:38:19 0 sqlt$r: generated sqlt_s34879_ashrpt_driver.sql
09:38:19 0 sqlt$r: < - ashrpt_driver 09:38:19 0 sqlt$r: -> xpand_sql_driver
09:38:19 0 sqlt$r: generated sqlt_s34879_xpand_sql_driver.sql
09:38:19 0 sqlt$r: < - xpand_sql_driver 09:38:19 0 sqlt$r: -> script_output_driver
09:38:19 0 sqlt$r: generated sqlt_s34879_script_output_driver.sql
09:38:19 0 sqlt$r: < - script_output_driver 09:38:19 0 sqlt$r: -> tkprof_px_driver
09:38:19 0 sqlt$a: -> session_trace_filename
09:38:19 0 sqlt$a: session_trace_filename, current trace_filename
09:38:19 0 sqlt$a: session_trace_filename, current process_name ora
09:38:19 0 sqlt$a: < - session_trace_filename rlzy_ora_3081178_s34879_10046_10053.trc
09:38:19 0 sqlt$r: trace rlzy_ora_3081178_s34879_10046_10053.trc exists in /oracle/admin/RLZY/udump/
09:38:19 0 sqlt$r: px files were not found
09:38:19 0 sqlt$r: generated sqlt_s34879_tkprof_px_driver.sql
09:38:19 0 sqlt$r: call_trace_analyzer_px
09:38:19 0 sqlt$i: skip "trace_analyzer_px" since there are no accesible PX traces
09:38:19 0 sqlt$i: < = call_trace_analyzer_px 09:38:19 0 sqlt$r: -> export_parfile
09:38:20 1 sqlt$r: generated sqlt_s34879_export_parfile.txt
09:38:20 0 sqlt$r: < - export_parfile 09:38:20 0 sqlt$r: -> export_parfile2
09:38:20 0 sqlt$r: generated sqlt_s34879_export_parfile2.txt
09:38:20 0 sqlt$r: < - export_parfile2 09:38:20 0 sqlt$r: -> export_driver
09:38:20 0 sqlt$r: generated sqlt_s34879_export_driver.sql
09:38:20 0 sqlt$r: < - export_driver 09:38:20 0 sqlt$r: -> import_script
09:38:20 0 sqlt$r: generated sqlt_s34879_import.sh
09:38:20 0 sqlt$r: < - import_script 09:38:20 0 sqlt$r: -> metadata_script
09:38:20 0 sqlt$r: < - metadata_script 09:38:20 0 sqlt$r: -> metadata_script1
09:38:20 0 sqlt$r: < - metadata_script1 09:38:20 0 sqlt$r: -> metadata_script2
09:38:20 0 sqlt$r: < - metadata_script2 09:38:20 0 sqlt$r: -> system_stats_script
09:38:20 0 sqlt$r: < - system_stats_script 09:38:20 0 sqlt$r: -> schema_stats_script
09:38:20 0 sqlt$r: < - schema_stats_script 09:38:20 0 sqlt$r: -> set_cbo_env_script
09:38:20 0 sqlt$r: < - set_cbo_env_script 09:38:20 0 sqlt$r: -> custom_sql_profile
09:38:20 0 sqlt$r: ** skip "custom_sql_profile" as per "custom_sql_profile" parameter. this functionality is now disabled by default.
09:38:20 0 sqlt$r: ** to enable this functionality execute: SQL> EXEC SQLTXADMIN.sqlt$a.set_param（"custom_sql_profile", "Y"）;
09:38:20 0 sqlt$r: < - custom_sql_profile 09:38:20 0 sqlt$r: -> plan
09:38:20 0 sqlt$r: < - plan 09:38:20 0 sqlt$r: -> s10053
09:38:20 0 sqlt$r: < - s10053 09:38:20 0 sqlt$r: -> flush
09:38:20 0 sqlt$r: < - flush 09:38:20 0 sqlt$r: -> purge
09:38:20 0 sqlt$r: < - purge 09:38:20 0 sqlt$r: -> restore
09:38:20 0 sqlt$r: < - restore 09:38:20 0 sqlt$r: -> del_hgrm
09:38:20 0 sqlt$r: < - del_hgrm 09:38:20 0 sqlt$r: -> tc_sql
09:38:20 0 sqlt$r: < - tc_sql 09:38:20 0 sqlt$r: -> xpress_sh
09:38:20 0 sqlt$r: < - xpress_sh 09:38:20 0 sqlt$r: -> xpress_sql
09:38:20 0 sqlt$r: < - xpress_sql 09:38:20 0 sqlt$r: -> setup
09:38:20 0 sqlt$r: < - setup 09:38:20 0 sqlt$r: -> readme
09:38:20 0 sqlt$r: < - readme 09:38:20 0 sqlt$r: -> tc_pkg
09:38:20 0 sqlt$r: < - tc_pkg 09:38:20 0 sqlt$r: -> sel
09:38:20 0 sqlt$r: < - sel 09:38:20 0 sqlt$r: -> sel_aux
09:38:20 0 sqlt$r: < - sel_aux 09:38:20 0 sqlt$r: -> install_sh
09:38:20 0 sqlt$r: < - install_sh 09:38:20 0 sqlt$r: -> install_sql
09:38:20 0 sqlt$r: < - install_sql 09:38:20 0 sqlt$r: -> tcx_pkg
09:38:20 0 sqlt$r: < - tcx_pkg 09:38:20 0 sqlt$r: -> lite_report
09:38:20 0 sqlt$r: -> lite_report.header
09:38:20 0 sqlt$r: -> lite_report.plans_summary
09:38:20 0 sqlt$r: -> lite_report.plans_list
09:38:20 0 sqlt$r: -> lite_report.plans
09:38:21 1 sqlt$r: -> lite_report.tables
09:38:21 0 sqlt$r: -> lite_report.table_columns
09:38:21 0 sqlt$r: -> lite_report.indexes
09:38:21 0 sqlt$r: -> lite_report.index_columns
09:38:22 1 sqlt$r: -> lite_report.footer
09:38:22 0 sqlt$r: < - lite_report 09:38:22 0 sqlt$a: -> upload_10053_trace
09:38:22 0 sqlt$a: -> upload_trace
09:38:22 0 sqlt$a: source = "rlzy_ora_3081178_s34879_10053.trc"
09:38:22 0 sqlt$a: target = "sqlt_s34879_10053_explain.trc"
09:38:22 0 sqlt$a: prepare file workspace
09:38:22 0 sqlt$a: open source trace （input）
09:38:22 0 sqlt$a: open target clob （output）
09:38:22 0 sqlt$a: source_offset:1 target_offset:1
09:38:22 0 sqlt$a: close trace and clob
09:38:22 0 sqlt$a: update file_size
09:38:22 0 sqlt$a: -> set_filesize for:sqlt_s34879_10053_explain.trc
09:38:22 0 sqlt$a: < - set_filesize for:sqlt_s34879_10053_explain.trc
09:38:22 0 sqlt$a: upload_10053_xtract
09:38:22 0 sqlt$a: -> upload_trace
09:38:22 0 sqlt$a: there is no trace to upload to repository
09:38:22 0 sqlt$a: < - upload_trace
09:38:22 0 sqlt$a: remote_trace_analyzer_and_copy
09:38:22 0 sqlt$i: < = remote_trace_analyzer_and_copy 09:38:22 0 sqlt$r: -> remote_driver
09:38:22 0 sqlt$r: generated sqlt_s34879_remote_driver.sql
09:38:22 0 sqlt$r: < - remote_driver 09:38:22 0 sqlt$a: input_filename "/oracle/sqlt/input/sample/mysql2.sql" was recorded 09:38:22 0 sqlt$m: => main_report_root
09:38:22 0 sqlt$a: -> common_initialization
09:38:22 0 sqlt$a: ALTER SESSION SET NLS_NUMERIC_CHARACTERS = ".,"
09:38:22 0 sqlt$a: ALTER SESSION SET NLS_SORT = BINARY
09:38:22 0 sqlt$a: < - common_initialization 09:38:22 0 sqlt$t: => temp_transformation
09:38:22 0 sqlt$t: build_column_html_table_pred
09:38:22 0 sqlt$t: 8 column html tables built
09:38:22 0 sqlt$t: build_column_html_table_idx
09:38:23 1 sqlt$t: 27 column html tables built
09:38:23 0 sqlt$t: index_columns
09:38:23 0 sqlt$t: < = temp_transformation 09:38:23 0 sqlt$h: => health_check
09:38:23 0 sqlt$h: -> global_hc
09:38:23 0 sqlt$h: < - global_hc 09:38:23 0 sqlt$h: -> table_hc_MT_APPLY
09:38:23 0 sqlt$h: < - table_hc_MT_APPLY 09:38:23 0 sqlt$h: -> index_hc_IDX_MT_APPLY_INDI
09:38:23 0 sqlt$h: < - index_hc_IDX_MT_APPLY_INDI 09:38:23 0 sqlt$h: -> index_hc_IDX_MT_APPLY_INPUT
09:38:23 0 sqlt$h: < - index_hc_IDX_MT_APPLY_INPUT 09:38:23 0 sqlt$h: -> index_hc_IDX_MT_APPLY_SERIAL
09:38:23 0 sqlt$h: < - index_hc_IDX_MT_APPLY_SERIAL 09:38:23 0 sqlt$h: -> index_hc_PK_MT_APPLY
09:38:23 0 sqlt$h: < - index_hc_PK_MT_APPLY 09:38:23 0 sqlt$h: -> column_hc_MT_APPLY_HOSPITAL_ID
09:38:23 0 sqlt$h: < - column_hc_MT_APPLY_HOSPITAL_ID 09:38:23 0 sqlt$h: -> column_hc_MT_APPLY_INDI_ID
09:38:23 0 sqlt$h: < - column_hc_MT_APPLY_INDI_ID 09:38:23 0 sqlt$h: -> column_hc_MT_APPLY_SERIAL_APPLY
09:38:23 0 sqlt$h: < - column_hc_MT_APPLY_SERIAL_APPLY 09:38:23 0 sqlt$h: -> column_hc_MT_APPLY_SERIAL_NO
09:38:23 0 sqlt$h: < - column_hc_MT_APPLY_SERIAL_NO 09:38:23 0 sqlt$h: -> column_hc_MT_APPLY_TREATMENT_TYPE
09:38:23 0 sqlt$h: < - column_hc_MT_APPLY_TREATMENT_TYPE 09:38:23 0 sqlt$h: -> column_hc_MT_APPLY_VALID_FLAG
09:38:23 0 sqlt$h: < - column_hc_MT_APPLY_VALID_FLAG 09:38:23 0 sqlt$h: -> table_hc_MT_BIZ_FIN
09:38:23 0 sqlt$h: < - table_hc_MT_BIZ_FIN 09:38:23 0 sqlt$h: -> index_hc_IDX$$_429C0001
09:38:23 0 sqlt$h: < - index_hc_IDX$$_429C0001 09:38:23 0 sqlt$h: -> index_hc_IDX_MT_BIZ_FIN_1
09:38:23 0 sqlt$h: < - index_hc_IDX_MT_BIZ_FIN_1 09:38:23 0 sqlt$h: -> index_hc_IDX_MT_BIZ_FIN_BEGIN_DATE
09:38:23 0 sqlt$h: < - index_hc_IDX_MT_BIZ_FIN_BEGIN_DATE 09:38:23 0 sqlt$h: -> index_hc_IDX_MT_BIZ_FIN_END_DATE
09:38:23 0 sqlt$h: < - index_hc_IDX_MT_BIZ_FIN_END_DATE 09:38:23 0 sqlt$h: -> index_hc_IDX_MT_BIZ_FIN_FIN_DATE
09:38:23 0 sqlt$h: < - index_hc_IDX_MT_BIZ_FIN_FIN_DATE 09:38:23 0 sqlt$h: -> index_hc_IDX_MT_BIZ_FIN_FIN_DATE_01
09:38:23 0 sqlt$h: < - index_hc_IDX_MT_BIZ_FIN_FIN_DATE_01 09:38:23 0 sqlt$h: -> index_hc_IDX_MT_BIZ_FIN_INDI_ID
09:38:23 0 sqlt$h: < - index_hc_IDX_MT_BIZ_FIN_INDI_ID 09:38:23 0 sqlt$h: -> index_hc_INDI_MT_BIZ_FIN_H_F
09:38:23 0 sqlt$h: < - index_hc_INDI_MT_BIZ_FIN_H_F 09:38:23 0 sqlt$h: -> index_hc_PK_MT_BIZ_FIN
09:38:23 0 sqlt$h: < - index_hc_PK_MT_BIZ_FIN 09:38:23 0 sqlt$h: -> column_hc_MT_BIZ_FIN_HOSPITAL_ID
09:38:23 0 sqlt$h: < - column_hc_MT_BIZ_FIN_HOSPITAL_ID 09:38:23 0 sqlt$h: -> column_hc_MT_BIZ_FIN_INDI_ID
09:38:23 0 sqlt$h: < - column_hc_MT_BIZ_FIN_INDI_ID 09:38:23 0 sqlt$h: -> column_hc_MT_BIZ_FIN_SERIAL_APPLY
09:38:23 0 sqlt$h: < - column_hc_MT_BIZ_FIN_SERIAL_APPLY 09:38:23 0 sqlt$h: -> column_hc_MT_BIZ_FIN_SERIAL_NO
09:38:23 0 sqlt$h: < - column_hc_MT_BIZ_FIN_SERIAL_NO 09:38:23 0 sqlt$h: -> column_hc_MT_BIZ_FIN_TREATMENT_TYPE
09:38:23 0 sqlt$h: < - column_hc_MT_BIZ_FIN_TREATMENT_TYPE 09:38:23 0 sqlt$h: -> column_hc_MT_BIZ_FIN_VALID_FLAG
09:38:23 0 sqlt$h: < - column_hc_MT_BIZ_FIN_VALID_FLAG 09:38:23 0 sqlt$h: -> table_hc_MT_PAY_RECORD_FIN
09:38:23 0 sqlt$h: < - table_hc_MT_PAY_RECORD_FIN 09:38:23 0 sqlt$h: -> index_hc_IDX$$_429C0002
09:38:23 0 sqlt$h: < - index_hc_IDX$$_429C0002 09:38:23 0 sqlt$h: -> index_hc_IDX_MT_PAY_RECORD_FIN_1
09:38:23 0 sqlt$h: < - index_hc_IDX_MT_PAY_RECORD_FIN_1 09:38:23 0 sqlt$h: -> index_hc_IDX_MT_PAY_RECORD_FIN_2
09:38:23 0 sqlt$h: < - index_hc_IDX_MT_PAY_RECORD_FIN_2 09:38:23 0 sqlt$h: -> index_hc_PK_MT_PAY_RECORD_FIN
09:38:23 0 sqlt$h: < - index_hc_PK_MT_PAY_RECORD_FIN 09:38:23 0 sqlt$h: -> column_hc_MT_PAY_RECORD_FIN_FUND_ID
09:38:23 0 sqlt$h: < - column_hc_MT_PAY_RECORD_FIN_FUND_ID 09:38:23 0 sqlt$h: -> column_hc_MT_PAY_RECORD_FIN_HOSPITAL_ID
09:38:23 0 sqlt$h: < - column_hc_MT_PAY_RECORD_FIN_HOSPITAL_ID 09:38:23 0 sqlt$h: -> column_hc_MT_PAY_RECORD_FIN_POLICY_ITEM_CODE
09:38:23 0 sqlt$h: < - column_hc_MT_PAY_RECORD_FIN_POLICY_ITEM_CODE 09:38:23 0 sqlt$h: -> column_hc_MT_PAY_RECORD_FIN_SERIAL_NO
09:38:23 0 sqlt$h: < - column_hc_MT_PAY_RECORD_FIN_SERIAL_NO 09:38:23 0 sqlt$h: -> column_hc_MT_PAY_RECORD_FIN_VALID_FLAG
09:38:23 0 sqlt$h: < - column_hc_MT_PAY_RECORD_FIN_VALID_FLAG
09:38:23 0 sqlt$h: <= health_check 09:38:23 0 sqlt$m: => main_report
09:38:23 0 sqlt$m: -> flags
09:38:24 1 sqlt$m: < - flags
09:38:24 0 sqlt$m: observations_sec
09:38:24 0 sqlt$m: sql_text_sec
09:38:24 0 sqlt$m: sql_identification_sec
09:38:24 0 sqlt$m: environment_sec
09:38:24 0 sqlt$m: cbo_environment_sec
09:38:24 0 sqlt$m: cbo_environment_mod
09:38:24 0 sqlt$m: cbo_environment_unmod
09:38:24 0 sqlt$m: bug_fix_control_sec
09:38:24 0 sqlt$m: bug_fix_control_sec_0
09:38:24 0 sqlt$m: bug_fix_control_sec_1
09:38:24 0 sqlt$m: system_stats_sec
09:38:24 0 sqlt$m: dbms_stats_setup_sec
09:38:25 1 sqlt$m: init_parameters_sec
09:38:25 0 sqlt$m: init_parameters_sec_FALSE
09:38:25 0 sqlt$m: init_parameters_sec_TRUE
09:38:25 0 sqlt$m: init_parameters_sys_mod
09:38:25 0 sqlt$m: init_parameters_sys
09:38:25 0 sqlt$m: nls_parameters_sec
09:38:25 0 sqlt$m: io_calibration_sec
09:38:25 0 sqlt$m: tool_config_params_sec
09:38:25 0 sqlt$m: cursor_sharing_sec
09:38:26 1 sqlt$m: plan_sum_sec
09:38:26 0 sqlt$m: plan_stats_sec
09:38:26 0 sqlt$m: plan_stats_sec_2582817425_GV$SQLAREA_PLAN_HASH_1
09:38:26 0 sqlt$m: plan_exec_sec
09:38:26 0 sqlt$m: plan_exec_sec_2582817425_1_1_0_07000005C96BA558
09:38:26 0 sqlt$m: src = "MEM"
09:38:26 0 sqlt$m: source = "GV$SQL_PLAN"
09:38:26 0 sqlt$m: phv = "2582817425"
09:38:26 0 sqlt$m: plan_id = "-1"
09:38:26 0 sqlt$m: inst_id = "1"
09:38:26 0 sqlt$m: child_number = "0"
09:38:26 0 sqlt$m: child_address = "07000005C96BA558"
09:38:26 0 sqlt$m: gv$sql_plan_statistics = "1"
09:38:26 0 sqlt$m: last_starts = "7"
09:38:26 0 sqlt$m: starts = "21"
09:38:26 0 sqlt$m: last_output_rows = "1185999"
09:38:26 0 sqlt$m: output_rows = "3557995"
09:38:26 0 sqlt$m: last_cr_buffer_gets = "408609"
09:38:26 0 sqlt$m: cr_buffer_gets = "1225838"
09:38:26 0 sqlt$m: last_cu_buffer_gets = "0"
09:38:26 0 sqlt$m: cu_buffer_gets = "0"
09:38:26 0 sqlt$m: last_disk_reads = "0"
09:38:26 0 sqlt$m: disk_reads = "1798"
09:38:26 0 sqlt$m: last_disk_writes = "0"
09:38:26 0 sqlt$m: disk_writes = "0"
09:38:26 0 sqlt$m: last_elapsed_time = "5388427"
09:38:26 0 sqlt$m: elapsed_time = "16192336"
09:38:26 0 sqlt$m: executions = "3"
09:38:26 0 sqlt$m: gv$sql_monitor.sql_exec_start = ""
09:38:26 0 sqlt$m: gv$sql_monitor.sql_exec_id = ""
09:38:26 0 sqlt$m: gv$sql_monitor.key = ""
09:38:26 0 sqlt$m: gv$sql_workarea = "1"
09:38:26 0 sqlt$m: sqlt$_plan_extension.more = "1"
09:38:26 0 sqlt$m: sqlt$_plan_extension.binds_peek = "0"
09:38:26 0 sqlt$m: sqlt$_plan_extension.binds_capt = "0"
09:38:26 0 sqlt$m: plan_exec_sec_2582817425_3_542___
09:38:26 0 sqlt$m: src = "XPL"
09:38:26 0 sqlt$m: source = "PLAN_TABLE"
09:38:26 0 sqlt$m: phv = "2582817425"
09:38:26 0 sqlt$m: plan_id = "542"
09:38:26 0 sqlt$m: inst_id = ""
09:38:26 0 sqlt$m: child_number = ""
09:38:26 0 sqlt$m: child_address = ""
09:38:26 0 sqlt$m: sqlt$_plan_extension.more = "1"
09:38:26 0 sqlt$m: sqlt$_plan_extension.binds_peek = "0"
09:38:26 0 sqlt$m: sqlt$_plan_extension.binds_capt = "0"
09:38:26 0 sqlt$m: act_sess_hist_sec
09:38:26 0 sqlt$m: sql_stats_sec
09:38:26 0 sqlt$m: sql_stats_sec_2582817425_1_0_07000005C96BA558_0700000438927940
09:38:26 0 sqlt$m: session_stats_sec
09:38:26 0 sqlt$m: session_event_sec
09:38:26 0 sqlt$m: parallel_processing_sec1
09:38:27 1 sqlt$m: table_sum_sec
09:38:27 0 sqlt$m: tab_stats_sec
09:38:27 0 sqlt$m: tab_stats_vers_sec
09:38:27 0 sqlt$m: tab_mod_sec
09:38:27 0 sqlt$m: tab_prop_sec
09:38:27 0 sqlt$m: tab_phy_prop_sec
09:38:27 0 sqlt$m: tab_cons_sec
09:38:27 0 sqlt$m: tab_cols_sec
09:38:29 2 sqlt$m: indexed_columns_sec
09:38:30 1 sqlt$m: tab_col_hgrm_sec
09:38:58 28 sqlt$m: index_sum_sec
09:39:00 2 sqlt$m: objects_sec
09:39:00 0 sqlt$m: dependencies_sec
09:39:00 0 sqlt$m: tablespaces_sec
09:39:00 0 sqlt$m: metadata_sec
09:39:00 0 sqlt$m: generated sqlt_s34879_main.html
09:39:00 0 sqlt$m: <= main_report 09:39:00 0 sqlt$e: -> get_file_attributes_from_repo
09:39:00 0 sqlt$e: < - get_file_attributes_from_repo
09:39:00 0 sqlt$m: main_report max_file_size: 104857600B （102400KB）（100MB）
09:39:00 0 sqlt$m: main_report current_size : 2786854B （2722KB）（3MB）
09:39:00 0 sqlt$m: no need to resize 1: scale down all lists by 0.5
09:39:00 0 sqlt$m: no need to resize 2: turn off go_to
09:39:00 0 sqlt$m: no need to resize 3: turn off overlib
09:39:00 0 sqlt$m: no need to resize 4: scale down all lists by 0.25
09:39:00 0 sqlt$m: no need to resize 5: turn off in_pred
09:39:00 0 sqlt$m: no need to resize 6: turn off sql_text
09:39:00 0 sqlt$m: no need to resize 7: scale down all lists by 0.125
09:39:00 0 sqlt$m: no need to resize 8: turn off metadata
09:39:00 0 sqlt$m: no need to resize 9: scale down all lists by 0.05
09:39:00 0 sqlt$m: <= main_report_root 09:39:00 0 sqlt$i: => call_trace_analyzer
Execution ID: 38597 started at 2014-08-26 09:39:00
In case of premature termination, read trcanlzr_error.log located in SQL*Plus default directory
/*************************************************************************************/
09:39:00 => trcanlzr
09:39:00 file_name:"rlzy_ora_3081178_s34879_10046_10053.trc"
09:39:00 analyze:"YES"
09:39:00 split:"YES"
09:39:00 tool_execution_id:"38597"
09:39:00 directory_alias_in:"SQLT$UDUMP"
09:39:00 file_name_log:"sqlt_s34879_"
09:39:00 file_name_html:"sqlt_s34879_"
09:39:00 file_name_txt:"sqlt_s34879_"
09:39:00 file_name_10046:""
09:39:00 file_name_10053:""
09:39:00 out_file_identifier:""
09:39:00 calling trca$p.parse_main
09:39:00 => parse_main
09:39:00 analyzing input file rlzy_ora_3081178_s34879_10046_10053.trc in /oracle/admin/RLZY/udump （SQLT$UDUMP）
09:39:00 -> parse_file
09:39:00 parsing file rlzy_ora_3081178_s34879_10046_10053.trc in /oracle/admin/RLZY/udump
09:39:01 invalid stat at line 233 "613" "" "123"
09:39:01 invalid stat at line 234 "613" "" "123"
09:39:01 invalid stat at line 235 "613" "" "123"
09:39:01 invalid stat at line 236 "613" "" "123"
09:39:01 invalid stat at line 237 "613" "" "123"
09:39:01 invalid stat at line 238 "613" "" "123"
09:39:01 invalid stat at line 239 "613" "" "123"
09:39:02 invalid stat at line 11296 "549" "" "105"
09:39:02 invalid stat at line 11297 "549" "" "105"
09:39:02 invalid stat at line 11298 "549" "" "105"
09:39:02 invalid stat at line 11299 "549" "" "105"
09:39:02 invalid stat at line 11300 "549" "" "105"
09:39:02 invalid stat at line 11301 "549" "" "105"
09:39:03 process_orphan_waits: creating some fake trace lines to aggregate waits into calls and cursors
09:39:03 =====================
09:39:03 PARSING IN CURSOR #0 len=9 dep=0 uid=0 oct=0 lid=0 tim=3502350433402 hv=0 ad="0"
09:39:03 CURSOR #0
09:39:03 END OF STMT
09:39:03 EXEC #0:c=0,e=340,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=0,tim=3502350433402
09:39:03 =====================
09:39:03 +
09:39:03 | 161 BINDS sets.
09:39:03 | 327 binds.
09:39:03 | 239 PARSE CALLs.
09:39:03 | 886 EXEC CALLs.
09:39:03 | 910 FETCH CALLs.
09:39:03 | 0 UNMAP CALLs.
09:39:03 | 0 SORT UNMAP CALLs.
09:39:03 | 47427547 CALL elapsed.
09:39:03 | 30780000 CALL cpu.
09:39:03 | 1828 CALL disk.
09:39:03 | 6547018 CALL query.
09:39:03 | 623 CALL current.
09:39:03 | 116 CALL misses.
09:39:03 | 3603 CALL rows.
09:39:03 | 21 WAIT count idle event.
09:39:03 | 720 WAIT count non-idle event.
09:39:03 | 26656 WAIT ela idle event.
09:39:03 | 310992 WAIT ela non-idle event.
09:39:03 | 885 STAT lines.
09:39:03 | 0 ERROR lines.
09:39:03 +
09:39:03 | 0 sessions in tracefile.
09:39:03 | 72 transactions in tracefile.
09:39:03 | 4 gaps in tracefile.
09:39:03 | 84 user SQL statements in trace file.
09:39:03 | 358 internal SQL statements in trace file.
09:39:03 | 442 SQL statements in trace file.
09:39:03 | 77 user unique SQL statements in trace file.
09:39:03 | 38 internal unique SQL statements in trace file.
09:39:03 | 115 unique SQL statements in trace file.
09:39:03 | 12043 lines in trace file.
09:39:03 | 0 long lines in trace file.
09:39:03 | 47 elapsed seconds in trace file.
09:39:03 +
09:39:03 parsed rlzy_ora_3081178_s34879_10046_10053.trc （input 713737 bytes, parsed as 713737 bytes）
09:39:03 < - parse_file
09:39:03 first_transformation
09:39:03 refresh tool data dictionary？
09:39:03 finding same database_id and host_name, considering dictionary refresh...
09:39:03 -> refresh_trca$_dict_from_this before（20140813）
09:39:03 => refresh_trca$_dict_from_this
09:39:03 -> purge_trca$_dict
09:39:03 dict_state_before_purge
09:39:03 -----------------------
09:39:03 -> print_dict_state
09:39:03 dict_refresh_days : 1
09:39:03 dict_refresh_date : 20140813
09:39:03 dict_database_id : 1589671076
09:39:03 dict_database_name: RLZY
09:39:03 dict_instance_id : 1
09:39:03 dict_instance_name: RLZY
09:39:03 dict_host_name : IBMP740-1
09:39:03 dict_platform : IBM/AIX RISC System/6000
09:39:03 dict_rdbms_version: 10.2.0.4.0
09:39:03 dict_db_files : 200
09:39:03 < - print_dict_state 09:39:03 -> call_purge_trca$_dict_gtt
09:39:03 < - call_purge_trca$_dict_gtt 09:39:25 dict_state_after_purge 09:39:25 ---------------------- 09:39:25 -> print_dict_state
09:39:25 dict_refresh_days :
09:39:25 dict_refresh_date :
09:39:25 dict_database_id :
09:39:25 dict_database_name:
09:39:25 dict_instance_id :
09:39:25 dict_instance_name:
09:39:25 dict_host_name :
09:39:25 dict_platform :
09:39:25 dict_rdbms_version:
09:39:25 dict_db_files :
09:39:25 < - print_dict_state
09:39:25 trca$_file$
09:39:25 < - trca$_file$ （78 rows） 09:39:25 -> trca$_segments
09:39:28 < - trca$_segments （96922 rows） 09:39:28 -> trca$_extents_dm
09:39:28 < - trca$_extents_dm （0 rows） 09:39:28 -> trca$_extents_lm
09:39:28 < - trca$_extents_lm （0 rows） 09:39:28 -> trca$_users
09:39:28 < - gather_table_stats: sqltxplain.trca$_users skipped
09:39:28 trca$_extents
09:39:28 < - gather_table_stats: sqltxplain.trca$_extents skipped
09:39:28 call_purge_trca$_dict_gtt
09:39:28 < - call_purge_trca$_dict_gtt 09:39:28 -> trca$_tables$
09:39:31 < - gather_table_stats: sqltxplain.trca$_tables$ skipped
09:39:31 trca$_ind