Various Logging Levels in Hibernate – Hibernate中的各种日志级别

最后修改: 2019年 12月 15日

中文/混合/英文(键盘快捷键:t)

1. Overview

1.概述

Since Hibernate handles the interaction with the database for us, we’re able to develop database-related code quickly. But, this can make debugging database-related failures difficult.

由于Hibernate为我们处理与数据库的交互,我们能够快速开发与数据库相关的代码。但是,这可能使调试与数据库有关的故障变得困难。

Hence, it can be useful to view the interaction of Hibernate with the database. For example, the SQL generated by Hibernate to read data from a table.

因此,查看Hibernate与数据库的交互是有用的。例如,由Hibernate生成的从表中读取数据的SQL。

In this tutorial, we’ll see the different levels of logging in Hibernate that can be used to achieve this.

在本教程中,我们将看到Hibernate中不同级别的日志,可用于实现这一目的

2. Logging SQL

2.记录SQL

At the most basic level, we can log the SQL statements generated by Hibernate without the actual parameter values passed to it.

在最基本的层面上,我们可以记录由Hibernate生成的SQL语句,而不记录传递给它的实际参数值。

Hibernate uses the category org.hibernate.SQL to log this information. So, all we’ve to do is set the logging level of this category to DEBUG.

Hibernate使用类别org.hibernate.SQL来记录这些信息。因此,我们所要做的就是将这个类别的日志级别设置为DEBUG。

In Log4J, we’ll have to add a logger element in the configuration XML:

在Log4J中,我们要在配置XML中添加一个logger元素。

<logger name="org.hibernate.SQL">
     <level value="debug"/>
</logger>

Similarly, in Log4J2, we’ll add a Logger element:

同样地,在Log4J2中,我们将添加一个Logger元素。

<Logger name="org.hibernate.SQL" level="debug"/>

And, in Logback, we’ll add a logger element:

而且,在Logback中,我们将添加一个logger元素。

<logger name="org.hibernate.SQL" level="DEBUG" />

We should now see the generated SQL in the logs:

现在我们应该在日志中看到生成的SQL。

2019-12-07 23:04:23 | DEBUG | [main] o.h.SQL:127 - insert into Employee 
(employeeNumber, name, title, id) values (?, ?, ?, ?)
2019-12-07 23:04:23 | DEBUG | [main] o.h.SQL:127 - select employee0_.id as id1_0_, 
employee0_.employeeNumber as employee2_0_, employee0_.name as name3_0_, 
employee0_.title as title4_0_ from Employee employee0_

3. Logging Parameter Values

3.记录参数值

Although normally the generated SQL is enough to identify problems, sometimes we might want to also view the parameters being passed to the SQL statement.

尽管通常情况下,生成的SQL语句足以识别问题,但有时我们可能还想查看传递给SQL语句的参数。

Hibernate logs the input parameters and retrieved results using the org.hibernate.type.descriptor.sql category with a log level of TRACE. Now, let’s add this category to our configuration files.

Hibernate使用org.hibernate.type.descriptor.sql类别来记录输入参数和检索结果,日志级别为TRACE。现在,让我们把这个类别添加到我们的配置文件中。

In Log4J we do:

在Log4J中,我们这样做。

<logger name="org.hibernate.type.descriptor.sql"> 
    <level value="trace"/> 
</logger>

In Log4J2:

在Log4J2中。

<Logger name="org.hibernate.type.descriptor.sql" level="trace"/>

And finally, in Logback:

最后,在Logback。

<logger name="org.hibernate.type.descriptor.sql" level="TRACE" />

Consequently, we should see the parameter values passed to the SQL statement as well as the result of the execution:

因此,我们应该看到传递给SQL语句的参数值,以及执行的结果。

2019-12-07 23:04:23 | DEBUG | [main] o.h.SQL:127 - insert into Employee (employeeNumber, name, title, id) 
values (?, ?, ?, ?)
2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicBinder:64 - binding parameter [1] 
as [VARCHAR] - [001]
2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicBinder:64 - binding parameter [2] 
as [VARCHAR] - [John Smith]
2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicBinder:52 - binding parameter [3] 
as [VARCHAR] - [null]
2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicBinder:64 - binding parameter [4] 
as [BIGINT] - [1]
2019-12-07 23:04:23 | DEBUG | [main] o.h.SQL:127 - select employee0_.id as id1_0_, 
employee0_.employeeNumber as employee2_0_, employee0_.name as name3_0_, 
employee0_.title as title4_0_ from Employee employee0_
2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicExtractor:60 - extracted value ([id1_0_] :
 [BIGINT]) - [1]
2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicExtractor:60 - extracted value ([employee2_0_] :
 [VARCHAR]) - [001]
2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicExtractor:60 - extracted value ([name3_0_] :
 [VARCHAR]) - [John Smith]
2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicExtractor:50 - extracted value ([title4_0_] :
 [VARCHAR]) - [null]

It’s worth noting that we don’t need to enable the org.hibernate.SQL category to view the above information. We can enable and disable the two categories independently.

值得注意的是,我们不需要启用org.hibernate.SQL类别来查看上述信息。我们可以独立启用和禁用这两个类别

But, it makes sense to enable org.hibernate.SQL so that we know which SQL statement the parameter values relate to.

但是,启用org.hibernate.SQL是有意义的,这样我们就能知道参数值与哪个SQL语句有关了

4. Activate Hibernate Statistics

4.激活Hibernate统计数据

Apart from the SQL and the JDBC parameter values, Hibernate can also log statistics for each SQL statement. This can be useful to identify potential performance issues.

除了SQL和JDBC参数值,Hibernate还可以记录每个SQL语句的统计数据。这对于识别潜在的性能问题很有用。

Hibernate uses the category org.hibernate.stat to log this information. But, Hibernate does not always generate these statistics because it can have a bad influence on the performance.

Hibernate使用类别org.hibernate.stat来记录这些信息。但是,Hibernate并不总是生成这些统计数据,因为它可能对性能产生不好的影响。

First, we’ve to tell Hibernate to generate these statistics by setting the configuration property hibernate.generate_statistics to true.

首先,我们必须通过将配置属性hibernate.generate_statistics设置为true来告诉Hibernate产生这些统计数据。

For example, we can set this property in our hibernate.cfg.xml file:

例如,我们可以在我们的hibernate.cfg.xml文件中设置这个属性。

<property name="hibernate.generate_statistics">true</property>

Along with this property, setting the category org.hibernate.stat to DEBUG will log a statement with the statistics for each query executed. It’ll also log one multi-line log statement at the end of the session that’ll have summarized statistical information:

除了这个属性,将类别org.hibernate.stat设为DEBUG,将记录每个查询的统计信息的语句。它还会在会话结束时记录一个多行的日志语句,其中会有汇总的统计信息。

2019-12-07 23:25:18 | DEBUG | [main] o.h.s.i.StatisticsInitiator:101 - Statistics initialized 
[enabled=true]
2019-12-07 23:25:19 | DEBUG | [main] o.h.s.i.StatisticsImpl:729 - HHH000117: HQL: 
from com.baeldung.hibernate.logging.Employee, time: 22ms, rows: 1
2019-12-07 23:25:19 | INFO  | [main] o.h.e.i.StatisticalLoggingSessionEventListener:258 - 
Session Metrics {
    55600 nanoseconds spent acquiring 1 JDBC connections;
    178600 nanoseconds spent releasing 1 JDBC connections;
    2167200 nanoseconds spent preparing 2 JDBC statements;
    2426800 nanoseconds spent executing 2 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;
    47098900 nanoseconds spent executing 1 flushes (flushing a total of 1 entities 
    and 0 collections);
    0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities 
    and 0 collections)
}

Note the first line in the log that indicates that the statistics are enabled.

请注意日志中的第一行,它表明统计被启用。

5. Log All Activity

5.记录所有活动

To dig even deeper into Hibernate’s interaction with the database, we’ll have to enable logging for the category org.hibernate. This category contains all messages logged by Hibernate.

为了更深入地挖掘Hibernate与数据库的交互,我们必须为org.hibernate类别启用日志。这个类别包含了所有由Hibernate记录的信息。

But, we must use this category with caution as it might create a lot of log output:
hibernate logs

但是,我们必须谨慎地使用这个类别,因为它可能会产生大量的日志输出:
hibernate logs

6. Conclusion

6.结论

In this tutorial, we saw the different levels of logging in Hibernate. The logged information can be very useful during development. But, we’ve to be careful while enabling this in production as it can adversely affect the application performance.

在本教程中,我们看到了Hibernate中不同级别的日志记录。在开发过程中,记录的信息可能非常有用。但是,在生产中启用这些信息时,我们必须要小心,因为它可能会对应用程序的性能产生不利影响。

And of course, the code that accompanies this tutorial can be found over on GitHub.

当然,与本教程配套的代码可以在GitHub上找到over