Tambang di bawah kinerja sedang menunggu di sayap: bagian 2

Dalam persiapan artikel terakhir, satu contoh aneh yang tertangkap dalam salah satu aplikasi kami membuat perhatian saya meleset. Saya mendesainnya sebagai artikel terpisah, yang sedang Anda baca.

Intinya sangat sederhana: ketika membuat laporan dan menulisnya ke database, dari waktu ke waktu kami mulai menerima OOME. Kesalahan mengambang: pada beberapa data itu direproduksi terus-menerus, pada yang lain itu tidak pernah direproduksi.

Saat memeriksa penyimpangan tersebut, urutan tindakannya jelas:

• kami meluncurkan aplikasi dalam lingkungan yang terisolasi dengan pengaturan seperti sebelumnya, tanpa melupakan flag yang diidam -XX:+HeapDumpOnOutOfMemoryError , sehingga VM membuat heap of heap ketika penuh
• melakukan tindakan yang mengarah ke jatuh
• ambil gips yang dihasilkan dan mulai memeriksanya

Dalam perkiraan pertama, dua bagian yang sama dari 71 MB terlihat jelas, dan yang terbesar adalah 6 kali lebih besar.

Merokok singkat dari rantai panggilan dan kode sumber membantu mengatasi semua "".

 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) 

Proyek ini menggunakan kombinasi Spring + Hibernate biasa untuk aplikasi seperti itu. Pada titik tertentu, untuk mempelajari lonjakan aplikasi dalam basis data (yang merupakan hal yang paling sering dilakukan), DataSource dibungkus p6spy . Ini adalah perpustakaan sederhana dan sangat berguna yang dirancang untuk mencegat dan mencatat permintaan basis data, serta mengukur waktu pelaksanaannya. Sorotnya adalah rekaman kueri yang masuk ke basis data dengan semua argumen, mis., Mengambil kueri dari log dapat langsung mengeksekusinya di konsol tanpa repot dengan konversi argumen (apakah Hibernate menulis alih-alih ? ), Mana yang nyaman saat menggunakan @Convert atau di hadapan bidang tipe Date / LocalDate / LocalTime dan turunannya. IMHO, suatu hal yang sangat berguna dalam ekonomi pengembang E.

Seperti inilah bentuk entitas yang berisi laporan:

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

Menggunakan array byte sangat nyaman ketika entitas digunakan hanya untuk menyimpan / membongkar laporan, dan sebagian besar alat untuk bekerja dengan xslx / pdf di luar kotak mendukung kemampuan untuk membuat buku / dokumen dalam formulir ini.

Dan kemudian hal yang mengerikan dan tidak terduga terjadi: kombinasi Hibernate, array byte dan p6spy berubah menjadi bom waktu, yang diam-diam terus berdetak untuk saat ini, dan ketika ada terlalu banyak data, ada ledakan.

Seperti disebutkan di atas, saat menyimpan entitas, p6spy mencegat permintaan dan menulisnya ke log dengan semua argumen. Dalam hal ini, hanya ada 2 di antaranya: kunci dan laporan itu sendiri. Pengembang P6spy memutuskan bahwa jika argumennya adalah array byte, maka alangkah baiknya mengonversinya menjadi heksadesimal. Di versi 3.6.0 yang kami gunakan, ini dilakukan seperti ini:

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

Akibatnya, sesuatu seperti ini ditulis ke log

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

Anda mengerti, ya? Jika terjadi kombinasi keadaan yang tidak berhasil, berikut ini dapat muncul dalam memori aplikasi:

• laporan, sebagai array byte
• array karakter diturunkan dari byte array
• string yang diperoleh dari array karakter diperoleh dari byte array
• StringBuilder , yang mencakup salinan string yang diperoleh dari array karakter yang diperoleh dari array byte
• string yang menyertakan salinan array di dalam StringBuilder , yang mencakup salinan string yang diperoleh dari array karakter yang diperoleh dari array byte.

Dalam kondisi ini, aplikasi demonstrasi yang terdiri dari 2 kelas, setelah dirakit dan diluncurkan di Java 11 (mis. Dengan saluran terkompresi) dengan 1 GB tumpukan, Anda dapat menempatkan laporan dengan berat hanya 71 MB!

Ada dua cara untuk mengatasi masalah ini tanpa membuang p6spy:

• ganti byte[] dengan java.sql.Clob (solusi begitu-begitu, karena data tidak dimuat segera dan rewel dengan InputStream / OutputStream )
• tambahkan excludebinary=true properti ke file excludebinary=true (ini telah ditambahkan dalam aplikasi tes, Anda hanya perlu membukanya)

Dalam hal ini, log kueri ringan dan indah:

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

Panduan Putar Ulang Lihat README.MD

Kesimpulan:

• kekekalan (khususnya baris) bernilai mahal Mahal SANGAT SAYANG
• jika Anda memiliki tabel dengan data sensitif (penampilan, kata sandi, dll.), Anda menggunakan p6spy, dan log-nya buruk, maka ... yah, Anda mengerti
• jika Anda memiliki p6spy dan Anda yakin itu akan secara permanen / permanen, maka untuk entitas besar masuk akal untuk melihat @DynamicInsert / @DynamicUpdate . Intinya adalah untuk mengurangi volume log dengan membuat permintaan untuk setiap pembaruan / penyisipan individu. Ya, pertanyaan ini akan dibuat setiap saat sekali lagi, tetapi dalam kasus di mana entitas memperbarui 1 bidang dari 20, kompromi semacam ini mungkin berguna. Lihat dokumentasi untuk penjelasan di atas untuk informasi lebih lanjut.

Itu saja untuk hari ini :)