如何通过正确的日志记录解决一些最常见的 Hibernate 问题?
Hibernate 的日志记录配置是一个重要但很少讨论的话题。正确的配置可以帮助您发现开发过程中的潜在问题,而错误的配置可能会导致生产中出现严重的性能问题。这就是为什么我在我的新书 Hibernate Tips: 70 多个常见 Hibernate 问题的解决方案 中解释不同配置选项的原因之一。
在这篇文章中,我们将分享书中最有用的 2 个 Hibernate 日志记录技巧。让我们开始吧。
让我们来看看书中包含的一个食谱。它可以帮助您在开发过程中找到 n+1 个选择问题。当 Hibernate 必须初始化实体之间延迟获取的关联时,通常会出现此性能问题。不幸的是,这个问题很难在源代码中找到,因为您只是调用映射关联的属性的 getter 方法,例如 author.getBooks()。如果您在遍历 作者列表 实体的循环中执行此操作,Hibernate 必须执行 1 个查询来加载 n 个 作者 实体和 n 个额外的查询来初始化关联。这就是所谓的 n+1 选择问题,它是最常见的性能问题之一。
您可以通过激活 Hibernate 的统计组件找到它,该组件提供了一种简单的方法来计算 Hibernate 会话中所有已执行的查询。让我们看看它是如何完成的。
我的一些用例很慢,而且似乎执行了太多查询。
如何统计在 Hibernate Session 中执行的所有查询?
计算所有已执行查询的最简单方法是激活 Hibernate 的统计组件。然后,Hibernate 会收集大量内部统计信息,并通过 Statistics API 将它们作为日志消息提供。
警告:不要在生产中使用它!收集统计信息会产生开销,从而降低您的应用程序速度。
Hibernate 的统计组件默认是关闭的。您可以通过将 hibernate.generate_statistics 参数设置为 true 来激活它。您可以通过提供具有相同名称的系统属性或通过在 persistence.xml 文件中设置参数来执行此操作。
<persistence> <persistence-unit name="my-persistence-unit"> <description>Hibernate Tips</description> <provider>org.hibernate.jpa.HibernatePersistenceProvider</provider> <properties> <property name="hibernate.generate_statistics" value="true" /> … </properties> </persistence-unit> </persistence>
您有两个选项来访问统计信息。 Hibernate 可以将包含每个会话最重要信息的子集写入日志文件,或者您可以通过 Statistics API 访问它们。
让我们先看一下日志消息。 Hibernate 在每个会话结束时写入一条日志消息,类似于以下消息。它显示了 SQL 语句的数量、准备和执行所花费的时间以及与二级缓存的交互。
16:24:55,318 INFO [org.hibernate.engine.internal.StatisticalLoggingSessionEventListener] – Session Metrics { 25659 nanoseconds spent acquiring 1 JDBC connections; 22394 nanoseconds spent releasing 1 JDBC connections; 1091216 nanoseconds spent preparing 12 JDBC statements; 11118842 nanoseconds spent executing 12 JDBC statements; 0 nanoseconds spent executing 0 JDBC batches; 0 nanoseconds spent performing 0 L2C puts; 0 nanoseconds spent performing 0 L2C hits; 0 nanoseconds spent performing 0 L2C misses; 16999942 nanoseconds spent executing 1 flushes (flushing a total of 17 entities and 17 collections); 63915 nanoseconds spent executing 1 partial-flushes (flushing a total of 0 entities and 0 collections)
您还可以通过 Hibernate 的Statistics 接口访问 Statistics API。您可以从 SessionFactory 获取它。它提供了几个 getter 方法,使您可以访问比日志输出更详细的信息。
Statistics stats = sessionFactory.getStatistics(); long queryCount = stats.getQueryExecutionCount(); long collectionFetchCount = stats.getCollectionFetchCount();
您可以在 本书 中找到包含此 Hibernate 技巧的可执行测试用例的项目的下载链接。
如果你想了解更多关于 Hibernate 的日志功能,你应该看看章节:
=============
对执行的查询进行计数可以帮助发现效率低下的地方并避免性能问题。但这还不够。您还需要知道 Hibernate 执行哪些查询以及它使用哪些参数值。使用正确的日志记录配置,Hibernate 会将所有这些信息写入日志。
=============
如何配置 Hibernate 以便将执行的 SQL 语句和使用的绑定参数写入日志文件?
Hibernate 使用两种不同的日志类别和日志级别来记录执行的 SQL 语句及其绑定参数:
您可以在日志配置中相互独立地激活和停用它们。
警告:记录所有 SQL 查询及其绑定参数绑定会减慢您的应用程序并创建巨大的日志文件。
您不应该在生产环境中激活这些日志消息。
以下代码片段显示了激活它们的 log4j 配置示例。
log4j.appender.stdout=org.apache.log4j.ConsoleAppender log4j.appender.stdout.Target=System.out log4j.appender.stdout.layout=org.apache.log4j.PatternLayout log4j.appender.stdout.layout.ConversionPattern=%d{HH:mm:ss,SSS} %-5p [%c] - %m%n log4j.rootLogger=info, stdout # basic log level for all messages log4j.logger.org.hibernate=info # SQL statements and parameters log4j.logger.org.hibernate.SQL=debug log4j.logger.org.hibernate.type.descriptor.sql=trace
Hibernate 然后将类似下面的日志消息写入您的日志文件。
17:34:50,353 DEBUG [org.hibernate.SQL] - select author0_.id as id1_0_, author0_.firstName as firstNam2_0_, author0_.lastName as lastName3_0_, author0_.version as version4_0_ from Author author0_ where author0_.id=1 17:34:50,362 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([id1_0_] : [BIGINT]) - [1] 17:34:50,373 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([firstNam2_0_] : [VARCHAR]) - [Thorben] 17:34:50,373 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([lastName3_0_] : [VARCHAR]) - [Janssen] 17:34:50,374 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([version4_0_] : [INTEGER]) - [0]
代码片段中的 SQL 语句不容易阅读。当您告诉 Hibernate 格式化它时,情况会好很多。
您可以通过将配置参数 hibernate.format_sql 设置为 true 来实现。您可以将其作为系统属性提供或在 persistence.xml 文件中设置,如以下代码片段或在 hibernate.cfg.xml 文件中设置。
<?xml version="1.0" encoding="UTF-8" standalone="yes"?> <persistence> <persistence-unit name="my-persistence-unit"> <description>Hibernate Tips</description> <provider> org.hibernate.jpa.HibernatePersistenceProvider </provider> <exclude-unlisted-classes>false</exclude-unlisted-classes> <properties> <property name="hibernate.format_sql" value="true" /> ... </properties> </persistence-unit> </persistence>
以下代码片段显示了格式化的 SQL 语句,它比上一条消息更易读。
16:42:56,873 DEBUG [org.hibernate.SQL] - select author0_.id as id1_0_, author0_.firstName as firstNam2_0_, author0_.lastName as lastName3_0_, author0_.version as version4_0_ from Author author0_ where author0_.id=? 16:42:56,926 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [1] as [BIGINT] - [1] 16:42:56,950 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([id1_0_] : [BIGINT]) - [1] 16:42:56,965 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([firstNam2_0_] : [VARCHAR]) - [Thorben] 16:42:56,965 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([lastName3_0_] : [VARCHAR]) - [Janssen] 16:42:56,966 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([version4_0_] : [INTEGER]) - [0]
您可以在 本书 中找到包含此 Hibernate 技巧的可执行测试用例的项目的下载链接。
如前所述,激活 TRACE 和 DEBUG 级别的消息并将它们发送到您的日志可能会产生巨大的文件,甚至可能会减慢您的应用程序。但是,它们可能包含对调试过程至关重要的信息片段,并且可以帮助在它们投入生产之前识别严重错误。
OverOps 向您显示在错误发生之前在生产环境中记录的最后 250 个 DEBUG、TRACE 和 INFO 级别的语句,即使它们已关闭并且从未到达日志文件。它还显示任何异常、记录的错误或警告背后的变量状态,而不依赖于实际记录的信息。您可以看到错误的整个调用堆栈的完整源代码和变量状态,甚至可以跨微服务和机器。
发现调试生产中错误的新方法。 观看 OverOps 的现场演示。
如需更多此类秘诀,请查看我的新书Hibernate 技巧:常见 Hibernate 问题的 70 多种解决方案。它为您提供了 70 多个现成的方法,涉及基本和高级映射、日志记录、Java 8 支持、缓存以及静态和动态定义的查询等主题。在短短几天内,您可以在 hibernate-tips.com 上以 2.99 美元的价格购买电子书,以 12.99 美元的价格购买平装书。
标签2: Java教程地址:https://www.cundage.com/article/jcg-hibernate-logging-tips-solutions-common-problems.html