【茶包射手日記】IIS 每天早上無法登入疑案

蠻奇妙的一次射茶包經驗。

執行一項測試排程的移機作業，檢查過程注意到另一個相關測試台排程已連續三天(4/17-4/19)不正常。向同事提起，同事說該排程所依賴的某個 IIS 最近很不穩定，已經好幾天一早上班時是壞的，瀏覽器一直彈出帳號密碼對話框，輸入正確帳密也無法登入，直到 IISRESET 才恢復。而未正常執行的排程時間是早上 07:00 呼叫該台 IIS 上一個 WebAPI，由此推測，這三天排程失敗 IIS 每天早上故障有關。

一時意志薄弱，想到人生苦短，何不當隻快樂小鴕鳥？既然 IISRESET 就可恢復，何不在問題主機設個每日 04:30 IISRESET 排程就高枕無憂囉~

但當茶包射手當久了，有些行為已被埋進潛意識燒成 BIOS。忽然一陣意識模糊，等回神過來，發現自己已登入問題主機開始射茶包...

事件檢視器有以下 NETLOGON 錯誤事件。

This computer was not able to set up a secure session with a domain controller in domain TESTDOMAIN due to the following: 
The RPC server is unavailable. 
This may lead to authentication problems. Make sure that this computer is connected to the network. 
If the problem persists, please contact your domain administrator.  

ADDITIONAL INFO 
If this computer is a domain controller for the specified domain, 
it sets up the secure session to the primary domain controller emulator in the specified domain. 
Otherwise, this computer sets up the secure session to any domain controller in the specified domain.

發生時機在清晨，每早上班 IIS 無法登入便有了合理解釋。而在 NETLOGON 錯誤之前，則有另一起警告：

A request to allocate an ephemeral port number from the global TCP port space has failed due to all such ports being in use.

在事件檢視器篩選這兩項事件，有項重大發現：4/17-19 連著三天在早上 07:00 之前，都是先發生 Tcpip 4231 錯誤，接著一分鐘內引發 NETLOGON 5719 錯誤，為這三天 07:00 排程呼叫 WebAPI 失敗及無法登入提供了鐵證。

爬文找到微軟文件 Troubleshoot port exhaustion issues ，其中提到 Tcpip 4231 警告多發生於本機段的動態 Port 號耗盡 (註：每條 TCP 連線除了伺服器端的 80、443、3389 等約定的 Well-Known Port 號，客戶端也需要一個動態指派的 Ephemeral Port 臨時埠號)，臨時埠號原則上可回收再利用，但是遇到程式同時開啟太多連線時(包含連線關閉後有 240 秒 TIME_WAIT 等待，先前談HttpClient 時有提過)，就有可能周轉不靈致無臨時埠號可用，會因此衍生無法登入網域(NETLOGON 5719 錯誤)、Group Policy 更新錯誤 1129、網路分享無法存取、RDP 連線失敗... 等異常。Windows 8/Windows Server 2012 有個 Hotfix 可改善臨時埠耗盡問題，但抓出吃光埠號的兇手才是治本之道。

跑 netstat 清查連線，發現問題主機有大量連線指向另一台主機的 8766 Port。

使用 netstat | find ":8766" /c 統計，同時開啟的連線數維持在 180 到 200 條之間。

詢問同事配合調閱 IIS Log，得知該主機近日有個 WebAPI 開始試俥，客戶端固定以每五秒一次頻率呼叫，而此 WebAPI 再以WCF net.tcp 方式查詢後端系統 (天哪! 又是 WCF。完全不想面對，我過不去，我過不去)，net.tcp 正是走 8766 Port。看了程式碼，WebAPI 建立 WCF Client 執行後沒有做 Close() 的動作，被懷疑是連線殘留的原因。過去相似 WCF 呼叫寫法挺多也沒刻意 Close()，印象中倒沒出過問題，差別在其他的 WCF 走 HTTP，推測 HTTP 非持續式連線，與 net.tcp 連線管理機制可能不同。爬文看到一些文章提及 Proxy 物件都應該要 .Close()。

• Programming WCF Services, 3rd Edition by Juval Lowy

  It is a recommended best practice to always close the proxy when the client is done using it.
  

• Close and Abort release resources safely when network connections have dropped

推算 180 條開啟連線的由來，每五秒呼叫一次，每分鐘增加 12 條連線，閒置 15 分鐘才關閉的話，差不多是這個數字，但我沒找到 15 分鐘這個限制的由來，但呼叫完畢 Close() 顯然有益無害。

同事修改程式，呼叫方法後執行 WCF Client Proxy 物件 .Close()，情況有了明顯改變，連線數下降到 1-2 條。

歷經幾天觀察，當天加上 .Close() 便未再發生臨時埠號用盡及 IIS 無法登入問題，Case Close。

事後想想，慶幸當時沒有靠 IISRESET 排程鋸箭，不然 WCF Proxy Client 問題就被掩埋了，未來在高負載情境下不知要爆出什麼詭異故障，難保不會是場災難。啊~ 福氣啦!

A ephemeral port number run out case caused by incorrect net.tcp WCF client usage.