Java >> Java tutorial >  >> Tag >> hibernate

Loggningsvejledning til Hibernate 4, 5 &6 – Brug den rigtige konfiguration til dev og prod

At vælge den rigtige logningskonfiguration kan gøre forskellen mellem at finde et ydelsesproblem under udvikling eller lide under det i produktionen. Men det kan også skabe en overhead, der bremser din ansøgning. Du skal beslutte, hvilke oplysninger du har brug for og konfigurere dit system i overensstemmelse hermed.

Jeg foretrækker derfor at bruge to forskellige konfigurationer:

  1. Udviklingskonfigurationen skal logge nok intern information til at forstå databaseinteraktionerne, se antallet af udførte forespørgsler og kontrollere SQL-sætningerne.
  2. Produktionskonfigurationen bør undgå enhver overhead ved at logge så få meddelelser som muligt.

Og ud over målsystemet afhænger din konfiguration også af den Hibernate-version, du bruger. Det er især tilfældet for din udviklingskonfiguration. Nogle logningsfunktioner, såsom den langsomme forespørgselslog, er ikke tilgængelige i ældre Hibernate-versioner, og Hibernate 6 ændrede navnene på nogle få vigtige logningskategorier.

Derfor vil jeg forklare de forskellige logkategorier og give dig mine anbefalede logkonfigurationer til udvikling og produktion, når du bruger Hibernate 4, 5 og 6.

Understøttede log-back-ends

Før vi ser på de forskellige logningskategorier og -niveauer, lad os tage et kort kig på logningsrammerne, der understøttes af Hibernate. Siden version 4.0 bruger Hibernate JBoss Logging-biblioteket til at skrive beskeder til en logfil. Dette bibliotek er en logningsbro, der integrerer forskellige logframeworks. Du kan bestemme, hvilke af følgende rammer du vil bruge til din applikation:

  1. JBoss LogManager
  2. Log4j 2
  3. Log4j 1
  4. Slf4j
  5. JDK-logning

Du behøver kun at tilføje din foretrukne ramme til klassestien, og JBoss Logging-biblioteket henter den. Hvis flere rammer er tilgængelige, vælger den den med højeste prioritet.

Koncepterne og logkategorierne er de samme for alle frameworks, men konfigurationsfilens format og logniveaus navne kan variere. Jeg vil vise et par forskellige konfigurationsfiler i denne artikel. Tjek venligst dokumentationen for din logningsramme, hvis din ikke er inkluderet.

Logkategorier

Ligesom alle applikationer og rammer skriver Hibernate logmeddelelser i forskellige kategorier og logniveauer.

Kategorierne grupperer logmeddelelser for specifikke emner, såsom udførte SQL-sætninger eller cache-interaktioner. Følgende tabel viser de vigtigste logkategorier, der bruges af Hibernate:

Kategori Beskrivelse
org.hibernate Denne kategori indeholder alle beskeder skrevet af Hibernate. Du kan bruge dette til at analysere uspecifikke problemer eller finde kategorier, der bruges af Hibernate.
Indstilling af denne kategori til et fint logniveau kan muligvis skabe en masse logoutput.
org.hibernate.SQL Alle SQL-sætninger, der udføres via JDBC, er skrevet til denne kategori. Du kan bruge den sammen med org.hibernate.type.descriptor.sql eller org.hibernate.orm.jdbc.bind for at få flere oplysninger om JDBC-parametre og resultater.
org.hibernate.type.descriptor.sql Dvale 4 og 5
Hibernate skriver de værdier, der er bundet til JDBC-parametrene og udtrukket fra JDBC-resultaterne til denne kategori. Denne kategori skal bruges sammen med org.hibernate.SQL til også at logge SQL-sætningerne.
org.hibernate.orm.jdbc.bind Dvale 6
Hibernate skriver værdierne bundet til JDBC-parametrene til denne kategori. Denne kategori skal bruges sammen med org.hibernate.SQL til også at logge SQL-sætningerne.
org.hibernate.SQL_SLOW Dvale>=5.4.5
Hibernate skriver en besked til den langsomme forespørgselslog, hvis udførelsen af ​​en SQL-sætning tog længere tid end den konfigurerede tærskel (se Log for langsom forespørgsel).
org.hibernate.pretty Dvale logger tilstanden ved skylletid på max. 20 enheder i denne kategori.
org.hibernate.cache Information om cache-aktiviteter på andet niveau er skrevet til denne kategori.
org.hibernate.stat Hibernate skriver nogle statistikker for hver forespørgsel til denne kategori. Statistikken skal aktiveres separat (se Aktiver Dvale-statistikker).
org.hibernate.hql.internal.ast.AST Dvale 4 og 5
Denne kategori grupperer HQL- og SQL-AST'erne under forespørgselsparsing.
org.hibernate.tool.hbm2ddl Hibernate skriver de DDL SQL-forespørgsler, der udføres under skemamigrering, til denne logkategori.

Navnene på logniveauerne er defineret af din logningsramme og definerer mængden og granulariteten af ​​logmeddelelserne. Du kan tildele et logniveau til hver kategori. Hvis du ikke angiver et logniveau for en specifik kategori, vil den arve niveauet fra sin overordnede kategori.

Brug ikke show_sql til at logge SQL-forespørgsler

Hvordan man får Hibernate til at logge de udførte SQL-forespørgsler er et ofte stillet spørgsmål, og det mest populære svar på internettet ser ud til at være at indstille show_sql parameter i persistence.xml til sand . Men gør venligst ikke dette!

Hibernate giver to måder at aktivere logningen af ​​de udførte SQL-forespørgsler på og indstille show_sql parameter til sand er den værre. Det har to store ulemper:

  1. Hibernate skriver alle udførte SQL-sætninger til standardud uden at bruge logningsrammerne. Derfor bliver det vanskeligt at definere den logfil, som skal indeholde disse specifikke logmeddelelser. At skrive til standard ud er også oftest meget langsommere end at bruge en optimeret logningsramme.
  2. persistence.xml er en del af en jar-fil i din applikation, og du skal åbne den binære fil, hvis du vil aktivere eller deaktivere logningen af ​​SQL-sætningerne. Din logningsrammes konfiguration er oftest en ekstern tekstfil, der nemt kan ændres på ethvert system.

Den bedre måde at aktivere logningen af ​​udførte SQL-sætninger på er at indstille logniveauet for org.hibernate.SQL kategori for at DEBUG (eller det tilsvarende logniveau for din logramme). Hibernate vil skrive SQL-sætningerne uden nogen information om de værdier, der er bundet til JDBC-parametrene eller udtrukket fra forespørgselsresultatet. Hvis du også vil have disse oplysninger, skal du indstille logniveauet for org.hibernate.type.descriptor.sql for at DEBUG (se udviklingsanbefalingen for et eksempel).

Anbefalede logningskonfigurationer

Kravene til produktions- og udviklingssystemer er meget forskellige. Under udviklingen skal du vide, hvad Hibernate laver i baggrunden. Men logning af disse oplysninger sænker applikationen, og det er ikke påkrævet i produktionen. Jeg anbefaler derfor at bruge to forskellige indstillinger:

Udvikling

Hibernate gør mange ting for dig i baggrunden, hvilket gør det nemt at glemme, at du stadig arbejder med en database. Men hvis du vil være sikker på, at din applikation vil fungere som forventet, skal du kontrollere antallet af udførte forespørgsler og deres SQL-sætninger.

Du skal indstille logniveauet for org.hibernate.SQL kategori for at DEBUG for at få disse oplysninger. Hvis du også vil logge de brugte bind-parameterværdier, skal du også indstille org.hibernate.type.descriptor.sql kategori (Hibernate 4 &5) eller org.hibernate.orm.jdbc.bind kategori (Hibernate 6) for at spore .

Ud over det foretrækker jeg at aktivere Hibernate-statistikker for at få en oversigt over de mest kritiske målinger i slutningen af ​​hver session. Og hvis du bruger Hibernate i mindst version 5.4.5, anbefaler jeg også at aktivere Hibernates langsomme forespørgselslog.

Du kan se en sådan logningskonfiguration for forskellige logningsrammer i de følgende afsnit.

Log4J-konfiguration til Hibernate 4, 5 og 6

###
# Global configuration for all Hibernate versions
###
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

###
# Hibernate < 5.4.5
###
# 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
# Statistics
log4j.logger.org.hibernate.stat=debug
# 2nd Level Cache
log4j.logger.org.hibernate.cache=debug

###
# Hibernate >= 5.4.5
###
# 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
# Statistics and slow queries
log4j.logger.org.hibernate.stat=debug
log4j.logger.org.hibernate.SQL_SLOW=info
# 2nd Level Cache
log4j.logger.org.hibernate.cache=debug

###
#Hibernate >= 6
###
# 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.orm.jdbc.bind=trace
# Statistics and slow queries
log4j.logger.org.hibernate.stat=debug
log4j.logger.org.hibernate.SQL_SLOW=info
# 2nd Level Cache
log4j.logger.org.hibernate.cache=debug

Log4J2-konfiguration til Hibernate 4, 5 og 6

<Configuration monitorInterval="60">
    <Properties>
        <Property name="log-path">PropertiesConfiguration</Property>
    </Properties>
    <Appenders>
        <Console name="Console-Appender" target="SYSTEM_OUT">
            <PatternLayout>
                <pattern>
                    [%-5level] %d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %c{1} - %msg%n
                </pattern>>
            </PatternLayout>
        </Console>
    </Appenders>
    <Loggers>
        <! – Hibernate before 5.4.5 – >
        <Logger name="org.hibernate.SQL" level="debug" additivity="false">
            <AppenderRef ref="Console-Appender"/>
        </Logger>
        <Logger name="org.hibernate.type.descriptor.sql" level="trace" additivity="false">
            <AppenderRef ref="Console-Appender"/>
        </Logger>
        <Logger name="org.hibernate.stat" level="trace" additivity="false">
            <AppenderRef ref="Console-Appender"/>
        </Logger>
        <Logger name="org.hibernate.cache" level="trace" additivity="false">
            <AppenderRef ref="Console-Appender"/>
        </Logger>

        <! – Hibernate after 5.4.5 – >
        <Logger name="org.hibernate.SQL" level="debug" additivity="false">
            <AppenderRef ref="Console-Appender"/>
        </Logger>
        <Logger name="org.hibernate.type.descriptor.sql" level="trace" additivity="false">
            <AppenderRef ref="Console-Appender"/>
        </Logger>
        <Logger name="org.hibernate.stat" level="trace" additivity="false">
            <AppenderRef ref="Console-Appender"/>
        </Logger>
        <Logger name="org.hibernate.SQL_SLOW" level="trace" additivity="false">
            <AppenderRef ref="Console-Appender"/>
        </Logger>
        <Logger name="org.hibernate.cache" level="trace" additivity="false">
            <AppenderRef ref="Console-Appender"/>
        </Logger>

        <! – Hibernate after 6 – >
        <Logger name="org.hibernate.SQL" level="debug" additivity="false">
            <AppenderRef ref="Console-Appender"/>
        </Logger>
        <Logger name="org.hibernate.orm.jdbc.bind" level="trace" additivity="false">
            <AppenderRef ref="Console-Appender"/>
        </Logger>
        <Logger name="org.hibernate.stat" level="trace" additivity="false">
            <AppenderRef ref="Console-Appender"/>
        </Logger>
        <Logger name="org.hibernate.SQL_SLOW" level="trace" additivity="false">
            <AppenderRef ref="Console-Appender"/>
        </Logger>
        <Logger name="org.hibernate.cache" level="trace" additivity="false">
            <AppenderRef ref="Console-Appender"/>
        </Logger>

        <Root level="info">
            <AppenderRef ref="Console-Appender"/>
        </Root>
    </Loggers>
</Configuration>

JDK-loggerkonfiguration til Hibernate 4, 5 og 6

###
# Global configuration for all Hibernate versions
###
handlers=java.util.logging.ConsoleHandler
java.util.logging.ConsoleHandler.level=FINEST
java.util.logging.ConsoleHandler.formatter=java.util.logging.SimpleFormatter

org.hibernate.level=INFO

###
# Hibernate < 5.4.5
###
# basic log level for all messages
org.hibernate.SQL.level=FINER
org.hibernate.type.descriptor.sql.level=FINEST
# Statistics
org.hibernate.stat.level=FINER
# 2nd Level Cache
org.hibernate.cache.level=FINER

###
# Hibernate >= 5.4.5
###
# basic log level for all messages
org.hibernate.SQL.level=FINER
org.hibernate.type.descriptor.sql.level=FINEST
# Statistics
org.hibernate.stat.level=FINER
org.hibernate.SQL_SLOW.level=INFO
# 2nd Level Cache
org.hibernate.cache.level=FINER

###
# Hibernate >= 6
###
# basic log level for all messages
org.hibernate.SQL.level=FINER
org.hibernate.orm.jdbc.bind.level=FINEST
# Statistics
org.hibernate.stat.level=FINER
org.hibernate.SQL_SLOW.level=INFO
# 2nd Level Cache
org.hibernate.cache.level=FINER

Log tilbage via Slf4j-konfiguration for Hibernate 4, 5 og 6

<configuration>
	<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
		<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
			<Pattern>
				%d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - %msg%n
			</Pattern>
		</encoder>
	</appender>
    <! – Hibernate before 5.4.5 – >
	<logger name="org.hibernate.SQL" level="debug" additivity="false">
		<appender-ref ref="STDOUT"/>
	</logger>
	<logger name="org.hibernate.type.descriptor.sql" level="trace" additivity="false">
		<appender-ref ref="STDOUT"/>
	</logger>
	<logger name="org.hibernate.stat" level="debug" additivity="false">
		<appender-ref ref="STDOUT"/>
	</logger>
	<logger name="org.hibernate.cache" level="debug" additivity="false">
		<appender-ref ref="STDOUT"/>
	</logger>

    <! – Hibernate after 5.4.5 – >
	<logger name="org.hibernate.SQL" level="debug" additivity="false">
		<appender-ref ref="STDOUT"/>
	</logger>
	<logger name="org.hibernate.type.descriptor.sql" level="trace" additivity="false">
		<appender-ref ref="STDOUT"/>
	</logger>
	<logger name="org.hibernate.stat" level="debug" additivity="false">
		<appender-ref ref="STDOUT"/>
	</logger>
	<logger name="org.hibernate.SQL_SLOW" level="info" additivity="false">
		<appender-ref ref="STDOUT"/>
	</logger>
	<logger name="org.hibernate.cache" level="debug" additivity="false">
		<appender-ref ref="STDOUT"/>
	</logger>

    <! – Hibernate after 6 – >
	<logger name="org.hibernate.SQL" level="debug" additivity="false">
		<appender-ref ref="STDOUT"/>
	</logger>
	<logger name="org.hibernate.orm.jdbc.bind" level="trace" additivity="false">
		<appender-ref ref="STDOUT"/>
	</logger>
	<logger name="org.hibernate.stat" level="debug" additivity="false">
		<appender-ref ref="STDOUT"/>
	</logger>
	<logger name="org.hibernate.SQL_SLOW" level="info" additivity="false">
		<appender-ref ref="STDOUT"/>
	</logger>
	<logger name="org.hibernate.cache" level="debug" additivity="false">
		<appender-ref ref="STDOUT"/>
	</logger>

	<root level="info">
		<appender-ref ref="STDOUT"/>
	</root>
</configuration>

Eksempellog for Hibernate 4 og 5

Hvis du bruger nogen af ​​disse konfigurationer med Hibernate 4 eller 5, vil den skrive en logfil, der ligner meget den følgende. Den blev skrevet af log4j2 og Hibernate 5. Loggen viser Hibernate-meddelelserne for en session, hvor jeg vedblev 2 nye Author enheder, opdaterede en af ​​dem bagefter og valgte alle Forfatter s med et givet efternavn.

13:45:20,863 DEBUG [org.hibernate.SQL] - select nextval ('hibernate_sequence')
13:45:20,907 DEBUG [org.hibernate.SQL] - select nextval ('hibernate_sequence')
13:45:20,939 DEBUG [org.hibernate.SQL] - insert into Author (firstName, lastName, version, id) values (?, ?, ?, ?)
13:45:20,950 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [1] as [VARCHAR] - [Thorben]
13:45:20,951 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [2] as [VARCHAR] - [Janssen]
13:45:20,952 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [3] as [INTEGER] - [0]
13:45:20,953 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [4] as [BIGINT] - [1]
13:45:20,960 DEBUG [org.hibernate.SQL] - insert into Author (firstName, lastName, version, id) values (?, ?, ?, ?)
13:45:20,960 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [1] as [VARCHAR] - [Nicolia]
13:45:20,960 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [2] as [VARCHAR] - [Parlog]
13:45:20,961 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [3] as [INTEGER] - [0]
13:45:20,961 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [4] as [BIGINT] - [2]
13:45:21,488 DEBUG [org.hibernate.SQL] - update Author set firstName=?, lastName=?, version=? where id=? and version=?
13:45:21,494 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [1] as [VARCHAR] - [Nicolai]
13:45:21,503 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [2] as [VARCHAR] - [Parlog]
13:45:21,505 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [3] as [INTEGER] - [1]
13:45:21,509 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [4] as [BIGINT] - [2]
13:45:21,510 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [5] as [INTEGER] - [0]
13:45:21,522 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_.lastName=?
13:45:21,524 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [1] as [VARCHAR] - [Janssen]
13:45:21,531 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([id1_0_] : [BIGINT]) - [1]
13:45:21,541 INFO  [org.hibernate.engine.internal.StatisticalLoggingSessionEventListener] - Session Metrics {
    71600 nanoseconds spent acquiring 1 JDBC connections;
    42200 nanoseconds spent releasing 1 JDBC connections;
    5946500 nanoseconds spent preparing 6 JDBC statements;
    9801200 nanoseconds spent executing 6 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;
    55887200 nanoseconds spent executing 2 flushes (flushing a total of 4 entities and 0 collections);
    27027800 nanoseconds spent executing 1 partial-flushes (flushing a total of 2 entities and 2 collections)
}

Hvis du ikke har brug for så meget information, anbefaler jeg at fjerne konfigurationen af ​​org.hibernate.type.descriptor.sql kategori. Dette vil fjerne logmeddelelserne, der viser bindingsparameterværdierne. Som du kan se i logfilen, er det størstedelen af ​​de skrevne logmeddelelser, og der er så mange af dem, at loggen bliver svær at læse.

Eksempellog for Hibernate 6

Som du kan se i det følgende uddrag, ligner loggen skrevet af Hibernate 6 meget. Hvis du vælger flere entitetsobjekter, er det ofte lidt nemmere at læse end loggen skrevet af tidligere Hibernate-versioner. Det er mest fordi kategorien org.hibernate.orm.jdbc.bind inkluderer kun logmeddelelser for bindeparametre, men ikke for udtrukne parametre.

Hvis du vil reducere mængden af ​​information, bør du overveje at deaktivere sporingslogning for kategorien org.hibernate.orm.jdbc.bind .

15:37:21,600 DEBUG [org.hibernate.SQL] - select nextval('Author_SEQ')
15:37:21,609 INFO  [org.hibernate.SQL_SLOW] - SlowQuery: 2 milliseconds. SQL: 'select nextval('Author_SEQ')'
15:37:21,612 DEBUG [org.hibernate.SQL] - select nextval('Author_SEQ')
15:37:21,615 INFO  [org.hibernate.SQL_SLOW] - SlowQuery: 2 milliseconds. SQL: 'select nextval('Author_SEQ')'
15:37:21,902 DEBUG [org.hibernate.SQL] - insert into Author (firstName, lastName, version, id) values (?, ?, ?, ?)
15:37:21,903 TRACE [org.hibernate.orm.jdbc.bind] - binding parameter [1] as [VARCHAR] - [Thorben]
15:37:21,903 TRACE [org.hibernate.orm.jdbc.bind] - binding parameter [2] as [VARCHAR] - [Janssen]
15:37:21,903 TRACE [org.hibernate.orm.jdbc.bind] - binding parameter [3] as [INTEGER] - [0]
15:37:21,904 TRACE [org.hibernate.orm.jdbc.bind] - binding parameter [4] as [BIGINT] - [1]
15:37:21,908 INFO  [org.hibernate.SQL_SLOW] - SlowQuery: 4 milliseconds. SQL: 'insert into Author (firstName, lastName, version, id) values ('Thorben', 'Janssen', 0, 1)'
15:37:21,911 DEBUG [org.hibernate.SQL] - insert into Author (firstName, lastName, version, id) values (?, ?, ?, ?)
15:37:21,911 TRACE [org.hibernate.orm.jdbc.bind] - binding parameter [1] as [VARCHAR] - [Nicolia]
15:37:21,911 TRACE [org.hibernate.orm.jdbc.bind] - binding parameter [2] as [VARCHAR] - [Parlog]
15:37:21,912 TRACE [org.hibernate.orm.jdbc.bind] - binding parameter [3] as [INTEGER] - [0]
15:37:21,912 TRACE [org.hibernate.orm.jdbc.bind] - binding parameter [4] as [BIGINT] - [2]
15:37:21,914 INFO  [org.hibernate.SQL_SLOW] - SlowQuery: 2 milliseconds. SQL: 'insert into Author (firstName, lastName, version, id) values ('Nicolia', 'Parlog', 0, 2)'
15:37:21,915 DEBUG [org.hibernate.SQL] - update Author set firstName=?, lastName=?, version=? where id=? and version=?
15:37:21,915 TRACE [org.hibernate.orm.jdbc.bind] - binding parameter [1] as [VARCHAR] - [Nicolai]
15:37:21,915 TRACE [org.hibernate.orm.jdbc.bind] - binding parameter [2] as [VARCHAR] - [Parlog]
15:37:21,916 TRACE [org.hibernate.orm.jdbc.bind] - binding parameter [3] as [INTEGER] - [1]
15:37:21,916 TRACE [org.hibernate.orm.jdbc.bind] - binding parameter [4] as [BIGINT] - [2]
15:37:21,916 TRACE [org.hibernate.orm.jdbc.bind] - binding parameter [5] as [INTEGER] - [0]
15:37:21,919 INFO  [org.hibernate.SQL_SLOW] - SlowQuery: 3 milliseconds. SQL: 'update Author set firstName='Nicolai', lastName='Parlog', version=1 where id=2 and version=0'
15:37:21,952 DEBUG [org.hibernate.SQL] - select a1_0.id,a1_0.firstName,a1_0.lastName,a1_0.version from Author a1_0 where a1_0.lastName=?
15:37:21,952 TRACE [org.hibernate.orm.jdbc.bind] - binding parameter [1] as [VARCHAR] - [Janssen]
15:37:21,959 INFO  [org.hibernate.SQL_SLOW] - SlowQuery: 6 milliseconds. SQL: 'select a1_0.id,a1_0.firstName,a1_0.lastName,a1_0.version from Author a1_0 where a1_0.lastName='Janssen''
15:37:21,964 DEBUG [org.hibernate.stat.internal.StatisticsImpl] - HHH000117: HQL: SELECT a FROM Author a WHERE a.lastName = :lastName, time: 26ms, rows: 1
15:37:21,972 INFO  [org.hibernate.engine.internal.StatisticalLoggingSessionEventListener] - Session Metrics {
    51899 nanoseconds spent acquiring 1 JDBC connections;
    30200 nanoseconds spent releasing 1 JDBC connections;
    419199 nanoseconds spent preparing 6 JDBC statements;
    21482801 nanoseconds spent executing 6 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;
    390499 nanoseconds spent executing 1 flushes (flushing a total of 2 entities and 2 collections);
    40233400 nanoseconds spent executing 1 partial-flushes (flushing a total of 2 entities and 2 collections)
}

Produktion

Så længe du ikke behøver at analysere et problem i produktionen, bør du logge så lidt information som muligt. Dette kan gøres for alle Hibernate-versioner ved at indstille alle Hibernate-relaterede logkategorier til FEJL . Du bør også sikre dig, at Dvalestatistikkomponenten og den langsomme forespørgselslog er deaktiveret.

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=error

Log4J2

<Configuration monitorInterval="60">
    <Properties>
        <Property name="log-path">PropertiesConfiguration</Property>
    </Properties>
    <Appenders>
        <Console name="Console-Appender" target="SYSTEM_OUT">
            <PatternLayout>
                <pattern>
                    [%-5level] %d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %c{1} - %msg%n
                </pattern>>
            </PatternLayout>
        </Console>
    </Appenders>
    <Loggers>
        <Logger name="org.hibernate" level="error" additivity="false">
            <AppenderRef ref="Console-Appender"/>
        </Logger>
        <Root level="info">
            <AppenderRef ref="Console-Appender"/>
        </Root>
    </Loggers>
</Configuration>

JDK-logger

handlers=java.util.logging.ConsoleHandler

java.util.logging.ConsoleHandler.level=FINEST
java.util.logging.ConsoleHandler.formatter=java.util.logging.SimpleFormatter

org.hibernate.level=SEVERE

Log tilbage via Slf4j

<configuration>
	<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
		<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
			<Pattern>
				%d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - %msg%n
			</Pattern>
		</encoder>
	</appender>
	<logger name="org.hibernate" level="error" additivity="false">
		<appender-ref ref="STDOUT"/>
	</logger>
	<root level="info">
		<appender-ref ref="STDOUT"/>
	</root>
</configuration>

Oversigt

Hibernate understøtter flere logningsudbydere, og du kan vælge den, du foretrækker, ved at tilføje den til din applikations klassesti.

Logmeddelelserne er grupperet i forskellige kategorier, og du kan aktivere eller deaktivere dem ved at tildele et logniveau for hver kategori.

Det tager noget tid at skrive log-beskeder og indsamle de nødvendige oplysninger. Du bør derfor slå alle unødvendige logmeddelelser fra i din produktionskonfiguration.

Udviklingskonfigurationen bør aktivere fejlretningslogning for nogle afgørende kategorier som f.eks. org.hibernate.SQL og jeg aktiverer oftest også Hibernate-statistikker for at finde potentielle ydeevneproblemer så hurtigt som muligt.


Java tag