今天在一套生产的库中执行脚本查询锁住的对象，执行下面一个SQL：
 
select username, lockwait, status, machine, program
  from v$session
 where sid in (select session_id from v$locked_object);
 
结果这么简单的一条语句竟然执行了30多秒，然后在其它环境中都是秒出，这显然有问题，那么我们该如何定位问题所在呢？
 
SQL_TRACE是Oracle提供的用于进行SQL跟踪的手段，是强有力的辅助诊断工具。我们可以通过sql_trace去分析下为什么上面的sql会这么慢。
 
#对当前的会话开启sql_trace
 
SQL> alter session set sql_trace=true;

Session altered

SQL> select username, lockwait, status, machine, program
  from v$session
 where sid in (select session_id from v$locked_object);

no rows selected

#关闭当前会话的sql_trace
SQL> alter session set sql_trace=false;

Session altered.
 
接下来找到对应的trace文件，利用tkprof工具将得到的trace文件格式化，输出结果如下：
 
 可以看到执行了36s之多，明显有问题的地方就是执行计划里面显示X$KTADM这张表竟然有2000万之多，显然有问题！还有X$KTCXB表显示有70多万，显然也不正确。
 
 可以看到实际值与之相差很多。这说明数据字典中记录的统计信息与实际情况不符合，那么我们只需要重新收集这两张表的统计信息即可。
 
然后我们再去执行同样的语句结果就秒出了！

 
如果一个系统的执行效率比较低，一个比较好的方法是通过跟踪用户的会话并且使用tkprof工具使用排序功能格式化输出，从而找出有问题的SQL语句。
 
例如首先从os上利用top命令找到当前占用cpu资源最高的一个进程的PID号9999；
 
然后在数据库中根据PID号找到相应的sid和serial#
 
select s.sid,s.serial# from v$session s,v$process p where
 
s.paddr=p.addr and p.spid='9999';
 
然后通过exec
 
dbms_monitor.session_trace_enable(sid,serial#)开启trace；
 
最后利用tkprof察看trace输出。
 
开启Trace文件输出可以通过以下方法开启Trace文件输出(需要ALTER
 
SESSION系统权限):
 
1) alter session/system set sql_trace=true
 
2) exec
 
dbms_monitor.session_trace_enable/dbms_monitor.database_trace_enable
 
3) alter session set events '10046 trace name context forever,
 
level 12'
 
Trace文件的位置
 
· 如果使用专用服务器连接，会在USER_DUMP_DEST参数指定的目录中生成跟踪文件。
 
· 如果使用共享服务器连接，则在BACKGROUND_DUMP_DEST参数指定的目录中生成跟踪文件。
 
关于专用服务器/共享服务器->http://blog.csdn.net/fw0124/article/details/6898693
 
对于DEDICATED方式，Oracle11g之前，可以通过如下语句获得Trace文件路径：
 
select c.value || '/' || d.instance_name || '_ora_' || a.spid ||
 
'.trc' trace
 
from v$process a, v$session b, v$parameter c,
 
v$instance d
 
where a.addr = b.paddr
 
and b.audsid =
 
userenv('sessionid')
 
and c.name =
 
'user_dump_dest'；
 
Oracle11g之后，可以访问v$diag_info来获得Trace文件存放路径：
 
select * from v$diag_info where name='Default Trace File';
 
可以使用参数TRACEFILE_IDENTIFIER，为跟踪文件名增加一个可以惟一标识的串。例如：
 
alter session set tracefile_identifier='my_trace_file';
 
这样，生成的Trace文件名就会以my_trace_file.trc结尾。
 
共享服务器模式下，或者需要跟踪某些特定客户端，可以使用DBMS_MONITOR.CLIENT_ID_TRACE_ENABLE。方法是：
 
a) sqlplus登陆，exec
 
DBMS_MONITOR.CLIENT_ID_TRACE_ENABLE('mytest');
 
这里mytest是客户端标示符。
 
*可以通过select * from DBA_ENABLED_TRACES;查看当前的活动trace。
 
b) 需要被跟踪的客户端连接执行exec DBMS_SESSION.SET_IDENTIFIER ('mytest');
 
c) 不需要跟踪的时候可以sqlplus登陆，执行exec
 
DBMS_MONITOR.CLIENT_ID_TRACE_DISABLE('mytest');
 
d) 到USER_DUMP_DEST目录下执行trcsess output=mytest_trc.txt
 
clientid=mytest，会自动合并各个会话的trace文件，生成mytest_trc.txt
 
e) 利用tkprof来生成分析报告。
 
利用tkprof工具分析Trace文件
 
可以利用tkprof工具分析Trace文件，产生一个更加清晰合理的输出结果。tkprof可以在$ORACLE_HOME/bin下面找到。
 
1)命令格式
 
命令格式为：
 
tkprof tracefile outputfile [explain= ] [table= ] [print= ]
 
[insert= ] [sys= ] [sort= ]
 
参数说明：
 
tracefile：要分析的trace文件
 
outputfile：格式化后的文件
 
explain=user/password@connectstring
 
table=schema.tablename
 
上述两个参数是一起使用的，explain指示tkprof要为在跟踪文件中找到的每个SQL语句提供一个执行计划。
 
这是通过执行SQL语句EXPLAIN
 
PLAN通过连接数据库对在trace文件中出现的每条sql语句查看执行计划，并将之输出到outputfile中。
 
指定的table名将提供给EXPLAIN PLAN语句。
 
print=n：只列出最初N个sql执行语句，默认是无限制的，只有在和参数sort一起使用的时候才有意义
 
insert=filename：会产生一个sql文件，运行此文件可将收集到的数据insert到数据库表中
 
sys=no：sys用户运行的SQL语句(例如，解析操作阶段对数据字典的递归查询)不输出到输出文件中。
 
record=filename：可将非嵌套执行的sql语句过滤到指定的文件中去
 
waits=yes|no：是否统计任何等待事件，默认是yes
 
aggregate=yes|no：是否将相同sql语句的执行信息合计起来，默认为yes
 
sort=
 
option：设置排序选项，可以用逗号分隔多个选项。默认是跟踪文件中发现的SQL顺序。具体选项可以查看tkprof的命令帮助输出得到。
 
例如：
 
tkprof sys=no sort=prsela,exeela,fchela
 
prsela elapsed time parsing
 
exeela elapsed time executing
 
fchela elapsed time fetching
 
2)输出结果格式输出结果中，首先是头部内容。
 
之后针对每个SQL语句提供如下信息：SQL 语句文本、执行统计、关于解析的信息、执行计划以及等待事件。
 
执行计划以及等待事件是可选的，只有存储在跟踪文件中才会出现。
 
例如下面的输出：
 
********************************************************************************
 
SQL ID: 0c07h414zr55p
 
Plan Hash: 1968341081
 
update emp set sal=2451
 
where
 
empno=7782
 
call count cpu elapsed disk query current rows
 
------- ------ -------- ---------- ----------
 
---------- ---------- ----------
 
Parse 2 0.01 0.00 0 0 0 0
 
Execute 2 0.00 3.71 0 3 7 2
 
Fetch 0 0.00 0.00 0 0 0 0
 
------- ------ -------- ---------- ----------
 
---------- ---------- ----------
 
total 4 0.01 3.72 0 3 7

 
本文介绍一些Android常见的调试技巧
 
一. 获取Trace
 
调用栈信息(Trace)是分析异常经常使用的，这里简单划分两类情况：
 
当前线程Trace: 当前执行流所在线程的调用栈信息；
 
目标进程Trace：可获取目标进程的调用栈，用于动态调试；
 
1.1 当前线程Trace
 
1) Java层
 
Thread.currentThread().dumpStack(); //方法1
 
Log.d(TAG,"Gityuan", new RuntimeException("Gityuan")); //方法2
 
new RuntimeException("Gityuan").printStackTrace(); //方法3
 
2) Native层
 
#include 
 
android::CallStack stack(("Gityuan"));
 
1.2 目标进程Trace
 
1) Java层
 
adb shell kill -3 [pid] //方法1
 
Process.sendSignal(pid, Process.SIGNAL_QUIT) //方法2
 
生成trace文件保存在文件data/anr/traces.txt
 
2) Native层
 
adb shell debuggerd -b [tid] //方法1
 
Debug.dumpNativeBacktraceToFile(pid, tracesPath) //方法2
 
前两条命令输出内容相同:
 
命令1输出到控制台
 
命令2输出到目标文件
 
对于debuggerd命令，若不带参数则输出tombstones文件，保存到目录/data/tombstones
 
3) Kernel层
 
adb shell cat /proc/[tid]/stack //方法1
 
WatchDog.dumpKernelStackTraces() //方法2
 
其中dumpKernelStackTraces()只能用于打印当前进程的kernel线程
 
1.3 小节
 
以下分别列举输出Java, Native, Kernel的调用栈方式：
 
类别
 
函数式
 
命令式
 
Java
 
Process.sendSignal(pid, Process.SIGNAL_QUIT)
 
kill -3 [pid]
 
Native
 
Debug.dumpNativeBacktraceToFile(pid, tracesPath)
 
debuggerd -b [pid]
 
Kernel
 
WD.dumpKernelStackTraces()
 
cat /proc/[tid]/stack
 
分析异常时往往需要关注的重要目录：
 
/data/anr/traces.txt
 
/data/tombstones/tombstone_X
 
/data/system/dropbox/
 
二. 时间调试
 
为了定位耗时过程，有时需要在关注点添加相应的systrace，而systrace可跟踪系统cpu,io以及各个子系统运行状态等信息，对于kernel是利用Linux的ftrace功能。当然也可以直接在方法前后加时间戳，输出log的方式来分析。
 
2.1 新增systrace
 
1) App
 
import android.os.Trace;
 
void foo() {
 
Trace.beginSection("app:foo");
 
...
 
Trace.endSection();
 
}
 
2) Java Framework
 
import android.os.Trace;
 
void foo() {
 
Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "fw:foo");
 
...
 
Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
 
}
 
3) Native Framework
 
#define ATRACE_TAG ATRACE_TAG_GITYUAN
 
#include // used for C++
 
#include // used for C
 
void foo() {
 
ATRACE_CALL();
 
...
 
}
 
或者
 
#define ATRACE_TAG ATRACE_TAG_GITYUAN
 
#include // used for C++
 
#include // used for C
 
void foo() {
 
ATRACE_BEGIN();
 
...
 
ATRACE_END();
 
}
 
2.2 打印时间戳
 
1) Java
 
import android.util.Log;
 
void foo(){
 
long startTime = System.currentTimeMillis();
 
...
 
long spendTime = System.currentTimeMillis() - startTime;
 
Log.i(TAG,"took " + spendTime + “ ms.”);
 
}
 
2) C/C++
 
#include 
 
#include 
 
void foo() {
 
struct timeval time;
 
gettimeofday(&time, NULL); //精度us
 
printf("took %lld ms.\n", time.tv_sec * 1000 + time.tv_usec /1000);
 
}
 
2.3 kernel log
 
有时候Kernel log的输出是由级别限制，可通过如下命令查看：
 
adb shell cat /proc/sys/kernel/printk
 
4 4 1 7
 
参数解读：
 
控制台日志级别：优先级高于该值的消息将被打印至控制台。
 
缺省的消息日志级别：将用该值来打印没有优先级的消息。
 
最低的控制台日志级别：控制台日志级别可能被设置的最小值。
 
缺省的控制台日志级别：控制台日志级别的缺省值
 
日志级别：
 
级别
 
值
 
说明
 
KERN_EMERG
 
0
 
致命错误
 
KERN_ALERT
 
1
 
报告消息
 
KERN_CRIT
 
2
 
严重异常
 
KERN_ERR
 
3
 
出错
 
KERN_WARNING
 
4
 
警告
 
KERN_NOTICE
 
5
 
通知
 
KERN_INFO
 
6
 
常规
 
KERN_DEBUG
 
7
 
调试
 
Log相关命令
 
dmesg 或 cat /proc/kmsg
 
logcat -L 或 cat /proc/last_kmsg
 
logcat -b events -b system
 
三. addr2line
 
addr2line功能是将函数地址解析为函数名。分析过Native Crash，那么对addr2line一定不会陌生。 addr2line命令参数：
 
Usage: addr2line [option(s)] [addr(s)]
 
The options are:
 
@ Read options from 
 
-a --addresses Show addresses
 
-b --target= Set the binary file format
 
-e --exe= Set the input file name (default is a.out)
 
-i --inlines Unwind inlined functions
 
-j --section= Read section-relative offsets instead of addresses
 
-p --pretty-print Make the output easier to read for humans
 
-s --basenames Strip directory names
 
-f --functions Show function names
 
-C --demangle[=style] Demangle function names
 
-h --help Display this information
 
-v --version Display the program's version
 
3.1 Native地址转换
 
Step 1: 获取symbols表
 
先获取对应版本的symbols，即可找到对应的so库。(最好是对应版本addr2line，可确保完全匹配)
 
Step 2: 执行addr2line命令
 
// 64位
 
cd prebuilts/gcc/linux-x86/aarch64/aarch64-linux-android-4.9/bin
 
./aarch64-linux-android-addr2line -f -C -e libxxx.so 
 
//32位
 
cd /prebuilts/gcc/linux-x86/arm/arm-linux-androideabi-4.9/bin
 
./arm-linux-androideabi-addr2line -f -C -e libxxx.so 
 
另外，有兴趣可以研究下development/scripts/stack，地址批量转换工具。
 
3.2 kernel地址转换
 
addr2line也适用于调试分析Linux Kernel的问题。例如，查询如下命令所对应的代码行号
 
[<0000000000000000>] binder_thread_read+0x2a0/0x324
 
Step 1: 获取符号地址
 
通过命令arm-eabi-nm从vmlinux找到目标方法的符号地址，其中nm和vmlinux所在目录：
 
arm-eabi-nm位于目录prebuilts/gcc/linux-x86/arm/arm-eabi-4.8/bin/
 
vmlinux位于目录out/target/product/xxx/obj/KERNEL_OBJ/
 
执行如下命令：(需要带上绝对目录)
 
arm-eabi-nm vmlinux |grep binder_thread_read
 
则输出结果： c02b2f28 T binder_thread_read，可知binder_thread_read的符号地址为c02b2f28， 其偏移量为0x2a0，则计算后的目标符号地址= c02b2f28 + 2a0，然后再采用addr2line转换得到方法所对应的行数
 
Step 2: 执行addr2line命令
 
./aarch64-linux-android-addr2line -f -C -e vmlinux [目标地址]
 
注意:对于kernel调用栈翻译过程都是通过vmlinux来获取的

 
Oracle中的Trace文件
 
如果一个系统的执行效率比较低，一个比较好的方法是通过跟踪用户的会话并且使用tkprof工具使用排序功能格式化输出，从而找出有问题的SQL语句。
 
例如首先从os上利用top命令找到当前占用cpu资源最高的一个进程的PID号9999；
 
然后在数据库中根据PID号找到相应的sid和serial#
 
select s.sid,s.serial# from v$session s,v$process p where s.paddr=p.addr and p.spid='9999';
 
然后通过exec dbms_monitor.session_trace_enable(sid,serial#)开启trace；
 
最后利用tkprof察看trace输出。
 
开启Trace文件输出
 
可以通过以下方法开启Trace文件输出(需要ALTER SESSION系统权限):
 
1) alter session/system set sql_trace=true
 
2) exec dbms_monitor.session_trace_enable/dbms_monitor.database_trace_enable
 
3) alter session set events '10046 trace name context forever, level 12'
 
Trace文件的位置
 
· 如果使用专用服务器连接，会在USER_DUMP_DEST参数指定的目录中生成跟踪文件。
 
· 如果使用共享服务器连接，则在BACKGROUND_DUMP_DEST参数指定的目录中生成跟踪文件。
 
Oracle11g之前，可以通过如下语句获得Trace文件路径：
 
select c.value || '/' || d.instance_name || '_ora_' || a.spid || '.trc' trace
 
from v$process a, v$session b, v$parameter c, v$instance d
 
where a.addr = b.paddr
 
and b.audsid = userenv('sessionid')
 
and c.name = 'user_dump_dest'；
 
Oracle11g之后，可以访问v$diag_info来获得Trace文件存放路径：
 
select * from v$diag_info where name='Default Trace File';
 
可以使用参数TRACEFILE_IDENTIFIER，为跟踪文件名增加一个可以惟一标识的串。例如：
 
alter session set tracefile_identifier='my_trace_file';
 
这样，生成的Trace文件名就会以my_trace_file.trc结尾。
 
利用tkprof工具分析Trace文件
 
可以利用tkprof工具分析Trace文件，产生一个更加清晰合理的输出结果。tkprof可以在$ORACLE_HOME/bin下面找到。
 
1)命令格式
 
命令格式为：
 
tkprof tracefile outputfile [explain= ] [table= ] [print= ] [insert= ] [sys= ] [sort= ]
 
参数说明：
 
tracefile：要分析的trace文件
 
outputfile：格式化后的文件
 
explain=user/password@connectstring
 
table=schema.tablename
 
上述两个参数是一起使用的，explain指示tkprof要为在跟踪文件中找到的每个SQL语句提供一个执行计划。
 
这是通过执行SQL语句EXPLAIN PLAN通过连接数据库对在trace文件中出现的每条sql语句查看执行计划，并将之输出到outputfile中。
 
指定的table名将提供给EXPLAIN PLAN语句。
 
print=n：只列出最初N个sql执行语句，默认是无限制的，只有在和参数sort一起使用的时候才有意义
 
insert=filename：会产生一个sql文件，运行此文件可将收集到的数据insert到数据库表中
 
sys=no：sys用户运行的SQL语句(例如，解析操作阶段对数据字典的递归查询)不输出到输出文件中。
 
record=filename：可将非嵌套执行的sql语句过滤到指定的文件中去
 
waits=yes|no：是否统计任何等待事件，默认是yes
 
aggregate=yes|no：是否将相同sql语句的执行信息合计起来，默认为yes
 
sort= option：设置排序选项，可以用逗号分隔多个选项。默认是跟踪文件中发现的SQL顺序。具体选项可以查看tkprof的命令帮助输出得到。
 
例如：
 
tkprof sys=no sort=prsela,exeela,fchela
 
prsela  elapsed time parsing
 
exeela  elapsed time executing
 
fchela  elapsed time fetching
 
2)输出结果格式
 
输出结果中，首先是头部内容。
 
之后针对每个SQL语句提供如下信息：SQL 语句文本、执行统计、关于解析的信息、执行计划以及等待事件。
 
执行计划以及等待事件是可选的，只有存储在跟踪文件中才会出现。
 
例如下面的输出：
 
********************************************************************************
 
SQL ID: 0c07h414zr55p
 
Plan Hash: 1968341081
 
update emp set sal=2451
 
where
 
empno=7782
 
call     count       cpu    elapsed       disk      query    current        rows
 
------- ------  -------- ---------- ---------- ---------- ----------  ----------
 
Parse        2      0.01       0.00          0          0          0           0
 
Execute      2      0.00       3.71          0          3          7           2
 
Fetch        0      0.00       0.00          0          0          0           0
 
------- ------  -------- ---------- ---------- ---------- ----------  ----------
 
total        4      0.01       3.72          0          3          7           2
 
Misses in library cache during parse: 1
 
Optimizer mode: ALL_ROWS
 
Parsing user id: 86  (TONY)
 
Rows     Row Source Operation
 
-------  ---------------------------------------------------
 
0  UPDATE  EMP (cr=1 pr=0 pw=0 time=0 us)
 
1   INDEX UNIQUE SCAN EMP_PK (cr=1 pr=0 pw=0 time=0 us cost=0 size=26 card=1)(object id 73464)
 
Rows     Execution Plan
 
-------  ---------------------------------------------------
 
0  UPDATE STATEMENT   MODE: ALL_ROWS
 
0   UPDATE OF 'EMP'
 
1    INDEX   MODE: ANALYZED (UNIQUE SCAN) OF 'EMP_PK' (INDEX
 
(UNIQUE))
 
********************************************************************************
 
执行统计有如下的几列：
 
count：表示执行的数据库调用数量。
 
cpu：表示处理数据调用花去的CPU时间，以秒为单位。
 
elapsed：是处理数据库调用花费的总的时间，以秒为单位，如果这个值比CPU时间高，下一节关于执行统计中的等待事件会提供在等待的资源或同步点。
 
disk：表示物理读的数据块数量。要当心，这不是物理I/O操作的数量，物理I/O操作数在关于等待事件一节给出。如果这个值大于逻辑读的数量(disk > query +current)，这意味着数据块填充进了临时表空间。
 
query：是在一致性模式(consistent mode)下从高速缓存逻辑读取的块数量。通常，这类型的逻辑读用作查询。
 
current：代表在当前模式下从高速缓存逻辑读取的块数量。通常，这类逻辑读被INSERT、DELETE、MERGE以及UPDATE等语句所使用。
 
rows：代表处理的数据行数量。对于查询来说，这就是获取的行数量。对于INSERT、DELETE、MERGE以及UPDATE 等语句来说，这是所影响的行数量。
 
关于解析的信息开始两行Misses in library cache during parse和Misses in library cache during execute提供了发生在解析和执行调用阶段的硬解析数量。
 
如果在执行调用时没有硬解析发生，Misses in library cache during execute这一行将不存在。
 
接下来是优化器模式以及用于解析SQL语句的用户。
 
执行计划分为两部分，第一部分称为行源操作(Row Source Operation )，是游标关闭且开启跟踪情况下写到跟踪文件中的执行计划。这意味着如果应用程序不关闭游标而重用它们的话，不会有新的针对重用游标的执行计划写入到跟踪文件中。第二部分，叫做执行计划 (Execution Plan)，是由指定了explain参数的TKPROF生成的。既然这是随后生成的，所以和第一部分不一定完全匹配。万一你看到不一致，前者是正确的。
 
两个执行计划都通过Rows列提供执行计划中每个操作返回的行数(不是处理的--要注意)。
 
对于每个行源操作来说，可能还会提供如下的运行时统计：
 
cr是一致性模式下逻辑读出的数据块数。
 
pr是从磁盘物理读出的数据块数。
 
pw是物理写入磁盘的数据块数。
 
time是以微秒表示的总的消逝时间。要注意根据统计得到的值不总是精确的。实际上，为了减少开销，可能用了采样。
 
cost是操作的评估开销。这个值只有在Oracle 11g才提供。
 
size是操作返回的预估数据量(字节数)。这个值只有在Oracle 11g才提供。
 
card是操作返回的预估行数。这个值只有在Oracle 11g才提供。
 
输出文件的结尾给出了所有关于跟踪文件的信息。首先可以看到跟踪文件名称、版本号、用于这个分析所使用的参数sort的值。然后，给出了所有会话数量与SQL语句数量。
 
参考至：http://blog.csdn.net/fw0124/article/details/6899162
 
来自 “ ITPUB博客 ” ，链接：http://blog.itpub.net/15489979/viewspace-746207/，如需转载，请注明出处，否则将追究法律责任。