排除MME中的DNS超時問題

簡介

本文說明在服務閘道(SGW)和封包資料網路閘道(PGW)選取的移動管理實體(MME)中針對DNS的查詢的網域名稱系統(DNS)逾時相關問題。

必要條件

需求

 思科建議您瞭解以下主題：

• StarOS
• 與DNS相關的MME功能

採用元件

本文中的資訊係根據以下軟體和硬體版本：

• DNS
• MME

本文中的資訊是根據特定實驗室環境內的裝置所建立。文中使用到的所有裝置皆從已清除（預設）的組態來啟動。如果您的網路運作中，請確保您瞭解任何指令可能造成的影響。

背景資訊

DNS

DNS將域名轉換為IP地址，瀏覽器可使用該地址載入ye mian頁面。連線到網路的每台裝置都有自己的IP地址，其他裝置使用該地址查詢裝置。

從移動性角度來看，DNS是用於接入點名稱(APN)的外部伺服器，並根據其與網路中節點的連線進行URL解析。

1. MME到DNS連線：用於SPGW選擇的APN解析

2. SPGW到DNS連線：用於URL解析，以聯絡網際網路服務提供商(ISP)

DNS中使用的記錄型別。

1. A/AAA記錄：用於定義對映到主機完全限定名稱的IPv4和IPv6主機地址，其中A記錄用於IPv4，身份驗證、授權和記帳(AAA)用於IPv6。

2. NAPTR記錄：用作查詢服務，指向4G APN和TAC解析的SPGW選擇流程的服務記錄(SRV)和A/AAA記錄。

3. SRV記錄：用作在名稱許可權指標(NAPTR)和A/AAA記錄之間進行對映的查詢。

範例：觀察A/SRV/NAPTR的對映方式。

與DNS相關的MME功能

• 與DNS相關的MME的基本功能是基於DNS查詢選擇SGW和PGW。
• Cisco MME擁有自己的DNS快取，這有助於避免頻繁查詢到外部伺服器，並將每個查詢儲存在MME DNS快取中，以減少將查詢傳送到外部DNS伺服器的需要。
• 當UE註冊到演化分組系統(EPS)網路時，必須為其分配適當的SGW和PGW。MME根據DNS選擇GW。
• NAPTR查詢用於進行GW地址解析。
• MME根據DNS查詢確定S-GW和P-GW之間的介面。

SPGW的選擇過程 

• MME執行初始DNS查詢以獲取GW標識和優先順序清單
• 基於跟蹤區域識別符號(TAI)的S-GW選擇
• 基於APN的P-GW選擇
• MME根據優先順序資訊或MME配置選擇GW
• 然後進行第二個DNS查詢，以獲取所需的GW的IP地址。

因此，按照此過程，MME總是進行2個DNS查詢來獲得GW IP地址，對此進行了說明。

查詢1:對於通過APN或TAI完成的第一個查詢，您會獲得與其對映的SRV配置檔案，或者直接對映為響應的A記錄輸出。

查詢2:此外，它向SRV配置檔案發出查詢，並將其作為替換字串傳送，以獲取GW IP。

例如：

Query Name: abcd.apn.epc.mncXXX.mccYYY.3gppnetwork.org
Query Type: NAPTR      TTL: 515 seconds
Answer:
Order: 100            Preference: 50000
Flags: a             Service: x-3gpp-pgw:x-s5-gtp:x-s8-gtp:x-gn:x-gp
Regular Expression:
Replacement: _nodes._pgw.epc.mncXXX.mccYYY.3gppnetwork.org

Query Name: _nodes._pgw.epc.mncXXX.mccYYY.3gppnetwork.org
Query Type: NAPTR      TTL: 515 seconds
Answer:
Order: 100            Preference: 50000
Flags: a            Service: x-3gpp-pgw:x-s5-gtp:x-s8-gtp:x-gn:x-gp

Regular Expression: topoff.pgw- s5s8.node.epc.mncXXX.mccYYY.3gppnetwork.org

Query Name: topoff.pgw- s5s8.node.epc.mncXXX.mccYYY.3gppnetwork.org
Query Type: A      TTL: 646 seconds
Answer:
IP Address: X.X.X.X

問題

1.從MME對APN abcd.apn.epc.mncXXX.mccYYY.3gppnetwork.org執行NAPTR查詢並在MME獲取DNS超時時。

附註：String +nc-nr是新增到5G服務的新字串，它針對每個NAPTR資源記錄(RR)新增以標識服務介面。

"x-3gpp-pgw:x-s5-gtp+nc-nr:x-s8-gtp:x-gn:x-gp"

附註：+nc-nr是基於5G服務的新字串，因此MME需要支援此服務才能工作，因為當MME進行DNS查詢並獲得響應以檢查特定服務是否在MME中啟用時。

[gn]SGSN-MME# dns-client query client-name dnsclient query-type NAPTR query-name abcd.apn.epc.mncXXX.mccYYY.3gppnetwork.org
Wednesday October 27 17:06:20 ICT 2021
Query Name: abcd.apn.epc.mncXXX.mccYYY.3gppnetwork.org
Query Type: NAPTR      TTL: 0 seconds
Answer: -Negative Reply-
Failure Reason: DNS query timed out

2.在PCAP跟蹤中，發現DNS伺服器收到查詢，並在響應中針對每個APN傳送30到35個替換，因為資料包大小變為4186位元組並且MME會發起TCP連線。

3.您可以看到DNS已收到查詢請求並傳送響應，但沒有任何內容只有一個標誌，即「消息被截斷」。 只有在響應消息被截斷，並且4G響應的其餘部分在消息未被截斷時工作正常的情況下，才會觀察到這種情況。

截斷消息的原因是，針對APN對映的替換數超過30，它增加消息的大小並傳送被截斷的消息標誌作為響應。響應消息的總大小是作為TCP負載的4181位元組（請參見圖）。

在MME收到此響應後，MME會發起與DNS的TCP連線。

 從MME到DNS

• 第31幀 — MME向DNS傳送查詢
• 第32幀 — DNS傳送帶有標誌設定為「消息被截斷」的響應
• 第33/34/35幀 — MME和DNS之間建立的TCP連線，並交換各自的功能

在給定的快照中，可以看到MME傳送的最大段大小(MSS)為9060。

當MME查詢哪個DNS傳送的響應帶有「Message is trunked」（消息被截斷），並且它沒有其他資訊後，基於DNS響應的MME發起TCP連線。

從DNS到MME

• MME在TCP連線後傳送查詢
•  DNS會確認這一點。
•  DNS傳送帶有標誌設定為「消息未截斷」的響應，因為與DNS共用的MSS設定為9060位元組，它一次傳送整個響應。
•  MME使用無內容的ACK進行響應
•  DNS將ACK傳送到消息38中的內容，其中負載為4181位元組
• MME傳送TCP，以在收到最後一個片段時立即重設和關閉連線。

當MME在2到3個區段中收到整個負載，或從DNS進行一次嘗試時，MME會傳送TCP重設訊息。

DNS commands to troubleshoot

show dns-client statistics
show dns-client statistics client <DNS Client Name>
show dns-client cache client <client name> [query-name <query-name>[query-type <NAPTR | AAAA | A>] | [query-type <NAPTR | AAAA | A>]]
dns-client query client-name <client name> query-type <NAPTR | AAAA> [query-name <query name>].show port datalink counters

Commands to check if there were any problem internal to the starOS system where request is not able to reach from demux vpnmgr to DNS app in sessmgrs

show port npu counters
show cloud configuration
show iftask stats summary
show npu utilization table
show iftask port-stats card <card>   ---- for all active SF cards
show iftask iomux-stats card <card>  ---- for all active SF cards

MON SUB to be captured with options enabled (verbosity 5,Y,S,34,35,19,A,26)

PCAP traces to be captured

DNS cache flush commands

clear dns-client <client-name> cache

測試方案

1.使用專用測試捕獲所有所需的調試日誌/跟蹤，並在訂戶瀏覽存在問題的APN時同時啟用日誌 

2.確保每次執行測試方案時，訂戶都需要執行新的附加來刷新訂戶。

3.為測試目的，指定一名測試人員，該測試人員需要對其內部管理介面執行專用測試，並需要訪問有問題的APN:abcd.apn.epc.mncXXX.mccYYY.3gppnetwork.org。

  logging filter active facility vpn level debug         ------ debug level logs
  logging filter active facility tcpdemux level debug    ------ debug level logs
  logging monitor msid <MSID number>                     ------ (these logging command to be executed in config mode)

疑難排解

1.檢查上述所有命令的輸出以確認系統內部是否存在任何丟包現象。

2.檢查統計資訊以確認節點中的DNS超時增加頻率。

[gn]SGSN-MME# show dns-client statistics client dnsclient
Friday August 20 13:31:48 ICT 2021
DNS Usage Statistics:
---------------------
Query Type             Attempts       Successes        Failures
A                    2430996860      2410410937        20546467
SRV                  1325520986      1325516557            4429
AAAA                 3939810089               0      3939810089
NAPTR                 480586697       432853033        47732791
PTR                           0               0               0
Total                3881947336      4168780527      4008093776

…
Total Resolver Queries: 4480708
Successful Queries:     670040
Query Timeouts:         409717  
Domain Not Found:       2455918
Connection Refused:     0
Other Failures:         580612

運行這些命令以捕獲多次迭代的統計資訊並觀察到查詢超時逐漸增加，但Demux和sessmgr之間沒有丟包，因此內部系統不會出現問題

為了檢查DNS中的外部連線或配置問題，您可以直接手動從MME而非APN執行替換值查詢，如圖所示，在該查詢中，可以無延遲地正確解決替換值，並得出外部連線和配置也沒有問題的結論。

[gn]SGSN-MME# dns-client query client-name dnsclient query-name TOPON.test.NODE.EPC.MNCXXX.MCCYYY.3GPPNETWORK.ORG
Monday August 02 18:51:29 ICT 2021
Query Name: TOPON.test.NODE.EPC.MNCXXX.MCCYYY.3GPPNETWORK.ORG
Query Type: A          TTL: 1038 seconds
Answer:
IP Address: X.X.X.X ------ resolve properly and gave IP

問題出在DNS和SGSN-MME之間，在此您可以看到DNS傳送響應（替換值為topon），並且MME必須再次查詢topon條目，但是如果我們手動執行查詢解析成功，則不會發生這種情況

根據命令輸出和跟蹤，很明顯，當您查詢APN時，會通過TCP連線以片段形式獲得具有30個替換的響應，而MME確認這些片段時，會向DNS傳送重置消息。

由於MME會傳送TCP以重設，因此我們在MME中可看到，其中DNS查詢將錯誤顯示為查詢逾時，而此時由於片段尚未完全確認且在此程式完成之前，我們看不到在MME指令輸出中的30個替代值。

Debug logs analysis

For abcd.apn.epc.mncXXX.mccYYY.3gppnetwork.org

2021-Oct-27+17:06:20.910 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] query:14585, UDP, Sent time 1635329180, Timeout set 1635329183  ---- timer is set here
2021-Oct-27+17:06:20.910 [vpn 5919 info] [9/0/11730 <vpnmgr:6> dns_resolver.c:323] [software internal system syslog] Sent out a DNS Query abcd.apn.epc.mncXXX.mccYYY.3gppnetwork.org to DNS Server   --------- DNS query is send for the first time
2021-Oct-27+17:06:20.911 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] TCP Connection Init, While Sending Query
2021-Oct-27+17:06:20.911 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] TCP Connection Open with DHost
2021-Oct-27+17:06:20.911 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] query:14585, TCP, Sent time 1635329180, Timeout set 1635329183 ------------ DNS query is send for the second time
2021-Oct-27+17:06:20.911 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] TCP Connection Successful - DHost-Id = 6766924, Sock_fd = 21
2021-Oct-27+17:06:21.008 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] TCP READ, Kernel Closed, EOF - DHost-Id = 6766924, Sock_fd = 21, errno = 115, req_read_len = 0
2021-Oct-27+17:06:21.008 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] TCP Connection close - DHost-Id = 6766924, Sock_fd = 21
2021-Oct-27+17:06:23.019 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] query:14585, TCP, Timeout detected: 1635329183 ---------------- Timeout detected here
2021-Oct-27+17:06:23.019 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] TCP Connection Init, While Sending Query --------------------- Query is send again
2021-Oct-27+17:06:23.019 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] TCP Connection Open with DHost
2021-Oct-27+17:06:23.019 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] query:14585, TCP, Sent time 1635329183, Timeout set 1635329186 ------- Again send the query with new timer value set
2021-Oct-27+17:06:23.019 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] TCP Connection Successful - DHost-Id = 6504921, Sock_fd = 23
2021-Oct-27+17:06:26.036 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] query:14585, TCP, Timeout detected: 1635329186 ---------------- Timeout detected here
2021-Oct-27+17:06:26.036 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] query:35196, UDP, Timeout detected: 1635329186 ---------------- Timeout detected here

 Another example abcd.apn.epc.mncXXX.mccYYY.3gppnetwork.org

2021-Oct-27+17:06:27.257 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] query:19140, UDP, Sent time 1635329187, Timeout set 1635329190 ---- timer is set here
2021-Oct-27+17:06:27.257 [vpn 5919 info] [9/0/11730 <vpnmgr:6> dns_resolver.c:323] [software internal system syslog] Sent out a DNS Query abcd.apn.epc.mncXXX.mccYYY.3gppnetwork.org to DNS Server --------- Query send for the first time
2021-Oct-27+17:06:27.258 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] TCP Connection Init, While Sending Query
2021-Oct-27+17:06:27.258 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] TCP Connection Open with DHost
2021-Oct-27+17:06:27.258 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] query:19140, TCP, Sent time 1635329187, Timeout set 1635329190  -------- Same Query send for the second time
2021-Oct-27+17:06:27.258 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] TCP Connection Successful - DHost-Id = 7201531, Sock_fd = 22
2021-Oct-27+17:06:27.309 [vpn 5921 debug] [7/0/12843 <sessmgr:79> dns_snaptr.c:1466] [software internal system syslog] VPN DEBUG : snaptr_match_valid_entries Initial ue_usage_type:0 nc_nr:0   ----- snaptr match starts
2021-Oct-27+17:06:27.309 [vpn 5921 debug] [7/0/12843 <sessmgr:79> dns_snaptr.c:237] [software internal system syslog] VPN DEBUG : snaptr_compare_service_protocol_set rr_service_parameter x-3gpp-mme:x-gn, inp_svc_param x-3gpp-sgw:x-s5-gtp ue_usage_type_enabled:0 nc_nr_enabled:0   ------- nc_nr enabled which I mentioned earlier
2021-Oct-27+17:06:27.309 [vpn 5921 debug] [7/0/12843 <sessmgr:79> dns_snaptr.c:237] [software internal system syslog] VPN DEBUG : snaptr_compare_service_protocol_set rr_service_parameter x-3gpp-sgw:x-s5-gtp:x-s8-gtp, inp_svc_param x-3gpp-sgw:x-s5-gtp ue_usage_type_enabled:0 nc_nr_e:nabled0
2021-Oct-27+17:06:27.309 [vpn 5921 debug] [7/0/12843 <sessmgr:79> dns_snaptr.c:279] [software internal system syslog] VPN DEBUG : 0.rr_prot_token x-s5-gtp, input token x-s5-gtp
2021-Oct-27+17:06:27.309 [vpn 5921 debug] [7/0/12843 <sessmgr:79> dns_snaptr.c:323] [software internal system syslog] VPN DEBUG : 4.Success Selected Protocol(Normal):x-s5-gtp  ----------- snaptr protocol matched
2021-Oct-27+17:06:30.057 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] query:19140, TCP, Timeout detected: 1635329190 -------- TCP timeout happens
2021-Oct-27+17:06:30.057 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] TCP Connection Init, While Sending Query ----- Again TCP connection initiated
2021-Oct-27+17:06:30.057 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] TCP Connection Open with DHost
2021-Oct-27+17:06:30.057 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] query:19140, TCP, Sent time 1635329190, Timeout set 1635329193 ------ New timer value set with send query
2021-Oct-27+17:06:30.057 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] TCP Connection Successful - DHost-Id = 7136007, Sock_fd = 21
2021-Oct-27+17:06:30.158 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] TCP READ, Kernel Closed, EOF - DHost-Id = 7136007, Sock_fd = 21, errno = 115, req_read_len = 0 – Error because TCP connection is busy because previous connection is not closed
2021-Oct-27+17:06:30.158 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] TCP Connection close - DHost-Id = 7136007, Sock_fd = 21 -------- Connection closed
2021-Oct-27+17:06:30.171 [vpn 5921 debug] [14/0/12709 <sessmgr:15> dns_snaptr.c:1466] [software internal system syslog] VPN DEBUG : snaptr_match_valid_entries Initial ue_usage_type:0 nc_nr:0 --- again snaptr match takes place
2021-Oct-27+17:06:30.171 [vpn 5921 debug] [14/0/12709 <sessmgr:15> dns_snaptr.c:237] [software internal system syslog] VPN DEBUG : snaptr_compare_service_protocol_set rr_service_parameter x-3gpp-mme:x-gn, inp_svc_param x-3gpp-sgw:x-s5-gtp ue_usage_type_enabled:0 nc_nr_enabled:0
2021-Oct-27+17:06:30.171 [vpn 5921 debug] [14/0/12709 <sessmgr:15> dns_snaptr.c:237] [software internal system syslog] VPN DEBUG : snaptr_compare_service_protocol_set rr_service_parameter x-3gpp-sgw:x-s5-gtp:x-s8-gtp, inp_svc_param x-3gpp-sgw:x-s5-gtp ue_usage_type_enabled:0 nc_nr_enabled:0
2021-Oct-27+17:06:30.171 [vpn 5921 debug] [14/0/12709 <sessmgr:15> dns_snaptr.c:279] [software internal system syslog] VPN DEBUG : 0.rr_prot_token x-s5-gtp, input token x-s5-gtp
2021-Oct-27+17:06:33.073 [vpn 5456 info] [9/0/11730 <vpnmgr:6> vpnmgr_func.c:8011] [software internal system syslog] query:19140, TCP, Timeout detected: 1635329193 -----TCP timeout detected

從日誌中，它表示在第一超時後，MME為下一次重試傳送錯誤115，因為第一個TCP連線仍然未在套接字上關閉。  第一個TCP連線的超時已發生，而上一個連線未關閉。

啟動新連線，該連線位於先前連線已建立但未清除的同一套接字上。您會看到錯誤115（操作正在進行中），即使已形成新連線，但在第一個超時後，套接字並未關閉上一個連線。

解決方案

重新啟動DNS上下文的vpnmgr。軟體修復尚未提供。