知識庫 / Spring RSS 訂閱

1. 簡介

我們最近研究了 Lightrun – 一個開發者可觀測性平台 – 以瞭解它能為我們提供哪些幫助，以便更好地觀察和理解我們的應用程序。

Spring 大量使用註解來控制各種功能，這可以以多種方式實現。 這可以使編寫應用程序變得非常高效 – 我們只需要添加適當的註解來啓用功能。 但是，當這種情況發生時，診斷可能會令人沮喪，因為沒有直接的方法調用可以進行檢查。

在本文中，我們將探討如何使用 Lightrun 來診斷 Spring 註解在我們的應用程序中的工作方式。

2. 調試事務邊界

Spring 使用 @Transactional 註解來標記應該在事務中執行的方法。這通過 Spring 在構造時檢測該註解並構造 JDK 代理來包裝我們的類實例來實現。該代理負責處理所有事務邊界的細節。 這確保了方法執行前事務開始，並在完成後正確清理。

因此，調試事務意味着我們首先必須確定需要查找的位置。 這最容易通過在我們的事務方法中添加快照並執行它，從而捕獲堆棧跟蹤來實現：

在這裏我們可以看到從我們的控制器 – deleteTask:74, TasksController – 到我們的事務性服務 – deleteTaskById: 40, TasksService 之間的整個堆棧跟蹤。 由於我們的代碼是直接方法調用，Spring 已經將兩者之間的所有內容插入了其中。

所以現在我們需要確定這些中哪些重要。 許多條目關注代理和需要進行反射調用來使事情正常工作。 但是，中間有三個條目非常集中於事務：

• invoke:119, TransactionInterceptor
• invokeWithinTransaction:388, TransactionAspectSupport
• proceedWithInvocation:123, TransactionInterceptor$1

此外，我們可以從這些方法名稱中推斷出大致正在發生什麼。 似乎 invokeWithinTransaction 是 Spring 代碼中管理事務邊界的地方。 因此，這是我們調試正在發生的事情的地方。

如果我們在 IDE 中打開 這段代碼，我們可以看到這裏正在發生的事情：

為了更好地瞭解這如何影響我們的代碼，我們可以使用 Lightrun 在運行時添加日誌到一些適當的行。 例如：

• 一個在第 382 行後的日誌顯示新開始的事務。
• 在第 392 行的日誌顯示異常是否已中止事務。
• 最後，在第 408 行的日誌顯示事務結束時的結果。

如果我們在控制器和服務中添加日誌 – 這樣我們就可以在事務內部和外部看到操作 – 那麼我們就可以看到正在發生的事情：

所以我們可以看到這裏啓動了三個 Spring 事務 – 其中一個在服務調用外部，另外兩個在內部。 這兩個在服務內部與我們這裏涉及兩個存儲庫調用的事實相符。 但是，因為它們都具有 PROPAGATION_REQUIRED，所以實際上它們參與了同一個數據庫事務。

這已經給了我們關於事務何時開始和結束、是否會回滾以及輸出是什麼的信息。 而且我們沒有中斷正在運行的應用程序 就完成了這一切。

3. 調試緩存邊界

Spring 通過在方法調用中添加適當的註解來支持緩存方法結果。 這將導致 Spring 自動在方法調用周圍插入代碼以緩存結果並返回緩存值，而不是在認為適當時實際調用方法。

緩存調試 notoriously 困難，因為緩存命中意味着底層代碼從未被調用，因此不會觸發其中的任何日誌。 這包括我們在代碼中直接編寫的日誌，以及 Lightrun 添加的日誌。 但是，Lightrun 允許我們在代碼和緩存代碼本身中放置這些日誌。

如前所述，我們可以使用 Snapshot 來查看我們的代碼以及 Spring 在其間注入的所有內容：

在這裏我們可以看到我們的控制器和服務以及 Spring 在其間插入的所有調用。 在這種情況下，我們感興趣的類是 CacheInterceptor 和 CacheAspectSupport。 如果進一步查看，我們會看到 CacheInterceptor 實際上是 CacheAspectSupport 的子類，所以實際上這已經是同一個類。

特別是，通過 檢查代碼，我們可以看到有趣的功能在於 CacheAspectSupport.execute()：

在此過程中，我們可以看到我們正在檢查緩存是否命中或是否未命中，並相應地採取行動。 因此，我們可以使用 Lightrun 在此處添加日誌，以無論是否為緩存命中或未命中，都能夠看到究竟發生了什麼：

• 一條在第 414 行的日誌允許我們查看是否有緩存命中或未命中。
• 一條在第 421 行的日誌允許我們指示我們即將調用底層的實現方法。
• 在第 423 行之後的一條日誌顯示給我們返回值，無論是否為緩存命中或未命中。

現在我們可以準確地看到我們緩存結果的情況：

在這裏我們可以看到兩次檢索相同資源的調用。 第一個調用進來，得到緩存未命中，並繼續調用實際的服務。 第二個調用進來，得到緩存命中，因此實際的服務未被調用。

如果沒有 Lightrun，我們能看到最好的就是控制器在兩種情況下都會被調用，並且只有在第一種情況下服務才會被調用，但我們沒有任何關於為什麼會這樣做的線索。

4. Debugging 請求映射

Spring WebMVC 是 Spring 框架中的一個重要組成部分，並且對於如何處理 HTTP 請求並將其轉發到正確的控制器至關重要。 然而，如果出現問題，準確地瞭解發生了什麼可能會讓人感到沮喪。

Lightrun 賦予我們一些額外的工具，以同樣的方式查看正在發生的事情。但是，由於 Spring 的內部機制在這個領域更復雜，實現起來需要更多的工作。

正如之前一樣，首先我們需要進入其中。我們通過在任何控制器中添加快照並觸發它來做到這一點，以獲取顯示導致控制器方法調用的堆棧跟蹤：

經過一番探索，我們發現 DispatcherServlet.doDispatch() 有趣，因為它有一個對 getHandler() 的調用。這似乎是確定給定 HTTP 請求用於處理的句柄的地方。這向我們展示了 Spring 中的多個堆棧幀，這些堆棧幀都指向我們的控制器。

查看內部實現，我們可以看到它迭代一個 HandlerMapping 實例的集合，並輪流詢問每個實例是否可以處理請求：

這是一個抽象方法，具有一些選項，因此讓我們在 1261 處添加一個日誌語句，看看實際發生了什麼：

這立即顯示了參與的句柄映射。而且，最重要的是，最後一個是返回了該請求的那個，因此讓我們接下來查看它。

在DispatcherServlet 中 getHandler() 的實際實現位於父類 RequestMappingHandlerMapping 中。但是，這在 terms of getHandlerInternal() within AbstractHandlerMethodMapping 方面立即起作用。這在 terms of lookupHandlerMethod() 方面起作用，因此讓我們查看那裏。

似乎最有趣的部分是 addMatchingMappings()，因此我們將添加一個日誌語句，以查看具體發生了什麼：

正如我們所期望的，大多數沒有返回匹配項。但是，一個返回了匹配項。這表明我們有一個“GET /{id}”句柄，它與我們的請求匹配——這正是我們期望的。如果這些都沒有返回匹配項，我們就會立即知道問題在於請求映射。 例如，如果我們使用不支持的 HTTP 方法或不正確的 URI 路徑發出 HTTP 調用，那麼我們就會在這些地方看到 null 匹配項，這會告訴我們問題所在：

在走這麼遠之後，如果我們需要，我們可以進一步診斷對句柄方法的調用，如果問題在於我們根本沒有被調用，那麼我們已經理解了原因，並且可以解決問題。

5. 結論

在本文中，我們探討了 Spring 註解的一些示例以及如何使用 Lightrun 來診斷這些註解的工作原理。我們尤其看到了如何利用這些工具來理解代碼何時正常工作，何時出現問題。

這些技術同樣適用於任何其他庫和框架。不妨下次您需要診斷其他庫時，嘗試使用它們。

如果您想了解更多關於 Lightrun 的信息，請查看他們的 博客。