Les mines en performance attendent dans les coulisses: partie 2

Lors de la préparation du dernier article, un exemple curieux pris dans l'une de nos candidatures a glissé mon attention. Je l'ai conçu comme un article séparé, que vous lisez actuellement.

L'essence est extrêmement simple: lors de la création d'un rapport et de son écriture dans la base de données, de temps en temps, nous avons commencé à recevoir OOME. L'erreur flottait: sur certaines données, elle était reproduite en permanence, sur d'autres, elle n'était jamais reproduite.

Dans l'étude de ces écarts, la séquence des actions est claire:

• nous lançons l'application dans un environnement isolé avec des paramètres de type prod, sans oublier l'indicateur convoité -XX:+HeapDumpOnOutOfMemoryError , de sorte que la machine virtuelle crée un tas du tas quand il est plein
• effectuer des actions menant à une chute
• prendre le casting résultant et commencer à l'examiner

En première approximation, deux morceaux égaux de 71 Mo sont clairement visibles, et le plus gros est 6 fois plus grand.

Un court fumage de la chaîne d'appels et des codes sources a aidé à parsemer tous les "".

 Exception in thread "main" java.lang.OutOfMemoryError: Java heap space at java.base/java.util.Arrays.copyOf(Arrays.java:3745) at java.base/java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:172) at java.base/java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:538) at java.base/java.lang.StringBuilder.append(StringBuilder.java:174) at com.p6spy.engine.common.Value.quoteIfNeeded(Value.java:167) at com.p6spy.engine.common.Value.convertToString(Value.java:116) at com.p6spy.engine.common.Value.toString(Value.java:63) at com.p6spy.engine.common.PreparedStatementInformation.getSqlWithValues(PreparedStatementInformation.java:56) at com.p6spy.engine.common.P6LogQuery.logElapsed(P6LogQuery.java:203) at com.p6spy.engine.logging.LoggingEventListener.logElapsed(LoggingEventListener.java:107) at com.p6spy.engine.logging.LoggingEventListener.onAfterAnyExecute(LoggingEventListener.java:44) at com.p6spy.engine.event.SimpleJdbcEventListener.onAfterExecuteUpdate(SimpleJdbcEventListener.java:121) at com.p6spy.engine.event.CompoundJdbcEventListener.onAfterExecuteUpdate(CompoundJdbcEventListener.java:157) at com.p6spy.engine.wrapper.PreparedStatementWrapper.executeUpdate(PreparedStatementWrapper.java:100) at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:175) at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3176) at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3690) at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:90) at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604) at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:478) at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:356) at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39) at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1454) at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:511) at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3290) at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2486) at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:473) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:178) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$300(JdbcResourceLocalTransactionCoordinatorImpl.java:39) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:271) at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:104) at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:532) 

Le projet a utilisé la combinaison Spring + Hibernate habituelle pour de telles applications. À un moment donné, pour étudier les hausses de l'application dans la base de données (ce qu'il fait la plupart du temps), le DataSource a été enveloppé dans p6spy . Il s'agit d'une bibliothèque simple et extrêmement utile conçue pour intercepter et enregistrer les requêtes de base de données, ainsi que pour mesurer leur temps d'exécution. Son point culminant est l'enregistrement d'une requête qui va à la base de données avec tous les arguments, c'est-à-dire que la récupération de la requête dans le journal peut immédiatement l'exécuter dans la console sans se soucier de la conversion des arguments (Hibernate écrit-il à leur place ? ), Ce qui est pratique lorsque vous utilisez @Convert ou en présence de champs de type Date / LocalDate / LocalTime et leurs dérivés. À mon humble avis, une chose extrêmement utile dans l'économie du développeur sanglant E.

Voici à quoi ressemble l'entité contenant le rapport:

 @Entity public class ReportEntity { @Id @GeneratedValue private long id; @Lob private byte[] reportContent; } 

L'utilisation d'un tableau d'octets est très pratique lorsqu'une entité est utilisée uniquement pour enregistrer / décharger un rapport, et la plupart des outils pour travailler avec xslx / pdf prêt à l'emploi prennent en charge la possibilité de créer un livre / document sous cette forme.

Et puis une chose terrible et imprévue s'est produite: la combinaison de Hibernate, un ensemble d'octets et de p6spy s'est transformée en une bombe à retardement, qui fonctionnait tranquillement pour le moment, et quand il y avait trop de données, il y avait des explosions.

Comme indiqué ci-dessus, lors de la sauvegarde de l'entité, p6spy a intercepté la demande et l'a écrite dans le journal avec tous les arguments. Dans ce cas, il n'y en a que 2: la clé et le rapport lui-même. Les développeurs de P6spy ont décidé que si l'argument est un tableau d'octets, alors ce serait bien de le convertir en hexadécimal. Dans la version 3.6.0 que nous utilisons, cela a été fait comme ceci:

 // class com.p6spy.engine.common.Value private String toHexString(byte[] bytes) { StringBuilder sb = new StringBuilder(); for (byte b : bytes) { int temp = (int) b & 0xFF; sb.append(HEX_CHARS[temp / 16]); sb.append(HEX_CHARS[temp % 16]); } return sb.toString(); } 

 private String toHexString(byte[] bytes) { char[] result = new char[bytes.length * 2]; int idx = 0; for (byte b : bytes) { int temp = (int) b & 0xFF; result[idx++] = HEX_CHARS[temp / 16]; result[idx++] = HEX_CHARS[temp % 16]; } return new String(result); } 

En conséquence, quelque chose comme ça a été écrit dans le journal

 insert into report_entity (report_content, id) values ('6C6F..........7565', 1); 

Tu vois, oui? En cas d'échec d'une combinaison de circonstances, les éléments suivants peuvent apparaître dans la mémoire de l'application:

• rapport, sous la forme d'un tableau d'octets
• tableau de caractères dérivé du tableau d'octets
• chaîne obtenue à partir d'un tableau de caractères obtenu à partir d'un tableau d'octets
• StringBuilder , qui inclut une copie de la chaîne obtenue à partir du tableau de caractères obtenu à partir du tableau d'octets
• une chaîne qui inclut une copie du tableau à l'intérieur de StringBuilder , qui comprend une copie de la chaîne obtenue à partir du tableau de caractères obtenu à partir du tableau d'octets.

Dans ces conditions, une application de démonstration composée de 2 classes, après avoir été assemblée et lancée sur Java 11 (c'est-à-dire avec des lignes compressées) avec 1 Go de tas, vous pouvez mettre un rapport ne pesant que 71 Mo!

Il existe deux façons de résoudre ce problème sans jeter p6spy:

• remplacer l' byte[] par java.sql.Clob (solution java.sql.Clob , car les données ne sont pas chargées immédiatement et l'agitation avec InputStream / OutputStream )
• ajoutez la propriété excludebinary=true au fichier excludebinary=true (elle a déjà été ajoutée dans l'application de test, il vous suffit de l'ouvrir)

Dans ce cas, le journal des requêtes est léger et beau:

 insert into report_entity (report_content, id) values ('[binary]', 1); 

Guide de lecture Voir README.MD

Conclusions:

• l'immuabilité (en particulier les lignes) vaut cher Cher TRÈS CHER
• si vous avez des tableaux avec des données sensibles (apparences, mots de passe, etc.), vous utilisez p6spy, et les logs sont mauvais, alors ... eh bien, vous comprenez
• si vous avez p6spy et que vous êtes sûr qu'il sera permanent / permanent, alors pour les grandes entités, il est logique de regarder @DynamicInsert / @DynamicUpdate . Le but est de réduire le volume des journaux en créant une demande pour chaque mise à jour / insertion individuelle. Oui, ces requêtes seront créées à la volée à chaque fois, mais dans les cas où une entité met à jour 1 champ sur 20, ce type de compromis peut être utile. Consultez la documentation des annotations ci-dessus pour plus d'informations.

C'est tout pour aujourd'hui :)