OutOfMemory aufgrund einer großen Protokollierungsmeldung im Logback, die durch die Validierung der Hibernate-Bean ausge
Posted: 16 Jan 2025, 11:13
Ich habe einen OOM erhalten und mir den Heapdump mit MAT für meine Java-Spring-Boot-Anwendung angesehen.
Ich habe große Threads gefunden, die 250 MB verbrauchen, weil sie ein zu großes ch.qos.logback.classic.spi.LoggingEvent enthalten< /code>
Der Stacktrace des Threads:
Wenn ich mir die Nachricht ansehe, sehe ich, dass meine JPA-Entität ContactHistoryEntity mit allen verbundenen ContactHistoryEntryEntity (1:n) geschrieben ist und diese selbst auch ein anderes Objekt hat und einfach explodiert.
In meinem Controller aktualisiere ich meine ParticipantEntity, die die ContactHistoryEntity enthält, in der ich die NotNull-Annotation habe
die andere Entität:
Was ich überprüft habe
Warum? Logback tritt hier ein? Die Validierung ist erfolgreich (nicht null) und warum ist eine Meldung erforderlich?
Wie kann man das verhindern?
Lösungsidee noch nicht getestet
ContactHistoryEntity.toString mit einer kürzeren Version überschreiben. Auf jeden Fall wäre es interessant, warum eine Logback-Nachricht generiert werden muss.
Ich habe große Threads gefunden, die 250 MB verbrauchen, weil sie ein zu großes ch.qos.logback.classic.spi.LoggingEvent enthalten< /code>
Code: Select all
Class Name | Shallow Heap | Retained Heap | Percentage
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
org.apache.tomcat.util.threads.TaskThread @ 0x706604d48 http-nio-9000-exec-232 Thread | 120 B | 481,48 MB | 28,58 %
'- ch.qos.logback.classic.spi.LoggingEvent @ 0x710363238 | 72 B | 240,09 MB | 14,25 %
'- formattedMessage,message java.lang.String @ 0x710363208 Validating value ContactHistoryEntity[entries=[ContactHistoryEntryEntity[complaintReason=,complaintResolution=,contactChannel=UNKNOWN,contactHistory=com.company.core.domain.participant.ContactHistoryEntity$HibernateProxy$eDuKFlHN@21646c05,detail...| 24 B | 240,09 MB | 14,25 %
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Code: Select all
http-nio-9000-exec-232
at java.lang.OutOfMemoryError.()V (OutOfMemoryError.java:48)
at java.util.Arrays.copyOf([BI)[B (Arrays.java:3537)
at java.lang.AbstractStringBuilder.ensureCapacityInternal(I)V (AbstractStringBuilder.java:228)
at java.lang.AbstractStringBuilder.append(Ljava/lang/String;)Ljava/lang/AbstractStringBuilder; (AbstractStringBuilder.java:582)
at java.lang.StringBuilder.append(Ljava/lang/String;)Ljava/lang/StringBuilder; (StringBuilder.java:179)
at ch.qos.logback.core.pattern.FormattingConverter.write(Ljava/lang/StringBuilder;Ljava/lang/Object;)V (FormattingConverter.java:39)
at ch.qos.logback.core.pattern.PatternLayoutBase.writeLoopOnConverters(Ljava/lang/Object;)Ljava/lang/String; (PatternLayoutBase.java:115)
at ch.qos.logback.classic.PatternLayout.doLayout(Lch/qos/logback/classic/spi/ILoggingEvent;)Ljava/lang/String; (PatternLayout.java:165)
at ch.qos.logback.classic.PatternLayout.doLayout(Ljava/lang/Object;)Ljava/lang/String; (PatternLayout.java:39)
at ch.qos.logback.core.encoder.LayoutWrappingEncoder.encode(Ljava/lang/Object;)[B (LayoutWrappingEncoder.java:116)
at ch.qos.logback.core.OutputStreamAppender.subAppend(Ljava/lang/Object;)V (OutputStreamAppender.java:230)
at ch.qos.logback.core.OutputStreamAppender.append(Ljava/lang/Object;)V (OutputStreamAppender.java:102)
at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(Ljava/lang/Object;)V (UnsynchronizedAppenderBase.java:84)
at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(Ljava/lang/Object;)I (AppenderAttachableImpl.java:51)
at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Lch/qos/logback/classic/spi/ILoggingEvent;)I (Logger.java:270)
at ch.qos.logback.classic.Logger.callAppenders(Lch/qos/logback/classic/spi/ILoggingEvent;)V (Logger.java:257)
at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Ljava/lang/String;Lorg/slf4j/Marker;Lch/qos/logback/classic/Level;Ljava/lang/String;[Ljava/lang/Object;Ljava/lang/Throwable;)V (Logger.java:421)
at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Ljava/lang/String;Lorg/slf4j/Marker;Lch/qos/logback/classic/Level;Ljava/lang/String;[Ljava/lang/Object;Ljava/lang/Throwable;)V (Logger.java:383)
at ch.qos.logback.classic.Logger.log(Lorg/slf4j/Marker;Ljava/lang/String;ILjava/lang/String;[Ljava/lang/Object;Ljava/lang/Throwable;)V (Logger.java:765)
at org.apache.logging.slf4j.SLF4JLogger.logMessage(Ljava/lang/String;Lorg/apache/logging/log4j/Level;Lorg/apache/logging/log4j/Marker;Lorg/apache/logging/log4j/message/Message;Ljava/lang/Throwable;)V (SLF4JLogger.java:234)
at org.jboss.logging.Log4j2Logger.doLogf(Lorg/jboss/logging/Logger$Level;Ljava/lang/String;Ljava/lang/String;[Ljava/lang/Object;Ljava/lang/Throwable;)V (Log4j2Logger.java:66)
at org.jboss.logging.Logger.logf(Ljava/lang/String;Lorg/jboss/logging/Logger$Level;Ljava/lang/Throwable;Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Object;)V (Logger.java:2414)
at org.jboss.logging.DelegatingBasicLogger.tracef(Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Object;)V (DelegatingBasicLogger.java:129)
at org.hibernate.validator.internal.engine.constraintvalidation.ConstraintTree.validateConstraints(Lorg/hibernate/validator/internal/engine/ValidationContext;Lorg/hibernate/validator/internal/engine/ValueContext;Ljava/util/Set;)V (ConstraintTree.java:108)
at org.hibernate.validator.internal.engine.constraintvalidation.ConstraintTree.validateConstraints(Lorg/hibernate/validator/internal/engine/ValidationContext;Lorg/hibernate/validator/internal/engine/ValueContext;)Z (ConstraintTree.java:87)
at org.hibernate.validator.internal.metadata.core.MetaConstraint.validateConstraint(Lorg/hibernate/validator/internal/engine/ValidationContext;Lorg/hibernate/validator/internal/engine/ValueContext;)Z (MetaConstraint.java:73)
at org.hibernate.validator.internal.engine.ValidatorImpl.validateMetaConstraint(Lorg/hibernate/validator/internal/engine/ValidationContext;Lorg/hibernate/validator/internal/engine/ValueContext;Lorg/hibernate/validator/internal/metadata/core/MetaConstraint;)Z (ValidatorImpl.java:620)
at org.hibernate.validator.internal.engine.ValidatorImpl.validateConstraint(Lorg/hibernate/validator/internal/engine/ValidationContext;Lorg/hibernate/validator/internal/engine/ValueContext;ZLorg/hibernate/validator/internal/metadata/core/MetaConstraint;)Z (ValidatorImpl.java:583)
at org.hibernate.validator.internal.engine.ValidatorImpl.validateConstraintsForSingleDefaultGroupElement(Lorg/hibernate/validator/internal/engine/ValidationContext;Lorg/hibernate/validator/internal/engine/ValueContext;Ljava/util/Map;Ljava/lang/Class;Ljava/util/Set;Lorg/hibernate/validator/internal/engine/groups/Group;)Z (ValidatorImpl.java:527)
at org.hibernate.validator.internal.engine.ValidatorImpl.validateConstraintsForDefaultGroup(Lorg/hibernate/validator/internal/engine/ValidationContext;Lorg/hibernate/validator/internal/engine/ValueContext;)V (ValidatorImpl.java:495)
at org.hibernate.validator.internal.engine.ValidatorImpl.validateConstraintsForCurrentGroup(Lorg/hibernate/validator/internal/engine/ValidationContext;Lorg/hibernate/validator/internal/engine/ValueContext;)V (ValidatorImpl.java:460)
at org.hibernate.validator.internal.engine.ValidatorImpl.validateInContext(Lorg/hibernate/validator/internal/engine/ValueContext;Lorg/hibernate/validator/internal/engine/ValidationContext;Lorg/hibernate/validator/internal/engine/groups/ValidationOrder;)Ljava/util/Set; (ValidatorImpl.java:410)
at org.hibernate.validator.internal.engine.ValidatorImpl.validate(Ljava/lang/Object;[Ljava/lang/Class;)Ljava/util/Set; (ValidatorImpl.java:207)
at org.hibernate.cfg.beanvalidation.BeanValidationEventListener.validate(Ljava/lang/Object;Lorg/hibernate/EntityMode;Lorg/hibernate/persister/entity/EntityPersister;Lorg/hibernate/engine/spi/SessionFactoryImplementor;Lorg/hibernate/cfg/beanvalidation/GroupsPerOperation$Operation;)V (BeanValidationEventListener.java:116)
at org.hibernate.cfg.beanvalidation.BeanValidationEventListener.onPreUpdate(Lorg/hibernate/event/spi/PreUpdateEvent;)Z (BeanValidationEventListener.java:88)
at org.hibernate.action.internal.EntityUpdateAction.preUpdate()Z (EntityUpdateAction.java:317)
at org.hibernate.action.internal.EntityUpdateAction.execute()V (EntityUpdateAction.java:175)
at org.hibernate.engine.spi.ActionQueue.executeActions(Lorg/hibernate/engine/spi/ExecutableList;)V (ActionQueue.java:604)
at org.hibernate.engine.spi.ActionQueue.lambda$executeActions$1(Ljava/lang/Class;Lorg/hibernate/engine/spi/ActionQueue$ListProvider;)V (ActionQueue.java:478)
at org.hibernate.engine.spi.ActionQueue$$Lambda$1767+0x0000000801a8cc10.accept(Ljava/lang/Object;Ljava/lang/Object;)V ()
at java.util.LinkedHashMap.forEach(Ljava/util/function/BiConsumer;)V (LinkedHashMap.java:721)
at org.hibernate.engine.spi.ActionQueue.executeActions()V (ActionQueue.java:475)
at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(Lorg/hibernate/event/spi/EventSource;)V (AbstractFlushingEventListener.java:344)
at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(Lorg/hibernate/event/spi/FlushEvent;)V (DefaultFlushEventListener.java:40)
at org.hibernate.internal.SessionImpl$$Lambda$1766+0x0000000801a8c9e0.accept(Ljava/lang/Object;Ljava/lang/Object;)V ()
at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(Ljava/lang/Object;Ljava/util/function/BiConsumer;)V (EventListenerGroupImpl.java:107)
at org.hibernate.internal.SessionImpl.doFlush()V (SessionImpl.java:1407)
at org.hibernate.internal.SessionImpl.managedFlush()V (SessionImpl.java:489)
at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion()V (SessionImpl.java:3303)
at org.hibernate.internal.SessionImpl.beforeTransactionCompletion()V (SessionImpl.java:2438)
at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion()V (JdbcCoordinatorImpl.java:449)
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback()V (JdbcResourceLocalTransactionCoordinatorImpl.java:183)
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$300(Lorg/hibernate/resource/transaction/backend/jdbc/internal/JdbcResourceLocalTransactionCoordinatorImpl;)V (JdbcResourceLocalTransactionCoordinatorImpl.java:40)
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit()V (JdbcResourceLocalTransactionCoordinatorImpl.java:281)
at org.hibernate.engine.transaction.internal.TransactionImpl.commit()V (TransactionImpl.java:101)
at org.springframework.orm.jpa.JpaTransactionManager.doCommit(Lorg/springframework/transaction/support/DefaultTransactionStatus;)V (JpaTransactionManager.java:562)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(Lorg/springframework/transaction/support/DefaultTransactionStatus;)V (AbstractPlatformTransactionManager.java:743)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(Lorg/springframework/transaction/TransactionStatus;)V (AbstractPlatformTransactionManager.java:711)
at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(Lorg/springframework/transaction/interceptor/TransactionAspectSupport$TransactionInfo;)V (TransactionAspectSupport.java:654)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(Ljava/lang/reflect/Method;Ljava/lang/Class;Lorg/springframework/transaction/interceptor/TransactionAspectSupport$InvocationCallback;)Ljava/lang/Object; (TransactionAspectSupport.java:407)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(Lorg/aopalliance/intercept/MethodInvocation;)Ljava/lang/Object; (TransactionInterceptor.java:119)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed()Ljava/lang/Object; (ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed()Ljava/lang/Object; (CglibAopProxy.java:762)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(Ljava/lang/Object;Ljava/lang/reflect/Method;[Ljava/lang/Object;Lorg/springframework/cglib/proxy/MethodProxy;)Ljava/lang/Object; (CglibAopProxy.java:707)
at com.company.coreapi.restapi.app.controller.participants.A020AppUsageController$$EnhancerBySpringCGLIB$$e52ac6e3.postAppUsage()V ()
Code: Select all
Content of the message:
Validating value ContactHistoryEntity
[entries=
[ContactHistoryEntryEntity[
complaintReason=,
Code: Select all
@Entity
public class ParticipantEntity extends AbstractCoreEntity {
@NotNull
@OneToOne(optional = false, fetch = FetchType.LAZY)
@JoinColumn(name = "CONTACTHISTORY_ID")
ContactHistoryEntity contactHistory;
Code: Select all
@Entity
public class ContactHistoryEntity extends AbstractCoreEntity {
@OneToMany(mappedBy = "contactHistory", cascade = CascadeType.ALL, orphanRemoval = true, fetch = FetchType.EAGER)
@OrderBy("defTime")
private List entries = new ArrayList();
- Loglevels sind auf Info und nicht im Trace
Keine speziellen Anmerkungen zur Validierung, nur das @Slfj von Lombok - Keine Protokollierung an diesen Stellen aus eigener Protokollierung
Warum? Logback tritt hier ein? Die Validierung ist erfolgreich (nicht null) und warum ist eine Meldung erforderlich?
Wie kann man das verhindern?
Lösungsidee noch nicht getestet
ContactHistoryEntity.toString mit einer kürzeren Version überschreiben. Auf jeden Fall wäre es interessant, warum eine Logback-Nachricht generiert werden muss.