使用 SmtpClient 發送大量郵件時出現 net_io_connectionclosed 錯誤

之前曾寫過一篇〈寄送郵件的封包被防火牆檔掉〉的文章,把當時的問題狀況和解決過程記錄下來。事隔一年多,應用程式的郵件發送 log 又出現頻繁的網路 IO 中斷的狀況。上次的情形是只有特定內容的信件才會被防火牆誤判而擋掉,這次則是沒有特定規則,也就是說,同一封郵件,有些人有收到,有些人則因為網路 IO 中斷而沒收到。

這個應用程式的寄信作業是透過 .NET 的 SmtpClient 類別,而且發送的信件量挺大,有時候一天要發給好幾萬個收件人。程式發信時若有錯誤,會將訊息寫入 log 檔案。這次的錯誤訊息是:

System.Net.Mail.SmtpException: 傳送郵件失敗。 ---> System.IO.IOException: 無法從傳輸連接讀取資料: net_io_connectionclosed。

(英文訊息是:"Unable to read data from the transport connection: net_io_connectionclosed.")

說來可笑,由於發信程式原本都運作得好好的,突然在某一天之後(似乎與更換 SMTP 伺服器與網路設備有關)才不斷出現這種網路 IO 異常中斷的錯誤,因此我一開始就朝網路異常的方向去想,完全沒去懷疑 .NET 的 SmtpClient 類別。就在繞了一大圈,請網管協助解決我對網路方面的疑惑之後,才想到搜尋 Google,這才發現原來 SmtpClient 有個挺嚴重的 bug:與 SMTP 伺服器的連線不會正常關閉。而且,這個 bug 一直到 .NET 4.0 才獲得修正。在 .NET 4.0 之前,應用程式可以透過設定  SmtpClient.ServicePoint.MaxTimeout = 1 來避開此問題(參考這個討論串)。

重點說完了,以下是我和網管合作研判此問題的過程,大概就不值得花時間看了,只是自己做個記錄。

從防火牆的 log 找線索

先把 Cisco 防火牆的 log 提供給網管,請專家協助。他們的回覆是,根據以下 Cisco 防火牆設備的 log(IP 位址被我改過了,以免央及無辜):

2010-10-11 14:10:09 Local4.Info 123.45.12.134 %ASA-6-302013: Built outbound TCP connection 32300149 for outside:123.45.2.64/25 (123.45.2.64/25) to inside:123.45.12.134/4887 (123.45.12.134/4887)
2010-10-11 14:10:10 Local4.Info 123.45.12.21 %ASA-6-302014: Teardown TCP connection 32300149 for outside:123.45.2.64/25 to inside:123.45.12.134/4887 duration 0:00:00 bytes 1261 TCP Reset-I

其中的  TCP Reset-I 的意思是:Reset was from the inside,故研判「該訊息顯示 inside (123.45.12.134) 送出一個 reset 封包  所以連線結束。」

這就不明白了,怎麼發信程式所在的伺服器(123.45.12.134),好端端的會自己發出 reset 訊號,導致發送郵件時的網路連線意外中斷呢?

讓證據說話

畢竟機器在自己「家裡」,如果沒有提供進一步的資訊或證據,專業的醫生恐怕也很難準確診斷出病因(Joker: Can't rely on anybody these days, you gotta do everything yourself, don't we?)。於是,我在發信程式所在的機器上裝了 Wireshark,然後從網路上的一些教學文章裡學了幾招三腳貓功夫,把應用程式寄信時的網路封包擷取下來。

由於是第一次使用 Wireshark,擔心遺漏任何重要線索,所以乾脆把全部的封包都抓下來。大約抓了兩個小時吧,把攔截下來的封包存成檔案,已經是好幾百 MB。這些攔截下來的網路封包資料實在太多了,若不加以篩選,根本不太可能找到自己想要的資料。於是我設定封包檢視的 filter,讓它只秀出那些來源或目的是 SMTP 伺服器 IP 位址的封包。接著,從應用程式發信的 error log 中,以收件人的 email 做為搜尋關鍵字,找到 Wireshark 中對應的幾段封包,果然有發現 RESET 訊號(RST)。如下圖:


應用程式發信時,是每一封信以密件副本的方式寄給三個人,但從上圖的封包記錄來看,原來網路層並不是只發送一次,而是分三次送出收件人的地址(不知這樣解讀對否)。

另一個大發現,是送出 RESET 訊號的,並非發信程式所在的機器,而是 SMTP 伺服器,這和之前網管的初步研判結果並不一致。於是,我再將上圖寄給網管,請他們協助研判。這次,我得到了更詳細、也更可靠的回覆。

對方的回覆內容,這裡不便直接貼上來。但他們提供了一個網頁連結:http://support.microsoft.com/kb/152474/zh-tw,實際的狀況便類似這份文件的第二張圖。進一步推測,在應用程式發送 email 時,一封 email 原本要發給三個信箱,可是在網路層送出第二個信箱的封包之後:
  1. SMTP 伺服器發現太多收件人的 email 信箱無效,於是回應 "550 Too many bad recipient",並緊接著送出 FIN, ACK 給應用程式伺服器,通知對方要結束 TCP 連線。
  2. 應用程式伺服器收到 FIN, ACK 之後,以 ACK 應答,表示收到了。
  3. 可是接著應用程式伺服器仍繼續送出第三個信箱的訊息:RCPT TO:user3@home.com,然後又接著送出與 step 1 對應的結束連線的 FIN, ACK 訊號。
  4. 於是 SMTP 伺服器送出 RST,TCP 連線結束。
為了確認以上說法,我先調整了發信程式的參數,改成一封只發給兩個收件人,結果發現網路中斷的錯誤已大幅減少。再改成一封只發給一個人之後,應用程式發信時都沒有再出現網路 IO 異常中斷的情形了。可見上述說法的確符合實情。只是,還有一個地方仍不明白:為什麼才一兩個收件人信箱無效,SMTP 伺服器就吐回 too many bad recipient?

最後,就如本文開頭所說的,真正的兇手原來是 .NET 的 SmtpClient 類別的 bug。也許是這個原因,在大量發信時,由於 SmtpClient 不會自己關閉連線,直到 timeout 掉,才由 SMTP server 主動結束連線,因而造成網路 IO 連線中斷的情形。Hmm....我懷疑那個 too many bad recipient 的問題也是這個 bug 造成的,因為在修改程式避開此 bug 之後,一次發給三人、甚至五人,都沒有再出現 too many bad recipient 和網路異常中斷的情形。
Copyright © 2012. Huan-Lin 學習筆記 - All Rights Reserved
Powered by Blogger
Template Design by Cool Blogger Tutorials
Published by Templates Doctor