【茶包射手日記】詭異的 WebApi 呼叫錯誤，奇妙的偵錯技巧

分享前陣子用奇妙偵錯技巧解掉好氣又好笑低級茶包的故事。

有個網站功能用 WebAPI 呼叫第三方服務執行作業，平時不常用，某日接到報案回報功能異常，貌似呼叫 WebAPI 失敗，但錯誤訊息模糊看不出哪裡出了問題。該 WebAPI 用類似先前範例教學：使用 ASP.NET MVC 打造 WebAPI 服務的方式開發，方法有用 try {… } catch {…} 包住，catch 到錯誤會傳回 ApiError 物件，而呼叫端也加了多重 try / catch 保護，理論上要能精準反映錯誤資訊：

using Newtonsoft.Json;
using System;
using System.Collections.Generic;
using System.Configuration;
using System.IO;
using System.Linq;
using System.Net;
using System.Text;
using System.Web;

namespace MyWeb.Models
{
    public class ExtFuncs
    {
        static string WebApiUrl = ConfigurationManager.AppSettings["WebApiUrl"];

        public static ApiResult<T> CallWebApi<T>(string methodName, Dictionary<string, object> args)
        {
            WebClient wc = new WebClient();

            string url = WebApiUrl + methodName;

            wc.Headers.Add("content-type", "application/json");
            string json = string.Empty;
            try
            {
                byte[] buff = wc.UploadData(url, "POST",
                    Encoding.UTF8.GetBytes(JsonConvert.SerializeObject(args)));
                json = Encoding.UTF8.GetString(buff);
            }
            catch (WebException we)
            {
                string resp = null;
                if (we.Response == null)
                    throw new ApplicationException("Web API呼叫錯誤：" + we.Message);
                using (StreamReader sr = new StreamReader(we.Response.GetResponseStream()))
                {
                    resp = sr.ReadToEnd();
                }
                throw new ApplicationException("WebAPI呼叫錯誤，詳細訊息請參考InnerException", 
                    new ApplicationException(resp));
            }
            ApiResult<T> ar = null;
            try
            {
                ar = JsonConvert.DeserializeObject<ApiResult<T>>(json);
            }
            catch (Exception ex)
            {
                throw new ApplicationException("WebAPI傳回結果格式有誤，詳細訊息請參考InnerException: " + ex.Message, 
                    new ApplicationException("ERROR JSON:" + json));
            }
            return ar;
        }
    }
}

依我的理解，照這個程式寫法，若方法名稱不對會得到 HTTP 404；傳入參數無法反序化應得到 HTTP 500；若參數正確傳入但 WebAPI 方法發生例外會以 HTTP 200 傳回 ApiError 物件；若傳回的 ApiResult/ApiError JSON 無法解析會被 try/catch 攔截顯示「WebAPI傳回結果格式有誤」；若無法連上 WebAPI 網站會得到「Web API呼叫錯誤：無法連接至遠端伺服器」；權限問題會有 HTTP 401；網站故障應該是 HTTP 503，幾乎都考慮的都考慮到了，但偏偏我得到一個古怪錯誤訊息 - 「Web API呼叫錯誤：在 WebClient 要求期間發生例外狀況。」，換言之，WebClient.UploadData 觸發了 WebException，但 Response == null。手動測試該 WebAPI URL 回應正確，確認服務主機狀態正常，到底是怎麼一回事？

卡關很久，左思右想想不出可能的原因，而線上環境很難改程式偵錯，故我想從觀察網路傳輸下手，卻又沒有 Fiddler 或 Wireshark 可用，於是我想起古老的 .NET 網路傳輸偵錯技巧 - 側錄 .NET 程式網路傳輸內容，這招對 ASP.NET 也有效。

參考微軟文件 - How to: Configure network tracing，我在 web.config 加入設定：(註：記得加<trace autoflush="true"/>，確保 Log 即時更新)

  <system.diagnostics>
    <sources>
      <source name="System.Net">
        <listeners>
          <add name="MyNetTrace"/>
        </listeners>
      </source>
      <source name="System.Net.Http">
        <listeners>
          <add name="MyNetTrace"/>
        </listeners>
      </source>
      <source name="System.Net.Sockets">
        <listeners>
          <add name="MyNetTrace"/>
        </listeners>
      </source>
    </sources>
    <sharedListeners>
      <add name="MyNetTrace"
           type="System.Diagnostics.TextWriterTraceListener"
           initializeData ="D:\NetTrace.log" />
    </sharedListeners>
    <switches>
      <add name="System.Net" value="Verbose"/>
      <add name="System.Net.Http" value="Verbose"/>
      <add name="System.Net.Sockets" value="Verbose"/>
    </switches>
    <trace autoflush="true"/>
  </system.diagnostics>

加入後重測一次拿到 Log，一語驚醒夢中人，我跌坐在地。居然沒發出任何 Socket 封包，等等，hhttp 是什麼鬼啦!

System.Net Information: 0 : [29908] 目前的作業系統安裝類型為 'Client'。
System.Net Verbose: 0 : [29552] Entering WebClient#23292825::UploadData(hhttp://127.0.0.1/DemoWeb/CodecApi/EncryptString, POST)
System.Net Verbose: 0 : [29552] Entering WebRequest::Create(hhttp://127.0.0.1/DemoWeb/CodecApi/EncryptString)
System.Net Verbose: 0 : [29552] Exiting WebRequest::Create() 

原來問題出在設定 appSetting 時 http 被誤打成 hhttp! 追查問題時其實有檢查過設定，但大腦對 hhttp 做了自動修正，沒看出 URL 有錯，折騰了大半天。帶著又好氣又好笑的心情，修正這個低級錯誤排除問題。

學到經驗，看來下回檢查設定值要一個字母一個字母朗讀出來才算到位。

Example of using .NET network tracing feature to debug a online issue.