使用 Lightrun 調試 Spring 方法註解

一、簡介

我們最近研究了 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 在方法調用周圍自動插入代碼以緩存結果並返回緩存的值，而不是在認為合適的情況下實際調用該方法。

眾所周知，緩存很難調試，因為緩存命中將意味著永遠不會調用底層代碼，因此不會觸發其中的任何日誌。這包括我們直接寫入代碼的日誌，也包括 Lightrun 添加的日誌。然而，Lightrun 允許我們將這些日誌放在我們的代碼和緩存代碼本身中。

和以前一樣，我們可以使用快照來查看我們的代碼以及 Spring 在其間注入的所有位：

抓拍框

在這裡我們可以看到我們的控制器和服務以及 Spring 插入其中的所有調用。在這種情況下，感興趣的類是CacheInterceptor和CacheAspectSupport 。如果我們進一步觀察，我們會發現CacheInterceptor實際上是CacheAspectSupport的子類，所以這實際上都是一個類。

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

檢查代碼

在此期間，我們可以看到我們正在檢查緩存是命中還是未命中並採取相應的行動。因此，我們可以使用 Lightrun 在此處添加一些日誌，以準確查看發生了什麼，無論是緩存命中還是未命中：

第 414 行的日誌允許我們查看是否有緩存命中或未命中。
第 421 行的日誌允許我們指示我們將調用我們的基礎方法。
第 423 行之後的日誌向我們顯示了返回值，無論是緩存命中還是未命中。

我們現在可以準確地看到我們的緩存結果發生了什麼：

在這裡我們可以看到兩次調用來檢索相同的資源。第一個進來，緩存未命中，然後繼續調用真正的服務。第二個進入，緩存命中，所以真正的服務沒有被調用。

如果沒有 Lightrun，我們最多只能看到控制器在兩種情況下都被調用，而服務僅在第一種情況下被調用，但我們不知道為什麼會這樣。

4.調試請求映射

Spring WebMVC 是 Spring 框架的重要組成部分，也是它處理 HTTP 請求並將它們轉發到正確控制器的基礎。但是，如果出現問題，準確地計算出發生了什麼可能會令人沮喪。

Lightrun 為我們提供了一些額外的工具，可以像以前一樣準確地查看發生了什麼。然而，這需要付出更多的努力才能實現，因為 Spring 的內部結構在這方面更為複雜。

和以前一樣，首先，我們需要一種方法。我們通過向任何控制器添加一個快照，然後觸發它來獲取顯示導致控制器方法的調用的堆棧跟踪來做到這一點：

Lightrun

經過一些探索，我們可以看到DispatcherServlet.doDispatch()很有趣，因為它調用了getHandler() 。這似乎是確定用於給定 HTTP 請求的處理程序的地方。這向我們展示了整個 Spring 中的幾個堆棧框架，它們通向我們的控制器。

看看這個，我們可以看到它迭代了一組HandlerMapping實例，並依次詢問每個實例是否可以處理請求：

獲取處理程序

這是一個有幾個選項的抽象方法，所以讓我們在 like 1261 上添加一條日誌語句，看看實際發生了什麼：

這立即向我們展示了涉及的處理程序映射。而且，重要的是，最後一個是為這個請求返回了一些東西的那個，所以我們接下來看一下。

RequestMappingHandlerMapping中getHandler()的實際實現是在超類AbstractHandlerMapping中。然而，這在 AbstractHandlerMethodMapping 中的getHandlerInternal()方面立即起作用AbstractHandlerMethodMapping.這在lookupHandlerMethod()方面有效，所以讓我們看看那裡。

第一個有趣的部分似乎是addMatchingMappings(),因此我們將向其中添加一個日誌，看看到底發生了什麼：

毫不奇怪，其中大多數都沒有返回匹配項。然而，有人做到了。這表明我們有一個與我們的請求相匹配的“GET /{id}”處理程序——這正是我們所期望的。如果這些都沒有返回匹配項，我們會立即知道問題出在請求映射上。例如，如果我們使用不受支持的 HTTP 方法或不正確的 URI 路徑進行 HTTP 調用，那麼我們會在這裡看到所有內容的null匹配，這會告訴我們問題出在哪裡：

到目前為止，如果需要，我們可以進一步診斷對處理程序方法的調用（如果這是問題所在）。但如果問題是我們根本沒有被調用，那麼我們已經理解為什麼會這樣並且可以解決問題。

5.結論

在本文中，我們查看了一些 Spring 註釋示例以及如何使用 Lightrun 診斷它們發生了什麼。特別是，我們已經看到瞭如何使用其中一些工具來了解什麼時候工作正常，什麼時候不工作。

這些相同的技術同樣適用於任何其他庫和框架。為什麼不在下次需要診斷正在使用的其他庫時嘗試一下呢？

如果您想閱讀有關 Lightrun 的更多信息，請查看他們的博客。

本作品係原創或者翻譯，採用《署名-非商業性使用-禁止演繹4.0國際》許可協議