Programmiererforum

by **Guest** » 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>

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 %
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

Der Stacktrace des Threads:

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 ()

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.

Code: Select all

Content of the message:
Validating value ContactHistoryEntity
[entries=
[ContactHistoryEntryEntity[
complaintReason=,

In meinem Controller aktualisiere ich meine ParticipantEntity, die die ContactHistoryEntity enthält, in der ich die NotNull-Annotation habe

Code: Select all

@Entity
public class ParticipantEntity extends AbstractCoreEntity {
@NotNull
@OneToOne(optional = false, fetch = FetchType.LAZY)
@JoinColumn(name = "CONTACTHISTORY_ID")
ContactHistoryEntity contactHistory;

die andere Entität:

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();

Was ich überprüft habe

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

Frage
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.

Programmiererforum

OutOfMemory aufgrund einer großen Protokollierungsmeldung im Logback, die durch die Validierung der Hibernate-Bean ausge

Post a reply

Expand view Topic review: OutOfMemory aufgrund einer großen Protokollierungsmeldung im Logback, die durch die Validierung der Hibernate-Bean ausge