Risoluzione dei problemi di timeout DNS in ME

Introduzione

In questo documento vengono descritti i problemi relativi al timeout del DNS (Domain Name System) per le query verso il DNS in MME (Mobile Management Entity) per la selezione di SGW (Serving GateWay) e PGW (Packet Data Network Gateway).

Prerequisiti

Requisiti

 Cisco raccomanda la conoscenza dei seguenti argomenti:

• StarOS
• Funzionalità MME correlate a DNS

Componenti usati

Le informazioni fornite in questo documento si basano sulle seguenti versioni software e hardware:

• DNS
• MME

Le informazioni discusse in questo documento fanno riferimento a dispositivi usati in uno specifico ambiente di emulazione. Su tutti i dispositivi menzionati nel documento la configurazione è stata ripristinata ai valori predefiniti. Se la rete è operativa, valutare attentamente eventuali conseguenze derivanti dall'uso dei comandi.

Premesse

DNS

Il DNS trasforma i nomi di dominio in indirizzi IP, che i browser utilizzano per caricare le pagine ABCD. Ogni dispositivo connesso alla rete dispone di un proprio indirizzo IP, utilizzato da altri dispositivi per individuare il dispositivo.

Dal punto di vista della mobilità, DNS è il server esterno utilizzato per il nome del punto di accesso (APN, Access Point Name) e la risoluzione degli URL in base alla connettività con i nodi della rete.

1. Connettività MME - DNS: utilizzata per la risoluzione APN per la selezione SPGW

2. Connettività da SPGW a DNS: Utilizzato per la risoluzione degli URL per raggiungere il provider di servizi Internet (ISP)

Tipi di record utilizzati nel DNS.

1. Record A/AAA: Utilizzato per definire gli indirizzi host IPv4 e IPv6 mappati al nome completo dell'host in cui il record A è utilizzato per IPv4 e l'autenticazione, l'autorizzazione e l'accounting (AAA) per IPv6.

2. Record NAPTR: utilizzato come servizio di ricerca che punta a un record di servizio (SRV) e record A/AAA per il processo di selezione SPGW per la risoluzione 4G APN e TAC.

3. Record SRV: Utilizzato come ricerca per eseguire il mapping tra un puntatore Autorità di certificazione (NAPTR) e un record A/AAA.

Esempio: Osservate come viene mappato A/SRV/NAPTR.

Funzionalità MME correlate a DNS

• La funzione di base di MME relativa a DNS è per la selezione di SGW e PGW basata su query DNS.
• Cisco MME dispone di una propria cache DNS che consente di evitare query frequenti su server esterni e di archiviare tutte le query eseguite nella cache DNS MME in modo da ridurre la necessità di inviare la query a un server DNS esterno.
• Quando l'UE si registra su una rete EPS (Evolved Packet System), le devono essere assegnati i SGW e i PGW appropriati. L'MME effettua la selezione del GW in base al DNS.
• La query NAPTR viene utilizzata per la risoluzione degli indirizzi GW.
• In base alla query DNS, MME determina l'interfaccia tra S-GW e P-GW.

Procedura di selezione di SPGW 

• MME esegue una query DNS iniziale per ottenere un elenco di identità e priorità GW
• Selezione S-GW eseguita in base all'identificatore dell'area di rilevamento (TAI, Tracking Area Identifier)
• Selezione P-GW eseguita in base al servizio APN
• MME seleziona il GW in base alle informazioni sulla priorità o alla configurazione MME
• Quindi viene eseguita una seconda query DNS per ottenere gli indirizzi IP del GW desiderato.

Come per la procedura, MME effettua sempre 2 query DNS per ottenere GW IP indirizzato che è spiegato.

Query 1: Per la prima query eseguita tramite APN o TAI, si ottiene un profilo SRV mappato con esso o direttamente un output di record A mappato in risposta.

Query 2: Inoltre, esegue una query sul profilo SRV e lo invia come stringa di sostituzione per ottenere l'IP GW.

Ad esempio:

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

Problema

1. Quando si esegue una query NAPTR da MME per APN abcd.apn.epc.mncXXX.mccYYY.3gppnetwork.org e si ottiene un timeout DNS da MME.

Nota: Stringa +nc-nr è la nuova stringa aggiunta al servizio 5G e aggiunta a ogni record di risorse NAPTR (RR) per identificare l'interfaccia del servizio.

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

Nota: +nc-nr è la nuova stringa basata sul servizio 5G, quindi MME deve supportare questo servizio perché quando MME effettua una query DNS e ottiene una risposta per verificare che un particolare servizio sia abilitato o meno in 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. Nelle tracce PCAP è stato rilevato che il server DNS riceve la query e in risposta invia da 30 a 35 sostituzioni per ogni APN a causa delle quali le dimensioni del pacchetto diventano 4186 byte e MME avvia la connessione TCP.

3. È possibile visualizzare che il DNS ha ricevuto la richiesta di query e ha inviato la risposta ma senza alcun contenuto con un solo contrassegno come "Messaggio troncato". Ciò si verifica solo nel caso in cui il messaggio di risposta venga troncato e le altre risposte 4G funzionino correttamente quando il messaggio non viene troncato.

Il messaggio troncato si verifica quando un numero di sostituzioni mappate sul nome APN è superiore a 30, aumenta le dimensioni del messaggio e invia il flag di messaggio troncato in risposta. La dimensione totale del messaggio di risposta è di 4181 byte come payload TCP (fare riferimento all'immagine).

Dopo aver ricevuto questa risposta da MME, MME avvia la connessione TCP con DNS.

 Da ME a DNS

• Frame 31 - MME invia una query al DNS
• Frame 32 - Il DNS invia una risposta con il contrassegno impostato su "Messaggio troncato"
• Frame 33/34/35 - Connessione TCP stabilita tra MME e DNS e scambio delle proprie funzionalità

Nell'istantanea specificata, è possibile vedere Maximum Segment Size (MSS) send from MME is 9060.

Quando MME esegue una query per la quale DNS invia una risposta con "Messaggio troncato" e non dispone di altre informazioni dopo le quali MME avvia la connessione TCP in base alla risposta DNS.

Da DNS a ME

• MME invia una query dopo la connessione TCP
•  Il DNS lo riconosce.
•  Il DNS invia una risposta con il contrassegno impostato su "Messaggio non troncato" perché il valore MSS condiviso con il DNS è impostato su 9060 byte e invia l'intera risposta in un'unica operazione.
•  MME risponde con un ACK privo di contenuto
•  Il DNS invia l'ACK al contenuto nel messaggio 38 dove il payload è di 4181 byte
• MME invia il messaggio TCP per ripristinare e chiudere le connessioni non appena riceve l'ultimo frammento.

Quando MME riceve l'intero payload in 2-3 segmenti o in un tentativo dal DNS, invia un messaggio di reimpostazione 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

Scenario di test

1. Acquisire tutti i log/tracce di debug necessari con un test dedicato e abilitare i log contemporaneamente quando il sottoscrittore sfoglia con un APN problematico 

2. Assicurarsi che ogni volta che viene eseguito uno scenario di test, il sottoscrittore debba eseguire un nuovo collegamento per scaricare il sottoscrittore.

3. Ai fini del test, assegnare un tester e che il tester deve eseguire un test dedicato con il suo IMSI e deve accedere a quel APN problematico: 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)

Risoluzione dei problemi

1. Controllare le uscite di tutti i comandi menzionati per verificare la presenza di perdite di pacchetti interne al sistema.

2. Controllare le statistiche per verificare la frequenza dell'aumento dei timeout DNS nel nodo.

[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

Dopo aver eseguito questi comandi per acquisire le statistiche per più iterazioni e osservare che i timeout delle query vengono aumentati gradualmente ma non si sono verificate perdite di pacchetti tra Demux e sessmgrs, il che non determina alcun problema con il sistema interno

Inoltre, per verificare eventuali problemi di connettività esterna o problemi di configurazione nel DNS, è possibile eseguire la query per i valori di sostituzione manualmente da MME invece che da APN, come mostrato nell'immagine, dove viene risolto correttamente senza alcun ritardo e si conclude che non ci sono problemi con la connettività e la configurazione esterne.

[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

Il problema è tra DNS e SGSN-MME, dove è possibile visualizzare le risposte DNS di invio con valori sostitutivi come topon e MME deve eseguire nuovamente la query per le voci topon, ma ciò non si è verificato altrimenti se la risoluzione della query viene eseguita manualmente

In base agli output e alle tracce del comando, è chiaro che quando si esegue una query su APN, si ottengono risposte con 30 sostituzioni tramite connessione TCP in frammenti e mentre MME riconosce questi frammenti invia la reimpostazione a DNS.

Poiché MME invia TCP per la reimpostazione, possiamo vedere in MME dove la query DNS mostra errori come timeout della query e fino a questo punto di tempo non vediamo quei 30 valori di sostituzione negli output del comando MME poiché i frammenti non sono stati riconosciuti completamente e prima del completamento di questo processo, MME invia TCP per la reimpostazione.

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

Dai log, indica che dopo il primo timeout MME invia l'errore 115 per i tentativi successivi perché la prima connessione TCP non è ancora chiusa sul socket.  Timeout della prima connessione TCP. La connessione precedente non è stata chiusa.

Viene avviata una nuova connessione che si trova sullo stesso socket in cui è stata stabilita la connessione precedente e non viene cancellata. Viene visualizzato l'errore 115 (operazioni in corso) anche se la nuova connessione è stata formata ma in qualche modo il socket non ha chiuso la connessione precedente dopo il primo timeout.

Soluzione

Riavviare vpnmgr del contesto DNS. Non è ancora disponibile una correzione software.