這篇文章描述了我最近使用Hibernate ORM的經驗。 多年以來，該框架并沒有讓我感到驚訝，您可能會在使用它時遇到性能問題。 我以為我已經看完了，但是這次我又措手不及了。

該問題的基礎是在對一個完全不相關的庫進行故障排除時建立的，該庫導致我們的生產服務器之一出現問題。 為了收集有關手頭原始問題的更多見解，我們增加了logback配置中的詳細信息。

因此，產生以下描述的效果所需要的只是org。*軟件包從ERROR到WARN的日志冗長更改。 進行必要的測試后，我們從日志中收集了信息，卻忘記了改回日志級別。

在日志配置傳播到生產后不久，問題就在第二天開始暴露出來。 突然之間，我們的監視開始報告左右生產中的問題。 當我們吃自己的狗食并使用Plumbr Performance Monitoring解決方案監視我們自己的服務時，我們收到的信息是，發布給最終用戶的某些服務面臨著與延遲相關的問題。

檢查公開的信息后，很明顯一切似乎都受到了影響。 這次不是整個性能較差的代碼位于單個服務/模塊中的更典型的情況，而是整個JVM似乎行為異常。 此外，似乎對于99％的事務，延遲幾乎沒有受到影響，但是幾乎所有服務的最壞情況下的延遲都已經消失了。

對我們來說幸運的是，問題的根源正盯著我們。 Plumbr檢測到的根本原因列表已將罪魁禍首暴露給源代碼中的一行。 我們面臨的是成千上萬的調用，它們正在JDBC上執行SHOW WARNINGS語句。

此外，Plumbr根本原因檢測還向我們暴露了進行調用的調用堆棧：

com.mysql.jdbc.StatementImpl.executeQuery():1500 com.mysql.jdbc.SQLError.convertShowWarningsToSQLWarnings():714 com.mysql.jdbc.SQLError.convertShowWarningsToSQLWarnings():666 com.mysql.jdbc.StatementImpl.getWarnings():2299 com.zaxxer.hikari.pool.HikariProxyPreparedStatement.getWarnings():N/A org.hibernate.engine.jdbc.spi.SqlExceptionHelper.handleAndClearWarnings():320 org.hibernate.engine.jdbc.spi.SqlExceptionHelper.logAndClearWarnings():273 org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.close():529 ... cut for brevity ... org.hibernate.jpa.spi.AbstractEntityManagerImpl.merge():1196 sun.reflect.GeneratedMethodAccessor.invoke():N/A sun.reflect.DelegatingMethodAccessorImpl.invoke():43 java.lang.reflect.Method.invoke():606 org.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler.invoke():293 com.sun.proxy.$Proxy.merge():N/A eu.plumbr.portal.service.ServiceDao.save():21

有了調用堆棧，我們直接進入了休眠狀態。 顯然，Hibernate在SqlExceptionHelper.handeAndClearWarnings（）方法中包含以下代碼：

public void handleAndClearWarnings(Statement statement, WarningHandler handler) {// See HHH-9174. Statement#getWarnings can be an expensive call for many JDBC libs. Don't do it unless// the log level would actually allow a warning to be logged.if (LOG.isEnabled(Level.WARN)) {try {walkWarnings( statement.getWarnings(), handler );}catch (SQLException sqlException) {// cut for brevity}//cut for brevity }

在這里，我們有罪魁禍首，正視著我們。 對日志配置的更改已啟用了Hibernate模塊的WARN級別日志記錄。 反過來，這導致對數據庫的每次訪問都執行重復的SQL查詢“ SHOW WARNINGS ”，實際上使對數據庫的JDBC調用次數增加了一倍。

根據Google的說法， 這個問題相當普遍。 這是Hibernate作者的合理設計嗎？ 一方面，該功能確實有用：如果您的JDBC訪問已生成任何警告，則可能希望公開此信息。 乍一看，當前的實現絕對是合乎邏輯的：配置是否要查看一些警告，然后配置日志記錄框架。

似乎毫無意義的是系統絕對不相關的方面（日志記錄和數據庫性能）之間的高度凝聚力。 配置日志記錄會導致數據庫調用數量增加一倍？ 完全出乎意料的蝴蝶效果。 如果沒有正確的工具，則可以對增加的數據庫負載進行故障排除，很幸運。 這次，我們在20分鐘內修補了該問題，然后繼續進行工作，但是我只能想象，如果沒有適當的監控工具來進行故障排除，需要花費多長時間。

翻譯自: https://www.javacodegeeks.com/2016/01/how-we-accidentally-doubled-our-jdbc-traffic-with-hibernate.html

總結

以上是生活随笔為你收集整理的我们如何意外地将Hibernate的JDBC流量增加了一倍的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。