使用自定义日志记录处理程序在JBoss AS 7中跟踪SQL语句

使用ORM从您的特定数据库中提取数据，并让它创建和发布您必须亲自编写的所有SQL语句似乎很方便。这就是使ORM解决方案受欢迎的原因。

但是它也有一个缺点：由于ORM为您做了很多工作，因此您在某种程度上失去了对生成的SQL的控制，您不得不依靠ORM为您创建高性能的语句。但是有可能发生的是，ORM生成的SQL可能不是您手工编写的，并期望ORM为您完成。在这种情况下，您必须恢复对SQL的控制，然后再次使用代码。

在大型应用程序中，此任务并非那么琐碎，因为可能有数百条语句发布到数据库，这些语句源于数百行Java代码，这些代码大量使用了JPA功能。跟踪数据库分析工具已确定为有问题的SQL语句，直到实际的代码行变得乏味。

我们知道我们可以在persistence.xml中使用以下两行来为Hibernate启用SQL语句日志记录：

<property name="hibernate.show_sql" value="true"/>
<property name="hibernate.format_sql" value="true"/>

但是，这只会输出已经生成的SQL。实际的Java代码行仍然不可见。对于较小的应用程序，将调试器附加到应用程序服务器并通过代码进行调试，直到找到记录有问题的SQL语句的行，这可能是可行的，但是对于较大的应用程序，这很费时间。

由于Hibernate本身不提供任何拦截日志记录的方法，并提供了更多信息来增强日志记录，因此我们将不得不自行完成此操作。 JBoss 文档指出可以编写自己的自定义日志记录处理程序。由于此日志记录处理程序接收到所有日志记录消息，并且消息还包含启用了SQL日志记录的Hibernate生成的消息，因此我们可以尝试找到我们要查找的行，然后将堆栈跟踪输出到我们自己的日志文件中。

编写自定义日志记录处理程序非常简单。您所要做的就是设置一个小项目，该类带有一个类，该类扩展了JDK包java.util.logging中的Handler类：

package mypackage;import java.util.logging.Handler;
import java.util.logging.LogRecord;public class MyJBossLogger extends Handler {@Overridepublic void publish(LogRecord record) {}@Overridepublic void flush() {}@Overridepublic void close() throws SecurityException {}
}

publish（）方法以LogRecord实例的形式接收所有日志记录输出。它的方法getMessage（）使我们可以直接访问输出。因此，我们可以将此消息与从某些配置文件中加载的某些关键字进行匹配：

@Override
public void publish(LogRecord record) {String message = record.getMessage();buffer.add(message + "\n");if (keywords == null) {keywords = loadKeywords();}if (matches(message, keywords)) {String stacktrace = "\nStacktrace:\n";StackTraceElement[] stackTrace = Thread.currentThread().getStackTrace();for (StackTraceElement element : stackTrace) {stacktrace += element.toString() + "\n";}buffer.add(stacktrace);flush();}
}

这里的Buffer是一些简单的数据结构（例如guava的EvictingQueue ），用于缓冲最后几行，因为对输出的每一行（！）都会调用publish（）方法。由于一条完整的SQL语句跨越多行，因此我们必须记住其中的几条。在缓冲行和当前行旁边，我们还输出当前堆栈跟踪的字符串表示形式。稍后，这将在日志文件中告诉我们调用该文件的位置以及项目中哪一行Java代码导致当前语句。

编译完项目后，我们可以将生成的jar文件复制到新创建的文件夹结构下：$ JBOSS_HOME / modules / system / layers / base / com / mydomain / mymodule / main（对于JBoss AS 7.2）。为了向JBoss AS告知我们的新模块，我们必须创建一个名为module.xml的XML文件，其内容如下：

<?xml version="1.0" encoding="UTF-8"?>
<module xmlns="urn:jboss:module:1.1" name="com.mydomain.mymodule"><resources><resource-root path="MyJBossLogger-0.0.1-SNAPSHOT.jar"/></resources>
</module>

模块的名称与JBoss modules文件夹中的路径相对应。它还将在配置文件中用于配置我们的自定义日志记录处理程序：

...
<subsystem xmlns="urn:jboss:domain:logging:1.2"><custom-handler name="CUSTOM" module="com.mydomain.mymodule" class="com.mydomain.mymodule.MyJBossLogger"><level name="DEBUG"/></custom-handler>...

当我们实现日志记录处理程序的flush（）方法以将输出写入某些日志文件时，我们将看到类似以下内容（当然是压缩形式）：

Hibernate:     select ... from customer ...
Stacktrace:
java.lang.Thread.getStackTrace(Thread.java:1568)
com.mydomain.mymodule.MyJBossLogger.publish(MyJBossLogger.java:20)
org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:292)
org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:300)
org.jboss.logmanager.Logger.logRaw(Logger.java:721)
org.jboss.logmanager.Logger.log(Logger.java:506)
...
com.mydomain.myapp.ArticleEntity.getCustomers(ArticleRepository.java:234)
...

在这里，我们可以清楚地看到哪个OneToMany关系导致了我们正在寻找的有问题的选择语句。