Introduction
Logs are critical to seeing how well systems are working and configuration troubleshooting. In the case of a 5G network, it helps to look at the logs to see how the system is designed from end-to-end. This way you can see how network components interact during specific processes.
Open5GS enables logging by default, the results are stored in the /tmp/log/open5gs directory. We can also use command line tools, such as tcpdump, to capture additional logs from the aspect of the core network.
srsRAN_Project also enables logging by default. Logging levels and directories are customizable in the gnb.yml configuration file and include pcap options.
I will go over many scenarios that will aid in understanding 5G processes, troubleshooting network configurations, 5G Core and gNB connection setups, etc. using log files and Wireshark packet captures.
Collection Points
Open5GS pcap
srsRAN_Project gNB pcap
Tools
tcpdump
Wireshark
Text Editor (I use Sublime Text)
Open5GS Logging
Log configuration per network function is defined in individual config files (amf.yaml, smf.yaml, upf.yaml, etc.)
Open5GS Logging Levels: fatal, error, warn, info (default), debug, trace
To set the logging level on specific network functions to other than the default info level
I usually like to view amf, smf, or upf logs as I am testing the network. For this, I open a dedicated terminal window and use the command sudo tail -f /var/log/open5gs/amf.log
Open5GS does not have options for collecting pcaps, so when I feel it is necessary I use one of the following commands in a new terminal window
sudo tcpdump -i any sctp -w 5gc_sctp.pcapsudo tcpdump -i any -w 5gc.pcap
The SCTP pcap will collect SCTP and NGAP data, and ANY interface will collect all available interfaces on the 5GC computer.
srsRAN_Project Logging
Log configuration for the gNB is defined in the config file being used and can be modified to include multiple pcap interfaces and gNB log layers/components.
gNB logging levels: none, error, warning, info, debug
gNB layers and components: all, phy, mac, rlc, pdcp, rrc, sdap, ngap, gtpu, radio, fapi, ofh, f1ap, f1u, du, cu, sec, and lib.
gNB pcap layers: ngap, e1ap, f1ap, mac, e2ap, and gtpu.
When gNB is set to all_level: debug the following layers are collected…
[PCAP ]
[UDP-GW ]
[SCTP-GW ]
[GTPU ]
[FAPI ]
[GNB ]
[CU-CP ]
[CU-CP-E1]
[CU-UP-E1]
[CU-CP-F1]
[CU-F1-U ]
[CU-UEMNG]
[DU-MNG ]
[DU-F1 ]
[DU-F1-U ]
[RRC ]
[MAC ]
[RLC ]
[PDCP ]
[SDAP ]
[NGAP ]
[RF ]
[UL-PHY0 ]
[UL-PHY1 ]
[DL-PHY0 ]
[Low-PHY ]
[SCHED ]
I use Sublime Text to view and edit log files – some log levels (such as FAPI) tend to take up a lot of real estate, so as a workaround, I will use the “Find and Replace” tool in Sublime Text to remove all lines that contain certain strings
pcaps are generated based on what is defined in your gnb.yml config file – each new iteration that the gnb is run, the file will be overwritten. When I get a good collection that I want to look at in Wireshark, I will scp the files to my working computer.
You will need to set up your DLT_USER profile in Wireshark to view content from gNB pcaps. There are steps on how to do this for each interface here
5GC Network Function Startup
Open5GS Network Addresses and Ports
Preconditions: 5GC and gNB are not running. User starts 5GC.
During this step, the 5G Core is turned on.
amf.log
AMF initialization – creates a log, creates NGAP server for gNB
smf.log
SMF initialization – creates a log, creates GTP-C/GTP-U and PFCP server, Connects ogstun to UPF over PFCP, Associates with UPF over PFCP
upf.log
UPF initialization – creates a log, creates PFCP and GTP-U server, Connects ogstun to SMF over PFCP, Associates with SMF over PFCP
smf/upf ANY pcap
SMF and UPF connect via PFCP upon 5GC startup – SMF communicates with localhost
Other NW Functions ANY pcap
AUSF, UDM, and PCF will communicate with the localhost upon 5GC startup
gNB Startup
Preconditions: 5GC is running, gNB is not running. The user starts gNB.
During this step, the gNB connects to the 5G Core Network.
amf.log
The AMF accepts the gNB connection
Open5GS SCTP pcap
The SCTP Handshake process between the AMF and gNB followed by the NGAP setup procedure
gNB NGAP pcap
The gNB NGAP pcap only shows the NGAP setup messages – the NGSetupRequest is sent from the gNB to the AMF and the NGSetupResponse is sent from the AMF to the gNB
gNB F1AP pcap
The gNB F1AP pcap shows the connection between the gNB DU and the gNB CU – the cells MIB and SIB1 is passed in the F1SetupRequest from the gNB DU to the gnb CU and the F1SetupResponse is sent from the gNB CU to the gNB DU.
gNB.log
The gNB initiates the connection with the AMF, creates a binding for the gNB then connects to the SCTP/NGAP port with the AMF (port 38412). The UDP-GW is associated with the GTP-U port 2152. The gNB must also initialize and connect the F1 (gNB DU – gNB CU) and E1 (CU Control plane – CU User Plane) Interfaces. The gNB then extracts the necessary parameters for broadcasting the MIB and SIB1
Continuing with the gNB setup of the F1 interface, RRC parameters, broadcasting SIB1, and the cells transmit configuration.
UE Connect to 5G Network
To see a detailed flow chart of the process described in this section, please reference the document here.
Preconditions: 5GC and gNB are running. The user connects UE to the network.
amf.log
AMF Info level logging shows basic information about the UE as it interacts with the 5GC. The number of UEs associated with the gNB and AMF, RAN parameters, UE 5G S-TMSI, Registration Request including the 5G GUTI, UE Identity Response including SUCI, UE IMSI/SUPI
amf.log (trace level)
With Trace level logging we observe the above data more granularly. We’re able to see the AMF interact with the scp, ausf, and gNB with routing information for specific messages.
udr.log (trace level)
The UDR interfaces with the WebUI (User Database) to pull UE authentication information. With Trace level logging on, we can observe the UDR getting the k and OPc Keys for a subscriber IMSI from the User Database to ensure that the subscriber can access the network.
udm.log (trace level)
The UDM stores UE encryption keys for de-concealing the SUCI and converting to SUPI – since I am using null encrypted SIMs and Open5GS is not (can not?) be configured for ProfileA/ProfileB encryption, the SUCI is equivalent to the SUPI/IMSI value. The UDM also stores UE subscription data.
ausf.log (trace level)
In the AMF we can see the Authentication Vectors generated that are sent to the UE (RAND, AUTN) in the NAS Authentication Request.
gnb.log
The process of the UE attaching to the network actually starts with the gNB. It transmits the MIB and SIB1 which gives cell access parameters to the UE. This is important for all UEs that decode the cell’s Minimum System Information (MSI) so each UE knows which cells it can or cannot camp on. The UE then initiates the Random Access Procedure (RACH) on the UL PRACH channel to the gNB with RACH message 1 (Preamble).
The gNB responds with appropriate parameters in RACH message 2 (Random Access Response) on the PDSCH
The UE sends RACH Message 3 next, which includes the RRC Setup Request message
The final step in the Random Access Procedure is the gNB sending RACH message 4 with the RRC Setup and assigning the UE with SRB1 for follow-on
5gc.pcap
From the 5GC perspective, the pcap shows the entire Registration Process with the UE. This process includes the UE Registration Request, Identity Request procedure, Authentication Procedure, NAS Security Mode Procedure, and Registration Complete/Accept.
gnb ngap.pcap
Similar to what is seen in the 5GC pcap, the gNB NGAP pcap shows the Registration Procedure with the UE on the NAS layer. All of the messages that pass from the 5GC to the UE and vice versa, are forwarded by the gNB.
gnb mac.pcap
The gNB MAC pcap shows the RRC procedures between the gNB and the UE. RRC Procedures are only between the UE and the gNB, though some RRC messages contain NAS information which is forwarded to or from the 5GC.
UE Connect to Data Network
Preconditions: 5GC and gNB are running, and UE is Registered with Network. UE initiates the data session.
amf.log
The UE is registered with the network and now a PDU session is set up on the DNN: apn.
smf.log
The SMF allocates an IP address for the UE (10.45.0.2) based on the request DNN (apn) and DNN type (IPv4)
upf.log (trace level)
The UPF assigns the UE a Fully Qualified Session Endpoint Identifier (F-SEID) associated with the UE IP address
The UPF communicates with the SMF over PFCP (127.0.0.4:8805) with N4 messages. UPF connects to the gNB over GTP-U (100.122.128.121:2152). Also observe the Tunnel Endpoint Identifier (TEID) with the gNB
The UPF communicates with the gNB (100.122.128.121) and the UE (10.45.0.2). Observe additional TEID [0x1]
gnb.log
There is too much data in the gNB log to sift through that is already shown in the other logs here. When you want to see detailed messages that are happening at the DU/CU, RLC, MAC, PDCP, SDAP, and PHY levels, then it is a good idea to look here.
5gc.pcap
From the 5GC pcap, we can see the PDU Session Establishment Request from the UE and the PDU Session Establishment Accept from the 5GC.
gnb ngap.pcap
Similar to the 5GC pcap – the PDU Session Establishment Procedure with the UE and 5GC is sent via the gNB.
gnb mac.pcap
UE DNS Query (5GC pcap)
Now the UE has established a PDU Session it can now access external data networks. The UE will send a DNS query to the defined DNS server. The packet includes the gNB and 5GC IP addresses, the UDP port (GTP-U), and within the GTP-U header – the UE IP address (10.45.0.2) and the destination DNS server (8.8.8.8) followed by the UDP header with DNS port 53.
UE HTTP Request (gnb_gtpu.pcap)
In the gnb_gtpu.pcap – we can observe the UE sending an HTTP GET request to http://www.sqimway.com – the GTPU header includes the UPF TEID
The website responds to the UE via the gNB. Notice the gNB TEID in the GTP-U header.
Conclusion
When you can collect logs from as many points as possible you can start to rule out specific issues that may be occurring in your network. For example… In a different hardware/software configuration than referenced in this article, I was able to verify that my UE was decoding MIB and SIB1 and subsequently sending RACH message 1, but the process didn’t go any further. I confirmed with UE logs that Message 1 was being sent, and then checked the gNB logs to see if Message 1 was being received. It was not. The UE was sending the message at too high of a power and the gNB could not read the message. I adjusted the ss-PBCH-BlockPower in SIB1 so that Message 1 would be sent at lower power, and after some fine-tuning, the gNB was able to receive Message 1 and move past the Random Access Procedure.
There are good resources available that expand on a lot of the procedures that are outlined in this article.
https://derekcheung.medium.com/5g-core-part-1-architecture-overview-6d29160c5c0e
Leave a Reply