用 p6spy 来观察 Java 程序中执行的所有 SQL 语句

mn6w 贡献于2014-09-07

作者 黄诚  创建于2009-11-22 00:59:00   修改者黄诚  修改于2009-11-22 01:05:00字数12702

文档摘要:p6spy 可以输出日志到文件中、控制台、或者传递给 Log4j,而且还能配搭 SQL Profiler 或 IronTrackSQL 图形化监控 SQL 语句,监测到哪些语句的执行是耗时的,逐个优化。关于与 SQL Profiler 或 IronTrackSQL 的配合使用可参数文件的链接。
关键词:

http://tech.ddvip.com/result.php?key=p6spy 用 p6spy 来观察 Java 程序中执行的所有 SQL 语句(一. 引子)   一个企业应用程序的性能瓶颈可能会在硬件配置、网络方面、程序代码、应用服务器配置、数据库配置、SQL 语句。这里我把本文的关注点 SQL 无意间放在了最后,其实它不并不意味着最后考虑的,而是过程中就要时刻留意的。   SQL 语句的优化总得把所执行语句抓出来瞧瞧,分析分析。如果直接用 JDBC 或者是类 iBatis 的东西来访问数据库,那所执行的 SQL 语句是明确的,而现在的项目大多会用 ORM 组件,例如 Hibernate、JPA、CMP、TopLink 都有自己特定的查询语法,最终当然要转换成 SQL 语句的,所以会生成什么样的 SQL 语句就不甚明了,若人为的看着专有查询语句来相象出 SQL 语句并非易事。虽然 Hibernate 设置 show_sql=true 时也能打印出生成的 SQL(带?号参数),配合详细的日志参数值也可以对上,不过挺麻烦的。   许多数据库本身就有 SQL 语句的跟踪功能。比如 Oracle 中,可以为某个用户开启 SQL 跟踪功能,根据条件把所执行的 SQL 语句记录在服务器的日志。或者可从 v$sql、v$sqltext、v$sqlarea 等视图中去查询所执行的 SQL 语句。   利用数据库的 SQL 功能需用特定于数据库的配置方法,好处就是不拘泥于某种编程语言。对于 Java 程序我们介绍 p6spy 组件,它可以拦截所有执行的 SQL 语句,而不管你使用的是什么 ORM 框架。对于 PrepareStatement 那样带参数(?) 的语句,它会帮你代上相应的参数值。   p6spy 的主页是 http://www.p6spy.com,它支持当前流行的应用服务器,如 JBoss、Orion、Tomcat、WebLogic、WebSphere 等,在 http://www.p6spy.com/documentation/install.htm#install 介绍了 p6spy 的安装。其实不用太在意 p6spy 的安装说明,关键是要了解了某个应用服务器本身,要搞清楚的一个问题是“谁在加载 p6spy 包,从哪里加载”,那么配置 p6spy 就不成问题了,你甚至可以把 p6spy 用在独立的 J ava 应用程序中。   p6spy 可以输出日志到文件中、控制台、或者传递给 Log4j,而且还能配搭 SQL Profiler 或 IronTrackSQL 图形化监控 SQL 语句,监测到哪些语句的执行是耗时的,逐个优化。关于与 SQL Profiler 或 IronTrackSQL 的配合使用可参数文件的链接。   原本写这个心里的布局是,先简介 SQL 跟踪,再引入 p6spy,然后讲讲在 Tomcat 中的配置,最后就是对 p6spy 作少许修改使之更符合自己的输出要求。可是前面一说又说便打不住了,生出了这许多累赘,那不妨顺势把介绍 p6spy 当成一个系列吧,不得已而把此编作为引子。下面分篇介绍 Tomcat 中的 p6spy 的配置,p6spy 的定制,必要时加上与 SQL Profiler 或 IronTrackSQL 的组合使用。 用 p6spy 来观察 Java 程序中执行的所有 SQL 语句(二. Tomcat 下的配置)   本文不打算依照官方的说明来做,我们让 Tomcat 的 Common 类加载器来加载 p6spy.jar 包,包含了 Tomcat 5/6 下的 p6spy 配置,数据库连接池实现用 C3P0,数据库为 Oracle,配置在一个与应用同名的单独的 xml 文件中,Tomcat 中是在应用的 META-INF/context.xml 文件中。步骤如下:   1. 软件准备   下载 Tomcat 5 或者 6 进行安装,不必多说。假设置 Tomcat 的目录为 $TOMCAT_HOME。   下载 p6spy-install.zip,解压缩 p6spy-install.zip,其中有 p6spy.jar 和 spy.properties   准备好数据库的驱动包,比如 Oracle 的 classes12.jar,和 C3P0 实现包,如 c3p0-0.9.0.2.jar。   2. 拷贝文件   在 Tomcat 5 下:    拷贝 p6spy.jar、classes12.jar、c3p0-0.9.0.2.jar 到 $TOMCAT_HOME/common/lib 目录下    拷贝 spy.properties 到 $TOMCAT_HOME/common/classes 目录下   在 Tomcat 6 下:    把 p6spy.jar、classes12.jar、c3p0-0.9.0.2.jar 和 spy.properties 都拷到 $TOMCAT_HOME/lib 目录下。   ----注:这里我们让 Tomcat 的 Common 类加载器来加载相关类,Common 加载的类对应 WebApp 是可见的。有关 Tomcat 类加载器层次可参考 Tomcat5 类装载器分析 和 Tomcat6 类装载器分析。   Tomcat5 的 Common 类加载器从 $TOMCAT_HOME/common/lib 目录下加载 jar/zip 文件,从 $TOMCAT_HOME/common/classes 下加载类文件。而 spy.properties 是通过 classloader 来加载的,所以应放在 classpath 下。而 Tomcat 6 的 Common 类加载器对 jar/zip,和 class 文件都是从 $TOMCAT_HOME/lib 中加载。   细心点还能注意到 Tomcat 5.5.20 是 Tomcat 5 到 Tomcat 6 的过度版本,实则是一个混乱的版本。同时有 $TOMCAT_HOME/lib 和 $TOMCAT_HOME/common 目录,可是又新奇的发现在 Tomcat 5.5.25 中没有 $TOMCAT_HOME/lib 目录了。Tomcat 6 中不再有 $TOMCAT_HOME/common 目录了。   3. 修改 p6spy 配置文件   打开 $TOMCAT_HOME/lib 或者 $TOMCAT_HOME/common/classes 下的 spy.properties 文件,此文件中本身有很详细的注释,很容易理解其中的配置。我们在这里修改几个主要的地方,让它能工作起来。   1) 找到 # realdriver=oracle.jdbc.driver.OracleDriver 把前面的 # 注释符去掉,因为我们用的是 Oracle 数据库,即改为 realdriver=oracle.jdbc.driver.OracleDriver   同时把 realdriver=org.gjt.mm.mysql.Driver 用 # 注释掉,即改为 # realdriver=org.gjt.mm.mysql.Driver   2) 打开输出过滤,因为我们希望对有些表(如用户表) 的查询不输出相应的 SQL,找到 filter=false,把它改为 filter=true。    再看它后面有几个配置 include = 、 exclude =  和 sqlexpression = 用来设置过虑规则。例如我们不想输出对 users、constants 表操作的 SQL,就配置 exclude = users,constants   3) 输出目的地的选择,在 spy.properties 中可以找到 #specifies the appender to use for logging #appender=com.p6spy.engine.logging.appender.Log4jLogger #appender=com.p6spy.engine.logging.appender.StdoutLogger appender=com.p6spy.engine.logging.appender.FileLogger   分别是输出到 Log4j、控制台和文件中,如果是输出到控制台的话,就让 appender=com.p6spy.engine.logging.appender.StdoutLogger 有效,其他两个注释掉。   如果你配置的是默认的 appender=com.p6spy.engine.logging.appender.FileLogger,那么它下面的 logfile = spy.log 就是指定要输出的日志文件,这个文件会生成在 System.getProperty("user.dir") 目录中,即 $TOMCAT_HOME/bin 目录中,你可以让它生成到 $TOMCAT_HOME/logs 目录中,就写成 logfile = ../logs/spy.log   如果是让 SQL 语句输出到日志文件的话,append=true,会较重要,为 true 时为附加,spy.log 会变得很大,否则为每次 Tomcat 重启后生成新的文件。   需留意一下最后的有关使用 Log4j 输出的配置   4. 配置数据库连接池   其实连接池的配置与使用 p6spy 无多大关系,无论你是在 Tomcat 中、还是 Spring、Hibernate 中配置连接池,甚至是直接用 JDBC 连接数据库都无所谓,关键是,要使 p6spy 在其中发生效用,所用的数据库驱动就必须是 com.p6spy.engine.spy.P6SpyDriver。   假定应用的 Context 是 MyWeb,且直接是部署在 $TOMCAT_HOME/webapps 目录下,那么我们配置这个应用的数据源就可以在 $TOMCAT_HOME/conf/Catalina/localhost 建立一个 MyWeb.xml 文件,文件内容如下:                                           factory               org.apache.nam ing.factory.BeanFactory                                     jdbcUrl               jdbc:oracle:thin:@192.168.0.1:1521:prod                                     driverClass               com.p6spy.engine.spy.P6SpyDriver                                     user               unmi                                      password               123456                       ----注:这一步不是必须的,主要通常我们都会使用连接池来访问数据库,其实只要在应用里使用 com.p6spy.engine.spy.P6SpyDriver 驱动,p6spy 就会在中间获取到它要的信息,并输出 SQL 语句。   关于不同版本的 Tomcat 连接池的配置又是个不小的议题。   如果是在 Tomcat 5.5 中,$TOMCAT_HOME/conf/Catalina/localhost/MyWeb.xml 的内容应如下:                         而到了 Tomcat 6 中时,$TOMCAT_HOME/conf/Catalina 目录都不存在了。Tomcat 6 中给应用配置连接池就要在应用的 META-INF 目录(例如 $TOMCAT_HOME/MyWeb/META-INF) 下建立文件 context.xml,内容如下:                 WEB-INF/web.xml                                   5. 测试应用   前面说过,只要是用 com.p6spy.engine.spy.P6SpyDriver 的话,不管你是用连接池还是每次建立 JDBC 连接,p6spy 都能给你输出所执行的 SQL 语句。默认时输出样子如下: 用 p6spy 来观察 Java 程序中执行的所有 SQL 语句(三. 定制输出)   既然提到 p6spy 的输出,那就有必要说明一下 p6spy 输出日志的格式了。从上一篇 用 p6spy 来观察 Java 程序中执行的所有 SQL 语句(二. Tomcat 下的配置) 中把输出的一段内容拿过来,如下: 03-16-09 15:12:06:656|16|4|statement|SELECT * FROM OM_CUSTOMERS  WHERE CUSTOMER_ID=? ORDER BY CUSTOMER_ID ASC|SELECT * FROM OM_CUSTOMERS  WHERE CUSTOMER_ID=2194 ORDER BY CUSTOMER_ID ASC 03-16-09 15:12:06:671|15|3|statement|SELECT * FROM OM_ORDER_TYPE WHERE TYPE_ID=?|SELECT * FROM OM_ORDER_TYPE WHERE TYPE_ID=25 03-16-09 15:12:06:687|16|1|statement|select * from sys_lookups where lookup_type=?  and lookup_code=? |select * from sys_lookups where lookup_type='OM_ORDER_STATUS'  and lookup_code='70' 03-16-09 15:12:06:812|-1||resultset|select * from sys_lookups where lookup_type='OM_ORDER_STATUS'  and lookup_code='70' |meaning = 已安排生产   再看 p6spy 官方文档的关于日志文件(控制台输出/Log4J也一样)格式的说明 -- http://www.p6spy.com/documentation/other.htm#log。日志格式是: current time|execution time|category|statement SQL string|effective SQL string   current time -- 当前时间   execution time -- 执行时长,包括执行 SQL 和处理结果集的时间(可以参考来调优)   category  -- 语句分类,statement、resultset 等   statement SQL string -- 查询语句。可能是 prepared statement,表现为 select * from table1 where c1=?,问号参数形式   effective SQL string -- 代入参数值的查询语句,如 select * from from table1 where c1=7   看到上面的日志输出,我们可能会有如下需求:   1) 对于 category 为 resultset 的输出你可能并不关心,查询了什么字段,取哪个字段或许早心理有数。上面例子中的 resultset 是 select *,然而只取了 meaning 一个字段,这是不推荐的。(不输出 resultset 语句)   2) 你可能不想被那些带问号参数的 prepared statement 干扰,而想直接看最终被执行的语句。(statement SQL string 不显示)   3) 你可能会想把控制台或日志文件中的一连串几个语句直接复制,贴到数据库客户端就能执行。(只输出 effective SQL string,并以分号隔开)   对于第一个要求,我们可以利用 p6spy 的显示过滤功能,可在 p6spy.properties 中配置。p6spy 有 resultset 这样一个 category,却未完善对其的过滤控制,为此我们需要修改源代码 com.p6spy.engine.spy.P6ResultSet.java,找到 152 行的 P6LogQuery.log("resultset", query, buffer.toString());   把其改为 //P6LogQuery.log("resultset", query, buffer.toString());   P6Connection p6connection = (P6Connection)this.statement.getConnection();   P6LogQuery.logElapsed(p6connection.getId(), System.currentTimeMillis(),"resultset", preparedQuery, query);    编译(最好用 1.4 或 1.5 的JDK 来编译,因为 JDK 1.6 的 ResultSet 多了些要实现的方法,修改起来要麻烦很多),把该类替换掉原来 p6spy.jar 中的相应 class。编译好的 FormattedLogger 在附件 changed_p6spy_classes.rar 中有,是 P6ResultSet.class 文件。   然后修改 p6spy.properties 文件,找到 excludecategories=info,debug,result,batch   加上对 resultset 的排除,改为 excludecategories=info,debug,result,batch,resultset   这样,在输出的语句中就没有眼花缭乱的 resultset 语句了,清爽了许多。   对于第二个要求,我们还要修改的是源代码 com.p6spy.engine.logging.appender.FormattedLogger,在 72 行找到 String logEntry = now + "|"+ elapsed + "|"+(connectionId==-1 ? "" : String.valueOf(connectionId))+"|"+category+"|"+prepared+"|"+sql;   我们不希望输出 prepared,所以把它改为 String logEntry = now + "|"+ elapsed + "|"+(connectionId==-1 ? "" : String.valueOf(connectionId))+"|"+category+"|"+sql;   编译,替换掉原 p6spy.jar 中相应类,编译好的 FormattedLogger 是附件 changed_p6spy_classes.rar 中有,是 FormattedLogger.class 文件。   要满足第三个条件,还是修改 com.p6spy.engine.logging.appender.FormattedLogger 的同一行代码,改为 String logEntry = sql + ";";   编译,替换掉原 p6spy.jar 中相应类,编译好的 FormattedLogger 是附件 changed_p6spy_classes.rar 中有,是 FormattedLogger1.class 文件,替换的时候请更名。那么由它指示输出的 SQL 语句就是以分号分隔的一条条了,基本是连续几条一起复制出来,放到 SQL 客户端工具中就能执行了。当然字符串的参数还是要稍加处理的。 用 p6spy 来观察 Java 程序中执行的所有 SQL 语句(四. 结合 Sql Profiler)   p6spy 虽好,但把 SQL 语句输出到文件或是控制台中看起来有些吃力。若能图形界面展示出来便可一目了然,亲切许多。有种方法是配置 p6spy.properties 使用 Log4j 的 SocketAppender,然后启动 Log4j 的 org.apache.log4j.net.SocketServer 界面,或是在 Eclipse log4j plug-in 中也能观察所执行的 SQL 语句。   不过还有种更专业做法,本篇将介绍 p6spy 如何结合 Sql Profiler 或 IronTrack SQL 来使用,并附以贴图,来感受一下吧。也以此来完成关于 p6spy 的这个系列。其实你到后面也会发现,即便是用 Sql Pofier 的实现过程也是借助了 Log4j 的 SocketApender,你可以从它自己带的 p6spy.properties 文件中的配置看出来,即其中的 log4j.appender.SQLPROFILER_CLIENT=org.apache.log4j.net.SocketAppender 这么一个配置。   结合 Sql Profiler 的文章网上较多,这里参考了文后链接中的几篇文章写就而成。下面分别以结合 Sql Profiler 和 IronTack SQL 说明。关于 p6spy 的使用配置可参考:用 p6spy 来观察 Java 程序中执行的所有 SQL 语句(二. Tomcat 下的配置)。你也可以配置在应用中,即把相关 jar 包放在应用的 WEB-INF/lib 下,p6spy.properties 放在应用的 WEB-INF/classes 中。所以下面有关于 p6spy 的配置就不再重复了。   p6spy + Sql Profiler 观察 SQL 语句   Sql Profiler 的下载地址:http://sourceforge.net/project/showfiles.php?group_id=80782,当前版本是 0.3,下载的文件是 sqlprofiler-0.3-bin.zip。   1. 把压缩包中的 sqlprofiler.jar 拷到 p6spy.jar 所在的目录中,比如 Tomcat 5.x 的 common/lib 目录中   2. 你也应该看到了压缩包中还有个 p6spy.properties 文件,我们就在这个文件基础上少作改动,把它放在加载 p6spy.jar 的加载器能见的位置上,如 Tomcat 5.x 的 common/classes 目录中。    注意:如果你在 Tomcat 中,p6spy.jar 和 sqlprofiler.jar 是由 commons 加载器加载的,那么要用到的 log4j-x.x.x.jar 也必须放在与他们同一目录中由 cmmons 类加载器来加载,如果仍然在应用的 WEB-INF/lib目录中的话,log4j 的类对于 p6spy 和 sqlprofiler 来说不可见。如果你对于类加载器不熟的话,还是别把事情搞太复杂了,把那些 jar 文件全部放到应用的 WEB-INF/lib 中吧,但是配置连接池的时候又可能碰到新问题。   3. 修改 p6spy.properties 文件,启用你所用的 realdriver,如对于 oracle 是 realdrive=oraclejdbc.driver.OacleDriver。   4. 命令行下进到 sqlprofiler.jar 所在的目录,执行 java -jar sqlprofiler.jar,出现界面,监听 p6spy 的 SQL 语句输出   5. 启动应用,进行业务操作,就能在Sql Profile 界面上直观的看到你需要的东西了。界面上有三个标签,分别看截图:   图片看不清楚?请点击这里查看原图(大图)。    Profiler 标签页   图片看不清楚?请点击这里查看原图(大图)。   Logger 标签页   图片看不清楚?请点击这里查看原图(大图)。    Analysis 标签页   图片看不清楚?请点击这里查看原图(大图)。    生成建议创建索引的脚本   再看看保存成的建议创建索引的 SQL 脚本: CREATE INDEX om_customer_user_index ON om_customer_user ( user_id );     CREATE INDEX om_order_headers_index ON om_order_headers ( creation_date,org_id );     CREATE INDEX om_order_type_index ON om_order_type ( type_name );     CREATE INDEX sys_lookups_index ON sys_lookups ( lookup_type,lookup_code );     CREATE INDEX sys_lookups_index2 ON sys_lookups ( lookup_type );     CREATE INDEX sys_menu_index ON sys_menu ( application_id );     CREATE INDEX sys_messages_lines_items_index ON sys_messages_lines_items ( reader_id,status,flag,reader_type,segmen3,item_id );     CREATE INDEX sys_org_v_index ON sys_org_v ( org_type_id );     p6spy + IronTrack SQL 观察 SQL 语句   考虑到篇幅和文章主题的鲜明性,还是把这部分内容放到单独日志中,请关注下一篇:用 p6spy 来观察 Java 程序中执行的所有 SQL 语句(五. 结合 IronTrack SQL) 用 p6spy 来观察 Java 程序中执行的所有 SQL 语句(五. 结合 IronTrack SQL)   本想把 p6spy 结合 SQL Profiler 或 IronTrack SQL 的使用介绍掇凑于一块来写。简单点说,只是一贴上图样,篇幅便需拖拉难遂人愿,也好,索性把它们分成两个篇章。一来每篇主旨鲜明,二来五篇成一系列比起四更来的自然且吉利。   前面讲过 p6spy 本身就可利用 Log4j 的 SocketAppender 向远端发送日志,SQL Profiler 不过是在这个基础上作了进一步拓展。而接下来要说的 IronTrack SQL 就略有不同了,看它带的 p6spy.properties 文件,里面有 IronTrack SQL 给 p6spy 定制的一个模块:module.ibeam=com.irongrid.ibeam.server.IBeamFactory。它用到了 log4j-1.2.8.jar,不过还得研究下 Log4j 在其中所起的作来。现在就来介绍 p6spy 结合 IrconTrack SQL 的使用,最好是你知道如何单独使用 p6spy。压缩包里有文档:是 IronTrackSQLdocsindex.html。   p6spy + IronTrack SQL 观察 SQL 语句   下载 IronTrack SQL:http://www.dlog.cn/uploads/files/IronTrackSQL.zip,网上很多文章说从 http://www.irongrid.com/ironeyesql 下载,而实际上这个域名不存在了。若是第一个地址无法下载,请留言我放哪里供大家下载。好再看使用步骤,解开 IronTrackSQL.zip,可以看到在第一级目录中有必须的 p6spy.ar、log4j-1.2.8.jar、irontracksql.jar、spy.properties、irongrid.properies 文件。   1. 把压缩包中的 irontracksql.jar 拷到 p6spy.jar 所在的目录中,比如 Tomcat 5.x 的 common/lib 目录中   2. 压缩包中还有个 p6spy.properties 文件,我们就在这个文件基础上少作改动,把它放在加载 p6spy.jar 的加载器能见的位置上,如 Tomcat 5.x 的 common/classes 目录中。    注意:如果你在 Tomcat 中,p6spy.jar 和 sqlprofiler.jar 是由 commons 加载器加载的,那么要用到的 log4j-1.2.8.jar 也必须放在与他们同一目录中由 cmmons 类加载器来加载,如果仍然在应用的 WEB-INF/lib目录中的话,log4j 的类对于 p6spy 和 sqlprofiler 来说不可见。如果你对于类加载器不熟的话,还是别把事情搞太复杂了,把那些 jar 文件全部放到应用的 WEB-INF/lib 中吧,但是配置连接池的时候又可能碰到新问题。   3. 修改 p6spy.properties 文件,只启用你所用的 realdriver,如对于 oracle 是 realdrive=oraclejdbc.driver.OacleDriver。    看到其中对模块 ibeam 的配置 monitorport=2000,我们就使用这个监听端口吧。   4. 命令行下进到 IronTrackSQL 的解压目录,执行 java -jar irontracksql.jar 来启动IronTrack SQL,监听 p6spy 的 SQL 语句输出   5. 启动应用,进行业务操作,就能在 IronTrack SQL 界面上直观的看到你需要的东西了。   不多说了,看看界面吧,这个 IronTrackSQL 看起来比 SQL Profiler 要专业些。   图片看不清楚?请点击这里查看原图(大图)。   SQL Monitor 界面   <   图片看不清楚?请点击这里查看原图(大图)。   Graphing 图形展示   图片看不清楚?请点击这里查看原图(大图)。   可设定监听端口,导出导入历史数据   irongrid.properties 文件中保存了 Iron TrackSQL 运行时的配置数据。与 SQL Profiler 相比,它有以下几个特点:   1. 界面标志些,使用了 JFreeChart 来展示图表   2. 既能实时监听,又能保存历史数据来对比分析   3. 并不要求先启动 Iron TrackSQL,相比于 SQL Profiler 的被动监听,它采取的是主动去查询。更适于远程监控,想在何时监控就启动,完事就关闭,不至于像 SQL Profiler 那样一旦监听窗口坏了一下,就得重启应用。而且我想它对应用程序的性能影响也较小些的

下载文档到电脑,查找使用更方便

文档的实际排版效果,会与网站的显示效果略有不同!!

需要 8 金币 [ 分享文档获得金币 ] 1 人已下载

下载文档