Las minas en rendimiento están esperando en las alas: parte 2

Al preparar el último artículo, un curioso ejemplo atrapado en una de nuestras aplicaciones me llamó la atención. Lo diseñé como un artículo separado, que estás leyendo actualmente.

La esencia es extremadamente simple: al crear un informe y escribirlo en la base de datos, de vez en cuando comenzamos a recibir OOME. El error fue flotante: en algunos datos se reprodujo constantemente, en otros nunca se reprodujo.

En el estudio de tales desviaciones, la secuencia de acciones es clara:

• Lanzamos la aplicación en un entorno aislado con configuraciones similares a productos, sin olvidar el codiciado indicador -XX:+HeapDumpOnOutOfMemoryError , para que la VM cree un montón del montón cuando esté lleno
• realizar acciones que conducen a una caída
• tomar el yeso resultante y comenzar a examinarlo

En una primera aproximación, dos piezas iguales de 71 MB son claramente visibles, y la más grande es 6 veces más grande.

Fumar brevemente la cadena de llamadas y los códigos fuente ayudó a marcar todos los "".

 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) 

El proyecto usó la combinación usual Spring + Hibernate para tales aplicaciones. En algún momento, para estudiar los aumentos de la aplicación en la base de datos (que es lo que hace la mayor parte del tiempo), DataSource fue envuelto en p6spy . Esta es una biblioteca simple y extremadamente útil diseñada para interceptar y registrar consultas de la base de datos, así como para medir su tiempo de ejecución. Lo más destacado es la grabación de una consulta que va a la base de datos con todos los argumentos, es decir, tomar la consulta del registro puede ejecutarla inmediatamente en la consola sin preocuparse por la conversión de argumentos (¿Hibernate escribe en lugar de ellos ? ), Lo cual es conveniente cuando se utiliza @Convert o en presencia de campos de tipo Date / LocalDate / LocalTime y sus derivados. En mi humilde opinión, una cosa extremadamente útil en la economía del desarrollador sangriento E.

Así es como se ve la entidad que contiene el informe:

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

El uso de una matriz de bytes es muy conveniente cuando una entidad se usa solo para guardar / descargar un informe, y la mayoría de las herramientas para trabajar con xslx / pdf de fábrica incluyen la capacidad de crear un libro / documento de esta forma.

Y luego sucedió algo terrible e imprevisto: la combinación de Hibernate, una serie de bytes y p6spy se convirtió en una bomba de tiempo, que por el momento estaba funcionando silenciosamente, y cuando había demasiados datos, había explosiones.

Como se señaló anteriormente, al guardar la entidad, p6spy interceptó la solicitud y la escribió en el registro con todos los argumentos. En este caso, solo hay 2 de ellos: la clave y el informe en sí. Los desarrolladores de P6spy decidieron que si el argumento es una matriz de bytes, sería bueno convertirlo a hexadecimal. En la versión 3.6.0 que estamos usando, esto se hizo así:

 // 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); } 

Como resultado, algo así se escribió en el registro

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

Ya ves, si? En el caso de una combinación de circunstancias fallida, lo siguiente podría aparecer en la memoria de la aplicación:

• informe, como una matriz de bytes
• matriz de caracteres derivada de la matriz de bytes
• cadena obtenida de la matriz de caracteres obtenida de la matriz de bytes
• StringBuilder , que incluye una copia de la cadena obtenida de la matriz de caracteres obtenida de la matriz de bytes
• una cadena que incluye una copia de la matriz dentro de StringBuilder , que incluye una copia de la cadena obtenida de la matriz de caracteres obtenida de la matriz de bytes.

En estas condiciones, una aplicación de demostración que consta de 2 clases, después de ser ensamblada y lanzada en Java 11 (es decir, con líneas comprimidas) con 1 GB de almacenamiento dinámico, puede poner un informe que pesa solo 71 MB.

Hay dos formas de resolver este problema sin tirar p6spy:

• reemplace el byte[] con java.sql.Clob (solución regular, porque los datos no se cargan inmediatamente y OutputStream alboroto con InputStream / OutputStream )
• agregue la propiedad excludebinary=true al archivo excludebinary=true (ya se ha agregado en la aplicación de prueba, solo necesita abrirlo)

En este caso, el registro de consultas es ligero y hermoso:

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

Guía de reproducción Ver README.MD

Conclusiones:

• la inmutabilidad (en filas particulares) vale caro Caro Muy querido
• si tiene tablas con datos confidenciales (apariencias, contraseñas, etc.), usa p6spy y los registros son malos, entonces ... bueno, entiende
• si tiene p6spy y está seguro de que será permanente / permanente, entonces, para las entidades grandes, tiene sentido mirar @DynamicInsert / @DynamicUpdate . El objetivo es reducir el volumen de registros creando una solicitud para cada actualización / inserción individual. Sí, estas consultas se crearán sobre la marcha cada vez más, pero en los casos en que una entidad actualice 1 campo de cada 20, este tipo de compromiso puede ser útil. Consulte la documentación de las anotaciones anteriores para obtener más información.

Eso es todo por hoy :)