與Java一樣，.Net Framework也是基于IL解析執行的，通過Microsoft提供的 !sos debug extension，我們基本上可以把.Net Framework的應用程式看個通透。本文通過一個使用者的.Net Framework應用網絡問題，抛磚引玉。
問題
有使用者回報他們Windows上的應用程式通路MySQL慢，但是行為很奇怪。架構是這樣的，
Client --------Internet---> Windows IIS server (.Net Framework application) ------Internet-----> MySQL server
使用者回報，
- 用戶端通路IIS server慢。
- IIS server通過自己的公網IP通路相同的頁面也比較慢 （VPC機器，EIP）。
使用者懷疑是Windows通路MySQL server慢，是以做了很多IIS, MySQL的優化，但均不解決問題。同時，使用者通過其他伺服器通路MySQL的測試，也排除了MySQL本身性能問題。
排查
咋一看，一切的矛頭都指向了Windows IIS server通過公網IP通路MySQL server慢。是以，我們收集了網絡請求的瀑布圖，
使用者說“用戶端通路IIS Server慢”，那麼我們要知道到底慢了多久。
從這張圖裡，我們可以很容易的看到，
- 用戶端的确通路IIS server慢，
- 總共慢了6秒多時間，
- 關鍵是每次通路GetAllCountrys的方法需要3.25s左右的時間等待伺服器傳回給我們第一個響應位元組 (TTFB)。
是否是用戶端跟伺服器端的網絡問題呢？通過在IIS server上擷取的網絡請求的瀑布圖，我們可以排除這一段的鍊路問題，
而伺服器上通過
http://localhost的方式通路所收集的情況更是确認了所有元件都沒有問題，
内容不變，大小差不多，響應也很正常，基本沒延遲。
一般情況下分析到這裡，基本上我們可以排除是産品問題。但延遲到底是怎麼來的，需要進一步抓取網絡資料包分析。
簡單說一下發現，
- 伺服器的确是3.25s前收到了請求，但是延遲響應。
- 伺服器收到請求後，從抓包看是立即去連接配接了MySQL server，并很快擷取了所有需要的内容，也就是Country相關的資訊。這部分可以很容的通過Wireshark導出資料包内容和用戶端收到的内容作對比。
- 在伺服器收到資料後一段時間，伺服器沒有立即傳回HTTP response，而中間我們看到有ARP的請求。邏輯上，這些額外的操作跟IIS是否傳回HTTP Response無關，但是通過幾次的抓包，我們總是能發現類似的行為，直覺上我們認為跟3.25s的延遲有關。
- 仔細看的話伺服器的ARP請求中使用了用戶端的公網IP位址。但是，這個ARP絕對不是Windows作業系統發起的。如果當時伺服器端嘗試跟用戶端通訊的話，它應該請求Gateway的位址。是以，ARP的請求從邏輯上來說是不對的，這也間接證明ARP跟我們的延遲問題有關
- Localhost的抓包對比看沒有ARP請求，不過由于是本機的流量，抓包無法抓到也是符合邏輯的。
可惜的是，Windows并沒有提供任何跟ARP有關的日志，為了擷取确切的證據，我們可以考慮，
- Process Monitor log收集應用運作過程。通過Process Monitor提供的Callstack等資訊尋找蛛絲馬迹。不過這類分析将會比較耗時，實在沒有思路的時候可以考慮收集一下，而目前我們對這個問題的分析已經比較清晰，更關注是問題發生是 .Net程式在做什麼。
-
收集.Net Framework的Network Trace日志，這部分日志會比抓包更要詳細，
How to: Configure Network Tracing :
http://msdn.microsoft.com/en-us/library/ty48b824(VS.90).aspx - 在3.25s 伺服器沒響應的中間，擷取IIS server的w3wp.exe程序user dump。邏輯上，IIS沒有響應一定是應用程式等在某個資源上面。隻是這個dump不大好抓，但是SysInternal提供了一個比較強大的工具：Process Dump。可以使用procdump.exe等待w3wp.exe，并每1 ~ 2秒生成一個dump來擷取确切發生問題時的callstack。 https://docs.microsoft.com/en-us/sysinternals/downloads/procdump
procdump -w -s 2 -n 10 w3wp.exe c:tempw3wp.dump
具體的用法，參考微軟文檔。
w3wp.exe User Dump分析
.Net Framework的Network Trace收集相對來說比較複雜一些，另外還需要使用者配合修改配置檔案。是以，我們直接收集userdump進行下一步分析。對于.Net程式，我們在使用Windbg打開dump檔案的時候第一時間加載SOS debugging extension。
關于SOS debugging extension的一切，可以參考：
https://docs.microsoft.com/en-us/dotnet/framework/tools/sos-dll-sos-debugging-extension通過研究w3wp.exe的線程資訊，我們定位在#27線程，
27 Id: 1b4.654 Suspend: 0 Teb: 00000078`1eca8000 Unfrozen
Child-SP RetAddr : Args to Child : Call Site
00000078`1fabd668 00007ff8`45a8175e : 00000000`00000068 00000000`00000020 00000000`00000014 00000078`00000008 : ntdll!NtDeviceIoControlFile+0x14
00000078`1fabd670 00007ff8`433cf70c : 00000078`1fabd890 00000078`1fabd8ac 00000000`00000002 00000078`1fabd8ac : nsi!NsiGetAllParameters+0xfe
00000078`1fabd760 00007ff8`433def36 : 00007ff7`d82f1398 00000000`00000000 00000000`924b782a 00000000`00000000 : IPHLPAPI!ResolveIpNetEntry2+0xfc
00000078`1fabd850 00007ff7`d84ab0fb : 00000000`00000000 000001ab`927bcb48 00000078`1fabdb58 000001ab`927b4658 : IPHLPAPI!SendARP+0x86
00000078`1fabd930 00007ff7`d84a70b6 : 00000000`924b782a 00000000`00000000 00000078`1fabdb48 00000078`1fabdb40 : 0x00007ff7`d84ab0fb
00000078`1fabda30 00007ff7`d84a7d84 : 000001aa`92a02a20 00000078`1fabefe0 00000000`0000fdff 000001aa`917e9304 : 0x00007ff7`d84a70b6
00000078`1fabdb70 00007ff7`d80dffc7 : 000001ab`927bcb48 000001ab`9279da98 000001ab`927bcb90 000001aa`92541420 : 0x00007ff7`d84a7d84
00000078`1fabdcf0 00007ff7`d82e010b : 000001ab`92794d18 000001ab`9279da98 00007ff7`d8281638 00000000`00000001 : 0x00007ff7`d80dffc7
00000078`1fabddf0 00007ff7`d80df338 : 000001ab`927b4870 000001ab`92794d18 000001ab`927b4710 00000078`1fabd8a4 : 0x00007ff7`d82e010b
00000078`1fabde30 00007ff7`d80df1e3 : 000001ab`9279e1e8 000001ab`92795110 000001ab`9279f728 000001ab`9279f728 : 0x00007ff7`d80df338
00000078`1fabde80 00007ff7`d80df121 : 000001ab`92795890 000001ab`92795110 000001ab`9279e1e8 000001ab`9279f728 : 0x00007ff7`d80df1e3
00000078`1fabdec0 00007ff7`d80defda : 000001ab`927b42d8 000001ab`927b44c8 000001ab`927b443c 00000000`00000000 : 0x00007ff7`d80df121
00000078`1fabdef0 00007ff7`d80de9f0 : 000001ab`92795890 000001ab`927b43e0 000001ab`9279e1e8 00000000`00000000 : 0x00007ff7`d80defda
00000078`1fabdf20 00007ff7`d80de7ee : 000001ab`927b40c0 000001ab`927b43e0 000001ab`927b4034 00000078`1fabe2a8 : 0x00007ff7`d80de9f0
00000078`1fabdf60 00007ff7`d80de52a : 000001ab`927b42b8 000001ab`927b43e0 000001ab`927b4034 00000078`1fabe2a8 : 0x00007ff7`d80de7ee
00000078`1fabdfd0 00007ff7`d80de480 : 000001ab`92795890 000001ab`927b3fd8 000001ab`9279f5c4 00000078`1fabe2a8 : 0x00007ff7`d80de52a
00000078`1fabe000 00007ff7`d80d8757 : 000001ab`9279f6e0 000001ab`927b3fd8 000001ab`9279f5c4 00000078`1fabe2a8 : 0x00007ff7`d80de480
00000078`1fabe040 00007ff7`d80d8946 : 000001ab`9279e3e8 000001ab`927b3fd8 000001ab`9279f5c4 00000078`1fabe2a8 : 0x00007ff7`d80d8757
00000078`1fabe090 00007ff7`d80d898b : 000001ab`92795890 000001ab`9279f568 000001ab`92795c24 00000078`1fabe2a8 : 0x00007ff7`d80d8946
00000078`1fabe0c0 00007ff7`d80d8b79 : 000001ab`92795710 000001ab`9279f568 000001ab`92795c24 00000078`1fabe2a8 : 0x00007ff7`d80d898b
00000078`1fabe0f0 00007ff7`d80d89f4 : 000001ab`92739e08 000001ab`92795008 00000078`1fabe1f0 000001ac`b7af5d90 : 0x00007ff7`d80d8b79
00000078`1fabe120 00007ff7`d80d8b79 : 000001ab`92794d18 000001ab`92795bc8 000001ab`927952c4 00000078`1fabe2a8 : 0x00007ff7`d80d89f4
00000078`1fabe160 00007ff7`d80d8a76 : 000001ab`92795210 000001ab`92795bc8 000001ab`927952c4 00000078`1fabe2a8 : 0x00007ff7`d80d8b79
00000078`1fabe190 00007ff7`d80d8ae9 : 000001ab`92794d18 000001ab`92795268 000001ab`92795064 00000078`1fabe2a8 : 0x00007ff7`d80d8a76
00000078`1fabe1c0 00007ff7`d80d8b79 : 000001ab`927938c8 000001ab`92795268 000001ab`92795064 00000078`1fabe2a8 : 0x00007ff7`d80d8ae9
00000078`1fabe200 00007ff7`d80d8bc6 : 000001ab`92794fb0 000001ab`92795268 000001ab`92795064 00000078`1fabe2a8 : 0x00007ff7`d80d8b79
00000078`1fabe230 00007ff8`14ea57ba : 000001ab`92791c60 000001ab`92795008 00000078`1fabe2b0 00000078`1fabe2a8 : 0x00007ff7`d80d8bc6
00000078`1fabe260 00007ff8`15574bb3 : 000001ab`92739e08 000001ab`92739e08 00000078`1fabe470 00000078`1fabe2b0 : System_Web_ni+0x2f57ba
00000078`1fabe2f0 00007ff8`14e66590 : 000001ab`92739e08 000001ab`92739e08 00000078`1fabe470 00000078`1fabe2b0 : System_Web_ni+0x9c4bb3
00000078`1fabe330 00007ff8`14e7ac6c : 000001ab`92733810 000001ab`92739e08 00000078`1fabe470 00000000`00000000 : System_Web_ni+0x2b6590
00000078`1fabe380 00007ff8`14e67089 : 000001ab`92739a90 00007ff8`14e7a0a6 00000000`00000000 00000078`1fabe570 : System_Web_ni+0x2cac6c
00000078`1fabe4c0 00007ff8`14e7909b : 00000078`1fabe4c0 00007ff8`14ed40f5 00000078`1fabe558 00007ff8`14c0a6d0 : System_Web_ni+0x2b7089
00000078`1fabe510 00007ff8`14e681bd : 000001aa`92799ef8 000001ab`9272e020 000001ab`9272e378 00000000`00000000 : System_Web_ni+0x2c909b
00000078`1fabe590 00007ff8`14e67dc3 : 00000000`00000000 000001aa`91d2aa08 00000000`00000000 00000000`00000000 : System_Web_ni+0x2b81bd
00000078`1fabe730 00007ff8`15563592 : 000007f0`e084fce1 00000000`00000000 00007ff8`2f4c0df0 00007ff8`2f511d38 : System_Web_ni+0x2b7dc3
00000078`1fabe770 00007ff8`3758221e : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : System_Web_ni+0x9b3592
00000078`1fabe7e0 00007ff8`2f51183f : 000001aa`91d2aa08 00000078`00000000 000001aa`91d2ae38 000001aa`91d2aeb4 : clr!UMThunkStub+0x6e
00000078`1fabe870 00007ff8`2f5204ba : 00007ff8`00000000 00007ff8`2f4b3ed0 000001aa`91d2aa08 000001aa`91d2aa08 : webengine4!W3_MGD_HANDLER::ProcessNotification+0x8e
00000078`1fabe8a0 00007ff8`2f5115fb : 00007ff8`2f4b3ed0 00000000`00000080 000001aa`91d2aa08 00000000`00000000 : webengine4!W3_MGD_HANDLER::DoWork+0x3a5
00000078`1fabe910 00007ff8`2f573b21 : 00000000`00000000 00000000`00000000 0000d54a`f3ef32bb 000001aa`91d29180 : webengine4!RequestDoWork+0x3fc
00000078`1fabe9b0 00007ff8`2f4bd3d9 : 00000000`00000000 00000000`00000000 000001aa`91b1fd30 ffffffff`00000000 : webengine4!CMgdEngHttpModule::OnExecuteRequestHandler+0x21
00000078`1fabe9f0 00007ff8`2f4bcd7c : 000001aa`91b1fd30 00000078`1fabeb01 00000000`00000016 000001aa`91d29190 : iiscore!NOTIFICATION_CONTEXT::RequestDoWork+0xb9
00000078`1fabea40 00007ff8`2f4bcbc6 : 00000000`00000000 00000000`00000000 000001aa`91b1fd30 00000000`00000000 : iiscore!NOTIFICATION_CONTEXT::CallModulesInternal+0x19c
00000078`1fabeb50 00007ff8`2f4bde08 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : iiscore!NOTIFICATION_CONTEXT::CallModules+0x36
00000078`1fabebb0 00007ff8`2f4b7956 : 00007ff8`2f4b7880 00007ff8`14f87b88 000001ac`b7af5d90 000001aa`91b1fd30 : iiscore!NOTIFICATION_MAIN::DoWork+0x3d8
00000078`1fabeed0 00007ff8`2f56f481 : 000001aa`91d29180 00007ff8`2f4b7880 00000078`1fabf060 ffffffff`fffffffe : iiscore!W3_CONTEXT_BASE::IndicateCompletion+0xd6
00000078`1fabef50 00007ff8`2f5720c2 : 00000078`1fabf1b0 00000078`1fabf1b0 00000078`1fabf500 00000000`00000000 : webengine4!W3_MGD_HANDLER::IndicateCompletion+0x5d
00000078`1fabef80 00007ff8`14ed4f9e : 00000000`00000000 00007ff8`375846d5 00000078`1fabefa0 00006202`e851b47c : webengine4!MgdIndicateCompletion+0x22
00000078`1fabefb0 00007ff8`14e68385 : 000001aa`91d2aa08 00000078`1fabf1b0 00000078`1fabf018 00000078`1fabf178 : System_Web_ni+0x324f9e
00000078`1fabf070 00007ff8`14e67dc3 : 00000000`00000000 000001aa`91d2aa08 00000078`1fabf2b0 00000000`00000000 : System_Web_ni+0x2b8385
00000078`1fabf210 00007ff8`15563592 : 000001ac`b7a94820 000001aa`91d2aa08 00000000`00000003 00000000`00000004 : System_Web_ni+0x2b7dc3
00000078`1fabf250 00007ff8`37582473 : ffffffff`ffffffff 00007ff8`00000001 000001aa`91cbb501 00007ff8`3758a528 : System_Web_ni+0x9b3592
00000078`1fabf2c0 00007ff8`3764cfba : 00460054`0045004e 00007ff8`37585b35 ffffffff`fffffffe 00007ff8`3758a270 : clr!UM2MThunk_WrapperHelper+0x43
00000078`1fabf300 00007ff8`3758a9c8 : 00000078`1fabf428 00000000`00000000 000001ac`b7af5d90 00007ff8`375866af : clr!UM2MThunk_Wrapper+0x60
00000078`1fabf350 00007ff8`3764d065 : 00000078`1fabf501 00000000`00000002 000007f0`e084ee51 00000078`1fabf560 : clr!Thread::DoADCallBack+0x13d
00000078`1fabf510 00007ff8`3758241d : 000001aa`92293c30 ffffffff`ffffffff 00000000`00000003 00000000`00000000 : clr!UM2MDoADCallBack+0xb3
00000078`1fabf590 00007ff8`2f51183f : 00000000`00000000 000001aa`91d2aa08 00000000`00000003 00000000`00000004 : clr!UMThunkStub+0x26d
00000078`1fabf620 00007ff8`2f511792 : 000001aa`00000004 000001aa`91d2aa08 00007ff8`37ec4410 00000078`1fabf800 : webengine4!W3_MGD_HANDLER::ProcessNotification+0x8e
00000078`1fabf650 00007ff8`375899e7 : 000001aa`91d2aa08 00007ff8`2f511750 00007ff8`37ec4410 000001ac`b7af5d90 : webengine4!ProcessNotificationCallback+0x42
00000078`1fabf680 00007ff8`3758819c : 00007ff8`37589a70 00000078`1fabf700 00000078`1fabf801 00000000`00bbd38e : clr!UnManagedPerAppDomainTPCount::DispatchWorkItem+0x1bc
00000078`1fabf720 00007ff8`37587f45 : 00000001`00010002 00000000`00000001 000001ac`b7af5d90 00000000`00000001 : clr!ThreadpoolMgr::ExecuteWorkRequest+0x64
00000078`1fabf750 00007ff8`37632e8f : 00000000`00000000 00000000`00000001 00000000`00000001 00000000`00000804 : clr!ThreadpoolMgr::WorkerThreadStart+0xf5
00000078`1fabf7f0 00007ff8`45878364 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : clr!Thread::intermediateThreadProc+0x86
00000078`1fabfa30 00007ff8`47967091 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : kernel32!BaseThreadInitThunk+0x14
00000078`1fabfa60 00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21
大家一眼可以看出 IPHLPAPI!SendARP ，從字面上看正是發送ARP請求的API。但是中間的一大串0x00007ff7`d84ab0fb的解析則需要!sos來處理，
而從stack上的.Net String object中，我們可以找到确切發送ARP的target address，
不過瘾的話，我們把IL列印出來分析一下，甚至把dll從dump中儲存出來，使用Reflector來反編譯
後記
從.Net的callstack，我們可以非常明确總結延遲問題發生的邏輯，
使用者的 .Net應用程式 從MySQL server擷取資訊後還需要寫回通路日志，但是程式追求收集用戶端的MAC Address資訊，導緻系統不斷往外發送ARP直至逾時。這個代碼在本地子網自然是沒有什麼問題的，但一旦跨網段後，ARP總是收不到任何響應，進而阻塞後續的響應操作，是以這種沒有必要的操作是需要盡量避免的。
在後面對.Net程式的IL分析中，我們也看到了代碼中GetWebClientHostname的調用，其實是調用DNS做PTR的反向查詢（可以從之前的抓包中也看到DNS PTR的Query，原諒我一開始沒有注意到這個）。相對于ARP，不管是否查詢成功，如果DNS server alive的話，總會是有響應的，是以對延遲的影響不是很大。但這類操作對于來自公網的用戶端通路可能意義并不是很大，建議使用Request.UserHostName替代，避免不必要的延遲。