GTP5G-Tracer: Detailed Project Explanation

Overview

gtp5g-tracer is an eBPF-based network tracing tool specifically designed to monitor and trace GTP-U (GPRS Tunneling Protocol User Plane) traffic in 5G networks. It provides real-time visibility into packet flows through the GTP5G kernel module, which is crucial for debugging and monitoring 5G network performance.

What is GTP5G?

GTP (GPRS Tunneling Protocol) is a fundamental protocol in mobile networks that has been used from 2G/GPRS through 5G networks. Here's why it's important:

GTP5G-Tracer

Uplink Flow (UE → Internet)

+--------+        +--------+        +----------------+        +---------+
|   UE   | -----> |  gNB   | -----> | UPF GTP Module | -----> | Internet|
+--------+        +--------+        +----------------+        +---------+
                                           |
                                           | gtp5g_encap_recv() called
                                           ↓
                  +------------------------------------------+
                  | BPF fentry hook triggered                |
                  | - Logs PID, TGID, CPU                    |
                  | - Logs device name (e.g., wlp2s0)        |
                  +------------------------------------------+
                                           |
                                           | GTP packet processing
                                           | - GTP header removed
                                           | - Inner IP packet extracted
                                           ↓
                  +------------------------------------------+
                  | BPF fexit hook triggered                 |
                  | - Logs PID, TGID, CPU                    |
                  | - Logs device name (e.g., upfgtp)        |
                  +------------------------------------------+
                                           |
                                           ↓
                                    Packet continues
                                    to destination

Downlink Flow (Internet → UE)

+---------+        +----------------+        +--------+        +--------+
| Internet| -----> | UPF GTP Module | -----> |  gNB   | -----> |   UE   |
+---------+        +----------------+        +--------+        +--------+
                          |
                          | gtp5g_xmit_skb_ipv4() called
                          ↓
                  +------------------------------------------+
                  | BPF fentry hook triggered                |
                  | - Logs PID, TGID, CPU                    |
                  | - Logs device name (e.g., upfgtp)        |
                  +------------------------------------------+
                          |
                          | GTP packet processing
                          | - GTP header added
                          | - IP packet encapsulated
                          ↓
                  +------------------------------------------+
                  | BPF fexit hook triggered                 |
                  | - Logs PID, TGID, CPU                    |
                  | - Logs device name (e.g., wlp2s0)        |
                  +------------------------------------------+
                          |
                          ↓
                    Packet continues
                    to destination

Understanding the Log

The logs from the GTP5G tracer provide valuable insights into the packet flow through the GTP tunnels in our 5G network. Let's break down what each part of the log means:

after:

sudo cat /sys/kernel/debug/tracing/trace_pipe

irq/135-iwlwifi-457     [007] ..s21 534515.160592: bpf_trace_printk: fexit/gtp5g_encap_recv: PID=457, TGID=457, CPU=7
irq/135-iwlwifi-457     [007] ..s21 534515.160594: bpf_trace_printk: fexit/gtp5g_encap_recv: DEV=upfgtp

Uplink Packet Example

# Entry point - Packet arrives from UE
irq/135-iwlwifi-457     [007] ..s21 534516.239030: bpf_trace_printk: fentry/gtp5g_encap_recv: PID=457, TGID=457, CPU=7
irq/135-iwlwifi-457     [007] ..s21 534516.239035: bpf_trace_printk: fentry/gtp5g_encap_recv: DEV=wlp2s0

# Exit point - Packet processed and forwarded
irq/135-iwlwifi-457     [007] ..s21 534516.239047: bpf_trace_printk: fexit/gtp5g_encap_recv: PID=457, TGID=457, CPU=7
irq/135-iwlwifi-457     [007] ..s21 534516.239048: bpf_trace_printk: fexit/gtp5g_encap_recv: DEV=upfgtp

Analysis:

1. Packet arrives on wireless interface (wlp2s0)
2. GTP5G module processes it (taking 17 microseconds)
3. Packet exits on UPF GTP interface (upfgtp)
4. Processing happens in interrupt context (irq/135-iwlwifi)
5. Same CPU (7) handles the entire operation

Downlink Packet Example (Hypothetical)

# Entry point - Packet arrives from Internet
kworker/3:1-1234        [003] ..s21 534517.345030: bpf_trace_printk: fentry/gtp5g_xmit_skb_ipv4: PID=1234, TGID=1234, CPU=3
kworker/3:1-1234        [003] ..s21 534517.345035: bpf_trace_printk: fentry/gtp5g_xmit_skb_ipv4: DEV=upfgtp

# Exit point - Packet processed and forwarded
kworker/3:1-1234        [003] ..s21 534517.345047: bpf_trace_printk: fexit/gtp5g_xmit_skb_ipv4: PID=1234, TGID=1234, CPU=3
kworker/3:1-1234        [003] ..s21 534517.345048: bpf_trace_printk: fexit/gtp5g_xmit_skb_ipv4: DEV=wlp2s0

Analysis:
1. Packet arrives on UPF GTP interface (upfgtp)
2. GTP5G module processes it (taking 12 microseconds)
3. Packet exits on wireless interface (wlp2s0)
4. Processing happens in kernel worker context
5. Same CPU (3) handles the entire operation

Log Components

1. Process Information: irq/135-iwlwifi-457
2. This shows the process handling the packet
3. irq/135-iwlwifi indicates it's an interrupt handler for the WiFi interface

4. 457 is the process ID

5. CPU Core: [007]

6. The packet is being processed on CPU core 7

7. Timestamp: 534515.160592

8. Time in seconds since system boot when this event occurred

9. Trace Source: bpf_trace_printk

10. Indicates the log was generated by our eBPF program using the bpf_printk() function

11. Function and Event Type: fexit/gtp5g_encap_recv

12. fexit means this is logged at the exit point of the function

13. gtp5g_encap_recv is the function being traced (handling uplink traffic)

14. Process Details: PID=457, TGID=457, CPU=7

15. PID: Process ID handling the packet
16. TGID: Thread Group ID (main process ID)

17. CPU: Confirms which CPU core is processing the packet

18. Interface: DEV=upfgtp or DEV=wlp2s0

19. The network device handling the packet
20. upfgtp is the GTP tunnel interface for the User Plane Function
21. wlp2s0 is likely your wireless network interface

Packet Flow Analysis

Looking at the sequence of logs:

irq/135-iwlwifi-457     [007] ..s21 534516.239030: bpf_trace_printk: fentry/gtp5g_encap_recv: PID=457, TGID=457, CPU=7
irq/135-iwlwifi-457     [007] ..s21 534516.239035: bpf_trace_printk: fentry/gtp5g_encap_recv: DEV=wlp2s0
irq/135-iwlwifi-457     [007] ..s21 534516.239047: bpf_trace_printk: fexit/gtp5g_encap_recv: PID=457, TGID=457, CPU=7
irq/135-iwlwifi-457     [007] ..s21 534516.239048: bpf_trace_printk: fexit/gtp5g_encap_recv: DEV=upfgtp

This sequence shows a complete uplink packet flow:

1. Packet Entry (fentry/gtp5g_encap_recv):
2. A packet enters the gtp5g_encap_recv function
3. It comes from the wireless interface wlp2s0

4. This is the start of uplink processing (UE → Core Network)

5. Packet Exit (fexit/gtp5g_encap_recv):

6. The same packet exits the function after processing
7. It's now associated with the upfgtp interface

8. This shows the packet has been successfully encapsulated in a GTP tunnel

9. Processing Time:

10. The time difference between entry and exit (534516.239047 - 534516.239030 = 0.000017 seconds or 17 microseconds)
11. This represents the processing overhead of GTP encapsulation

What This Tells Us

1. Uplink Traffic Flow:
2. The logs show packets coming from the wireless interface (likely from a UE)
3. These packets are being encapsulated into GTP tunnels

4. They exit through the UPF's GTP interface toward the core network

5. GTP Tunnel Operation:

6. The GTP5G module is successfully receiving packets from the wireless interface
7. It's processing them through the gtp5g_encap_recv function

8. It's forwarding them through the GTP tunnel interface

9. Performance Insights:

10. Processing time is in microseconds, showing efficient packet handling
11. The same CPU core (7) handles the entire operation, avoiding inter-core communication overhead
12. The interrupt handler for the wireless card is directly involved in the GTP processing

Significance for 5G Networks

These logs confirm that:

1. The GTP5G kernel module is correctly handling uplink traffic
2. Packets are being properly encapsulated into GTP tunnels
3. The data path from UE to core network is functioning

This tracing capability is valuable for:
- Debugging GTP tunnel issues
- Performance analysis of the 5G user plane
- Verifying correct packet flow in a 5G deployment
- Identifying potential bottlenecks in packet processing

BPF Tracing vs. Traditional Tracing Methods

Feature	BPF Tracing	tcpdump
Overhead	Very low	Medium
Kernel Modification	No	No
Granularity	Function level	Packet level
Context Information	Rich (PID, CPU, etc.)	Limited
Dynamic Attachment	Yes	N/A
Safety	Verified by kernel	N/A
Performance Impact	Minimal	Medium

Next Steps: Hand-on some new entry

To gain further insights:
1. Compare with downlink traffic (look for gtp5g_xmit_skb_ipv4 entries)
2. Correlate with actual application performance
3. Monitor under different load conditions
4. Compare processing times across different packet types and sizes

List available functions in GTP5G:

wirelab@wirelab-14Z980-G-AA52C2:~/work/gtp5g-tracer$ sudo cat /sys/kernel/tracing/available_filter_functions | grep "gtp5g"
[sudo] password for wirelab: 
get_dbg_lvl [gtp5g]
set_dbg_lvl [gtp5g]
ip_string [gtp5g]
gtp5g_dev_uninit [gtp5g]
gtp5g_dev_init [gtp5g]
gtp5g_find_dev [gtp5g]
update_usage_statistic [gtp5g]
gtp5g_dev_xmit [gtp5g]
dev_hashtable_new [gtp5g]
gtp5g_hashtable_free [gtp5g]
gtp5g_encap_disable.part.0 [gtp5g]
gtp5g_encap_disable_locked [gtp5g]
    .
    .
    .

These functions handle the main packet processing flow:

Function	Description	Tracing Value
gtp5g_encap_recv	Handles uplink GTP packets	High - Entry point for uplink traffic
gtp5g_xmit_skb_ipv4	Transmits downlink packets	High - Entry point for downlink traffic
gtp5g_handle_skb_ipv4	Processes IPv4 packets	High - Core packet handling
gtp5g_push_header	Adds GTP header to packets	Medium - Header encapsulation
ip4_find_route	Finds routing for IPv4 packets	Medium - Routing decisions
ip_xmit	Transmits IP packets	Medium - Final transmission

These functions handle QoS enforcement and traffic policing:

Function	Description	Tracing Value
policePacket	Applies traffic policing	High - QoS enforcement
update_counter	Updates traffic counters	Medium - Traffic accounting
update_usage_statistic	Updates usage statistics	Medium - Usage tracking
check_counter	Checks traffic counters	Low - Counter verification

These functions handle device initialization and management:

Function	Description	Tracing Value
gtp5g_dev_init	Initializes GTP5G device	Medium - Device setup
gtp5g_dev_uninit	Uninitializes GTP5G device	Medium - Device cleanup
gtp5g_find_dev	Finds GTP5G device	Low - Device lookup
gtp5g_link_setup	Sets up GTP5G link	Medium - Link establishment

Enhanced GTP5G Tracing: Advanced Analysis Guide

This document provides a comprehensive explanation of the enhanced GTP5G tracer, focusing on the advanced features we've implemented and how to interpret the detailed trace output.

1. Introduction to Enhanced Tracing

The enhanced GTP5G tracer provides deep visibility into the GTP5G kernel module's packet processing pipeline. Our advanced tracing features now capture:

• Packet lengths at various processing stages
• High-precision timestamps for performance analysis
• Hexadecimal representation of memory pointers
• Device transitions during packet processing
• GTP packet detection
• Packet metadata presence

2. Key Enhancements

2.1 Packet Length Tracking

We now track packet sizes throughout the processing pipeline:

if (skb)
{
    skb_len = skb->len;
    bpf_printk("fentry/gtp5g_xmit_skb_ipv4: LEN=%u, TS=%llu", skb_len, ts);
}

This allows us to observe GTP header overhead and packet transformations.

2.2 High-Precision Timestamps

Nanosecond timestamps enable precise performance measurements:

__u64 ts = bpf_ktime_get_ns();
bpf_printk("fexit/gtp5g_push_header: RET=0x%x (skb ptr), LEN=%u, TS=%llu", ret, skb_len, ts);

2.3 Improved Return Value Presentation

Return values are now displayed in hexadecimal with explanatory comments:

bpf_printk("fexit/gtp5g_handle_skb_ipv4: PID=%u, TGID=%u, RET=0x%x (skb ptr)", pid, tgid, ret);

2.4 Device Transition Tracking

We explicitly track which network interfaces packets traverse:

if (skb && skb->dev)
{
    bpf_printk("fentry/gtp5g_xmit_skb_ipv4: DEV=%s", skb->dev->name);
}

3. Packet Flow Analysis

3.1 Uplink Flow (UE → Core Network)

The trace clearly shows the uplink packet flow:

# Packet arrives on external interface (wlp2s0)
irq/135-iwlwifi-457 [007] ..s21 592868.790221: bpf_trace_printk: fentry/gtp5g_encap_recv: DEV=wlp2s0
irq/135-iwlwifi-457 [007] ..s21 592868.790223: bpf_trace_printk: fentry/gtp5g_encap_recv: GTP packet detected (len >= 8)
irq/135-iwlwifi-457 [007] ..s21 592868.790225: bpf_trace_printk: fentry/gtp5g_encap_recv: PID=457, TGID=457, CPU=7, LEN=108

# PDR lookup succeeds
irq/135-iwlwifi-457 [007] ..s21 592868.790227: bpf_trace_printk: fentry/pdr_find_by_gtp1u: PID=457, TGID=457
irq/135-iwlwifi-457 [007] ..s21 592868.790230: bpf_trace_printk: fexit/pdr_find_by_gtp1u: PID=457, PDR=Found

# Packet exits on internal interface (upfgtp) after processing
irq/135-iwlwifi-457 [007] ..s21 592868.790238: bpf_trace_printk: fexit/gtp5g_encap_recv: PID=457, TGID=457, CPU=7
irq/135-iwlwifi-457 [007] ..s21 592868.790239: bpf_trace_printk: fexit/gtp5g_encap_recv: DEV=upfgtp

Key observations:
- Initial packet length: 108 bytes (includes GTP header)
- GTP packet detection confirms GTP-U protocol
- PDR lookup succeeds, indicating proper rule configuration
- Device transition: wlp2s0 (external) → upfgtp (internal)

3.2 Downlink Flow (Core Network → UE)

The downlink flow is equally well-documented:

# Packet starts on internal interface (upfgtp)
irq/135-iwlwifi-457 [007] b.s21 592868.797649: bpf_trace_printk: fentry/gtp5g_handle_skb_ipv4: PID=457, TGID=457, CPU=7
irq/135-iwlwifi-457 [007] b.s21 592868.797650: bpf_trace_printk: fentry/gtp5g_handle_skb_ipv4: DEV=upfgtp

# GTP header addition (encapsulation)
irq/135-iwlwifi-457 [007] b.s21 592868.797655: bpf_trace_printk: fentry/gtp5g_push_header: PID=457, TGID=457, LEN=84
irq/135-iwlwifi-457 [007] b.s21 592868.797655: bpf_trace_printk: fentry/gtp5g_push_header: DEV=upfgtp
irq/135-iwlwifi-457 [007] b.s21 592868.797657: bpf_trace_printk: fexit/gtp5g_push_header: RET=0xc02cc8d0 (skb ptr), LEN=100, TS=592873802793332

# Packet handling completed with new size
irq/135-iwlwifi-457 [007] b.s21 592868.797661: bpf_trace_printk: fexit/gtp5g_handle_skb_ipv4: LEN=100, TS=592873802797124
irq/135-iwlwifi-457 [007] b.s21 592868.797662: bpf_trace_printk: fexit/gtp5g_handle_skb_ipv4: PID=457, TGID=457, RET=0x13dfa000 (skb ptr)

# Packet transmission begins
irq/135-iwlwifi-457 [007] b.s21 592868.797664: bpf_trace_printk: fentry/gtp5g_xmit_skb_ipv4: DEV=upfgtp
irq/135-iwlwifi-457 [007] b.s21 592868.797664: bpf_trace_printk: fentry/gtp5g_xmit_skb_ipv4: LEN=100, TS=592873802800132
irq/135-iwlwifi-457 [007] b.s21 592868.797665: bpf_trace_printk: fentry/gtp5g_xmit_skb_ipv4: pktinfo exists

# Packet exits on external interface with final size
irq/135-iwlwifi-457 [007] b.s21 592868.797680: bpf_trace_printk: fexit/gtp5g_xmit_skb_ipv4: DEV=wlp2s0
irq/135-iwlwifi-457 [007] b.s21 592868.797681: bpf_trace_printk: fexit/gtp5g_xmit_skb_ipv4: LEN=170, TS=592873802816526

Key observations:
- Initial packet length: 84 bytes (IP packet)
- After GTP header addition: 100 bytes (+16 bytes GTP header)
- Final packet length: 170 bytes (additional headers added during transmission)
- Device transition: upfgtp (internal) → wlp2s0 (external)
- Return values shown as memory pointers (0xc02cc8d0, 0x13dfa000)

4. Performance Analysis

4.1 Function Processing Time

With high-precision timestamps, we can calculate processing times:

# gtp5g_push_header function
Entry: TS=592873802793332
Exit:  TS=592873802797124
Duration: 3,792 nanoseconds (3.8 microseconds)

# gtp5g_xmit_skb_ipv4 function
Entry: TS=592873802800132
Exit:  TS=592873802816526
Duration: 16,394 nanoseconds (16.4 microseconds)

4.2 GTP Header Overhead

The traces clearly show the GTP header size:

Before encapsulation: 84 bytes
After encapsulation:  100 bytes
GTP header overhead:  16 bytes

Conclusion

The enhanced GTP5G tracer provides unprecedented visibility into the GTP5G kernel module's packet processing pipeline. With detailed packet length tracking, high-precision timestamps, improved return value presentation, and device transition tracking, it's now possible to gain deep insights into GTP-U packet processing, troubleshoot issues, and optimize performance.

This level of visibility is essential for understanding, debugging, and optimizing 5G User Plane Function (UPF) implementations, making it an invaluable tool for 5G core network development and operations.

About

Hello, I'm William Lin. I'd like to share my excitement about being a member of the free5GC project, which is a part of the Linux Foundation. I'm always eager to discuss any aspects of core network development or related technologies.

Connect with Me

• GitHub: williamlin0518
• Linkedin: Cheng Wei Lin