排除MME中的DNS超时问题

简介

本文档介绍与域名系统(DNS)超时有关的问题，这些问题针对移动管理实体(MME)中的DNS查询，用于为网关(SGW)和数据包数据网关(PGW)选择服务。

先决条件

要求

 Cisco 建议您了解以下主题：

• StarOS
• 与DNS相关的MME功能

使用的组件

本文档中的信息基于以下软件和硬件版本：

• DNS
• MME

本文档中的信息都是基于特定实验室环境中的设备编写的。本文档中使用的所有设备最初均采用原始（默认）配置。如果您的网络处于活动状态，请确保您了解所有命令的潜在影响。

背景信息

DNS

DNS将域名转换为IP地址，浏览器使用这些地址加载ABCD页面。连接到网络的每台设备都有自己的IP地址，供其他设备用于定位设备。

从移动性的角度来说，DNS是外部服务器，根据它与网络中节点的连接性，用于接入点名称(APN)和URL解析。

1. MME到DNS的连接：用于SPGW选择的APN解析

2. SPGW到DNS的连接：用于URL解析以访问Internet服务提供商(ISP)

DNS中使用的记录类型。

1. A/AAA记录：用于定义映射到主机的完全限定名称的IPv4和IPv6主机地址，其中A记录用于IPv4，而Authentication， Authorization and Accounting(AAA)用于IPv6。

2. NAPTR记录：用作指向服务记录(SRV)和A/AAA记录的查找服务，用于4G APN和TAC解决方案的SPGW选择过程。

3. SRV记录：用作名称颁发机构指针(NAPTR)和A/AAA记录之间映射的查找。

示例：观察A/SRV/NAPTR的映射方式。

与DNS相关的MME功能

• MME与DNS相关的基本功能是根据DNS查询选择SGW和PGW。
• 思科MME有其自己的DNS缓存，有助于避免频繁查询外部服务器，并将执行的每个查询存储在MME DNS缓存中，以减少向外部DNS服务器发送查询的需要。
• 当UE注册到演进分组系统(EPS)网络时，必须为其分配适当的SGW和PGW。MME根据DNS进行GW选择。
• NAPTR查询用于进行GW地址解析。
• 根据DNS查询，MME确定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配置文件或直接映射的响应记录输出。

查询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时，在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，并且增加了消息的大小并发送截断的消息标志作为响应。响应消息的总大小为4181字节作为TCP负载（请参阅图像）。

在MME收到此响应后，MME将启动与DNS的TCP连接。

 从MME到DNS

• 帧31 - MME向DNS发送查询
• 帧32 - DNS发送一个响应，其标志设置为“消息被截断”
• 帧33/34/35 — 在MME和DNS之间建立TCP连接，并交换各自的功能

在给定快照中，您可以看到从MME发送的最大段大小(MSS)为9060。

当MME查询哪个DNS发送的响应“消息被截断”，并且它没有其他信息时，MME会根据DNS响应发起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.为了测试目的，请分配一台测试仪，该测试仪需要使用其IMSI执行专用测试，并需要访问有问题的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和会话之间没有丢包，因此内部系统没有问题

此外，为了检查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中，您可以看到DNS发送响应，替换值为topon，MME必须再次查询topon条目，但如果手动执行查询解析成功，则不会出现此情况

根据命令输出和跟踪，很明显，当您查询APN时，您会通过分段中的TCP连接获得30个替换项的响应，而MME会确认这些分段会将重置发送到DNS。

由于MME发送TCP以重置，在MME中，我们可以看到DNS查询显示错误为查询超时，并且到此时，我们在MME命令输出中看不到这30个替换值，因为分段未完全确认，在此过程完成之前，MME发送TCP以重置。

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。尚未提供软件修复。