eUPF Integration with Nokia CMU SMF #535

howardswe499 · 2024-03-12T08:47:09Z

howardswe499
Mar 12, 2024

Hi All,

I'm trying to perform integration with Nokia CMU (Nokia's 5G core solution), using eUPF as UPF and UERANSIM as UE+RAN.

I've run into a problem where eUPF seems to be unable to forward packets that are received from RAN. On the tcpdump of packets outgoing RAN, when performing "ping -I uesimtun0 8.8.8.8", I'm getting "ICMP udp port 2152 unreachable" message from eUPF.

(192.168.102.54 = UERANSIM; 192.168.102.55 = eUPF)

Here are the logs of eUPF:

[+] Running 2/0
 ✔ Container eupf-docker-net-tools-1  Created                                                                                                                                0.0s 
 ✔ Container eupf-docker-eupf-1       Created                                                                                                                                0.0s 
Attaching to eupf-1, net-tools-1
net-tools-1  | The directory /usr/share/nginx/html is not mounted.
net-tools-1  | Over-writing the default index.html file with some useful information.
eupf-1       | 2024/03/05 08:34:20 Unable to read config file: open ./config.yml: no such file or directory. Using defaults
eupf-1       | 2024/03/05 08:34:20 Startup config: map[api_address::8080 echo_interval:10 far_map_size:1024 feature_ftup:true feature_ueip:true gtp_peer:[] heartbeat_interval:5 heartbeat_retries:3 heartbeat_timeout:5 interface_name:ens192,ens224 logging_level:debug metrics_address::9091 n3_address:192.168.102.55 pdr_map_size:1024 pfcp_address::8805 pfcp_node_id:192.168.102.55 qer_map_size:1024 resize_ebpf_maps:false teid_pool:65535 ueip_pool:10.60.0.0/24 xdp_attach_mode:generic]
net-tools-1  | RTNETLINK answers: File exists
net-tools-1  | RTNETLINK answers: File exists
net-tools-1  | RTNETLINK answers: File exists
net-tools-1  | RTNETLINK answers: No such process
net-tools-1  | done
eupf-1       | 2024/03/05 08:34:20 Apply eUPF config: {InterfaceName:[ens192 ens224] XDPAttachMode:generic ApiAddress::8080 PfcpAddress::8805 PfcpNodeId:192.168.102.55 MetricsAddress::9091 N3Address:192.168.102.55 GtpPeer:[] EchoInterval:10 QerMapSize:1024 FarMapSize:1024 PdrMapSize:1024 EbpfMapResize:false HeartbeatRetries:3 HeartbeatInterval:5 HeartbeatTimeout:5 LoggingLevel:debug UEIPPool:10.60.0.0/24 FTEIDPool:65535 FeatureUEIP:true FeatureFTUP:true}
eupf-1       | 2024/03/05 08:34:20 INF Attached XDP program to iface "ens192" (index 2)
eupf-1       | 2024/03/05 08:34:20 INF Attached XDP program to iface "ens224" (index 3)
eupf-1       | 2024/03/05 08:34:20 INF Initialize resources: UEIP pool (CIDR: "10.60.0.0/24"), TEID pool (size: 65535)
eupf-1       | 2024/03/05 08:34:20 INF Starting PFCP connection: :8805 with Node ID: 192.168.102.55 and N3 address: 192.168.102.55
eupf-1       | 2024/03/05 08:34:20 INF running on :8080
eupf-1       | 2024/03/05 08:34:20 INF running on :9091

[removed unrelated info]

eupf-1       | 2024/03/05 08:34:46 WRN Got unexpected message Association Release Request: {Version: 1, Flags: {FO: false, MP: false, S: false}, Type: 9, Length: 13, SEID: 0x0000000000000000, SequenceNumber: 0x3, MessagePriority: 0, Payload: 0x003c0005000af6703e}, from: 10.246.112.62:8805
eupf-1       | 2024/03/05 08:34:50 DBG Sent Heartbeat Request to: 192.168.102.52
eupf-1       | 2024/03/05 08:34:50 DBG Received 16 bytes from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:34:50 DBG Handling PFCP message from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:34:50 DBG Got Heartbeat Response with TS: 2024-03-05 06:38:06 +0000 UTC, from: 192.168.102.52
eupf-1       | 2024/03/05 08:34:51 DBG Received 25 bytes from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:34:51 DBG Handling PFCP message from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:34:51 INF Got Association Setup Request from: 10.246.112.62. 
eupf-1       | 
eupf-1       | 2024/03/05 08:34:51 INF 
eupf-1       | Association Setup Request:
eupf-1       |   Node ID: 10.246.112.62
eupf-1       |   Recovery Time: 2024-03-05 08:34:52 +0000 UTC
eupf-1       | 
eupf-1       | 2024/03/05 08:34:51 INF Saving new association: &{ID:10.246.112.62 Addr:10.246.112.62 NextSessionID:1 NextSequenceID:1 Sessions:map[] HeartbeatChannel:0xc0004f54a0 FailedHeartbeats:0 HeartbeatsActive:false Mutex:{state:0 sema:0}}
eupf-1       | 2024/03/05 08:34:51 DBG Received 16 bytes from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:34:51 DBG Handling PFCP message from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:34:51 DBG Got Heartbeat Request with TS: 2024-03-05 08:34:52 +0000 UTC, from: 10.246.112.62
eupf-1       | 2024/03/05 08:34:51 DBG Sent Heartbeat Response to: 10.246.112.62
eupf-1       | 2024/03/05 08:34:54 DBG Received 16 bytes from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:34:54 DBG Handling PFCP message from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:34:54 DBG Got Heartbeat Request with TS: 2024-03-05 06:38:06 +0000 UTC, from: 192.168.102.52
eupf-1       | 2024/03/05 08:34:54 DBG Sent Heartbeat Response to: 192.168.102.52
eupf-1       | 2024/03/05 08:34:55 DBG Sent Heartbeat Request to: 10.246.112.62
eupf-1       | 2024/03/05 08:34:55 DBG Sent Heartbeat Request to: 192.168.102.52
eupf-1       | 2024/03/05 08:34:55 DBG Received 16 bytes from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:34:55 DBG Handling PFCP message from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:34:55 DBG Got Heartbeat Response with TS: 2024-03-05 06:38:06 +0000 UTC, from: 192.168.102.52
eupf-1       | 2024/03/05 08:34:55 DBG Received 16 bytes from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:34:55 DBG Handling PFCP message from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:34:55 DBG Got Heartbeat Response with TS: 2024-03-05 08:34:52 +0000 UTC, from: 10.246.112.62
eupf-1       | 2024/03/05 08:35:00 DBG Sent Heartbeat Request to: 192.168.102.52
eupf-1       | 2024/03/05 08:35:00 DBG Sent Heartbeat Request to: 10.246.112.62
eupf-1       | 2024/03/05 08:35:00 DBG Received 16 bytes from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:00 DBG Handling PFCP message from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:00 DBG Got Heartbeat Response with TS: 2024-03-05 06:38:06 +0000 UTC, from: 192.168.102.52
eupf-1       | 2024/03/05 08:35:00 DBG Received 16 bytes from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:00 DBG Handling PFCP message from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:00 DBG Got Heartbeat Response with TS: 2024-03-05 08:34:52 +0000 UTC, from: 10.246.112.62
eupf-1       | 2024/03/05 08:35:01 DBG Received 658 bytes from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:01 DBG Handling PFCP message from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:01 INF Got Session Establishment Request from: 10.246.112.62.
eupf-1       | 2024/03/05 08:35:01 INF 
eupf-1       | Session Establishment Request:
eupf-1       |   CreatePDR ID: 18944 
eupf-1       |     Outer Header Removal: 1 
eupf-1       |     FAR ID: 327680 
eupf-1       |     QER ID: 57 
eupf-1       |     QER ID: 4117 
eupf-1       |     URR ID: 1610612737 
eupf-1       |     Source Interface: 0 
eupf-1       |     TEID: 0 
eupf-1       |     Ipv4: <nil> 
eupf-1       |     Ipv6: <nil> 
eupf-1       |     UE IPv4 Address: 10.246.115.216 
eupf-1       |     SDF Filter: permit out ip from any to any 
eupf-1       |   CreatePDR ID: 35328 
eupf-1       |     FAR ID: 537198592 
eupf-1       |     QER ID: 57 
eupf-1       |     QER ID: 4117 
eupf-1       |     URR ID: 1610612737 
eupf-1       |     Source Interface: 1 
eupf-1       |     UE IPv4 Address: 10.246.115.216 
eupf-1       |     SDF Filter:  
eupf-1       |   CreateFAR ID: 327680 
eupf-1       |     Apply Action: [2] 
eupf-1       |     Forwarding Parameters:
eupf-1       |       Network Instance: 5gtest1 
eupf-1       |   CreateFAR ID: 537198592 
eupf-1       |     Apply Action: [4] 
eupf-1       |     Forwarding Parameters:
eupf-1       |       Network Instance:n3-realm 
eupf-1       |     BAR ID: 5 
eupf-1       |   CreateQER ID: 57 
eupf-1       |     Gate Status DL: 0 
eupf-1       |     Gate Status UL: 0 
eupf-1       |     Max Bitrate DL: 5000000 
eupf-1       |     Max Bitrate UL: 5000000 
eupf-1       |   CreateQER ID: 4117 
eupf-1       |     Gate Status DL: 0 
eupf-1       |     Gate Status UL: 0 
eupf-1       |     QFI: 5 
eupf-1       |   CreateURR ID: 1610612737 
eupf-1       |     Measurement Method: 3 
eupf-1       |   CreateURR ID: 1073741829 
eupf-1       |     Measurement Method: 2 
eupf-1       |     Volume Threshold: &{Flags:1 TotalVolume:104857600 UplinkVolume:0 DownlinkVolume:0} 
eupf-1       |   CreateURR ID: 1073741825 
eupf-1       |     Measurement Method: 2 
eupf-1       |   CreateBAR ID: 5
eupf-1       |     Downlink Data Notification Delay: 0s 
eupf-1       | 
eupf-1       | 2024/03/05 08:35:01 INF WARN: No OuterHeaderCreation
eupf-1       | 2024/03/05 08:35:01 INF Saving FAR info to session: 327680, {Action:2 OuterHeaderCreation:0 Teid:0 RemoteIP:0 LocalIP:929474752 TransportLevelMarking:0}
eupf-1       | 2024/03/05 08:35:01 DBG EBPF: Put FAR: internalId=3, qerInfo={Action:2 OuterHeaderCreation:0 Teid:0 RemoteIP:0 LocalIP:929474752 TransportLevelMarking:0}
eupf-1       | 2024/03/05 08:35:01 INF WARN: No OuterHeaderCreation
eupf-1       | 2024/03/05 08:35:01 INF Saving FAR info to session: 537198592, {Action:4 OuterHeaderCreation:0 Teid:0 RemoteIP:0 LocalIP:929474752 TransportLevelMarking:0}
eupf-1       | 2024/03/05 08:35:01 DBG EBPF: Put FAR: internalId=4, qerInfo={Action:4 OuterHeaderCreation:0 Teid:0 RemoteIP:0 LocalIP:929474752 TransportLevelMarking:0}
eupf-1       | 2024/03/05 08:35:01 INF Saving QER info to session: 57, {GateStatusUL:0 GateStatusDL:0 Qfi:0 MaxBitrateUL:705032704 MaxBitrateDL:705032704 StartUL:0 StartDL:0}
eupf-1       | 2024/03/05 08:35:01 DBG EBPF: Put QER: internalId=1, qerInfo={GateStatusUL:0 GateStatusDL:0 Qfi:0 MaxBitrateUL:705032704 MaxBitrateDL:705032704 StartUL:0 StartDL:0}
eupf-1       | 2024/03/05 08:35:01 INF Saving QER info to session: 4117, {GateStatusUL:0 GateStatusDL:0 Qfi:5 MaxBitrateUL:0 MaxBitrateDL:0 StartUL:0 StartDL:0}
eupf-1       | 2024/03/05 08:35:01 DBG EBPF: Put QER: internalId=2, qerInfo={GateStatusUL:0 GateStatusDL:0 Qfi:5 MaxBitrateUL:0 MaxBitrateDL:0 StartUL:0 StartDL:0}
eupf-1       | 2024/03/05 08:35:01 DBG EBPF: Put PDR Uplink: teid=1, pdrInfo={OuterHeaderRemoval:1 FarId:3 QerId:1 SdfFilter:{Protocol:1 SrcAddress:{Type:0 Ip:<nil> Mask:<nil>} SrcPortRange:{LowerBound:0 UpperBound:65535} DstAddress:{Type:0 Ip:<nil> Mask:<nil>} DstPortRange:{LowerBound:0 UpperBound:65535}}}
eupf-1       | 2024/03/05 08:35:01 ERR SDFFilter err: SDF Filter: bad formatting. Should be compatible with regexp: ^permit out (icmp|ip|tcp|udp|\d+) from (any|[\d.]+|[\da-fA-F:]+)(?:/(\d+))?(?: (\d+|\d+-\d+))? to (assigned|any|[\d.]+|[\da-fA-F:]+)(?:/(\d+))?(?: (\d+|\d+-\d+))?$
eupf-1       | 2024/03/05 08:35:01 ERR error extracting PDR info: SDF Filter: bad formatting. Should be compatible with regexp: ^permit out (icmp|ip|tcp|udp|\d+) from (any|[\d.]+|[\da-fA-F:]+)(?:/(\d+))?(?: (\d+|\d+-\d+))? to (assigned|any|[\d.]+|[\da-fA-F:]+)(?:/(\d+))?(?: (\d+|\d+-\d+))?$
eupf-1       | 2024/03/05 08:35:01 INF Session Establishment Request from 10.246.112.62 accepted.
eupf-1       | 2024/03/05 08:35:01 Matched groups: [permit out ip from any to any ip any   any  ]
eupf-1       | 2024/03/05 08:35:01 Matched groups: []
eupf-1       | 2024/03/05 08:35:02 DBG Received 80 bytes from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:02 DBG Handling PFCP message from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:02 INF Got Session Modification Request from: 10.246.112.62. 
eupf-1       | 
eupf-1       | 2024/03/05 08:35:02 INF Finding association for 10.246.112.62
eupf-1       | 2024/03/05 08:35:02 INF Finding session 2
eupf-1       | 2024/03/05 08:35:02 INF 
eupf-1       | Session Modification Request:
eupf-1       |   UpdateFAR ID: 537198592 
eupf-1       |     Apply Action: [2] 
eupf-1       |     Update forwarding Parameters:
eupf-1       |       Network Instance:n3-realm 
eupf-1       |       Outer Header Creation: &{OuterHeaderCreationDescription:256 TEID:1 IPv4Address:192.168.102.54 IPv6Address:<nil> PortNumber:0 CTag:0 STag:0} 
eupf-1       | 
eupf-1       | 2024/03/05 08:35:02 INF Updating FAR info: 537198592, {FarInfo:{Action:2 OuterHeaderCreation:1 Teid:1 RemoteIP:912697536 LocalIP:929474752 TransportLevelMarking:0} GlobalId:4}
eupf-1       | 2024/03/05 08:35:02 DBG EBPF: Update FAR: internalId=4, farInfo={Action:2 OuterHeaderCreation:1 Teid:1 RemoteIP:912697536 LocalIP:929474752 TransportLevelMarking:0}
eupf-1       | 2024/03/05 08:35:05 DBG Received 16 bytes from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:05 DBG Handling PFCP message from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:05 DBG Got Heartbeat Request with TS: 2024-03-05 06:38:06 +0000 UTC, from: 192.168.102.52
eupf-1       | 2024/03/05 08:35:05 DBG Sent Heartbeat Response to: 192.168.102.52
eupf-1       | 2024/03/05 08:35:05 DBG Sent Heartbeat Request to: 192.168.102.52
eupf-1       | 2024/03/05 08:35:05 DBG Received 16 bytes from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:05 DBG Handling PFCP message from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:05 DBG Got Heartbeat Response with TS: 2024-03-05 06:38:06 +0000 UTC, from: 192.168.102.52
eupf-1       | 2024/03/05 08:35:05 DBG Sent Heartbeat Request to: 10.246.112.62
eupf-1       | 2024/03/05 08:35:05 DBG Received 16 bytes from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:05 DBG Handling PFCP message from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:05 DBG Got Heartbeat Response with TS: 2024-03-05 08:34:52 +0000 UTC, from: 10.246.112.62
eupf-1       | 2024/03/05 08:35:10 DBG Sent Heartbeat Request to: 192.168.102.52
eupf-1       | 2024/03/05 08:35:10 DBG Received 16 bytes from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:10 DBG Handling PFCP message from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:10 DBG Got Heartbeat Response with TS: 2024-03-05 06:38:06 +0000 UTC, from: 192.168.102.52
eupf-1       | 2024/03/05 08:35:10 DBG Sent Heartbeat Request to: 10.246.112.62
eupf-1       | 2024/03/05 08:35:10 DBG Received 16 bytes from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:10 DBG Handling PFCP message from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:10 DBG Got Heartbeat Response with TS: 2024-03-05 08:34:52 +0000 UTC, from: 10.246.112.62
eupf-1       | 2024/03/05 08:35:15 DBG Sent Heartbeat Request to: 192.168.102.52
eupf-1       | 2024/03/05 08:35:15 DBG Received 16 bytes from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:15 DBG Handling PFCP message from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:15 DBG Got Heartbeat Response with TS: 2024-03-05 06:38:06 +0000 UTC, from: 192.168.102.52
eupf-1       | 2024/03/05 08:35:15 DBG Sent Heartbeat Request to: 10.246.112.62
eupf-1       | 2024/03/05 08:35:15 DBG Received 16 bytes from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:15 DBG Handling PFCP message from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:15 DBG Got Heartbeat Response with TS: 2024-03-05 08:34:52 +0000 UTC, from: 10.246.112.62
eupf-1       | 2024/03/05 08:35:16 DBG Received 16 bytes from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:16 DBG Handling PFCP message from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:16 DBG Got Heartbeat Request with TS: 2024-03-05 06:38:06 +0000 UTC, from: 192.168.102.52
eupf-1       | 2024/03/05 08:35:16 DBG Sent Heartbeat Response to: 192.168.102.52
eupf-1       | 2024/03/05 08:35:20 DBG Sent Heartbeat Request to: 192.168.102.52
eupf-1       | 2024/03/05 08:35:20 DBG Received 16 bytes from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:20 DBG Handling PFCP message from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:20 DBG Got Heartbeat Response with TS: 2024-03-05 06:38:06 +0000 UTC, from: 192.168.102.52
eupf-1       | 2024/03/05 08:35:20 DBG Sent Heartbeat Request to: 10.246.112.62
eupf-1       | 2024/03/05 08:35:20 DBG Received 16 bytes from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:20 DBG Handling PFCP message from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:20 DBG Got Heartbeat Response with TS: 2024-03-05 08:34:52 +0000 UTC, from: 10.246.112.62
eupf-1       | 2024/03/05 08:35:25 DBG Sent Heartbeat Request to: 192.168.102.52
eupf-1       | 2024/03/05 08:35:25 DBG Received 16 bytes from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:25 DBG Handling PFCP message from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:25 DBG Got Heartbeat Response with TS: 2024-03-05 06:38:06 +0000 UTC, from: 192.168.102.52
eupf-1       | 2024/03/05 08:35:25 DBG Sent Heartbeat Request to: 10.246.112.62
eupf-1       | 2024/03/05 08:35:25 DBG Received 16 bytes from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:25 DBG Handling PFCP message from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:25 DBG Got Heartbeat Response with TS: 2024-03-05 08:34:52 +0000 UTC, from: 10.246.112.62
eupf-1       | 2024/03/05 08:35:27 DBG Received 16 bytes from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:27 DBG Handling PFCP message from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:27 DBG Got Heartbeat Request with TS: 2024-03-05 06:38:06 +0000 UTC, from: 192.168.102.52
eupf-1       | 2024/03/05 08:35:27 DBG Sent Heartbeat Response to: 192.168.102.52
eupf-1       | 2024/03/05 08:35:30 DBG Sent Heartbeat Request to: 192.168.102.52
eupf-1       | 2024/03/05 08:35:30 DBG Received 16 bytes from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:30 DBG Handling PFCP message from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:30 DBG Got Heartbeat Response with TS: 2024-03-05 06:38:06 +0000 UTC, from: 192.168.102.52
eupf-1       | 2024/03/05 08:35:30 DBG Sent Heartbeat Request to: 10.246.112.62
eupf-1       | 2024/03/05 08:35:30 DBG Received 16 bytes from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:30 DBG Handling PFCP message from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:30 DBG Got Heartbeat Response with TS: 2024-03-05 08:34:52 +0000 UTC, from: 10.246.112.62
eupf-1       | 2024/03/05 08:35:35 DBG Sent Heartbeat Request to: 192.168.102.52
eupf-1       | 2024/03/05 08:35:35 DBG Received 16 bytes from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:35 DBG Handling PFCP message from 192.168.102.52:8805
eupf-1       | 2024/03/05 08:35:35 DBG Got Heartbeat Response with TS: 2024-03-05 06:38:06 +0000 UTC, from: 192.168.102.52
eupf-1       | 2024/03/05 08:35:35 DBG Sent Heartbeat Request to: 10.246.112.62
eupf-1       | 2024/03/05 08:35:35 DBG Received 16 bytes from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:35 DBG Handling PFCP message from 10.246.112.62:8805
eupf-1       | 2024/03/05 08:35:35 DBG Got Heartbeat Response with TS: 2024-03-05 08:34:52 +0000 UTC, from: 10.246.112.62
Gracefully stopping... (press Ctrl+C again to force)
[+] Stopping 2/2
 ✔ Container eupf-docker-net-tools-1  Stopped                                                                                                                               10.3s 
 ✔ Container eupf-docker-eupf-1       Stopped                                                                                                                                0.2s 
canceled

Here are the logs of UERANSIM:

======================
=== UERANSIM (RAN) ===
======================
^Croot@da-ueransim:~/UERANSIM/config/[redacted]# ../../build/nr-gnb -c ./[redacted] 
UERANSIM v3.2.6
[2024-03-05 16:34:58.835] [sctp] [info] Trying to establish SCTP connection... (10.246.112.18:38412)
[2024-03-05 16:34:58.864] [sctp] [info] SCTP connection established (10.246.112.18:38412)
[2024-03-05 16:34:58.864] [sctp] [debug] SCTP association setup ascId[32]
[2024-03-05 16:34:58.864] [ngap] [debug] Sending NG Setup Request
[2024-03-05 16:34:58.875] [ngap] [debug] NG Setup Response received
[2024-03-05 16:34:58.876] [ngap] [info] NG Setup procedure is successful
[2024-03-05 16:35:00.915] [rrc] [debug] UE[1] new signal detected
[2024-03-05 16:35:00.919] [rrc] [info] RRC Setup for UE[1]
[2024-03-05 16:35:00.920] [ngap] [debug] Initial NAS message received from UE[1]
[2024-03-05 16:35:01.181] [ngap] [debug] UE Context Release Command received
[2024-03-05 16:35:01.181] [ngap] [warning] Sending an error indication with cause: radio-network/inconsistent-remote-UE-NGAP-ID
[2024-03-05 16:35:01.552] [ngap] [debug] Initial Context Setup Request received
[2024-03-05 16:35:02.026] [ngap] [info] PDU session resource(s) setup for UE[1] count[1]
^Croot@da-ueransim:~/UERANSIM/config/[redacted]# 

=====================
=== UERANSIM (UE) ===
=====================
^Croot@da-ueransim:~/UERANSIM/config/[redacted]# ../../build/nr-ue -c ./[redacted]
UERANSIM v3.2.6
[2024-03-05 16:35:00.914] [nas] [info] UE switches to state [MM-DEREGISTERED/PLMN-SEARCH]
[2024-03-05 16:35:00.915] [rrc] [debug] New signal detected for cell[1], total [1] cells in coverage
[2024-03-05 16:35:00.916] [nas] [info] Selected plmn[001/01]
[2024-03-05 16:35:00.916] [rrc] [info] Selected cell plmn[001/01] tac[redacted] category[SUITABLE]
[2024-03-05 16:35:00.916] [nas] [info] UE switches to state [MM-DEREGISTERED/PS]
[2024-03-05 16:35:00.916] [nas] [info] UE switches to state [MM-DEREGISTERED/NORMAL-SERVICE]
[2024-03-05 16:35:00.917] [nas] [debug] Initial registration required due to [MM-DEREG-NORMAL-SERVICE]
[2024-03-05 16:35:00.917] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2024-03-05 16:35:00.917] [nas] [debug] Sending Initial Registration
[2024-03-05 16:35:00.918] [nas] [info] UE switches to state [MM-REGISTER-INITIATED]
[2024-03-05 16:35:00.918] [rrc] [debug] Sending RRC Setup Request
[2024-03-05 16:35:00.919] [rrc] [info] RRC connection established
[2024-03-05 16:35:00.919] [rrc] [info] UE switches to state [RRC-CONNECTED]
[2024-03-05 16:35:00.919] [nas] [info] UE switches to state [CM-CONNECTED]
[2024-03-05 16:35:01.020] [nas] [debug] Authentication Request received
[2024-03-05 16:35:01.020] [nas] [debug] Sending Authentication Failure due to SQN out of range
[2024-03-05 16:35:01.163] [nas] [debug] Authentication Request received
[2024-03-05 16:35:01.182] [nas] [debug] Security Mode Command received
[2024-03-05 16:35:01.182] [nas] [debug] Selected integrity[2] ciphering[0]
[2024-03-05 16:35:01.553] [nas] [debug] Registration accept received
[2024-03-05 16:35:01.553] [nas] [info] UE switches to state [MM-REGISTERED/NORMAL-SERVICE]
[2024-03-05 16:35:01.553] [nas] [debug] Sending Registration Complete
[2024-03-05 16:35:01.553] [nas] [info] Initial Registration is successful
[2024-03-05 16:35:01.553] [nas] [debug] Sending PDU Session Establishment Request
[2024-03-05 16:35:01.554] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2024-03-05 16:35:01.775] [nas] [debug] Configuration Update Command received
[2024-03-05 16:35:02.026] [nas] [debug] PDU Session Establishment Accept received
[2024-03-05 16:35:02.026] [nas] [info] PDU Session establishment is successful PSI[1]
[2024-03-05 16:35:02.083] [app] [info] Connection setup for PDU session[1] is successful, TUN interface[uesimtun0, 10.246.115.216] is up.
^Croot@da-ueransim:~/UERANSIM/config/[redacted]#

I did not have XDP logging enabled when I performed the above tests, but I did obtain XDP logs on the same test performed later:
(I enabled XDP logs using steps described here:

===============================
=== CMU Integration XDP Logs ==
===============================
          <idle>-0       [000] d.s.1 512573.117567: bpf_trace_printk: upf: arp received. passing to kernel
          <idle>-0       [000] d.s.1 512573.404139: bpf_trace_printk: upf: gtp-u received
          <idle>-0       [000] dNs.1 512573.404161: bpf_trace_printk: SDF: filter protocol: 1
          <idle>-0       [000] dNs.1 512573.404171: bpf_trace_printk: SDF: filter source ip: 0.0.0.0, destination ip: 0.0.0.0
          <idle>-0       [000] dNs.1 512573.404180: bpf_trace_printk: SDF: filter source ip mask: 0.0.0.0, destination ip mask: 0.0.0.0
          <idle>-0       [000] dNs.1 512573.404210: bpf_trace_printk: SDF: filter source port lower bound: 0, source port upper bound: 65535
          <idle>-0       [000] dNs.1 512573.404219: bpf_trace_printk: SDF: filter destination port lower bound: 0, destination port upper bound: 65535
          <idle>-0       [000] dNs.1 512573.404224: bpf_trace_printk: SDF: packet protocol: 0
          <idle>-0       [000] dNs.1 512573.404232: bpf_trace_printk: SDF: packet source ip: 10.246.115.216, destination ip: 8.8.8.8
          <idle>-0       [000] dNs.1 512573.404238: bpf_trace_printk: SDF: packet source port: 0, destination port: 0
          <idle>-0       [000] dNs.1 512573.404248: bpf_trace_printk: Packet with source ip: 10.246.115.216, destination ip: 8.8.8.8 matches SDF filter
          <idle>-0       [000] dNs.1 512573.404254: bpf_trace_printk: upf: sdf filter matches teid:1
          <idle>-0       [000] dNs.1 512573.404260: bpf_trace_printk: upf: far:0 action:2 outer_header_creation:0
          <idle>-0       [000] dNs.1 512573.404266: bpf_trace_printk: upf: qer:0 gate_status:0 mbr:705032704
          <idle>-0       [000] dNs.1 512573.404273: bpf_trace_printk: upf: session for teid:1 far:0 outer_header_removal:1
          <idle>-0       [000] dNs.1 512573.404287: bpf_trace_printk: upf: bpf_fib_lookup 192.168.102.54 -> 192.168.102.55: 4
          <idle>-0       [000] d.s.1 512573.712024: bpf_trace_printk: upf: arp received. passing to kernel

Here are XDP logs from O5GS integration, which works as intended.

================================
=== O5GS Integration XDP Logs ==
================================
          <idle>-0       [001] d.s.1 414557.805545: bpf_trace_printk: upf: no downlink session for ip:192.168.102.55
          <idle>-0       [001] d.s.1 414559.245725: bpf_trace_printk: upf: gtp-u received
          <idle>-0       [001] d.s.1 414559.245753: bpf_trace_printk: SDF: filter protocol: 4
          <idle>-0       [001] d.s.1 414559.245763: bpf_trace_printk: SDF: filter source ip: 0.0.0.2, destination ip: 0.0.0.0
          <idle>-0       [001] d.s.1 414559.245773: bpf_trace_printk: SDF: filter source ip mask: 255.255.255.255, destination ip mask: 0.0.0.0
          <idle>-0       [001] d.s.1 414559.245781: bpf_trace_printk: SDF: filter source port lower bound: 0, source port upper bound: 65535
          <idle>-0       [001] d.s.1 414559.245790: bpf_trace_printk: SDF: filter destination port lower bound: 0, destination port upper bound: 65535
          <idle>-0       [001] d.s.1 414559.245794: bpf_trace_printk: SDF: packet protocol: 0
          <idle>-0       [001] d.s.1 414559.245802: bpf_trace_printk: SDF: packet source ip: 10.45.0.2, destination ip: 8.8.8.8
          <idle>-0       [001] d.s.1 414559.245809: bpf_trace_printk: SDF: packet source port: 0, destination port: 0
          <idle>-0       [001] d.s.1 414559.245814: bpf_trace_printk: upf: sdf filter doesn't match teid:1
          <idle>-0       [001] d.s.1 414559.245821: bpf_trace_printk: upf: far:1 action:2 outer_header_creation:0
          <idle>-0       [001] d.s.1 414559.245827: bpf_trace_printk: upf: qer:0 gate_status:0 mbr:1000000000
          <idle>-0       [001] d.s.1 414559.245834: bpf_trace_printk: upf: session for teid:1 far:1 outer_header_removal:0
          <idle>-0       [001] d.s.1 414559.245858: bpf_trace_printk: upf: bpf_fib_lookup 10.45.0.2 -> 8.8.8.8: nexthop: 172.16.6.5
          <idle>-0       [001] d.s.1 414559.249879: bpf_trace_printk: upf: downlink session for ip:10.45.0.2  far:0 action:2

Finally, here are the API outputs I grabbed of both CMU and O5GS:

### CMU Packet Stats ###
{
    "rx_arp": 30,
    "rx_icmp": 0,
    "rx_icmp6": 0,
    "rx_ip4": 998,
    "rx_ip6": 0,
    "rx_tcp": 977,
    "rx_udp": 21,
    "rx_other": 0,
    "rx_gtp_echo": 0,
    "rx_gtp_pdu": 9,
    "rx_gtp_other": 0,
    "rx_gtp_unexp": 0
}

### CMU Xdp Stats ###
{
    "aborted": 0,
    "drop": 0,
    "pass": 1087,
    "tx": 0,
    "redirect": 0
}

### CMU PFCP Assocations ###
{
    "10.246.112.62": {
        "ID": "10.246.112.62",
        "Addr": "10.246.112.62",
        "NextSessionID": 2
    }
}

### CMU PFCP Sessions ###
[
    {
        "LocalSEID": 2,
        "RemoteSEID": 114960,
        "PDRs": {
            "18944": {
                "PdrID": 18944,
                "PdrInfo": {
                    "OuterHeaderRemoval": 1,
                    "FarId": 0,
                    "QerId": 0,
                    "SdfFilter": {
                        "Protocol": 1,
                        "SrcAddress": {
                            "Type": 0,
                            "Ip": "",
                            "Mask": null
                        },
                        "SrcPortRange": {
                            "LowerBound": 0,
                            "UpperBound": 65535
                        },
                        "DstAddress": {
                            "Type": 0,
                            "Ip": "",
                            "Mask": null
                        },
                        "DstPortRange": {
                            "LowerBound": 0,
                            "UpperBound": 65535
                        }
                    }
                },
                "Teid": 1,
                "Ipv4": "",
                "Ipv6": "",
                "Allocated": true
            }
        },
        "FARs": {
            "327680": {
                "FarInfo": {
                    "action": 2,
                    "local_ip": "192.168.102.55",
                    "outer_header_creation": 0,
                    "remote_ip": "0.0.0.0",
                    "teid": 0,
                    "transport_level_marking": 0
                },
                "GlobalId": 0
            },
            "537198592": {
                "FarInfo": {
                    "action": 2,
                    "local_ip": "192.168.102.55",
                    "outer_header_creation": 1,
                    "remote_ip": "192.168.102.54",
                    "teid": 1,
                    "transport_level_marking": 0
                },
                "GlobalId": 1
            }
        },
        "QERs": {
            "63": {
                "QerInfo": {
                    "GateStatusUL": 0,
                    "GateStatusDL": 0,
                    "Qfi": 0,
                    "MaxBitrateUL": 705032704,
                    "MaxBitrateDL": 705032704,
                    "StartUL": 0,
                    "StartDL": 0
                },
                "GlobalId": 0
            },
            "4117": {
                "QerInfo": {
                    "GateStatusUL": 0,
                    "GateStatusDL": 0,
                    "Qfi": 5,
                    "MaxBitrateUL": 0,
                    "MaxBitrateDL": 0,
                    "StartUL": 0,
                    "StartDL": 0
                },
                "GlobalId": 1
            }
        }
    }
]



### O5GS packet stats ###
{
    "rx_arp": 143,
    "rx_icmp": 3,
    "rx_icmp6": 0,
    "rx_ip4": 189,
    "rx_ip6": 0,
    "rx_tcp": 122,
    "rx_udp": 64,
    "rx_other": 0,
    "rx_gtp_echo": 0,
    "rx_gtp_pdu": 7,
    "rx_gtp_other": 0,
    "rx_gtp_unexp": 0
}

### O5GS xdp stats ###
{
    "aborted": 0,
    "drop": 0,
    "pass": 232,
    "tx": 4,
    "redirect": 6
}

### O5GS pfcp associations
{
    "192.168.102.52": {
        "ID": "192.168.102.52",
        "Addr": "192.168.102.52",
        "NextSessionID": 2
    }
}

### O5GS pfcp sessions ###
[
    {
        "LocalSEID": 2,
        "RemoteSEID": 3123,
        "PDRs": {
            "1": {
                "PdrID": 1,
                "PdrInfo": {
                    "OuterHeaderRemoval": 0,
                    "FarId": 0,
                    "QerId": 0,
                    "SdfFilter": null
                },
                "Teid": 0,
                "Ipv4": "10.45.0.2",
                "Ipv6": "",
                "Allocated": false
            },
            "2": {
                "PdrID": 2,
                "PdrInfo": {
                    "OuterHeaderRemoval": 0,
                    "FarId": 1,
                    "QerId": 0,
                    "SdfFilter": null
                },
                "Teid": 1,
                "Ipv4": "",
                "Ipv6": "",
                "Allocated": true
            },
            "3": {
                "PdrID": 3,
                "PdrInfo": {
                    "OuterHeaderRemoval": 0,
                    "FarId": 0,
                    "QerId": 0,
                    "SdfFilter": null
                },
                "Teid": 2,
                "Ipv4": "",
                "Ipv6": "",
                "Allocated": true
            },
            "4": {
                "PdrID": 4,
                "PdrInfo": {
                    "OuterHeaderRemoval": 0,
                    "FarId": 2,
                    "QerId": 0,
                    "SdfFilter": {
                        "Protocol": 4,
                        "SrcAddress": {
                            "Type": 2,
                            "Ip": "ff02::2",
                            "Mask": "/////////////////////w=="
                        },
                        "SrcPortRange": {
                            "LowerBound": 0,
                            "UpperBound": 65535
                        },
                        "DstAddress": {
                            "Type": 0,
                            "Ip": "",
                            "Mask": null
                        },
                        "DstPortRange": {
                            "LowerBound": 0,
                            "UpperBound": 65535
                        }
                    }
                },
                "Teid": 1,
                "Ipv4": "",
                "Ipv6": "",
                "Allocated": true
            }
        },
        "FARs": {
            "1": {
                "FarInfo": {
                    "action": 2,
                    "local_ip": "192.168.102.55",
                    "outer_header_creation": 1,
                    "remote_ip": "192.168.102.54",
                    "teid": 1,
                    "transport_level_marking": 0
                },
                "GlobalId": 0
            },
            "2": {
                "FarInfo": {
                    "action": 2,
                    "local_ip": "192.168.102.55",
                    "outer_header_creation": 0,
                    "remote_ip": "0.0.0.0",
                    "teid": 0,
                    "transport_level_marking": 0
                },
                "GlobalId": 1
            },
            "3": {
                "FarInfo": {
                    "action": 2,
                    "local_ip": "192.168.102.55",
                    "outer_header_creation": 1,
                    "remote_ip": "192.168.102.52",
                    "teid": 1,
                    "transport_level_marking": 0
                },
                "GlobalId": 2
            }
        },
        "QERs": {
            "1": {
                "QerInfo": {
                    "GateStatusUL": 0,
                    "GateStatusDL": 0,
                    "Qfi": 1,
                    "MaxBitrateUL": 1000000000,
                    "MaxBitrateDL": 1000000000,
                    "StartUL": 0,
                    "StartDL": 0
                },
                "GlobalId": 0
            }
        }
    }
]

The main problem I noticed in these logs was the fact that the SDF filter sent in "PFCP Session Establishment Request" was unable to be processed by eUPF due to not conforming to regex rules. This lead to default SDF filter rules being applied (source 0.0.0.0/0 dest 0.0.0.0/0 port range 0~65535), which would match every packet that comes in to the interface to use TEID=1. Then, a fib lookup of 192.168.102.54->192.168.102.55 was performed, but with the result "4" being outputted. I checked the logs with open5gs integration, and the fib lookup would usually result in xdp outputting the next-hop IP address, so this output of "4" was curious to me.

I suspect with CMU the behavior is caused by the packet being matched with PDR 18944, which has OuterHeaderRemoval value of 1, as opposed to O5GS which matched the packet with a PDR that has OuterHeaderRemoval value of 0.

I would be grateful for any assistance. Please let me know if any other info could be provided. Thanks in advance.

BR
Howard

pirog-spb · 2024-03-12T15:45:59Z

pirog-spb
Mar 12, 2024
Maintainer

Hi Howard @howardswe499 ,

Well, there are several issues. Let's go step by step:

eUPF ignored PDR 35328, because of empty SDF Filter. eUPF expects that SDF Filter matches some pattern when exists in CreatePDR field. Without this PDR applied downlink traffic can't be forwarded.
For PDR 18944 Outer Header Removal: 1 was received. It means that eUPF should remove GTPU&UDP&IPv6 headers from packet. It's not supported and moreover not needed in your case if I'm not mistaken. I suppose, CMU should send "Outer Header Removal: 0", which will instructs eUPF to remove GTPU&UDP&IPv4 headers.
bpf_fib_lookup 192.168.102.54 -> 192.168.102.55: 4 - eUPF tried to route packet without GTP-U & UDP & IPv4 headers removed. That's why you see 192.168.102.54 -> 192.168.102.55 instead of 10.246.115.216 -> 8.8.8.8. Result code 4 means BPF_FIB_LKUP_RET_NOT_FWDED. So you have to check host routing table. But, actually, you have to fix previous problem with outer header removing first.

As a conclusion. My proposal is to fix/configure CMU to send correct PDR instructions if it's possible.

Also I think it's possible to just ignore empty SDF filter on eUPF side in order not to skip the whole PDR and allow to forward downlink traffic. I can fix it with ease.

-- BR, Alex

3 replies

howardswe499 Mar 12, 2024
Author

Hi Alex @pirog-spb , I appreciate your quick and helpful reply.

Interesting! Your explanation really clarified for me what goes on behind the scenes. I hadn't considered that the empty SDF filter field was part of the problem, and also that Outer Header Removal value was not boolean. That explains a lot!

The problem is, I'm not very familiar with CMU configuration, so it may take a while for me to find out how to configure the PDR instructions so that Outer Header Removal is set to 0 instead of 1. I'll keep you updated for any breakthroughs.

Also, it would be very helpful if you could inform me how to let eUPF ignore the empty SDF filter.

Many thanks
Howard

howardswe499 Mar 27, 2024
Author

Hi @pirog-spb ,

I was wondering where you got the information regarding result code from point no. 3? I ran into an issue where I got result code 8 on bpf_fib_lookup.

howardswe499 Mar 27, 2024
Author

Nevermind, I found out it meant BPF_FIB_LKUP_RET_FRAG_NEEDED.

Here are the rest of the codes if other people are interested

0: BPF_FIB_LKUP_RET_SUCCESS,      /* lookup successful */
1: BPF_FIB_LKUP_RET_BLACKHOLE,    /* dest is blackholed; can be dropped */
2: BPF_FIB_LKUP_RET_UNREACHABLE,  /* dest is unreachable; can be dropped */
3: BPF_FIB_LKUP_RET_PROHIBIT,     /* dest not allowed; can be dropped */
4: BPF_FIB_LKUP_RET_NOT_FWDED,    /* packet is not forwarded */
5: BPF_FIB_LKUP_RET_FWD_DISABLED, /* fwding is not enabled on ingress */
6: BPF_FIB_LKUP_RET_UNSUPP_LWT,   /* fwd requires encapsulation */
7: BPF_FIB_LKUP_RET_NO_NEIGH,     /* no neighbor entry for nh */
8: BPF_FIB_LKUP_RET_FRAG_NEEDED,  /* fragmentation required to fwd */

pirog-spb · 2024-03-13T06:39:04Z

pirog-spb
Mar 13, 2024
Maintainer

The problem is, I'm not very familiar with CMU configuration, so it may take a while for me to find out how to configure the PDR instructions so that Outer Header Removal is set to 0 instead of 1. I'll keep you updated for any breakthroughs.

Take a closer look at CMU's N3 configuration. I suppose, CMU misconfigured to threat connection to UPF as IPv6-based.

0 replies

pirog-spb · 2024-03-13T19:30:05Z

pirog-spb
Mar 13, 2024
Maintainer

@howardswe499 You can try fix for empty SDF Filter from #538

1 reply

howardswe499 Mar 14, 2024
Author

Hi Alex @pirog-spb ,

I updated the project using the following commands

cd ~/eupf
git fetch
git checkout 537-ignore-empty-sdf-filter-field
git pull
BPF_CFLAGS="-DENABLE_LOG" go generate -v ./cmd/...
go clean -cache
go build -v -o bin/eupf ./cmd/

However, the PDR with empty SDF filter is still being ignored, here are the eUPF, XDP logs, and API outputs:
BTW may I ask how API output Uplink PDR Maps is generated? It doesn't seem to correspond to any of the PDRs received.

============
=== eUPF ===
============
root@da-eupf:~/eupf# ./bin/eupf
2024/03/14 10:07:18 Startup config: map[api_address::8080 echo_interval:10 far_map_size:1024 feature_ftup:true feature_ueip:true gtp_peer:[] heartbeat_interval:5 heartbeat_retries:3 heartbeat_timeout:5 interface_name:[ens224 ens192] logging_level:info metrics_address::9090 n3_address:192.168.102.55 pdr_map_size:1024 pfcp_address:192.168.102.55:8805 pfcp_node_id:192.168.102.55 qer_map_size:1024 resize_ebpf_maps:false teid_pool:65536 ueip_pool:10.45.0.0/16 xdp_attach_mode:generic]
2024/03/14 10:07:18 Apply eUPF config: {InterfaceName:[ens224 ens192] XDPAttachMode:generic ApiAddress::8080 PfcpAddress:192.168.102.55:8805 PfcpNodeId:192.168.102.55 MetricsAddress::9090 N3Address:192.168.102.55 GtpPeer:[] EchoInterval:10 QerMapSize:1024 FarMapSize:1024 PdrMapSize:1024 EbpfMapResize:false HeartbeatRetries:3 HeartbeatInterval:5 HeartbeatTimeout:5 LoggingLevel:info UEIPPool:10.45.0.0/16 FTEIDPool:65536 FeatureUEIP:true FeatureFTUP:true}
2024/03/14 10:07:19 INF Attached XDP program to iface "ens224" (index 4)
2024/03/14 10:07:19 INF Attached XDP program to iface "ens192" (index 3)
2024/03/14 10:07:19 INF Initialize resources: UEIP pool (CIDR: "10.45.0.0/16"), TEID pool (size: 65536)
2024/03/14 10:07:19 INF Starting PFCP connection: 192.168.102.55:8805 with Node ID: 192.168.102.55 and N3 address: 192.168.102.55
[GIN-debug] [WARNING] Creating an Engine instance with the Logger and Recovery middleware already attached.

[GIN-debug] [WARNING] Running in "debug" mode. Switch to "release" mode in production.
 - using env:   export GIN_MODE=release
 - using code:  gin.SetMode(gin.ReleaseMode)

[GIN-debug] GET    /api/v1/health            --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).InitRoutes.func1 (4 handlers)
[GIN-debug] GET    /api/v1/xdp_stats         --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).displayXdpStatistics-fm (4 handlers)
[GIN-debug] GET    /api/v1/packet_stats      --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).displayPacketStats-fm (4 handlers)
[GIN-debug] GET    /api/v1/config            --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).displayConfig-fm (4 handlers)
[GIN-debug] POST   /api/v1/config            --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).editConfig-fm (4 handlers)
[GIN-debug] GET    /api/v1/uplink_pdr_map/:id --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).getUplinkPdrValue-fm (4 handlers)
[GIN-debug] PUT    /api/v1/uplink_pdr_map/:id --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).setUplinkPdrValue-fm (4 handlers)
[GIN-debug] GET    /api/v1/qer_map           --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).listQerMapContent-fm (4 handlers)
[GIN-debug] GET    /api/v1/qer_map/:id       --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).getQerValue-fm (4 handlers)
[GIN-debug] PUT    /api/v1/qer_map/:id       --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).setQerValue-fm (4 handlers)
[GIN-debug] GET    /api/v1/far_map/:id       --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).getFarValue-fm (4 handlers)
[GIN-debug] PUT    /api/v1/far_map/:id       --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).setFarValue-fm (4 handlers)
[GIN-debug] GET    /api/v1/pfcp_associations --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).listPfcpAssociations-fm (4 handlers)
[GIN-debug] GET    /api/v1/pfcp_associations/full --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).listPfcpAssociationsFull-fm (4 handlers)
[GIN-debug] GET    /api/v1/pfcp_sessions     --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).listPfcpSessionsFiltered-fm (4 handlers)
[GIN-debug] GET    /swagger/*any             --> github.com/swaggo/gin-swagger.CustomWrapHandler.func1 (4 handlers)
[GIN-debug] [WARNING] Creating an Engine instance with the Logger and Recovery middleware already attached.

[GIN-debug] [WARNING] Running in "debug" mode. Switch to "release" mode in production.
 - using env:   export GIN_MODE=release
 - using code:  gin.SetMode(gin.ReleaseMode)

[GIN-debug] GET    /metrics                  --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).InitMetricsRoute.func1.1 (4 handlers)
2024/03/14 10:07:19 INF running on :8080
2024/03/14 10:07:19 INF running on :9090
2024/03/14 10:07:37 WRN Got unexpected message Association Release Request: {Version: 1, Flags: {FO: false, MP: false, S: false}, Type: 9, Length: 13, SEID: 0x0000000000000000, SequenceNumber: 0x3, MessagePriority: 0, Payload: 0x003c0005000af6703e}, from: 10.246.112.62:8805
2024/03/14 10:07:41 INF Got Association Setup Request from: 10.246.112.62. 

2024/03/14 10:07:41 INF 
Association Setup Request:
  Node ID: 10.246.112.62
  Recovery Time: 2024-03-14 10:07:41 +0800 CST

2024/03/14 10:07:41 INF Saving new association: &{ID:10.246.112.62 Addr:10.246.112.62 NextSessionID:1 NextSequenceID:1 Sessions:map[] HeartbeatChannel:0xc00009c7e0 FailedHeartbeats:0 HeartbeatsActive:false Mutex:{state:0 sema:0}}
2024/03/14 10:07:51 INF Got Session Establishment Request from: 10.246.112.62.
2024/03/14 10:07:51 INF 
Session Establishment Request:
  CreatePDR ID: 18944 
    Outer Header Removal: 1 
    FAR ID: 327680 
    QER ID: 73 
    QER ID: 4117 
    URR ID: 1610612737 
    Source Interface: 0 
    TEID: 0 
    Ipv4: <nil> 
    Ipv6: <nil> 
    UE IPv4 Address: 10.246.115.216 
    SDF Filter: permit out ip from any to any 
  CreatePDR ID: 35328 
    FAR ID: 537198592 
    QER ID: 73 
    QER ID: 4117 
    URR ID: 1610612737 
    Source Interface: 1 
    UE IPv4 Address: 10.246.115.216 
    SDF Filter:  
  CreateFAR ID: 327680 
    Apply Action: [2] 
    Forwarding Parameters:
      Network Instance: 5gtest1 
  CreateFAR ID: 537198592 
    Apply Action: [4] 
    Forwarding Parameters:
      Network Instance:n3-realm 
    BAR ID: 5 
  CreateQER ID: 73 
    Gate Status DL: 0 
    Gate Status UL: 0 
    Max Bitrate DL: 5000000 
    Max Bitrate UL: 5000000 
  CreateQER ID: 4117 
    Gate Status DL: 0 
    Gate Status UL: 0 
    QFI: 5 
  CreateURR ID: 1610612737 
    Measurement Method: 3 
  CreateURR ID: 1073741829 
    Measurement Method: 2 
    Volume Threshold: &{Flags:1 TotalVolume:104857600 UplinkVolume:0 DownlinkVolume:0} 
  CreateURR ID: 1073741825 
    Measurement Method: 2 
  CreateBAR ID: 5
    Downlink Data Notification Delay: 0s 

2024/03/14 10:07:51 INF WARN: No OuterHeaderCreation
2024/03/14 10:07:51 INF Saving FAR info to session: 327680, {Action:2 OuterHeaderCreation:0 Teid:0 RemoteIP:0 LocalIP:929474752 TransportLevelMarking:0}
2024/03/14 10:07:51 INF WARN: No OuterHeaderCreation
2024/03/14 10:07:51 INF Saving FAR info to session: 537198592, {Action:4 OuterHeaderCreation:0 Teid:0 RemoteIP:0 LocalIP:929474752 TransportLevelMarking:0}
2024/03/14 10:07:51 INF Saving QER info to session: 73, {GateStatusUL:0 GateStatusDL:0 Qfi:0 MaxBitrateUL:705032704 MaxBitrateDL:705032704 StartUL:0 StartDL:0}
2024/03/14 10:07:51 INF Saving QER info to session: 4117, {GateStatusUL:0 GateStatusDL:0 Qfi:5 MaxBitrateUL:0 MaxBitrateDL:0 StartUL:0 StartDL:0}
2024/03/14 10:07:51 Matched groups: [permit out ip from any to any ip any   any  ]
2024/03/14 10:07:51 Matched groups: []
2024/03/14 10:07:51 ERR SDFFilter err: SDF Filter: bad formatting. Should be compatible with regexp: ^permit out (icmp|ip|tcp|udp|\d+) from (any|[\d.]+|[\da-fA-F:]+)(?:/(\d+))?(?: (\d+|\d+-\d+))? to (assigned|any|[\d.]+|[\da-fA-F:]+)(?:/(\d+))?(?: (\d+|\d+-\d+))?$
2024/03/14 10:07:51 ERR error extracting PDR info: SDF Filter: bad formatting. Should be compatible with regexp: ^permit out (icmp|ip|tcp|udp|\d+) from (any|[\d.]+|[\da-fA-F:]+)(?:/(\d+))?(?: (\d+|\d+-\d+))? to (assigned|any|[\d.]+|[\da-fA-F:]+)(?:/(\d+))?(?: (\d+|\d+-\d+))?$
2024/03/14 10:07:51 INF Session Establishment Request from 10.246.112.62 accepted.
2024/03/14 10:07:51 INF Got Session Modification Request from: 10.246.112.62. 

2024/03/14 10:07:51 INF Finding association for 10.246.112.62
2024/03/14 10:07:51 INF Finding session 2
2024/03/14 10:07:51 INF 
Session Modification Request:
  UpdateFAR ID: 537198592 
    Apply Action: [2] 
    Update forwarding Parameters:
      Network Instance:n3-realm 
      Outer Header Creation: &{OuterHeaderCreationDescription:256 TEID:1 IPv4Address:192.168.102.54 IPv6Address:<nil> PortNumber:0 CTag:0 STag:0} 

2024/03/14 10:07:51 INF Updating FAR info: 537198592, {FarInfo:{Action:2 OuterHeaderCreation:1 Teid:1 RemoteIP:912697536 LocalIP:929474752 TransportLevelMarking:0} GlobalId:1}
[GIN] 2024/03/14 - 10:08:39 | 200 |    1.071917ms |  192.168.98.154 | GET      "/api/v1/pfcp_sessions"
[GIN] 2024/03/14 - 10:08:44 | 200 |     296.678µs |  192.168.98.154 | GET      "/api/v1/pfcp_sessions"
[GIN] 2024/03/14 - 10:08:59 | 200 |     292.681µs |  192.168.98.154 | GET      "/api/v1/uplink_pdr_map/1"
[GIN] 2024/03/14 - 10:09:01 | 404 |     178.965µs |  192.168.98.154 | GET      "/api/v1/uplink_pdr_map/0"
[GIN] 2024/03/14 - 10:09:03 | 404 |      89.125µs |  192.168.98.154 | GET      "/api/v1/uplink_pdr_map/2"
[GIN] 2024/03/14 - 10:09:04 | 404 |       86.87µs |  192.168.98.154 | GET      "/api/v1/uplink_pdr_map/3"
[GIN] 2024/03/14 - 10:09:06 | 200 |      94.254µs |  192.168.98.154 | GET      "/api/v1/uplink_pdr_map/1"
[GIN] 2024/03/14 - 10:09:29 | 200 |     153.703µs |  192.168.98.154 | GET      "/api/v1/pfcp_associations"
[GIN] 2024/03/14 - 10:09:31 | 200 |      82.809µs |  192.168.98.154 | GET      "/api/v1/uplink_pdr_map/1"
[GIN] 2024/03/14 - 10:09:32 | 200 |    1.360823ms |  192.168.98.154 | GET      "/api/v1/xdp_stats"
[GIN] 2024/03/14 - 10:09:34 | 200 |     299.169µs |  192.168.98.154 | GET      "/api/v1/packet_stats"

### CMU Packet Stats ###
{
    "rx_arp": 66,
    "rx_icmp": 0,
    "rx_icmp6": 0,
    "rx_ip4": 364,
    "rx_ip6": 0,
    "rx_tcp": 333,
    "rx_udp": 31,
    "rx_other": 0,
    "rx_gtp_echo": 0,
    "rx_gtp_pdu": 2,
    "rx_gtp_other": 0,
    "rx_gtp_unexp": 0
}

### CMU Xdp Stats ###
{
    "aborted": 0,
    "drop": 0,
    "pass": 422,
    "tx": 0,
    "redirect": 0
}

### CMU Uplink PDR Maps ### 
{
    "id": 1,
    "outer_header_removal": 0,
    "far_id": 0,
    "qer_id": 256
}

### CMU PFCP Assocations ###
{
    "10.246.112.62": {
        "ID": "10.246.112.62",
        "Addr": "10.246.112.62",
        "NextSessionID": 2
    }
}

### CMU PFCP Sessions ###
[
    {
        "LocalSEID": 2,
        "RemoteSEID": 94480,
        "PDRs": {
            "18944": {
                "PdrID": 18944,
                "PdrInfo": {
                    "OuterHeaderRemoval": 1,
                    "FarId": 0,
                    "QerId": 0,
                    "SdfFilter": {
                        "Protocol": 1,
                        "SrcAddress": {
                            "Type": 0,
                            "Ip": "",
                            "Mask": null
                        },
                        "SrcPortRange": {
                            "LowerBound": 0,
                            "UpperBound": 65535
                        },
                        "DstAddress": {
                            "Type": 0,
                            "Ip": "",
                            "Mask": null
                        },
                        "DstPortRange": {
                            "LowerBound": 0,
                            "UpperBound": 65535
                        }
                    }
                },
                "Teid": 1,
                "Ipv4": "",
                "Ipv6": "",
                "Allocated": true
            }
        },
        "FARs": {
            "327680": {
                "FarInfo": {
                    "action": 2,
                    "local_ip": "192.168.102.55",
                    "outer_header_creation": 0,
                    "remote_ip": "0.0.0.0",
                    "teid": 0,
                    "transport_level_marking": 0
                },
                "GlobalId": 0
            },
            "537198592": {
                "FarInfo": {
                    "action": 2,
                    "local_ip": "192.168.102.55",
                    "outer_header_creation": 1,
                    "remote_ip": "192.168.102.54",
                    "teid": 1,
                    "transport_level_marking": 0
                },
                "GlobalId": 1
            }
        },
        "QERs": {
            "73": {
                "QerInfo": {
                    "GateStatusUL": 0,
                    "GateStatusDL": 0,
                    "Qfi": 0,
                    "MaxBitrateUL": 705032704,
                    "MaxBitrateDL": 705032704,
                    "StartUL": 0,
                    "StartDL": 0
                },
                "GlobalId": 0
            },
            "4117": {
                "QerInfo": {
                    "GateStatusUL": 0,
                    "GateStatusDL": 0,
                    "Qfi": 5,
                    "MaxBitrateUL": 0,
                    "MaxBitrateDL": 0,
                    "StartUL": 0,
                    "StartDL": 0
                },
                "GlobalId": 1
            }
        }
    }
]

================
=== XDP Logs ===
================
          <idle>-0       [001] d.s.1 661734.454631: bpf_trace_printk: upf: no downlink session for ip:192.168.102.55
          <idle>-0       [001] d.s.1 661734.471477: bpf_trace_printk: upf: gtp-u received
          <idle>-0       [001] dNs.1 661734.471495: bpf_trace_printk: SDF: filter protocol: 1
          <idle>-0       [001] dNs.1 661734.471504: bpf_trace_printk: SDF: filter source ip: 0.0.0.0, destination ip: 0.0.0.0
          <idle>-0       [001] dNs.1 661734.471513: bpf_trace_printk: SDF: filter source ip mask: 0.0.0.0, destination ip mask: 0.0.0.0
          <idle>-0       [001] dNs.1 661734.471521: bpf_trace_printk: SDF: filter source port lower bound: 0, source port upper bound: 65535
          <idle>-0       [001] dNs.1 661734.471530: bpf_trace_printk: SDF: filter destination port lower bound: 0, destination port upper bound: 65535
          <idle>-0       [001] dNs.1 661734.471535: bpf_trace_printk: SDF: packet protocol: 0
          <idle>-0       [001] dNs.1 661734.471543: bpf_trace_printk: SDF: packet source ip: 10.246.115.216, destination ip: 8.8.8.8
          <idle>-0       [001] dNs.1 661734.471549: bpf_trace_printk: SDF: packet source port: 0, destination port: 0
          <idle>-0       [001] dNs.1 661734.471559: bpf_trace_printk: Packet with source ip: 10.246.115.216, destination ip: 8.8.8.8 matches SDF filter
          <idle>-0       [001] dNs.1 661734.471564: bpf_trace_printk: upf: sdf filter matches teid:1
          <idle>-0       [001] dNs.1 661734.471571: bpf_trace_printk: upf: far:0 action:2 outer_header_creation:0
          <idle>-0       [001] dNs.1 661734.471577: bpf_trace_printk: upf: qer:0 gate_status:0 mbr:705032704
          <idle>-0       [001] dNs.1 661734.471584: bpf_trace_printk: upf: session for teid:1 far:0 outer_header_removal:1
          <idle>-0       [001] dNs.1 661734.471597: bpf_trace_printk: upf: bpf_fib_lookup 192.168.102.54 -> 192.168.102.55: 4
          <idle>-0       [001] d.s.1 661734.474827: bpf_trace_printk: upf: no downlink session for ip:192.168.102.55
          <idle>-0       [001] d.s.1 661734.476450: bpf_trace_printk: upf: no downlink session for ip:192.168.102.55

Thanks for your help
BR, Howard

pirog-spb · 2024-03-17T08:04:21Z

pirog-spb
Mar 17, 2024
Maintainer

@howardswe499 Could you provide pcap dump for this scenario? Seems like the SDF Filter is not empty but contains spaces or some other unexpected content. May be as well the PFCP library used in eUPF fails to decode SDF Filter correctly.

1 reply

howardswe499 Mar 18, 2024
Author

Hi Alex @pirog-spb ,
Here are the pcap files for the scenario. https://drive.google.com/drive/folders/1fueVbpsWvl6lzWnZcjH_Cxm4PpAiY4qR?usp=sharing

I took a look at the packet, and this was in the problematic PDR's SDF filter field (Flow Description seems to be absent as there is no Flow Description flag):

Hope this helps.

BR
Howard

pirog-spb · 2024-03-19T07:03:18Z

pirog-spb
Mar 19, 2024
Maintainer

I've double-checked fix and see no way it may not satisfy you scenario. Could you please recheck on this commit 62cde23b0abaef95616645f84661be0437a9f148 from the same branch as well?

1 reply

howardswe499 Mar 20, 2024
Author

Hi @pirog-spb ,

I've updated to commit 62cde23b0abaef95616645f84661be0437a9f148 and rebuilt eupf, but the problem persists.

root@da-eupf:~/eupf# git rev-parse HEAD
62cde23b0abaef95616645f84661be0437a9f148

Here are the logs (Changes made were that I added 172.16.13.0/24 as N3 network):

============
=== eUPF ===
============
root@da-eupf:~/eupf# ./bin/eupf
2024/03/20 10:23:36 Startup config: map[api_address::8080 echo_interval:10 far_map_size:1024 feature_ftup:true feature_ueip:true gtp_peer:[] heartbeat_interval:5 heartbeat_retries:3 heartbeat_timeout:5 interface_name:[ens161 ens224 ens192] logging_level:info metrics_address::9090 n3_address:172.16.13.5 pdr_map_size:1024 pfcp_address:192.168.102.55:8805 pfcp_node_id:192.168.102.55 qer_map_size:1024 resize_ebpf_maps:false teid_pool:65536 ueip_pool:10.45.0.0/16 xdp_attach_mode:generic]
2024/03/20 10:23:36 Apply eUPF config: {InterfaceName:[ens161 ens224 ens192] XDPAttachMode:generic ApiAddress::8080 PfcpAddress:192.168.102.55:8805 PfcpNodeId:192.168.102.55 MetricsAddress::9090 N3Address:172.16.13.5 GtpPeer:[] EchoInterval:10 QerMapSize:1024 FarMapSize:1024 PdrMapSize:1024 EbpfMapResize:false HeartbeatRetries:3 HeartbeatInterval:5 HeartbeatTimeout:5 LoggingLevel:info UEIPPool:10.45.0.0/16 FTEIDPool:65536 FeatureUEIP:true FeatureFTUP:true}
2024/03/20 10:23:37 INF Attached XDP program to iface "ens161" (index 2)
2024/03/20 10:23:37 INF Attached XDP program to iface "ens224" (index 4)
2024/03/20 10:23:37 INF Attached XDP program to iface "ens192" (index 3)
2024/03/20 10:23:37 INF Initialize resources: UEIP pool (CIDR: "10.45.0.0/16"), TEID pool (size: 65536)
2024/03/20 10:23:37 INF Starting PFCP connection: 192.168.102.55:8805 with Node ID: 192.168.102.55 and N3 address: 172.16.13.5
[GIN-debug] [WARNING] Creating an Engine instance with the Logger and Recovery middleware already attached.

[GIN-debug] [WARNING] Running in "debug" mode. Switch to "release" mode in production.
 - using env:   export GIN_MODE=release
 - using code:  gin.SetMode(gin.ReleaseMode)

[GIN-debug] GET    /api/v1/health            --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).InitRoutes.func1 (4 handlers)
[GIN-debug] GET    /api/v1/xdp_stats         --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).displayXdpStatistics-fm (4 handlers)
[GIN-debug] GET    /api/v1/packet_stats      --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).displayPacketStats-fm (4 handlers)
[GIN-debug] GET    /api/v1/config            --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).displayConfig-fm (4 handlers)
[GIN-debug] POST   /api/v1/config            --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).editConfig-fm (4 handlers)
[GIN-debug] GET    /api/v1/uplink_pdr_map/:id --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).getUplinkPdrValue-fm (4 handlers)
[GIN-debug] PUT    /api/v1/uplink_pdr_map/:id --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).setUplinkPdrValue-fm (4 handlers)
[GIN-debug] GET    /api/v1/qer_map           --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).listQerMapContent-fm (4 handlers)
[GIN-debug] GET    /api/v1/qer_map/:id       --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).getQerValue-fm (4 handlers)
[GIN-debug] PUT    /api/v1/qer_map/:id       --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).setQerValue-fm (4 handlers)
[GIN-debug] GET    /api/v1/far_map/:id       --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).getFarValue-fm (4 handlers)
[GIN-debug] PUT    /api/v1/far_map/:id       --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).setFarValue-fm (4 handlers)
[GIN-debug] GET    /api/v1/pfcp_associations --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).listPfcpAssociations-fm (4 handlers)
[GIN-debug] GET    /api/v1/pfcp_associations/full --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).listPfcpAssociationsFull-fm (4 handlers)
[GIN-debug] GET    /api/v1/pfcp_sessions     --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).listPfcpSessionsFiltered-fm (4 handlers)
[GIN-debug] GET    /swagger/*any             --> github.com/swaggo/gin-swagger.CustomWrapHandler.func1 (4 handlers)
[GIN-debug] [WARNING] Creating an Engine instance with the Logger and Recovery middleware already attached.

[GIN-debug] [WARNING] Running in "debug" mode. Switch to "release" mode in production.
 - using env:   export GIN_MODE=release
 - using code:  gin.SetMode(gin.ReleaseMode)

[GIN-debug] GET    /metrics                  --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).InitMetricsRoute.func1.1 (4 handlers)
2024/03/20 10:23:37 INF running on :8080
2024/03/20 10:23:37 INF running on :9090
2024/03/20 10:23:38 INF Got Association Setup Request from: 10.246.112.62. 

2024/03/20 10:23:38 INF 
Association Setup Request: # CMU's SMF
  Node ID: 10.246.112.62
  Recovery Time: 2024-03-19 16:59:28 +0800 CST

2024/03/20 10:23:38 INF Saving new association: &{ID:10.246.112.62 Addr:10.246.112.62 NextSessionID:1 NextSequenceID:1 Sessions:map[] HeartbeatChannel:0xc000092f60 FailedHeartbeats:0 HeartbeatsActive:false Mutex:{state:0 sema:0}}
2024/03/20 10:23:39 INF Got Association Setup Request from: 192.168.102.52. 

2024/03/20 10:23:39 INF 
Association Setup Request: # This is another lab's SMF
  Node ID: 192.168.102.52
  Recovery Time: 2024-03-18 12:01:16 +0800 CST

2024/03/20 10:23:39 INF Saving new association: &{ID:192.168.102.52 Addr:192.168.102.52 NextSessionID:1 NextSequenceID:1 Sessions:map[] HeartbeatChannel:0xc000092fc0 FailedHeartbeats:0 HeartbeatsActive:false Mutex:{state:0 sema:0}}
2024/03/20 10:23:39 INF Got Association Setup Request from: 192.168.102.52. 

2024/03/20 10:23:39 INF 
Association Setup Request: # This is another lab's SMF
  Node ID: 192.168.102.52
  Recovery Time: 2024-03-18 12:01:16 +0800 CST

2024/03/20 10:23:39 WRN Association Setup Request with NodeID: 192.168.102.52 from: 192.168.102.52 already exists 
2024/03/20 10:23:39 WRN Session retention is not yet implemented
2024/03/20 10:23:39 INF Saving new association: &{ID:192.168.102.52 Addr:192.168.102.52 NextSessionID:1 NextSequenceID:1 Sessions:map[] HeartbeatChannel:0xc000093140 FailedHeartbeats:0 HeartbeatsActive:false Mutex:{state:0 sema:0}} 
2024/03/20 10:24:38 INF Got Session Establishment Request from: 10.246.112.62.
2024/03/20 10:24:38 INF 
Session Establishment Request:
  CreatePDR ID: 18944 
    Outer Header Removal: 1 
    FAR ID: 327680 
    QER ID: 77 
    QER ID: 4117 
    URR ID: 1610612737 
    Source Interface: 0 
    TEID: 0 
    Ipv4: <nil> 
    Ipv6: <nil> 
    UE IPv4 Address: 10.246.115.216 
    SDF Filter: permit out ip from any to any 
  CreatePDR ID: 35328 
    FAR ID: 537198592 
    QER ID: 77 
    QER ID: 4117 
    URR ID: 1610612737 
    Source Interface: 1 
    UE IPv4 Address: 10.246.115.216 
    SDF Filter:  
  CreateFAR ID: 327680 
    Apply Action: [2] 
    Forwarding Parameters:
      Network Instance: 5gtest1 
  CreateFAR ID: 537198592 
    Apply Action: [4] 
    Forwarding Parameters:
      Network Instance:n3-realm 
    BAR ID: 5 
  CreateQER ID: 77 
    Gate Status DL: 0 
    Gate Status UL: 0 
    Max Bitrate DL: 5000000 
    Max Bitrate UL: 5000000 
  CreateQER ID: 4117 
    Gate Status DL: 0 
    Gate Status UL: 0 
    QFI: 5 
  CreateURR ID: 1610612737 
    Measurement Method: 3 
  CreateURR ID: 1073741829 
    Measurement Method: 2 
    Volume Threshold: &{Flags:1 TotalVolume:104857600 UplinkVolume:0 DownlinkVolume:0} 
  CreateURR ID: 1073741825 
    Measurement Method: 2 
  CreateBAR ID: 5
    Downlink Data Notification Delay: 0s 

2024/03/20 10:24:38 INF WARN: No OuterHeaderCreation
2024/03/20 10:24:38 INF Saving FAR info to session: 327680, {Action:2 OuterHeaderCreation:0 Teid:0 RemoteIP:0 LocalIP:84742316 TransportLevelMarking:0}
2024/03/20 10:24:38 INF WARN: No OuterHeaderCreation
2024/03/20 10:24:38 INF Saving FAR info to session: 537198592, {Action:4 OuterHeaderCreation:0 Teid:0 RemoteIP:0 LocalIP:84742316 TransportLevelMarking:0}
2024/03/20 10:24:38 INF Saving QER info to session: 77, {GateStatusUL:0 GateStatusDL:0 Qfi:0 MaxBitrateUL:705032704 MaxBitrateDL:705032704 StartUL:0 StartDL:0}
2024/03/20 10:24:38 INF Saving QER info to session: 4117, {GateStatusUL:0 GateStatusDL:0 Qfi:5 MaxBitrateUL:0 MaxBitrateDL:0 StartUL:0 StartDL:0}
2024/03/20 10:24:38 Matched groups: [permit out ip from any to any ip any   any  ]
2024/03/20 10:24:38 Matched groups: []
2024/03/20 10:24:38 ERR SDFFilter err: SDF Filter: bad formatting. Should be compatible with regexp: ^permit out (icmp|ip|tcp|udp|\d+) from (any|[\d.]+|[\da-fA-F:]+)(?:/(\d+))?(?: (\d+|\d+-\d+))? to (assigned|any|[\d.]+|[\da-fA-F:]+)(?:/(\d+))?(?: (\d+|\d+-\d+))?$
2024/03/20 10:24:38 ERR error extracting PDR info: SDF Filter: bad formatting. Should be compatible with regexp: ^permit out (icmp|ip|tcp|udp|\d+) from (any|[\d.]+|[\da-fA-F:]+)(?:/(\d+))?(?: (\d+|\d+-\d+))? to (assigned|any|[\d.]+|[\da-fA-F:]+)(?:/(\d+))?(?: (\d+|\d+-\d+))?$
2024/03/20 10:24:38 INF Session Establishment Request from 10.246.112.62 accepted.
2024/03/20 10:24:39 INF Got Session Modification Request from: 10.246.112.62. 

2024/03/20 10:24:39 INF Finding association for 10.246.112.62
2024/03/20 10:24:39 INF Finding session 2
2024/03/20 10:24:39 INF 
Session Modification Request:
  UpdateFAR ID: 537198592 
    Apply Action: [2] 
    Update forwarding Parameters:
      Network Instance:n3-realm 
      Outer Header Creation: &{OuterHeaderCreationDescription:256 TEID:1 IPv4Address:172.16.13.1 IPv6Address:<nil> PortNumber:0 CTag:0 STag:0} 

2024/03/20 10:24:39 INF Updating FAR info: 537198592, {FarInfo:{Action:2 OuterHeaderCreation:1 Teid:1 RemoteIP:17633452 LocalIP:84742316 TransportLevelMarking:0} GlobalId:1}
[GIN] 2024/03/20 - 10:29:32 | 200 |     854.886µs |   192.168.97.64 | GET      "/api/v1/packet_stats"
[GIN] 2024/03/20 - 10:29:38 | 200 |    1.104144ms |   192.168.97.64 | GET      "/api/v1/xdp_stats"
[GIN] 2024/03/20 - 10:29:41 | 404 |      274.11µs |   192.168.97.64 | GET      "/api/v1/uplink_pdr_map/6"
[GIN] 2024/03/20 - 10:29:46 | 404 |     126.119µs |   192.168.97.64 | GET      "/api/v1/uplink_pdr_map/0"
[GIN] 2024/03/20 - 10:29:48 | 200 |     152.002µs |   192.168.97.64 | GET      "/api/v1/uplink_pdr_map/1"
[GIN] 2024/03/20 - 10:29:54 | 404 |     253.313µs |   192.168.97.64 | GET      "/api/v1/uplink_pdr_map/2"
[GIN] 2024/03/20 - 10:29:56 | 404 |      93.618µs |   192.168.97.64 | GET      "/api/v1/uplink_pdr_map/3"
[GIN] 2024/03/20 - 10:30:00 | 200 |    1.075693ms |   192.168.97.64 | GET      "/api/v1/pfcp_associations"
[GIN] 2024/03/20 - 10:30:06 | 200 |    5.293935ms |   192.168.97.64 | GET      "/api/v1/pfcp_sessions"

================
=== XDP Logs ===
================
          <idle>-0       [000] d.s.1 1182088.449308: bpf_trace_printk: upf: no downlink session for ip:192.168.102.55
          <idle>-0       [000] d.s.1 1182088.502765: bpf_trace_printk: upf: gtp-u received
          <idle>-0       [000] d.s.1 1182088.502794: bpf_trace_printk: SDF: filter protocol: 1
          <idle>-0       [000] d.s.1 1182088.502804: bpf_trace_printk: SDF: filter source ip: 0.0.0.0, destination ip: 0.0.0.0
          <idle>-0       [000] d.s.1 1182088.502813: bpf_trace_printk: SDF: filter source ip mask: 0.0.0.0, destination ip mask: 0.0.0.0
          <idle>-0       [000] d.s.1 1182088.502822: bpf_trace_printk: SDF: filter source port lower bound: 0, source port upper bound: 65535
          <idle>-0       [000] d.s.1 1182088.502831: bpf_trace_printk: SDF: filter destination port lower bound: 0, destination port upper bound: 65535
          <idle>-0       [000] d.s.1 1182088.502835: bpf_trace_printk: SDF: packet protocol: 0
          <idle>-0       [000] d.s.1 1182088.502846: bpf_trace_printk: SDF: packet source ip: 10.246.115.216, destination ip: 8.8.8.8
          <idle>-0       [000] d.s.1 1182088.502852: bpf_trace_printk: SDF: packet source port: 0, destination port: 0
          <idle>-0       [000] d.s.1 1182088.502863: bpf_trace_printk: Packet with source ip: 10.246.115.216, destination ip: 8.8.8.8 matches SDF filter
          <idle>-0       [000] d.s.1 1182088.502868: bpf_trace_printk: upf: sdf filter matches teid:1
          <idle>-0       [000] d.s.1 1182088.502874: bpf_trace_printk: upf: far:0 action:2 outer_header_creation:0
          <idle>-0       [000] d.s.1 1182088.502880: bpf_trace_printk: upf: qer:0 gate_status:0 mbr:705032704
          <idle>-0       [000] d.s.1 1182088.502888: bpf_trace_printk: upf: session for teid:1 far:0 outer_header_removal:1
          <idle>-0       [000] d.s.1 1182088.502902: bpf_trace_printk: upf: bpf_fib_lookup 172.16.13.1 -> 172.16.13.5: 4
          <idle>-0       [000] d.s.1 1182088.508902: bpf_trace_printk: upf: no downlink session for ip:192.168.102.55
          <idle>-0       [000] d.s.1 1182088.519014: bpf_trace_printk: upf: no downlink session for ip:192.168.102.55

### CMU Packet Stats ###
{
    "rx_arp": 203,
    "rx_icmp": 34,
    "rx_icmp6": 0,
    "rx_ip4": 1067,
    "rx_ip6": 0,
    "rx_tcp": 748,
    "rx_udp": 285,
    "rx_other": 0,
    "rx_gtp_echo": 0,
    "rx_gtp_pdu": 102,
    "rx_gtp_other": 0,
    "rx_gtp_unexp": 0
}

### CMU Xdp Stats ###
{
    "aborted": 0,
    "drop": 0,
    "pass": 1292,
    "tx": 0,
    "redirect": 0
}

### CMU Uplink PDR Maps ###
{
    "id": 1,
    "outer_header_removal": 0,
    "far_id": 0,
    "qer_id": 256
}

### CMU PFCP Assocations ###
{
    "10.246.112.62": {
        "ID": "10.246.112.62",
        "Addr": "10.246.112.62",
        "NextSessionID": 2
    },
    "192.168.102.52": { # Other Lab PFCP Association
        "ID": "192.168.102.52",
        "Addr": "192.168.102.52",
        "NextSessionID": 1
    }
}

### CMU PFCP Sessions ###
[
    {
        "LocalSEID": 2,
        "RemoteSEID": 176432,
        "PDRs": {
            "18944": {
                "PdrID": 18944,
                "PdrInfo": {
                    "OuterHeaderRemoval": 1,
                    "FarId": 0,
                    "QerId": 0,
                    "SdfFilter": {
                        "Protocol": 1,
                        "SrcAddress": {
                            "Type": 0,
                            "Ip": "",
                            "Mask": null
                        },
                        "SrcPortRange": {
                            "LowerBound": 0,
                            "UpperBound": 65535
                        },
                        "DstAddress": {
                            "Type": 0,
                            "Ip": "",
                            "Mask": null
                        },
                        "DstPortRange": {
                            "LowerBound": 0,
                            "UpperBound": 65535
                        }
                    }
                },
                "Teid": 1,
                "Ipv4": "",
                "Ipv6": "",
                "Allocated": true
            }
        },
        "FARs": {
            "327680": {
                "FarInfo": {
                    "action": 2,
                    "local_ip": "172.16.13.5",
                    "outer_header_creation": 0,
                    "remote_ip": "0.0.0.0",
                    "teid": 0,
                    "transport_level_marking": 0
                },
                "GlobalId": 0
            },
            "537198592": {
                "FarInfo": {
                    "action": 2,
                    "local_ip": "172.16.13.5",
                    "outer_header_creation": 1,
                    "remote_ip": "172.16.13.1",
                    "teid": 1,
                    "transport_level_marking": 0
                },
                "GlobalId": 1
            }
        },
        "QERs": {
            "77": {
                "QerInfo": {
                    "GateStatusUL": 0,
                    "GateStatusDL": 0,
                    "Qfi": 0,
                    "MaxBitrateUL": 705032704,
                    "MaxBitrateDL": 705032704,
                    "StartUL": 0,
                    "StartDL": 0
                },
                "GlobalId": 0
            },
            "4117": {
                "QerInfo": {
                    "GateStatusUL": 0,
                    "GateStatusDL": 0,
                    "Qfi": 5,
                    "MaxBitrateUL": 0,
                    "MaxBitrateDL": 0,
                    "StartUL": 0,
                    "StartDL": 0
                },
                "GlobalId": 1
            }
        }
    }
]

Thanks for the help.
BR
Howard

pirog-spb · 2024-03-20T17:42:41Z

pirog-spb
Mar 20, 2024
Maintainer

Looks strange, because in the last commit I slightly changed log format.

Instead of:

Matched groups: [permit out ip from any to any ip any   any  ]

should be (results are quoted)

Matched groups: ["permit out ip from any to any" "ip" "any" "" "" "any" "" ""]

Could you please double check that you run right version of eUPF?

0 replies

howardswe499 · 2024-03-21T02:38:05Z

howardswe499
Mar 21, 2024
Author

Great news, the fix works! The program was indeed not getting updated properly (probably due to my end, honestly).

I checked the ~/eupf/bin/eupf file's modification date, and it was showing an older version. I tried deleting the whole ~/eupf/bin/ folder, then re-building eupf, but that didn't work either (no /bin/eupf was created). So I ended up saving my config files, deleting the ~/eupf folder, and re-cloning the repo.

# Delete eupf project (after saving configs)
rm -rf eupf

# Re-cloning eupf
git clone https://github.com/edgecomllc/eupf.git -b 537-ignore-empty-sdf-filter-field

# Confirm I am on correct commit
git rev-parse HEAD 

# Build eupf
BPF_CFLAGS="-DENABLE_LOG" go generate -v ./cmd/...
go build -v -o bin/eupf ./cmd/

Here are the logs, the PDR with the empty SDF filter field is no longer getting ignored!:

Logs

============
=== eUPF ===
============
root@da-eupf:~/eupf# ./bin/eupf
2024/03/21 10:21:35 Startup config: map[api_address::8080 echo_interval:10 far_map_size:1024 feature_ftup:true feature_ueip:true gtp_peer:[] heartbeat_interval:60 heartbeat_retries:3 heartbeat_timeout:60 interface_name:[ens161 ens224 ens192] logging_level:info metrics_address::9090 n3_address:172.16.13.5 pdr_map_size:1024 pfcp_address:192.168.102.55:8805 pfcp_node_id:192.168.102.55 qer_map_size:1024 resize_ebpf_maps:false teid_pool:65536 ueip_pool:10.60.0.0/24 xdp_attach_mode:generic]
2024/03/21 10:21:35 Apply eUPF config: {InterfaceName:[ens161 ens224 ens192] XDPAttachMode:generic ApiAddress::8080 PfcpAddress:192.168.102.55:8805 PfcpNodeId:192.168.102.55 MetricsAddress::9090 N3Address:172.16.13.5 GtpPeer:[] EchoInterval:10 QerMapSize:1024 FarMapSize:1024 PdrMapSize:1024 EbpfMapResize:false HeartbeatRetries:3 HeartbeatInterval:60 HeartbeatTimeout:60 LoggingLevel:info UEIPPool:10.60.0.0/24 FTEIDPool:65536 FeatureUEIP:true FeatureFTUP:true}
2024/03/21 10:21:35 INF Attached XDP program to iface "ens161" (index 8)
2024/03/21 10:21:35 INF Attached XDP program to iface "ens224" (index 9)
2024/03/21 10:21:35 INF Attached XDP program to iface "ens192" (index 7)
2024/03/21 10:21:35 INF Initialize resources: UEIP pool (CIDR: "10.60.0.0/24"), TEID pool (size: 65536)
2024/03/21 10:21:35 INF Starting PFCP connection: 192.168.102.55:8805 with Node ID: 192.168.102.55 and N3 address: 172.16.13.5
[GIN-debug] [WARNING] Creating an Engine instance with the Logger and Recovery middleware already attached.

[GIN-debug] [WARNING] Running in "debug" mode. Switch to "release" mode in production.
 - using env:   export GIN_MODE=release
 - using code:  gin.SetMode(gin.ReleaseMode)

[GIN-debug] GET    /api/v1/health            --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).InitRoutes.func1 (4 handlers)
[GIN-debug] GET    /api/v1/xdp_stats         --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).displayXdpStatistics-fm (4 handlers)
[GIN-debug] GET    /api/v1/packet_stats      --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).displayPacketStats-fm (4 handlers)
[GIN-debug] GET    /api/v1/config            --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).displayConfig-fm (4 handlers)
[GIN-debug] POST   /api/v1/config            --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).editConfig-fm (4 handlers)
[GIN-debug] GET    /api/v1/uplink_pdr_map/:id --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).getUplinkPdrValue-fm (4 handlers)
[GIN-debug] PUT    /api/v1/uplink_pdr_map/:id --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).setUplinkPdrValue-fm (4 handlers)
[GIN-debug] GET    /api/v1/qer_map           --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).listQerMapContent-fm (4 handlers)
[GIN-debug] GET    /api/v1/qer_map/:id       --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).getQerValue-fm (4 handlers)
[GIN-debug] PUT    /api/v1/qer_map/:id       --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).setQerValue-fm (4 handlers)
[GIN-debug] GET    /api/v1/far_map/:id       --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).getFarValue-fm (4 handlers)
[GIN-debug] PUT    /api/v1/far_map/:id       --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).setFarValue-fm (4 handlers)
[GIN-debug] GET    /api/v1/pfcp_associations --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).listPfcpAssociations-fm (4 handlers)
[GIN-debug] GET    /api/v1/pfcp_associations/full --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).listPfcpAssociationsFull-fm (4 handlers)
[GIN-debug] GET    /api/v1/pfcp_sessions     --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).listPfcpSessionsFiltered-fm (4 handlers)
[GIN-debug] GET    /swagger/*any             --> github.com/swaggo/gin-swagger.CustomWrapHandler.func1 (4 handlers)
[GIN-debug] [WARNING] Creating an Engine instance with the Logger and Recovery middleware already attached.

[GIN-debug] [WARNING] Running in "debug" mode. Switch to "release" mode in production.
 - using env:   export GIN_MODE=release
 - using code:  gin.SetMode(gin.ReleaseMode)

[GIN-debug] GET    /metrics                  --> github.com/edgecomllc/eupf/cmd/api/rest.(*ApiHandler).InitMetricsRoute.func1.1 (4 handlers)
2024/03/21 10:21:35 INF running on :8080
2024/03/21 10:21:35 INF running on :9090
2024/03/21 10:21:38 INF Got Association Setup Request from: 10.246.112.62. 

2024/03/21 10:21:38 INF 
Association Setup Request:
  Node ID: 10.246.112.62
  Recovery Time: 2024-03-21 10:18:33 +0800 CST

2024/03/21 10:21:38 INF Saving new association: &{ID:10.246.112.62 Addr:10.246.112.62 NextSessionID:1 NextSequenceID:1 Sessions:map[] HeartbeatChannel:0xc000102780 FailedHeartbeats:0 HeartbeatsActive:false Mutex:{state:0 sema:0}}
2024/03/21 10:21:44 INF Got Session Establishment Request from: 10.246.112.62.
2024/03/21 10:21:44 INF 
Session Establishment Request:
  CreatePDR ID: 18944 
    Outer Header Removal: 1 
    FAR ID: 327680 
    QER ID: 78 
    QER ID: 4117 
    URR ID: 1610612737 
    Source Interface: 0 
    TEID: 0 
    Ipv4: <nil> 
    Ipv6: <nil> 
    UE IPv4 Address: 10.246.115.216 
    SDF Filter: permit out ip from any to any 
  CreatePDR ID: 35328 
    FAR ID: 537198592 
    QER ID: 78 
    QER ID: 4117 
    URR ID: 1610612737 
    Source Interface: 1 
    UE IPv4 Address: 10.246.115.216 
    SDF Filter:  
  CreateFAR ID: 327680 
    Apply Action: [2] 
    Forwarding Parameters:
      Network Instance: 5gtest1 
  CreateFAR ID: 537198592 
    Apply Action: [4] 
    Forwarding Parameters:
      Network Instance:n3-realm 
    BAR ID: 5 
  CreateQER ID: 78 
    Gate Status DL: 0 
    Gate Status UL: 0 
    Max Bitrate DL: 5000000 
    Max Bitrate UL: 5000000 
  CreateQER ID: 4117 
    Gate Status DL: 0 
    Gate Status UL: 0 
    QFI: 5 
  CreateURR ID: 1610612737 
    Measurement Method: 3 
  CreateURR ID: 1073741829 
    Measurement Method: 2 
    Volume Threshold: &{Flags:1 TotalVolume:104857600 UplinkVolume:0 DownlinkVolume:0} 
  CreateURR ID: 1073741825 
    Measurement Method: 2 
  CreateBAR ID: 5
    Downlink Data Notification Delay: 0s 

2024/03/21 10:21:44 INF WARN: No OuterHeaderCreation
2024/03/21 10:21:44 INF Saving FAR info to session: 327680, {Action:2 OuterHeaderCreation:0 Teid:0 RemoteIP:0 LocalIP:84742316 TransportLevelMarking:0}
2024/03/21 10:21:44 INF WARN: No OuterHeaderCreation
2024/03/21 10:21:44 INF Saving FAR info to session: 537198592, {Action:4 OuterHeaderCreation:0 Teid:0 RemoteIP:0 LocalIP:84742316 TransportLevelMarking:0}
2024/03/21 10:21:44 INF Saving QER info to session: 78, {GateStatusUL:0 GateStatusDL:0 Qfi:0 MaxBitrateUL:705032704 MaxBitrateDL:705032704 StartUL:0 StartDL:0}
2024/03/21 10:21:44 INF Saving QER info to session: 4117, {GateStatusUL:0 GateStatusDL:0 Qfi:5 MaxBitrateUL:0 MaxBitrateDL:0 StartUL:0 StartDL:0}
2024/03/21 10:21:44 Matched groups: ["permit out ip from any to any" "ip" "any" "" "" "any" "" ""]
2024/03/21 10:21:44 WRN SDFFilter is empty
2024/03/21 10:21:44 INF Session Establishment Request from 10.246.112.62 accepted.
2024/03/21 10:21:45 INF Got Session Modification Request from: 10.246.112.62. 

2024/03/21 10:21:45 INF Finding association for 10.246.112.62
2024/03/21 10:21:45 INF Finding session 2
2024/03/21 10:21:45 INF 
Session Modification Request:
  UpdateFAR ID: 537198592 
    Apply Action: [2] 
    Update forwarding Parameters:
      Network Instance:n3-realm 
      Outer Header Creation: &{OuterHeaderCreationDescription:256 TEID:5 IPv4Address:172.16.13.1 IPv6Address:<nil> PortNumber:0 CTag:0 STag:0} 

2024/03/21 10:21:45 INF Updating FAR info: 537198592, {FarInfo:{Action:2 OuterHeaderCreation:1 Teid:5 RemoteIP:17633452 LocalIP:84742316 TransportLevelMarking:0} GlobalId:1}

================
=== XDP Logs ===
================
          <idle>-0       [001] d.s.1 1268091.105499: bpf_trace_printk: upf: no downlink session for ip:192.168.102.55
          <idle>-0       [001] d.s.1 1268091.139335: bpf_trace_printk: upf: gtp-u received
          <idle>-0       [001] d.s.1 1268091.139365: bpf_trace_printk: SDF: filter protocol: 1
          <idle>-0       [001] d.s.1 1268091.139374: bpf_trace_printk: SDF: filter source ip: 0.0.0.0, destination ip: 0.0.0.0
          <idle>-0       [001] d.s.1 1268091.139383: bpf_trace_printk: SDF: filter source ip mask: 0.0.0.0, destination ip mask: 0.0.0.0
          <idle>-0       [001] d.s.1 1268091.139391: bpf_trace_printk: SDF: filter source port lower bound: 0, source port upper bound: 65535
          <idle>-0       [001] d.s.1 1268091.139401: bpf_trace_printk: SDF: filter destination port lower bound: 0, destination port upper bound: 65535
          <idle>-0       [001] d.s.1 1268091.139405: bpf_trace_printk: SDF: packet protocol: 0
          <idle>-0       [001] d.s.1 1268091.139413: bpf_trace_printk: SDF: packet source ip: 10.246.115.216, destination ip: 8.8.8.8
          <idle>-0       [001] d.s.1 1268091.139420: bpf_trace_printk: SDF: packet source port: 0, destination port: 0
          <idle>-0       [001] d.s.1 1268091.139430: bpf_trace_printk: Packet with source ip: 10.246.115.216, destination ip: 8.8.8.8 matches SDF filter
          <idle>-0       [001] d.s.1 1268091.139435: bpf_trace_printk: upf: sdf filter matches teid:1
          <idle>-0       [001] d.s.1 1268091.139441: bpf_trace_printk: upf: far:0 action:2 outer_header_creation:0
          <idle>-0       [001] d.s.1 1268091.139450: bpf_trace_printk: upf: qer:0 gate_status:0 mbr:705032704
          <idle>-0       [001] d.s.1 1268091.139458: bpf_trace_printk: upf: session for teid:1 far:0 outer_header_removal:1
          <idle>-0       [001] d.s.1 1268091.139472: bpf_trace_printk: upf: bpf_fib_lookup 172.16.13.1 -> 172.16.13.5: 4
          <idle>-0       [001] d.s.1 1268091.147344: bpf_trace_printk: upf: no downlink session for ip:192.168.102.55

### CMU Packet Stats ###
{
    "rx_arp": 34,
    "rx_icmp": 0,
    "rx_icmp6": 0,
    "rx_ip4": 128,
    "rx_ip6": 0,
    "rx_tcp": 85,
    "rx_udp": 43,
    "rx_other": 0,
    "rx_gtp_echo": 0,
    "rx_gtp_pdu": 39,
    "rx_gtp_other": 0,
    "rx_gtp_unexp": 0
}

### CMU Xdp Stats ###
{
    "aborted": 0,
    "drop": 0,
    "pass": 360,
    "tx": 0,
    "redirect": 0
}

### CMU Uplink PDR Maps ###
{
    "id": 1,
    "outer_header_removal": 0,
    "far_id": 0,
    "qer_id": 256
}

### CMU PFCP Assocations ###
{
    "10.246.112.62": {
        "ID": "10.246.112.62",
        "Addr": "10.246.112.62",
        "NextSessionID": 2
    }
}

### CMU PFCP Sessions ###
[
    {
        "LocalSEID": 2,
        "RemoteSEID": 180496,
        "PDRs": {
            "18944": {
                "PdrID": 18944,
                "PdrInfo": {
                    "OuterHeaderRemoval": 1,
                    "FarId": 0,
                    "QerId": 0,
                    "SdfFilter": {
                        "Protocol": 1,
                        "SrcAddress": {
                            "Type": 0,
                            "Ip": "",
                            "Mask": null
                        },
                        "SrcPortRange": {
                            "LowerBound": 0,
                            "UpperBound": 65535
                        },
                        "DstAddress": {
                            "Type": 0,
                            "Ip": "",
                            "Mask": null
                        },
                        "DstPortRange": {
                            "LowerBound": 0,
                            "UpperBound": 65535
                        }
                    }
                },
                "Teid": 1,
                "Ipv4": "",
                "Ipv6": "",
                "Allocated": true
            },
            "35328": {
                "PdrID": 35328,
                "PdrInfo": {
                    "OuterHeaderRemoval": 0,
                    "FarId": 1,
                    "QerId": 0,
                    "SdfFilter": null
                },
                "Teid": 0,
                "Ipv4": "10.246.115.216",
                "Ipv6": "",
                "Allocated": false
            }
        },
        "FARs": {
            "327680": {
                "FarInfo": {
                    "action": 2,
                    "local_ip": "172.16.13.5",
                    "outer_header_creation": 0,
                    "remote_ip": "0.0.0.0",
                    "teid": 0,
                    "transport_level_marking": 0
                },
                "GlobalId": 0
            },
            "537198592": {
                "FarInfo": {
                    "action": 2,
                    "local_ip": "172.16.13.5",
                    "outer_header_creation": 1,
                    "remote_ip": "172.16.13.1",
                    "teid": 5,
                    "transport_level_marking": 0
                },
                "GlobalId": 1
            }
        },
        "QERs": {
            "78": {
                "QerInfo": {
                    "GateStatusUL": 0,
                    "GateStatusDL": 0,
                    "Qfi": 0,
                    "MaxBitrateUL": 705032704,
                    "MaxBitrateDL": 705032704,
                    "StartUL": 0,
                    "StartDL": 0
                },
                "GlobalId": 0
            },
            "4117": {
                "QerInfo": {
                    "GateStatusUL": 0,
                    "GateStatusDL": 0,
                    "Qfi": 5,
                    "MaxBitrateUL": 0,
                    "MaxBitrateDL": 0,
                    "StartUL": 0,
                    "StartDL": 0
                },
                "GlobalId": 1
            }
        }
    }
]

Thanks for your work and patience.

Cheers,
Howard

0 replies

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

eUPF Integration with Nokia CMU SMF #535

{{title}}

{{editor}}'s edit

{{editor}}'s edit

Replies: 7 comments 6 replies

{{title}}

{{title}}

{{title}}

{{title}}

{{editor}}'s edit

{{editor}}'s edit

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{editor}}'s edit

{{editor}}'s edit

{{title}}

{{title}}

{{editor}}'s edit

{{editor}}'s edit

{{title}}

{{title}}

Select a reply

eUPF Integration with Nokia CMU SMF #535

howardswe499 Mar 12, 2024

Replies: 7 comments · 6 replies

pirog-spb Mar 12, 2024 Maintainer

howardswe499 Mar 12, 2024 Author

howardswe499 Mar 27, 2024 Author

howardswe499 Mar 27, 2024 Author

pirog-spb Mar 13, 2024 Maintainer

pirog-spb Mar 13, 2024 Maintainer

howardswe499 Mar 14, 2024 Author

pirog-spb Mar 17, 2024 Maintainer

howardswe499 Mar 18, 2024 Author

pirog-spb Mar 19, 2024 Maintainer

howardswe499 Mar 20, 2024 Author

pirog-spb Mar 20, 2024 Maintainer

howardswe499 Mar 21, 2024 Author

howardswe499
Mar 12, 2024

Replies: 7 comments 6 replies

pirog-spb
Mar 12, 2024
Maintainer

howardswe499 Mar 12, 2024
Author

howardswe499 Mar 27, 2024
Author

howardswe499 Mar 27, 2024
Author

pirog-spb
Mar 13, 2024
Maintainer

pirog-spb
Mar 13, 2024
Maintainer

howardswe499 Mar 14, 2024
Author

pirog-spb
Mar 17, 2024
Maintainer

howardswe499 Mar 18, 2024
Author

pirog-spb
Mar 19, 2024
Maintainer

howardswe499 Mar 20, 2024
Author

pirog-spb
Mar 20, 2024
Maintainer

howardswe499
Mar 21, 2024
Author