線上故障複盤-jackson無限遞歸導緻StackOverflowError

問題現象

我們自定義了個列印controller請求參數的日志切面，線上環境突然抛出這樣的異常

com.fasterxml.jackson.databind.JsonMappingException: Infinite recursion (StackOverflowError)。

異常資訊如下：

com.fasterxml.jackson.databind.JsonMappingException: Infinite recursion (StackOverflowError) 
(through reference chain: org.springframework.web.multipart.support.StandardMultipartHttpServletRequest["request"]->
  org.apache.catalina.connector.RequestFacade["session"]->
  org.apache.catalina.session.StandardSessionFacade["servletContext"]->
  org.apache.catalina.core.ApplicationContextFacade["classLoader"]......)
  at com.fasterxml.jackson.databind.ser.std.BeanSerializerBase.serializeFields(BeanSerializerBase.java:770)
	at com.fasterxml.jackson.databind.ser.BeanSerializer.serialize(BeanSerializer.java:178)
	at com.fasterxml.jackson.databind.ser.std.ObjectArraySerializer.serializeContents(ObjectArraySerializer.java:252)
	at com.fasterxml.jackson.databind.ser.std.ObjectArraySerializer.serialize(ObjectArraySerializer.java:213)           

bug分析

切面的關鍵代碼，如下：

ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
HttpServletRequest request = attributes.getRequest();
Object[] args = joinPoint.getArgs();
int i = 0;
for (Object arg : args) {
  if (arg ==request) {
    i += 1;
    continue;
  }
  if (不是基本類型) {
    logStr.append(params[i]).append("=").append(objectMapper.writeValueAsString(arg));
  } else {
    logStr.append(params[i]).append("=").append(arg);
  }
  i += 1;
}           

根據異常資訊可推斷objectMapper.writeValueAsString(arg)執行報錯了，攔截的方法是

public RspVO info(@RequestParam("order_no") String orderNo,HttpServletRequest request)           

就兩個參數：orderNo和request，一看就知道問題出在request參數上了。但是切面代碼中有這樣一段邏輯：

if (arg ==request) {
    i += 1;
    continue;
  }           

如果參數是request的話，就忽略不列印。這段邏輯和上面的猜測互斥啊。[衰]

不管别的，先本地啟下測試一把，看看有問題嘛，跑了一把沒問題，那問題出在哪了？什麼時候這個條件arg !=request成立呢？

要不先把這個條件arg ==request注釋掉，試試看看objectMapper.writeValueAsString(arg)抛異常嗎？然後測試了一把，竟然沒有報錯，你說說這咋搞？

會不會跟環境有關系啊？要不去測試環境上看看，是不是這樣的錯誤日志？翻了個遍，沒有任何異常！開始懷疑人生了！這個異常隻影響列印日志，對業務沒啥影響，然後就把這個問題放了放。

今天突然想起來了，要不看看抛異常的位置：

at com.fasterxml.jackson.databind.ser.std.BeanSerializerBase.serializeFields(BeanSerializerBase.java:770)           

上面标注的位置，引起我的注意，這個位置就是錯誤日志中的這塊：

org.springframework.web.multipart.support.StandardMultipartHttpServletRequest["request"]->
  org.apache.catalina.connector.RequestFacade["session"]->
  org.apache.catalina.session.StandardSessionFacade["servletContext"]->
  org.apache.catalina.core.ApplicationContextFacade["classLoader"]......)           

從這裡面我發現了這個類StandardMultipartHttpServletRequest，這個隻會在檔案上傳時用到，為啥會出現在此處呢？難道他們請求使用form-data方式請求的？然後我就用form-data方式試了一把，竟然複現下了！于是和上司确認了下會不會業務方會不會用form-data請求，他說會有。

問題找到了，那怎麼解決呢？

隻需把 if (arg ==request)改成if (arg instanceof HttpServletRequest)就可以了           

反思總結

• 思維定格在request上了，日志看得不夠仔細。
• 對列印的遞歸鍊不了解，源碼：(mapE.prependPath(new JsonMappingException.Reference(bean, name));)