064、SQL跟踪与性能分析（ST05）

上个月客户一个电话把我从午睡里拽了出来。说某个Z报表跑了一个小时还没出数IT部门的人已经急得嘴上起泡。我打开那台测试机用SE80把主流程翻了一遍代码逻辑不算绕循环里的SELECT也带了索引怎么看都觉得不能这么慢。数据量表才二十几万行。那问题出在哪我只好祭出ST05。ST05是ABAP里最常用的SQL跟踪工具事务代码就叫ST05。它的作用说白了就是把你指定的用户、指定的时间段内所有发送到数据库的SQL语句原封不动地记录下来。有人说“原封不动”不完全准确至少能让你看到数据库真正执行的语句而不是你在ABAP里写的那句OPEN SQL。这很重要因为遇到隐式转换、缓冲失效、或者优化器抽风的时候你根本不知道数据库那边做了什么妖。先不说原理直接讲怎么用。在命令框里输入ST05进去后界面很简洁有几个复选框什么“SQL跟踪”“锁跟踪”“RFC跟踪”之类的。咱们日常用得最多的就是SQL跟踪其他先别勾勾多了日志文件会爆炸光清理就能浪费你半天时间。然后指定跟踪对象默认情况下是当前用户也可以输入其他用户的用户名。我一般直接保持当前用户因为我要去运行那个报表用同一个会话最方便。接着点那个“开启跟踪”的按钮像录音机一样从这一刻起数据库语句就开始被记录进去了。开了跟踪之后马上打开你要分析的ABAP程序跑一小段。这里有个很重要的经验别傻乎乎地等整个报表跑完再关那样会用巨大的跟踪文件把系统拖死。我通常是执行程序后等上十秒二十秒看看到达某个关键节点或者直接预选一小部分数据就停然后立刻回到ST05点“关闭跟踪”。你要是忘了关跟踪会一直开着系统会越来越慢最后所有用户的查询都排着队等你那场面真的不太优雅。关掉跟踪之后点上面的“列表”按钮或者“分析”也行就能看到刚才记录的一堆数据库操作。界面分两大部分左边是表名右边是操作类型和统计信息。表名下面能看到SELECT、INSERT、UPDATE、DELETE各自有多少次总共花了多少时间。别一上来就看最上面的先按“耗时”排序。通常问题最严重的那条SQL就在第一屏。我那个客户的问题就是这么暴露的。跟踪结果里有一条SELECT SINGLE出现了1600多次单次平均时间0.03秒累加起来就有48分钟。语句是DATA: lv_code TYPE char10. lv_code lv_str. SELECT SINGLE * FROM zhead WHERE zcode lv_code AND zflag X.我盯着这句愣了三秒。zcode字段上明明有索引zflag也是索引列的第二部分理论上走索引只要几毫秒。为什么数据库傻乎乎地全表扫我顺手在ST05里选中那条语句点了一下“执行计划”结果看到索引被忽略了扫描方式变成了“FULL TABLE SCAN”。原因很快被揪了出来我那个LV_CODE变量定义了CHAR10而数据库表字段ZCODE是NUMC10。ABAP的Open SQL在语法检查时不会报错运行时SQL被转换后数据库层面为了比较不同类型可能会隐式地对字段做转换。这个转换一动索引就废了。解决方案也简单直接让变量类型跟着表字段走DATA: lv_code TYPE zhead-zcode. 用这种定义方式类型天然匹配别再自作聪明写CHAR10了 lv_code lv_str. SELECT SINGLE * FROM zhead WHERE zcode lv_code AND zflag X.改完之后这条语句从单次0.03秒降到0.0001秒整个报表跑完不到两分钟。客户觉得我很神其实都是ST05的功劳。再举一个我看到过的经典场景。某同事写了一个程序为了追求效率用FOR ALL ENTRIES把一个内表作为查询条件去数据库捞数据思路没问题但他在查询完之后又在一个内表循环里写了一句SELECT。ST05一开发现数据库被访问了上万次。每一个循环里的SELECT看着都走索引但架不住一万次啊。更隐蔽的是FOR ALL ENTRIES本身会扩展成一条很长的SQL如果内表数据特别多生成的SQL语句可能会超长数据库解析都会卡。ST05的列表里能看到SQL语句的文本长度好几个字段我就见过几KB甚至几十KB的。遇到这种情况我的习惯是用JOIN替代一部分FOR ALL ENTRIES或者把大内表拆成几个小批次处理别一口气塞进去。ST05还能帮你看ABAP缓冲是否生效。如果某个表开启了ABAP缓冲那么同一会话内重复读取的数据可能直接从应用服务器缓存里拿数据库那边根本不会被访问。在ST05的跟踪结果里每个操作会有“直达数据库”还是“缓冲读取”之类的标记。如果你发现一个应该命中缓冲的配置表每次都在跟数据库打交道那可能缓冲设置没生效或者语句的WHERE条件不符合缓冲特性比如用了非主键字段查询缓冲机制直接绕过。这个坑在经常读取的自定义表上特别常见动不动就拖慢整体响应。有人会问我用SE30看事务码的运行时不也能看到时间吗SE30看到的是程序在应用服务器上的CPU时间以及个部分耗时但SQL层面到底哪条语句垃圾它没有ST05这么细。ST05聚焦于数据库交互能直接看到SQL文本、执行次数、花费的数据库时间以及执行计划。两个工具配合起来用能快速定位到性能问题是出在应用逻辑还是数据库访问。我调性能的基本套路是先用SE30跑一遍找到总耗时最高的那一小段再用ST05单独跟踪这一段精确到SQL。用ST05有个注意点生产系统上千万别随便全用户跟踪。开启跟踪本身会对数据库通信产生额外开销如果库的数据量一大跟踪文件会把磁盘写满严重时直接宕机。我一般只在开发或者质量系统上折腾生产上有问题我宁可在非高峰时段只跟踪自己那个客户端进程。还有一点跟踪结果看完就关别一直开着。另外说说执行计划。ST05里选中一条SQL后有个“执行计划”的按钮点开能看到数据库优化器选择的访问路径走没走索引一目了然。有些版本还可以显示具体使用的索引名。这个功能是分析的关键不要只盯着时间。一条SQL慢了先看执行计划如果显示索引没走就检查WHERE条件的字段类型、函数包裹、OR条件、NULL判断这些常见的索引杀手。如果你改了SQL再重新跑一遍跟踪对比执行计划的变化确保优化起作用了。说到函数包裹程序员有个不好的习惯喜欢在条件里写“TO_UPPER(字段) 变量”或者“SUBSTR(字段, 1, 2) ‘AB’”尤其从其他语言转过来的朋友。这种写法在ABAP里也能跑但一旦对索引字段用了函数数据库就没法走索引。ST05的执行计划会诚实地告诉你结果。如果非要这么查就得考虑添加函数索引之类的方法但不同数据库支持情况不一样。最稳妥的还是把数据整理好让查询条件不带函数。还有一个小技巧ST05的跟踪列表一般都支持按列排序你把鼠标点到“总计时间”那一列的标题上点一下让它按从大到小排序所有高耗时的SQL就自动排到上面了。有些版本可能需要右键选择排序方式反正万变不离其宗。找出耗时TOP5或者TOP10逐个击破优化效率比盲调高十倍不止。我个人习惯是每次优化完把ST05的结果导出成文本文件带上当时的日期和程序名放到项目共享目录里。这样过几个月回来还能知道当初为什么这么改比截图舒服多了文本能搜历史记录。截图虽然直观但没法检索而且里面包含数据库表名和SQL语句发给别人看还得打马赛克。文本导出的时候注意选只导出当前跟踪别把整个系统日志导出来。回到开头的案例当我用ST05揪出那个类型不匹配的问题后同事还一脸不信说这也能影响性能我直接把ST05里执行计划前后两张截图放在一起——好吧不能截图但即使没有图数据库执行计划里那个“FULL TABLE SCAN”是无法辩驳的。所以这篇里面所有说到的界面细节你只要打开ST05实际操作一遍就全明白了。好了这篇关于SQL跟踪与性能分析的内容就到这儿。ST05不是那种花里胡哨的工具界面也谈不上精美但它就像一把手术刀精准地切开数据库访问的皮肤让你看到真正的病灶。下一篇我打算聊聊SE30运行时分析或者如果有人想听ABAP调试器里那些不为人知的用法也可以安排。评论区见吧。