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

/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 的主页是 ，它支持当前流行的应用服务器，如 JBoss、Orion、Tomcat、WebLogic、WebSphere 等，在 /documentation/install.htm#install 介绍了 p6spy 的安装。其实不用太在意 p6spy 的安装说明，关键是要了解了某个应用服务器本身，要搞清楚的一个问题是“谁在加载 p6spy 包，从哪里加载”，那么配置 p6spy 就不成问题了，你甚至可以把 p6spy 用在独立的 Java 应用程序中。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 和 perties准备好数据库的驱动包，比如 Oracle 的 classes12.jar，和 C3P0 实现包，如 c3p0-.jar。2. 拷贝文件在 Tomcat 5 下： 拷贝 p6spy.jar、classes12.jar、c3p0-.jar 到 $TOMCAT_HOME/common/lib 目录下 拷贝 perties 到 $TOMCAT_HOME/common/classes 目录下在 Tomcat 6 下： 把 p6spy.jar、classes12.jar、c3p0-.jar 和 perties 都拷到 $TOMCAT_HOME/lib 目录下。-注：这里我们让 Tomcat 的 Common 类加载器来加载相关类，Common 加载的类对应 WebApp 是可见的。有关 Tomcat 类加载器层次可参考 Tomcat5 类装载器分析和 Tomcat6 类装载器分析。Tomcat5 的 Common 类加载器从 $TOMCAT_HOME/common/lib 目录下加载 jar/zip 文件，从 $TOMCAT_HOME/common/classes 下加载类文件。而 perties 是通过 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 下的 perties 文件，此文件中本身有很详细的注释，很容易理解其中的配置。我们在这里修改几个主要的地方，让它能工作起来。1) 找到 # realdriver=oracle.jdbc.driver.OracleDriver 把前面的 # 注释符去掉，因为我们用的是 Oracle 数据库，即改为realdriver=oracle.jdbc.driver.OracleDriver同时把 realdriver=org.gjt.mm.mysql.Driver 用 # 注释掉，即改为# realdriver=org.gjt.mm.mysql.Driver2) 打开输出过滤，因为我们希望对有些表(如用户表) 的查询不输出相应的 SQL，找到 filter=false，把它改为 filter=true。 再看它后面有几个配置 include =、 exclude = 和 sqlexpression = 用来设置过虑规则。例如我们不想输出对 users、constants 表操作的 SQL，就配置exclude = users,constants3) 输出目的地的选择，在 perties 中可以找到#specifies the appender to use for logging#appender=com.p6spy.engine.logging.appender.Log4jLogger#appender=com.p6spy.engine.logging.appender.StdoutLoggerappender=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 文件，文件内容如下：factoryorg.apache.naming.factory.BeanFactoryjdbcUrljdbc:oracle:thin::1521:proddriverClasscom.p6spy.engine.spy.P6SpyDriveruserunmipassword123456-注：这一步不是必须的，主要通常我们都会使用连接池来访问数据库，其实只要在应用里使用 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 ASC03-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=2503-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也一样)格式的说明 - /documentation/other.htm#log。日志格式是：current time|execution time|category|statement SQL string|effective SQL stringcurrent 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 的显示过滤功能，可在 perties 中配置。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 文件。然后修改 perties 文件，找到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 语句输出到文件或是控制台中看起来有些吃力。若能图形界面展示出来便可一目了然，亲切许多。有种方法是配置 perties 使用 Log4j 的 SocketAppender，然后启动 Log4j 的 .SocketServer 界面，或是在 Eclipse log4j plug-in 中也能观察所执行的 SQL 语句。不过还有种更专业做法，本篇将介绍 p6spy 如何结合 Sql Profiler 或 IronTrack SQL 来使用，并附以贴图，来感受一下吧。也以此来完成关于 p6spy 的这个系列。其实你到后面也会发现，即便是用 Sql Pofier 的实现过程也是借助了 Log4j 的 SocketApender，你可以从它自己带的 perties 文件中的配置看出来，即其中的 log4j.appender.SQLPROFILER_CLIENT=.SocketAppender 这么一个配置。结合 Sql Profiler 的文章网上较多，这里参考了文后链接中的几篇文章写就而成。下面分别以结合 Sql Profiler 和 IronTack SQL 说明。关于 p6spy 的使用配置可参考：用 p6spy 来观察 Java 程序中执行的所有 SQL 语句(二. Tomcat 下的配置）。你也可以配置在应用中，即把相关 jar 包放在应用的 WEB-INF/lib 下，perties 放在应用的 WEB-INF/classes 中。所以下面有关于 p6spy 的配置就不再重复了。p6spy + Sql Profiler 观察 SQL 语句Sql Profiler 的下载地址：/project/showfiles.php?group_id=80782，当前版本是 0.3，下载的文件是 sqlprofiler-0.3-bin.zip。1. 把压缩包中的 sqlprofiler.jar 拷到 p6spy.jar 所在的目录中，比如 Tomcat 5.x 的 common/lib 目录中2. 你也应该看到了压缩包中还有个 perties 文件，我们就在这个文件基础上少作改动，把它放在加载 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. 修改 perties 文件，启用你所用的 realdriver，如对于 oracle 是 realdrive=oraclejdbc.driver.OacleDriver。4. 命令行下进到 sqlprofiler.jar 所在的目录，执行 java -jar sqlprofiler.jar，出现界面，监听 p6spy 的 SQL 语句输出5. 启动应用，进行业务操作，就能在Sql Profile 界面上直观的看到你需要的东西了。界面上有三个标签，分别看截图：图片看不清楚？请点击这里查看原图（大图）。Profiler 标签页图片看不清楚？请点击这里查看原图（大图）。Logger 标签页图片看不清楚？请点击这里查看原图（大图）。Analysis 标签页图片看不清楚？请点击这里查看原图（大图）。生成建议创建索引的脚本再看看保存成的建议创建索引的 SQL 脚本：CREATEINDEXom_customer_user_indexONom_customer_user(user_id); CREATEINDEXom_order_headers_indexONom_order_headers(creation_date,org_id); CREATEINDEXom_order_type_indexONom_order_type(type_name); CREATEINDEXsys_lookups_indexONsys_lookups(lookup_type,lookup_code); CREATEINDEXsys_lookups_index2ONsys_lookups(lookup_type); CREATEINDEXsys_menu_indexONsys_menu(application_id); CREATEINDEXsys_messages_lines_items_indexONsys_messages_lines_items(reader_id,status,flag,reader_type,segmen3,item_id); CREATEINDEXsys_org_v_indexONsys_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 就略有不同了，看它带的 perties 文件，里面有 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：/uploads/files/IronTrackSQL.zip，网上很多文章说从 /ironeyesql 下载，而实际上这个域名不存在了。若是第一个地址无法下载，请留言我放哪里供大家下载。好再看使用步骤，解开 IronTrackSQL.zip，可以看到在第一级目录中有必须的 p6spy.ar、log4j-1